mysql慢查询和慢查询日志分析工具及优化_慢查询

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

View 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\G

View 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,也是覆盖索引
不需要查询表的数据就能查到结果