应用示例荟萃 | performance_schema全方位介绍（下）

悠悠 2022-12-23 11:24 146阅读 0赞

### **3. 查看最近的SQL执行信息** ###

#### **3.1 查看最近的top sql** ####

使用performance\_schema中的语句当前事件记录表和语句事件历史记录表可以查询数据库中最近执行的一些SQL语句，以及语句相关的信息，这里我们以events\_statements\_history表为例，查询结果按照语句完成时间倒序排序，如下：

root@localhost : performance_schema 04:33:33> select THREAD_ID,EVENT_NAME,SOURCE,sys.format_time(TIMER_WAIT),sys.format_time(LOCK_TIME),SQL_TEXT,CURRENT_SCHEMA,MESSAGE_TEXT,ROWS_AFFECTED,ROWS_SENT,ROWS_EXAMINED from events_statements_history where CURRENT_SCHEMA!='performance_schema' order by TIMER_WAIT desc limit 10\G;
    *************************** 1. row ***************************
                  THREAD_ID: 114
                 EVENT_NAME: statement/sql/update
                     SOURCE: socket_connection.cc:101
    sys.format_time(TIMER_WAIT): 24.93 m
    sys.format_time(LOCK_TIME): 24.93 m
                   SQL_TEXT: update sbtest1 set pad='xxx' where id=1
             CURRENT_SCHEMA: sbtest
               MESSAGE_TEXT: Rows matched: 0 Changed: 0 Warnings: 0
              ROWS_AFFECTED: 0
                  ROWS_SENT: 0
              ROWS_EXAMINED: 0
    *************************** 2. row ***************************
                  THREAD_ID: 114
                 EVENT_NAME: statement/sql/update
                     SOURCE: socket_connection.cc:101
    sys.format_time(TIMER_WAIT): 7.84 m
    sys.format_time(LOCK_TIME): 7.84 m
                   SQL_TEXT: update sbtest1 set pad='xxx' where id=1
             CURRENT_SCHEMA: sbtest
               MESSAGE_TEXT: Rows matched: 0 Changed: 0 Warnings: 0
              ROWS_AFFECTED: 0
                  ROWS_SENT: 0
              ROWS_EXAMINED: 0
    ......
    10 rows in set (0.00 sec)

按照我们通常优化慢SQL的原则，优先优化执行次数最多的，然后是执行时间最长的，以上的查询结果并不是我们通常说的top sql，我们可以使用events\_statements\_summary\_by\_digest表来查询经过统计之后的top sql

root@localhost : performance_schema 05:04:41> select SCHEMA_NAME,DIGEST_TEXT,COUNT_STAR,sys.format_time(SUM_TIMER_WAIT) as sum_time,sys.format_time(MIN_TIMER_WAIT) as min_time,sys.format_time(AVG_TIMER_WAIT) as avg_time,sys.format_time(MAX_TIMER_WAIT) as max_time,sys.format_time(SUM_LOCK_TIME) as sum_lock_time,SUM_ROWS_AFFECTED,SUM_ROWS_SENT,SUM_ROWS_EXAMINED from events_statements_summary_by_digest where SCHEMA_NAME is not null order by COUNT_STAR desc limit 10\G
    *************************** 1. row ***************************
      SCHEMA_NAME: sbtest
      DIGEST_TEXT: UPDATE `sbtest1` SET `pad` = ? WHERE `id` = ? 
       COUNT_STAR: 10
         sum_time: 2.19 h
         min_time: 216.90 us
         avg_time: 13.15 m
         max_time: 1.50 h
    sum_lock_time: 2.04 h
    SUM_ROWS_AFFECTED: 3
    SUM_ROWS_SENT: 0
    SUM_ROWS_EXAMINED: 4
    *************************** 2. row ***************************
      SCHEMA_NAME: sbtest
      DIGEST_TEXT: SHOW WARNINGS 
       COUNT_STAR: 9
         sum_time: 397.62 us
         min_time: 16.50 us
         avg_time: 44.18 us
         max_time: 122.58 us
    sum_lock_time: 0 ps
    SUM_ROWS_AFFECTED: 0
    SUM_ROWS_SENT: 0
    SUM_ROWS_EXAMINED: 0
    ......
    *************************** 5. row ***************************
      SCHEMA_NAME: sbtest
      DIGEST_TEXT: SELECT * FROM `sbtest1` LIMIT ? 
       COUNT_STAR: 5
         sum_time: 138.93 ms
         min_time: 145.77 us
         avg_time: 27.79 ms
         max_time: 112.29 ms
    sum_lock_time: 95.53 ms
    SUM_ROWS_AFFECTED: 0
    SUM_ROWS_SENT: 104
    SUM_ROWS_EXAMINED: 104
    ......
    10 rows in set (0.00 sec)

PS： events\_statements\_summary\_by\_digest 表中记录的SQL语句文本并不完整，默认情况下只截取了1024个字节，且也是使用这1024个字节的SQL文本进行hash计算，把hashcode相同的累计计算在一起，performance\_schema提供的数据只能算作慢日志分析的一个补充，如果需要完整的SQL语句文本还得依赖慢查询日志分析

#### **3.2 查看最近执行失败的SQL** ####

曾经有同事问，代码对数据库的某些操作(比如：python的ORM模块操作数据库)报了语法错误，但是代码并没有记录SQL语句文本的功能，问在MySQL数据库层能否查看到具体的SQL文本，看看是否有哪里写错了。这个时候，大多数人首先想到的就是去查看错误日志。很遗憾，对于SQL语句的语法错误，错误日志并不会记录。如果你没有完全了解performance\_schema，那么你很可能就会给同事回复说：MySQL层面也并没有记录语法错误的信息

实际上，performance\_schema的语句事件记录表中针对每一个语句的执行状态都记录了较为详细的信息，例如：events\_statements\_*表和events\_statements\_summary\_by\_digest表(events\_statements\_*表记录的语句所有的执行错误信息，但events\_statements\_summary\_by\_digest表只记录了语句在执行过程中发生的错误的语句记录统计，具体的错误类型不记录，例如：语法错误类的不记录)，下面我们分别演示如何使用这两个表查询语句发生错误的语句信息

首先，我们模拟一个语法错误的SQL，使用events\_statements\_history\_long或者events\_statements\_history表查询发生语法错误的SQL语句，开启一个会话(会话1)

root@localhost : performance_schema 05:18:09> select * from;
    ERROR 1064 (42000): You have an error in your SQL syntax; check the manual that corresponds to your MySQL server version for the right syntax to use near '' at line 1

然后，我们查询events\_statements\_history\_long表中错误号为1064的记录，开启另一个会话（会话2）

root@localhost : sbtest 05:32:55> use performance_schema
    Database changed
    root@localhost : performance_schema 05:33:03> select THREAD_ID,EVENT_NAME,SOURCE,sys.format_time(TIMER_WAIT) as exec_time,sys.format_time(LOCK_TIME) as lock_time,SQL_TEXT,CURRENT_SCHEMA,MESSAGE_TEXT,ROWS_AFFECTED,ROWS_SENT,ROWS_EXAMINED,MYSQL_ERRNO from events_statements_history where MYSQL_ERRNO=1064\G;
    *************************** 1. row ***************************
     THREAD_ID: 119
    EVENT_NAME: statement/sql/error
        SOURCE: socket_connection.cc:101
     exec_time: 71.72 us
     lock_time: 0 ps
      SQL_TEXT: select * from
    CURRENT_SCHEMA: sbtest
    MESSAGE_TEXT: You have an error in your SQL syntax; check the manual that corresponds to your MySQL server version for the right syntax to use
    ROWS_AFFECTED: 0
    ROWS_SENT: 0
    ROWS_EXAMINED: 0
    MYSQL_ERRNO: 1064
    1 row in set (0.01 sec)

可能你不知道错误号是多少，可以查询发生错误次数不为0的语句记录，在里边找到MESSAGE\_TEXT字段提示信息为语法错误的就是它了

root@localhost : performance_schema 05:34:00> select THREAD_ID,EVENT_NAME,SOURCE,sys.format_time(TIMER_WAIT) as exec_time,sys.format_time(LOCK_TIME) as lock_time,SQL_TEXT,CURRENT_SCHEMA,MESSAGE_TEXT,ROWS_AFFECTED,ROWS_SENT,ROWS_EXAMINED,MYSQL_ERRNO,errors from events_statements_history where errors>0\G;
    *************************** 1. row ***************************
     THREAD_ID: 119
    EVENT_NAME: statement/sql/error
        SOURCE: socket_connection.cc:101
     exec_time: 71.72 us
     lock_time: 0 ps
      SQL_TEXT: select * from
    CURRENT_SCHEMA: sbtest
    MESSAGE_TEXT: You have an error in your SQL syntax; check the manual that corresponds to your MySQL server version for the right syntax to use
    ROWS_AFFECTED: 0
    ROWS_SENT: 0
    ROWS_EXAMINED: 0
    MYSQL_ERRNO: 1064
        errors: 1
    1 row in set (0.00 sec)

使用events\_statements\_summary\_by\_digest表查询发生语句执行错误的SQL语句记录，首先，我们在会话1制造一两个语句执行一定会发生错误的语句

root@localhost : sbtest 05:32:34> select * ;
    ERROR 1096 (HY000): No tables used
    root@localhost : sbtest 05:40:57> select * from sbtest4 where id between 100 and 2000 and xx=1;
    ERROR 1054 (42S22): Unknown column 'xx' in 'where clause'

然后，我们在events\_statements\_summary\_by\_digest表中查询发生错误次数大于0的记录，在会话2执行

root@localhost : performance_schema 05:34:03> select SCHEMA_NAME,DIGEST_TEXT,COUNT_STAR,sys.format_time(AVG_TIMER_WAIT) as avg_time,sys.format_time(MAX_TIMER_WAIT) as max_time,sys.format_time(SUM_LOCK_TIME) as sum_lock_time,SUM_ERRORS,FIRST_SEEN,LAST_SEEN from events_statements_summary_by_digest where SUM_ERRORS!=0\G;
    *************************** 1. row ***************************
    ......
    *************************** 10. row ***************************
    SCHEMA_NAME: sbtest
    DIGEST_TEXT: SELECT *   # 这里就是第一个执行错误的语句
    COUNT_STAR: 1
     avg_time: 55.14 us
     max_time: 55.14 us
    sum_lock_time: 0 ps
    SUM_ERRORS: 1
    FIRST_SEEN: 2018-06-25 17:40:57
    LAST_SEEN: 2018-06-25 17:40:57
    *************************** 11. row ***************************
    SCHEMA_NAME: sbtest
    DIGEST_TEXT: SELECT * FROM `sbtest4` WHERE `id` BETWEEN ? AND ? AND `xx` = ?   # 这里就是第二个执行错误的语句
    COUNT_STAR: 1
     avg_time: 101.68 us
     max_time: 101.68 us
    sum_lock_time: 0 ps
    SUM_ERRORS: 1
    FIRST_SEEN: 2018-06-25 17:41:03
    LAST_SEEN: 2018-06-25 17:41:03
    11 rows in set (0.00 sec)

PS：我们前面说过，events\_statements\_summary\_by\_digest表中不记录具体的错误信息，只做错误语句统计，所以，如果需要查询到具体的错误信息（如：具体的错误代码，具体的错误提示信息以及具体的错误SQL文本等），还需要查询events\_statements\_history或者events\_statements\_history\_long表

root@localhost : performance_schema 05:45:03> select THREAD_ID,EVENT_NAME,SOURCE,sys.format_time(TIMER_WAIT) as exec_time,sys.format_time(LOCK_TIME) as lock_time,SQL_TEXT,CURRENT_SCHEMA,MESSAGE_TEXT,ROWS_AFFECTED,ROWS_SENT,ROWS_EXAMINED,MYSQL_ERRNO from events_statements_history where MYSQL_ERRNO!=0\G;
    *************************** 1. row ***************************
    ......
    *************************** 2. row ***************************
     THREAD_ID: 119
    EVENT_NAME: statement/sql/select
        SOURCE: socket_connection.cc:101
     exec_time: 55.14 us
     lock_time: 0 ps
      SQL_TEXT: select *
    CURRENT_SCHEMA: sbtest
    MESSAGE_TEXT: No tables used
    ROWS_AFFECTED: 0
    ROWS_SENT: 0
    ROWS_EXAMINED: 0
    MYSQL_ERRNO: 1096
    *************************** 3. row ***************************
     THREAD_ID: 119
    EVENT_NAME: statement/sql/select
        SOURCE: socket_connection.cc:101
     exec_time: 101.68 us
     lock_time: 0 ps
      SQL_TEXT: select * from sbtest4 where id between 100 and 2000 and xx=1
    CURRENT_SCHEMA: sbtest
    MESSAGE_TEXT: Unknown column 'xx' in 'where clause'
    ROWS_AFFECTED: 0
    ROWS_SENT: 0
    ROWS_EXAMINED: 0
    MYSQL_ERRNO: 1054
    3 rows in set (0.00 sec)

###     ###

### **4. 查看SQL执行进度信息** ###

MariaDB分支支持一个不依赖于performance\_schema性能数据的进度展示功能，我们通过show processlist语句返回结果的最后一列就是进度信息

在MySQL中也提供了类似的功能，通过阶段事件中具有可预估工作量的阶段事件进行记录与计算，就可以得到一个语句的执行的阶段信息和进度信息，下面我们分别举例介绍如何查看

#### **4.1 查看SQL执行阶段** ####

首先， 我们需要进行配置启用，阶段事件默认并未启用，开启一个会话（会话1）

root@localhost : performance_schema 05:59:26> use performance_schema
    Database changed
    root@localhost : performance_schema 05:59:45> update setup_instruments set enabled='yes',timed='yes' where name like 'stage/%';
    Query OK, 120 rows affected (0.00 sec)
    Rows matched: 129 Changed: 120 Warnings: 0
    root@localhost : performance_schema 05:59:47> update setup_consumers set enabled='yes' where name like '%stage%';
    Query OK, 3 rows affected (0.00 sec)
    Rows matched: 3 Changed: 3 Warnings: 0

开启第二个会话（会话2），查询thread\_id

root@localhost : sbtest 06:02:22> select sys.ps_thread_id(connection_id());
    +-----------------------------------+
    | sys.ps_thread_id(connection_id()) |
    +-----------------------------------+
    | 119 |
    +-----------------------------------+
    1 row in set (0.00 sec)

先对之前旧的信息进行清理，避免干扰（会话1）

# 先关闭其他线程的事件记录功能，使用前面步骤查询到的thread_id
    root@localhost : performance_schema 06:05:38> update performance_schema.threads set INSTRUMENTED='NO' where THREAD_ID!=119;
    Query OK, 101 rows affected (0.00 sec)
    Rows matched: 101 Changed: 101 Warnings: 0
    # 清空阶段事件的3张表
    root@localhost : performance_schema 05:59:52> truncate events_stages_current;truncate events_stages_history;truncate events_stages_history_long;
    Query OK, 0 rows affected (0.00 sec)
    Query OK, 0 rows affected (0.00 sec)
    Query OK, 0 rows affected (0.02 sec)

现在，回到会话2执行DML语句

root@localhost : sbtest 06:06:37> select count(*) from sbtest.sbtest4 where id between 100 and 200;
    +----------+
    | count(*) |
    +----------+
    | 50 |
    +----------+
    1 row in set (0.00 sec)

在会话1中查询events\_stages\_history\_long表

通过以上的查询数据可以清晰地看到一个select语句的执行全过程，以及每一个过程的时间开销等信息，那DDL语句的执行阶段又是怎样的呢？

先对之前旧的信息进行清理，避免干扰（会话1）

root@localhost : performance_schema 06:10:48> truncate events_stages_current;truncate events_stages_history;truncate events_stages_history_long;
    Query OK, 0 rows affected (0.00 sec)
    Query OK, 0 rows affected (0.00 sec)
    Query OK, 0 rows affected (0.02 sec)

然后，执行DDL语句(会话2)

root@localhost : sbtest 03:37:32> alter table sbtest1 add index i_c(c);

此时，在会话1中查询阶段事件信息(此时DDL语句并未执行完成，从最后一行记录信息中可以看到，WORK\_COMPLETED 和WORK\_ESTIMATED 列值不为NULL，表示该阶段事件是一个可以度量的事件)

待到DDL语句执行完成之后，我们再次查看阶段事件信息（会话1）

root@localhost : performance_schema 06:31:07> select THREAD_ID,EVENT_NAME,SOURCE,sys.format_time(TIMER_WAIT) as exec_time,WORK_COMPLETED,WORK_ESTIMATED from events_stages_history_long;
    +-----------+------------------------------------------------------+--------------------------+-----------+----------------+----------------+
    | THREAD_ID | EVENT_NAME | SOURCE | exec_time | WORK_COMPLETED | WORK_ESTIMATED |
    +-----------+------------------------------------------------------+--------------------------+-----------+----------------+----------------+
    ......
    | 119 | stage/innodb/alter table (read PK and internal sort) | ut0stage.h:241 | 27.09 s | 230040 | 470155 |
    | 119 | stage/innodb/alter table (merge sort) | ut0stage.h:501 | 1.15 m | 345060 | 512319 |
    | 119 | stage/innodb/alter table (insert) | ut0stage.h:501 | 11.83 s | 460146 | 523733 |
    | 119 | stage/innodb/alter table (flush) | ut0stage.h:501 | 18.35 s | 523658 | 523733 |
    | 119 | stage/innodb/alter table (log apply index) | ut0stage.h:501 | 54.63 ms | 524042 | 524042 |
    | 119 | stage/innodb/alter table (flush) | ut0stage.h:501 | 21.18 us | 524042 | 524042 |
    | 119 | stage/sql/committing alter table to storage engine | sql_table.cc:7535 | 5.12 us | NULL | NULL |
    | 119 | stage/innodb/alter table (end) | ut0stage.h:501 | 233.52 ms | 524042 | 524042 |
    ......
    +-----------+------------------------------------------------------+--------------------------+-----------+----------------+----------------+
    24 rows in set (0.01 sec)

通过以上的查询数据可以清晰地看到一个alter语句添加索引的执行全过程，以及每一个过程的时间开销等信息，执行时间最长的是stage/innodb/alter table (merge sort)，其次是stage/innodb/alter table (read PK and internal sort)，说明在本示例中创建索引主要的时间开销在于内部的数据排序和排序合并操作

PS：阶段事件长历史记录表中的数据产生较快，默认的10000行配额可能很快就被打满了，可在配置文件中把配额调整为一个较大值，以便完整查看DDL语句执行阶段(例如：performance\_schema\_events\_stages\_history\_long\_size=1000000，同时要注意关掉其他不相干的任务)

#### **4.2 查看SQL执行进度** ####

在官方MySQL 版本中，performance\_schema下并没有很直观地查询整个语句执行进度的方法，但是可以借助后续章节中介绍的sys.session视图进行查看

root@localhost : performance_schema 04:16:38> select * from sys.session where conn_id!=connection_id()\G;
    *************************** 1. row ***************************
                thd_id: 45
              conn_id: 4
    ......
                state: alter table (merge sort)
                  time: 30
    current_statement: alter table sbtest1 add index i_c(c)
    statement_latency: 29.42 s
              progress: 46.40   # 进度百分比在这里
          lock_latency: 2.19 ms
        rows_examined: 0
            rows_sent: 0
        rows_affected: 0
            tmp_tables: 0
      tmp_disk_tables: 0
            full_scan: NO
    ......
          program_name: mysql
    1 row in set (0.33 sec)

###     ###

### **5. 查看最近的事务执行信息** ###

虽然，我们可以通过慢查询日志查询到一个语句的执行总时长，但，如果数据库中存在着一些大事务执行过程中回滚了，或者说执行过程中异常终止，这个时候慢查询日志就爱莫能助了，这个时候我们可以借助performance\_schema的events\_transactions\_\*表进行查看事务相关的记录，这些表中详细记录了是否有事务被回滚、活跃(长事件未提交的事务也属于活跃事件)或已提交等，下面我们分别模拟几种事务情况，并查看事务事件记录表。

首先，我们需要进行配置启用，事务事件默认并未启用（会话1）

root@localhost : performance_schema 04:16:59> update setup_instruments set enabled='yes',timed='yes' where name like 'transaction';
    Query OK, 1 row affected (0.00 sec)
    Rows matched: 1  Changed: 1  Warnings: 0
    root@localhost : performance_schema 04:23:12> update setup_consumers set enabled='yes' where name like '%transaction%';
    Query OK, 3 rows affected (0.00 sec)
    Rows matched: 3  Changed: 3  Warnings: 0

执行清理，避免其他事务干扰（会话1）

root@localhost : performance_schema 04:30:25> truncate events_transactions_current;truncate events_transactions_history;truncate events_transactions_history_long;
    Query OK, 0 rows affected (0.00 sec)
    Query OK, 0 rows affected (0.00 sec)
    Query OK, 0 rows affected (0.00 sec)

然后，开启一个新会话（会话2）用于执行事务，并模拟事务回滚

root@localhost : sbtest 04:18:34> use sbtest
    Database changed
    root@localhost : sbtest 04:24:27> begin;
    Query OK, 0 rows affected (0.00 sec)
    root@localhost : sbtest 04:25:02> update sbtest1 set pad='yyy' where id=1;
    Query OK, 1 row affected (0.01 sec)
    Rows matched: 1  Changed: 1  Warnings: 0

会话1查询活跃事务，活跃事务表示当前正在执行的事务事件，需要从events\_transactions\_current表查询

root@localhost : performance_schema 04:33:44> select THREAD_ID,EVENT_NAME,STATE,TRX_ID,GTID,SOURCE,TIMER_WAIT,ACCESS_MODE,ISOLATION_LEVEL,AUTOCOMMIT,NESTING_EVENT_ID,NESTING_EVENT_TYPE from events_transactions_current\G;
    *************************** 1. row ***************************
        THREAD_ID: 47
        EVENT_NAME: transaction
            STATE: ACTIVE
            TRX_ID: NULL
              GTID: AUTOMATIC
            SOURCE: transaction.cc:209
        TIMER_WAIT: 21582764879000
      ACCESS_MODE: READ WRITE
    ISOLATION_LEVEL: READ COMMITTED
        AUTOCOMMIT: NO
    NESTING_EVENT_ID: 30
    NESTING_EVENT_TYPE: STATEMENT
    1 row in set (0.00 sec)

会话2，回滚事务，被回滚完成的事务不再活跃

root@localhost : sbtest 04:25:08> rollback;
    Query OK, 0 rows affected (0.01 sec)

会话1，查询事务事件历史记录表events\_transactions\_history\_long

root@localhost : performance_schema 04:27:34> select THREAD_ID,EVENT_NAME,STATE,TRX_ID,GTID,SOURCE,TIMER_WAIT,ACCESS_MODE,ISOLATION_LEVEL,AUTOCOMMIT,NESTING_EVENT_ID,NESTING_EVENT_TYPE from events_transactions_history_long\G;
    *************************** 1. row ***************************
        THREAD_ID: 45
        EVENT_NAME: transaction
            STATE: ROLLED BACK
            TRX_ID: NULL
              GTID: AUTOMATIC
            SOURCE: transaction.cc:209
        TIMER_WAIT: 39922043951000
      ACCESS_MODE: READ WRITE
    ISOLATION_LEVEL: READ COMMITTED
        AUTOCOMMIT: NO
    NESTING_EVENT_ID: 194
    NESTING_EVENT_TYPE: STATEMENT
    1 row in set (0.00 sec)

可以看到在事务事件表中记录了一行事务事件信息，线程ID为45的线程执行了一个事务，事务状态为ROLLED BACK，现在，我们来模拟事务正常提交

# 会话2
    root@localhost : sbtest 04:40:27> begin;
    Query OK, 0 rows affected (0.00 sec)
    root@localhost : sbtest 04:40:29> update sbtest1 set pad='yyy' where id=1;
    Query OK, 1 row affected (0.00 sec)
    Rows matched: 1  Changed: 1  Warnings: 0
    root@localhost : sbtest 04:40:31> commit;
    Query OK, 0 rows affected (0.01 sec)
    # 会话1
    root@localhost : performance_schema 04:38:32> select THREAD_ID,EVENT_NAME,STATE,TRX_ID,GTID,SOURCE,TIMER_WAIT,ACCESS_MODE,ISOLATION_LEVEL,AUTOCOMMIT,NESTING_EVENT_ID,NESTING_EVENT_TYPE from events_transactions_current\G;
    *************************** 1. row ***************************
        THREAD_ID: 44
        EVENT_NAME: transaction
            STATE: COMMITTED
            TRX_ID: 421759004106352
              GTID: AUTOMATIC
            SOURCE: handler.cc:1421
        TIMER_WAIT: 87595486000
      ACCESS_MODE: READ WRITE
    ISOLATION_LEVEL: READ COMMITTED
        AUTOCOMMIT: YES
    NESTING_EVENT_ID: 24003703
    NESTING_EVENT_TYPE: STATEMENT
    *************************** 2. row ***************************
        THREAD_ID: 47
        EVENT_NAME: transaction
            STATE: COMMITTED
            TRX_ID: NULL
              GTID: ec123678-5e26-11e7-9d38-000c295e08a0:181879
            SOURCE: transaction.cc:209
        TIMER_WAIT: 7247256746000
      ACCESS_MODE: READ WRITE
     ISOLATION_LEVEL: READ COMMITTED
        AUTOCOMMIT: NO
    NESTING_EVENT_ID: 55
    NESTING_EVENT_TYPE: STATEMENT
    2 rows in set (0.00 sec)

从上面的查询数据可以看到，第二行事务事件记录中的事务事件为COMMITTED状态，表示事务已经提交成功

PS：如果一个事务长时间未提交(长事件处于ACTIVE状态)，这种情况虽然我们从events\_transactions\_current表中可以查询到未提交事务事件信息，但是并不能很直观地看到事务是什么时间点开始的，我们可以借助于information\_schema.innodb\_trx表来进行辅助判断

root@localhost : performance_schema 04:57:50> select * from information_schema.innodb_trx\G;
    *************************** 1. row ***************************
                    trx_id: 2454336
                trx_state: RUNNING
              trx_started: 2018-01-14 16:43:29
    trx_requested_lock_id: NULL
          trx_wait_started: NULL
                trx_weight: 3
      trx_mysql_thread_id: 6
    ......
    1 row in set (0.00 sec)

###     ###

### **6. 查看多线程复制报错详情** ###

官方MySQL 从5.6版本开始支持基于库级别的并行复制，在MySQL 5.7版本中支持基于事务的并行复制，在我们启用了并行复制之后，如果一旦发生复制报错，通常通过show slave status语句无法查看到具体的报错详情(show slave status语句只能查看到SQL线程的报错信息，而在多线程复制下，SQL线程的报错信息是根据worker线程的报错信息的一个汇总信息)，类似如下：

admin@localhost : (none) 12:45:19> show slave status\G;
    ............
                  Last_Errno: 1062
                  Last_Error: Coordinator stopped because there were error(s) in the worker(s). The most recent failure being: Worker 1 failed executing transaction '23fb5832-e4bc-11e7-8ea4-525400a4b2e1:2553990' at master log mysql-bin.000034, end_log_pos 98797. See error log and/or performance_schema.replication_applier_status_by_worker table for more details about this failure or others, if any.
    ............
              Last_SQL_Errno: 1062
              Last_SQL_Error: Coordinator stopped because there were error(s) in the worker(s). The most recent failure being: Worker 1 failed executing transaction '23fb5832-e4bc-11e7-8ea4-525400a4b2e1:2553990' at master log mysql-bin.000034, end_log_pos 98797. See error log and/or performance_schema.replication_applier_status_by_worker table for more details about this failure or others, if any.
    ............
    1 row in set (0.00 sec)

根据报错提示查看performance\_schema.replication\_applier\_status\_by\_worker表，该表中详细记录了每一个worker线程的详细信息，从这里我们就可以找到发生报错的worker线程具体的报错原因

admin@localhost : (none) 12:51:53> select * from performance_schema.replication_applier_status_by_worker where LAST_ERROR_MESSAGE!=''\G;
    *************************** 1. row ***************************
        CHANNEL_NAME: 
            WORKER_ID: 2
            THREAD_ID: NULL
        SERVICE_STATE: OFF
    LAST_SEEN_TRANSACTION: 23fb5832-e4bc-11e7-8ea4-525400a4b2e1:2553991
    LAST_ERROR_NUMBER: 1062
    LAST_ERROR_MESSAGE: Worker 2 failed executing transaction '23fb5832-e4bc-11e7-8ea4-525400a4b2e1:2553991' at master log mysql-bin.000034, end_log_pos 99514; Could not execute Write_rows event on table sbtest.sbtest4; Duplicate entry '833353' for key 'PRIMARY', Error_code: 1062; handler error HA_ERR_FOUND_DUPP_KEY; the event's master log FIRST, end_log_pos 99514
    LAST_ERROR_TIMESTAMP: 2018-01-02 14:08:58
    1 row in set (0.00 sec)

从查询performance\_schema.replication\_applier\_status\_by\_worker表可以发现，具体的复制报错信息是因为主键冲突了

PS：由于历史原因，performance\_schema中的复制信息记录表只记录跟GTID相关的信息，而在mysql系统字典库下的slave\_master\_info、slave\_relay\_log\_info、slave\_worker\_info表记录的是跟binlog position相关的信息。另外，如果选择相关的复制信息记录到文件，那么磁盘上还存在着master.info、relay\_log.info等文件记录binlog position相关的信息

--------------------

"翻过这座山，你就可以看到一片海！"。坚持阅读我们的performance\_schema系列文章分享，你就可以系统地学完它。截止到本文结束，我们的“performance\_schema全方位介绍” 划上了圆满的句号，关于performance\_schema的使用场景上还需要大家共同去挖掘。后续将为大家分享"sys 系统库全方位介绍"系列 ，谢谢你的阅读，我们下期不见不散！

**| 作者简介**

### **罗小波·数据库技术专家** ###

《千金良方——MySQL性能优化金字塔法则》、《数据生态：MySQL复制技术与生产实践》作者之一。熟悉MySQL体系结构，擅长数据库的整体调优，喜好专研开源技术，并热衷于开源技术的推广，在线上线下做过多次公开的数据库专题分享，发表过近100篇数据库相关的研究文章。

全文完。

Enjoy MySQL :)

叶老师的「MySQL核心优化」大课已升级到MySQL 8.0，扫码开启MySQL 8.0修行之旅吧

![format_png][]

[format_png]: /images/20221120/1f469628c458482597bf9e66608c15ad.png