MySQL 性能模式是宝贵数据的金矿。在您可以从中提取的许多块中，有一个事务的历史报告：一个事务执行了多长时间，其中执行了哪些查询（带有查询指标），以及查询之间的空闲时间。挖掘这些信息并非易事，但它很有趣，这篇博文展示了如何开始。
这篇博文是十一篇中的第九篇：一篇用于序言，十篇用于我的书 Efficient MySQL Performance 的每一章。完整列表是 tags/efficient-mysql-performance。
查询与事务
首先，为什么要关心事务而不是查询？毕竟，性能是查询响应时间。虽然这是真的，查询响应时间是 MySQL 性能的北极星，但事务是相对于应用程序的工作单元。
例如，一个应用程序可能有一个多语句事务来更新用户配置文件。从应用程序的角度来看，“更新用户资料”是一个单一的逻辑事件（包含多个语句）。因此，了解和分析该事件（事务）的响应时间很有用。 （了解它的吞吐量和其他指标也很有用，但为了简单起见，我们将坚持使用响应时间。）此外，正如我们将在本博文后面看到的那样，事务响应时间不是其构成查询响应时间的总和.事件层次结构开始解释原因。
事件层次结构
交易
└── 声明
└── 阶段
└── 等待
引用 MySQL 手册：
性能模式监视服务器事件。 “事件”是服务器所做的任何需要时间的事情，并且已经过检测，以便可以收集时间信息。通常，事件可以是函数调用、操作系统等待、SQL 语句执行的一个阶段（如解析或排序），或者整个语句或一组语句。
MySQL 将事件组织到上面显示的层次结构中。实际上，每个事件都是一次交易。事务包含语句，这些语句通常是查询，但并非总是如此。语句有不同的执行阶段：解析 SQL、打开表、执行等等。最后但并非最不重要的一点是，阶段会产生等待，例如等待磁盘 I/O 或客户端。
对事件和事件层次结构的简要介绍是高效 MySQL 性能第 8 章开头的原因：
MySQL 具有非事务性存储引擎，例如 MyISAM，但 InnoDB 是默认的和假定的规范。因此，实际上，默认情况下，每个 MySQL 查询都在一个事务中执行，即使是单个 SELECT 语句。
要检查事务，您必须深入事件层次结构及其各种表。 Performance Schema 非常庞大，因此我无法在简单的博客文章中介绍它。至少，请阅读：
- 27.9 当前和历史事件的性能模式表。
- 27.12 性能模式表说明
- 27.12.1 性能模式表参考
这三页会给你一个土地的布局。
除此之外，重要的是要知道每个事件都有一个事件 ID，它是每个线程单调递增的整数值。所以事件表的主键通常是(thread_id, event_id)。由于事件是按层次结构组织的，因此大多数事件表都有 end_event_id、nesting_event_id 和 nesting_event_type 列。这允许我们通过加入嵌套在给定事务事件 ID 下的所有事件来挖掘事务的性能模式。
我不会在这篇博文中讨论如何设置或配置性能模式。对于下面的示例，我已启用大多数工具来生成完整示例，但在繁忙的生产服务器上，如此广泛的工具可能不是一个好主意。
检查交易
对于下面的例子，我使用了整本书都使用的表元素；您可以在 https://github.com/efficient-mysql-performance/examples 下载它。
交易超级简单：
BEGIN;
SELECT * FROM TABLE elem;
DELETE FROM elem WHERE id=10;
COMMIT;
我手动输入了这四个查询，这是我们稍后会看到的重要细节。
但这四个查询不是重点。 事务是焦点，目标是从性能模式中提取所有事件，从而在提交后重构整个事务。
说起来容易做起来难。
我将以两种方式展示这个例子。 首先是“原始矿石”：来自相关性能模式表的原始查询和输出。 与原矿石一样，这些数据需要经过精炼才能发挥作用。 其次是“元宝”：将原始数据细化为相关事件的颜色编码组，因此更容易从头到尾检查交易。
原矿
交易
首先我们提取交易（层次结构的顶部）：
SELECT
thread_id, event_id, end_event_id, event_name, nesting_event_id, nesting_event_type,
ROUND(timer_wait/1000000) t
FROM
events_transactions_history
WHERE
autocommit='NO';
+-----------+----------+--------------+-------------+------------------+--------------------+---------+
| thread_id | event_id | end_event_id | event_name | NESTING_EVENT_ID | NESTING_EVENT_TYPE | t |
+-----------+----------+--------------+-------------+------------------+--------------------+---------+
| 1 | 123 | 126 | transaction | NULL | NULL | 26 |
| 54 | 233 | 281 | transaction | 229 | STATEMENT | 7729078 |
+-----------+----------+--------------+-------------+------------------+--------------------+---------+
线程 ID 1 是 MySQL 的主线程，所以忽略它。 我们的线程 ID 是 54，这很重要：我们只需要 thread_id=54 的嵌套事件。
autocommit=‘NO’ 谓词也很重要：默认情况下 MySQL 自动提交是打开的。 启用自动提交的单个 SELECT 是一个隐式事务：用户（或应用程序）没有显式执行 BEGIN 或 START TRANSACTION。 因此，隐式事务通常是单个语句（查询）。 但是我们真正想要检查的是显式的多语句事务，例如这个例子。 因此，我们必须过滤 where autocommit=‘NO’。
但是请注意，即使启用了自动提交，以下显式事务也是可能的，但很浪费：
BEGIN;
-- One query
COMMIT;
我说这很浪费，因为启用自动提交时，BEGIN 和 COMMIT 是两次浪费的往返。令人惊讶的是，我看到一些 ORM 确实做到了这一点，但这是下个月我介绍第 9 章“其他挑战”时的主题。
在输出上向右滚动并注意 t | 7729078：事务执行耗时 7.7 秒。 （查询将时间从皮秒转换为微秒。）当然，MySQL 没有执行这么慢的四个语句中的任何一个。正如我在这篇博文前面所暗示的那样，事务时间是由于语句之间的空闲时间，因为我是一个一个地手动输入查询。
事务中语句之间的空闲时间是检查事务的最重要原因之一。事务空闲时间不会出现在查询分析中，因为它不是任何查询的属性，而是查询之间的时间。因此，尽管查询分析无法揭示它，但应用程序（和用户）会体验到它。为什么会出现事务空闲时间？阅读 Efficient MySQL Performance 的第 8 章中的“常见问题”部分。
通知 NESTING_EVENT_TYPE |输出中的语句。这意味着事务嵌套在语句事件中/下，这与事件层次结构相矛盾。完整的解释很复杂（并记录在 MySQL 手册中）；简短的回答是：BEGIN 语句首先出现并创建事务。
end_event_id 很重要，因为它允许我们有效地查询嵌套表：仅使用 (thread_id, event_id) 上的主键。我们知道线程 ID：54。由于每个线程的事件 ID 单调递增，我们知道所有嵌套事件必须介于 229（创建事务的 BEGIN）和 281（事务 end_event_id）之间。现在我们准备好查询层次结构中的下一层：语句。
声明
然后我们提取事务中的语句：
SELECT
event_id, end_event_id, event_name, source,
ROUND(timer_wait/1000000) t,
ROUND(lock_time/1000000) lockt,
LEFT(sql_text,1000),
COALESCE(current_schema,'') db,
nesting_event_id, nesting_event_type
FROM
events_statements_history
WHERE
thread_id=54
AND event_id BETWEEN 229 and 281;
+----------+--------------+----------------------+---------------------------------+------+-------+------------------------------+------+------------------+--------------------+
| event_id | end_event_id | event_name | source | t | lockt | LEFT(sql_text,1000) | db | NESTING_EVENT_ID | NESTING_EVENT_TYPE |
+----------+--------------+----------------------+---------------------------------+------+-------+------------------------------+------+------------------+--------------------+
| 229 | 237 | statement/sql/begin | init_net_server_extension.cc:97 | 48 | 0 | begin | test | NULL | NULL |
| 239 | 258 | statement/sql/select | init_net_server_extension.cc:97 | 226 | 2 | select * from elem | test | 233 | TRANSACTION |
| 260 | 275 | statement/sql/delete | init_net_server_extension.cc:97 | 303 | 2 | delete from elem where id=10 | test | 233 | TRANSACTION |
| 277 | 285 | statement/sql/commit | init_net_server_extension.cc:97 | 750 | 0 | commit | test | 233 | TRANSACTION |
+----------+--------------+----------------------+---------------------------------+------+-------+------------------------------+------+------------------+--------------------+
注意 WHERE 子句：如上所述，按线程 ID 和开始和结束事件 ID 的范围。
正如预期的那样，我们提取了事务的四个 SQL 语句。输出中的 t 列是以微秒为单位的查询执行时间。表 (events_statements_history) 中提供了完整范围的查询指标，为简洁起见，此处未显示。同样如预期的那样，每个查询都很快：不到 1 毫秒。总查询执行时间为 1.3 毫秒，由于语句之间的空闲时间，大大低于事务执行时间的 7.7 秒。
通知 NESTING_EVENT_TYPE | BEGIN 为 NULl，因为它启动了整个事件链，但 NESTING_EVENT_TYPE |其他语句的 TRANSACTION，与事件层次结构一致。
每个语句的结束事件 ID 比语句多几个事件，因为嵌套在每个语句中的是阶段。请注意，最后一条语句 (COMMIT) 的结束事件 ID 为 285，它是嵌套阶段事件 ID，并且大于此表查询中使用的 BETWEEN 值。我们需要在查询嵌套阶段时使用此阶段事件 ID，以确保我们提取所有阶段。
阶段
第三，我们提取语句中的阶段：
SELECT
event_id, end_event_id, event_name,
source,
nesting_event_id, nesting_event_type
FROM
events_stages_history
WHERE
thread_id=54
AND event_id BETWEEN 229 and 285;
+----------+--------------+------------------------------------------------+----------------------------------+------------------+--------------------+
| event_id | end_event_id | event_name | source | nesting_event_id | nesting_event_type |
+----------+--------------+------------------------------------------------+----------------------------------+------------------+--------------------+
| 230 | 230 | stage/sql/starting | init_net_server_extension.cc:103 | 229 | STATEMENT |
| 231 | 231 | stage/sql/Executing hook on transaction begin. | rpl_handler.cc:1472 | 229 | STATEMENT |
| 232 | 233 | stage/sql/starting | rpl_handler.cc:1474 | 229 | STATEMENT |
| 234 | 234 | stage/sql/query end | sql_parse.cc:4735 | 229 | STATEMENT |
| 235 | 235 | stage/sql/closing tables | sql_parse.cc:4794 | 229 | STATEMENT |
| 236 | 236 | stage/sql/freeing items | sql_parse.cc:5249 | 229 | STATEMENT |
| 237 | 237 | stage/sql/cleaning up | sql_parse.cc:2381 | 229 | STATEMENT |
| 240 | 240 | stage/sql/starting | init_net_server_extension.cc:103 | 239 | STATEMENT |
| 241 | 241 | stage/sql/checking permissions | sql_authorization.cc:2160 | 239 | STATEMENT |
| 242 | 242 | stage/sql/Opening tables | sql_base.cc:5796 | 239 | STATEMENT |
| 243 | 243 | stage/sql/init | sql_select.cc:562 | 239 | STATEMENT |
| 244 | 245 | stage/sql/System lock | lock.cc:331 | 239 | STATEMENT |
| 246 | 246 | stage/sql/optimizing | sql_optimizer.cc:296 | 239 | STATEMENT |
| 247 | 247 | stage/sql/statistics | sql_optimizer.cc:624 | 239 | STATEMENT |
| 248 | 248 | stage/sql/preparing | sql_optimizer.cc:708 | 239 | STATEMENT |
| 249 | 250 | stage/sql/executing | sql_union.cc:1198 | 239 | STATEMENT |
| 251 | 251 | stage/sql/end | sql_select.cc:595 | 239 | STATEMENT |
| 252 | 252 | stage/sql/query end | sql_parse.cc:4735 | 239 | STATEMENT |
| 253 | 253 | stage/sql/waiting for handler commit | handler.cc:1595 | 239 | STATEMENT |
| 254 | 254 | stage/sql/closing tables | sql_parse.cc:4794 | 239 | STATEMENT |
| 255 | 255 | stage/sql/freeing items | sql_parse.cc:5249 | 239 | STATEMENT |
| 256 | 257 | stage/sql/logging slow query | log.cc:1648 | 239 | STATEMENT |
| 258 | 258 | stage/sql/cleaning up | sql_parse.cc:2381 | 239 | STATEMENT |
| 261 | 261 | stage/sql/starting | init_net_server_extension.cc:103 | 260 | STATEMENT |
| 262 | 262 | stage/sql/checking permissions | sql_authorization.cc:2160 | 260 | STATEMENT |
| 263 | 263 | stage/sql/Opening tables | sql_base.cc:5796 | 260 | STATEMENT |
| 264 | 264 | stage/sql/init | sql_select.cc:562 | 260 | STATEMENT |
| 265 | 266 | stage/sql/System lock | lock.cc:331 | 260 | STATEMENT |
| 267 | 269 | stage/sql/updating | sql_delete.cc:561 | 260 | STATEMENT |
| 270 | 270 | stage/sql/end | sql_select.cc:595 | 260 | STATEMENT |
| 271 | 271 | stage/sql/query end | sql_parse.cc:4735 | 260 | STATEMENT |
| 272 | 272 | stage/sql/waiting for handler commit | handler.cc:1595 | 260 | STATEMENT |
| 273 | 273 | stage/sql/closing tables | sql_parse.cc:4794 | 260 | STATEMENT |
| 274 | 274 | stage/sql/freeing items | sql_parse.cc:5249 | 260 | STATEMENT |
| 275 | 275 | stage/sql/cleaning up | sql_parse.cc:2381 | 260 | STATEMENT |
| 278 | 278 | stage/sql/starting | init_net_server_extension.cc:103 | 277 | STATEMENT |
| 279 | 281 | stage/sql/waiting for handler commit | handler.cc:1595 | 277 | STATEMENT |
| 282 | 282 | stage/sql/query end | sql_parse.cc:4735 | 277 | STATEMENT |
| 283 | 283 | stage/sql/closing tables | sql_parse.cc:4794 | 277 | STATEMENT |
| 284 | 284 | stage/sql/freeing items | sql_parse.cc:5249 | 277 | STATEMENT |
| 285 | 285 | stage/sql/cleaning up | sql_parse.cc:2381 | 277 | STATEMENT |
+----------+--------------+------------------------------------------------+----------------------------------+------------------+--------------------+
输出是压倒性的，但有一个模式：每个语句都以 stage stage/sql/starting 开始，以 stage stage/sql/cleaning up 结束。 滚动到输出的右侧，查看nesting_event_id 值的重复块：每个语句对应一个语句事件ID：
执行实际查询（SQL 语句）只是众多阶段中的一个。 阶段也有执行时间，但我没有在这里包括它，因为我认为它不是特别有用。 为什么？ 两个原因：阶段通常不是问题； 除非是查询执行阶段，否则对于慢速阶段您无能为力，在这种情况下，您优化的是查询，而不是阶段。
等待
最后，我们提取阶段内的等待：
SELECT
event_id, end_event_id, event_name,
source,
ROUND(timer_wait/1000000) t,
COALESCE(object_type, '') obj_type,
COALESCE(object_schema,'') obj_scheme,
COALESCE(object_name,'') obj_name,
COALESCE(index_name, '') idx,
operation op,
number_of_bytes n,
nesting_event_id, nesting_event_type
FROM
events_waits_history
WHERE
thread_id=54
AND event_id BETWEEN 229 and 285;
+----------+--------------+-----------------------------+---------------------------------+---------+----------+------------+-----------------------------------------+---------+----------------+------+------------------+--------------------+
| event_id | end_event_id | event_name | source | t | obj_type | obj_scheme | obj_name | idx | op | n | nesting_event_id | nesting_event_type |
+----------+--------------+-----------------------------+---------------------------------+---------+----------+------------+-----------------------------------------+---------+----------------+------+------------------+--------------------+
| 238 | 238 | idle | init_net_server_extension.cc:67 | 2688899 | | | | | idle | NULL | NULL | NULL |
| 245 | 245 | wait/lock/table/sql/handler | handler.cc:7901 | 1 | TABLE | test | elem | PRIMARY | read external | NULL | 244 | STAGE |
| 250 | 250 | wait/io/table/sql/handler | handler.cc:2993 | 25 | TABLE | test | elem | | fetch | 10 | 249 | STAGE |
| 257 | 257 | wait/io/file/sql/slow_log | mf_iocache.cc:1691 | 35 | FILE | | /usr/local/var/mysql@8.0/slow-query.log | | write | 571 | 256 | STAGE |
| 259 | 259 | idle | init_net_server_extension.cc:67 | 3824614 | | | | | idle | NULL | NULL | NULL |
| 266 | 266 | wait/lock/table/sql/handler | handler.cc:7901 | 1 | TABLE | test | elem | PRIMARY | write external | NULL | 265 | STAGE |
| 268 | 268 | wait/io/table/sql/handler | handler.cc:3264 | 20 | TABLE | test | elem | PRIMARY | fetch | 1 | 267 | STAGE |
| 269 | 269 | wait/io/table/sql/handler | handler.cc:8027 | 32 | TABLE | test | elem | PRIMARY | delete | 1 | 267 | STAGE |
| 276 | 276 | idle | init_net_server_extension.cc:67 | 1214261 | | | | | idle | NULL | NULL | NULL |
| 280 | 280 | wait/io/file/sql/binlog | mf_iocache.cc:1691 | 19 | FILE | | /usr/local/var/mysql@8.0/binlog.000077 | | write | 295 | 279 | STAGE |
| 281 | 281 | wait/io/file/sql/binlog | basic_ostream.cc:88 | 137 | FILE | | /usr/local/var/mysql@8.0/binlog.000077 | | sync | NULL | 279 | STAGE |
+----------+--------------+-----------------------------+---------------------------------+---------+----------+------------+-----------------------------------------+---------+----------------+------+------------------+--------------------+
我喜欢 MySQL 手册如何定义等待：
性能模式仪器等待，这是需要时间的事件。
所以等待是需要时间的事件……但是等待（双关语），不是每个事件都需要时间吗？ 🤔
我将等待定义为 MySQL 等待共享资源或客户端所花费的时间。
共享资源包括存储和网络 I/O、数据锁和同步机制。例如，所有存储 I/O 都需要非零时间。即使是最快的存储系统也有几微秒的延迟。几乎每个数据库都有锁和同步（如互斥锁），它们会导致非零的等待时间来获取，尤其是在高并发负载下。
等待客户端是一个称为空闲的特殊等待事件，如上面的输出中报告的 3 次。空闲事件在 10.3.5 socket_instances 表中描述：
套接字状态，IDLE 或 ACTIVE。使用相应的套接字仪器跟踪活动套接字的等待时间。使用空闲仪器跟踪空闲套接字的等待时间。
如果套接字正在等待来自客户端的请求，则它是空闲的。当套接字变为空闲时，socket_instances 中跟踪套接字的事件行从 ACTIVE 状态切换到 IDLE。
EVENT_NAME 值保持等待/io/socket/*，但仪器的计时暂停。而是在 events_waits_current 表中生成一个事件，其 EVENT_NAME 值为 idle。
当接收到下一个请求时，idle 事件终止，socket 实例从 IDLE 切换到 ACTIVE，并且 socket 仪器的计时恢复。
等待通常嵌套在阶段中，但空闲事件是一个例外（在输出上向右滚动）。例如，第一个空闲事件的 ID 为 238，但这对应的是什么？由于事件 ID 单调递增（每个线程），因此此空闲事件立即发生在以事件 ID 237 结束的语句事件 ID 229 (BEGIN) 之后：
请记住：我手动输入了这些查询，因此 MySQL 在语句之间空闲了 2.7 秒（t | 2688899 µs），等待我（客户端）。
输出中的其他等待是共享资源等待：两个表锁和几个磁盘 I/O 等待。它们嵌套在阶段事件中，但随着嵌套事件 ID 在层次结构中向上，您会发现等待是在（或由）语句中引起的。例如，最后两个等待嵌套在阶段事件 ID 279 中，它们嵌套在语句事件 ID 277：COMMIT 中。再次回到等待状态，obj_name 和 op（操作的缩写）列列出了 MySQL 在提交期间等待的内容：二进制日志。
关于 MySQL 等待事件的知识比我在这里介绍的要多。这篇博文的目的只是展示如何开始挖掘性能模式的交易。但是关于 MySQL 性能的等待，我会多说几句。
零等待（或零等待时间）是不可能的，因为所有计算机系统都继承了延迟。正如我之前提到的，所有存储（和网络）I/O 都需要非零时间。因此，就等待而言，目标是将等待时间减少到尽可能接近于零。这对于空闲等待事件（等待客户端）尤其重要，因为它是由应用程序引起的，因此您可以直接解决。同样，请阅读 Efficient MySQL Performance 的第 8 章中的“常见问题”部分。
在 MySQL 的世界中，在性能故障排除中使用等待并不像人们想象的那么普遍，尤其是自从 12 年前（2010 年）发布的 MySQL 5.5 以来它们就已经可用。相反，几乎所有关于 MySQL 性能的阅读（或收听）——包括我的书——都集中在 MySQL 正在做什么以及花费了多长时间——主要是语句事件。我们可以认为这两种方法是同一枚硬币的两个方面：执行时间与等待时间。 MySQL 正在执行或等待。但我认为这有点误导，因为当事件层次结构正确建模时，执行会导致等待：执行 → 等待。 （空闲等待事件是一个例外，这就是它没有嵌套在任何事件中的原因。）因此，如果我们首先关注等待，我们无法单独从它们中学习或减少它们。例如，假设性能模式显示查询花费大量时间等待磁盘 I/O。如果不考虑查询为什么要访问这么多数据，实际上唯一的解决方案是通过升级存储系统来降低磁盘 I/O 延迟并提高磁盘 IOPS。这可能有效，但效率极低，可能非常昂贵，我向你保证，没有 MySQL 专家会建议这种方法。相反，正确和最有效的方法是我的书的全部内容：查询响应时间。在此示例中，您首先查看导致磁盘 I/O 等待的语句。也许您发现查询缺少良好的索引，或者有不必要的 ORDER BY 子句，或者有无数其他原因导致语句效率低下，从而导致磁盘 I/O 等待。您几乎可以免费优化查询——比升级存储系统容易得多。
在我看来，等待对于进行深入分析的 MySQL 专家或真正想要深入研究查询响应时间的勇敢的软件工程师很有用，因为等待是响应时间的一部分。无论哪种方式，MySQL 的性能都是查询响应时间。
锭
上一节的标题是 Raw Ore，现在您可以了解原因了：一个简单的四语句交易会产生大量原始输出，这些输出在模型中是分层的，但在您查询时是扁平的并且有点混杂。为了更好地可视化和理解交易，我为每个语句组合了事件并对输出进行了颜色编码。
颜色代码：
- 陈述
- 阶段
- 等待
- 闲置的
例如，SELECT 和空闲事件之后以语句事件开头。下面是四个阶段。每个阶段下都有相应的等待。最后，一个空闲事件：MySQL 等待我（客户端）输入并输入下一条语句。
单击图像以查看完整尺寸。
BEGIN 和 idle：
SELECT 和 idle:
DELETE 和 idle:
COMMIT
最先进的
据我所知，目前还没有开源工具可以挖掘性能模式并将原始数据处理成易于人类消费的东西。 MySQL sys Schema 有许多使用原始 Performance Schema 数据的视图，但这仍然很原始，无法表达完整的事务，如此处所示。 另外，Performance Schema 的数据比我在这里展示的要多得多，因此业界确实需要一个复杂的工具，可以将 Performance Schema 中的大量数据提取并提炼成黄金：深入且几乎完全地洞察 MySQL 性能。
但在此之前，关于事务报告的最新技术是复制粘贴，正如我在 Efficient MySQL Performance 的第 8 章中所写，转载于 https://hackmysql.com/trx，并在这篇博文中进行了扩展。
原文标题：Mining the MySQL Performance Schema for Transactions
原文作者：Daniel Nichter
原文地址：https://hackmysql.com/post/book-8/
