千金良方:MySQL性能优化金字塔法则
上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)