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里面查看完整事务。

©著作权归作者所有,转载或内容合作请联系作者
  • 序言:七十年代末,一起剥皮案震惊了整个滨河市,随后出现的几起案子,更是在滨河造成了极大的恐慌,老刑警刘岩,带你破解...
    沈念sama阅读 218,386评论 6 506
  • 序言:滨河连续发生了三起死亡事件,死亡现场离奇诡异,居然都是意外死亡,警方通过查阅死者的电脑和手机,发现死者居然都...
    沈念sama阅读 93,142评论 3 394
  • 文/潘晓璐 我一进店门,熙熙楼的掌柜王于贵愁眉苦脸地迎上来,“玉大人,你说我怎么就摊上这事。” “怎么了?”我有些...
    开封第一讲书人阅读 164,704评论 0 353
  • 文/不坏的土叔 我叫张陵,是天一观的道长。 经常有香客问我,道长,这世上最难降的妖魔是什么? 我笑而不...
    开封第一讲书人阅读 58,702评论 1 294
  • 正文 为了忘掉前任,我火速办了婚礼,结果婚礼上,老公的妹妹穿的比我还像新娘。我一直安慰自己,他们只是感情好,可当我...
    茶点故事阅读 67,716评论 6 392
  • 文/花漫 我一把揭开白布。 她就那样静静地躺着,像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上,一...
    开封第一讲书人阅读 51,573评论 1 305
  • 那天,我揣着相机与录音,去河边找鬼。 笑死,一个胖子当着我的面吹牛,可吹牛的内容都是我干的。 我是一名探鬼主播,决...
    沈念sama阅读 40,314评论 3 418
  • 文/苍兰香墨 我猛地睁开眼,长吁一口气:“原来是场噩梦啊……” “哼!你这毒妇竟也来了?” 一声冷哼从身侧响起,我...
    开封第一讲书人阅读 39,230评论 0 276
  • 序言:老挝万荣一对情侣失踪,失踪者是张志新(化名)和其女友刘颖,没想到半个月后,有当地人在树林里发现了一具尸体,经...
    沈念sama阅读 45,680评论 1 314
  • 正文 独居荒郊野岭守林人离奇死亡,尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 37,873评论 3 336
  • 正文 我和宋清朗相恋三年,在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 39,991评论 1 348
  • 序言:一个原本活蹦乱跳的男人离奇死亡,死状恐怖,灵堂内的尸体忽然破棺而出,到底是诈尸还是另有隐情,我是刑警宁泽,带...
    沈念sama阅读 35,706评论 5 346
  • 正文 年R本政府宣布,位于F岛的核电站,受9级特大地震影响,放射性物质发生泄漏。R本人自食恶果不足惜,却给世界环境...
    茶点故事阅读 41,329评论 3 330
  • 文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹,春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 31,910评论 0 22
  • 文/苍兰香墨 我抬头看了看天上的太阳。三九已至,却和暖如春,着一层夹袄步出监牢的瞬间,已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 33,038评论 1 270
  • 我被黑心中介骗来泰国打工, 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留,地道东北人。 一个月前我还...
    沈念sama阅读 48,158评论 3 370
  • 正文 我出身青楼,却偏偏与公主长得像,于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子,可洞房花烛夜当晚...
    茶点故事阅读 44,941评论 2 355

推荐阅读更多精彩内容