LOAD DATA (400k rows) INFILE takes about 7 minutes, cannot kill the “logging slow query” process?

By Posted on

Question :

MySQL version: 5.5.13

The query that I’m using:

SET AUTOCOMMIT=0; 
LOAD DATA INFILE '/data10/select_into.outfile/v3_zone_date.out' INTO TABLE v3_zone_date FIELDS TERMINATED BY  ','; 
COMMIT;

Normally it takes 3s to complete. But sometime, the insert query takes about 3-7 minutes to run:

     Id: 97
   User: tom
   Host: 192.168.6.31:27059
     db: test
Command: Query
   Time: 155
  State: logging slow query
   Info: COMMIT

and my database is locked completely (very slow when connecting). The process Id 97 continues running after I try to kill it. The init script shows the [ FAILED ] flag when trying to restart MySQL, so I must use kill -9 and start again.

I will try to disable the unique_checks follow this guide. But I’m trying to find out why it’s locked.

There are some Waiting for table metadata lock states on temporary tables:

     Id: 180098
   User: jerry
   Host: 192.168.6.31:54909
     db: test
Command: Query
   Time: 142
  State: Waiting for table metadata lock
   Info: DROP TABLE IF EXISTS norep_locationtmp

and a Waiting for table level lock state:

     Id: 180233
   User: bob
   Host: 192.168.6.31:43537
     db: test
Command: Query
   Time: 65
  State: Waiting for table level lock
   Info: SELECT COUNT(DISTINCT A.`campaignid`)  INTO _c
FROM `ox_campaigns` A 
INNER JOIN `selfserving_users` B ON B.`user_id` = A.`uid`
INNER JOIN `v3_cam_date` C ON C.`campaignid` = A.`campaignid`
WHERE A.`revenue_type` = 5 AND A.`deleted` = 0 AND A.`expire` = DATE_ADD(CURRENT_DATE, INTERVAL 1 DAY) 
AND A.`isExpired` = 0 AND IF( NAME_CONST('_permitid',3) = -1, 1=1, IF( NAME_CONST('_permitid',3) = 0, A.`uid` IN (SELECT C.`user_id` FROM `selfserving_users` C WHERE C.`groupid` =  NAME_CONST('_groupid',12) ) ,A.`uid` =  NAME_CONST('userid',388)))

There isn’t anything related to the above table – v3_zone_date and no deadlock detected in SHOW ENGINE INNODB STATUS. Where should I take a look at first to troubleshoot this case? Let me know if you need any further information.

Reply to @RolandoMySQLDBA:

The scary part about the query is the self-reference

You have selfserving_users acting in a self serving manner against
itself.

I will ask the developer to rewrite it.

  • You are hammering the InnoDB Buffer
  • Some memory swapping may be going on

I have 40GB RAM and:

innodb_buffer_pool_size     = 20G
innodb_buffer_pool_instances    = 8

The memory graph exhibit that there is no increase.

Possible full table locking issues that are affecting data pages
outside the v3_zone_date table (such was with the selfserving_users
table)

Do you have any ideas to avoid the full table locking issue?

There may be a way to throttle the LOAD DATA INFILE process on an
InnoDB table. I cannot give you a solid answer on this one, but try
this link from Baron Schwartz.

I will trying the fifo method and let you know the result.

UPDATE: Wed Feb 22 12:19:03 ICT 2012

Below is snippet of the SHOW ENGINE INNODB STATUS output when hanging:

---TRANSACTION 1EF3CC26, ACTIVE (PREPARED) 332 sec
68 lock struct(s), heap size 14776, 6933 row lock(s), undo log entries 3465
MySQL thread id 4088, query id 11411947 192.168.6.31 bob
COMMIT
Trx read view will not see trx with id >= 1EF3CC27, sees < 1EF06C8E

Based on the thread id, I found out the culprit is a .NET process which is loading data into the database by following steps:

  • LOCK TABLES;
  • SET autocommit=0;
  • SET unique_checks=0;
  • SET foreign_key_checks=0;
  • LOAD DATA;
  • COMMIT;
  • UNLOCK TABLES;
  • SET unique_checks=1;
  • SET foreign_key_checks=1;

It seems that the insert processing hangs at COMMIT step, the table cannot be unlock and freezing my database. Should I swap the COMMIT and UNLOCK TABLES step?

According to the MySQL document:

Beginning with MySQL 5.5.5, it is no longer possible to set
@@session.sql_log_bin within a transaction or subquery. (Bug #53437)

As my understanding, 400K rows is not big enough, cannot find out why it locked my db?

Any ideas?

Answer :

The query under process ID 180233 looks like it is in distress.

Here is the query itself

SELECT COUNT(DISTINCT A.`campaignid`)  INTO _c
FROM `ox_campaigns` A 
INNER JOIN `selfserving_users` B ON B.`user_id` = A.`uid`
INNER JOIN `v3_cam_date` C ON C.`campaignid` = A.`campaignid`
WHERE A.`revenue_type` = 5 AND A.`deleted` = 0
AND A.`expire` = DATE_ADD(CURRENT_DATE, INTERVAL 1 DAY) 
AND A.`isExpired` = 0
AND IF( NAME_CONST('_permitid',3) = -1, 1=1,
IF( NAME_CONST('_permitid',3) = 0, A.`uid` IN
(SELECT C.`user_id` FROM `selfserving_users` C
WHERE C.`groupid` =  NAME_CONST('_groupid',12) ) ,
A.`uid` =  NAME_CONST('userid',388)));

The scary part about the query is the self-reference

You have selfserving_users acting in a self serving manner against itself.

Sometimes, the MySQL Query Optimizer will play a bait-and-switch, smoke-and-mirrors games with data, especially with a self reference, in order to formulate the best EXPLAIN plan possible. While mysql is very capable of completing sub-SELECTs, it can be still be expensive.

However, this is just a symptom that manifested because of Process ID 97. What is really the issue here?

LOAD DATA INFILE against an InnoDB table could make mysqld a little punch drunk. I don’t believe (or at least I don’t exercise full confidence) you can encapsulate it as a normal transaction although this was addressed back in MySQL 5.0.

Just picture it:

  • You are hammering the InnoDB Buffer
  • Some memory swapping may be going on
  • Possible full table locking issues that are affecting data pages outside the v3_zone_date table (such was with the selfserving_users table)

There may be a way to throttle the LOAD DATA INFILE process on an InnoDB table. I cannot give you a solid answer on this one, but try this link from Baron Schwartz.

UPDATE 2012-02-22 12:00 EST

There is open bug report in MySQL 5.5.7 called Deadlock when DDL under LOCK TABLES WRITE, READ + PREPARE. At the bottom of the report, a person complained about a block problem cause by the explicit LOCK TABLES.

Launching a COMMIT on locked rows in a table would hang because of trying to unraveling MVCC data assocaited with the locked rows. Based on the InnoDB Status you have shown, there would exist 6933 row locks on the table you are importing. I know that in Oracle, when introducing new rows to a table, MVCC is still generated because the previous version of the newly inserted row is a nonexistent row. The same must be occurring for InnoDB.

UPDATE 2012-02-22 12:42 EDT

In your question you stated the following about your .NET process

  • LOCK TABLES;
  • SET autocommit=0;
  • SET unique_checks=0;
  • SET foreign_key_checks=0;
  • LOAD DATA;
  • COMMIT;
  • UNLOCK TABLES;
  • SET autocommit=1;
  • SET unique_checks=1;

All of these events are running within the same DB Session. This is also happening within one DB Connection. Thus, this is not a deadlock in the traditional sense. It is just a case of blocking your COMMIT within a given DB Connection/Session because the tables were locked within the same DB Connection/Session.

UPDATE 2012-02-23 19:00 EDT

I would change the sequence to be this:

  • SET autocommit=0;
  • SET unique_checks=0;
  • SET foreign_key_checks=0;
  • LOCK TABLES;
  • LOAD DATA;
  • UNLOCK TABLES;
  • COMMIT;
  • SET autocommit=1;
  • SET unique_checks=1;
  • SET foreign_key_checks=1;

Please remember, a COMMIT cannot proceed if you have the tables locked in serial fashion. Therefore, UNLOCK TABLES must precede COMMIT.

First of all, I want to know about your tool of MySQL used by you either it is GUI or Command Line. As, there are lot of difference between booth the tools.

My system configuration is P4 with 3GB Ram and 500 GB of HDD. So, while using minimum or very less resources in comparison to your system availability. I have loaded a file of about 1GB containing about 2,258K Rows and tried to insert through both GUI and command line to my surprise the difference is very high. Through GUI time taken to insert is about 8-10 Mins and through Command line it takes only 1.45 Mins.

Why there is so, much differences is the working of both tools. GUI tool is dependent on the Memory available to it and the threads available are limited as it dependent on the OS which controls all the Memory of the system. The bytes transfers depend on the system Memory available and it would send the limited bytes to tool is many splits. So, if you have 40GB of RAM the maximum RAM available to tool would be around 2-3GB and the GUI first reads it then send the command and check the execution and then go for another set. But the bytes would remain in Memory until the execution is completed. Another reason is threads the maximum threads used by GUI in my case is 45 threads.

On the other hand in command line tool all the things are managed the the tool itself as it doesn’t have to depend on any system memory. It will start as many threads required by the process and the process will be done fast then GUI. In this case the maximum threads are used by tool is 90 threads.

Hope this information would greatly resolve you problem to..

Leave a Reply

Your email address will not be published. Required fields are marked *