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)
  8. mysql> select @@profiling;
  9. +-------------+
  10. | @@profiling |
  11. +-------------+
  12. | 0 |
  13. +-------------+
  14. 1 row in set (0.00 sec)
  15. mysql> set session profiling=1;
  16. Query OK, 0 rows affected (0.00 sec)
  17. mysql> select @@profiling;
  18. +-------------+
  19. | @@profiling |
  20. +-------------+
  21. | 1 |
  22. +-------------+
  23. 1 row in set (0.00 sec)
  1. mysql> select @@have_profiling;
  2. +------------------+
  3. | @@have_profiling |
  4. +------------------+
  5. | YES              |
  6. +------------------+
  7. 1 row in set (0.00 sec)
  8. mysql> select @@profiling;
  9. +-------------+
  10. | @@profiling |
  11. +-------------+
  12. |           0 |
  13. +-------------+
  14. 1 row in set (0.00 sec)
  15. mysql> set session profiling=1;
  16. Query OK, 0 rows affected (0.00 sec)
  17. mysql> select @@profiling;
  18. +-------------+
  19. | @@profiling |
  20. +-------------+
  21. |           1 |
  22. +-------------+
  23. 1 row in set (0.00 sec)
mysql> select @@have_profiling;

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

| @@have_profiling |

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

| YES              |

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

1 row in set (0.00 sec)

mysql> select @@profiling;


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


| @@profiling |


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


|           0 |


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


1 row in set (0.00 sec)

mysql> set session profiling=1;


Query OK, 0 rows affected (0.00 sec)

mysql> select @@profiling;


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


| @@profiling |


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


|           1 |


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


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

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

| count(*) |

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

|    16049 |

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

1 row in set (0.03 sec)

mysql> show profiles;


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


| Query_ID | Duration   | Query                               |


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


|        1 | 0.00020400 | select @@profiling                  |


|        2 | 0.00008900 | select count() from payment        |


|        3 | 0.00006800 | show databaes                       |


|        4 | 0.02102800 | show databases                      |


|        5 | 0.02847600 | select count() from sakila.payment |


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


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)
  31. mysql> select count(*) from sakila.payment;
  32. +----------+
  33. | count(*) |
  34. +----------+
  35. | 16049 |
  36. +----------+
  37. 1 row in set (0.00 sec)
  38. mysql> show profiles;
  39. +----------+------------+-------------------------------------+
  40. | Query_ID | Duration | Query |
  41. +----------+------------+-------------------------------------+
  42. | 1 | 0.00020400 | select @@profiling |
  43. | 2 | 0.00008900 | select count(*) from payment |
  44. | 3 | 0.00006800 | show databaes |
  45. | 4 | 0.02102800 | show databases |
  46. | 5 | 0.02847600 | select count(*) from sakila.payment |
  47. | 6 | 0.00006900 | select count(*) from sakila.payment |
  48. +----------+------------+-------------------------------------+
  49. 6 rows in set (0.00 sec)
  50. mysql> show profile for query 6;
  51. +--------------------------------+----------+
  52. | Status | Duration |
  53. +--------------------------------+----------+
  54. | starting | 0.000029 |
  55. | Waiting for query cache lock | 0.000004 |
  56. | checking query cache for query | 0.000007 |
  57. | checking privileges on cached | 0.000004 |
  58. | checking permissions | 0.000008 |
  59. | sending cached result to clien | 0.000012 |
  60. | logging slow query | 0.000002 |
  61. | cleaning up | 0.000003 |
  62. +--------------------------------+----------+
  63. 8 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)
  31. mysql> select count(*) from sakila.payment;
  32. +----------+
  33. | count(*) |
  34. +----------+
  35. |    16049 |
  36. +----------+
  37. 1 row in set (0.00 sec)
  38. mysql> show profiles;
  39. +----------+------------+-------------------------------------+
  40. | Query_ID | Duration   | Query                               |
  41. +----------+------------+-------------------------------------+
  42. |        1 | 0.00020400 | select @@profiling                  |
  43. |        2 | 0.00008900 | select count(*) from payment        |
  44. |        3 | 0.00006800 | show databaes                       |
  45. |        4 | 0.02102800 | show databases                      |
  46. |        5 | 0.02847600 | select count(*) from sakila.payment |
  47. |        6 | 0.00006900 | select count(*) from sakila.payment |
  48. +----------+------------+-------------------------------------+
  49. 6 rows in set (0.00 sec)
  50. mysql> show profile for query 6;
  51. +--------------------------------+----------+
  52. | Status                         | Duration |
  53. +--------------------------------+----------+
  54. | starting                       | 0.000029 |
  55. | Waiting for query cache lock   | 0.000004 |
  56. | checking query cache for query | 0.000007 |
  57. | checking privileges on cached  | 0.000004 |
  58. | checking permissions           | 0.000008 |
  59. | sending cached result to clien | 0.000012 |
  60. | logging slow query             | 0.000002 |
  61. | cleaning up                    | 0.000003 |
  62. +--------------------------------+----------+
  63. 8 rows in set (0.00 sec)
mysql> show profile for query 5;

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

| Status                         | Duration |

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

| starting                       | 0.000030 |

| Waiting for query cache lock   | 0.000005 |

| checking query cache for query | 0.000043 |

| checking permissions           | 0.000007 |

| Opening tables                 | 0.000027 |

| System lock                    | 0.000010 |

| Waiting for query cache lock   | 0.000010 |

| init                           | 0.000000 |

| optimizing                     | 0.023255 |

| statistics                     | 0.000118 |

| preparing                      | 0.000041 |

| executing                      | 0.000033 |

| Sending data                   | 0.003833 |

| end                            | 0.000054 |

| query end                      | 0.000045 |

| closing tables                 | 0.000045 |

| freeing items                  | 0.000072 |

| Waiting for query cache lock   | 0.000033 |

| freeing items                  | 0.000785 |

| Waiting for query cache lock   | 0.000016 |

| freeing items                  | 0.000002 |

| storing result in query cache  | 0.000005 |

| logging slow query             | 0.000003 |

| cleaning up                    | 0.000004 |

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

24 rows in set (0.00 sec)

mysql> select count() from sakila.payment;


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


| count() |


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


|    16049 |


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


1 row in set (0.00 sec)

mysql> show profiles;


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


| Query_ID | Duration   | Query                               |


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


|        1 | 0.00020400 | select @@profiling                  |


|        2 | 0.00008900 | select count() from payment        |


|        3 | 0.00006800 | show databaes                       |


|        4 | 0.02102800 | show databases                      |


|        5 | 0.02847600 | select count() from sakila.payment |


|        6 | 0.00006900 | select count(*) from sakila.payment |


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


6 rows in set (0.00 sec)

mysql> show profile for query 6;


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


| Status                         | Duration |


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


| starting                       | 0.000029 |


| Waiting for query cache lock   | 0.000004 |


| checking query cache for query | 0.000007 |


| checking privileges on cached  | 0.000004 |


| checking permissions           | 0.000008 |


| sending cached result to clien | 0.000012 |


| logging slow query             | 0.000002 |


| cleaning up                    | 0.000003 |


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


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)
  32. mysql> show profile cpu for query 5;
  33. +--------------------------------+----------+----------+------------+
  34. | Status | Duration | CPU_user | CPU_system |
  35. +--------------------------------+----------+----------+------------+
  36. | starting | 0.000030 | 0.000000 | 0.000000 |
  37. | Waiting for query cache lock | 0.000005 | 0.000000 | 0.000000 |
  38. | checking query cache for query | 0.000043 | 0.000000 | 0.000000 |
  39. | checking permissions | 0.000007 | 0.000000 | 0.000000 |
  40. | Opening tables | 0.000027 | 0.000000 | 0.000000 |
  41. | System lock | 0.000010 | 0.000000 | 0.000000 |
  42. | Waiting for query cache lock | 0.000010 | 0.001000 | 0.000000 |
  43. | init | 0.000000 | 0.000000 | 0.000000 |
  44. | optimizing | 0.023255 | 0.000000 | 0.000000 |
  45. | statistics | 0.000118 | 0.000000 | 0.000000 |
  46. | preparing | 0.000041 | 0.000000 | 0.000000 |
  47. | executing | 0.000033 | 0.000000 | 0.000000 |
  48. | Sending data | 0.003833 | 0.002999 | 0.001000 |
  49. | end | 0.000054 | 0.000000 | 0.000000 |
  50. | query end | 0.000045 | 0.000000 | 0.000000 |
  51. | closing tables | 0.000045 | 0.000000 | 0.000000 |
  52. | freeing items | 0.000072 | 0.000000 | 0.000000 |
  53. | Waiting for query cache lock | 0.000033 | 0.000000 | 0.000000 |
  54. | freeing items | 0.000785 | 0.000000 | 0.000000 |
  55. | Waiting for query cache lock | 0.000016 | 0.000000 | 0.000000 |
  56. | freeing items | 0.000002 | 0.000000 | 0.000000 |
  57. | storing result in query cache | 0.000005 | 0.000000 | 0.000000 |
  58. | logging slow query | 0.000003 | 0.000000 | 0.000000 |
  59. | cleaning up | 0.000004 | 0.000000 | 0.000000 |
  60. +--------------------------------+----------+----------+------------+
  61. 24 rows in set (0.00 sec)
  62. mysql> show profile block io for query 5;
  63. +--------------------------------+----------+--------------+---------------+
  64. | Status | Duration | Block_ops_in | Block_ops_out |
  65. +--------------------------------+----------+--------------+---------------+
  66. | starting | 0.000030 | 0 | 0 |
  67. | Waiting for query cache lock | 0.000005 | 0 | 0 |
  68. | checking query cache for query | 0.000043 | 0 | 0 |
  69. | checking permissions | 0.000007 | 0 | 0 |
  70. | Opening tables | 0.000027 | 0 | 0 |
  71. | System lock | 0.000010 | 0 | 0 |
  72. | Waiting for query cache lock | 0.000010 | 0 | 0 |
  73. | init | 0.000000 | 0 | 0 |
  74. | optimizing | 0.023255 | 0 | 0 |
  75. | statistics | 0.000118 | 0 | 0 |
  76. | preparing | 0.000041 | 0 | 0 |
  77. | executing | 0.000033 | 0 | 0 |
  78. | Sending data | 0.003833 | 0 | 0 |
  79. | end | 0.000054 | 0 | 0 |
  80. | query end | 0.000045 | 0 | 0 |
  81. | closing tables | 0.000045 | 0 | 0 |
  82. | freeing items | 0.000072 | 0 | 0 |
  83. | Waiting for query cache lock | 0.000033 | 0 | 0 |
  84. | freeing items | 0.000785 | 0 | 0 |
  85. | Waiting for query cache lock | 0.000016 | 0 | 0 |
  86. | freeing items | 0.000002 | 0 | 0 |
  87. | storing result in query cache | 0.000005 | 0 | 0 |
  88. | logging slow query | 0.000003 | 0 | 0 |
  89. | cleaning up | 0.000004 | 0 | 0 |
  90. +--------------------------------+----------+--------------+---------------+
  91. 24 rows in set (0.00 sec)
  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. mysql> show profile cpu for query 5;
  33. +--------------------------------+----------+----------+------------+
  34. | Status                         | Duration | CPU_user | CPU_system |
  35. +--------------------------------+----------+----------+------------+
  36. | starting                       | 0.000030 | 0.000000 |   0.000000 |
  37. | Waiting for query cache lock   | 0.000005 | 0.000000 |   0.000000 |
  38. | checking query cache for query | 0.000043 | 0.000000 |   0.000000 |
  39. | checking permissions           | 0.000007 | 0.000000 |   0.000000 |
  40. | Opening tables                 | 0.000027 | 0.000000 |   0.000000 |
  41. | System lock                    | 0.000010 | 0.000000 |   0.000000 |
  42. | Waiting for query cache lock   | 0.000010 | 0.001000 |   0.000000 |
  43. | init                           | 0.000000 | 0.000000 |   0.000000 |
  44. | optimizing                     | 0.023255 | 0.000000 |   0.000000 |
  45. | statistics                     | 0.000118 | 0.000000 |   0.000000 |
  46. | preparing                      | 0.000041 | 0.000000 |   0.000000 |
  47. | executing                      | 0.000033 | 0.000000 |   0.000000 |
  48. | Sending data                   | 0.003833 | 0.002999 |   0.001000 |
  49. | end                            | 0.000054 | 0.000000 |   0.000000 |
  50. | query end                      | 0.000045 | 0.000000 |   0.000000 |
  51. | closing tables                 | 0.000045 | 0.000000 |   0.000000 |
  52. | freeing items                  | 0.000072 | 0.000000 |   0.000000 |
  53. | Waiting for query cache lock   | 0.000033 | 0.000000 |   0.000000 |
  54. | freeing items                  | 0.000785 | 0.000000 |   0.000000 |
  55. | Waiting for query cache lock   | 0.000016 | 0.000000 |   0.000000 |
  56. | freeing items                  | 0.000002 | 0.000000 |   0.000000 |
  57. | storing result in query cache  | 0.000005 | 0.000000 |   0.000000 |
  58. | logging slow query             | 0.000003 | 0.000000 |   0.000000 |
  59. | cleaning up                    | 0.000004 | 0.000000 |   0.000000 |
  60. +--------------------------------+----------+----------+------------+
  61. 24 rows in set (0.00 sec)
  62. mysql> show profile block io for query 5;
  63. +--------------------------------+----------+--------------+---------------+
  64. | Status                         | Duration | Block_ops_in | Block_ops_out |
  65. +--------------------------------+----------+--------------+---------------+
  66. | starting                       | 0.000030 |            0 |             0 |
  67. | Waiting for query cache lock   | 0.000005 |            0 |             0 |
  68. | checking query cache for query | 0.000043 |            0 |             0 |
  69. | checking permissions           | 0.000007 |            0 |             0 |
  70. | Opening tables                 | 0.000027 |            0 |             0 |
  71. | System lock                    | 0.000010 |            0 |             0 |
  72. | Waiting for query cache lock   | 0.000010 |            0 |             0 |
  73. | init                           | 0.000000 |            0 |             0 |
  74. | optimizing                     | 0.023255 |            0 |             0 |
  75. | statistics                     | 0.000118 |            0 |             0 |
  76. | preparing                      | 0.000041 |            0 |             0 |
  77. | executing                      | 0.000033 |            0 |             0 |
  78. | Sending data                   | 0.003833 |            0 |             0 |
  79. | end                            | 0.000054 |            0 |             0 |
  80. | query end                      | 0.000045 |            0 |             0 |
  81. | closing tables                 | 0.000045 |            0 |             0 |
  82. | freeing items                  | 0.000072 |            0 |             0 |
  83. | Waiting for query cache lock   | 0.000033 |            0 |             0 |
  84. | freeing items                  | 0.000785 |            0 |             0 |
  85. | Waiting for query cache lock   | 0.000016 |            0 |             0 |
  86. | freeing items                  | 0.000002 |            0 |             0 |
  87. | storing result in query cache  | 0.000005 |            0 |             0 |
  88. | logging slow query             | 0.000003 |            0 |             0 |
  89. | cleaning up                    | 0.000004 |            0 |             0 |
  90. +--------------------------------+----------+--------------+---------------+
  91. 24 rows in set (0.00 sec)
mysql> select min(seq) seq,state,count(*) numb_ops,

    ->     round(sum(duration),5) sum_dur, round(avg(duration),5) avg_dur,

    ->     round(sum(cpu_user),5) sum_cpu, round(avg(cpu_user),5) avg_cpu

    ->     from information_schema.profiling

    ->     where query_id = 5

    ->     group by state

    ->     order by seq;

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

| seq  | state                          | numb_ops | sum_dur | avg_dur | sum_cpu | avg_cpu |

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

|    2 | starting                       |        1 | 0.00003 | 0.00003 | 0.00000 | 0.00000 |

|    3 | Waiting for query cache lock   |        4 | 0.00006 | 0.00002 | 0.00100 | 0.00025 |

|    4 | checking query cache for query |        1 | 0.00004 | 0.00004 | 0.00000 | 0.00000 |

|    5 | checking permissions           |        1 | 0.00001 | 0.00001 | 0.00000 | 0.00000 |

|    6 | Opening tables                 |        1 | 0.00003 | 0.00003 | 0.00000 | 0.00000 |

|    7 | System lock                    |        1 | 0.00001 | 0.00001 | 0.00000 | 0.00000 |

|    9 | init                           |        1 | 0.00000 | 0.00000 | 0.00000 | 0.00000 |

|   10 | optimizing                     |        1 | 0.02326 | 0.02326 | 0.00000 | 0.00000 |

|   11 | statistics                     |        1 | 0.00012 | 0.00012 | 0.00000 | 0.00000 |

|   12 | preparing                      |        1 | 0.00004 | 0.00004 | 0.00000 | 0.00000 |

|   13 | executing                      |        1 | 0.00003 | 0.00003 | 0.00000 | 0.00000 |

|   14 | Sending data                   |        1 | 0.00383 | 0.00383 | 0.00300 | 0.00300 |

|   15 | end                            |        1 | 0.00005 | 0.00005 | 0.00000 | 0.00000 |

|   16 | query end                      |        1 | 0.00005 | 0.00005 | 0.00000 | 0.00000 |

|   17 | closing tables                 |        1 | 0.00005 | 0.00005 | 0.00000 | 0.00000 |

|   18 | freeing items                  |        3 | 0.00086 | 0.00029 | 0.00000 | 0.00000 |

|   23 | storing result in query cache  |        1 | 0.00001 | 0.00001 | 0.00000 | 0.00000 |

|   24 | logging slow query             |        1 | 0.00000 | 0.00000 | 0.00000 | 0.00000 |

|   25 | cleaning up                    |        1 | 0.00000 | 0.00000 | 0.00000 | 0.00000 |

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

19 rows in set (0.00 sec)

mysql> show profile cpu for query 5;


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


| Status                         | Duration | CPU_user | CPU_system |


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


| starting                       | 0.000030 | 0.000000 |   0.000000 |


| Waiting for query cache lock   | 0.000005 | 0.000000 |   0.000000 |


| checking query cache for query | 0.000043 | 0.000000 |   0.000000 |


| checking permissions           | 0.000007 | 0.000000 |   0.000000 |


| Opening tables                 | 0.000027 | 0.000000 |   0.000000 |


| System lock                    | 0.000010 | 0.000000 |   0.000000 |


| Waiting for query cache lock   | 0.000010 | 0.001000 |   0.000000 |


| init                           | 0.000000 | 0.000000 |   0.000000 |


| optimizing                     | 0.023255 | 0.000000 |   0.000000 |


| statistics                     | 0.000118 | 0.000000 |   0.000000 |


| preparing                      | 0.000041 | 0.000000 |   0.000000 |


| executing                      | 0.000033 | 0.000000 |   0.000000 |


| Sending data                   | 0.003833 | 0.002999 |   0.001000 |


| end                            | 0.000054 | 0.000000 |   0.000000 |


| query end                      | 0.000045 | 0.000000 |   0.000000 |


| closing tables                 | 0.000045 | 0.000000 |   0.000000 |


| freeing items                  | 0.000072 | 0.000000 |   0.000000 |


| Waiting for query cache lock   | 0.000033 | 0.000000 |   0.000000 |


| freeing items                  | 0.000785 | 0.000000 |   0.000000 |


| Waiting for query cache lock   | 0.000016 | 0.000000 |   0.000000 |


| freeing items                  | 0.000002 | 0.000000 |   0.000000 |


| storing result in query cache  | 0.000005 | 0.000000 |   0.000000 |


| logging slow query             | 0.000003 | 0.000000 |   0.000000 |


| cleaning up                    | 0.000004 | 0.000000 |   0.000000 |


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


24 rows in set (0.00 sec)

mysql> show profile block io for query 5;


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


| Status                         | Duration | Block_ops_in | Block_ops_out |


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


| starting                       | 0.000030 |            0 |             0 |


| Waiting for query cache lock   | 0.000005 |            0 |             0 |


| checking query cache for query | 0.000043 |            0 |             0 |


| checking permissions           | 0.000007 |            0 |             0 |


| Opening tables                 | 0.000027 |            0 |             0 |


| System lock                    | 0.000010 |            0 |             0 |


| Waiting for query cache lock   | 0.000010 |            0 |             0 |


| init                           | 0.000000 |            0 |             0 |


| optimizing                     | 0.023255 |            0 |             0 |


| statistics                     | 0.000118 |            0 |             0 |


| preparing                      | 0.000041 |            0 |             0 |


| executing                      | 0.000033 |            0 |             0 |


| Sending data                   | 0.003833 |            0 |             0 |


| end                            | 0.000054 |            0 |             0 |


| query end                      | 0.000045 |            0 |             0 |


| closing tables                 | 0.000045 |            0 |             0 |


| freeing items                  | 0.000072 |            0 |             0 |


| Waiting for query cache lock   | 0.000033 |            0 |             0 |


| freeing items                  | 0.000785 |            0 |             0 |


| Waiting for query cache lock   | 0.000016 |            0 |             0 |


| freeing items                  | 0.000002 |            0 |             0 |


| storing result in query cache  | 0.000005 |            0 |             0 |


| logging slow query             | 0.000003 |            0 |             0 |


| cleaning up                    | 0.000004 |            0 |             0 |


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


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

Query OK, 0 rows affected (0.03 sec)

mysql> alter table payment_myisam engine=myisam;


Query OK, 0 rows affected (0.03 sec)


Records: 0  Duplicates: 0  Warnings: 0

mysql> show create table payment_myisam\G


*************************** 1. row ***************************


Table: payment_myisam


Create Table: CREATE TABLE payment_myisam (


payment_id smallint(5) unsigned NOT NULL AUTO_INCREMENT,


customer_id smallint(5) unsigned NOT NULL,


staff_id tinyint(3) unsigned NOT NULL,


rental_id int(11) DEFAULT NULL,


amount decimal(5,2) NOT NULL,


payment_date datetime NOT NULL,


last_update timestamp NOT NULL DEFAULT CURRENT_TIMESTAMP ON UPDATE CURRENT_TIMESTAMP,


PRIMARY KEY (payment_id),


KEY idx_fk_staff_id (staff_id),


KEY idx_fk_customer_id (customer_id),


KEY fk_payment_rental (rental_id)


) ENGINE=MyISAM DEFAULT CHARSET=utf8


1 row in set (0.00 sec)

mysql> insert into payment_myisam select * from payment;


Query OK, 16049 rows affected (0.10 sec)


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)
  8. mysql> show profiles;
  9. | 23 | 0.09449600 | insert into payment_myisam select * from payment |
  10. | 24 | 0.00023500 | select count(*) from payment_myisam |
  11. 15 rows in set (0.00 sec)
  1. mysql> select count(*) from payment_myisam;
  2. +----------+
  3. | count(*) |
  4. +----------+
  5. |    16049 |
  6. +----------+
  7. 1 row in set (0.01 sec)
  8. mysql> show profiles;
  9. |       23 | 0.09449600 | insert into payment_myisam select * from payment                                                                                                                                                                                                                                        |
  10. |       24 | 0.00023500 | select count(*) from payment_myisam                                                                                                                                                                                                                                                     |
  11. 15 rows in set (0.00 sec)
mysql> select count(*) from payment_myisam;

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

| count(*) |

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

|    16049 |

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

1 row in set (0.01 sec)

mysql> show profiles;

|       23 | 0.09449600 | insert into payment_myisam select * from payment                                                                                                                                                                                                                                        |


|       24 | 0.00023500 | select count(*) from payment_myisam                                                                                                                                                                                                                                                     |

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. +--------------------------------+----------+

最新文章

  1. Appfuse：扩展自己的GenericManager
  2. transition
  3. update语句关联表更新
  4. information_schema系列五（表，触发器，视图，存储过程和函数）
  5. ping与telnet的区别
  6. Unity3D NGUI UIPlayTween控件（一）动态打开关闭窗口
  7. 2016年团体程序设计天梯赛-决赛 L1-2. I Love GPLT（5）
  8. 【QAQ的Minecraft】
  9. iOS中 static变量与全局、局部变量的区别 !
  10. python3 Flask -day1
  11. Python django解决跨域请求的问题
  12. CS模式，客户端页面加载
  13. Java多线程学习（八）线程池与Executor 框架
  14. iis服务器配置
  15. one by one 项目 part 1
  16. （转）NGUI研究院之三种方式监听NGUI的事件方法
  17. 关于SQL语句的一些注意事项
  18. Eclipse实用用快捷键
  19. [Erlang00]:gen_server:reply/2
  20. Service Fabric eShop On Containers

热门文章

  1. jQuery学习(七)——使用JQ完成下拉列表左右选择
  2. 用js将CheckBox的值存入数据库和将数据库字符串的值转为数组选中CheckBox
  3. LCD段码驱动
  4. DotNetCore.1.0.1-VS2015Tools.Preview2.0.3 相关问题及解决办法
  5. php——get与post方法（转）
  6. swift 20 - Nested Types
  7. [HNOI2004]打砖块（敲砖块）
  8. redis 多实例监控
  9. centeros 7开机自动挂载磁盘
  10. 使用InstelliJ IDEA创建Web应用程序