MySQL如何定位未提交事务执行的SQL语句?
一、问题描述
我们经常会碰到这样的情况,某个事务执行完了未提交,后续再来一个DDL和DML操作,导致后面的session要么处于waiting for metadata lock,要么是锁等待超时。这时我们往往只能找到这个未提交的事务的事务id和session id,但是一般都处于sleep状态,不好分析事务内容到底是什么,所以通常都是粗鲁地kill这个session后解决问题,但是应用层的研发人员往往找不到到底是哪个事务引起的,后面再出现问题时还要重复kill。那这个情况下,怎么办呢?
下面我先模拟两种情况
这里我特意在开启session后执行一条update,又执行了一条insert语句。
这时session2一直卡住
我们再开一个窗口session3。
mysql> show processlist;
+----+------+-----------+------+---------+------+---------------------------------+----------------------------------------------------+
| Id | User | Host | db | Command | Time | State | Info |
+----+------+-----------+------+---------+------+---------------------------------+----------------------------------------------------+
| 4 | root | localhost | test | Sleep | 841 | | NULL |
| 5 | root | localhost | test | Query | 709 | Waiting for table metadata lock | alter table test_lock add column name2 varchar(50) |
| 6 | root | localhost | NULL | Query | 0 | starting | show processlist |
+----+------+-----------+------+---------+------+---------------------------------+----------------------------------------------------+
可看到ddl操作也被卡住了,之前的事务1也处于sleep状态,无法得知它到底执行了什么。
这时我们查询innodb_trx表可看到事务1也看不到sql信息。
二、解决方案
方案一
我想到的第一种方法是利用performance_schema中的相关信息查询
mysql> show variables like 'performance_schema';
+--------------------+-------+
|Variable_name | Value |
+--------------------+-------+
|performance_schema | ON |
+--------------------+-------+
1 row in set(0.00 sec)
通过查看events_statements_current表可看到每一个session正在执行的sql,哪怕它依旧执行完成了,只是没有提交。这里可看到事务1最后执行的正是insert into test_lock values(4,'andy');
mysql> select * from performance_schema.events_statements_current\G
不过方案1有个缺陷,一个事务可能有一组sql组成,这个方法只能看到这个事务最后执行的是什么SQL,无法看到全部。也就是说,关于information_schema.processlist和events_statements_current如何一一对应起来,可以通过performance_schema.threads表来关联,语句如下:
mysql> select * from performance_schema.events_statements_current where THREAD_ID in (select THREAD_ID from performance_schema.threads where PROCESSLIST_ID=4)\G
如果你是MySQL 5.7版本,可以通过查看sys.session视图和sys.processlist视图得到最后一次执行的SQL语句。
方案二
然后我想到了是不是可以用general_log的方式,一般情况下general_log不大可能打开,所以我们先打开general_log等着问题复现的方式来定位,经测试,即使事务没有提交,一样会写到general_log。
mysql> show variables like '%general%';
+------------------+-------------------------------------------+
| Variable_name | Value |
+------------------+-------------------------------------------+
| general_log | OFF |
| general_log_file | /data/mysql/3306/data/qs-ops-db-01.log |
+------------------+-------------------------------------------+
2 rows in set (0.00 sec)
mysql> set global general_log=1;
Query OK, 0 rowsaffected (0.00 sec)
开启general日志后,只要知道了未提交事务的进程号就可以完美找到对应的SQL语句了。
$ cat /data/mysql/3306/data/qs-ops-db-01.log | grep 4
mysqld, Version: 5.7.17-log (MySQL Community Server (GPL)). started with:
Tcp port: 3306 Unix socket: /data/mysql/3306/mysql.sock
Time Id Command Argument
2017-03-29T07:22:00.949233Z 4 Query begin
2017-03-29T07:22:11.090712Z 4 Query update test_lock set id=123 where id=1
2017-03-29T07:22:18.347311Z 4 Query insert into test_lock values(4,'andy')
这样只要后续能否复现的话,就能找到所有的SQL了,就是如果此会话是长连接,那么必然执行的SQL语句较多,这时候就需要慢慢排查了。
方案三
假如后面应用层最终commit了,那么会在binlog里记录,可以根据当时的session id去binlog里面查看完整事务。