MySQL 日志之--慢查询日志（slow-query-log）

水深无声 2022-08-18 03:12 239阅读 0赞

**MySQL 日志之--慢查询日志（slow-query-log）**

**慢查询日志：**  
  
 **MySQL慢查询日志记录下所有执行超过long\_query\_time时间的SQL语句，帮你找到执行慢的SQL，方便我们对这些SQL进行优化。**    
  
**慢查询日志的配置：**

**默认情况下，mysql没有启用慢查询日志。**

**\[root@rh64 ~\]\# mysql -u root -p**  
Enter password:

Welcome to the MySQL monitor.  Commands end with ; or \g.
    Your MySQL connection id is 1
    Server version: 5.6.25-73.1 Percona Server (GPL), Release 73.1, Revision 07b797f
    Copyright (c) 2009-2015 Percona LLC and/or its affiliates
    Copyright (c) 2000, 2015, Oracle and/or its affiliates. All rights reserved.
    Oracle is a registered trademark of Oracle Corporation and/or its
    affiliates. Other names may be trademarks of their respective
    owners。
    Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.

[mysqld]
    datadir=/var/lib/mysql
    socket=/var/lib/mysql/mysql.sock
    user=mysql
    # Disabling symbolic-links is recommended to prevent assorted security risks
    symbolic-links=0
    innodb_data_file_path=ibdata1:12M;ibdata2:10M:autoextend
    sql_mode=STRICT_TRANS_TABLES ,NO_ENGINE_SUBSTITUTION
    slow_query_log=true
    slow_query_log_file = "/var/lib/mysql/rh64-slow.log"
    long_query_time=1
    log-queries-not-using-indexes=true
    [mysqld_safe]
    log-error=/var/log/mysqld.log
    pid-file=/var/run/mysqld/mysqld.pid
    explicit_defaults_for_timestamp=true
    innodb_buffer_pool_size = 128M
    join_buffer_size = 128M
    sort_buffer_size = 2M
    read_rnd_buffer_size = 2M

use prod;
    SET timestamp=1449476453;
    insert into emp1 select * from emp1;
    # Time: 151207 16:21:11
    # User@Host: root[root] @ localhost []  Id:     2
    # Schema: prod  Last_errno: 0  Killed: 0
    # Query_time: 16.748949  Lock_time: 0.000137  Rows_sent: 0  Rows_examined: 1236992  Rows_affected: 618496
    # Bytes_sent: 58

SET timestamp=1449476471;
    insert into emp1 select * from emp1;
    [root@rh64 mysql]# tail -f rh64-slow.log 
    use prod;

SET timestamp=1449476453;
    insert into emp1 select * from emp1;
    # Time: 151207 16:21:11
    # User@Host: root[root] @ localhost []  Id:     2
    # Schema: prod  Last_errno: 0  Killed: 0
    # Query_time: 16.748949  Lock_time: 0.000137  Rows_sent: 0  Rows_examined: 1236992  Rows_affected: 618496
    # Bytes_sent: 58

SET timestamp=1449476471;
    insert into emp1 select * from emp1;
    # Time: 151207 16:22:54
    # User@Host: root[root] @ localhost []  Id:     2
    # Schema: prod  Last_errno: 0  Killed: 0
    # Query_time: 44.036039  Lock_time: 0.000083  Rows_sent: 0  Rows_examined: 2473984  Rows_affected: 1236992
    # Bytes_sent: 59

SET timestamp=1449476574;
    insert into emp1 select * from emp1;
    # Time: 151207 16:26:46
    # User@Host: root[root] @ localhost []  Id:     2
    # Schema: prod  Last_errno: 0  Killed: 0
    # Query_time: 106.674422  Lock_time: 0.000148  Rows_sent: 0  Rows_examined: 4947968  Rows_affected: 2473984
    # Bytes_sent: 59

SET timestamp=1449476806;
    insert into emp1 select * from emp1;

**记录没有使用索引的语句：  
mysql> set @@global.log\_queries\_not\_using\_indexes=on;**  
Query OK, 0 rows affected (0.00 sec)  
  
mysql> show variables like '%index%';  
\+----------------------------------------+-------+  
| Variable\_name                          | Value |  
\+----------------------------------------+-------+  
| eq\_range\_index\_dive\_limit              | 10    |  
| expand\_fast\_index\_creation             | OFF   |  
| innodb\_adaptive\_hash\_index             | ON    |  
| innodb\_adaptive\_hash\_index\_partitions  | 1     |  
| innodb\_cmp\_per\_index\_enabled           | OFF   |  
| log\_bin\_index                          |       |  
**| log\_queries\_not\_using\_indexes          | ON    |**  
| log\_throttle\_queries\_not\_using\_indexes | 0     |  
| relay\_log\_index                        |       |  
\+----------------------------------------+-------+  
9 rows in set (0.00 sec)  
  
**测试：  
mysql> select count(\*) from emp1 where empno=7788;**  
\+----------+  
| count(\*) |  
\+----------+  
|   688128 |  
\+----------+  
1 row in set (4.03 sec)  
  
**\[root@rh64 mysql\]\# tail rh64-slow.log**

SET timestamp=1449476806;
    insert into emp1 select * from emp1;
    # Time: 151207 16:30:44
    # User@Host: root[root] @ localhost []  Id:     2
    # Schema: prod  Last_errno: 0  Killed: 0
    # Query_time: 4.025612  Lock_time: 0.000098  Rows_sent: 1  Rows_examined: 4947968  Rows_affected: 0
    # Bytes_sent: 68

SET timestamp=1449477044;
    select count(*) from emp1 where empno=7788;

**4、通过mysqldumpslow工具查看慢查询日志  
\[root@rh64 mysql\]\# mysqldumpslow**

Can't determine basedir from 'my_print_defaults mysqld' output: --datadir=/var/lib/mysql
    --socket=/var/lib/mysql/mysql.sock
    --user=mysql
    --symbolic-links=0
    --innodb_data_file_path=ibdata1:12M;ibdata2:10M:autoextend
    --sql_mode=STRICT_TRANS_TABLES ,NO_ENGINE_SUBSTITUTION

**\[root@rh64 mysql\]\# mysqldumpslow --help**

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

**  \[root@rh64 mysql\]\# mysqldumpslow rh64-slow.log **

Reading mysql slow query log from rh64-slow.log
    Count: 3  Time=0.00s (0s)  Lock=0.00s (0s)  Rows=0.0 (0), root[root]@localhost
      # Schema: prod  Last_errno: N  Killed: N
      # Query_time: N.N  Lock_time: N.N  Rows_sent: N  Rows_examined: N  Rows_affected: N
      # Bytes_sent: N
      SET timestamp=N;
      insert into emp1 select * from emp1
    
    Count: 1  Time=0.00s (0s)  Lock=0.00s (0s)  Rows=0.0 (0), root[root]@localhost
      # Schema: prod  Last_errno: N  Killed: N
      # Query_time: N.N  Lock_time: N.N  Rows_sent: N  Rows_examined: N  Rows_affected: N
      # Bytes_sent: N
      use prod;
      SET timestamp=N;
      insert into emp1 select * from emp1
    
    Count: 1  Time=0.00s (0s)  Lock=0.00s (0s)  Rows=0.0 (0), root[root]@localhost
      # Schema: prod  Last_errno: N  Killed: N
      # Query_time: N.N  Lock_time: N.N  Rows_sent: N  Rows_examined: N  Rows_affected: N
      # Bytes_sent: N
      SET timestamp=N;
      select count(*) from emp1 where empno=N
      
      按照平均锁定时间进行排序，查找前10名：
      [root@rh64 mysql]# mysqldumpslow -s al -n 10 rh64-slow.log 
    Reading mysql slow query log from rh64-slow.log
    Count: 3  Time=0.00s (0s)  Lock=0.00s (0s)  Rows=0.0 (0), root[root]@localhost
      # Schema: prod  Last_errno: N  Killed: N
      # Query_time: N.N  Lock_time: N.N  Rows_sent: N  Rows_examined: N  Rows_affected: N
      # Bytes_sent: N
      SET timestamp=N;
      insert into emp1 select * from emp1
    Count: 1  Time=0.00s (0s)  Lock=0.00s (0s)  Rows=0.0 (0), root[root]@localhost
      # Schema: prod  Last_errno: N  Killed: N
      # Query_time: N.N  Lock_time: N.N  Rows_sent: N  Rows_examined: N  Rows_affected: N
      # Bytes_sent: N
      use prod;
      SET timestamp=N;
      insert into emp1 select * from emp1
    Count: 1  Time=0.00s (0s)  Lock=0.00s (0s)  Rows=0.0 (0), root[root]@localhost
      # Schema: prod  Last_errno: N  Killed: N
      # Query_time: N.N  Lock_time: N.N  Rows_sent: N  Rows_examined: N  Rows_affected: N
      # Bytes_sent: N
      SET timestamp=N;
      select count(*) from emp1 where empno=N