剖析查询性能

0x00 使用SHOW PROFILE

SHOW PROFILE命令是从MySQL 5.1之后的版本引入的,这个工具默认是禁用的,可以使用如下命令将其打开

SET profiling = 1;

这个工具会在服务器执行一条查询的时候,将性能信息记录到一张临时表,并且会记录你的SQL语句,并为其赋予一个单独的从1开始的整数标识符

首先我们执行一条查询

mysql> select * from Country limit 20;
..查询结果略..

然后使用SHOW PROFILES语句来查看查询信息

mysql> show profiles;
+----------+------------+--------------------------------+
| Query_ID | Duration | Query |
+----------+------------+--------------------------------+
| 1 | 0.00042900 | show tables |
| 2 | 0.00032925 | select * from Country |
| 3 | 0.00040525 | select * from Country limit 20 |
+----------+------------+--------------------------------+
3 rows in set, 1 warning (0.00 sec)

第一列就是查询ID,第二列是所使用的时间(单位为秒),第三列是你所使用的SQL语句

现在我们来看刚刚所执行的那一条查询(由上表可知Query ID为3)MySQL所执行的每个步骤所花费的时间,使用语句

mysql> show profile for query 3;
+----------------------+----------+
| Status | Duration |
+----------------------+----------+
| starting | 0.000058 |
| checking permissions | 0.000006 |
| Opening tables | 0.000050 |
| init | 0.000042 |
| System lock | 0.000010 |
| optimizing | 0.000003 |
| statistics | 0.000012 |
| preparing | 0.000010 |
| executing | 0.000002 |
| Sending data | 0.000173 |
| end | 0.000007 |
| query end | 0.000006 |
| closing tables | 0.000005 |
| freeing items | 0.000012 |
| cleaning up | 0.000012 |
+----------------------+----------+
15 rows in set, 1 warning (0.00 sec)

上表所给出的是按照执行顺序排序的各个步骤所花费的时间

那我们想看哪个步骤所花费的时间最多怎么办,用ORDER BY语句排序?很不幸的是show profile语句无法使用ORDER BY子句进行排序

这个时候我们只能通过直接查询它记录在INFORMATION_SCHEMA数据库中的PROFILING表来获取对应信息

使用DESC命令可查看此表的详细信息

mysql> desc information_schema.profiling;
+---------------------+--------------+------+-----+----------+-------+
| Field | Type | Null | Key | Default | Extra |
+---------------------+--------------+------+-----+----------+-------+
| QUERY_ID | int(20) | NO | | 0 | |
| SEQ | int(20) | NO | | 0 | |
| STATE | varchar(30) | NO | | | |
| DURATION | decimal(9,6) | NO | | 0.000000 | |
| CPU_USER | decimal(9,6) | YES | | NULL | |
| CPU_SYSTEM | decimal(9,6) | YES | | NULL | |
| CONTEXT_VOLUNTARY | int(20) | YES | | NULL | |
| CONTEXT_INVOLUNTARY | int(20) | YES | | NULL | |
| BLOCK_OPS_IN | int(20) | YES | | NULL | |
| BLOCK_OPS_OUT | int(20) | YES | | NULL | |
| MESSAGES_SENT | int(20) | YES | | NULL | |
| MESSAGES_RECEIVED | int(20) | YES | | NULL | |
| PAGE_FAULTS_MAJOR | int(20) | YES | | NULL | |
| PAGE_FAULTS_MINOR | int(20) | YES | | NULL | |
| SWAPS | int(20) | YES | | NULL | |
| SOURCE_FUNCTION | varchar(30) | YES | | NULL | |
| SOURCE_FILE | varchar(20) | YES | | NULL | |
| SOURCE_LINE | int(20) | YES | | NULL | |
+---------------------+--------------+------+-----+----------+-------+
18 rows in set (0.00 sec)

好,下面来看一组我格式化输出后的性能分析统计信息,先来看SQL语句

SELECT
STATE,
SUM( DURATION ) AS "Total Time",
ROUND( 100 * SUM( DURATION ) / ( SELECT SUM( DURATION ) FROM information_schema.PROFILING WHERE QUERY_ID = 1 ), 2 ) AS "Percent",
COUNT( * ) AS "Calls",
SUM( DURATION ) / COUNT( * ) AS "R/Call"
FROM
information_schema.PROFILING
WHERE
QUERY_ID = 1
GROUP BY
STATE
ORDER BY
2 DESC;

执行结果

+----------------------+------------+---------+-------+--------------+
| STATE | Total Time | Percent | Calls | R/Call |
+----------------------+------------+---------+-------+--------------+
| Sending data | 0.000652 | 77.53 | 1 | 0.0006520000 |
| starting | 0.000062 | 7.37 | 1 | 0.0000620000 |
| init | 0.000023 | 2.73 | 1 | 0.0000230000 |
| Opening tables | 0.000017 | 2.02 | 1 | 0.0000170000 |
| statistics | 0.000014 | 1.66 | 1 | 0.0000140000 |
| cleaning up | 0.000011 | 1.31 | 1 | 0.0000110000 |
| preparing | 0.000010 | 1.19 | 1 | 0.0000100000 |
| freeing items | 0.000010 | 1.19 | 1 | 0.0000100000 |
| System lock | 0.000008 | 0.95 | 1 | 0.0000080000 |
| checking permissions | 0.000008 | 0.95 | 1 | 0.0000080000 |
| query end | 0.000007 | 0.83 | 1 | 0.0000070000 |
| end | 0.000007 | 0.83 | 1 | 0.0000070000 |
| closing tables | 0.000006 | 0.71 | 1 | 0.0000060000 |
| optimizing | 0.000004 | 0.48 | 1 | 0.0000040000 |
| executing | 0.000002 | 0.24 | 1 | 0.0000020000 |
+----------------------+------------+---------+-------+--------------+
15 rows in set, 2 warnings (0.00 sec)

说明:

STATE是所执行的步骤名

Total Time得到的是当前STATE所执行的总时间

Percent得到的是当前STATE所消耗时间占总时间的百分数(保留两位小数)

Calls是当前操作总共被执行了多少遍

R/Call是对于一个STATE而言,平均每遍执行所消耗的时间

由返回结果我们可以看出,发送数据(Sending data)消耗了最多的时间,占到了总时间的77.53%

0x01 使用performance_schema数据库

performance_schema数据库是自MySQL5.5引入的,在MySQL5.5里面默认关闭,自MySQL5.6开始默认开启

如果你使用的MySQL版本为5.5,可以在my.cnf文件里添加/修改如下语句将其开启

performance_schema=ON

performance_schema是以存储引擎的方式实现的,可以通过如下方法确认:

mysql> SHOW ENGINES\G
*************************** 1. row ***************************
Engine: PERFORMANCE_SCHEMA
Support: YES
Comment: Performance Schema
Transactions: NO
XA: NO
Savepoints: NO

用户不可以创建存储引擎为performance_schema的数据库

但是我们可以像使用普通数据库一样去访问performance_schema

0x00 设置用户纬度

用户纬度就是告诉MySQL去监控哪些用户的性能信息,默认是全部监控

可以通过修改setup_actors表来设置用户纬度,默认如下:

mysql> select * from setup_actors;
+------+------+------+---------+---------+
| HOST | USER | ROLE | ENABLED | HISTORY |
+------+------+------+---------+---------+
| % | % | % | YES | YES |
+------+------+------+---------+---------+
1 row in set (0.00 sec)

0x01 设置事件的消费者类型

事件的消费者类型就是收集到的event信息写入哪些统计表中

可以通过UPDATE setup_consumers表来进行配置,默认如下:

mysql> select * from setup_consumers;
+----------------------------------+---------+
| NAME | ENABLED |
+----------------------------------+---------+
| events_stages_current | NO |
| events_stages_history | NO |
| events_stages_history_long | NO |
| events_statements_current | YES |
| events_statements_history | YES |
| events_statements_history_long | NO |
| events_transactions_current | NO |
| events_transactions_history | NO |
| events_transactions_history_long | NO |
| events_waits_current | NO |
| events_waits_history | NO |
| events_waits_history_long | NO |
| global_instrumentation | YES |
| thread_instrumentation | YES |
| statements_digest | YES |
+----------------------------------+---------+
15 rows in set (0.00 sec)

NAME指的是表名,可以在performance_schema数据库下找到相应的表

ENABLED标识的是是否开启记录

如果想查看那个就使用UPDATE语句更新其值为YES,更新完成后立即生效,但是不会永久生效,什么意思呢,就是重启MySQL服务器后又会变成默认值

想要永久生效需要在my.cnf里设置,格式如下

performance_schema_consumer_/*NAME字段*/=on # on为开启

例如,我想把events_stages_current设置为永久开始,我可以配置:

performance_schema_consumer_events_stages_current=on

注意:

setup_consumers表是具有层级关系的,只要上一层为YES,才会去检查下一层是否开启,如果上一层为NO,下一层即便设置了YES,也不会生效,层级关系如下:

global_instrumentation > thread_instrumentation = statements_digest > events_stages_current = events_statements_current = events_waits_current > events_stages_history = events_statements_history = events_waits_history > events_stages_history_long = events_statements_history_long = events_waits_history_long

0x02 设置监控对象

默认的监控对象是除了mysql,performance_schema和information_schema这三个数据库之外的其他所有数据库中的事件、函数、存储过程、表、触发器

如果想要配置监控对象的话,可以通过配置setup_objects表,默认信息如下:

mysql> select * from setup_objects;
+-------------+--------------------+-------------+---------+-------+
| OBJECT_TYPE | OBJECT_SCHEMA | OBJECT_NAME | ENABLED | TIMED |
+-------------+--------------------+-------------+---------+-------+
| EVENT | mysql | % | NO | NO |
| EVENT | performance_schema | % | NO | NO |
| EVENT | information_schema | % | NO | NO |
| EVENT | % | % | YES | YES |
| FUNCTION | mysql | % | NO | NO |
| FUNCTION | performance_schema | % | NO | NO |
| FUNCTION | information_schema | % | NO | NO |
| FUNCTION | % | % | YES | YES |
| PROCEDURE | mysql | % | NO | NO |
| PROCEDURE | performance_schema | % | NO | NO |
| PROCEDURE | information_schema | % | NO | NO |
| PROCEDURE | % | % | YES | YES |
| TABLE | mysql | % | NO | NO |
| TABLE | performance_schema | % | NO | NO |
| TABLE | information_schema | % | NO | NO |
| TABLE | % | % | YES | YES |
| TRIGGER | mysql | % | NO | NO |
| TRIGGER | performance_schema | % | NO | NO |
| TRIGGER | information_schema | % | NO | NO |
| TRIGGER | % | % | YES | YES |
+-------------+--------------------+-------------+---------+-------+
20 rows in set (0.00 sec)

0x03 设置具体的instrument

要是干说instrument这个确实不是很好理解,这个表是用来设置哪些行为被列入监控的对象,具体什么意思呢,我们在这里渗透一点本篇文章后面的知识

一个SQL语句的执行对于MySQL来说划分为若干阶段,每一个阶段就对应一个instrument,我们可以通过设置setup_instruments表来设置对哪个具体的instrument进行监控

表结构如下:

mysql> desc setup_instruments;
+---------+------------------+------+-----+---------+-------+
| Field | Type | Null | Key | Default | Extra |
+---------+------------------+------+-----+---------+-------+
| NAME | varchar(128) | NO | | NULL | |
| ENABLED | enum('YES','NO') | NO | | NULL | |
| TIMED | enum('YES','NO') | NO | | NULL | |
+---------+------------------+------+-----+---------+-------+

这个表一共有3个字段,NAME就对应了instrument名,ENABLED就对应了是否记录此项,TIMED是是否对此instrument执行所花费的时间进行计时。

如果还不明白,请查看本文后面第0x0A节实现类似profiling的功能,里面有此表操纵选项的具体示例

0x04 查看instance信息

因为部分语句返回结果太多,作为示例,我们使用limit 1子句来限制只输出1条信息

系统打开的文件信息:

mysql> select * from file_instances limit 1\G
*************************** 1. row ***************************
FILE_NAME: /usr/share/mysql/english/errmsg.sys
EVENT_NAME: wait/io/file/sql/ERRMSG
OPEN_COUNT: 0

OPEN_COUNT指的是当前文件被打开过多少次

系统所使用的互斥量信息:

mysql> select * from mutex_instances limit 1\G
*************************** 1. row ***************************
NAME: wait/synch/mutex/mysys/THR_LOCK_heap
OBJECT_INSTANCE_BEGIN: 32111712
LOCKED_BY_THREAD_ID: NULL

LOCKED_BY_THREAD_ID指明了当前哪个线程正在持有mutex,如果没有线程持有则为NULL

系统所使用的读写锁对象信息:

mysql> select * from rwlock_instances limit 1\G
*************************** 1. row ***************************
NAME: wait/synch/rwlock/session/LOCK_srv_session_collection
OBJECT_INSTANCE_BEGIN: 31340088
WRITE_LOCKED_BY_THREAD_ID: NULL
READ_LOCKED_BY_COUNT: 0

此表仅能查看哪个线程持有锁,如果想知道哪个线程在等待锁,需要查询events_waits_current表

活跃会话对象实例:

mysql> select * from socket_instances limit 1\G
*************************** 1. row ***************************
EVENT_NAME: wait/io/socket/sql/server_tcpip_socket
OBJECT_INSTANCE_BEGIN: 58547328
THREAD_ID: 1
SOCKET_ID: 27
IP: ::
PORT: 3306
STATE: ACTIVE

event_name主要包含3类: wait/io/socket/sql/server_unix_socket:服务端unix监听socket wait/io/socket/sql/server_tcpip_socket:服务端tcp监听socket wait/io/socket/sql/client_connection:客户端socket

0x05 查看线程信息

  1. events_waits_current:记录了当前线程等待的事件

  2. events_waits_history:记录了每个线程最近等待的10个事件

  3. events_waits_history_long:记录了最近所有线程产生的10000个事件

  4. events_stages_current:记录了当前线程所处的执行阶段

  5. events_stages_history:记录了当前线程所处的执行阶段10条历史记录

  6. events_stages_history_long:记录了当前线程所处的执行阶段10000条记录

0x06 修改记录数量

在0x04中我们可以观察到,history表一般只记录10条历史记录,history_long表一般也只记录10000条记录,超过这些记录后,新来的覆盖最老的,下面给出修改这个记录数量的方法

这些表的长度,都是通过控制参数来决定的,如下:

mysql> show variables like 'performance_schema%history%size';
+----------------------------------------------------------+-------+
| Variable_name | Value |
+----------------------------------------------------------+-------+
| performance_schema_events_stages_history_long_size | 10000 |
| performance_schema_events_stages_history_size | 10 |
| performance_schema_events_statements_history_long_size | 10000 |
| performance_schema_events_statements_history_size | 10 |
| performance_schema_events_transactions_history_long_size | 10000 |
| performance_schema_events_transactions_history_size | 10 |
| performance_schema_events_waits_history_long_size | 10000 |
| performance_schema_events_waits_history_size | 10 |
+----------------------------------------------------------+-------+

可以通过修改这些变量的值来修改这些表的长度:

我一开始使用SET命令修改events_waits_history表的长度,可以报错,说这是只读变量

mysql> SET @@performance_schema_events_waits_history_size=100;
ERROR 1238 (HY000): Variable 'performance_schema_events_waits_history_size' is a read only variable

对于只读的变量,我们只能在MySQL初始化的时候修改,也就是在my.cnf文件中添加:

[mysqld]
performance_schema_events_waits_history_size=100

修改后重启MySQL服务,然后登陆MySQL,使用命令:

mysql> show variables like 'performance_schema_events_waits_history_size';
+----------------------------------------------+-------+
| Variable_name | Value |
+----------------------------------------------+-------+
| performance_schema_events_waits_history_size | 100 |
+----------------------------------------------+-------+

发现已经修改成功

0x07 查看Connection信息

用户连接信息:

mysql> select * from users;
+------+---------------------+-------------------+
| USER | CURRENT_CONNECTIONS | TOTAL_CONNECTIONS |
+------+---------------------+-------------------+
| NULL | 25 | 29 |
| root | 1 | 1 |
+------+---------------------+-------------------+

CURRENT_CONNECTIONS:当前连接数

TOTAL_CONNECTIONS:总连接数

主机连接信息:

mysql> select * from hosts;
+-----------+---------------------+-------------------+
| HOST | CURRENT_CONNECTIONS | TOTAL_CONNECTIONS |
+-----------+---------------------+-------------------+
| NULL | 25 | 29 |
| localhost | 1 | 1 |
+-----------+---------------------+-------------------+

用户主机连接信息:

mysql> select * from accounts;
+------+-----------+---------------------+-------------------+
| USER | HOST | CURRENT_CONNECTIONS | TOTAL_CONNECTIONS |
+------+-----------+---------------------+-------------------+
| NULL | NULL | 25 | 29 |
| root | localhost | 1 | 1 |
+------+-----------+---------------------+-------------------+

0x08 查看执行的SQL语句信息

主要分布在如下三个表里:

  1. events_statements_current

  2. events_statements_history

  3. events_statements_history_long

表的结构定义如下:

CREATE TABLE `events_statements_current` (
`THREAD_ID` bigint(20) unsigned NOT NULL COMMENT '线程ID',
`EVENT_ID` bigint(20) unsigned NOT NULL COMMENT '事件ID',
`END_EVENT_ID` bigint(20) unsigned DEFAULT NULL COMMENT '结束事件ID',
`EVENT_NAME` varchar(128) NOT NULL COMMENT '事件名称',
`SOURCE` varchar(64) DEFAULT NULL COMMENT '源码位置',
`TIMER_START` bigint(20) unsigned DEFAULT NULL COMMENT '事件开始时间(皮秒)',
`TIMER_END` bigint(20) unsigned DEFAULT NULL COMMENT '事件结束结束时间(皮秒)',
`TIMER_WAIT` bigint(20) unsigned DEFAULT NULL COMMENT '事件等待时间(皮秒)',
`LOCK_TIME` bigint(20) unsigned NOT NULL COMMENT '锁时间',
`SQL_TEXT` longtext COMMENT '记录SQL语句',
`DIGEST` varchar(32) DEFAULT NULL COMMENT '对SQL_TEXT做MD5产生的32位字符串',
`DIGEST_TEXT` longtext COMMENT '将语句中值部分用问号代替,用于SQL语句归类',
`CURRENT_SCHEMA` varchar(64) DEFAULT NULL COMMENT '默认的数据库名',
`OBJECT_TYPE` varchar(64) DEFAULT NULL COMMENT '保留字段',
`OBJECT_SCHEMA` varchar(64) DEFAULT NULL COMMENT '保留字段',
`OBJECT_NAME` varchar(64) DEFAULT NULL COMMENT '保留字段',
`OBJECT_INSTANCE_BEGIN` bigint(20) unsigned DEFAULT NULL COMMENT '内存地址',
`MYSQL_ERRNO` int(11) DEFAULT NULL COMMENT '',
`RETURNED_SQLSTATE` varchar(5) DEFAULT NULL COMMENT '',
`MESSAGE_TEXT` varchar(128) DEFAULT NULL COMMENT '信息',
`ERRORS` bigint(20) unsigned NOT NULL COMMENT '错误数目',
`WARNINGS` bigint(20) unsigned NOT NULL COMMENT '警告数目',
`ROWS_AFFECTED` bigint(20) unsigned NOT NULL COMMENT '影响的数目',
`ROWS_SENT` bigint(20) unsigned NOT NULL COMMENT '返回的记录数',
`ROWS_EXAMINED` bigint(20) unsigned NOT NULL COMMENT '读取扫描的记录数目',
`CREATED_TMP_DISK_TABLES` bigint(20) unsigned NOT NULL COMMENT '创建磁盘临时表数目',
`CREATED_TMP_TABLES` bigint(20) unsigned NOT NULL COMMENT '创建临时表数目',
`SELECT_FULL_JOIN` bigint(20) unsigned NOT NULL COMMENT 'join时,第一个表为全表扫描的数目',
`SELECT_FULL_RANGE_JOIN` bigint(20) unsigned NOT NULL COMMENT '引用表采用range方式扫描的数目',
`SELECT_RANGE` bigint(20) unsigned NOT NULL COMMENT 'join时,第一个表采用range方式扫描的数目',
`SELECT_RANGE_CHECK` bigint(20) unsigned NOT NULL COMMENT '',
`SELECT_SCAN` bigint(20) unsigned NOT NULL COMMENT 'join时,第一个表位全表扫描的数目',
`SORT_MERGE_PASSES` bigint(20) unsigned NOT NULL COMMENT '',
`SORT_RANGE` bigint(20) unsigned NOT NULL COMMENT '范围排序数目',
`SORT_ROWS` bigint(20) unsigned NOT NULL COMMENT '排序的记录数目',
`SORT_SCAN` bigint(20) unsigned NOT NULL COMMENT '全表排序数目',
`NO_INDEX_USED` bigint(20) unsigned NOT NULL COMMENT '没有使用索引数目',
`NO_GOOD_INDEX_USED` bigint(20) unsigned NOT NULL COMMENT '',
`NESTING_EVENT_ID` bigint(20) unsigned DEFAULT NULL COMMENT '该事件对应的父事件ID',
`NESTING_EVENT_TYPE` enum('STATEMENT','STAGE','WAIT') DEFAULT NULL COMMENT '父事件类型(STATEMENT, STAGE, WAIT)'
) ENGINE=PERFORMANCE_SCHEMA DEFAULT CHARSET=utf8

0x09 获取概要信息

概要信息主要是几个Summary表,在此只说其中的一个,其余的可参考MySQL官方手册

events_statements_summary_by_digest表

此表按照事件的语句进行聚合,表结构如下:

CREATE TABLE `events_statements_summary_by_digest` (
`SCHEMA_NAME` varchar(64) DEFAULT NULL COMMENT '库名',
`DIGEST` varchar(32) DEFAULT NULL COMMENT '对SQL_TEXT做MD5产生的32位字符串。如果为consumer表中没有打开statement_digest选项,则为NULL',
`DIGEST_TEXT` longtext COMMENT '将语句中值部分用问号代替,用于SQL语句归类。如果为consumer表中没有打开statement_digest选项,则为NULL。',
`COUNT_STAR` bigint(20) unsigned NOT NULL COMMENT '事件计数',
`SUM_TIMER_WAIT` bigint(20) unsigned NOT NULL COMMENT '总的等待时间',
`MIN_TIMER_WAIT` bigint(20) unsigned NOT NULL COMMENT '最小等待时间',
`AVG_TIMER_WAIT` bigint(20) unsigned NOT NULL COMMENT '平均等待时间',
`MAX_TIMER_WAIT` bigint(20) unsigned NOT NULL COMMENT '最大等待时间',
`SUM_LOCK_TIME` bigint(20) unsigned NOT NULL COMMENT '锁时间总时长',
`SUM_ERRORS` bigint(20) unsigned NOT NULL COMMENT '错误数的总',
`SUM_WARNINGS` bigint(20) unsigned NOT NULL COMMENT '警告的总数',
`SUM_ROWS_AFFECTED` bigint(20) unsigned NOT NULL COMMENT '影响的总数目',
`SUM_ROWS_SENT` bigint(20) unsigned NOT NULL COMMENT '返回总数目',
`SUM_ROWS_EXAMINED` bigint(20) unsigned NOT NULL COMMENT '总的扫描的数目',
`SUM_CREATED_TMP_DISK_TABLES` bigint(20) unsigned NOT NULL COMMENT '创建磁盘临时表的总数目',
`SUM_CREATED_TMP_TABLES` bigint(20) unsigned NOT NULL COMMENT '创建临时表的总数目',
`SUM_SELECT_FULL_JOIN` bigint(20) unsigned NOT NULL COMMENT '第一个表全表扫描的总数目',
`SUM_SELECT_FULL_RANGE_JOIN` bigint(20) unsigned NOT NULL COMMENT '总的采用range方式扫描的数目',
`SUM_SELECT_RANGE` bigint(20) unsigned NOT NULL COMMENT '第一个表采用range方式扫描的总数目',
`SUM_SELECT_RANGE_CHECK` bigint(20) unsigned NOT NULL COMMENT '',
`SUM_SELECT_SCAN` bigint(20) unsigned NOT NULL COMMENT '第一个表位全表扫描的总数目',
`SUM_SORT_MERGE_PASSES` bigint(20) unsigned NOT NULL COMMENT '',
`SUM_SORT_RANGE` bigint(20) unsigned NOT NULL COMMENT '范围排序总数',
`SUM_SORT_ROWS` bigint(20) unsigned NOT NULL COMMENT '排序的记录总数目',
`SUM_SORT_SCAN` bigint(20) unsigned NOT NULL COMMENT '第一个表排序扫描总数目',
`SUM_NO_INDEX_USED` bigint(20) unsigned NOT NULL COMMENT '没有使用索引总数',
`SUM_NO_GOOD_INDEX_USED` bigint(20) unsigned NOT NULL COMMENT '',
`FIRST_SEEN` timestamp NOT NULL DEFAULT '0000-00-00 00:00:00' COMMENT '第一次执行时间',
`LAST_SEEN` timestamp NOT NULL DEFAULT '0000-00-00 00:00:00' COMMENT '最后一次执行时间'
) ENGINE=PERFORMANCE_SCHEMA DEFAULT CHARSET=utf8

下面是有关此表相对常用的几个统计信息:

统计哪个SQL语句执行的次数最多:

SELECT
SCHEMA_NAME, # 数据库名
DIGEST_TEXT, # SQL语句
COUNT_STAR, # 总执行次数
SUM_ROWS_SENT, # 返回总数目
SUM_ROWS_EXAMINED, # 总的扫描的数目
SUM_ROWS_AFFECTED, # 影响的总条数
FIRST_SEEN, # 第一次执行
LAST_SEEN # 最后一次执行
FROM
events_statements_summary_by_digest
ORDER BY
COUNT_STAR DESC
LIMIT 1;

TL;DR

写完上面的这个语句,我又顺手写了另外一个语句用来实现相同的功能

SELECT
SCHEMA_NAME,# 数据库名
DIGEST_TEXT,# SQL语句
COUNT_STAR,# 总执行次数
SUM_ROWS_SENT,# 返回总数目
SUM_ROWS_EXAMINED,# 总的扫描的数目
SUM_ROWS_AFFECTED,# 影响的总条数
FIRST_SEEN,# 第一次执行
LAST_SEEN # 最后一次执行
FROM
events_statements_summary_by_digest
WHERE
COUNT_STAR = ( SELECT MAX( COUNT_STAR ) FROM events_statements_summary_by_digest )

这个是用WHERE子查询实现的,然后我使用下列语句比较两者性能:

SELECT
DIGEST_TEXT, AVG_TIMER_WAIT, SUM_ROWS_EXAMINED
FROM
events_statements_summary_by_digest
WHERE
DIGEST_TEXT LIKE 'SELECT SCHEMA_NAME %'

返回结果如下:

*************************** 1. row ***************************
DIGEST_TEXT: __语句一__
AVG_TIMER_WAIT: 925939000
SUM_ROWS_EXAMINED: 141
*************************** 2. row ***************************
DIGEST_TEXT: __WHERE子查询语句__
AVG_TIMER_WAIT: 1414154000
SUM_ROWS_EXAMINED: 318

使用where子查询所消耗的时间大约是使用order by然后limit 1查询的1.527倍

使用where子查询所查询的行数大约是使用order by然后limit 1查询的2.255倍

得出结论:语句一查询效率快一些

我想了想也是,如果使用order by的话,MySQL先对数据进行排序,假设说他使用的是归并排序的话,整个语句的时间复杂度为O(n*log(n)),如果使用where子查询的话,先进行子查询,然后依据子查询结果再进行查询,最坏情况下应该是O(n^2)的时间复杂度

统计哪个SQL语句平均响应时间最长:

SELECT
SCHEMA_NAME,
DIGEST_TEXT,
COUNT_STAR,
AVG_TIMER_WAIT, # 平均响应时间
SUM_ROWS_SENT,
SUM_ROWS_EXAMINED,
FIRST_SEEN,
LAST_SEEN
FROM
events_statements_summary_by_digest
ORDER BY
AVG_TIMER_WAIT DESC
LIMIT 1;

0x0A 实现类似profiling的功能:

上文中也描述过了,profiling可以给我们单条SQL语句每个执行步骤所花费的时间,我们用performance_schema也来实现相同的功能

在profiling功能中,我们使用show profiles;语句来获取执行SQL语句的Query ID,在performance_schema数据库中,我们可以通过查询events_statements_history_long表(默认不开启,需手动)来获取对应的Query ID

SELECT
event_id,
sql_text
FROM
events_statements_history_long
WHERE
NOT isnull( sql_text );

输出结果如下:

+----------+--------------------------------+
| event_id | sql_text |
+----------+--------------------------------+
| 119 | select * from City limit 5 |
| 123 | select * from Country limit 5 |
+----------+--------------------------------+

假设现在查询event_id为119的各阶段所花费的时间,可以通过查询events_stages_history_long来实现,其中刚刚通过events_statements_history_long所获取的event_id对应events_stages_history_long表中的nesting_event_id

SELECT
event_id,
event_name, # 就是show profiling里面的Status
timer_end - timer_start # 结束时间-开始时间 = 所花费时间
FROM
events_stages_history_long
WHERE
nesting_event_id = 119;

输出结果如下:

+----------+--------------------------------+-------------------------+
| event_id | event_name | timer_end - timer_start |
+----------+--------------------------------+-------------------------+
| 508 | stage/sql/starting | 87830000 |
| 509 | stage/sql/checking permissions | 8082000 |
| 510 | stage/sql/Opening tables | 21709000 |
| 511 | stage/sql/init | 22506000 |
| 512 | stage/sql/System lock | 10153000 |
| 514 | stage/sql/optimizing | 5055000 |
| 515 | stage/sql/statistics | 17608000 |
| 516 | stage/sql/preparing | 11901000 |
| 517 | stage/sql/executing | 57258000 |
| 518 | stage/sql/Sending data | 82455000 |
| 520 | stage/sql/end | 4452000 |
| 521 | stage/sql/query end | 9026000 |
| 522 | stage/sql/closing tables | 8405000 |
| 523 | stage/sql/freeing items | 16851000 |
| 524 | stage/sql/cleaning up | 1022000 |
+----------+--------------------------------+-------------------------+

如果在你的电脑上查出来的结果是Empty Set:

  1. 使用语句select * from events_stages_history_long;,如果有结果,那就说明是你nesting_event_id 弄错了,如果没有结果,请看第二步

  2. 这就说明你在setup_instrument 表中没有设置监控相应的instrument,使用语句:

    update setup_instruments set enabled='YES', timed='YES' where name like 'stage%';
  3. 成功执行之后,重新进行相关查询,然后在表events_statements_history_long查询你刚刚执行的SQL的event id,然后再重新查询events_stages_history_long表,此时就应该可以看到和我一样的输出结果了

  4. 步骤2-3可以参考本文第0x03小节设置具体的instrument

0x02 对比

  • 操作复杂度:SHOW PROFILE操作起来相对简单

  • 功能:performance_schema数据库提供了大而全的功能,可以通过多个维度来衡量各个指标

  • MySQL最低版本,SHOW PROFILE ≥ 5.1,performance_schema ≥ 5.5