10

A simple table creation on one of my MySQL databases takes forever:

mysql> CREATE TABLE blah (id BIGINT UNSIGNED NOT NULL PRIMARY KEY);
Query OK, 0 rows affected (16.58 sec)

The machine is quite idle:

01:21:26 PM       CPU     %user     %nice   %system   %iowait    %steal     %idle
01:21:27 PM       all      0.50      0.00      0.21      0.00      0.00     99.29

Any ideas how to investigate this?

EDIT: Following DTest's advice, this is the execution profile:

mysql> SHOW PROFILE FOR QUERY 1;
+----------------------+----------+
| Status               | Duration |
+----------------------+----------+
| starting             | 0.000044 |
| checking permissions | 0.000024 |
| creating table       | 8.668129 |
| After create         | 0.000014 |
| query end            | 0.000005 |
| freeing items        | 0.000028 |
| logging slow query   | 0.000004 |
| logging slow query   | 0.000206 |
| cleaning up          | 0.000006 |
+----------------------+----------+
  • @Phil A physical machine with some 16GB of memory. – Adam Matan Oct 29 '12 at 13:42
  • @Phil It's a production server with many MySQL operations, so the disk shouldn't be idle. – Adam Matan Oct 29 '12 at 13:54
10

I would turn on profiling to get an idea of what takes so long. An example using mysql's CLI:

SET profiling = 1;
CREATE TABLE blah (id BIGINT UNSIGNED NOT NULL PRIMARY KEY);
SET profiling = 1;

You should get a response something like this:

mysql> SHOW PROFILES;
| Query_ID | Duration   | Query |
+----------+------------+-------------------------------------------------------------+
|        1 | 0.00913800 | CREATE TABLE blah (id BIGINT UNSIGNED NOT NULL PRIMARY KEY) |
+----------+------------+-------------------------------------------------------------+
1 row in set (0.00 sec)

mysql> SHOW PROFILE FOR QUERY 1;
+----------------------+----------+
| Status               | Duration |
+----------------------+----------+
| starting             | 0.000071 |
| checking permissions | 0.000007 |
| Opening tables       | 0.001698 |
| System lock          | 0.000043 |
| creating table       | 0.007260 |
| After create         | 0.000004 |
| query end            | 0.000004 |
| closing tables       | 0.000015 |
| freeing items        | 0.000031 |
| logging slow query   | 0.000002 |
| cleaning up          | 0.000003 |
+----------------------+----------+
11 rows in set (0.00 sec)
  • 1
    @AdamMatan not sure if you read the profiling documentation, but there are other flags for showing profile of the query CPU, BLOCK IO etc that might help you on the 'creating table' stage. – Derek Downey Oct 29 '12 at 15:05

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.