mysql8.0使用ps_trace_statement_digest()追踪语句执行流程

r囧r小猫 2023-03-01 12:59 15阅读 0赞

# 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`

## 常见用法 ##

1.  查看`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;
2.  开始追踪
    
        CALL sys.ps_trace_statement_digest('0c16682717552abfe94da3598604c606be3dea8fe964e735b267eda666840df8', 60, 0.5, TRUE, TRUE);
3.  查看生成结果
    
        +-------------------+
        | 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