• 企业400电话
  • 微网小程序
  • AI电话机器人
  • 电商代运营
  • 全 部 栏 目

    企业400电话 网络优化推广 AI电话机器人 呼叫中心 网站建设 商标✡知产 微网小程序 电商运营 彩铃•短信 增值拓展业务
    MySQL DeadLock故障排查全过程记录

    【作者】

    刘博:携程技术保障中心数据库高级经理,主要关注Sql server和Mysql的运维和故障处理。

    【环境】

    版本号:5.6.21

    隔离级别:REPEATABLE READ

    【问题描述】

    接到监控报警,有一个线上的应用DeadLock报错,每15分钟会准时出现,报错统计如下图:


    登录Mysql服务器查看日志:

    mysql> show engine innodb status\G
    
    *** (1) TRANSACTION:
    
    TRANSACTION 102973, ACTIVE 11 sec starting index read
    
    mysql tables in use 3, locked 3
    
    LOCK WAIT 4 lock struct(s), heap size 1136, 3 row lock(s)
    
    MySQL thread id 6, OS thread handle 140024996574976, query id 83 localhost us updating
    
    UPDATE TestTable
    
    SET column1 = 1,
    
    Column2 = sysdate(),
    
    Column3= '026'
    
    Column4 = 0
    
    AND column5 = 485
    
    AND column6 = 'SEK'
    
    *** (1) WAITING FOR THIS LOCK TO BE GRANTED:
    
    RECORD LOCKS space id 417 page no 1493 n bits 1000 index idx_column6 of table test.TestTable trx id 102973 lock_mode X waiting
    
    Record lock, heap no 859 PHYSICAL RECORD: n_fields 2; compact format; info bits 0
    
    0: len 3; hex 53454b; asc SEK;;
    
    1: len 8; hex 80000000007e1452; asc ~ R;;
    
    *** (2) TRANSACTION:
    
    TRANSACTION 102972, ACTIVE 26 sec starting index read
    
    mysql tables in use 3, locked 3
    
    219 lock struct(s), heap size 24784, 2906 row lock(s), undo log entries 7
    
    MySQL thread id 5, OS thread handle 140024996841216, query id 84 localhost us updating
    
    UPDATE TestTable
    
    SET Column1 = 1,
    
    Column2 = sysdate(),
    
    Column3 = '026'
    
    Column4 = 0
    
    AND Column5 = 485
    
    AND Column6 = 'SEK'
    
    *** (2) HOLDS THE LOCK(S):
    
    RECORD LOCKS space id 417 page no 1493 n bits 1000 index idx_Column6 of table test.TestTable trx id 102972 lock_mode X
    
    Record lock, heap no 1 PHYSICAL RECORD: n_fields 1; compact format; info bits 0
    
    0: len 8; hex 73757072656d756d; asc supremum;;
    
    
    Record lock, heap no 859 PHYSICAL RECORD: n_fields 2; compact format; info bits 0
    
    0: len 3; hex 53454b; asc SEK;;
    
    1: len 8; hex 80000000007e1452; asc ~ R;;
    *** (2) WAITING FOR THIS LOCK TO BE GRANTED:
    
    RECORD LOCKS space id 601 page no 89642 n bits 1000 index idx_column6 of table test.TestTable trx id 32231892482 lock_mode X locks rec but not gap waiting
    
    Record lock, heap no 38 PHYSICAL RECORD: n_fields 2; compact format; info bits 0
    
    0: len 3; hex 53454b; asc SEK;;
    
    1: len 8; hex 80000000007eea14; asc ~ ;;

    大致一看,更新同一索引的同一行,应该是一个Block,报TimeOut的错才对,怎么会报DeadLock?

    【初步分析】

    先分析下(2) TRANSACTION,TRANSACTION 32231892482。

    等待的锁信息为:

    0: len 3; hex 53454b; asc SEK;;
    
    1: len 8; hex 80000000007eea14; asc

    持有的锁信息为:

    0: len 3; hex 53454b; asc SEK;;
    
    1: len 8; hex 80000000007eeac4; asc

    再先分析下(1) TRANSACTION,TRANSACTION 32231892617。

    等待的锁信息为:

    0: len 3; hex 53454b; asc SEK;;
    
    1: len 8; hex 80000000007eeac4; asc

    于是可以画出的死锁表,两个资源相互依赖,造成死锁:

    TRANSACTION Hold Wait
    32231892617 53454b\80000000007eea14 53454b\80000000007eeac4
    32231892482 53454b\80000000007eeac4 53454b\80000000007eea14

    让我们再看一下explain结果:

    mysql>desc UPDATE TestTable SET Column1=1, Column2 = sysdate(),Column3 = '025' Column4 = 0 AND Column5 = 477 AND Column6 = 'SEK' \G;

    *************************** 1. row ***************************

    id: 1

    select_type: UPDATE

    table: TestTable

    partitions: NULL

    type: index_merge

    possible_keys: column5_index,idx_column5_column6_Column1,idxColumn6

    key: column5_index,idxColumn6

    key_len: 8,9

    ref: NULL

    rows: 7

    filtered: 100.00

    Extra: Using intersect(column5_index,idxColumn6); Using where

    可以看到 EXTRA 列:

    Using intersect(column5_index,idxColumn6)

    从5.1开始,引入了 index merge 优化技术,对同一个表可以使用多个索引分别进行条件扫描。

    相关文档:http://dev.mysql.com/doc/refman/5.7/en/index-merge-optimization.html

    The Index Merge method is used to retrieve rows with several range scans and to merge their results into one. The merge can produce unions, intersections, or unions-of-intersections of its underlying scans. This access method merges index scans from a single table; it does not merge scans across multiple tables.

    【模拟与验证】

    根据以上初步分析,猜测应该就是intersect造成的,于是在测试环境模拟验证,开启2个session模拟死锁:

    时间序列 Session1 Session2
    1 Begin;
    2 UPDATE TestTable SET Column2 = sysdate() Column4 = 0 AND Column5 = 47 AND Column6 = 'SEK 
    执行成功,影响7行
    3 Begin;
    4 UPDATE TestTable SET Column2 = sysdate(),Column4 = 0 AND Column5 = 485 AND Column6 = 'SEK';
    被Blocking
    5 UPDATE TestTable SET Column2 = sysdate(),Column4 = 0 AND Column5 = 485 AND Column6 = 'SEK';
    执行成功
    ERROR 1213 (40001): Deadlock found when trying to get lock; try restarting transaction

    依据以上信息可以发现Session2虽然被Block了,但也获取了一些Session1在时间序列5时所需资源的X锁,可以再开启一个查询select count(Column5) from TestTable where Column5 = 485,设置SET TRANSACTION ISOLATION LEVEL SERIALIZABLE,去查询Column5 = 485的行,观察锁等待的信息:
    mysql> SELECT r.trx_id waiting_trx_id, r.trx_mysql_thread_id waiting_thread, r.trx_query waiting_query, b.trx_id

    mysql> SELECT r.trx_id waiting_trx_id, r.trx_mysql_thread_id waiting_thread, r.trx_query waiting_query, b.trx_id blocking_trx_id, b.trx_mysql_thread_id blocking_thread, b.trx_query blocking_query FROM information_schema.innodb_lock_waits w INNER JOIN information_schema.innodb_trx b ON b.trx_id = w.blocking_trx_id INNER JOIN information_schema.innodb_trx r ON r.trx_id = w.requesting_trx_id \G;
    
    *************************** 1. row ***************************
    
    waiting_trx_id: 103006
    
    waiting_thread: 36
    
    waiting_query: UPDATE TestTable SET Column1 = 1, Column2 = sysdate(), Column3 = '026' Column4 = 0 AND Column5 = 485 AND Column6 = 'SEK'
    
    blocking_trx_id: 103003
    
    blocking_thread: 37
    
    blocking_query: NULL
    
    *************************** 2. row ***************************
    
    waiting_trx_id: 421500433538672
    
    waiting_thread: 39
    
    waiting_query: select count(Column5) from TestTable where Column5 = 485
    
    blocking_trx_id: 103006
    
    blocking_thread: 36
    
    blocking_query: UPDATE TestTable SET Column1 = 1, Column2 = sysdate(), Column3 = '026' Column4 = 0 AND Column5 = 485 AND Column6 = 'SEK'
    
    2 rows in set, 1 warning (0.00 sec)
    
    mysql> select * from information_schema.innodb_lock_waits \G;
    
    *************************** 1. row ***************************
    
    requesting_trx_id: 103006
    
    requested_lock_id: 103006:417:1493:859
    
    blocking_trx_id: 103003
    
    blocking_lock_id: 103003:417:1493:859
    
    *************************** 2. row ***************************
    
    requesting_trx_id: 421500433538672
    
    requested_lock_id: 421500433538672:417:749:2
    
    blocking_trx_id: 103006
    
    blocking_lock_id: 103006:417:749:2
    
    2 rows in set, 1 warning (0.00 sec)
    mysql> select * from INNODB_LOCKS \G;
    
    *************************** 1. row ***************************
    
    lock_id: 103006:417:1493:859
    
    lock_trx_id: 103006
    
    lock_mode: X
    
    lock_type: RECORD
    
    lock_table: test.TestTable
    
    lock_index: idxColumn6
    
    lock_space: 417
    
    lock_page: 1493
    
    lock_rec: 859
    
    lock_data: 'SEK', 8262738
    
    *************************** 2. row ***************************
    
    lock_id: 103003:417:1493:859
    
    lock_trx_id: 103003
    
    lock_mode: X
    
    lock_type: RECORD
    
    lock_table:test.TestTable
    
    lock_index: idxColumn6
    
    lock_space: 417
    
    lock_page: 1493
    
    lock_rec: 859
    
    lock_data: 'SEK', 8262738
    
    *************************** 3. row ***************************
    
    lock_id: 421500433538672:417:749:2
    
    lock_trx_id: 421500433538672
    
    lock_mode: S
    
    lock_type: RECORD
    
    lock_table: test.TestTable
    
    lock_index: column5_index
    
    lock_space: 417
    
    lock_page: 749
    
    lock_rec: 2
    
    lock_data: 485, 8317620
    
    *************************** 4. row ***************************
    
    lock_id: 103006:417:749:2
    
    lock_trx_id: 103006
    
    lock_mode: X
    
    lock_type: RECORD
    
    lock_table: test.TestTable
    
    lock_index: column5_index
    
    lock_space: 417
    
    lock_page: 749
    
    lock_rec: 2
    
    lock_data: 485, 8317620
    
    4 rows in set, 1 warning (0.00 sec)

    可以看到Session2,trx_id 103006阻塞了trx_id 421500433538672,而trx_id 421500433538672 requested_lock也正好是lock_data: 485, 8317620。由此可见Session2虽然别block了,但是还是获取到了Index column5_index相关的锁。被Block是因为intersect的原因,还需要idxColumn6的锁,至此思路已经清晰,对整个分配锁的信息简化一下,如下表格(请求到的锁用青色表示,需获取但未获取到的锁用红色表示):

    时间点 Session1 Session2
    1 477 SEK
    2 485 SEK
    3 485 SEK 死锁发生

    可以看到485 SEK这两个资源形成了一个环状,最终发生死锁。

    【解决方法】

    总结

    以上就是这篇文章的全部内容了,希望本文的内容对大家的学习或者工作具有一定的参考学习价值,如果有疑问大家可以留言交流,谢谢大家对脚本之家的支持。

    您可能感兴趣的文章:
    • mysql报错:Deadlock found when trying to get lock; try restarting transaction的解决方法
    • 线上MYSQL同步报错故障处理方法总结(必看篇)
    • MYSQL主从库不同步故障一例解决方法
    • 一次MySQL慢查询导致的故障
    • MySQL下高可用故障转移方案MHA的超级部署教程
    • MySQL复制的概述、安装、故障、技巧、工具(火丁分享)
    • 检测MySQL的表的故障的方法
    上一篇:MySQL配置SSL主从复制
    下一篇:基于MySQL数据库的数据约束实例及五种完整性约束介绍
  • 相关文章
  • 

    © 2016-2020 巨人网络通讯 版权所有

    《增值电信业务经营许可证》 苏ICP备15040257号-8

    MySQL DeadLock故障排查全过程记录 MySQL,DeadLock,故障,排查,全过程,