mysql慢查询功能详细介绍

2025-03-21 技术教程

这篇文章主要讲解了“mysql慢查询功能详细介绍”，文中的讲解内容简单清晰，易于学习与理解，下面请大家跟着小编的思路慢慢深入，一起来研究和学习“mysql慢查询功能详细介绍”吧！

开启mysql慢查询日志
1.查看当前慢查询设置情况

#查看慢查询时间，默认10s，建议降到1s或以下，mysql>showvariableslike"long_query_time";+-----------------+----------+|Variable_name|Value|+-----------------+----------+|long_query_time|1.000000|+-----------------+----------+1rowinset(0.00sec)#查看慢查询配置情况mysql>showvariableslike"%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||+-----------------------------------+----------------------+14rowsinset(0.01sec)

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

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

vimmy.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管理指令也会被记录到慢查询。比如OPTIMEZETABLE,ALTERTABLE,默认关闭,看需求开启,会产生很多日志,可动态修改#log-slow-admin-statements

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

tail-f/tmp/slow_querys.log

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

#开启慢查询功能，1是开启，0是关闭mysql>setglobalslow_query_log=1;#定义查过多少秒的查询算是慢查询，我这里定义的是1秒，5.6之后允许设置少于1秒，例如0.1秒mysql>setgloballong_query_time=1;#定义慢查询日志的路径mysql>setglobalslow_query_log_file='/tmp/slow_querys.log';#关闭功能：setglobalslow_query_log=0;然后通过一下命令查看是否成功mysql>showvariableslike'long%';mysql>showvariableslike'slow%';#设置慢查询记录到表中#setgloballog_output='TABLE';

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

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

慢查询日志的记录定义

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

tail-fslow_query.log#Time:11010716:22:11#User@Host:root[root]@localhost[]#Query_time:9.869362Lock_time:0.000035Rows_sent:1Rows_examined:6261774SETtimestamp=1294388531;selectcount(*)fromep_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在，看起来还是费劲，所以建议输出到文件来看了。输出的信息会分成三部分，

第一部分：总体统计结果

#580msusertime,0systemtime,35.46Mrss,100.01Mvsz#Currentdate:WedJul1914:32:402017#Hostname:yztserver1#Files:slow_querys.log#Overall:2.63ktotal,36unique,0.03QPS,0.03xconcurrency___________#Timerange:2017-07-18T03:17:17to2017-07-19T06:30:18#Attributetotalminmaxavg95%stddevmedian#=============================================================#Exectime3145s1s5s1s2s258ms1s#Locktime677ms064ms257us260us2ms144us#Rowssent8.44k05.50k3.290.99108.920.99#Rowsexamine1.06G02.12M421.02k619.64k155.33k419.40k#Rowsaffecte0000000#Bytessent9.00M116.24M3.51k13.78k119.76k65.89#Querysize735.85k62.19k286.72463.90128.05246.02

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

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

Attribute：属性解析，其他子项：

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

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

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

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

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

#Profile#RankQueryIDResponsetimeCallsR/CallV/MItem#==================================================================#10x8965CC929FB1C7B22080.054666.1%18161.14540.03SELECT1#20x9C57D04CEA1970B4228.47547.3%1311.74410.10SELECT2#30x94B4D7AA44982464138.59644.4%1121.23750.05SELECT3#40x6BD09392D1D0B5D784.16812.7%701.20240.03SELECT4#50x1E9926677DBA365781.22602.6%681.19450.03SELECT5#60xBBCE31227D8C6A9369.65942.2%561.24390.05SELECT6#70x9A691CB1A14640F460.45171.9%511.18530.04SELECT7#80xDA99A20C8BE81B9C55.77511.8%461.21250.05SELECT8#90x1F53AC684A36532655.63781.8%451.23640.03SELECT9_#100x664E0C18531443A538.68941.2%311.24800.05SELECTway_bill_main#110xF591153EC390D8CA32.53701.0%281.16200.01SELECTway_bill_main#120xA3A82D5207F1BC2E24.65820.8%201.23290.06SELECTway_bill_main#130xFCED276145371CE422.25430.7%181.23630.05SELECTway_bill_main#140x4895DF4252D5A60021.31840.7%171.25400.07SELECTway_bill_main#160xA4DD833DF8C96D0414.61070.5%131.12390.01SELECTway_bill_main#170x0426A3C3538CBBA813.97990.4%131.07540.00SELECTway_bill_main#180x2C52F334EF3D8D2D12.59600.4%101.25960.03SELECTway_bill_main#MISC0xMISC110.20303.5%831.32770.0<19ITEMS>

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

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

#Query1:0.02QPS,0.02xconcurrency,ID0x8965CC929FB1C7B2atbyte868609#Thisitemisincludedinthereportbecauseitmatches--limit.#Scores:V/M=0.03#Timerange:2017-07-18T03:17:56to2017-07-19T06:30:18#Attributepcttotalminmaxavg95%stddevmedian#================================================================#Count691816#Exectime662080s1s4s1s1s189ms1s#Locktime51349ms67us19ms192us194us760us144us#Rowssent211.77k111101#Rowsexamine71771.37M262.54k440.03k434.96k419.40k24.34k419.40k#Rowsaffecte00000000#Bytessent1120.49k656867.9465.890.3565.89#Querysize60443.31k248250249.97246.020.00246.02#String:#Databasesytttt#Hosts10.25.28.2#Lasterrno0#Usersgztttttt#Query_timedistribution#1us#10us#100us#1ms#10ms#100ms#1s#################################################################10s+#Tables#SHOWTABLESTATUSFROM`ytttt`LIKE'way_bill_main'\G#SHOWCREATETABLE`ytttt`.`way_bill_main`\G#SHOWTABLESTATUSFROM`ytttt`LIKE'scheduler_task'\G#SHOWCREATETABLE`ytttt`.`scheduler_task`\G#EXPLAIN/*!50100PARTITIONS*/SELECTCOUNT(1)FROM1aswinnerjoin.....此处省略。。。

这部分的上面一部分和第一部分信息类似，统计该记录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执行了多少次慢查询，所以实际使用上还是见仁见智，自己看着办。

额外说明:

1.个别情况下,mysql慢查询记录可能达不到目的.

那是因为mysql的慢查询记录机制导致,因为mysql只是把在引擎阶段的慢查询记录到慢日志,其他例如网络延迟(如:跨机房),IO传输延时(如:读写频繁),客户端延迟(如:jdbc高负载),还有个别内部资源锁等待,可能导致增加的查询延时,但又不一定记录在慢日志的.

所以很可能就出现一种诡异的情况,明明查询确实很慢,但是mysql的慢日志就是没有记录下来.这个时候就要我们的思路更广阔一些才行了.

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

感谢各位的阅读，以上就是“mysql慢查询功能详细介绍”的内容了，经过本文的学习后，相信大家对mysql慢查询功能详细介绍这一问题有了更深刻的体会，具体使用情况还需要大家实践验证。这里是亿速云，小编将为大家推送更多相关知识点的文章，欢迎关注！