mysql性能调试工具profile

4r221

  我一直在找mysql中有没有类似Oracle 10046类似的工具，可以看到SQL执行的时间消耗在哪里。终于在网上找到一个profile,使用一些，觉得不错。mysql> select version();
+-----------+
| version() |
+-----------+
| 5.6.16    |
+-----------+
1 row in set (0.00 sec)


mysql> SELECT @@profiling;
+-------------+
| @@profiling |
+-------------+
|           0 |
+-------------+
1 row in set, 1 warning (0.00 sec)


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


mysql> select count(1) from test1 t1,test2 t2;
+----------+
| count(1) |
+----------+
|  7096832 |
+----------+
1 row in set (0.38 sec)


mysql> show profile cpu,block io for query 1;  --for query 1 是看第1条执行的SQL语句
+--------------------------------+----------+----------+------------+--------------+---------------+
| Status                         | Duration | CPU_user | CPU_system | Block_ops_in | Block_ops_out |
+--------------------------------+----------+----------+------------+--------------+---------------+
| starting                       | 0.000006 | 0.000000 |   0.000000 |         NULL |          NULL |
| Waiting for query cache lock   | 0.000002 | 0.000000 |   0.000000 |         NULL |          NULL |
| init                           | 0.000002 | 0.000000 |   0.000000 |         NULL |          NULL |
| checking query cache for query | 0.000023 | 0.000000 |   0.000000 |         NULL |          NULL |
| checking permissions           | 0.000003 | 0.000000 |   0.000000 |         NULL |          NULL |
| checking permissions           | 0.000002 | 0.000000 |   0.000000 |         NULL |          NULL |
| Opening tables                 | 0.000026 | 0.000000 |   0.000000 |         NULL |          NULL |
| init                           | 0.000008 | 0.000000 |   0.000000 |         NULL |          NULL |
| System lock                    | 0.000007 | 0.000000 |   0.000000 |         NULL |          NULL |
| Waiting for query cache lock   | 0.000002 | 0.000000 |   0.000000 |         NULL |          NULL |
| System lock                    | 0.000022 | 0.000000 |   0.000000 |         NULL |          NULL |
| optimizing                     | 0.000004 | 0.000000 |   0.000000 |         NULL |          NULL |
| statistics                     | 0.000012 | 0.000000 |   0.000000 |         NULL |          NULL |
| preparing                      | 0.000022 | 0.000000 |   0.000000 |         NULL |          NULL |
| executing                      | 0.000002 | 0.000000 |   0.000000 |         NULL |          NULL |
| Sending data                   | 0.388263 | 0.375000 |   0.000000 |         NULL |          NULL |
| end                            | 0.000017 | 0.000000 |   0.000000 |         NULL |          NULL |
| query end                      | 0.000008 | 0.000000 |   0.000000 |         NULL |          NULL |
| closing tables                 | 0.000014 | 0.000000 |   0.000000 |         NULL |          NULL |
| freeing items                  | 0.000006 | 0.000000 |   0.000000 |         NULL |          NULL |
| Waiting for query cache lock   | 0.000002 | 0.000000 |   0.000000 |         NULL |          NULL |
| freeing items                  | 0.000045 | 0.000000 |   0.000000 |         NULL |          NULL |
| Waiting for query cache lock   | 0.000002 | 0.000000 |   0.000000 |         NULL |          NULL |
| freeing items                  | 0.000002 | 0.000000 |   0.000000 |         NULL |          NULL |
| storing result in query cache  | 0.000004 | 0.000000 |   0.000000 |         NULL |          NULL |
| cleaning up                    | 0.000015 | 0.000000 |   0.000000 |         NULL |          NULL |
+--------------------------------+----------+----------+------------+--------------+---------------+
26 rows in set, 1 warning (0.00 sec)


mysql> select count(1) from test1 t1,test2 t2, test2 t3;
+------------+
| count(1)   |
+------------+
| 1185170944 |
+------------+
1 row in set (1 min 26.67 sec)


mysql> show profile cpu,block io for query 2;  --for query 2 是看第2条执行的SQL语句
+--------------------------------+-----------+-----------+------------+--------------+---------------+
| Status                         | Duration  | CPU_user  | CPU_system | Block_ops_in | Block_ops_out |
+--------------------------------+-----------+-----------+------------+--------------+---------------+
| starting                       |  0.000005 |  0.000000 |   0.000000 |         NULL |          NULL |
| Waiting for query cache lock   |  0.000002 |  0.000000 |   0.000000 |         NULL |          NULL |
| init                           |  0.000002 |  0.000000 |   0.000000 |         NULL |          NULL |
| checking query cache for query |  0.000029 |  0.000000 |   0.000000 |         NULL |          NULL |
| checking permissions           |  0.000002 |  0.000000 |   0.000000 |         NULL |          NULL |
| checking permissions           |  0.000002 |  0.000000 |   0.000000 |         NULL |          NULL |
| checking permissions           |  0.000002 |  0.000000 |   0.000000 |         NULL |          NULL |
| Opening tables                 |  0.000071 |  0.000000 |   0.000000 |         NULL |          NULL |
| init                           |  0.000008 |  0.000000 |   0.000000 |         NULL |          NULL |
| System lock                    |  0.000005 |  0.000000 |   0.000000 |         NULL |          NULL |
| Waiting for query cache lock   |  0.000002 |  0.000000 |   0.000000 |         NULL |          NULL |
| System lock                    |  0.000021 |  0.000000 |   0.000000 |         NULL |          NULL |
| optimizing                     |  0.000004 |  0.000000 |   0.000000 |         NULL |          NULL |
| statistics                     |  0.000011 |  0.000000 |   0.000000 |         NULL |          NULL |
| preparing                      |  0.000019 |  0.000000 |   0.000000 |         NULL |          NULL |
| executing                      |  0.000002 |  0.000000 |   0.000000 |         NULL |          NULL |
| Sending data                   | 86.679145 | 86.640625 |   0.000000 |         NULL |          NULL |
| end                            |  0.000024 |  0.000000 |   0.000000 |         NULL |          NULL |
| query end                      |  0.000008 |  0.000000 |   0.000000 |         NULL |          NULL |
| closing tables                 |  0.000014 |  0.000000 |   0.000000 |         NULL |          NULL |
| freeing items                  |  0.000006 |  0.000000 |   0.000000 |         NULL |          NULL |
| Waiting for query cache lock   |  0.000002 |  0.000000 |   0.000000 |         NULL |          NULL |
| freeing items                  |  0.000045 |  0.000000 |   0.000000 |         NULL |          NULL |
| Waiting for query cache lock   |  0.000002 |  0.000000 |   0.000000 |         NULL |          NULL |
| freeing items                  |  0.000002 |  0.000000 |   0.000000 |         NULL |          NULL |
| storing result in query cache  |  0.000003 |  0.000000 |   0.000000 |         NULL |          NULL |
| logging slow query             |  0.000003 |  0.000000 |   0.000000 |         NULL |          NULL |
| cleaning up                    |  0.000014 |  0.000000 |   0.000000 |         NULL |          NULL |
+--------------------------------+-----------+-----------+------------+--------------+---------------+
28 rows in set, 1 warning (0.00 sec)

SHOW PROFILES Syntax
SHOW PROFILE [type [, type] ... ]
    [FOR QUERY n]
    [LIMIT row_count [OFFSET offset]]
type:
    ALL
  | BLOCK IO
  | CONTEXT SWITCHES
  | CPU
  | IPC
  | MEMORY
  | PAGE FAULTS
  | SOURCE
  | SWAPS
type类型的含义：
ALL displays all information
BLOCK IO displays counts for block input and output operations
CONTEXT SWITCHES displays counts for voluntary and involuntary context switches
CPU displays user and system CPU usage times
IPC displays counts for messages sent and received
MEMORY is not currently implemented
PAGE FAULTS displays counts for major and minor page faults
SOURCE displays the names of functions from the source code, together with the name and line number of the file in which the function occurs
SWAPS displays swap counts