mysql8.0使用ps_trace_statement_digest()追踪语句执行流程
简介
根据指定的digest
监控events_statements_history_long
和events_stages_ history_long
表,以获取指定digest
相关的事件,分析的结果包括摘要数据以及详细信息。
参数
- Digest: 语句的标识, 可以查看
events_statements_summary_by_digest
获取追踪语句对应得digest值 - Runtime: 监控时长
- Poll Interval: 采集间隔时间
- Refresh: 是否在启动前先
truncate
表events_statements_history_long
),events_stages_history_long
- Auto Setup: 是否自动启用所需要的
consumers
常见用法
-
查看
events_statements_summary_by_digest
表获取语句对应的digest
,也可以直接SET @digest = STATEMENT_DIGEST('BEGIN');
,然后digest参数直接写@digest
SELECT DIGEST, DIGEST_TEXT FROM performance_schema.events_statements_summary_by_digest WHERE DIGEST_TEXT LIKE '%INSERT%' LIMIT 1;
-
开始追踪
CALL sys.ps_trace_statement_digest('0c16682717552abfe94da3598604c606be3dea8fe964e735b267eda666840df8', 60, 0.5, TRUE, TRUE);
-
查看生成结果
+-------------------+ | summary | +-------------------+ | Disabled 1 thread | +-------------------+ 1 row in set (0.01 sec) +--------------------+ | SUMMARY STATISTICS | +--------------------+ | SUMMARY STATISTICS | +--------------------+ 1 row in set (1 min 0.46 sec) -- executions 执行次数 -- exec_time 执行总时长 -- lock_time 锁等待总时长 -- rows_sent 发送的总行数 -- rows_affected 生效的行数 -- rows_examined 检查的行数 -- tmp_tables 使用的临时表个数 -- full_scans 全表扫描次数 +------------+-----------+-----------+-----------+---------------+---------------+------------+------------+ | executions | exec_time | lock_time | rows_sent | rows_affected | rows_examined | tmp_tables | full_scans | +------------+-----------+-----------+-----------+---------------+---------------+------------+------------+ | 8898 | 53.57 s | 953.60 ms | 0 | 8898 | 0 | 0 | 0 | +------------+-----------+-----------+-----------+---------------+---------------+------------+------------+ 1 row in set (1 min 0.49 sec) -- 这个语句执行过程中产生的event以及对应的延迟 +------------------------------------------------+-------+-----------+ | event_name | count | latency | +------------------------------------------------+-------+-----------+ | stage/sql/waiting for handler commit | 4204 | 23.21 s | | stage/sql/update | 4147 | 565.60 ms | | stage/sql/starting | 8233 | 284.96 ms | | stage/sql/freeing items | 4321 | 179.22 ms | | stage/sql/Opening tables | 4121 | 128.72 ms | | stage/sql/closing tables | 4190 | 53.89 ms | | stage/sql/System lock | 4086 | 26.82 ms | | stage/sql/checking permissions | 4111 | 15.21 ms | | stage/sql/init | 4247 | 14.45 ms | | stage/sql/end | 4154 | 10.32 ms | | stage/sql/query end | 4177 | 4.73 ms | | stage/sql/cleaning up | 4155 | 4.30 ms | | stage/sql/Executing hook on transaction begin. | 4110 | 2.97 ms | +------------------------------------------------+-------+-----------+ 13 rows in set (1 min 0.69 sec) +---------------------------+ | LONGEST RUNNING STATEMENT | +---------------------------+ | LONGEST RUNNING STATEMENT | +---------------------------+ 1 row in set (1 min 0.70 sec) -- 这个语句运行时间最长的一次具体信息 +-----------+-----------+-----------+-----------+---------------+---------------+------------+-----------+ | thread_id | exec_time | lock_time | rows_sent | rows_affected | rows_examined | tmp_tables | full_scan | +-----------+-----------+-----------+-----------+---------------+---------------+------------+-----------+ | 108 | 201.09 ms | 120.00 us | 0 | 1 | 0 | 0 | 0 | +-----------+-----------+-----------+-----------+---------------+---------------+------------+-----------+ 1 row in set (1 min 0.71 sec) +-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+ | sql_text | +-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+ | INSERT INTO sbtest5 (id, k, c, pad) VALUES (0, 50316, '86539702156-26530319622-32826744596-31791260593-20574370067-09507408637-55919947787-63819846779-86443542983-67978229383', '43591303543-94583187223-19570388062-12361278127-68855452960') | +-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+ 1 row in set (1 min 0.72 sec) Empty set (1 min 0.78 sec) +------------------+ | summary | +------------------+ | Enabled 1 thread | +------------------+ 1 row in set (1 min 0.85 sec) Query OK, 0 rows affected (1 min 0.85 sec)
参考
- https://dev.mysql.com/doc/refman/8.0/en/sys-ps-trace-thread.html