“大”事务引起的锁等待分析案例
来源:互联网 发布:2017淘宝男装店铺排行 编辑:程序博客网 时间:2024/06/06 05:25
导读
作者:周晓,知数堂第8期学员
曾在TP-LINK任Oracle DBA和系统运维工作,目前在六度人和科技做MySQL DBA,主导多次与数据库相关的项目重构与设计、数据无停服迁移,帮助开发优化了大量SQL并组织培训,网络常用id: seanlook。
微信号:zhouxiao_zx77
博客:seanlook.com
一、现象
生产环境数据库在某一刻突然发现大量活跃连接,而且大部分状态是updating。问题出现在周六上午,持续了大概三、四分钟,得益于我们自己的快照程序,拿到了当时现场的processlist, 锁等待关系,及innodb status 信息:(经过脱敏处理)
innodb_status.txt gist片段: var_mydb_snapshot.html,详见:https://gist.coding.net/u/seanlook/d6ad649f81c64e23a25f3a980c44a1fe (也可以通过 pt-stalk 收集)
首先在 Lock Waits Info 一节,看到每行的trx_id(事务)的role分为 Blocker(引起阻塞的线程) 与 Blockee(被阻塞者);最后一列 blocking_trx_id 在role是Blockee时才有值,代表谁阻塞了当前事务。 根据上面的关系,可以得出以下结论:
1、事务 19705811640 运行了231s,阻塞了19706118937、19706124453、19706124752,而这些事务都在做同一个UPDATE语句;
2、被锁定的记录是 mydb.mytable1表的主键索引值为5317885行;
3、事务19706124752既被阻塞,也阻塞了别人19706125253;
4、不难发现19705811640应该最先运行的事务,且对其它事务产生了链式阻塞,它的thread_id(9898630) 和来源IP信息(xx.76)。
但是,当你兴冲冲地找到引起阻塞的事务19705811640 在做什么事情时,发现它没有任何sql的信息,lock info以及processlist里面都是None。那么有哪些情况会导致在会话是活跃的,但sql的内容为空:
1、执行show processlist的时候,刚好在事务里面两个sql的中间;
2、sql已经执行完成,但长时间没有提交。
二、初步分析
其实这个现象已经遇到过很多次了,第1个原因常发生在 大量单条记录更新 的情况,一个sql在一个事务里循环执行10000次,即使每条都很快,但大部分时间都在网络传输上,(可以改成批量的形式)。在本案例基本上能确定的是第2个原因:事务开启之后,sql也执行了,但中间又做别的事情去了。那么怎样才能知道这个事务是什么内容呢?两个方向去找:
1、从来源ip上的应用程序的日志里分析
2、binlog里面分析
应用程序日志里可以看 10:21:00 ~ 10:26:00 之间,mydb.mytable1 表上主键id=5317885 在做什么事情。因为我们上了听云,在听云APM里面也可以清楚的看到这个时间点的哪个方法慢:
响应时间230多秒,从“相关SQL”里面看到操作的记录内容,确定就是它了(根据innodb status快照时间 - ACTIVE 230.874 sec,倒推得到的时间与这里刚好吻合)。
从接口名称也清楚的知道是在进行禁用用户的操作,猜想: 禁用用户的逻辑上有先挪到回收站,再删资料、删权限、删关系,清理缓存等等一系列操作,放在事务里保证他们的原子性,似乎是合理的。但为什么执行了将近4分钟还没有提交呢,分析相关的sql效率都很高。
有三种情况:
1、这个事务执行到一半,它需要操作的数据被别人锁住,等待了这么久
2、类似事务要操作5000条数据,但是一条一条的操作,然后一起提交(已出现过类似的例子)
3、事务务执行完成很快,但调用其它接口迟迟没有返回,导致事务没提交。
不会是1和2,因为从一开始的分析看到事务 19705811640 都是在阻塞别人,而不是受害者。那么结合上图中有个有两个操作redis的接口执行时间占比96%,可以下定论了:
在禁用用户时,开启了一个事务,四五个增删改很快完成,但是操作redis缓存过程比较慢,也包含在了事务代码之间,长时间没有提交。前端用户操作的时候因为迟迟没有响应,进行了多次重复点击操作,因为影响的还是同一行记录,所以只能等待前面的锁释放。
Bingo,跟最初的设想一样。但是,开发检查代码之后告诉我,没有用事务!那前面的猜想和结论都不成立了。
三、 论证
于是走另外一个思路,分析binlog。如果binlog里面记录那条记录修改(设置禁用标志)和删除(真正删除)的时间是 10:21:58,说明数据库操作那时候就完成;如果是10:25:xx,说明最后才提交。为了弄明白这个问题,也为了搞情况事务的内容到底是什么,解析当时的binlog。(阿里云rds的数据追踪功能本来挺好用,但这一次用着报内部错误)
还记得前面那个thread_id吗,可以用在这里过滤(也可以用记录值):
上面的 summarize_binlogs.sh 脚本来源于《MySQL运维内参》,可以汇总分析binlog里面事务的执行时间。
mysql-bin.010743.sql.txt:
binlog格式当中,一个事务最先记录的是GTID事件,而这个GTID的值只有在提交的时候才会生成,binlog里面的GTID时间的时间10:25:54就是事务提交的时间。 Xid在最末尾,时间也是10:25:54。但中间该事务的其它binlog事件,像UpdateRows/DeleteRows/InsertRows,前面的时间10:21:58是事务开始的时间。中间有4分钟的空档,与前面redis操作4分钟不谋而合。
这下就更加明朗了:有显式的开启事务。但开发说没有用事务,又该怎么解释呢?
不同的语言,不同的框架,使用事务的方式不一样。数据库里面开启显式事务有两种方式,一是设置 set autocommit=0,二是运行start transaction。两者都要显式调用commit命令提交事务。 为了证实程序的确用了事务,在测试环境应用服务器模拟用户的操作,然后抓包:
有发送 set autocommit=0,这下更放心了。开发再次回去检查,发现在Spring框架的时,在类上面用 @Transactional 的方式做了事务,而常规的做法是把注解加在类的方法上,导致忽略了这个因素。
四、解决
解决办法是把需要做事务控制的地方放到Services接口级别,让redis清理缓存的操作在事务之外,或者异步清理。(但也要考虑这样做会有什么负面影响) 另外,Redis操作慢,是否是设计上的问题。(听云监控里面显示该事务里面调用了1300次)
五、总结
首先根据但是的现场快照,分析锁等待关系;根据以前的经验,怀疑是“大”事务中有无关的调用;根据程序日志和听云分析出对应的接口;但开发说没有事务,于是进一步通过分析binlog,经过tcp抓包,拿出证据;最后解决。
我们经常说,尽量少用大事务,但由于现在开发都是基于各种框架,使用事务的方式被封装,要理解它们的用法。其次,我们上面的事务并不大,每个sql更新都很快,但是却把其它调用也写在事务里面,就容易阻塞而长时间不提交,也许这样做的初衷是操作db与清理redis缓存放在一个事务里,要么都成功,要么都失败,但是这种分布式设计就不合理(当然有办法是可以做到,这里不展开)。
本文即是一个大事务锁的分析案例,也展示了引用各种工具,去分析论证的过程。
扫码加入知数堂技术交流QQ群
(群号:579036588)
群内可@各位助教了解双11活动优惠
知数堂
叶金荣与吴炳锡联合打造
领跑IT精英培训
行业资深专家强强联合,倾心定制
MySQL实战/MySQL优化 / Python/ SQL优化
数门精品课程
紧随技术发展趋势,定期优化培训教案
融入大量生产案例,贴合企业一线需求
社群陪伴学习,一次报名,可学3期
DBA、开发工程师必修课
上千位学员已华丽转身,薪资翻番,职位提升
改变已悄然发生,你还在等什么?
扫码下载知数堂精品课程试听视频
或点击“阅读原文”直达下载地址
(MySQL 实战/优化、Python开发,及SQL优化等课程)
密码:hg3h
- “大”事务引起的锁等待分析案例
- 事务队列等待深入分析:记录锁
- 查看正在执行的事务、锁、等待
- DB2环境变量设置引起的锁等待超时问题
- 大IO操作引起ksearch性能波动的问题分析
- 等待成功所引起的副作用
- SQL的事务回滚操作带案例分析
- 事务队列等待深入分析:ITL争用
- 4大案例分析金融机构的大数据应用
- 利用索引降低并发事务引起的锁
- MySql事务隔离级别锁机制实际案例深入分析
- 分析DB2数据库的锁等待
- ORACLE脚本之锁表时 查询谁锁了表而又引起谁的等待
- 案例分析2:为什么db2频现“锁等待”或“911”错误
- 一个由于spring事务引起的bug
- 锁等待分析处理
- mysql锁等待分析
- 案例:死锁引起的应用挂起
- Java对象流与序列化
- 数据结构
- C++ 11的继承构造函数
- 有了开发板和平台资源,AI语音技能开发没有想象那么难
- 78/90. Subsets (子集合)
- “大”事务引起的锁等待分析案例
- Android出现:Your project path contains non-ASCII characters.
- 如何下载golang.org/x包
- 法兰距大全
- Centos7中搭建最新版nexus3_maven私服
- Token生成规则以及工具
- Oracle 时间戳 日期
- qt上位机,将下位机发送数据解码显示实时曲线
- ActiveMq 简单使用