mysql慢查询日志

通过开启慢查询日志，mysql服务器会记录那些执行时间长的sql语句，能够帮助我们优化sql查询。

开启慢查询日志

log_output=FILE	//日志保存到文件
slow_query_log=ON	//开启慢查询日志
slow_query_log_file=/path/to/somefile //慢查询日志保存的文件
log_queries_not_using_indexes=ON //记录没有使用索引的sql
long_query_time=time //执行时间超过多少秒被记为慢查询sql
log_slow_admin_statements =ON //记录那些ddl数据库定义语言的慢sql，例如alter table

日志分析工具

mysqldumpslow

mysql官方只带提供的慢查询日志分析工具

 mysqldumpslow [ OPTS... ] [ LOGS... ]
 -s 根据某列进行排序
 	al：平均锁占用时间
 	ar：平均返回记录数
 	at：平均查询时间
 	c：sql语句出现次数
 	l：总锁占用时间
 	r：总返回记录数
 	t：总查询时间
 -r 反向排序
 -t num 只显示头几行

pt-query-digest

常用参数
–filter 按字符串匹配需要显示的慢查询
–limit 显示排序靠前几行
–host myslq服务器地址
–user mysql登录用户账号
–password mysql账号密码
–output 选择输出格式，report、slowlog、json、json-anon
–since 从指定时间开始
–until 到指定时间结束

分析结果信息

• 汇总信息

# 4.7s user time, 50ms system time, 31.92M rss, 226.53M vsz
# Current date: Wed Apr 24 09:42:20 2019
# Hostname: test.c7.my
# Files: slow-query-log.log
# Overall: 9.78k total, 302 unique, 0.00 QPS, 0.00x concurrency __________
# Time range: 2018-09-10 18:22:43 to 2019-04-09 10:15:04
# Attribute          total     min     max     avg     95%  stddev  median
# ============     ======= ======= ======= ======= ======= ======= =======
# Exec time         15084s    55us    154s      2s      4s      4s      1s
# Lock time          3399s       0     54s   348ms      2s      1s   103us
# Rows sent          1.94M       0 531.84k  208.59   19.46   8.42k    0.99
# Rows examine      23.74M       0 664.79k   2.49k   2.89k  30.56k   21.45
# Query size         2.15M      14  44.34k  230.93  755.64  611.12  112.7

第一行：生成报表用户空间占用的时间、系统调用占用时间、实际内存占用、虚拟内存占用
第二行：报表生成时间
第四行：对那个慢查询日志进行分析
第五行：总的查询数，不相同的查询数，每秒查询数，并发数
第六行：分析慢查询日志记录的开始时间和结束时间
表格： total 总数，min最小值，max最大值，avg平均值，95% 位于95%位置的记录数值，median中位数，
Exectime 执行时间，lock time 锁占用时间，rows sent 返回给客户端的行数， Rows examine 存储引擎扫描的行数， Query size查询sql的大小

• 查询分组统计结果

Profile
#Rank Query ID           Response time   Calls R/Call  V/M   Item
#==== ================== =============== ===== ======= ===== ============
#1 0x8A8FB546792C9ADD 7212.9891 47.8%  2711  2.6606  0.34 SHOW COLUMNS
#2 0x445D20E44CF56324 1366.6386  9.1%    74 18.4681 49.72 SHOW TABLE STATUS
#3 0x78632B2074C53F88  719.1441  4.8%   445  1.6161  0.68 SELECT train_user train_user_ext train_user_ext_address train_user_ext_commission train_user_ext_money train_member_ext
#4 0x1AB1F445975DE219  695.9611  4.6%    41 16.9747 54.35 SHOW COLUMNS
#5 0x0CF6DE6C18C897F2  680.4680  4.5%   140  4.8605  3.88 SHOW TABLES

• 每条sql语句的详细信息

# Query 1: 0.00 QPS, 0.00x concurrency, ID 0x8A8FB546792C9ADD at byte 1586789
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.34
# Time range: 2018-09-21 18:40:04 to 2019-04-08 14:50:08
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count         27    2711
# Exec time     47   7213s      1s      9s      3s      5s   958ms      2s
# Lock time     87   2990s   170us      4s      1s      3s   831ms   857ms
# Rows sent      1  31.77k      12      12      12      12       0      12
# Rows examine   0  31.77k      12      12      12      12       0      12
# Query size     5 111.19k      42      42      42      42       0      42
# String:
# Databases    aidevops
# Hosts        localhost
# Users        root
# Query_time distribution
#   1us
#  10us
# 100us
#   1ms
#  10ms
# 100ms
#    1s  ################################################################
#  10s+
# Tables
#    SHOW TABLE STATUS FROM `aidevops` LIKE 'aidevops_update_record'\G
#    SHOW CREATE TABLE `aidevops`.`aidevops_update_record`\G
SHOW COLUMNS FROM `aidevops_update_record`\G

第一行：编号、每秒查询数、并发数
第四行：慢查询记录的时间
表格： total 总数，min最小值，max最大值，avg平均值，95% 位于95%位置的记录数值，median中位数，
count 相同sql出现次数， Exectime 执行时间，lock time 锁占用时间，rows sent 返回给客户端的行数， Rows examine 存储引擎扫描的行数， Query size查询sql的大小
Databases：数据库
Hosts：mysql服务器地址
User：登录账号
Query_time distribution：查询消耗时间分布图
Tables：打印查看表结构和表表状态的sql
最后一行：分析的慢查询sql语句