mysql慢查询功能详细介绍
这篇文章主要讲解了“MySQL慢查询功能详细介绍”,文中的讲解内容简单清晰,易于学习与理解,下面请大家跟着小编的思路慢慢深入,一起来研究和学习“mysql慢查询功能详细介绍”吧!
10余年的即墨网站建设经验,针对设计、前端、开发、售后、文案、推广等六对一服务,响应快,48小时及时工作处理。成都全网营销的优势是能够根据用户设备显示端的尺寸不同,自动调整即墨建站的显示方式,使网站能够适用不同显示终端,在浏览器中调整网站的宽度,无论在任何一种浏览器上浏览网站,都能展现优雅布局与设计,从而大程度地提升浏览体验。创新互联从事“即墨网站设计”,“即墨网站推广”以来,每个客户项目都认真落实执行。
开启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执行了多少次慢查询,所以实际使用上还是见仁见智,自己看着办。
额外说明:
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慢查询功能详细介绍这一问题有了更深刻的体会,具体使用情况还需要大家实践验证。这里是创新互联,小编将为大家推送更多相关知识点的文章,欢迎关注!
文章标题:mysql慢查询功能详细介绍
文章位置:http://scjbc.cn/article/psdcgp.html