查看mysql正在执行的SQL语句，使用profile分析SQL执行状态

http://qq85609655.iteye.com/blog/2113960

 

1)我们先通过status命令查看Mysql运行状态

mysql> status;

--------------

mysql Ver 14.14 Distrib 5.1.73, for redhat-linux-gnu (x86_64) using readline 5.1

Connection id: 113752

Current database: information_schema

Current user: push_user@localhost

SSL: Not in use

Current pager: stdout

Using outfile: ''

Using delimiter: ;

Server version: 5.1.73 Source distribution

Protocol version: 10

Connection: Localhost via UNIX socket

Server characterset: latin1

Db characterset: utf8

Client characterset: latin1

Conn. characterset: latin1

UNIX socket: /tmp/mysql.sock

Uptime: 22 days 8 hours 31 min 23 sec

Threads: 38 Questions: 1037751897 Slow queries: 2356 Opens: 79836 Flush tables: 1 Open tables: 64 Queries per second avg: 537.282

--------------

在上面显示列表的最后一条，我们来查看Slow queries这一项的值，如果多次查看的值大于0的话,说明有些查询sql命令执行时间过长。

2)这时再通过show processlist命令来查看当前正在运行的SQL，从中找出运行慢的SQL语句，找到执行慢的语句后，再用explain命令查看这些语句的执行计划。

mysql> show processlist;

+--------+-----------+---------------------+--------------------+---------+-------+-------+------------------+

| Id | User | Host | db | Command | Time | State | Info |

+--------+-----------+---------------------+--------------------+---------+-------+-------+------------------+

| 50270 | ambari | DataBase-01:41512 | ambari | Sleep | 23 | | NULL |

| 50271 | ambari | DataBase-01:41511 | ambari | Sleep | 6 | | NULL |

| 50272 | ambari | DataBase-01:41514 | ambari | Sleep | 23 | | NULL |

| 62452 | oozie | DataBase-02:42987 | oozie | Sleep | 25 | | NULL |

| 63660 | ambari | DataBase-01:56052 | ambari | Sleep | 0 | | NULL |

| 110404 | push_user | localhost:33817 | quartz | Sleep | 12 | | NULL |

| 112835 | push_user | localhost:46571 | hibernate | Sleep | 1 | | NULL |

| 113163 | push_user | localhost:56585 | hibernate | Sleep | 1 | | NULL |

| 113289 | push_user | 14.118.132.20:47333 | DW | Sleep | 628 | | NULL |

| 113320 | push_user | localhost:47428 | hibernate | Sleep | 3 | | NULL |

| 113321 | push_user | localhost:47429 | hibernate | Sleep | 3 | | NULL |

| 113322 | push_user | localhost:47430 | hibernate | Sleep | 3 | | NULL |

| 113357 | push_user | localhost:52337 | hibernate | Sleep | 3 | | NULL |

| 113364 | push_user | localhost:57206 | hibernate | Sleep | 3 | | NULL |

| 113366 | push_user | localhost:34813 | hibernate | Sleep | 1 | | NULL |

| 113398 | push_user | localhost:37382 | hibernate | Sleep | 1 | | NULL |

| 113498 | push_user | localhost:47626 | quartz | Sleep | 12717 | | NULL |

| 113709 | push_user | localhost:59382 | hibernate | Sleep | 1 | | NULL |

| 113710 | push_user | localhost:33627 | hibernate | Sleep | 1 | | NULL |

| 113715 | hive | DataBase-02:54968 | hive | Sleep | 2390 | | NULL |

| 113716 | hive | DataBase-02:54969 | hive | Sleep | 2390 | | NULL |

| 113717 | hive | DataBase-02:54974 | hive | Sleep | 2336 | | NULL |

| 113718 | hive | DataBase-02:54975 | hive | Sleep | 2336 | | NULL |

| 113719 | push_user | localhost:48243 | hibernate | Sleep | 1 | | NULL |

| 113720 | push_user | localhost:48245 | hibernate | Sleep | 1 | | NULL |

| 113721 | push_user | localhost:48244 | hibernate | Sleep | 1 | | NULL |

| 113722 | push_user | localhost:48247 | hibernate | Sleep | 1 | | NULL |

| 113723 | push_user | localhost:48249 | hibernate | Sleep | 1 | | NULL |

| 113724 | push_user | localhost:48248 | hibernate | Sleep | 1 | | NULL |

| 113745 | push_user | localhost:50684 | hibernate | Sleep | 1 | | NULL |

| 113746 | push_user | localhost:50685 | hibernate | Sleep | 1 | | NULL |

| 113747 | push_user | localhost:50695 | hibernate | Sleep | 1 | | NULL |

| 113748 | push_user | localhost:50696 | hibernate | Sleep | 1 | | NULL |

| 113749 | push_user | localhost:50697 | hibernate | Sleep | 1 | | NULL |

| 113750 | push_user | localhost:50699 | hibernate | Sleep | 1 | | NULL |

| 113751 | push_user | localhost:50700 | hibernate | Sleep | 1 | | NULL |

| 113752 | push_user | localhost | information_schema | Query | 0 | NULL | show processlist |

| 113753 | push_user | 14.118.132.20:28688 | DW | Sleep | 396 | | NULL |

+--------+-----------+---------------------+--------------------+---------+-------+-------+------------------+

38 rows in set (0.00 sec)

或者通过如下命令查询:

mysql> use information_schema;

mysql> select * from PROCESSLIST where info is not null;

+--------+-----------+-----------+--------------------+---------+------+-----------+--------------------------------------------------+

| ID | USER | HOST | DB | COMMAND | TIME | STATE | INFO |

+--------+-----------+-----------+--------------------+---------+------+-----------+--------------------------------------------------+

| 113752 | push_user | localhost | information_schema | Query | 0 | executing | select * from PROCESSLIST where info is not null |

+--------+-----------+-----------+--------------------+---------+------+-----------+--------------------------------------------------+

1 row in set (0.00 sec)

 

 

MySQL使用profile分析SQL执行状态

打开profile

  1. mysql> select @@have_profiling;
  2. +------------------+
  3. | @@have_profiling |
  4. +------------------+
  5. | YES |
  6. +------------------+
  7. 1 row in set (0.00 sec)
  9. mysql> select @@profiling;
  10. +-------------+
  11. | @@profiling |
  12. +-------------+
  13. | 0 |
  14. +-------------+
  15. 1 row in set (0.00 sec)
  17. mysql> set session profiling=1;
  18. Query OK, 0 rows affected (0.00 sec)
  20. mysql> select @@profiling;
  21. +-------------+
  22. | @@profiling |
  23. +-------------+
  24. | 1 |
  25. +-------------+
  26. 1 row in set (0.00 sec)
[plain] view plain copy
 print?
  1. mysql> select @@have_profiling;  
  2. +------------------+  
  3. | @@have_profiling |  
  4. +------------------+  
  5. | YES              |  
  6. +------------------+  
  7. 1 row in set (0.00 sec)  
  8.   
  9. mysql> select @@profiling;  
  10. +-------------+  
  11. | @@profiling |  
  12. +-------------+  
  13. |           0 |  
  14. +-------------+  
  15. 1 row in set (0.00 sec)  
  16.   
  17. mysql> set session profiling=1;  
  18. Query OK, 0 rows affected (0.00 sec)  
  19.   
  20. mysql> select @@profiling;  
  21. +-------------+  
  22. | @@profiling |  
  23. +-------------+  
  24. |           1 |  
  25. +-------------+  
  26. 1 row in set (0.00 sec)  


使用profile分析SQL，可以看到执行两次后,Send data和sending cached result to clien执行效率的变化

 

  1. mysql> select count(*) from sakila.payment;
  2. +----------+
  3. | count(*) |
  4. +----------+
  5. | 16049 |
  6. +----------+
  7. 1 row in set (0.03 sec)
  9. mysql> show profiles;
  10. +----------+------------+-------------------------------------+
  11. | Query_ID | Duration | Query |
  12. +----------+------------+-------------------------------------+
  13. | 1 | 0.00020400 | select @@profiling |
  14. | 2 | 0.00008900 | select count(*) from payment |
  15. | 3 | 0.00006800 | show databaes |
  16. | 4 | 0.02102800 | show databases |
  17. | 5 | 0.02847600 | select count(*) from sakila.payment |
  18. +----------+------------+-------------------------------------+
  19. 5 rows in set (0.00 sec)
[plain] view plain copy
 print?
  1. mysql> select count(*) from sakila.payment;  
  2. +----------+  
  3. | count(*) |  
  4. +----------+  
  5. |    16049 |  
  6. +----------+  
  7. 1 row in set (0.03 sec)  
  8.   
  9. mysql> show profiles;  
  10. +----------+------------+-------------------------------------+  
  11. | Query_ID | Duration   | Query                               |  
  12. +----------+------------+-------------------------------------+  
  13. |        1 | 0.00020400 | select @@profiling                  |  
  14. |        2 | 0.00008900 | select count(*) from payment        |  
  15. |        3 | 0.00006800 | show databaes                       |  
  16. |        4 | 0.02102800 | show databases                      |  
  17. |        5 | 0.02847600 | select count(*) from sakila.payment |  
  18. +----------+------------+-------------------------------------+  
  19. 5 rows in set (0.00 sec)  

 
  1. mysql> show profile for query 5;
  2. +--------------------------------+----------+
  3. | Status | Duration |
  4. +--------------------------------+----------+
  5. | starting | 0.000030 |
  6. | Waiting for query cache lock | 0.000005 |
  7. | checking query cache for query | 0.000043 |
  8. | checking permissions | 0.000007 |
  9. | Opening tables | 0.000027 |
  10. | System lock | 0.000010 |
  11. | Waiting for query cache lock | 0.000010 |
  12. | init | 0.000000 |
  13. | optimizing | 0.023255 |
  14. | statistics | 0.000118 |
  15. | preparing | 0.000041 |
  16. | executing | 0.000033 |
  17. | Sending data | 0.003833 |
  18. | end | 0.000054 |
  19. | query end | 0.000045 |
  20. | closing tables | 0.000045 |
  21. | freeing items | 0.000072 |
  22. | Waiting for query cache lock | 0.000033 |
  23. | freeing items | 0.000785 |
  24. | Waiting for query cache lock | 0.000016 |
  25. | freeing items | 0.000002 |
  26. | storing result in query cache | 0.000005 |
  27. | logging slow query | 0.000003 |
  28. | cleaning up | 0.000004 |
  29. +--------------------------------+----------+
  30. 24 rows in set (0.00 sec)
  32. mysql> select count(*) from sakila.payment;
  33. +----------+
  34. | count(*) |
  35. +----------+
  36. | 16049 |
  37. +----------+
  38. 1 row in set (0.00 sec)
  40. mysql> show profiles;
  41. +----------+------------+-------------------------------------+
  42. | Query_ID | Duration | Query |
  43. +----------+------------+-------------------------------------+
  44. | 1 | 0.00020400 | select @@profiling |
  45. | 2 | 0.00008900 | select count(*) from payment |
  46. | 3 | 0.00006800 | show databaes |
  47. | 4 | 0.02102800 | show databases |
  48. | 5 | 0.02847600 | select count(*) from sakila.payment |
  49. | 6 | 0.00006900 | select count(*) from sakila.payment |
  50. +----------+------------+-------------------------------------+
  51. 6 rows in set (0.00 sec)
  53. mysql> show profile for query 6;
  54. +--------------------------------+----------+
  55. | Status | Duration |
  56. +--------------------------------+----------+
  57. | starting | 0.000029 |
  58. | Waiting for query cache lock | 0.000004 |
  59. | checking query cache for query | 0.000007 |
  60. | checking privileges on cached | 0.000004 |
  61. | checking permissions | 0.000008 |
  62. | sending cached result to clien | 0.000012 |
  63. | logging slow query | 0.000002 |
  64. | cleaning up | 0.000003 |
  65. +--------------------------------+----------+
  66. 8 rows in set (0.00 sec)
[plain] view plain copy
 print?
  1. mysql> show profile for query 5;  
  2. +--------------------------------+----------+  
  3. | Status                         | Duration |  
  4. +--------------------------------+----------+  
  5. | starting                       | 0.000030 |  
  6. | Waiting for query cache lock   | 0.000005 |  
  7. | checking query cache for query | 0.000043 |  
  8. | checking permissions           | 0.000007 |  
  9. | Opening tables                 | 0.000027 |  
  10. | System lock                    | 0.000010 |  
  11. | Waiting for query cache lock   | 0.000010 |  
  12. | init                           | 0.000000 |  
  13. | optimizing                     | 0.023255 |  
  14. | statistics                     | 0.000118 |  
  15. | preparing                      | 0.000041 |  
  16. | executing                      | 0.000033 |  
  17. | Sending data                   | 0.003833 |  
  18. | end                            | 0.000054 |  
  19. | query end                      | 0.000045 |  
  20. | closing tables                 | 0.000045 |  
  21. | freeing items                  | 0.000072 |  
  22. | Waiting for query cache lock   | 0.000033 |  
  23. | freeing items                  | 0.000785 |  
  24. | Waiting for query cache lock   | 0.000016 |  
  25. | freeing items                  | 0.000002 |  
  26. | storing result in query cache  | 0.000005 |  
  27. | logging slow query             | 0.000003 |  
  28. | cleaning up                    | 0.000004 |  
  29. +--------------------------------+----------+  
  30. 24 rows in set (0.00 sec)  
  31.   
  32. mysql> select count(*) from sakila.payment;  
  33. +----------+  
  34. | count(*) |  
  35. +----------+  
  36. |    16049 |  
  37. +----------+  
  38. 1 row in set (0.00 sec)  
  39.   
  40. mysql> show profiles;  
  41. +----------+------------+-------------------------------------+  
  42. | Query_ID | Duration   | Query                               |  
  43. +----------+------------+-------------------------------------+  
  44. |        1 | 0.00020400 | select @@profiling                  |  
  45. |        2 | 0.00008900 | select count(*) from payment        |  
  46. |        3 | 0.00006800 | show databaes                       |  
  47. |        4 | 0.02102800 | show databases                      |  
  48. |        5 | 0.02847600 | select count(*) from sakila.payment |  
  49. |        6 | 0.00006900 | select count(*) from sakila.payment |  
  50. +----------+------------+-------------------------------------+  
  51. 6 rows in set (0.00 sec)  
  52.   
  53. mysql> show profile for query 6;  
  54. +--------------------------------+----------+  
  55. | Status                         | Duration |  
  56. +--------------------------------+----------+  
  57. | starting                       | 0.000029 |  
  58. | Waiting for query cache lock   | 0.000004 |  
  59. | checking query cache for query | 0.000007 |  
  60. | checking privileges on cached  | 0.000004 |  
  61. | checking permissions           | 0.000008 |  
  62. | sending cached result to clien | 0.000012 |  
  63. | logging slow query             | 0.000002 |  
  64. | cleaning up                    | 0.000003 |  
  65. +--------------------------------+----------+  
  66. 8 rows in set (0.00 sec)  


sending data比较耗费cpu

 

  1. mysql> select min(seq) seq,state,count(*) numb_ops,
  2. -> round(sum(duration),5) sum_dur, round(avg(duration),5) avg_dur,
  3. -> round(sum(cpu_user),5) sum_cpu, round(avg(cpu_user),5) avg_cpu
  4. -> from information_schema.profiling
  5. -> where query_id = 5
  6. -> group by state
  7. -> order by seq;
  8. +------+--------------------------------+----------+---------+---------+---------+---------+
  9. | seq | state | numb_ops | sum_dur | avg_dur | sum_cpu | avg_cpu |
  10. +------+--------------------------------+----------+---------+---------+---------+---------+
  11. | 2 | starting | 1 | 0.00003 | 0.00003 | 0.00000 | 0.00000 |
  12. | 3 | Waiting for query cache lock | 4 | 0.00006 | 0.00002 | 0.00100 | 0.00025 |
  13. | 4 | checking query cache for query | 1 | 0.00004 | 0.00004 | 0.00000 | 0.00000 |
  14. | 5 | checking permissions | 1 | 0.00001 | 0.00001 | 0.00000 | 0.00000 |
  15. | 6 | Opening tables | 1 | 0.00003 | 0.00003 | 0.00000 | 0.00000 |
  16. | 7 | System lock | 1 | 0.00001 | 0.00001 | 0.00000 | 0.00000 |
  17. | 9 | init | 1 | 0.00000 | 0.00000 | 0.00000 | 0.00000 |
  18. | 10 | optimizing | 1 | 0.02326 | 0.02326 | 0.00000 | 0.00000 |
  19. | 11 | statistics | 1 | 0.00012 | 0.00012 | 0.00000 | 0.00000 |
  20. | 12 | preparing | 1 | 0.00004 | 0.00004 | 0.00000 | 0.00000 |
  21. | 13 | executing | 1 | 0.00003 | 0.00003 | 0.00000 | 0.00000 |
  22. | 14 | Sending data | 1 | 0.00383 | 0.00383 | 0.00300 | 0.00300 |
  23. | 15 | end | 1 | 0.00005 | 0.00005 | 0.00000 | 0.00000 |
  24. | 16 | query end | 1 | 0.00005 | 0.00005 | 0.00000 | 0.00000 |
  25. | 17 | closing tables | 1 | 0.00005 | 0.00005 | 0.00000 | 0.00000 |
  26. | 18 | freeing items | 3 | 0.00086 | 0.00029 | 0.00000 | 0.00000 |
  27. | 23 | storing result in query cache | 1 | 0.00001 | 0.00001 | 0.00000 | 0.00000 |
  28. | 24 | logging slow query | 1 | 0.00000 | 0.00000 | 0.00000 | 0.00000 |
  29. | 25 | cleaning up | 1 | 0.00000 | 0.00000 | 0.00000 | 0.00000 |
  30. +------+--------------------------------+----------+---------+---------+---------+---------+
  31. 19 rows in set (0.00 sec)
  33. mysql> show profile cpu for query 5;
  34. +--------------------------------+----------+----------+------------+
  35. | Status | Duration | CPU_user | CPU_system |
  36. +--------------------------------+----------+----------+------------+
  37. | starting | 0.000030 | 0.000000 | 0.000000 |
  38. | Waiting for query cache lock | 0.000005 | 0.000000 | 0.000000 |
  39. | checking query cache for query | 0.000043 | 0.000000 | 0.000000 |
  40. | checking permissions | 0.000007 | 0.000000 | 0.000000 |
  41. | Opening tables | 0.000027 | 0.000000 | 0.000000 |
  42. | System lock | 0.000010 | 0.000000 | 0.000000 |
  43. | Waiting for query cache lock | 0.000010 | 0.001000 | 0.000000 |
  44. | init | 0.000000 | 0.000000 | 0.000000 |
  45. | optimizing | 0.023255 | 0.000000 | 0.000000 |
  46. | statistics | 0.000118 | 0.000000 | 0.000000 |
  47. | preparing | 0.000041 | 0.000000 | 0.000000 |
  48. | executing | 0.000033 | 0.000000 | 0.000000 |
  49. | Sending data | 0.003833 | 0.002999 | 0.001000 |
  50. | end | 0.000054 | 0.000000 | 0.000000 |
  51. | query end | 0.000045 | 0.000000 | 0.000000 |
  52. | closing tables | 0.000045 | 0.000000 | 0.000000 |
  53. | freeing items | 0.000072 | 0.000000 | 0.000000 |
  54. | Waiting for query cache lock | 0.000033 | 0.000000 | 0.000000 |
  55. | freeing items | 0.000785 | 0.000000 | 0.000000 |
  56. | Waiting for query cache lock | 0.000016 | 0.000000 | 0.000000 |
  57. | freeing items | 0.000002 | 0.000000 | 0.000000 |
  58. | storing result in query cache | 0.000005 | 0.000000 | 0.000000 |
  59. | logging slow query | 0.000003 | 0.000000 | 0.000000 |
  60. | cleaning up | 0.000004 | 0.000000 | 0.000000 |
  61. +--------------------------------+----------+----------+------------+
  62. 24 rows in set (0.00 sec)
  64. mysql> show profile block io for query 5;
  65. +--------------------------------+----------+--------------+---------------+
  66. | Status | Duration | Block_ops_in | Block_ops_out |
  67. +--------------------------------+----------+--------------+---------------+
  68. | starting | 0.000030 | 0 | 0 |
  69. | Waiting for query cache lock | 0.000005 | 0 | 0 |
  70. | checking query cache for query | 0.000043 | 0 | 0 |
  71. | checking permissions | 0.000007 | 0 | 0 |
  72. | Opening tables | 0.000027 | 0 | 0 |
  73. | System lock | 0.000010 | 0 | 0 |
  74. | Waiting for query cache lock | 0.000010 | 0 | 0 |
  75. | init | 0.000000 | 0 | 0 |
  76. | optimizing | 0.023255 | 0 | 0 |
  77. | statistics | 0.000118 | 0 | 0 |
  78. | preparing | 0.000041 | 0 | 0 |
  79. | executing | 0.000033 | 0 | 0 |
  80. | Sending data | 0.003833 | 0 | 0 |
  81. | end | 0.000054 | 0 | 0 |
  82. | query end | 0.000045 | 0 | 0 |
  83. | closing tables | 0.000045 | 0 | 0 |
  84. | freeing items | 0.000072 | 0 | 0 |
  85. | Waiting for query cache lock | 0.000033 | 0 | 0 |
  86. | freeing items | 0.000785 | 0 | 0 |
  87. | Waiting for query cache lock | 0.000016 | 0 | 0 |
  88. | freeing items | 0.000002 | 0 | 0 |
  89. | storing result in query cache | 0.000005 | 0 | 0 |
  90. | logging slow query | 0.000003 | 0 | 0 |
  91. | cleaning up | 0.000004 | 0 | 0 |
  92. +--------------------------------+----------+--------------+---------------+
  93. 24 rows in set (0.00 sec)
[plain] view plain copy
 print?
  1. mysql> select min(seq) seq,state,count(*) numb_ops,  
  2.     ->     round(sum(duration),5) sum_dur, round(avg(duration),5) avg_dur,  
  3.     ->     round(sum(cpu_user),5) sum_cpu, round(avg(cpu_user),5) avg_cpu  
  4.     ->     from information_schema.profiling  
  5.     ->     where query_id = 5  
  6.     ->     group by state  
  7.     ->     order by seq;  
  8. +------+--------------------------------+----------+---------+---------+---------+---------+  
  9. | seq  | state                          | numb_ops | sum_dur | avg_dur | sum_cpu | avg_cpu |  
  10. +------+--------------------------------+----------+---------+---------+---------+---------+  
  11. |    2 | starting                       |        1 | 0.00003 | 0.00003 | 0.00000 | 0.00000 |  
  12. |    3 | Waiting for query cache lock   |        4 | 0.00006 | 0.00002 | 0.00100 | 0.00025 |  
  13. |    4 | checking query cache for query |        1 | 0.00004 | 0.00004 | 0.00000 | 0.00000 |  
  14. |    5 | checking permissions           |        1 | 0.00001 | 0.00001 | 0.00000 | 0.00000 |  
  15. |    6 | Opening tables                 |        1 | 0.00003 | 0.00003 | 0.00000 | 0.00000 |  
  16. |    7 | System lock                    |        1 | 0.00001 | 0.00001 | 0.00000 | 0.00000 |  
  17. |    9 | init                           |        1 | 0.00000 | 0.00000 | 0.00000 | 0.00000 |  
  18. |   10 | optimizing                     |        1 | 0.02326 | 0.02326 | 0.00000 | 0.00000 |  
  19. |   11 | statistics                     |        1 | 0.00012 | 0.00012 | 0.00000 | 0.00000 |  
  20. |   12 | preparing                      |        1 | 0.00004 | 0.00004 | 0.00000 | 0.00000 |  
  21. |   13 | executing                      |        1 | 0.00003 | 0.00003 | 0.00000 | 0.00000 |  
  22. |   14 | Sending data                   |        1 | 0.00383 | 0.00383 | 0.00300 | 0.00300 |  
  23. |   15 | end                            |        1 | 0.00005 | 0.00005 | 0.00000 | 0.00000 |  
  24. |   16 | query end                      |        1 | 0.00005 | 0.00005 | 0.00000 | 0.00000 |  
  25. |   17 | closing tables                 |        1 | 0.00005 | 0.00005 | 0.00000 | 0.00000 |  
  26. |   18 | freeing items                  |        3 | 0.00086 | 0.00029 | 0.00000 | 0.00000 |  
  27. |   23 | storing result in query cache  |        1 | 0.00001 | 0.00001 | 0.00000 | 0.00000 |  
  28. |   24 | logging slow query             |        1 | 0.00000 | 0.00000 | 0.00000 | 0.00000 |  
  29. |   25 | cleaning up                    |        1 | 0.00000 | 0.00000 | 0.00000 | 0.00000 |  
  30. +------+--------------------------------+----------+---------+---------+---------+---------+  
  31. 19 rows in set (0.00 sec)  
  32.   
  33. mysql> show profile cpu for query 5;  
  34. +--------------------------------+----------+----------+------------+  
  35. | Status                         | Duration | CPU_user | CPU_system |  
  36. +--------------------------------+----------+----------+------------+  
  37. | starting                       | 0.000030 | 0.000000 |   0.000000 |  
  38. | Waiting for query cache lock   | 0.000005 | 0.000000 |   0.000000 |  
  39. | checking query cache for query | 0.000043 | 0.000000 |   0.000000 |  
  40. | checking permissions           | 0.000007 | 0.000000 |   0.000000 |  
  41. | Opening tables                 | 0.000027 | 0.000000 |   0.000000 |  
  42. | System lock                    | 0.000010 | 0.000000 |   0.000000 |  
  43. | Waiting for query cache lock   | 0.000010 | 0.001000 |   0.000000 |  
  44. | init                           | 0.000000 | 0.000000 |   0.000000 |  
  45. | optimizing                     | 0.023255 | 0.000000 |   0.000000 |  
  46. | statistics                     | 0.000118 | 0.000000 |   0.000000 |  
  47. | preparing                      | 0.000041 | 0.000000 |   0.000000 |  
  48. | executing                      | 0.000033 | 0.000000 |   0.000000 |  
  49. | Sending data                   | 0.003833 | 0.002999 |   0.001000 |  
  50. | end                            | 0.000054 | 0.000000 |   0.000000 |  
  51. | query end                      | 0.000045 | 0.000000 |   0.000000 |  
  52. | closing tables                 | 0.000045 | 0.000000 |   0.000000 |  
  53. | freeing items                  | 0.000072 | 0.000000 |   0.000000 |  
  54. | Waiting for query cache lock   | 0.000033 | 0.000000 |   0.000000 |  
  55. | freeing items                  | 0.000785 | 0.000000 |   0.000000 |  
  56. | Waiting for query cache lock   | 0.000016 | 0.000000 |   0.000000 |  
  57. | freeing items                  | 0.000002 | 0.000000 |   0.000000 |  
  58. | storing result in query cache  | 0.000005 | 0.000000 |   0.000000 |  
  59. | logging slow query             | 0.000003 | 0.000000 |   0.000000 |  
  60. | cleaning up                    | 0.000004 | 0.000000 |   0.000000 |  
  61. +--------------------------------+----------+----------+------------+  
  62. 24 rows in set (0.00 sec)  
  63.   
  64. mysql> show profile block io for query 5;  
  65. +--------------------------------+----------+--------------+---------------+  
  66. | Status                         | Duration | Block_ops_in | Block_ops_out |  
  67. +--------------------------------+----------+--------------+---------------+  
  68. | starting                       | 0.000030 |            0 |             0 |  
  69. | Waiting for query cache lock   | 0.000005 |            0 |             0 |  
  70. | checking query cache for query | 0.000043 |            0 |             0 |  
  71. | checking permissions           | 0.000007 |            0 |             0 |  
  72. | Opening tables                 | 0.000027 |            0 |             0 |  
  73. | System lock                    | 0.000010 |            0 |             0 |  
  74. | Waiting for query cache lock   | 0.000010 |            0 |             0 |  
  75. | init                           | 0.000000 |            0 |             0 |  
  76. | optimizing                     | 0.023255 |            0 |             0 |  
  77. | statistics                     | 0.000118 |            0 |             0 |  
  78. | preparing                      | 0.000041 |            0 |             0 |  
  79. | executing                      | 0.000033 |            0 |             0 |  
  80. | Sending data                   | 0.003833 |            0 |             0 |  
  81. | end                            | 0.000054 |            0 |             0 |  
  82. | query end                      | 0.000045 |            0 |             0 |  
  83. | closing tables                 | 0.000045 |            0 |             0 |  
  84. | freeing items                  | 0.000072 |            0 |             0 |  
  85. | Waiting for query cache lock   | 0.000033 |            0 |             0 |  
  86. | freeing items                  | 0.000785 |            0 |             0 |  
  87. | Waiting for query cache lock   | 0.000016 |            0 |             0 |  
  88. | freeing items                  | 0.000002 |            0 |             0 |  
  89. | storing result in query cache  | 0.000005 |            0 |             0 |  
  90. | logging slow query             | 0.000003 |            0 |             0 |  
  91. | cleaning up                    | 0.000004 |            0 |             0 |  
  92. +--------------------------------+----------+--------------+---------------+  
  93. 24 rows in set (0.00 sec)  


再看同结构数据的MyISAM表

 

  1. mysql> create table payment_myisam like payment;
  2. Query OK, 0 rows affected (0.03 sec)
  4. mysql> alter table payment_myisam engine=myisam;
  5. Query OK, 0 rows affected (0.03 sec)
  6. Records: 0 Duplicates: 0 Warnings: 0
  8. mysql> show create table payment_myisam\G
  9. *************************** 1. row ***************************
  10. Table: payment_myisam
  11. Create Table: CREATE TABLE `payment_myisam` (
  12. `payment_id` smallint(5) unsigned NOT NULL AUTO_INCREMENT,
  13. `customer_id` smallint(5) unsigned NOT NULL,
  14. `staff_id` tinyint(3) unsigned NOT NULL,
  15. `rental_id` int(11) DEFAULT NULL,
  16. `amount` decimal(5,2) NOT NULL,
  17. `payment_date` datetime NOT NULL,
  18. `last_update` timestamp NOT NULL DEFAULT CURRENT_TIMESTAMP ON UPDATE CURRENT_TIMESTAMP,
  19. PRIMARY KEY (`payment_id`),
  20. KEY `idx_fk_staff_id` (`staff_id`),
  21. KEY `idx_fk_customer_id` (`customer_id`),
  22. KEY `fk_payment_rental` (`rental_id`)
  23. ) ENGINE=MyISAM DEFAULT CHARSET=utf8
  24. 1 row in set (0.00 sec)
  26. mysql> insert into payment_myisam select * from payment;
  27. Query OK, 16049 rows affected (0.10 sec)
  28. Records: 16049 Duplicates: 0 Warnings: 0
[plain] view plain copy
 print?
  1. mysql> create table payment_myisam like payment;  
  2. Query OK, 0 rows affected (0.03 sec)  
  3.   
  4. mysql> alter table payment_myisam engine=myisam;  
  5. Query OK, 0 rows affected (0.03 sec)  
  6. Records: 0  Duplicates: 0  Warnings: 0  
  7.   
  8. mysql> show create table payment_myisam\G  
  9. *************************** 1. row ***************************  
  10.        Table: payment_myisam  
  11. Create Table: CREATE TABLE `payment_myisam` (  
  12.   `payment_id` smallint(5) unsigned NOT NULL AUTO_INCREMENT,  
  13.   `customer_id` smallint(5) unsigned NOT NULL,  
  14.   `staff_id` tinyint(3) unsigned NOT NULL,  
  15.   `rental_id` int(11) DEFAULT NULL,  
  16.   `amount` decimal(5,2) NOT NULL,  
  17.   `payment_date` datetime NOT NULL,  
  18.   `last_update` timestamp NOT NULL DEFAULT CURRENT_TIMESTAMP ON UPDATE CURRENT_TIMESTAMP,  
  19.   PRIMARY KEY (`payment_id`),  
  20.   KEY `idx_fk_staff_id` (`staff_id`),  
  21.   KEY `idx_fk_customer_id` (`customer_id`),  
  22.   KEY `fk_payment_rental` (`rental_id`)  
  23. ) ENGINE=MyISAM DEFAULT CHARSET=utf8  
  24. 1 row in set (0.00 sec)  
  25.   
  26. mysql> insert into payment_myisam select * from payment;  
  27. Query OK, 16049 rows affected (0.10 sec)  
  28. Records: 16049  Duplicates: 0  Warnings: 0  

 
  1. mysql> select count(*) from payment_myisam;
  2. +----------+
  3. | count(*) |
  4. +----------+
  5. | 16049 |
  6. +----------+
  7. 1 row in set (0.01 sec)
  9. mysql> show profiles;
  11. | 23 | 0.09449600 | insert into payment_myisam select * from payment |
  12. | 24 | 0.00023500 | select count(*) from payment_myisam |
  14. 15 rows in set (0.00 sec)
[plain] view plain copy
 print?
  1. mysql> select count(*) from payment_myisam;  
  2. +----------+  
  3. | count(*) |  
  4. +----------+  
  5. |    16049 |  
  6. +----------+  
  7. 1 row in set (0.01 sec)  
  8.   
  9. mysql> show profiles;  
  10.                                                                                                                                                                           
  11. |       23 | 0.09449600 | insert into payment_myisam select * from payment                                                                                                                                                                                                                                        |  
  12. |       24 | 0.00023500 | select count(*) from payment_myisam                                                                                                                                                                                                                                                     |  
  13.   
  14. 15 rows in set (0.00 sec)  

 
  1. mysql> show profile for query 24;
  2. +--------------------------------+----------+
  3. | Status | Duration |
  4. +--------------------------------+----------+
  5. | starting | 0.000026 |
  6. | Waiting for query cache lock | 0.000003 |
  7. | checking query cache for query | 0.000037 |
  8. | checking permissions | 0.000006 |
  9. | Opening tables | 0.000015 |
  10. | System lock | 0.000009 |
  11. | Waiting for query cache lock | 0.000019 |
  12. | init | 0.000011 |
  13. | optimizing | 0.000006 |
  14. | executing | 0.000006 |
  15. | end | 0.000000 |
  16. | query end | 0.000001 |
  17. | closing tables | 0.000008 |
  18. | freeing items | 0.000019 |
  19. | Waiting for query cache lock | 0.000008 |
  20. | freeing items | 0.000013 |
  21. | Waiting for query cache lock | 0.000008 |
  22. | freeing items | 0.000008 |
  23. | storing result in query cache | 0.000015 |
  24. | logging slow query | 0.000008 |
  25. | cleaning up | 0.000009 |
  26. +--------------------------------+----------+

 

posted @ 2018-06-22 17:30  星朝  阅读(755)  评论(0)  编辑  收藏  举报