一条SQL走错索引导致数据库出现超时问题排查过程

现象

最近刚接手的一个项目,在某天中午12点30多分接到开发反馈,他们业务请求数据库的时候,出现了大量请求超时问题,虽然之前也有过,但是这次持续很久,大概两分钟多又恢复好了。
数据库版本8.0.22。隔离级别RR。

初步分析

接到问题,不着急,先看一下监控:
在这里插入图片描述
在这里插入图片描述
从监控图上看可以看到在对应的12点36分左右的时候出现了连接数开始飙高,以及这个点出现了少量的慢sql.
查看的对应时间点的慢查询日志,查到对应时刻有如下的慢查询sql:
在这里插入图片描述
这里可以看到这个慢查询从12点36分执行了155s。
这个SQL按理说不会慢,因为(uid,msg_id)是一个uk索引,id是主键。
然后因为出现超时,所以猜测是因为锁导致的超时原因吗?
但是由于新项目没有很深层的关于锁相关监控,只能去查询存储引擎信息
Show engine innodb status\G; 这个只能看到最近一次的死锁信息。要想看到完整的死锁信息 建议打开innodb_print_all_deadlocks,该参数会将所有的死锁信息输出到 MySQL的error log当中。这样就不会错过对应时间点的死锁日志。
结果在里面发生了一条在对应时间点的死锁信息,如下:
在这里插入图片描述

从最近一次的死锁日志里面,我们可以得知:
当时的时候出现了锁等待情况 这里需要声明一下锁等待和死锁的区别
1.死锁发生的时候会立即报错,并且回滚代价小的SQL。 锁等待是根据innodb_lock_wait_timeout 默认50s,如果在50s拿不到对应的锁,就会报错事务try again。 所以说死锁肯定是因为先出现锁等待的情况。
在这里插入图片描述

  1. 当时的锁竞争主要在于主键索引上的record锁竞争导致 但是,从两个SQL来看,这两个SQL都是有uk索引的,最后主键不可能出现锁竞争的情况。

查到这里,有点没想法了,后面就想着只能回过头去看看执行计划了,是不是执行计划没有走到;

在这里插入图片描述

神奇一幕发生了,这个SQL居然走了主键索引,那这就有思路了。
表里面的数据本来就2500w条,这里看到基本上像是扫描了全表,
如果是全表扫的话,对主键上全部加了锁,那这样就说的通了。

总结

问题的流程大概如下:
12点36分,这个慢SQL由于走错索引,拿了全部主键索引的gap和record锁
接着其他请求过来,因为innodb_lock_wait_timeout=50s的默认值情况下,
所以后续的SQL在拿不到锁等待50s之后报错try again,业务反应为超时。
就这样一直在这个慢查询执行期间,后边相应的SQL都没法拿到锁,都在50s后超时,
也因为等待,所以连接堆积,飙高,后边慢SQL 155s执行完毕,恢复正常。

评论
添加红包

请填写红包祝福语或标题

红包个数最小为10个

红包金额最低5元

当前余额3.43前往充值 >
需支付:10.00
成就一亿技术人!
领取后你会自动成为博主和红包主的粉丝 规则
hope_wisdom
发出的红包

打赏作者

渔不是鱼

你的鼓励将是我创作的最大动力

¥1 ¥2 ¥4 ¥6 ¥10 ¥20
扫码支付:¥1
获取中
扫码支付

您的余额不足,请更换扫码支付或充值

打赏作者

实付
使用余额支付
点击重新获取
扫码支付
钱包余额 0

抵扣说明:

1.余额是钱包充值的虚拟货币,按照1:1的比例进行支付金额的抵扣。
2.余额无法直接购买下载,可以购买VIP、付费专栏及课程。

余额充值