如何正确理解 RT 并监控 MySQL 的响应时间

一、前言

响应时间（response time 简称 RT）是从系统接收请求开始到返回响应之间的时间跨度，是一项极其重要的性能指标。它可以从侧面反映系统的整体吞吐量，也是业务请求（比如 sql 请求）的性能好坏的判断依据。

举个例子 A 要从杭州坐飞机到北京机场，经历如下：

1. 从公司到萧山机场 40min
2. 机场安检，候机，登机 40min
3. 飞机飞行  耗时 100min
4. `机落地，打的到望京  耗时40min
5. RT= 40 + 40 + 100 + 40 =220min

其中真正的 ‘执行’ 时间就飞机飞行的时间（100min+40+40），其他安检、候机、堵车的都是等待时间。

RT = 等待时间 + 执行时间

假如到机场的过程中发生堵车，或者空中管制导致候机时间延长，整体的 RT 也会变长，但是飞机飞行时间是相对一定的。

从技术的角度来看 SQL 的请求路径：

app <---->（网络建立连接，data 传输）<----> proxy <---->（网络建立连接，data 传输）<----> mysql（执行）

因为网络问题丢包，重传等导致数据传输时间增加，进而导致总体的 RT 时间增加 ，还有常见的案例 app 服务器 cpu 飙高导致程序执行的速度变慢，JAVA 程序 GC 等因素也会导致 RT 升高。所以说 SQL 慢，其实 RT 就会高。但是反过来 RT 高，不一定是 SQL 慢的原因。如果是开发同学遇到监控尤其是 trace 系统发现某个接口慢了，并不一定是 SQL 慢。

重点：不要把 trace 系统中的监控 rt 直接当做 db 的执行时间

参考案例：Strace 解决性能问题案例一则

二、如何监控

前面说了 RT 的定义以及它所代表意义。接下来我们看看如何监控数据库的 RT ，现有的方式主要有两种。

2.1 tcprstat

tcprstat 是 Percona 基于 libpcap 研发的工具，是通过测量 TCP 的 request 和 response 所需的时间间隔，适用于一问一答式协议类型的处理。通常用来监测 MySQL 响应时间，或者说是请求在服务器端的处理时间，其输出结果包括了响应时间相关的统计值，用来诊断服务器端性能状况。

举个例子：

其输出结果包括了时间戳，以及响应时间的最大值、均值、方差等信息，输出信息可以通过 -f 参数进行定制，其中响应时间的单位为微妙。

其中对我们比较重要的是：

count：此间隔内处理完成的请求数量。

avg：此间隔内所有完成的请求，响应的平均时间。

95_avg ：此间隔内，95% 的请求量的平均响应时间，单位微妙，该值较能体现 MySQL Server 的查询平均响应时间。

如果我们只需要输出 count, 平均时间， 95_avg , 99_avg 则可以用如下命令。tcprstat -p 3312 -t 1 -n 0 -l ip_address -f ‘%T\t%n\t%a\t%95a\t%99a\n’

关于 -f 的参数解释如下，读者朋友可以根据需要来调整输出

如果执行 tcprstat 遇到如下问题：

# tcprstat -p 3312 -t 1 -n 5
pcap: SIOCGIFFLAGS: bonding_masters: No such device

可以通过指定本地 ip -l local_ip 来解决。

2.2 MySQL 插件

Percona Server 提供一个叫做响应时间区间的功能，将 sql 耗时在指定区间的请求次数和总共的执行时间记录到表里面。其中时间区间跨度由 query_response_time_range_base 控制。

常用的区间范围为：(0, 0.000001], (0.000001, 0.000010],(0.000010,0.000100],(0.000100,0.001000],(0.001000, 0.010000], (0.010000,0.100000],(0.100000,1.000000],(1,10] 。

从 MySQL 5.6 开始以插件形式安装：

INSTALL PLUGIN QUERY_RESPONSE_TIME_AUDIT SONAME 'query_response_time.so';
INSTALL PLUGIN QUERY_RESPONSE_TIME SONAME 'query_response_time.so';
INSTALL PLUGIN QUERY_RESPONSE_TIME_READ SONAME 'query_response_time.so';
INSTALL PLUGIN QUERY_RESPONSE_TIME_WRITE SONAME 'query_response_time.so';

然后通过 show plugins 命令检查插件是否安装成功。

> SHOW PLUGINS;
......
| QUERY_RESPONSE_TIME         | ACTIVE   | INFORMATION SCHEMA | query_response_time.so | GPL     |
| QUERY_RESPONSE_TIME_AUDIT   | ACTIVE   | AUDIT              | query_response_time.so | GPL     |
| QUERY_RESPONSE_TIME_READ    | ACTIVE   | INFORMATION SCHEMA | query_response_time.so | GPL     |
| QUERY_RESPONSE_TIME_WRITE   | ACTIVE   | INFORMATION SCHEMA | query_response_time.so | GPL     |
+-----------------------------+----------+--------------------+------------------------+---------

安装完成之后 在 INFORMATION_SCHEMA 生成三张表

QUERY_RESPONSE_TIME_WRITE 记录所有写请求的响应时间分布
QUERY_RESPONSE_TIME_READ 记录所有读请求的响应时间分布
QUERY_RESPONSE_TIME 可以认为是所有请求的响应时间分布。

查看 QUERY_RESPONSE_TIME 的内容

查询结果中 717 个 sql 请求耗时在 (0, 0.000001] 之间。47898 个 sql 请求的耗时在 (0.000001, 0.000010]，总耗时 0.29 秒，其他以此类推。需要注意的是 count 和total是累计值，监控的时候需要取后值减前值除以采样的时间间隔。

如何开启响应时间统计

在命令行中执行

SET GLOBAL query_response_time_stats = 1 ;

在 my.cnf 中

query_response_time_stats = 1

重置（将数据清零）三张表的统计值

SET GLOBAL query_response_time_flush=‘ON’;

常用的 sql

INFORMATION_SCHEMA [RW][TEST:qa_single_0:3312] 11:50:44
>SELECT c.count, c.time, (SELECT SUM(a.count) FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME as a WHERE a.count != 0) as query_count, (SELECT COUNT(*)     FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME as b WHERE b.count != 0) as not_zero_region_count, (SELECT COUNT(*)     FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME) as region_count FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME as c WHERE c.count > 0;
+-------+----------------+-------------+-----------------------+--------------+
| count | time           | query_count | not_zero_region_count | region_count |
+-------+----------------+-------------+-----------------------+--------------+
|     1 |       0.000001 |       71370 |                     7 |           14 |
|    86 |       0.000010 |       71370 |                     7 |           14 |
| 47375 |       0.000100 |       71370 |                     7 |           14 |
| 23404 |       0.001000 |       71370 |                     7 |           14 |
|   423 |       0.010000 |       71370 |                     7 |           14 |
|    79 |       0.100000 |       71370 |                     7 |           14 |
|     2 |       1.000000 |       71370 |                     7 |           14 |
+-------+----------------+-------------+-----------------------+--------------+
7 rows in set (0.00 sec)

通过监控脚本获取响应时间的数据在 grafna 展示的结果如下：

其他更详细的介绍可以去查阅 Percona 的官方文档。

三、小结

本文总结介绍 RT 在技术体系中的含义，以及介绍两种监控 MySQL 响应时间的方法。如果有其他更好的方式方法，欢迎读者朋友一起讨论。