上QQ阅读APP看本书,新人免费读10天
设备和账号都新为新人
6.5 查看最近的事务执行信息
虽然我们可以通过慢查询日志查询到一条语句的执行总时长,但是如果数据库中存在着一些大事务在执行过程中回滚了,或者在执行过程中异常中止,这个时候慢查询日志就爱莫能助了,这时我们可以借助performance_schema的events_transactions_*表来查看与事务相关的记录,在这些表中详细记录了是否有事务被回滚、活跃(长时间未提交的事务也属于活跃事务)或已提交等信息。下面分别模拟几种事务情况,并查看事务事件记录表。
首先需要进行配置启用,事务事件默认并未启用(会话1)。
mysql> 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 mysql> 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)。
mysql> truncate events_transactions_current; truncate events_transactions_history;truncate events_transactions_history_long;
Query OK, 0 rows affected(0.00 sec)
......
然后开启一个新会话(会话2)用于执行事务,并模拟事务回滚。
mysql> use sbtest Database changed mysql> begin; Query OK, 0 rows affected(0.00 sec) mysql> 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表中查询。
mysql> 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,回滚事务,被回滚完成的事务不再活跃。
mysql> rollback;
Query OK, 0 rows affected(0.01 sec)
会话1,查询事务事件历史记录表events_transactions_history_long。
mysql> 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 mysql> begin; Query OK, 0 rows affected(0.00 sec) mysql> update sbtest1 set pad='yyy' where id=1; Query OK, 1 row affected(0.00 sec) Rows matched: 1 Changed: 1 Warnings: 0 mysql> commit; Query OK, 0 rows affected(0.01 sec) # 会话1 mysql> 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状态,表示事务已经提交成功。
提示:如果一个事务长时间未提交(长时间处于ACTIVE状态),对于这种情况,虽然从events_transactions_current表中可以查询到未提交的事务事件信息,但是并不能很直观地看到事务是什么时间点开始的,我们可以借助information_schema.innodb_trx表来进行辅助判断。
mysql> 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)