一条慢查询会造成什么后果?刚开始使用MySQL的开发、初级DBA 以为就是简单的查询变慢些,体验稍微有一丢丢影响,殊不知,慢查询的破坏力远不止如此。业务高峰期,这头SQL还没处理完,大量新的查询请求堆积,CPU使用率长时间居高不下,甚至高达100%,系统直接崩溃……慢查询这样的黑天鹅事件,可能直接影响业务稳定性,造成巨大经济损失。
慢查询,字面理解就是查询慢的意思,比如某类查询,正常情况下消耗100ms 左右,异常时可能飙升到 15s。为定位慢查询问题,我们可以按如下几个步骤进行:
一、开启慢日志;
二、使用慢日志查询分析管理工具;
三、基于已有的慢日志分析,对系统本身做优化(如查询语句或表结构设计方面)。
启用慢日志,定位异常
慢日志默认情况下时不开启的,如果需要对SQL做优化,可以开启这个功能。登陆 MySQL 后,执行如下 SQL 语句即可开启慢日志(这里以MySQL 5.7.33 为例 ,其它版本基本通用):
SET GLOBAL slow_query_log = 'ON';
-- 未使用索引的查询也认为是一个可能的慢查询
set global log_queries_not_using_indexes = 'ON';
一般情况下,MySQL 慢日志位于 /var/lib/mysql/<host-name>-slow.log,我们可以模拟一个慢查询,然后即可看到慢日志记录产生:
-- 手动触发一个慢查询:MySQL默认认为,一个大于 10s 的查询就是慢查询
SELECT sleep(11);
看下慢查询日志:
$ sudo cat /var/lib/mysql/ubt-server-slow.log /usr/sbin/mysqld, Version: 5.7.33-0ubuntu0.18.04.1 ((Ubuntu)). started with: Tcp port: 3306 Unix socket: /var/run/mysqld/mysqld.sock # Time: 2021-03-12T08:52:54.227174Z # User@Host: df-test[df-test] @ [10.100.64.118] Id: 2 # Query_time: 11.000551 Lock_time: 0.000000 Rows_sent: 1 Rows_examined: 0 use number1; SET timestamp=1615539174; select sleep(11);
从该日志中,我们能看到如下几个信息(根据不同的 MySQL 版本或者配置,这些信息可能有增减):
- 产生时间:2021-03-12T08:52:54.227174Z
- 来源:df-test[df-test] @ [10.100.64.118],即用户 df-test 在10.100.64.118 这个机器上执行了这个查询
- 查询统计:如消耗的时间,发送/接收的行数
- 具体的 SQL 语句
从这些信息中,我们可以比较清晰地知道这个慢查询的来龙去脉,比较精确地定位具体的业务代码。但这里有个问题,为保障MySQL数据库安全,MySQL要求只有登录到具体服务器才能看到慢查询日志详情,这直接影响到对异常出现时的处理效率,拖累异常地位、分析和解决的进度。
除开启系统自带的慢日志之外,还有什么有效的方式能让开发人员快速、直接且准确地解决这个问题?
使用MySQL 慢日志分析工具
常用的对慢SQL做优化的分析工具有:mysqldumpslow、mysqlsla、mysql-explain-slow-log、mysql-log-filter、myprofi。
这里以mysqldumpslow和mysql-log-filter为例。
01 mysqldumpslow
mysqldumpslow是官方提供的慢查询日志分析工具。主要功能包括统计不同慢 sql 的
- 出现次数(Count)
- 执行耗费的平均时间和累计总耗费时间(Time)
- 等待锁耗费的时间(Lock)
- 发送给客户端的行总数(Rows)
- 扫描的行总数(Rows)
- 用户以及 SQL 语句本身(抽象了一下格式,比如 limit 1, 20 用 limit N,N 表示)
可参考:《4.6.9 mysqldumpslow-汇总慢查询日志文件》
https://dev.mysql.com/doc/refman/8.0/en/mysqldumpslow.html
02 mysql-log-filter
google code 上找到的一个分析工具,提供了 python 和 php 两种可执行的脚本。基本功能比官方的 mysqldumpslow 多了查询时间的统计信息(平均、最大、累计),其他类似。特色功能除了统计信息外,针对输出内容做了排版和格式化,保证整体输出的简洁。推荐给喜欢简洁报表的朋友。
可参考:
http://code.google.com/p/mysql-log-filter/
其他几款工具,这里就不再赘述,有兴趣的朋友可以直接从网上搜一下。上面介绍的这些工具,多多少少会有一些使用上的小问题,要么数据缺失,要么配置麻烦,诸如此类。下面介绍一下一站式数据监测云平台(DataFlux) 的解决方案。
03 DataFlux方案
如前所述,慢日志具有很大的破坏力,为进一步实现MySQL 数据库性能优化,我们需要解决如下几个问题:
- 数据采集
- 数据解析
- 数据存储
- 数据展示以及查询
在 DataFlux 中有专用于各种数据采集的工具——DataKit。针对 MySQL,它提供了各种 MySQL 日志的采集能力。这里我们介绍下 DataKit 采集器在 Linux 平台的基本使用。
首先,我们登录DataFlux官网注册并登录会员账号,接着可按照下图(控制台-管理-数据网关),或参考链接2找到并安装DataKit。
参考链接:
1. DataFlux官网:https://www.dataflux.cn/
2.《DataKit安装》:https://help.dataflux.cn/doc/0c6ebce225784bd2ad994d5f89c5dbc89e025792#toc34
安装好 DataKit 后,在 /usr/local/cloudcare/dataflux/datakit/conf.d/log/ 目录下,复制一份 MySQL 日志采集配置
$ sudo cp mysqlog.conf.sample mysqlog.conf 编辑 mysqlog.conf: [[inputs.tailf]]
# 填写各种 MySQL 日志的文件路径,不同版本可能不同
# 注意,这里只支持文本文件。我们这里使用的版本是 MySQL 5.7.33 logfiles = [
"/var/lib/mysql/*.log",
"/var/log/mysql/mysql.log",
"/var/log/mysql/error.log",
] source = "mysqlog" # 指定服务名
service = "mysqlog" # 专用的日志解析脚本(DataKit 已经内置了)
pipeline = "mysql.p" [inputs.tailf.tags]
# 这里可以添加一些标签,比如:
biz = "订单系统" # 省略其它默认配置...
至此,MySQL 的日志采集就配置好了,重新启动一下 DataKit 的即可(数据需要稍等一会才能在 Dataflux 平台看到)
参考链接:《DataKit不同系统的重启方式》
https://help.dataflux.cn/doc/0c6ebce225784bd2ad994d5f89c5dbc89e025792#toc27
接下来,我们就能在 DataFlux 平台看到对应的日志了:
从图中我们可以看到,SQL 的执行时间(query_time)已经提取出来了,就是上文慢日志中看到的时间。沿着这条日志,点进去,即可看到日志详情:
从日志详情图中,我们可以看到红框标记的慢查询 SQL 语句,另外还有其它提取出来的日志信息,比如查询时间、来源、服务器主机名、请求发送的数据行数等信息。
除此之外,我们在拉出来的日志详情中,还可看到当前这台主机在慢日志产生的那个时间点附近(红色虚竖线)的资源占用情况(诸如 CPU、内存、磁盘、网络等信息),在一定程度上能帮助开发人员更好的解决问题。
至此,我们解决了 MySQL 慢日志的采集、解析以及展示问题。现在数据已经有了,开发人员就能方便的在网页上找到对应的慢查询日志,并且综合 MySQL 服务器的整体资源占用情况,给出更加合理的解决方案。
以上便是今天我们针对MySQL慢日志查询问题,提供的几种解决办法。在实际应用过程中,我们还是要多尝试不同维度的解决方案,并结合自身所处行业、业务等特点,挑选适合自己和团队使用的数据库分析工具,保障系统和业务的稳定。