22.Show Profile

MySQL提供可以用来分析当前会话中语句执行的资源消耗情况。可以用于SQL的调优测量

官网 http://dev.mysq.com/doc/refman/5.5/en/show-profile.html

默认情况下,参数处于关闭状态,并保存最近15次的运行结果

分析步骤

  • 1.查看当前mysql版本是否支持
  • 2.开启功能。 默认是关闭状态,使用前需要开启
  • 3.运行SQL
  • 4.查看结果 ,show profiles;
  • 5.诊断SQL, show profile cpu, block io for query
  • 6.日常开发需要注意的结论。

查看是否关闭状态

mysql> show variables like 'profiling';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| profiling     | OFF   |
+---------------+-------+
1 row in set (0.01 sec)

开启

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

mysql> show variables like 'profiling';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| profiling     | ON    |
+---------------+-------+
1 row in set (0.01 sec)

运行SQL

运行sql报错时 参考资料

mysql> select * from emp group by id%10 limit 150000;
ERROR 1055 (42000): Expression #1 of SELECT list is not in GROUP BY clause and contains nonaggregated column 'bigData.emp.id' which is not functionally dependent on columns in GROUP BY clause; this is incompatible with sql_mode=only_full_group_by

mysql> select @@sql_mode;
+-------------------------------------------------------------------------------------------------------------------------------------------+
| @@sql_mode                                                                                                                                |
+-------------------------------------------------------------------------------------------------------------------------------------------+
| ONLY_FULL_GROUP_BY,STRICT_TRANS_TABLES,NO_ZERO_IN_DATE,NO_ZERO_DATE,ERROR_FOR_DIVISION_BY_ZERO,NO_AUTO_CREATE_USER,NO_ENGINE_SUBSTITUTION |
+-------------------------------------------------------------------------------------------------------------------------------------------+

mysql> set sql_mode='STRICT_TRANS_TABLES,NO_ZERO_IN_DATE,NO_ZERO_DATE,ERROR_FOR_DIVISION_BY_ZERO,NO_AUTO_CREATE_USER,NO_ENGINE_SUBSTITUTION';
Query OK, 0 rows affected (0.00 sec)

mysql> select * from emp group by id%10 limit 150000;
+----+--------+--------+---------+-----+------------+---------+--------+--------+
| id | empno  | ename  | job     | mgr | hiredate   | sal     | comm   | deptno |
+----+--------+--------+---------+-----+------------+---------+--------+--------+
| 10 | 100011 | PrnqNV | SALEMAN |   1 | 2017-05-12 | 2000.00 | 400.00 |   1002 |
|  1 | 100002 | UEjlAT | SALEMAN |   1 | 2017-05-12 | 2000.00 | 400.00 |   1009 |
|  2 | 100003 | SFvojc | SALEMAN |   1 | 2017-05-12 | 2000.00 | 400.00 |   1006 |
|  3 | 100004 | puhzcN | SALEMAN |   1 | 2017-05-12 | 2000.00 | 400.00 |   1006 |
|  4 | 100005 | bgECZn | SALEMAN |   1 | 2017-05-12 | 2000.00 | 400.00 |   1003 |
|  5 | 100006 | ZUzNpm | SALEMAN |   1 | 2017-05-12 | 2000.00 | 400.00 |   1002 |
|  6 | 100007 | OaIqFc | SALEMAN |   1 | 2017-05-12 | 2000.00 | 400.00 |   1003 |
|  7 | 100008 | TjpXTB | SALEMAN |   1 | 2017-05-12 | 2000.00 | 400.00 |   1009 |
|  8 | 100009 | oyCses | SALEMAN |   1 | 2017-05-12 | 2000.00 | 400.00 |   1005 |
|  9 | 100010 | KSinOf | SALEMAN |   1 | 2017-05-12 | 2000.00 | 400.00 |   1002 |
+----+--------+--------+---------+-----+------------+---------+--------+--------+
10 rows in set (1.09 sec)


mysql> select * from emp group by id%20 order by 5;
+----+--------+--------+---------+-----+------------+---------+--------+--------+
| id | empno  | ename  | job     | mgr | hiredate   | sal     | comm   | deptno |
+----+--------+--------+---------+-----+------------+---------+--------+--------+
|  8 | 100009 | oyCses | SALEMAN |   1 | 2017-05-12 | 2000.00 | 400.00 |   1005 |
| 16 | 100017 | SvDBYm | SALEMAN |   1 | 2017-05-12 | 2000.00 | 400.00 |   1003 |
|  3 | 100004 | puhzcN | SALEMAN |   1 | 2017-05-12 | 2000.00 | 400.00 |   1006 |
| 11 | 100012 | xBpTzQ | SALEMAN |   1 | 2017-05-12 | 2000.00 | 400.00 |   1006 |
| 19 | 100020 | hUcDMW | SALEMAN |   1 | 2017-05-12 | 2000.00 | 400.00 |   1004 |
|  6 | 100007 | OaIqFc | SALEMAN |   1 | 2017-05-12 | 2000.00 | 400.00 |   1003 |
| 14 | 100015 | ewUhcR | SALEMAN |   1 | 2017-05-12 | 2000.00 | 400.00 |   1000 |
|  1 | 100002 | UEjlAT | SALEMAN |   1 | 2017-05-12 | 2000.00 | 400.00 |   1009 |
|  9 | 100010 | KSinOf | SALEMAN |   1 | 2017-05-12 | 2000.00 | 400.00 |   1002 |
| 17 | 100018 | WJDRxL | SALEMAN |   1 | 2017-05-12 | 2000.00 | 400.00 |   1002 |
|  4 | 100005 | bgECZn | SALEMAN |   1 | 2017-05-12 | 2000.00 | 400.00 |   1003 |
| 12 | 100013 | SpUFsW | SALEMAN |   1 | 2017-05-12 | 2000.00 | 400.00 |   1005 |
| 20 | 100021 | zfaOQM | SALEMAN |   1 | 2017-05-12 | 2000.00 | 400.00 |   1002 |
|  7 | 100008 | TjpXTB | SALEMAN |   1 | 2017-05-12 | 2000.00 | 400.00 |   1009 |
| 15 | 100016 | FZexaM | SALEMAN |   1 | 2017-05-12 | 2000.00 | 400.00 |   1006 |
|  2 | 100003 | SFvojc | SALEMAN |   1 | 2017-05-12 | 2000.00 | 400.00 |   1006 |
| 10 | 100011 | PrnqNV | SALEMAN |   1 | 2017-05-12 | 2000.00 | 400.00 |   1002 |
| 18 | 100019 | nxyaHi | SALEMAN |   1 | 2017-05-12 | 2000.00 | 400.00 |   1009 |
|  5 | 100006 | ZUzNpm | SALEMAN |   1 | 2017-05-12 | 2000.00 | 400.00 |   1002 |
| 13 | 100014 | hWmune | SALEMAN |   1 | 2017-05-12 | 2000.00 | 400.00 |   1006 |
+----+--------+--------+---------+-----+------------+---------+--------+--------+
20 rows in set (0.93 sec

show profiles;

一定要先 set profiling=on;

mysql> show profiles;
+----------+------------+-----------------------------------------------+
| Query_ID | Duration   | Query                                         |
+----------+------------+-----------------------------------------------+
|        1 | 0.88353975 | select * from emp group by id%10 limit 150000 |
|        2 | 0.92210775 | select * from emp group by id%20 order by 5   |
+----------+------------+-----------------------------------------------+
2 rows in set, 1 warning (0.00 sec)

诊断SQL

show profile cpu, block io for query + Query_ID

mysql> show profile cpu, block io for query 1;
+----------------------+----------+----------+------------+--------------+---------------+
| Status               | Duration | CPU_user | CPU_system | Block_ops_in | Block_ops_out |
+----------------------+----------+----------+------------+--------------+---------------+
| starting             | 0.000098 | 0.000000 |   0.000000 |            0 |             0 |
| checking permissions | 0.000013 | 0.000000 |   0.000000 |            0 |             0 |
| Opening tables       | 0.000020 | 0.000000 |   0.000000 |            0 |             0 |
| init                 | 0.000041 | 0.000000 |   0.000000 |            0 |             0 |
| System lock          | 0.000016 | 0.000000 |   0.000000 |            0 |             0 |
| optimizing           | 0.000008 | 0.000000 |   0.000000 |            0 |             0 |
| statistics           | 0.000034 | 0.000000 |   0.000000 |            0 |             0 |
| preparing            | 0.000023 | 0.000000 |   0.000000 |            0 |             0 |
| Creating tmp table   | 0.000067 | 0.000000 |   0.000000 |            0 |             0 |
| Sorting result       | 0.000009 | 0.000000 |   0.000000 |            0 |             0 |
| executing            | 0.000004 | 0.000000 |   0.000000 |            0 |             0 |
| Sending data         | 0.883066 | 0.884000 |   0.000000 |            0 |             0 |
| Creating sort index  | 0.000075 | 0.000000 |   0.000000 |            0 |             0 |
| end                  | 0.000004 | 0.000000 |   0.000000 |            0 |             0 |
| query end            | 0.000010 | 0.000000 |   0.000000 |            0 |             0 |
| removing tmp table   | 0.000007 | 0.000000 |   0.000000 |            0 |             0 |
| query end            | 0.000003 | 0.000000 |   0.000000 |            0 |             0 |
| closing tables       | 0.000007 | 0.000000 |   0.000000 |            0 |             0 |
| freeing items        | 0.000021 | 0.000000 |   0.000000 |            0 |             0 |
| cleaning up          | 0.000013 | 0.000000 |   0.000000 |            0 |             0 |
+----------------------+----------+----------+------------+--------------+---------------+
20 rows in set, 1 warning (0.00 sec)

mysql> show profile cpu, block io for query 2;
+----------------------+----------+----------+------------+--------------+---------------+
| Status               | Duration | CPU_user | CPU_system | Block_ops_in | Block_ops_out |
+----------------------+----------+----------+------------+--------------+---------------+
| starting             | 0.000132 | 0.000000 |   0.000000 |            0 |             0 |
| checking permissions | 0.000018 | 0.000000 |   0.000000 |            0 |             0 |
| Opening tables       | 0.000033 | 0.000000 |   0.000000 |            0 |             0 |
| init                 | 0.000067 | 0.004000 |   0.000000 |            0 |             0 |
| System lock          | 0.000025 | 0.000000 |   0.000000 |            0 |             0 |
| optimizing           | 0.000011 | 0.000000 |   0.000000 |            0 |             0 |
| statistics           | 0.000045 | 0.000000 |   0.000000 |            0 |             0 |
| preparing            | 0.000057 | 0.000000 |   0.000000 |            0 |             0 |
| Creating tmp table   | 0.000089 | 0.000000 |   0.000000 |            0 |             0 |
| Sorting result       | 0.000011 | 0.000000 |   0.000000 |            0 |             0 |
| executing            | 0.000004 | 0.000000 |   0.000000 |            0 |             0 |
| Sending data         | 0.921470 | 0.916000 |   0.000000 |            0 |             0 |
| Creating sort index  | 0.000081 | 0.000000 |   0.000000 |            0 |             0 |
| end                  | 0.000006 | 0.000000 |   0.000000 |            0 |             0 |
| query end            | 0.000008 | 0.000000 |   0.000000 |            0 |             0 |
| removing tmp table   | 0.000007 | 0.000000 |   0.000000 |            0 |             0 |
| query end            | 0.000003 | 0.000000 |   0.000000 |            0 |             0 |
| closing tables       | 0.000007 | 0.000000 |   0.000000 |            0 |             0 |
| freeing items        | 0.000022 | 0.000000 |   0.000000 |            0 |             0 |
| cleaning up          | 0.000014 | 0.000000 |   0.000000 |            0 |             0 |
+----------------------+----------+----------+------------+--------------+---------------+
20 rows in set, 1 warning (0.00 sec)
  • ALL 显示所有的开销
  • BLOCK IO 显示IO 相关开销
  • CONTEXT SWITCHES 上下文切换相关开销
  • CPU 显示CPU 相关开销信息
  • IPC 显示发送和接收相关开销息息
  • MEMORY 显示内存相关开销信息
  • PAGE FAULTS 显示页面错误相关开销信息
  • SOURCE 显示Souce_function, Source_file, Source_line相关的开销信息
  • SWAPS 显示交换次数相关开销的信息

日常开发需要注决心的结论

  • converting HEAP to MyISAM 查询结果太大,内存都不够用了往磁盘上搬了。
  • Creating tmp table 创建临时表
    • 拷贝数据到临时表
    • 用完再删除
  • Copying to tmp table on disk 把内存中临时表复制到磁盘,危险!!
  • locked