网站导航
> 文章列表 > MySQL 8.0 OCP (1Z0-908) 考点精析-性能优化考点4：慢速查询日志（slow query log）

MySQL 8.0 OCP (1Z0-908) 考点精析-性能优化考点4：慢速查询日志（slow query log）

网友: 文章列表 2024-03-22 04:13:12

MySQL 8.0 OCP (1Z0-908) 考点精析-性能优化考点4：慢速查询日志（slow query log）

文章目录

    • MySQL 8.0 OCP (1Z0-908) 考点精析-性能优化考点4：慢速查询日志（slow query log）
      • 慢速查询日志（slow query log）
      • 慢速查询日志（slow query log）相关参数
        • 1.slow_query_log
        • 2.slow_query_log_file
        • 3. log_slow_admin_statements
        • 4. long_query_time
        • 5. log_queries_not_using_indexes
        • 6. min_examined_row_limit
        • 7. log_throttle_queries_not_using_indexes
      • 慢速查询日志（slow query log）的查看和分析
        • OS工具或命令查看慢速查询日志（slow query log）
        • mysqldumpslow 工具分析慢速查询日志（slow query log）
      • 慢速查询日志（slow query log）的内容说明
      • 清空慢速查询日志（slow query log）
      • 慢速查询日志（slow query log）使用例
      • 例题
      • 例题解析
      • 参考

MySQL 8.0 OCP (1Z0-908) 考点精析-性能优化考点4：慢速查询日志（slow query log）

慢速查询日志（slow query log）

慢速查询日志（slow query log）主要用于查找超过指定时间、执行时间很长的SQL。
默认情况下这个功能是无效的，所以要启用慢速查询日志需要设置slow_query_log 为1(ON)。

慢速查询日志（slow query log）相关参数

下面我们看看慢速查询日志（slow query log）相关参数。

1.slow_query_log

通过设置slow_query_log 参数可以启用和禁用慢速查询日志（0/ON：功能无效，1/OFF：功能有效）。
slow_query_log 选项是可以动态设定的全局系统变量，设置时无需重启。

例：

--默认设置（无效）
mysql> show variables like 'slow_query_log';
+----------------+-------+
| Variable_name  | Value |
+----------------+-------+
| slow_query_log | OFF   |
+----------------+-------+
1 row in set (0.00 sec)--启用慢速查询日志
mysql> SET GLOBAL slow_query_log =1;
Query OK, 0 rows affected (0.01 sec)
或者
mysql>  SET GLOBAL slow_query_log =ON;
Query OK, 0 rows affected (0.00 sec)--确认设置结果
mysql> show variables like 'slow_query_log';
+----------------+-------+
| Variable_name  | Value |
+----------------+-------+
| slow_query_log | ON    |
+----------------+-------+
1 row in set (0.00 sec)

参考：
https://dev.mysql.com/doc/refman/8.0/en/server-system-variables.html#sysvar_slow_query_log
Command-Line Format –slow-query-log[={OFF
System Variable slow_query_log
Scope Global
Dynamic Yes
SET_VAR Hint Applies No
Type Boolean
Default Value OFF

2.slow_query_log_file

slow_query_log_file参数用于控制慢日志文件的写入位置，文件名默认为host_name-slow.log。

mysql> show variables like 'slow_query_log_file';
+---------------------+----------------------------------+
| Variable_name       | Value                            |
+---------------------+----------------------------------+
| slow_query_log_file | /var/lib/mysql/mysql-vm-slow.log |
+---------------------+----------------------------------+
1 row in set (0.00 sec)

由上面的输出我们可以知道，慢日志文件为/var/lib/mysql/mysql-vm-slow.log 。

参考：
https://dev.mysql.com/doc/refman/8.0/en/server-system-variables.html#sysvar_slow_query_log_file
Command-Line Format –slow-query-log-file=file_name
System Variable slow_query_log_file
Scope Global
Dynamic Yes
SET_VAR Hint Applies No
Type File name
Default Value host_name-slow.log

3. log_slow_admin_statements

log_slow_admin_statements用于控制是否将超时的慢管理语句（ ALTER TABLE、ANALYZE TABLE、CHECK TABLE、CREATE INDEX、DROP INDEX、OPTIMIZE TABLE、 REPAIR TABLE）记录到慢查询的日志中。
该选项默认为关闭。

例：

--查看状态
mysql> show variables like 'log_slow_admin_statements';
+---------------------------+-------+
| Variable_name             | Value |
+---------------------------+-------+
| log_slow_admin_statements | OFF   |
+---------------------------+-------+
1 row in set (0.01 sec)
--启用
mysql> SET GLOBAL log_slow_admin_statements=on;
Query OK, 0 rows affected (0.01 sec)--查看状态`
mysql> show variables like 'log_slow_admin_statements';
+---------------------------+-------+
| Variable_name             | Value |
+---------------------------+-------+
| log_slow_admin_statements | ON    |
+---------------------------+-------+
1 row in set (0.01 sec)

参考：
https://dev.mysql.com/doc/refman/8.0/en/server-system-variables.html#sysvar_log_slow_admin_statements
Command-Line Format –log-slow-admin-statements[={OFF
System Variable log_slow_admin_statements
Scope Global
Dynamic Yes
SET_VAR Hint Applies No
Type Boolean
Default Value OFF

4. long_query_time

long_query_time参数用于控制判断慢查询的时间阈值。
只有大于这个时间的阀值（long_query_time）的SQL才会记录到慢查询日志中，默认值是10秒，最小值是0。
通过服务器状态变量 slow_queries可以看到记录的慢SQL数量。

例：

mysql> show variables like 'long_query_time';
+-----------------+-----------+
| Variable_name   | Value     |
+-----------------+-----------+
| long_query_time | 10.000000 |
+-----------------+-----------+
1 row in set (0.00 sec)mysql>  set global long_query_time=1;
Query OK, 0 rows affected (0.00 sec)mysql> show variables like 'long_query_time';
+-----------------+-----------+
| Variable_name   | Value     |
+-----------------+-----------+
| long_query_time | 10.000000 |   --》我们注意到global 修改long_query_time后，在同一个session中确认变量值并未改变。
+-----------------+-----------+
1 row in set (0.00 sec)

新开一个会话后可以看到修改后的long_query_time值。

mysql> show variables like 'long_query_time';
+-----------------+----------+
| Variable_name   | Value    |
+-----------------+----------+
| long_query_time | 1.000000 |
+-----------------+----------+
1 row in set (0.00 sec)

设置long_query_time会话级别的值。
例：

mysql> show status like 'slow_queries';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| Slow_queries  | 0     |
+---------------+-------+
1 row in set (0.00 sec)mysql> set long_query_time=0;
Query OK, 0 rows affected (0.00 sec)mysql> show variables like 'long_query_time';
+-----------------+----------+
| Variable_name   | Value    |
+-----------------+----------+
| long_query_time | 0.000000 |
+-----------------+----------+
1 row in set (0.00 sec)--查看记录的慢SQL数量。
mysql> show status like 'slow_queries';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| Slow_queries  | 2     |
+---------------+-------+
1 row in set (0.00 sec)

参考：
https://dev.mysql.com/doc/refman/8.0/en/server-system-variables.html#sysvar_long_query_time
Command-Line Format –long-query-time=#
System Variable long_query_time
Scope Global, Session
Dynamic Yes
SET_VAR Hint Applies No
Type Numeric
Default Value 10
Minimum Value 0
Maximum Value 31536000
Unit seconds

5. log_queries_not_using_indexes

log_queries_not_using_indexes参数用于控制是否记录未走索引的SQL到慢日志中。
需要注意的是，这个参数的官方定义为“If you enable this variable with the slow query log enabled, queries that are expected to retrieve all rows are logged. ”，所以开启这个选项后，不仅全表扫描的SQL会记录到慢日志中，索引全扫描的SQL也将记录到慢日志中。

参考：
https://dev.mysql.com/doc/refman/8.0/en/server-system-variables.html#sysvar_log_queries_not_using_indexes
Command-Line Format –log-queries-not-using-indexes[={OFF
System Variable log_queries_not_using_indexes
Scope Global
Dynamic Yes
SET_VAR Hint Applies No
Type Boolean
Default Value OFF

6. min_examined_row_limit

min_examined_row_limit参数用于控制记录到慢日志的SQL需要满足的最小返回行数，即SQL语句执行扫描的行数小于该参数设置的值不会被记录到慢日志。

参考：
https://dev.mysql.com/doc/refman/8.0/en/server-system-variables.html#sysvar_min_examined_row_limit
Command-Line Format –min-examined-row-limit=#
System Variable min_examined_row_limit
Scope Global, Session
Dynamic Yes
SET_VAR Hint Applies No
Type Integer
Default Value 0
Minimum Value 0
Maximum Value (64-bit platforms) 18446744073709551615
Maximum Value (32-bit platforms) 4294967295

7. log_throttle_queries_not_using_indexes

开启 log_queries_not_using_indexes 后，通过log_throttle_queries_not_using_indexes参数可以限制每分钟可以写入慢速查询日志的此类查询的数量，参数设置 0 为不限制。

例：

mysql> show variables like 'log_throttle_queries_not_using_indexes';
+----------------------------------------+-------+
| Variable_name                          | Value |
+----------------------------------------+-------+
| log_throttle_queries_not_using_indexes | 0     |
+----------------------------------------+-------+
1 row in set (0.00 sec)

参考：
https://dev.mysql.com/doc/refman/8.0/en/server-system-variables.html#sysvar_log_throttle_queries_not_using_indexes
Command-Line Format –log-throttle-queries-not-using-indexes=#
System Variable log_throttle_queries_not_using_indexes
Scope Global
Dynamic Yes
SET_VAR Hint Applies No
Type Integer
Default Value 0
Minimum Value 0
Maximum Value 4294967295

慢速查询日志（slow query log）的查看和分析

慢速查询日志（slow query log）的查看和分析的方式可以分为两种：

  1. OS工具或命令
  2. 通过mysqldumpslow 工具

OS工具或命令查看慢速查询日志（slow query log）

Linux环境中可以直接使用 less 或 more 命令来查看。

  1. 通过查看slow_query_log_file 参数确认慢速查询日志（slow query log）的位置
  2. 直接使用 less 或 more 命令来查看。

例：

mysql> show variables like 'slow_query%';
+---------------------+----------------------------------+
| Variable_name       | Value                            |
+---------------------+----------------------------------+
| slow_query_log      | ON                               |
| slow_query_log_file | /var/lib/mysql/mysql-vm-slow.log |
+---------------------+----------------------------------+
2 rows in set (0.01 sec)mysql> exit
Bye
ubuntu@mysql-vm:~$ su - root
Password:
root@mysql-vm:~# ls -l /var/lib/mysql/mysql-vm-slow.log
-rw-r----- 1 mysql mysql 1953 Apr 16 02:31 /var/lib/mysql/mysql-vm-slow.log
root@mysql-vm:~# more /var/lib/mysql/mysql-vm-slow.log
/usr/sbin/mysqld, Version: 8.0.32-0ubuntu0.22.04.2 ((Ubuntu)). started with:
Tcp port: 3306  Unix socket: /var/run/mysqld/mysqld.sock
Time                 Id Command    Argument
/usr/sbin/mysqld, Version: 8.0.32-0ubuntu0.22.04.2 ((Ubuntu)). started with:
Tcp port: 3306  Unix socket: /var/run/mysqld/mysqld.sock
Time                 Id Command    Argument
# Time: 2023-04-15T18:21:25.323110Z
# User@Host: root[root] @ localhost []  Id:    54
# Query_time: 0.000433  Lock_time: 0.000000 Rows_sent: 0  Rows_examined: 0
SET timestamp=1681582885;
set long_query_time=0;
# Time: 2023-04-15T18:21:37.852981Z
# User@Host: root[root] @ localhost []  Id:    54
# Query_time: 0.002395  Lock_time: 0.000003 Rows_sent: 1  Rows_examined: 1
SET timestamp=1681582897;
show variables like 'long_query_time';
# Time: 2023-04-15T18:23:55.385870Z
# User@Host: root[root] @ localhost []  Id:    54
# Query_time: 0.022970  Lock_time: 0.000004 Rows_sent: 1  Rows_examined: 0
SET timestamp=1681583035;
select count(*) from sakila.actor;

mysqldumpslow 工具分析慢速查询日志（slow query log）

另一种方式是利用 MySQL 官方提供给我们的mysqldumpslow工具来分析慢速查询日志（slow query log）。
mysqldumpslow工具提供各种选项来过滤输出结果。

ubuntu@mysql-vm:~$ 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 defaultal: average lock timear: average rows sentat: average query timec: countl: lock timer: rows sentt: 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 timeubuntu@mysql-vm:~$

使用mysqldumpslow 工具查看慢速查询日志（slow query log）

例：

root@mysql-vm:/var/lib/mysql# mysqldumpslow /var/lib/mysql/mysql-vm-slow.logReading mysql slow query log from /var/lib/mysql/mysql-vm-slow.log
Count: 1  Time=0.02s (0s)  Lock=0.00s (0s)  Rows=1.0 (1), root[root]@localhostselect count(*) from sakila.actorCount: 1  Time=0.02s (0s)  Lock=0.00s (0s)  Rows=1.0 (1), root[root]@localhostselect count(*) from sakila.film_text

参考：
https://dev.mysql.com/doc/refman/8.0/en/mysqldumpslow.html

慢速查询日志（slow query log）的内容说明

慢速查询日志（slow query log）会针对每个对象查询的输出相应结果。

例：

# Time: 2023-04-15T21:24:11.462101Z
# User@Host: root[root] @ localhost []  Id:    59
# Query_time: 0.025023  Lock_time: 0.000004 Rows_sent: 1  Rows_examined: 0
SET timestamp=1681593851;
select count(*) count_n from sakila.film_text;

各个标签的含义如下：

Time 		        # 慢 SQL 的时间的执行时间
query_time		# SQL 语句的查询时间
lock_time: 	        # 锁的时间
rows_sent: 		    #返回了多少行到客户端
rows_examined:	#执行这条 SQL 服务器端处理了多少行数据
SET timestamp 	#时间戳
select count(*) count_n from sakila.film_text; #对象慢 SQL

清空慢速查询日志（slow query log）

要想清空旧的慢速查询日志（slow query log），需要关闭慢速查询日志，然后使用OS命令删除，再启用慢速查询日志。

例：

1.关闭慢速查询日志

mysql>  show variables like 'slow_query%';
+---------------------+----------------------------------+
| Variable_name       | Value                            |
+---------------------+----------------------------------+
| slow_query_log      | ON                               |
| slow_query_log_file | /var/lib/mysql/mysql-vm-slow.log |
+---------------------+----------------------------------+
2 rows in set (0.00 sec)mysql>  set global slow_query_log =off;
Query OK, 0 rows affected (0.01 sec)mysql> show variables like 'slow_query%';
+---------------------+----------------------------------+
| Variable_name       | Value                            |
+---------------------+----------------------------------+
| slow_query_log      | OFF                              |
| slow_query_log_file | /var/lib/mysql/mysql-vm-slow.log |
+---------------------+----------------------------------+
2 rows in set (0.01 sec)mysql>

2.使用OS命令删除

# rm /var/lib/mysql/mysql-vm-slow.log

3.启用慢速查询日志

mysql> set global slow_query_log =on;
Query OK, 0 rows affected (0.00 sec)mysql> show variables like 'slow_query%';
+---------------------+----------------------------------+
| Variable_name       | Value                            |
+---------------------+----------------------------------+
| slow_query_log      | ON                               |
| slow_query_log_file | /var/lib/mysql/mysql-vm-slow.log |
+---------------------+----------------------------------+
2 rows in set (0.00 sec)

慢速查询日志（slow query log）使用例

  1. 开启慢速查询日志（slow query log）
mysql> set global slow_query_log =on;
Query OK, 0 rows affected (0.00 sec)mysql> show variables like 'slow_query%';
+---------------------+----------------------------------+
| Variable_name       | Value                            |
+---------------------+----------------------------------+
| slow_query_log      | ON                               |
| slow_query_log_file | /var/lib/mysql/mysql-vm-slow.log |
+---------------------+----------------------------------+
2 rows in set (0.00 sec)
  1. 设置条件
    作为例子把当前会话的long_query_time设为0，记录所有当前会话的SQL。
mysql> show variables like 'long_query%';
+-----------------+----------+
| Variable_name   | Value    |
+-----------------+----------+
| long_query_time | 1.000000 |
+-----------------+----------+
1 row in set (0.00 sec)mysql> set long_query_time=0;
Query OK, 0 rows affected (0.00 sec)mysql> show variables like 'long_query%';
+-----------------+----------+
| Variable_name   | Value    |
+-----------------+----------+
| long_query_time | 0.000000 |
+-----------------+----------+
1 row in set (0.00 sec)
  1. 执行SQL
mysql> select count(*) from sakila.film_text;
+----------+
| count(*) |
+----------+
|     1000 |
+----------+
1 row in set (0.03 sec)mysql> select count(*) count_n from sakila.film_text;
+---------+
| count_n |
+---------+
|    1000 |
+---------+
1 row in set (0.03 sec)
  1. 查看慢速查询日志（slow query log）
root@mysql-vm:/var/lib/mysql# more mysql-vm-slow.log
/usr/sbin/mysqld, Version: 8.0.32-0ubuntu0.22.04.2 ((Ubuntu)). started with:
Tcp port: 3306  Unix socket: /var/run/mysqld/mysqld.sock
Time                 Id Command    Argument
root@mysql-vm:/var/lib/mysql# more mysql-vm-slow.log
/usr/sbin/mysqld, Version: 8.0.32-0ubuntu0.22.04.2 ((Ubuntu)). started with:
Tcp port: 3306  Unix socket: /var/run/mysqld/mysqld.sock
Time                 Id Command    Argument
# Time: 2023-04-15T21:22:53.485378Z
# User@Host: root[root] @ localhost []  Id:    59
# Query_time: 0.000458  Lock_time: 0.000000 Rows_sent: 0  Rows_examined: 0
SET timestamp=1681593773;
set long_query_time=0;
# Time: 2023-04-15T21:22:57.503456Z
# User@Host: root[root] @ localhost []  Id:    59
# Query_time: 0.002329  Lock_time: 0.000003 Rows_sent: 1  Rows_examined: 1
SET timestamp=1681593777;
show variables like 'long_query%';
# Time: 2023-04-15T21:23:06.789833Z
# User@Host: root[root] @ localhost []  Id:    59
# Query_time: 0.024464  Lock_time: 0.000003 Rows_sent: 1  Rows_examined: 0
SET timestamp=1681593786;
select count(*) from sakila.film_text;
root@mysql-vm:/var/lib/mysql# more mysql-vm-slow.log
/usr/sbin/mysqld, Version: 8.0.32-0ubuntu0.22.04.2 ((Ubuntu)). started with:
Tcp port: 3306  Unix socket: /var/run/mysqld/mysqld.sock
Time                 Id Command    Argument
# Time: 2023-04-15T21:22:53.485378Z
# User@Host: root[root] @ localhost []  Id:    59
# Query_time: 0.000458  Lock_time: 0.000000 Rows_sent: 0  Rows_examined: 0
SET timestamp=1681593773;
set long_query_time=0;
# Time: 2023-04-15T21:22:57.503456Z
# User@Host: root[root] @ localhost []  Id:    59
# Query_time: 0.002329  Lock_time: 0.000003 Rows_sent: 1  Rows_examined: 1
SET timestamp=1681593777;
show variables like 'long_query%';
# Time: 2023-04-15T21:23:06.789833Z
# User@Host: root[root] @ localhost []  Id:    59
# Query_time: 0.024464  Lock_time: 0.000003 Rows_sent: 1  Rows_examined: 0
SET timestamp=1681593786;
select count(*) from sakila.film_text;
# Time: 2023-04-15T21:24:11.462101Z
# User@Host: root[root] @ localhost []  Id:    59
# Query_time: 0.025023  Lock_time: 0.000004 Rows_sent: 1  Rows_examined: 0
SET timestamp=1681593851;
select count(*) count_n from sakila.film_text;
root@mysql-vm:/var/lib/mysql#

例题

Choose the best answer. 
Which utility would you use to view the queries in the slow query log sorted by average query time?A) mysqlcheck
B) mysqlshow
C) mysqlimport
D) mysqldump
E) mysqldumpslow

例题解析

通过前面的介绍我们知道，mysqldumpslow的-s 选项可以进行排序。

参考：
https://dev.mysql.com/doc/refman/8.0/en/mysqldumpslow.html#option_mysqldumpslow_sort

-s sort_type
How to sort the output. The value of sort_type should be chosen from the following list:
t, at: Sort by query time or average query time
l, al: Sort by lock time or average lock time
r, ar: Sort by rows sent or average rows sent
c: Sort by count

参考答案：E

参考

https://dev.mysql.com/doc/refman/8.0/en/slow-query-log.html
https://dev.mysql.com/doc/refman/8.0/en/mysqldumpslow.html

网络标签：

相关问题