事情的起因:
我司有一款应用处于新旧系统切换阶段,新旧服务同时穿插运行,新服务不断迭代的同时来不断下线旧服务,其中有一个编辑客户信息的功能因为工作量太大,所以其中一部分内容是通过RPC的方式调用新服务的API进行保存的,然后在出现了一个神奇的问题,RPC接口频繁超时,
于是我对RPC接口中各个阶段的代码执行了耗时统计,统计结果如下:
可以很清楚的看到第三个任务足足执行了9秒,但是这个任务是一个非常简单的主键删除,并且只有一行删除代码,没有其他逻辑,而且也可以看到剩余其他任务执行的非常快,所以我估计超时的原因在这个删除的SQL上
于是乎,我去云平台上抓了监控,发现这条删除SQL居然执行了7秒之久,表中仅有两万条数据,而且是按照主键进行删除的,这个执行时间非常之不科学
但是我在本地进行单元测试时,任务执行的非常快,丝毫没有这个问题。
于是乎,我把目标开始转向死锁方向进行排查,执行以下代码获取mysql innodb 引擎的事务会话和锁信息,我发现,当我代码执行时,总是会同时出现两个事务并且其中一个事务的权重非常高,而我执行的SQL一直在进行锁等待,所以我猜测是另一个事务影响了我的删除
于是乎我根据事务id对innodb的锁进行了排查,发现这两个事务拿的是同一个物理扇区的同一个行锁而且是X排他锁
但是我自己执行单元测试时,发现并没有这些锁的问题,所以我猜测,是旧服务通过RPC调用我之前对这条数据进行了修改,提前拿到了X锁,所以导致了新服务侧再次拿锁时只能等待
于是我去翻了半天老服务代码,发现果然在RPC调用之前有一个UPDATE操作,这个UPDATE先拿到了X锁,然后RPC调用新服务时,新服务只能在那死等,但是旧服务是等待RPC调用成功后才会提交事务,所以就导致了死锁。
这个BUG说实话犯的很蠢,花了半天的时间才找到原因,期间过于依赖云平台的监控,一直没考虑过是因为新旧服务的锁冲突导致的问题,甚至给阿里云提了工单怀疑是他们数据的问题,最后还是通过最原始的方法才找到了问题的根本原因。
标签:事务,服务,删除,RPC,排查,死锁,MySQL,执行 From: https://www.cnblogs.com/Tassdar/p/17636809.html