简介
对于将数据库整合到其技术栈中的网站和应用程序,用户体验的很大一部分会受到数据库性能的影响。慢查询会延迟数据检索、页面渲染以及任何其他与数据层交互的操作。由于这种潜在的巨大影响,了解如何识别和修复这些问题至关重要。
在本文中,我们将讨论识别 MySQL 数据库中性能不佳的查询的各种方法。这将为优化这些查询并提高其性能奠定基础。
检查活动查询和进程
检查 MySQL 当前运行状态的最直接方法之一是查看其进程列表。
显示完整进程列表
要显示 MySQL 处理线程正在执行的所有当前操作,请键入
SHOW FULL PROCESSLIST;
+----+-----------------+-----------+------+---------+---------+------------------------+-----------------------+| Id | User | Host | db | Command | Time | State | Info |+----+-----------------+-----------+------+---------+---------+------------------------+-----------------------+| 5 | event_scheduler | localhost | NULL | Daemon | 1834441 | Waiting on empty queue | NULL || 50 | root | localhost | NULL | Query | 0 | init | show full processlist |+----+-----------------+-----------+------+---------+---------+------------------------+-----------------------+2 rows in set (0.00 sec)
上面的输出显示一个空闲服务器,只有我们自己的查询和一个长期运行的事件监听器。一个活动服务器会显示更多的进程,其中一些可能运行时间很长。如果没有 FULL 修饰符,此命令将只显示前 100 个进程,这可能会根据您的服务器活动截断您的结果,也可能不会。
需要注意的一些重要部分是 Time 和 State 列。Time 列计算线程处于所提及的 State 中的秒数。如果您发现某些进程的 Time 值与您对给定操作的预期不符,那么可能是时候进一步调查了。
检查存储引擎状态
另一个需要检查的地方是实际存储引擎的状态。
您可以通过键入以下命令找到与给定表关联的存储引擎
SHOW CREATE TABLE <database>.<table>\G
例如,要显示 mysql.time_zone 表使用的存储引擎,请键入
SHOW CREATE TABLE mysql.time_zone`\G
*************************** 1. row ***************************Table: time_zoneCreate Table: CREATE TABLE `time_zone` (`Time_zone_id` int unsigned NOT NULL AUTO_INCREMENT,`Use_leap_seconds` enum('Y','N') CHARACTER SET utf8 COLLATE utf8_general_ci NOT NULL DEFAULT 'N',PRIMARY KEY (`Time_zone_id`)) /*!50100 TABLESPACE `mysql` */ ENGINE=InnoDB DEFAULT CHARSET=utf8mb3 STATS_PERSISTENT=0 ROW_FORMAT=DYNAMIC COMMENT='Time zones'1 row in set (0.01 sec)
ENGINE=InnoDB 表示该表正在使用 InnoDB 存储引擎。这是大多数配置中的默认存储引擎,因此您可能需要检查其状态。
您可以通过键入以下命令显示 InnoDB 引擎的状态
SHOW ENGINE INNODB STATUS\G
*************************** 1. row ***************************Type: InnoDBName:Status:=====================================2022-02-26 11:55:52 139992513984256 INNODB MONITOR OUTPUT=====================================Per second averages calculated from the last 16 seconds-----------------BACKGROUND THREAD-----------------srv_master_thread loops: 1 srv_active, 0 srv_shutdown, 1835091 srv_idlesrv_master_thread log flush and writes: 0----------SEMAPHORES----------OS WAIT ARRAY INFO: reservation count 555OS WAIT ARRAY INFO: signal count 457RW-shared spins 0, rounds 0, OS waits 0RW-excl spins 0, rounds 0, OS waits 0RW-sx spins 0, rounds 0, OS waits 0Spin rounds per wait: 0.00 RW-shared, 0.00 RW-excl, 0.00 RW-sx------------TRANSACTIONS------------Trx id counter 8778Purge done for trx's n:o < 8713 undo n:o < 0 state: running but idleHistory list length 0LIST OF TRANSACTIONS FOR EACH SESSION:---TRANSACTION 421467955133656, not started0 lock struct(s), heap size 1128, 0 row lock(s)---TRANSACTION 421467955132848, not started0 lock struct(s), heap size 1128, 0 row lock(s)---TRANSACTION 421467955132040, not started0 lock struct(s), heap size 1128, 0 row lock(s)--------FILE I/O--------I/O thread 0 state: waiting for completed aio requests (insert buffer thread)I/O thread 1 state: waiting for completed aio requests (log thread)I/O thread 2 state: waiting for completed aio requests (read thread)I/O thread 3 state: waiting for completed aio requests (read thread)I/O thread 4 state: waiting for completed aio requests (read thread)I/O thread 5 state: waiting for completed aio requests (read thread)I/O thread 6 state: waiting for completed aio requests (write thread)I/O thread 7 state: waiting for completed aio requests (write thread)I/O thread 8 state: waiting for completed aio requests (write thread)I/O thread 9 state: waiting for completed aio requests (write thread)Pending normal aio reads: [0, 0, 0, 0] , aio writes: [0, 0, 0, 0] ,ibuf aio reads:, log i/o's:, sync i/o's:Pending flushes (fsync) log: 0; buffer pool: 01779 OS file reads, 3384 OS file writes, 1870 OS fsyncs0.00 reads/s, 0 avg bytes/read, 0.00 writes/s, 0.00 fsyncs/s-------------------------------------INSERT BUFFER AND ADAPTIVE HASH INDEX-------------------------------------Ibuf: size 1, free list len 0, seg size 2, 0 mergesmerged operations:insert 0, delete mark 0, delete 0discarded operations:insert 0, delete mark 0, delete 0Hash table size 34679, node heap has 2 buffer(s)Hash table size 34679, node heap has 9 buffer(s)Hash table size 34679, node heap has 9 buffer(s)Hash table size 34679, node heap has 15 buffer(s)Hash table size 34679, node heap has 7 buffer(s)Hash table size 34679, node heap has 3 buffer(s)Hash table size 34679, node heap has 4 buffer(s)Hash table size 34679, node heap has 6 buffer(s)0.00 hash searches/s, 0.00 non-hash searches/s---LOG---Log sequence number 38540718Log buffer assigned up to 38540718Log buffer completed up to 38540718Log written up to 38540718Log flushed up to 38540718Added dirty pages up to 38540718Pages flushed up to 38540718Last checkpoint at 385407182197 log i/o's done, 0.00 log i/o's/second----------------------BUFFER POOL AND MEMORY----------------------Total large memory allocated 0Dictionary memory allocated 473011Buffer pool size 8192Free buffers 6241Database pages 1896Old database pages 719Modified db pages 0Pending reads 0Pending writes: LRU 0, flush list 0, single page 0Pages made young 8, not young 00.00 youngs/s, 0.00 non-youngs/sPages read 1754, created 142, written 9260.00 reads/s, 0.00 creates/s, 0.00 writes/sNo buffer pool page gets since the last printoutPages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/sLRU len: 1896, unzip_LRU len: 0I/O sum[0]:cur[0], unzip sum[0]:cur[0]--------------ROW OPERATIONS--------------0 queries inside InnoDB, 0 queries in queue0 read views open inside InnoDBProcess ID=59529, Main thread ID=139992560166656 , state=sleepingNumber of rows inserted 0, updated 0, deleted 0, read 00.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.00 reads/sNumber of system rows inserted 0, updated 317, deleted 0, read 61280.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.00 reads/s----------------------------END OF INNODB MONITOR OUTPUT============================1 row in set (0.00 sec)
输出将包含大量关于引擎正在使用的资源、正在执行的进程等信息。您可以使用此信息来了解是否存在执行瓶颈或争用进程的数量是否导致性能问题。
启用慢查询日志
获取关于长时间运行或缓慢执行的查询的更多信息的一种方法是使用慢查询日志。慢查询日志会告诉 MySQL 每当查询超过某个执行阈值时进行记录。这对于精确定位运行不佳的特定查询非常有用,而无需在进程列表中实时捕获它。
检查 MySQL 是否正在记录慢查询
您应该做的第一件事是验证慢查询日志的当前状态。如果慢查询日志已经启用,您无需执行任何操作。
您可以通过键入以下命令检查慢查询日志是否已启用
SHOW GLOBAL VARIABLES LIKE 'slow_query_log%';
+---------------------+------------------------------------+| Variable_name | Value |+---------------------+------------------------------------+| slow_query_log | OFF || slow_query_log_file | /var/lib/mysql/mysqlutils-slow.log |+---------------------+------------------------------------+2 rows in set (0.01 sec)
上述输出表示慢查询当前未被记录,因为该功能已关闭。
如果慢查询日志已开启,您的输出将如下所示
+---------------------+-------------------------------+| Variable_name | Value |+---------------------+-------------------------------+| slow_query_log | ON || slow_query_log_file | /var/log/mysql/mysql-slow.log |+---------------------+-------------------------------+2 rows in set (0.02 sec)
现在您已了解当前状态,您可以根据需要进行更改。
配置 MySQL 记录慢查询
在继续之前,需要注意的是,虽然慢查询日志非常有用,但它可能会带来额外的性能影响。MySQL 必须执行额外的操作来计时每个查询并记录结果到日志中。这可能会影响性能并意外地占用硬盘空间。
并非所有时候都记录慢查询都是一个好主意。相反,在您积极调查问题时启用该功能,并在完成后禁用它。
考虑到这一点,您可以通过修改 MySQL 服务器的配置文件来配置慢查询日志。您还可以交互式地修改这些值,但在配置中设置好的默认值将使以后更容易交互式调整。
打开 MySQL 的配置文件。在大多数基于 Debian Linux 的系统上,配置文件将位于 /etc/mysql/mysql.conf.d/mysqld.conf
sudo vim /etc/mysql/mysql.conf.d/mysqld.conf
我们将需要修改或可能添加以下设置
| 变量 | 设置 | 描述 |
|---|---|---|
slow_query_log | ON | 切换是否启用慢查询。 |
slow_query_log_file | /var/log/mysql/mysql-slow.log | 记录慢查询的日志文件。 |
long_query_time | (时间,以秒为单位) | 查询被认为是“慢查询”之前必须经过的阈值(以秒为单位)。 |
min_examined_row_limit | (行数) | 查询在成为慢查询候选之前必须考虑的行数。 |
log_slow_admin_statements | ON | 切换管理命令是否也受日志记录影响。 |
log_queries_not_using_indexes | ON | 切换查询是否在不使用索引的情况下被记录。 |
log_slow_extra | ON | 对于 MySQL 服务器 8.0.14 或更高版本,此选项用于切换是否记录有关查询的额外信息。 |
log_slow_replica_statements | ON | 对于 MySQL 服务器 8.0.26 或更高版本,此选项用于切换是否记录在副本上执行的慢语句。这仅适用于 binlog_format 设置为 STATEMENT 或 MIXED 的语句。 |
log_slow_slave_statements | ON | 对于 MySQL 服务器 8.0.25 或更早版本,此选项用于切换是否记录在副本上执行的慢语句。这仅适用于 binlog_format 设置为 STATEMENT 或 MIXED 的语句。 |
因此,例如,如果我们想开启所有可选日志记录,并记录任何检查至少 100 行且执行时间超过 2 秒的语句,我们可以使用以下设置
; enable MySQL to log slow queriesslow_query_log = ON; query log locationslow_query_log_file = /var/log/mysql/mysql-slow.log; amount of seconds that a query must surpass to be loggedlong_query_time = 2; minimum number of rows affected for a query to be loggedmin_examined_row_limit = 100; include administrative commands in the logslog_slow_admin_statements = ON; also log queries that are not using indexeslog_queries_not_using_indexes = ON; for MySQL servers version 8.0.14 or later, we can; get extra information by setting thislog_slow_extra = ON; Also log slow statements that have executed on; the replica; This only will log statements if `binlog_format` is; set to `STATEMENT` or `MIXED` and the statement is; logged in statement format; RE: https://dev.mysqlserver.cn/doc/refman/8.0/en/replication-options-replica.html#sysvar_log_slow_replica_statements; This option name depends on your MySQL version:; versions >= 8.0.26: log_slow_replica_statements; versions < 8.0.26: log_slow_slave_statements; log_slow_slave_statements = ONlog_slow_replica_statements = ON
保存并关闭文件后,您可以通过键入以下命令验证您的配置更改
sudo mysqld --validate-config
如果没有返回错误,您的 MySQL 服务器配置文件在语法上是有效的。您可以通过键入以下命令重启 MySQL 服务器进程
sudo systemctl restart mysql
您可以通过重新运行原始发现查询来验证慢查询是否已启用
SHOW GLOBAL VARIABLES LIKE 'slow_query_log%';
一旦您按照需要配置了慢查询,就可以在 MySQL 内部根据需要启用和禁用它。调整值的语法如下所示
SET GLOBAL slow_query_log = 'OFF';
使用 mysqldumpslow 分析慢查询日志
一旦您有了慢查询日志生成的文件,您可以通过几种不同的方式对其进行分析,以准确找出问题所在。
分析日志最简单的方法是使用 mysqldumpslow 工具,因为它包含在 MySQL 服务器安装中。要使用它,您可以将其指向您生成的慢查询日志
sudo mysqldumpslow /var/log/mysql/mysql-slow.log
Reading mysql slow query log from /var/log/mysql/mysql-slow.logCount: 4 Time=4.25s (17s) Lock=0.00s (0s) Rows=1.0 (4), root[root]@localhostselect sleep(N)
以上输出显示,根据我们的标准,有四个查询被认为是“慢查询”。它们都是 SELECT SLEEP(); 查询的不同变体,命令中带有不同的数字(由 N 占位符表示)(如果您想测试此功能,请确保 min_examined_row_limit 未设置)。执行这些语句的实际时间约为 17 秒。
mysqldumpslow 命令包含几个选项来控制输出的排序和显示。例如,您可以使用 -t 选项将结果限制为前“N”个结果。例如,以下显示前五个结果
sudo mysqldumpslow -t 5 /var/log/mysql/mysql-slow.log
您可以使用 -s 选项更改排序顺序。您可以按查询时间 (t)、锁定时间 (l)、发送的行数 (r) 或这些指标的平均值 (at、al 和 ar) 进行排序。默认情况下,mysqldumpslow 按平均查询时间 (at) 排序。
要按锁定时间量显示前三个查询,您可以键入
sudo mysqldumpslow -t 3 -s l /var/log/mysql/mysql-slow.log
使用 pt-query-digest 分析慢查询日志
另一个流行的分析慢查询日志的工具是 Percona 开发的 pt-query-digest 工具。pt-query-digest 工具是 Percona Toolkit 的一部分,Percona Toolkit 是一套开源命令行工具,旨在帮助数据库管理员更轻松地管理数据库。
第一步是将 Percona Toolkit 下载到您的服务器。您可以通过在Percona Toolkit 下载页面上选择您想要的工具包版本和您将使用的平台来找到相应的文件。
下载并安装适用于您平台的工具包版本后,您应该可以使用 pt-query-digest 工具了。
针对慢查询日志运行 pt-query-digest 会比 mysqldumpslow 生成更多的输出
sudo pt-query-digest /var/log/mysql/mysql-slow.log
# A software update is available:# 680ms user time, 100ms system time, 44.71M rss, 59.35M vsz# Current date: Sat Feb 26 13:06:41 2022# Hostname: mysqlutils# Files: /var/log/mysql/mysql-slow.log# Overall: 4 total, 1 unique, 0.07 QPS, 0.30x concurrency ________________# Time range: 2022-02-26T12:44:35 to 2022-02-26T12:45:32# Attribute total min max avg 95% stddev median# ============ ======= ======= ======= ======= ======= ======= =======# Exec time 17s 2s 8s 4s 8s 2s 6s# Lock time 0 0 0 0 0 0 0# Rows sent 4 1 1 1 1 0 1# Rows examine 4 1 1 1 1 0 1# Bytes sent 224 56 56 56 56 0 56# Query size 60 15 15 15 15 0 15# Bytes receiv 0 0 0 0 0 0 0# Created tmp 0 0 0 0 0 0 0# Created tmp 0 0 0 0 0 0 0# Errno 0 0 0 0 0 0 0# Read first 0 0 0 0 0 0 0# Read key 0 0 0 0 0 0 0# Read last 0 0 0 0 0 0 0# Read next 0 0 0 0 0 0 0# Read prev 0 0 0 0 0 0 0# Read rnd 0 0 0 0 0 0 0# Read rnd nex 0 0 0 0 0 0 0# Sort merge p 0 0 0 0 0 0 0# Sort range c 0 0 0 0 0 0 0# Sort rows 0 0 0 0 0 0 0# Sort scan co 0 0 0 0 0 0 0# Profile# Rank Query ID Response time Calls R/Call V/M# ==== =================================== ============== ===== ====== ===# 1 0x59A74D08D407B5EDF9A57DD5A41825CA 17.0039 100.0% 4 4.2510 1.12 SELECT# Query 1: 0.07 QPS, 0.30x concurrency, ID 0x59A74D08D407B5EDF9A57DD5A41825CA at byte 1266# This item is included in the report because it matches --limit.# Scores: V/M = 1.12# Time range: 2022-02-26T12:44:35 to 2022-02-26T12:45:32# Attribute pct total min max avg 95% stddev median# ============ === ======= ======= ======= ======= ======= ======= =======# Count 100 4# Exec time 100 17s 2s 8s 4s 8s 2s 6s# Lock time 0 0 0 0 0 0 0 0# Rows sent 100 4 1 1 1 1 0 1# Rows examine 100 4 1 1 1 1 0 1# Bytes sent 100 224 56 56 56 56 0 56# Query size 100 60 15 15 15 15 0 15# Bytes receiv 0 0 0 0 0 0 0 0# Created tmp 0 0 0 0 0 0 0 0# Created tmp 0 0 0 0 0 0 0 0# Errno 0 0 0 0 0 0 0 0# Read first 0 0 0 0 0 0 0 0# Read key 0 0 0 0 0 0 0 0# Read last 0 0 0 0 0 0 0 0# Read next 0 0 0 0 0 0 0 0# Read prev 0 0 0 0 0 0 0 0# Read rnd 0 0 0 0 0 0 0 0# Read rnd nex 0 0 0 0 0 0 0 0# Sort merge p 0 0 0 0 0 0 0 0# Sort range c 0 0 0 0 0 0 0 0# Sort rows 0 0 0 0 0 0 0 0# Sort scan co 0 0 0 0 0 0 0 0# String:# End 2022-02-26... (1/25%), 2022-02-26... (1/25%)... 2 more# Hosts localhost# Start 2022-02-26... (1/25%), 2022-02-26... (1/25%)... 2 more# Users root# Query_time distribution# 1us# 10us# 100us# 1ms# 10ms# 100ms# 1s ################################################################# 10s+# EXPLAIN /*!50100 PARTITIONS*/select sleep(8)\G
输出显示执行时间、查询大小、锁定时间、检查和发送的行数等等。pt-query-digest 命令有许多不同的选项,用于调整输出并仅显示您感兴趣的项。请查阅手册页以了解可能的功能。
结论
能够发现查询执行中的瓶颈对于维护数据库和应用程序的性能至关重要。当出现性能下降时,重要的是要有策略来定位这些问题区域并找出其影响范围。
MySQL 生态系统拥有许多旨在简化这些任务的工具。查看活动进程和存储引擎状态,以及启用和分析慢查询日志信息,为您提供了定位最昂贵查询所需的信息。在我们的下一篇指南中,我们将讨论如何实际优化您发现的查询以及在保持最佳性能方面需要记住的事项。
如果您正在将 Prisma 与 MySQL 数据库一起使用,您可以在文档的查询优化部分了解优化查询的方法。这将帮助您了解在使用 Prisma 时各种查询结构如何影响数据库性能。
