Query_time、Rows_examined、Rows_sent这3个信息让我们看到了查询需要优化什么。查询时间最长的SQL往往是最需要优化的,如果检查了大量记录(Rows_examined),而只返回很小的结果集(Rows_sent),往往也意味着存在不良SQL。但在一个高并发的数据库服务上,或者在做压力测试时,如果发现慢查询日志增长得非常快,很难筛选和查找里面的信息,那么在这种情况下,有如下两种选择。
l 调整阈值,先设置为较大的阈值,这样慢查询记录就很少了,等优化得差不多了,再减少阈值,不断进行优化。
l 使用命令/脚本、工具进行分析,如mysqldumpslow、pt-query-digest等。
l 第一种方法比较繁琐,建议大家使用第二种方法。如果优化效果比较理想,希望更进一步调优,则可以减低阈值,然后记录更多的慢查询日志,然后继续使用脚本、工具进行分析。
1.使用操作系统命令分析
可以使用操作系统自带的命令进行一些简单的统计,如grep、awk、wc,但不容易实现更高级的筛选排序。
下面来看个示例,通过如下命令可以看到每秒的慢查询的统计,当检查到有突变时,往往会有异常发生,这时便可以更进
一步到具体的慢查询日志里去查找可能的原因。
awk'/^# Time:/{print $3, $4, c;c=0}/^# User/{c++}' /var/lib/mysql/service1-slow.log> /tmp/aaa.log
2.mysqldumpslow
mysqldumpslow命令是官方自带的,此命令可获得日志中的查询摘要。
以下是mysqldumpslow命令的使用示例。
访问时间最长的10个sql语句的命令如下。
mysqldumpslow -t10/var/lib/mysql/service1-slow.log
访问次数最多的10个sql语句的命令如下。
mysqldumpslow -s c -t10/var/lib/mysql/service1-slow.log
访问记录集最多的10个sql语句的命令如下。
mysqldumpslow-s r -t10 /var/lib/mysql/service1-slow.log
试验过程如下:
[root@service1~]# mysql -uroot -p
Enterpassword:
Welcometo the MySQL monitor. Commands end with; or \g.
YourMySQL connection id is 6
Serverversion: 5.7.22-log MySQL Community Server (GPL)
Copyright(c) 2000, 2018, Oracle and/or its affiliates. All rights reserved.
Oracleis a registered trademark of Oracle Corporation and/or its
affiliates.Other names may be trademarks of their respective
owners.
Type'help;' or '\h' for help. Type '\c' to clear the current input statement.
mysql>show variables like 'slow_query%';
+---------------------+----------------------------------+
|Variable_name | Value |
+---------------------+----------------------------------+
|slow_query_log | OFF |
|slow_query_log_file | /var/lib/mysql/service1-slow.log |
+---------------------+----------------------------------+
2rows in set (0.03 sec)
mysql>set global slow_query_log=1;
QueryOK, 0 rows affected (0.00 sec)
mysql>set global long_query_time=1;
QueryOK, 0 rows affected (0.00 sec)
mysql>show variables like 'slow_query%';
+---------------------+----------------------------------+
|Variable_name | Value |
+---------------------+----------------------------------+
|slow_query_log | ON |
|slow_query_log_file | /var/lib/mysql/service1-slow.log |
+---------------------+----------------------------------+
2rows in set (0.00 sec)
mysql>select sleep(2);
+----------+
|sleep(2) |
+----------+
| 0 |
+----------+
1row in set (2.01 sec)
在同一个session执行select sleep(2);在慢查询日志不起作用,换一个session,执行如下:
mysql>select sleep(2);
+----------+
|sleep(2) |
+----------+
| 0 |
+----------+
1row in set (2.00 sec)
换一个session,执行如下:
[root@service1~]# mysqldumpslow -t 10 /var/lib/mysql/service1-slow.log
Readingmysql slow query log from /var/lib/mysql/service1-slow.log
Count:1 Time=2.00s (2s) Lock=0.00s (0s) Rows=1.0 (1), root[root]@localhost
select sleep(N)
Count:1 Time=0.00s (0s) Lock=0.00s (0s) Rows=0.0 (0), 0users@0hosts
Diedat /usr/bin/mysqldumpslow line 161, <> chunk 1.
3.pt-query-digest
有一些第三方分析工具(如msyqlsla、pt-query-digest)比mysqldumpslow更强大,更友好。以下将重点介绍pt-query-digest工具。
pt-query-digest可以生成一份比官方mysqldumpslow可读性好得多的报告。安装也很简单,命令如下。
wget www.percona.com/get/pt-query-digest
chmod u+x pt-query-digest
我是如下操作的(linux当时无法上网):在/usr/bin/ 目下vi vipt-query-digest,把www.percona.com/get/pt-query-digest内容粘贴过来,然后执行chmod u+x pt-query-digest即可。
基本语法格式如下所示。
pt-query-digest [OPTIONS] [FILES] [DSN]
详细的语法介绍,请参考16.2.2节,这里仅给出一些常用的示例。
直接分析慢查询的命令如下。
[root@service1 bin]# pt-query-digest/var/lib/mysql/service1-slow.log > /root/service1-slow.rtf
分析半个小时内的慢查询的命令如下。
pt-query-digest --since 1800s /path/of/slow.log >slow.rtf
分析一段时间范围内的慢查询的命令如下。
pt-query-digest --since '2014-04-14 22:00:00' --until'2014-04-14 23:00:00' /path/of/slow.log > slow.rtf
显示所有分析的查询命令如下。
pt-query-digest --limit 100% /path/of/slow.log >slow.rtf
其中,“--limit”参数默认是“95%:20”,表示显示95%的最差的查询,或者20个最差的查询。
此外,也可以用这个工具来分析二进志日志,以查看我们日常的修改语句是如何分布的,首先需要把二进志日志转换为文
本格式。
mysqlbinlog mysql-bin.012639 > /tmp/012639.log
pt-query-digest --type binlog /tmp/012639.log
对于以上分析命令,同样可以加上参数筛选信息,如“--since”、“--until”。
那么,如何查看pt-query-digest报告呢?
以下是一个输出报告,为了节省篇幅,删除了部分信息。
# 140.9s user time, 1.4s system time, 57.93M rss, 154.03Mvsz
# Current date: Sun Feb 16 09:16:39 2011
解释:执行pt-query-digest工具的时间。
# Files: /usr/lcoal/mysql/data/slowquery.log
# Overall: 304.88k total, 159 unique, 0.22 QPS, 0.15xconcurrency ________
解释:慢查询次数一共是304.88k,唯一的查询159个。
# Time range: 2010-12-01 00:00:01 to 2010-12-17 09:05:17
解释:这里记录的是发现第一条慢查询的时间到最后一条慢查询的时间。
# Attribute total min max avg 95% stddev median
# ============ ======= ======== ======= ======= ============= =======
# Exec time 216112s 500ms 21s 709ms 1s 968ms 552ms
# Lock time 414s 21us 101ms 1ms 626us 7ms 84us
# Rows sent 169.69M 0 213.73k 583.60 97.36 10.75k 9.83
# Rows examine 60.26G 0 866.23k 207.25k 328.61k 70.68k201.74k
# Query size 120.31M 35 21.07k 413.76 719.66 148.97363.48
解释分别如下。
·Exec time:执行时间。
·Lock time:表锁的时间。
·Rows sent:返回的结果集记录数。
·Rows examine:实际扫描的记录数。
·Query size:应用和数据库交互的查询文本大小。
# Profile
# Rank Query ID Response time Calls R/Call Apdx V/M Item
# ==== ================== ================ ====== =========== ===== =====
# 1 0x5931CCE8168ECE59 92062.4390 42.6% 168672 0.54581.00 0.01 SELECT game_info game_stat
# 2 0x0E8691F18411F3DC 23404.4270 10.8% 18602 1.2582 0.600.04 SELECT game_info game_stat game_info_2
...
...
解释分别如下。
·Rank:所有查询日志分析完毕后,此查询的排序。
·Query ID:查询的标识字符串。
·Response time:总的响应时间,以及总占比。一般小于5%可以不用关注。
·Calls:查询被调用执行的次数。
·R/Call:每次执行的平均响应时间。
·Apdx:应用程序的性能指数得分。(Apdex响应的时间越长,得分越低。)
·V/M:响应时间的方差均值比(变异数对平均数比,变异系数)。可说明样本的分散程度,这个值越大,往往是越值得考
虑优化的对象。
·Item:查询的简单显示,包括查询的类型和所涉及的表。
以下将按默认的响应时间进行排序,并列出TOP n条查询。并且pt-query-digest输出了EXPLAIN的语句,以方便我们验证查
询计划。
# Query 1: 0.12 QPS, 0.07x concurrency, ID0x5931CCE8168ECE59 at byte 243208985
# This item is included in the report because it matches--limit.
# Scores: Apdex = 1.00 [1.0], V/M = 0.01
# Query_time sparkline: | ^__|
# Time range: 2010-12-01 00:00:01 to 2010-12-17 09:04:53
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ============== ======= =======
# Count 55 168672
# Exec time 42 92062s 500ms 11s 546ms 640ms 77ms 501ms
# Lock time 68 283s 58us 101ms 2ms 690us 8ms 80us
# Rows sent 1 2.04M 10 100 12.67 9.83 14.86 9.83
# Rows examine 54 33.12G 204.96k 208.16k 205.90k 201.74k0.00 201.74k
# Query size 50 60.64M 376 378 376.97 363.48 0 363.48
# String:
# Hosts
# Users sd_game
# Query_time distribution
# 1us
# 10us
# 100us
# 1ms
# 10ms
# 100ms################################################################
# 1s #
# 10s+ #
# Tables
# SHOW TABLE STATUS LIKE 'game_info'\G
# SHOW CREATE TABLE 'game_info'\G
# SHOW TABLE STATUS LIKE 'game_stat'\G
# SHOW CREATE TABLE 'game_stat'\G
# EXPLAIN /*!50100 PARTITIONS*/
select ...
以上关于SELECT查询的具体文本此处省略。
从pt-query-digest工具中看到的信息里,对于响应时间,不仅需要关注平均值,还需要关注百分比响应,以及关注其的分布情况和离散程度。
对于响应时间的方差均值比,如果该均值比很大,则可能意味着有一些异常值。
慢查询日志里的慢查询不一定就是BAD SQL。可能是受到了其他查询的影响,或者是受系统资源限制所导致的。有了分析报告,就可以用EXPLAIN工具确认慢查询的执行计划,从而进行调优。通常,80%的问题是因为索引不佳而引起的,添加适当的索引即可。
登录 | 立即注册