通过开启慢查询日志,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语句