阿里云-云小站(无限量代金券发放中)
【腾讯云】云服务器、云数据库、COS、CDN、短信等热卖云产品特惠抢购

MySQL慢查询功能详解

432次阅读
没有评论

共计 9796 个字符,预计需要花费 25 分钟才能阅读完成。

有人的地方就有江湖,数据库也是,sql 优化这个问题,任重道远,我们总是禁不住有烂 sql。怎么办呢,还好各大数据库都有相关烂 sql 的收集功能,而 MySQL 的慢查询收集也是异曲同工,配合分析 sql 的执行计划,这个优化就有了搞头了。

开启 MySQL 慢查询日志

1. 查看当前慢查询设置情况

# 查看慢查询时间,默认 10s,建议降到 1s 或以下,
mysql> show variables like “long_query_time”;
+—————–+———-+
| Variable_name  | Value    |
+—————–+———-+
| long_query_time | 1.000000 |
+—————–+———-+
1 row in set (0.00 sec)
# 查看慢查询配置情况
mysql> show variables like “%slow%”;
+———————————–+———————-+
| Variable_name                    | Value                |
+———————————–+———————-+
| log_slow_admin_statements        | OFF                  |
| log_slow_filter                  |                      |
| log_slow_rate_limit              | 1                    |
| log_slow_rate_type                | session              |
| log_slow_slave_statements        | OFF                  |
| log_slow_sp_statements            | ON                  |
| log_slow_verbosity                |                      |
| max_slowlog_files                | 0                    |
| max_slowlog_size                  | 0                    |
| slow_launch_time                  | 2                    |
| slow_query_log                    | ON                  |
| slow_query_log_always_write_time  | 10.000000            |
| slow_query_log_file              | /tmp/slow_querys.log |
| slow_query_log_use_global_control |                      |
+———————————–+———————-+
14 rows in set (0.01 sec)

其中,slow_query_log 的值是 on 就是已开启功能了。

2. 如何开启慢查询功能
方法一:在服务器上找到 mysql 的配置文件 my.cnf , 然后再 mysqld 模块里追加一下内容,这样的好处是会一直生效,不好就是需要重启 mysql 进程。

vim my.cnf
[mysqld]
slow_query_log = ON
# 定义慢查询日志的路径
slow_query_log_file = /tmp/slow_querys.log
# 定义查过多少秒的查询算是慢查询,我这里定义的是 1 秒,5.6 之后允许设置少于 1 秒,例如 0.1 秒
long_query_time = 1
# 用来设置是否记录没有使用索引的查询到慢查询记录, 默认关闭, 看需求开启, 会产生很多日志, 可动态修改
#log-queries-not-using-indexes
管理指令也会被记录到慢查询。比如 OPTIMEZE TABLE, ALTER TABLE, 默认关闭, 看需求开启, 会产生很多日志, 可动态修改
#log-slow-admin-statements

然后重启 mysql 服务器即可,这是通过一下命令看一下慢查询日志的情况:

tail -f /tmp/slow_querys.log

方法二:通过修改 mysql 的全局变量来处理,这样做的好处是,不用重启 mysql 服务器,登陆到 mysql 上执行一下 sql 脚本即可,不过重启后就失效了。

# 开启慢查询功能,1 是开启,0 是关闭
mysql> set global slow_query_log=1;
# 定义查过多少秒的查询算是慢查询,我这里定义的是 1 秒,5.6 之后允许设置少于 1 秒,例如 0.1 秒
mysql> set global long_query_time=1;
# 定义慢查询日志的路径
mysql> set global slow_query_log_file=’/tmp/slow_querys.log’;
# 关闭功能:set global slow_query_log=0;
然后通过一下命令查看是否成功
mysql> show variables like ‘long%’;
mysql> show variables like ‘slow%’;
# 设置慢查询记录到表中
#set global log_output=’TABLE’;

当然了,你也可以两者合一,一方面不用重启 mysql 进程就能生效,另一方面也不用怕重启后参数失效,效果也是一致的。

特别要注意的是 long_query_time 的设置,5.6 之后支持设置低于 0.1 秒,所以记录的详细程度,就看你自己的需求,数据库容量比较大的,超过 0.1 秒还是比较多,所以就变得有点不合理了。

慢查询日志的记录定义

直接查看 mysql 的慢查询日志分析,比如我们可以 tail -f  slow_query.log 查看里面的内容

tail -f  slow_query.log
# Time: 110107 16:22:11
# User@Host: root[root] @ localhost []
# Query_time: 9.869362 Lock_time: 0.000035 Rows_sent: 1 Rows_examined: 6261774
SET timestamp=1294388531;
select count(*) from ep_friends;

字段意义解析:

第一行,SQL 查询执行的时间
第二行, 执行 SQL 查询的连接信息,用户和连接 IP
第三行, 记录了一些我们比较有用的信息,如下解析
    Query_time, 这条 SQL 执行的时间, 越长则越慢
    Lock_time, 在 MySQL 服务器阶段(不是在存储引擎阶段) 等待表锁时间
    Rows_sent, 查询返回的行数
    Rows_examined, 查询检查的行数,越长就当然越费时间

第四行, 设置时间戳,没有实际意义,只是和第一行对应执行时间。

第五行及后面所有行(第二个# Time: 之前), 执行的 sql 语句记录信息,因为 sql 可能会很长。

分析慢查询的软件

虽然慢查询日志已经够清晰,但是往往我们的日志记录到的不是只有一条 sql,可能有很多很多条,如果不加以统计,估计要看到猴年马月,这个时候就需要做统计分析了。

方法一:使用 mysql 程序自带的 mysqldumpslow 命令分析,例如:
mysqldumpslow -s c -t 10 /tmp/slow-log
这会输出记录次数最多的 10 条 SQL 语句,得出的结果和上面一般慢查询记录的格式没什么太大差别,这里就不展开来详细解析了。

参数解析:
-s:是表示按照何种方式排序,子参数如下:

    c、t、l、r:分别是按照记录次数、时间、查询时间、返回的记录数来排序,

    ac、at、al、ar:表示相应的倒叙;

-t:返回前面多少条的数据,这里意思就是返回 10 条数据了(也可以说是前十)

-g:后边可以写一个正则匹配模式,大小写不敏感的,比如:
    /path/mysqldumpslow -s r -t 10 /tmp/slow-log,得到返回记录集最多的 10 个查询。
    /path/mysqldumpslow -s t -t 10 -g“left join”/tmp/slow-log,得到按照时间排序的前 10 条里面含有左连接的查询语句。

方法二:使用 pt(Percona Toolkit)工具的 pt-query-digest 进行统计分析。这个是由 Percona 公司出品的一个用 perl 编写的脚本,只有安装上 pt 工具集才会存在,有兴趣的朋友就要先安装 pt 工具了。直接分析慢查询文件,执行如下:

pt-query-digest slow_querys.log >t.txt

因为记录里还是可能有很多 sql 在,看起来还是费劲,所以建议输出到文件来看了。输出的信息会分成三部分,

第一部分:总体统计结果

# 580ms user time, 0 system time, 35.46M rss, 100.01M vsz
# Current date: Wed Jul 19 14:32:40 2017
# Hostname: yztserver1
# Files: slow_querys.log
# Overall: 2.63k total, 36 unique, 0.03 QPS, 0.03x concurrency ___________
# Time range: 2017-07-18T03:17:17 to 2017-07-19T06:30:18
# Attribute          total    min    max    avg    95%  stddev  median
# ============    ======= ======= ======= ======= ======= ======= =======
# Exec time          3145s      1s      5s      1s      2s  258ms      1s
# Lock time          677ms      0    64ms  257us  260us    2ms  144us
# Rows sent          8.44k      0  5.50k    3.29    0.99  108.92    0.99
# Rows examine      1.06G      0  2.12M 421.02k 619.64k 155.33k 419.40k
# Rows affecte          0      0      0      0      0      0      0
# Bytes sent        9.00M      11  6.24M  3.51k  13.78k 119.76k  65.89
# Query size      735.85k      6  2.19k  286.72  463.90  128.05  246.02

记录这个慢日志文件里面的所有慢查询统计信息,通常粗略看看就好了:

Overall: 这个文件里总共有多少条查询,上例为总共 2.63k 个查询,也就是 2.63k 条慢查询。
Time range: 查询执行的时间范围。
unique: 唯一查询数量,即对查询条件进行参数化以后,统计的总共有多少个不同的查询,该例为 36。也就是说这 2.63K 条慢查询,实际归类为 36 条。

Attribute:属性解析,其他子项:

    total: 总计,min: 最小,max: 最大,avg: 平均,

    95%: 把所有值从小到大排列,位置位于 95% 的那个数,这个数一般最具有参考价值,

    median: 中位数,把所有值从小到大排列,位置位于中间那个数。

其他就字面意思,去翻译一下就好。

第二部分:查询分组统计结果

# Profile
# Rank Query ID          Response time  Calls R/Call V/M  Item
# ==== ================== =============== ===== ====== ===== =============
#    1 0x8965CC929FB1C7B2 2080.0546 66.1%  1816 1.1454  0.03 SELECT 1
#    2 0x9C57D04CEA1970B4  228.4754  7.3%  131 1.7441  0.10 SELECT 2
#    3 0x94B4D7AA44982464  138.5964  4.4%  112 1.2375  0.05 SELECT 3
#    4 0x6BD09392D1D0B5D7  84.1681  2.7%    70 1.2024  0.03 SELECT 4
#    5 0x1E9926677DBA3657  81.2260  2.6%    68 1.1945  0.03 SELECT 5
#    6 0xBBCE31227D8C6A93  69.6594  2.2%    56 1.2439  0.05 SELECT 6
#    7 0x9A691CB1A14640F4  60.4517  1.9%    51 1.1853  0.04 SELECT 7
#    8 0xDA99A20C8BE81B9C  55.7751  1.8%    46 1.2125  0.05 SELECT 8
#    9 0x1F53AC684A365326  55.6378  1.8%    45 1.2364  0.03 SELECT 9_
#  10 0x664E0C18531443A5  38.6894  1.2%    31 1.2480  0.05 SELECT way_bill_main
#  11 0xF591153EC390D8CA  32.5370  1.0%    28 1.1620  0.01 SELECT way_bill_main
#  12 0xA3A82D5207F1BC2E  24.6582  0.8%    20 1.2329  0.06 SELECT way_bill_main
#  13 0xFCED276145371CE4  22.2543  0.7%    18 1.2363  0.05 SELECT way_bill_main
#  14 0x4895DF4252D5A600  21.3184  0.7%    17 1.2540  0.07 SELECT way_bill_main
#  16 0xA4DD833DF8C96D04  14.6107  0.5%    13 1.1239  0.01 SELECT way_bill_main
#  17 0x0426A3C3538CBBA8  13.9799  0.4%    13 1.0754  0.00 SELECT way_bill_main
#  18 0x2C52F334EF3D8D2D  12.5960  0.4%    10 1.2596  0.03 SELECT way_bill_main
# MISC 0xMISC              110.2030  3.5%    83 1.3277  0.0 <19 ITEMS>

这部分对查询进行参数化并分组,然后对各类查询的执行情况进行分析,结果按总执行时长,从大到小排序,恕我改了些显示。
Response: 总的响应时间。
time: 该查询在本次分析中总的时间占比。
calls: 执行次数,即本次分析总共有多少条这种类型的查询语句。
R/Call: 平均每次执行的响应时间。
Item : 查询对象

第三部分:每一种查询的详细统计结果,这是其中一个

# Query 1: 0.02 QPS, 0.02x concurrency, ID 0x8965CC929FB1C7B2 at byte 868609
# This item is included in the report because it matches –limit.
# Scores: V/M = 0.03
# Time range: 2017-07-18T03:17:56 to 2017-07-19T06:30:18
# Attribute    pct  total    min    max    avg    95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count        69    1816
# Exec time    66  2080s      1s      4s      1s      1s  189ms      1s
# Lock time    51  349ms    67us    19ms  192us  194us  760us  144us
# Rows sent    21  1.77k      1      1      1      1      0      1
# Rows examine  71 771.37M 262.54k 440.03k 434.96k 419.40k  24.34k 419.40k
# Rows affecte  0      0      0      0      0      0      0      0
# Bytes sent    1 120.49k      65      68  67.94  65.89    0.35  65.89
# Query size    60 443.31k    248    250  249.97  246.02    0.00  246.02
# String:
# Databases    ytttt
# Hosts        10.25.28.2
# Last errno  0
# Users        gztttttt
# Query_time distribution
#  1us
#  10us
# 100us
#  1ms
#  10ms
# 100ms
#    1s  ################################################################
#  10s+
# Tables
#    SHOW TABLE STATUS FROM `ytttt` LIKE ‘way_bill_main’\G
#    SHOW CREATE TABLE `ytttt`.`way_bill_main`\G
#    SHOW TABLE STATUS FROM `ytttt` LIKE ‘scheduler_task’\G
#    SHOW CREATE TABLE `ytttt`.`scheduler_task`\G
# EXPLAIN /*!50100 PARTITIONS*/
SELECT COUNT(1) FROM 1 as w inner join  ….. 此处省略。。。

这部分的上面一部分和第一部分信息类似,统计该记录 sql 的总运行效率信息,下面一部分的解析如下:

Databases: 库名
Users: 各个用户执行的次数(占比),现在只有一个用户,因为我授权的就是一个库一个独立用户。
Query_time distribution : 查询时间分布, 长短体现区间占比,本例中基本上都是 1s。
Tables: 查询中涉及到的表
Explain: 示例,也就是这条 sql 本身的信息。

后面其他信息也大体和这个类似,只是显示不同的 sql 信息而已,都属于这个第三部分。

pt-query-digest 参数说明:

–create-review-table  当使用 –review 参数把分析结果输出到表中时,如果没有表就自动创建。
–create-history-table  当使用 –history 参数把分析结果输出到表中时,如果没有表就自动创建。
–filter  对输入的慢查询按指定的字符串进行匹配过滤后再进行分析
–limit 限制输出结果百分比或数量,默认值是 20, 即将最慢的 20 条语句输出,如果是 50% 则按总响应时间占比从大到小排序,输出到总和达到 50% 位置截止。
–host  MySQL 服务器地址
–user  mysql 用户名
–password  mysql 用户密码
–history 将分析结果保存到表中,分析结果比较详细,下次再使用 –history 时,如果存在相同的语句,且查询所在的时间区间和历史表中的不同,则会记录到数据表中,可以通过查询同一 CHECKSUM 来比较某类型查询的历史变化。
–review 将分析结果保存到表中,这个分析只是对查询条件进行参数化,一个类型的查询一条记录,比较简单。当下次使用 –review 时,如果存在相同的语句分析,就不会记录到数据表中。
–output 分析结果输出类型,值可以是 report(标准分析报告)、slowlog(Mysql slow log)、json、json-anon,一般使用 report,以便于阅读。
–since 从什么时间开始分析,值为字符串,可以是指定的某个”yyyy-mm-dd [hh:mm:ss]”格式的时间点,也可以是简单的一个时间值:s(秒)、h(小时)、m(分钟)、d(天),如 12h 就表示从 12 小时前开始统计。
–until 截止时间,配合—since 可以分析一段时间内的慢查询。

其他命令示例:

1. 分析最近 12 小时内的查询:
pt-query-digest  –since=12h  slow.log > slow_report2.log
2. 分析指定时间范围内的查询:
pt-query-digest slow.log –since ‘2014-04-17 09:30:00’ –until ‘2014-04-17  10:00:00’>>slow_report3.log
3. 分析指含有 select 语句的慢查询
pt-query-digest–filter ‘$event->{fingerprint} =~ m/^select/i’ slow.log> slow_report4.log
4. 针对某个用户的慢查询
pt-query-digest–filter ‘($event->{user} || “”) =~ m/^root/i’ slow.log> slow_report5.log
5. 查询所有所有的全表扫描或 full join 的慢查询
pt-query-digest–filter ‘(($event->{Full_scan} || “”) eq “yes”) ||(($event->{Full_join} || “”) eq “yes”)’ slow.log> slow_report6.log
6. 把查询保存到 query_review 表
pt-query-digest  –user=root –password=abc123 –review  h=localhost,D=test,t=query_review–create-review-table  slow.log
7. 把查询保存到 query_history 表
pt-query-digest  –user=root –password=abc123 –review  h=localhost,D=test,t=query_ history–create-review-table  slow.log_20140401
pt-query-digest  –user=root –password=abc123–review  h=localhost,D=test,t=query_history–create-review-table  slow.log_20140402
8. 通过 tcpdump 抓取 mysql 的 tcp 协议数据,然后再分析
tcpdump -s 65535 -x -nn -q -tttt -i any -c 1000 port 3306 > mysql.tcp.txt
pt-query-digest –type tcpdump mysql.tcp.txt> slow_report9.log
9. 分析 binlog
mysqlbinlog mysql-bin.000093 > mysql-bin000093.sql
pt-query-digest  –type=binlog  mysql-bin000093.sql > slow_report10.log
10. 分析 general log
pt-query-digest  –type=genlog  localhost.log > slow_report11.log

其实 pt-query-digest 虽然信息很多,但是输出的有用信息不见得就比 mysqldumpslow 好很多,反而眼花缭乱的,而且还要装多个工具才能用。不过可以甩问题给开发看到效率有多差也算是一个好事,可以说清楚着个 sql 执行了多少次慢查询,所以实际使用上还是见仁见智,自己看着办。

题外话
一般慢查询日志解决不了问题的话,就建议开查询日志 general-log 来跟踪 sql 了
大体和上面操作差不多,先查看当前状态
show variables like ‘general%’;
可以在 my.cnf 里添加
general-log = 1 开启(0 关闭)
log = /log/mysql_query.log 路径
也可以设置变量那样更改
set global general_log= 1 开启(0 关闭)

正文完
星哥玩云-微信公众号
post-qrcode
 0
星锅
版权声明:本站原创文章,由 星锅 于2022-01-22发表,共计9796字。
转载说明:除特殊说明外本站文章皆由CC-4.0协议发布,转载请注明出处。
【腾讯云】推广者专属福利,新客户无门槛领取总价值高达2860元代金券,每种代金券限量500张,先到先得。
阿里云-最新活动爆款每日限量供应
评论(没有评论)
验证码
【腾讯云】云服务器、云数据库、COS、CDN、短信等云产品特惠热卖中

星哥玩云

星哥玩云
星哥玩云
分享互联网知识
用户数
4
文章数
19351
评论数
4
阅读量
7981329
文章搜索
热门文章
星哥带你玩飞牛NAS-6:抖音视频同步工具,视频下载自动下载保存

星哥带你玩飞牛NAS-6:抖音视频同步工具,视频下载自动下载保存

星哥带你玩飞牛 NAS-6:抖音视频同步工具,视频下载自动下载保存 前言 各位玩 NAS 的朋友好,我是星哥!...
星哥带你玩飞牛NAS-3:安装飞牛NAS后的很有必要的操作

星哥带你玩飞牛NAS-3:安装飞牛NAS后的很有必要的操作

星哥带你玩飞牛 NAS-3:安装飞牛 NAS 后的很有必要的操作 前言 如果你已经有了飞牛 NAS 系统,之前...
我把用了20年的360安全卫士卸载了

我把用了20年的360安全卫士卸载了

我把用了 20 年的 360 安全卫士卸载了 是的,正如标题你看到的。 原因 偷摸安装自家的软件 莫名其妙安装...
再见zabbix!轻量级自建服务器监控神器在Linux 的完整部署指南

再见zabbix!轻量级自建服务器监控神器在Linux 的完整部署指南

再见 zabbix!轻量级自建服务器监控神器在 Linux 的完整部署指南 在日常运维中,服务器监控是绕不开的...
飞牛NAS中安装Navidrome音乐文件中文标签乱码问题解决、安装FntermX终端

飞牛NAS中安装Navidrome音乐文件中文标签乱码问题解决、安装FntermX终端

飞牛 NAS 中安装 Navidrome 音乐文件中文标签乱码问题解决、安装 FntermX 终端 问题背景 ...
阿里云CDN
阿里云CDN-提高用户访问的响应速度和成功率
随机文章
飞牛NAS中安装Navidrome音乐文件中文标签乱码问题解决、安装FntermX终端

飞牛NAS中安装Navidrome音乐文件中文标签乱码问题解决、安装FntermX终端

飞牛 NAS 中安装 Navidrome 音乐文件中文标签乱码问题解决、安装 FntermX 终端 问题背景 ...
零成本上线!用 Hugging Face免费服务器+Docker 快速部署HertzBeat 监控平台

零成本上线!用 Hugging Face免费服务器+Docker 快速部署HertzBeat 监控平台

零成本上线!用 Hugging Face 免费服务器 +Docker 快速部署 HertzBeat 监控平台 ...
300元就能买到的”小钢炮”?惠普7L四盘位小主机解析

300元就能买到的”小钢炮”?惠普7L四盘位小主机解析

  300 元就能买到的 ” 小钢炮 ”?惠普 7L 四盘位小主机解析 最近...
4盘位、4K输出、J3455、遥控,NAS硬件入门性价比之王

4盘位、4K输出、J3455、遥控,NAS硬件入门性价比之王

  4 盘位、4K 输出、J3455、遥控,NAS 硬件入门性价比之王 开篇 在 NAS 市场中,威...
小白也能看懂:什么是云服务器?腾讯云 vs 阿里云对比

小白也能看懂:什么是云服务器?腾讯云 vs 阿里云对比

小白也能看懂:什么是云服务器?腾讯云 vs 阿里云对比 星哥玩云,带你从小白到上云高手。今天咱们就来聊聊——什...

免费图片视频管理工具让灵感库告别混乱

一言一句话
-「
手气不错
星哥带你玩飞牛NAS-16:飞牛云NAS换桌面,fndesk图标管理神器上线!

星哥带你玩飞牛NAS-16:飞牛云NAS换桌面,fndesk图标管理神器上线!

  星哥带你玩飞牛 NAS-16:飞牛云 NAS 换桌面,fndesk 图标管理神器上线! 引言 哈...
还在找免费服务器?无广告免费主机,新手也能轻松上手!

还在找免费服务器?无广告免费主机,新手也能轻松上手!

还在找免费服务器?无广告免费主机,新手也能轻松上手! 前言 对于个人开发者、建站新手或是想搭建测试站点的从业者...
星哥带你玩飞牛NAS-16:不再错过公众号更新,飞牛NAS搭建RSS

星哥带你玩飞牛NAS-16:不再错过公众号更新,飞牛NAS搭建RSS

  星哥带你玩飞牛 NAS-16:不再错过公众号更新,飞牛 NAS 搭建 RSS 对于经常关注多个微...
一句话生成拓扑图!AI+Draw.io 封神开源组合,工具让你的效率爆炸

一句话生成拓扑图!AI+Draw.io 封神开源组合,工具让你的效率爆炸

一句话生成拓扑图!AI+Draw.io 封神开源组合,工具让你的效率爆炸 前言 作为天天跟架构图、拓扑图死磕的...
开发者福利:免费 .frii.site 子域名,一分钟申请即用

开发者福利:免费 .frii.site 子域名,一分钟申请即用

  开发者福利:免费 .frii.site 子域名,一分钟申请即用 前言 在学习 Web 开发、部署...