-
Notifications
You must be signed in to change notification settings - Fork 111
PROFILING
xiaoboluo768 edited this page Jun 7, 2020
·
2 revisions
- 该表提供查询关于语句性能分析的信息。其记录内容对应于SHOW PROFILES和SHOW PROFILE语句产生的信息
- 该表需要在会话变量 profiling=1时才会记录语句性能分析信息，否则该表不记录
- 该表为Memory引擎临时表，注意：从MySQL 5.7.2开始，此表不再推荐使用，在未来的MySQL版本中删除。改用Performance Schema;代替
- 表定义语句
CREATE TEMPORARY TABLE `PROFILING` (
`QUERY_ID` int(20) NOT NULL DEFAULT '0',
`SEQ` int(20) NOT NULL DEFAULT '0',
`STATE` varchar(30) NOT NULL DEFAULT '',
`DURATION` decimal(9,6) NOT NULL DEFAULT '0.000000',
`CPU_USER` decimal(9,6) DEFAULT NULL,
`CPU_SYSTEM` decimal(9,6) DEFAULT NULL,
`CONTEXT_VOLUNTARY` int(20) DEFAULT NULL,
`CONTEXT_INVOLUNTARY` int(20) DEFAULT NULL,
`BLOCK_OPS_IN` int(20) DEFAULT NULL,
`BLOCK_OPS_OUT` int(20) DEFAULT NULL,
`MESSAGES_SENT` int(20) DEFAULT NULL,
`MESSAGES_RECEIVED` int(20) DEFAULT NULL,
`PAGE_FAULTS_MAJOR` int(20) DEFAULT NULL,
`PAGE_FAULTS_MINOR` int(20) DEFAULT NULL,
`SWAPS` int(20) DEFAULT NULL,
`SOURCE_FUNCTION` varchar(30) DEFAULT NULL,
`SOURCE_FILE` varchar(20) DEFAULT NULL,
`SOURCE_LINE` int(20) DEFAULT NULL
) ENGINE=MEMORY DEFAULT CHARSET=utf8- 表字段含义
- QUERY_ID：执行的语句的数字标识符
- SEQ：一个序列号，用于表示具有相同QUERY_ID值的语句记录行的显示顺序，
- STATE：表示语句性能分析的状态(语句阶段)
- DURATION：表示语句在性能分析中的某个给定状态下持续的时长(单位为秒)
- CPU_USER和CPU_SYSTEM：表示用户CPU的us%和sy%的时间开销(单位为秒)
- CONTEXT_VOLUNTARY和CONTEXT_INVOLUNTARY：表示发生了多少次自主或非自主的上下文切换
- BLOCK_OPS_IN和BLOCK_OPS_OUT：表示块输入和输出的操作数量
- MESSAGES_SENT和MESSAGES_RECEIVED：表示发送和接收的通信消息的数量
- PAGE_FAULTS_MAJOR和PAGE_FAULTS_MINOR：表示主要和次要页面错误的数量
- SWAPS：表示发生了多少次swap
- SOURCE_FUNCTION、SOURCE_FILE和SOURCE_LINE：提供关于在源代码中执行的性能状态和位置信息
- 表记录内容示例
root@localhost : sbtest 04:47:17> set profiling=1;
Query OK, 0 rows affected, 1 warning (0.00 sec)
root@localhost : (none) 04:47:10> use sbtest
Database changed
root@localhost : sbtest 04:47:21> select min(id) from sbtest1;
+---------+
| min(id) |
+---------+
| 1 |
+---------+
1 row in set (0.00 sec)
root@localhost : sbtest 04:47:33> select * from information_schema.profiling;
+----------+-----+----------------------+----------+----------+------------+-------------------+---------------------+--------------+---------------+---------------+-------------------+-------------------+-------------------+-------+-----------------------+----------------------+-------------+
| QUERY_ID | SEQ | STATE | DURATION | CPU_USER | CPU_SYSTEM | CONTEXT_VOLUNTARY | CONTEXT_INVOLUNTARY | BLOCK_OPS_IN | BLOCK_OPS_OUT | MESSAGES_SENT | MESSAGES_RECEIVED | PAGE_FAULTS_MAJOR | PAGE_FAULTS_MINOR | SWAPS | SOURCE_FUNCTION | SOURCE_FILE | SOURCE_LINE |
+----------+-----+----------------------+----------+----------+------------+-------------------+---------------------+--------------+---------------+---------------+-------------------+-------------------+-------------------+-------+-----------------------+----------------------+-------------+
| 1 | 2 | starting | 0.000040 | 0.000000 | 0.000000 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | NULL | NULL | NULL |
| 1 | 3 | query end | 0.000008 | 0.000000 | 0.000000 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | mysql_execute_command | sql_parse.cc | 4968 |
| 1 | 4 | closing tables | 0.000004 | 0.000000 | 0.000000 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | mysql_execute_command | sql_parse.cc | 5020 |
| 1 | 5 | freeing items | 0.000008 | 0.000000 | 0.000000 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | mysql_parse | sql_parse.cc | 5596 |
| 1 | 6 | cleaning up | 0.000007 | 0.000000 | 0.000000 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | dispatch_command | sql_parse.cc | 1902 |
| 2 | 2 | starting | 0.000107 | 0.000000 | 0.000000 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | NULL | NULL | NULL |
| 2 | 3 | checking permissions | 0.000022 | 0.000000 | 0.000000 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | check_access | sql_authorization.cc | 810 |
| 2 | 4 | Opening tables | 0.000080 | 0.000000 | 0.000000 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | open_tables | sql_base.cc | 5650 |
| 2 | 5 | init | 0.000056 | 0.000000 | 0.000000 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | handle_query | sql_select.cc | 121 |
| 2 | 6 | System lock | 0.000021 | 0.000000 | 0.000000 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | mysql_lock_tables | lock.cc | 323 |
| 2 | 7 | optimizing | 0.000057 | 0.000000 | 0.000000 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | optimize | sql_optimizer.cc | 151 |
| 2 | 8 | executing | 0.000007 | 0.000000 | 0.000000 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | exec | sql_executor.cc | 119 |
| 2 | 9 | end | 0.000003 | 0.000000 | 0.000000 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | handle_query | sql_select.cc | 199 |
| 2 | 10 | query end | 0.000023 | 0.000000 | 0.000000 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | mysql_execute_command | sql_parse.cc | 4968 |
| 2 | 11 | closing tables | 0.000016 | 0.000000 | 0.000000 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | mysql_execute_command | sql_parse.cc | 5020 |
| 2 | 12 | freeing items | 0.000012 | 0.000000 | 0.000000 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | mysql_parse | sql_parse.cc | 5596 |
| 2 | 13 | cleaning up | 0.000008 | 0.000000 | 0.000000 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | dispatch_command | sql_parse.cc | 1902 |
+----------+-----+----------------------+----------+----------+------------+-------------------+---------------------+--------------+---------------+---------------+-------------------+-------------------+-------------------+-------+-----------------------+----------------------+-------------+
17 rows in set, 1 warning (0.00 sec)
- 该表中的信息还可以使用show语句查询，如下
# 需要使用set profiling=1;语句开启，该功能即将废弃，使用performance_schema中的阶段事件代替
## 启用
root@localhost : information_schema 02:30:20> set profiling=1;
Query OK, 0 rows affected, 1 warning (0.00 sec)
## 列出查询语句的query id和语句文本等信息
root@localhost : sbtest 04:33:47> show profiles;
+----------+------------+-----------------------------+
| Query_ID | Duration | Query |
+----------+------------+-----------------------------+
| 1 | 0.00005125 | show warnings |
| 2 | 0.00073950 | select * from profiling |
| 3 | 0.00007150 | show warnings |
| 4 | 0.00021025 | set profiling=1 |
| 5 | 0.00003250 | show warnings |
| 6 | 0.00038300 | select * from profiling |
| 7 | 0.00003625 | show warnings |
| 8 | 0.00018250 | SELECT DATABASE() |
| 9 | 0.08272525 | select max(id) from sbtest1 |
+----------+------------+-----------------------------+
9 rows in set, 1 warning (0.00 sec)
## 找到query id为9，查询该ID的性能分析数据
root@localhost : sbtest 04:33:53> show profile all for query 9;
+----------------------+----------+----------+------------+-------------------+---------------------+--------------+---------------+---------------+-------------------+-------------------+-------------------+-------+-----------------------+----------------------+-------------+
| Status | Duration | CPU_user | CPU_system | Context_voluntary | Context_involuntary | Block_ops_in | Block_ops_out | Messages_sent | Messages_received | Page_faults_major | Page_faults_minor | Swaps | Source_function | Source_file | Source_line |
+----------------------+----------+----------+------------+-------------------+---------------------+--------------+---------------+---------------+-------------------+-------------------+-------------------+-------+-----------------------+----------------------+-------------+
| starting | 0.000089 | 0.000000 | 0.000000 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 1 | 0 | NULL | NULL | NULL |
| checking permissions | 0.000011 | 0.000000 | 0.000000 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | check_access | sql_authorization.cc | 810 |
| Opening tables | 0.082168 | 0.000000 | 0.081988 | 25 | 2 | 128 | 0 | 0 | 0 | 0 | 800 | 0 | open_tables | sql_base.cc | 5650 |
| init | 0.000173 | 0.000000 | 0.000000 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 10 | 0 | handle_query | sql_select.cc | 121 |
| System lock | 0.000012 | 0.000000 | 0.000000 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | mysql_lock_tables | lock.cc | 323 |
| optimizing | 0.000079 | 0.000000 | 0.000000 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 2 | 0 | optimize | sql_optimizer.cc | 151 |
| executing | 0.000010 | 0.000000 | 0.000000 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | exec | sql_executor.cc | 119 |
| end | 0.000003 | 0.000000 | 0.000000 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | handle_query | sql_select.cc | 199 |
| query end | 0.000009 | 0.000000 | 0.000000 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | mysql_execute_command | sql_parse.cc | 4968 |
| closing tables | 0.000008 | 0.000000 | 0.000000 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | mysql_execute_command | sql_parse.cc | 5020 |
| freeing items | 0.000150 | 0.000000 | 0.000000 | 0 | 1 | 0 | 0 | 0 | 0 | 0 | 3 | 0 | mysql_parse | sql_parse.cc | 5596 |
| cleaning up | 0.000013 | 0.000000 | 0.000000 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | dispatch_command | sql_parse.cc | 1902 |
+----------------------+----------+----------+------------+-------------------+---------------------+--------------+---------------+---------------+-------------------+-------------------+-------------------+-------+-----------------------+----------------------+-------------+
12 rows in set, 1 warning (0.00 sec)
- PS：关于show profiling语句，详见链接：https://dev.mysql.com/doc/refman/5.7/en/show-profile.html
- 验证、测试、整理：罗小波
- QQ：309969177
- 提示：本系列文章的主体结构遵循Oracle MySQL 官方 5.7 手册中，关于information_schema、mysql schema、performance_schema、sys schema的章节结构体系，并额外添加了一些验证、测试数据。鉴于本人精力和能力有限，难免出现一些纰漏，欢迎大家踊跃指正！