What does 'system lock' mean in mysql profiling a LOAD DATA INFILE statement?

2M rows inserted using LOAD DATA INFILE to innodb takes 7.5min, and profiling shows 99% of that time is in "System lock".


Does this tell me anything useful?

mysql> set profiling=1;
   Query OK, 0 rows affected (0.00 sec)

   mysql> LOAD DATA CONCURRENT LOCAL INFILE '/tmp/item' REPLACE INTO TABLE item_load;
   Query OK, 1964807 rows affected, 8 warnings (7 min 27.35 sec)
   Records: 1964806  Deleted: 1  Skipped: 0  Warnings: 8

   mysql> show profile for query 1;
   +------------------------------+------------+
   | Status                       | Duration   |
   +------------------------------+------------+
   | starting                     |   0.000206 |
   | checking permissions         |   0.000015 |
   | Opening tables               |   0.000034 |
   | System lock                  | 447.327523 |
   | Waiting for query cache lock |   0.000352 |
   | query end                    |   0.000011 |
   | closing tables               |   0.000014 |
   | freeing items                |   0.000033 |
   | logging slow query           |   0.000007 |
   | logging slow query           |   0.000006 |
   | cleaning up                  |   0.000006 |
   +------------------------------+------------+
   11 rows in set (0.02 sec)

The mysql_load() function calls the open_and_lock_tables() function to lock the table mentioned in the LOAD DATA statement.

MySQL obtains an exclusive lock on the table so that it can very quickly load data into the table. There is very little overhead in the LOAD DATA process, just the bare minimum parsing is done to make it work.

The CONCURRENT option only affects MyISAM tables, if you are loading into an InnoDB table it does not permit concurrent access.

The reason why System lock took so long is that the actual data load was lumped into the timing for that step. The profiler works by measuring time between fenceposts, that is the entry time is logged for each instrumented user function. The mysql_lock_tables() function is called from inside mysql_load(), but mysql_load() is not instrumented, so the elapsed time starts at the system lock and ends at the next fencepost, which was the query cache lock.

Your data load of 1.96mn rows took about 447 seconds, there isn't any way to separate the actual lock time overhead from the loading time because the loading isn't instrumented.

StackExchange Database Administrators Q#31823, answer score: 10