记一次Mysql故障排查(lock wait timeout exceeded;try restarting transaction)

Posted

tags:

篇首语:本文由小常识网(cha138.com)小编为大家整理,主要介绍了记一次Mysql故障排查(lock wait timeout exceeded;try restarting transaction)相关的知识,希望对你有一定的参考价值。

参考技术A 最近接了一个锅,进入新公司接手了一个进入交付阶段的项目.在code review的时候发现很多问题,然后开始修复bug.

在测试阶段突然发现几乎所有涉及到更新的操作都失败,下面贴出异常信息.

第一次 出现的时候百度了一下,猜想可能是多服务部署资源冲突,重启服务故障消失.所以没有特别重视

第二次 出现的时候只有测试环境部署,不存在多机资源冲突的问题,猜想是多线程资源交叉导致的,于是给可能导致资源竞争的地方加上了分布式锁.

由于无法重现故障,所以并没有确认问题得到解决.

第三次 故障依旧,当发现问题依然存在的时候,开始认真反思,发现自己解决问题的思路明显有问题,过于片面,一直都只在应用层面寻求解决问题的办法,而且解决问题的方式也只是在尝试百度出来的方法.并没有去思考更深层的问题.

mysql5.5中,information_schema 库中增加了三个关于锁的表(MEMORY引擎);

INNODB_TRX ## 当前运行的所有事务

INNODB _LOCKS ## 当前出现的锁

  INNODB_LOCK_WAITS ## 锁等待的对应关系

通过查询 INNODB_TRX 发现

当前事务中又两个RUNNING状态开始时间在一个小时之前

开始一直以为是锁表了

查看了 INNODB _LOCKS  事务信息之后发现有4行数据被锁住了一直没有释放

从这里开始发现问题了,应用已经抛了异常,事务理所当然的应该回滚才对,为什么资源依然没有释放,导致持续的阻塞呢?

其实最开始的异常信息就已经给出了答案,回到开始的地方,再看异常信息就很清楚了,应用里面的异常类是 MySQLTransactionRollBackException

是一个回滚异常, 这就说明在事务回滚的时候出了问题资源没有得到释放

然后开始查询 MySQLTransactionRollBackException  相关的信息

这个时候 innodb_rollback_on_timeout =0(默认配置)这个MySQL的配置开始进入我的视线,

举个栗子

事务在锁等待超时后是回滚事务内所有的statement还是最后一条语句;

 0表示rollback最后一条语句,默认值; 有点坑爹啊( 细思极恐 )

 1表示回滚事务内所有的statements;(此参数是只读参数,需在my.cnf中配置,并且重启生效;)

吃过一次亏,这次并没有盲目的相信百度到的信息

于是开始测试

一、验证innodb_rollback_on_timeout=off的情况

1.session A

    开启事务,事务未提交,锁住id=1的数据

2.session B 

开启事务,执行更新id=2的数据成功(事务未提交,锁住id=2),然后请求id=1等待锁超时,id=2的数据更改为222.

3.session C

请求id=2的数据50秒后显示等待锁超时

执行 SELECT * FROM information_schema.INNODB_TRX;

可发现有资源一直未释放,具体到测试数据中就是id=2的资源一直被锁定,线程一直被挂起.

总结:通过实验基本可以确定是业务资源交叉导致死锁之后资源没释放造成的持续阻塞,

二.验证innodb_rollback_on_timeout=on

修改配置后将验证innodb_rollback_on_timeout=off的步骤再走一遍

发现锁等待只能在业务层面尽量避免

on/off的区别在于session C进入时不会持续阻塞,session B异常后全部回滚

记一次HBase RegionServer 经常挂掉 故障排查过程

参考技术A 原始采集数据采用HBase进行存储。 实时采集数据流量很大,在入库的时候,有时候会发生阻塞。 

测试环境正常,生产环境下,时不时出现HRegionServer挂掉的情况, 而HMaster正常。 重启Hbase之后,短时间内恢复正常,然而一段时间之后,再次出现RegionServer挂掉的情况。 因此,我们决定对此故障进行深入排查,找出故障原因。 

从日志的异常记录来看, region-server日志中存在大量WAL异常(敏感信息已加码)

RegionServer挂掉以及JVM因GC暂停

从上述异常日志,我们可以故障原因推理。 因为某些原因导致GC(垃圾回收机制)花费时间过长, 进而JVM被暂停了。因此该节点不能够发送心跳给Zookeeper, Zookeeper将该节点标记为dead server。 启动容错机制,将状态记录在WAL中, 由其他节点代替该节点进行工作。 

在该节点GC完毕,恢复正常,请求Zookeeper重新将该节点加入集群。 然后超过timeout阈值,导致WAL无法被找到,恢复失败。 同理,直至所有节点都被Zookeeper标记为异常节点,导致整个集群的region server都无法工作。 

导致GC时间过长的原因有很多, 例如 

1. ZooKeeper内存分配不足,尤其是大量数据导入的时候 

2. 其他程序存在内存溢出bug 

3. CPU消耗过大

4. 节点失效timeout阈值过短

经过逐步排查,我们定位故障原因为第4点,timeout阈值不足。 

我们使用的是Hbase自带的ZooKeeper, 因此需要修改hbase-site.xml文件来配置timout值。

修改 zookeeper.session.timeout 为 100000 ms, 默认为 90000 ms

修改  hbase.zookeeper.property.tickTime 为 6000 ms, 默认为 2000ms

注: 

如果timeout < tickTime * 2, 则实际timeout 为 tickTime * 2

如果timeout > tickTime * 20, 则实际timeout 为 tickTime * 20 

因此,我们需要注意 zookeeper.session.timeout 和 tickTime 之前的关系。 

以上是关于记一次Mysql故障排查(lock wait timeout exceeded;try restarting transaction)的主要内容,如果未能解决你的问题,请参考以下文章

记一次MongoDB故障排查的过程

记一次无法远程故障排查20161211.2111

解Bug之路-记一次存储故障的排查过程

记一次CLOSE_WAIT多的故障

记一次HBase RegionServer 经常挂掉 故障排查过程

排查MySQL事务没有提交导致 锁等待 Lock wait timeout exceeded