查看MySQL最近的事务执行信息

发布时间：2020-03-03 12:35:07 作者：wjw555
来源：网络阅读：316

课题：查看MySQL最近的事务执行信息

*虽然我们可以通过查询慢查询日志查询到一条语句的执行总时长，但是如果数据库中存在一些大事务在执行过程中回滚了，，或者在执行过程中异常终止了，这个时候慢查询日志中是不会记录的，这时需要借助
performance_schema的 eventstransactions—的表来查看与事务相关的记录，在这些表中详细记录了是否有事务被回滚，活跃（长时间未提交的事务也属于活跃事务）活已提交等信息。**

下面模拟几种事务情况，并查看事务事件记录表：

事务事件，默认是没启用的，首先需要进行配置启用


root@localhost [performance_schema]>select * from setup_instruments where name like 'transaction';
+-------------+---------+-------+
| NAME        | ENABLED | TIMED |
+-------------+---------+-------+
| transaction | NO      | NO    |
+-------------+---------+-------+
1 row in set (0.00 sec)

root@localhost [performance_schema]>select * from setup_instruments where name like '%transaction%';
+--------------------------------------------------------------------------------+---------+-------+
| NAME                                                                           | ENABLED | TIMED |
+--------------------------------------------------------------------------------+---------+-------+
| wait/synch/mutex/sql/LOCK_transaction_cache                                    | NO      | NO    |
| stage/sql/Waiting for preceding transaction to commit                          | NO      | NO    |
| stage/sql/Waiting for dependent transaction to commit                          | NO      | NO    |
| transaction                                                                    | NO      | NO    |
| memory/performance_schema/events_transactions_summary_by_account_by_event_name | YES     | NO    |
| memory/performance_schema/events_transactions_summary_by_host_by_event_name    | YES     | NO    |
| memory/performance_schema/events_transactions_summary_by_thread_by_event_name  | YES     | NO    |
| memory/performance_schema/events_transactions_history                          | YES     | NO    |
| memory/performance_schema/events_transactions_summary_by_user_by_event_name    | YES     | NO    |
| memory/performance_schema/events_transactions_history_long                     | YES     | NO    |
| memory/sql/THD::transactions::mem_root                                         | YES     | NO    |
+--------------------------------------------------------------------------------+---------+-------+
11 rows in set (0.00 sec)

查看最近的事务执行信息：

开启事务生产者的参数：

root@localhost [performance_schema]>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]>update setup_instruments  set enabled='yes' where name like '%transaction%';
Query OK, 3 rows affected (0.00 sec)
Rows matched: 11  Changed: 3  Warnings: 0

登录mysql会话1，执行清理，避免其他事务的干扰：
提示：线上最好不要直接truncate清除

root@localhost [performance_schema]>truncate events_transactions_current;truncate events_transactions_history; truncate events_transactions_history_long;

root@localhost [performance_schema]>select * from events_transactions_current;
Empty set (0.00 sec)

root@localhost [performance_schema]>select * from events_transactions_history;
Empty set (0.00 sec)

root@localhost [performance_schema]>select * from events_transactions_history_long;
Empty set (0.00 sec)

开启新的会话2，用于执行事务，并模拟事务的回滚：

root@localhost [test001]>begin;
Query OK, 0 rows affected (0.00 sec)

root@localhost [test001]>update test1_event set username='fox' where id=1;
Query OK, 1 row affected (0.00 sec)
Rows matched: 1  Changed: 1  Warnings: 0
root@localhost [test001]>rollback;
Query OK, 0 rows affected (0.00 sec)

在会话1查看当前活跃的事务，查看结果却是空值：

root@localhost [performance_schema]>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
Empty set (0.00 sec)
root@localhost [(none)]>

root@localhost [performance_schema]>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
Empty set (0.00 sec)
root@localhost [(none)]>

root@localhost [performance_schema]>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
Empty set (0.00 sec)
root@localhost [(none)]>

查看结果却是空值，原因是MySQL消费者参数setup_consumers这一块没开启

root@localhost [performance_schema]>select * from setup_consumers where name like '%transaction%';
+----------------------------------+---------+
| NAME                             | ENABLED |
+----------------------------------+---------+
| events_transactions_current      | NO      |
| events_transactions_history      | NO      |
| events_transactions_history_long | NO      |
+----------------------------------+---------+
3 rows in set (0.01 sec)

开启消费者参数：

root@localhost [performance_schema]>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

root@localhost [performance_schema]>select * from setup_consumers where name like '%transaction%';
+----------------------------------+---------+
| NAME                             | ENABLED |
+----------------------------------+---------+
| events_transactions_current      | YES     |
| events_transactions_history      | YES     |
| events_transactions_history_long | YES     |
+----------------------------------+---------+
3 rows in set (0.00 sec)

这些消费参数在分析完事务后记得关闭，关闭命令如下：

update setup_consumers  set enabled='no' where name like '%transaction%';

再次在会话1查看当前活跃的事务：

root@localhost [performance_schema]>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: 3957325
        EVENT_NAME: transaction
             STATE: ACTIVE
            TRX_ID: NULL
              GTID: AUTOMATIC
            SOURCE: 
        TIMER_WAIT: 85087447373000
       ACCESS_MODE: READ WRITE
   ISOLATION_LEVEL: REPEATABLE READ
        AUTOCOMMIT: NO
  NESTING_EVENT_ID: 27
NESTING_EVENT_TYPE: STATEMENT
1 row in set (0.00 sec)

在会话2 上rollback回滚事务：

root@localhost [test001]>begin;
Query OK, 0 rows affected (0.00 sec)

root@localhost [test001]>update test1_event set username='fox' where id=1;
Query OK, 1 row affected (0.00 sec)
Rows matched: 1  Changed: 1  Warnings: 0
root@localhost [test001]>rollback;
Query OK, 0 rows affected (0.00 sec)

再次在会话1查看当前活跃的事务：


root@localhost [performance_schema]>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: 3957325
        EVENT_NAME: transaction
             STATE: ROLLED BACK
            TRX_ID: NULL
              GTID: AUTOMATIC
            SOURCE: 
        TIMER_WAIT: 170837979344000
       ACCESS_MODE: READ WRITE
   ISOLATION_LEVEL: REPEATABLE READ
        AUTOCOMMIT: NO
  NESTING_EVENT_ID: 27
NESTING_EVENT_TYPE: STATEMENT
1 row in set (0.00 sec)

查看事务事件历史记录表：events_transactions_history：


root@localhost [performance_schema]>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\G
*************************** 1. row ***************************
         THREAD_ID: 3957325
        EVENT_NAME: transaction
             STATE: ROLLED BACK
            TRX_ID: NULL
              GTID: AUTOMATIC
            SOURCE: 
        TIMER_WAIT: 170837979344000
       ACCESS_MODE: READ WRITE
   ISOLATION_LEVEL: REPEATABLE READ
        AUTOCOMMIT: NO
  NESTING_EVENT_ID: 27
NESTING_EVENT_TYPE: STATEMENT
2 rows in set (0.00 sec)

root@localhost [test001]>select THREAD_ID,EVENT_NAME,STATE,TRX_ID,GTID,SOURCE,TIMER_WAIT,ACCESS_MODE,ISOLATION_LEVEL,AUTOCOMMIT,NESTING_EVENT_ID,NESTING_EVENT_TYPE from performance_schema.events_transactions_history_long where STATE='ROLLED BACK'\G
*************************** 1. row ***************************
         THREAD_ID: 3957325
        EVENT_NAME: transaction
             STATE: ROLLED BACK
            TRX_ID: NULL
              GTID: AUTOMATIC
            SOURCE: 
        TIMER_WAIT: 170837979344000
       ACCESS_MODE: READ WRITE
   ISOLATION_LEVEL: REPEATABLE READ
        AUTOCOMMIT: NO
  NESTING_EVENT_ID: 27
NESTING_EVENT_TYPE: STATEMENT
1 row in set (0.00 sec)

++++++++++++++++++++++++++++=+++++++++++++++++++++++++
在会话2上模拟正常提交事务：
开始事务


root@localhost [test001]>begin;
Query OK, 0 rows affected (0.00 sec)

root@localhost [test001]>update test1_event set username='fox' where id=1;
Query OK, 1 row affected (0.00 sec)
Rows matched: 1  Changed: 1  Warnings: 0

会话1上查看事务信息：


root@localhost [performance_schema]>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: 3957325
        EVENT_NAME: transaction
             STATE: ACTIVE
            TRX_ID: NULL
              GTID: AUTOMATIC
            SOURCE: 
        TIMER_WAIT: 18063808685000
       ACCESS_MODE: READ WRITE
   ISOLATION_LEVEL: REPEATABLE READ
        AUTOCOMMIT: NO
  NESTING_EVENT_ID: 75
NESTING_EVENT_TYPE: STATEMENT
1 row in set (0.00 sec)

在会话2上正常提交事务

root@localhost [test001]>commit;
Query OK, 0 rows affected (0.00 sec)

会话1上查看事务信息：


root@localhost [performance_schema]>
root@localhost [performance_schema]>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: 3957325
        EVENT_NAME: transaction
             STATE: COMMITTED                                           ##事务已经提交成功
            TRX_ID: NULL
              GTID: 64a062d1-2e92-11ea-847e-801844ed7bbc:2584551         ##事务正常提交后要记录Gtid的
            SOURCE: 
        TIMER_WAIT: 28245631402000
       ACCESS_MODE: READ WRITE
   ISOLATION_LEVEL: REPEATABLE READ
        AUTOCOMMIT: NO
  NESTING_EVENT_ID: 75
NESTING_EVENT_TYPE: STATEMENT
1 row in set (0.00 sec)

提示：如果一个事务长时间未提交（长时间处于ACTIVE状态）对于这情况，俺们可以查看表nformation_schema.innodb_trx 表直观的看到事务是什么时候开始的，
以及产生这个事务的mysql的线程id号trx_mysql_thread_id: 3957292（也就是会话2的线程id号）

root@localhost [performance_schema]>select * from information_schema.innodb_trx \G
*************************** 1. row ***************************
                    trx_id: 2594744
                 trx_state: RUNNING
               trx_started: 2020-02-13 17:53:23
     trx_requested_lock_id: NULL
          trx_wait_started: NULL
                trx_weight: 3
       trx_mysql_thread_id: 3957292

performance_schema相关表意思具体可参考下面资料：
配置详解 | performance_schema全方位介绍（二）
http://www.sohu.com/a/253338003_610509
应用示例荟萃 | performance_schema全方位介绍
https://blog.csdn.net/woqutechteam/article/details/81114520

查看MySQL最近的事务执行信息

相关阅读