课题:查看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全方位介绍