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 time
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\G
找出有问题的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,也是覆盖索引 不需要查询表的数据就能查到结果
