mysql慢查询开启及慢查询分析
mysql慢查询配置
mysql会记录所有执行超过long_query_time参数设定时间阀值的sql语句,慢查询日志就是这些sql的日志
开启慢查询方法
方法一、
在Mysql配置文件里(windows下My.ini,linux下my.cnf)
里的mysqld的下面添加
log_slow_queries="D:\wamp\bin\mysql\mysql5.5.28\mylog\slowquery.log"
long_query_time=1
log-queries-not-using-indexes(如果查询的sql没使用索引(无论表有没有索引),也会被记录)方法二、
mysql> show variables like '%quer%';
+----------------------------------------+----------------------------------------------------+
| Variable_name | Value |
+----------------------------------------+----------------------------------------------------+
| binlog_rows_query_log_events | OFF |
| ft_query_expansion_limit | 20 |
| have_query_cache | YES |
| log_queries_not_using_indexes | ON |
| log_throttle_queries_not_using_indexes | 0 |
| long_query_time | 10.000000 |
| query_alloc_block_size | 8192 |
| query_cache_limit | 1048576 |
| query_cache_min_res_unit | 4096 |
| query_cache_size | 1048576 |
| query_cache_type | OFF |
| query_cache_wlock_invalidate | OFF |
| query_prealloc_size | 8192 |
| slow_query_log | OFF |
| slow_query_log_file | D:/wamp64/bin/mysql/mysql5.7.14/log/mysql-slow.log |
+----------------------------------------+----------------------------------------------------+set global slow_query=1;
set global log_queries_not_using_indexes=on;
set global long_query_time=0
也可已在配置文件mysqld下添加该项配置
global slow_query=1
long_query_time=1
slow_query_log_file=/tmp/slow.log方法一配置了的话，方法二就失效了，方法一优先！
慢查询日志的存储格式
# Time: 2018-03-17T02:48:42.857232Z
# User@Host: root[root] @ localhost [127.0.0.1] Id: 13
# Query_time: 0.000000 Lock_time: 0.000000 Rows_sent: 2 Rows_examined: 2
SET timestamp=1521254922;
SELECT * from store limit 10;慢查询日志分析工具
mysqldumpslow -h
windows下是一个perl脚本(mysqldumpslow.pl) 需要安装perl
/var/run/mysqld/mysqld-slow.log
-s order 来排序
-t num 前多少条
mysqldumpslow -t 3 /var/run/mysqld/mysqld-slow.log
[root@centos1 sakila-db]# mysqldumpslow -t 3 /var/run/mysqld/mysqld-slow.log
Reading mysql slow query log from /var/run/mysqld/mysqld-slow.log
Count: 2 Time=0.00s (0s) Lock=0.00s (0s) Rows=14.0 (28), root[root]@localhost
show variables like 'S'
Count: 1 Time=0.00s (0s) Lock=0.00s (0s) Rows=1.0 (1), root[root]@localhost
select @@version_comment limit N
Count: 23 Time=0.00s (0s) Lock=0.00s (0s) Rows=0.0 (0), root[root]@localhost
[root@centos1 sakila-db]# mysqldumpslow -h
Option h requires an argument
ERROR: bad option
Usage: mysqldumpslow [ OPTS... ] [ LOGS... ]
Parse and summarize the MySQL slow query log. Options are
--verbose verbose
--debug debug
--help write this text to standard output
-v verbose
-d debug
-s ORDER what to sort by (al, at, ar, c, l, r, t), 'at' is default
al: average lock time
ar: average rows sent
at: average query time
c: count
l: lock time
r: rows sent
t: query time
-r reverse the sort order (largest last instead of first)
-t NUM just show the top n queries
-a don't abstract all numbers to N and strings to 'S'
-n NUM abstract numbers with at least n digits within names
-g PATTERN grep: only consider stmts that include this string
-h HOSTNAME hostname of db server for *-slow.log filename (can be wildcard),
default is '*', i.e. match all
-i NAME name of server instance (if using mysql.server startup script)
-l don't subtract lock time from total timeView Code
pt-query-digest
输出到文件
pt-query-digest slow-log>slow_log_report
输出到数据库表
pt-query-digest slow.log -review h127.0.0.1,D=test,p=root,p=3306,u=root,t=query_review --create-reviewtable --review-history t=hostname_slow
安装
yum -y install perl perl-IO-Socket-SSL perl-DBD-MySQL perl-Time-HiRes
或者
wget http://www.percona.com/get/pt-query-digest
chmod +x pt-query-digest
root@centos1 sakila-db]# ./pt-query-digest /var/run/mysqld/mysqld-slow.log
# A software update is available:
# 160ms user time, 50ms system time, 24.92M rss, 211.78M vsz
# Current date: Sat Mar 17 12:03:21 2018
# Hostname: centos1
# Files: /var/run/mysqld/mysqld-slow.log
# Overall: 12 total, 9 unique, 0.06 QPS, 0.00x concurrency _______________
# Time range: 2018-03-17 11:33:58 to 11:37:28
# Attribute total min max avg 95% stddev median
# ============ ======= ======= ======= ======= ======= ======= =======
# Exec time 3ms 3us 620us 237us 445us 183us 214us
# Lock time 628us 0 180us 52us 103us 52us 63us
# Rows sent 88 0 23 7.33 22.53 8.30 4.96
# Rows examine 86 0 23 7.17 22.53 8.44 4.96
# Query size 253 11 32 21.08 28.75 7.74 26.08
# Profile
# Rank Query ID Response time Calls R/Call V/M Item
# ==== ================== ============= ===== ====== ===== ==============
# 1 0x7DD5F6760F2D2EBB 0.0010 35.9% 2 0.0005 0.00 SHOW VARIABLES
# 2 0x5CBA2034458B5BC9 0.0007 23.0% 2 0.0003 0.00 SHOW DATABASES
# 3 0x132628303F99240D 0.0005 18.8% 2 0.0003 0.00 SHOW TABLES
# 4 0xE3A3649C5FAC418D 0.0004 12.4% 1 0.0004 0.00 SELECT
# 5 0x48AB709485D784C3 0.0002 5.9% 1 0.0002 0.00 SELECT store
# MISC 0xMISC 0.0001 4.0% 4 0.0000 0.0 <4 ITEMS>
# Query 1: 0.01 QPS, 0.00x concurrency, ID 0x7DD5F6760F2D2EBB at byte 376
# Scores: V/M = 0.00
# Time range: 2018-03-17 11:34:15 to 11:37:08
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 16 2
# Exec time 35 1ms 405us 620us 512us 620us 152us 512us
# Lock time 28 182us 76us 106us 91us 106us 21us 91us
# Rows sent 31 28 14 14 14 14 0 14
# Rows examine 32 28 14 14 14 14 0 14
# Query size 22 56 28 28 28 28 0 28
# String:
# Databases sakila
# Hosts localhost
# Users root
# Query_time distribution
# 1us
# 10us
# 100us ################################################################
# 1ms
# 10ms
# 100ms
# 1s
# 10s+
show variables like '%quer%'\G
# Query 2: 0.25 QPS, 0.00x concurrency, ID 0x5CBA2034458B5BC9 at byte 1299
# Scores: V/M = 0.00
# Time range: 2018-03-17 11:36:05 to 11:36:13
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 16 2
# Exec time 23 657us 196us 461us 328us 461us 187us 328us
# Lock time 39 245us 65us 180us 122us 180us 81us 122us
# Rows sent 11 10 5 5 5 5 0 5
# Rows examine 11 10 5 5 5 5 0 5
# Query size 11 28 14 14 14 14 0 14
# String:
# Databases sakila
# Hosts localhost
# Users root
# Query_time distribution
# 1us
# 10us
# 100us ################################################################
# 1ms
# 10ms
# 100ms
# 1s
# 10s+
show databases\G
# Query 3: 0.25 QPS, 0.00x concurrency, ID 0x132628303F99240D at byte 1456
# Scores: V/M = 0.00
# Time range: 2018-03-17 11:36:13 to 11:36:21
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 16 2
# Exec time 18 537us 218us 319us 268us 319us 71us 268us
# Lock time 22 141us 70us 71us 70us 71us 0 70us
# Rows sent 52 46 23 23 23 23 0 23
# Rows examine 53 46 23 23 23 23 0 23
# Query size 8 22 11 11 11 11 0 11
# String:
# Databases sakila
# Hosts localhost
# Users root
# Query_time distribution
# 1us
# 10us
# 100us ################################################################
# 1ms
# 10ms
# 100ms
# 1s
# 10s+
show tables\G
# Query 4: 0 QPS, 0x concurrency, ID 0xE3A3649C5FAC418D at byte 0 ________
# Scores: V/M = 0.00
# Time range: all events occurred at 2018-03-17 11:33:58
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 8 1
# Exec time 12 354us 354us 354us 354us 354us 0 354us
# Lock time 0 0 0 0 0 0 0 0
# Rows sent 1 1 1 1 1 1 0 1
# Rows examine 0 0 0 0 0 0 0 0
# Query size 12 32 32 32 32 32 0 32
# String:
# Hosts localhost
# Users root
# Query_time distribution
# 1us
# 10us
# 100us ################################################################
# 1ms
# 10ms
# 100ms
# 1s
# 10s+
# EXPLAIN /*!50100 PARTITIONS*/
select @@version_comment limit 1\G
# Query 5: 0 QPS, 0x concurrency, ID 0x48AB709485D784C3 at byte 5056 _____
# Scores: V/M = 0.00
# Time range: all events occurred at 2018-03-17 11:36:35
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 8 1
# Exec time 5 167us 167us 167us 167us 167us 0 167us
# Lock time 9 60us 60us 60us 60us 60us 0 60us
# Rows sent 2 2 2 2 2 2 0 2
# Rows examine 2 2 2 2 2 2 0 2
# Query size 11 28 28 28 28 28 0 28
# String:
# Databases sakila
# Hosts localhost
# Users root
# Query_time distribution
# 1us
# 10us
# 100us ################################################################
# 1ms
# 10ms
# 100ms
# 1s
# 10s+
# Tables
# SHOW TABLE STATUS FROM `sakila` LIKE 'store'\G
# SHOW CREATE TABLE `sakila`.`store`\G
# EXPLAIN /*!50100 PARTITIONS*/
select * from store limit 10\GView Code
找出有问题的sql
通常为pt-query-digest分析查询的前几个查询
io大的sql
rows examine项
未命中索引的
rows examole和rows send对比
在sakila数据库里
优化count()和max()
mysql> desc payment;
+--------------+----------------------+------+-----+-------------------+-----------------------------+
| Field | Type | Null | Key | Default | Extra |
+--------------+----------------------+------+-----+-------------------+-----------------------------+
| payment_id | smallint(5) unsigned | NO | PRI | NULL | auto_increment |
| customer_id | smallint(5) unsigned | NO | MUL | NULL | |
| staff_id | tinyint(3) unsigned | NO | MUL | NULL | |
| rental_id | int(11) | YES | MUL | NULL | |
| amount | decimal(5,2) | NO | | NULL | |
| payment_date | datetime | NO | | NULL | |
| last_update | timestamp | NO | | CURRENT_TIMESTAMP | on update CURRENT_TIMESTAMP |
+--------------+----------------------+------+-----+-------------------+-----------------------------+mysql> explain select max(payment_date) from payment\G
*************************** 1. row ***************************
id: 1
select_type: SIMPLE
table: payment
type: ALL
possible_keys: NULL
key: NULL
key_len: NULL
ref: NULL
rows: 16374
Extra:
1 row in set (0.00 sec)
在payment_date上建立索引
create index idx_paydate on payment(payment_date);
mysql> explain select max(payment_date) from payment\G
*************************** 1. row ***************************
id: 1
select_type: SIMPLE
table: NULL
type: NULL
possible_keys: NULL
key: NULL
key_len: NULL
ref: NULL
rows: NULL
Extra: Select tables optimized away
1 row in set (0.00 sec)
table也为null,也是覆盖索引
不需要查询表的数据就能查到结果
