1. 问题现象
有一天下午运营反馈管理台评论外放接口操作老是超时,处理不成功。
2. 问题定位分析过程
2.1 收集信息
出现问题后首先查看PINPOINT监控,发现那天下午有很多管理台接口超时,超时接口大部分都是如下
update comment set xxx=?
然后在ELK上搜索相关容器日志,发现有很多数据库报错日志,报错信息如下
RecoverableDataAccessException ### Error update database ...
从上面两个地方可以看出可能是数据库存在问题,查看数据库可能存在问题。
查看对应数据库监控,发现流量和IO基本正常,数据库连接数也正常。
接着查看是否是存在大的事务或者锁表
// 检索InnoDB存储引擎中当前活动事务的信息,并按照它们的开始时间进行排序。
SELECT
trX_id,
trx_state,
trx_started,
trx_weight,
trx_mysql_thread_id,
trx_query,
trx_operation_state
FROM
information_schema.innodb_trX
ORDER BY
trX_started DESC;
// 发现两个活跃事务,一个trx_started是下午 16:19 没有对应的sql trx_mysql_thread_id为1
// 另外一个trx_started是 17:56 对应的sql update comment_a xxx trx_mysql_thread_id为2
//继续使用sql查询InnoDB存储引擎中的锁等待情况,以便了解哪些事务正在被阻塞以及它们正在等待的资源
SELECT r.trx_id AS waiting_trx_id, r.trx_mysql_thread_id AS waiting_thread, LEFT(r.trx_query, 30) AS waiting_query,
b.trx_id AS blocking_trx_id, b.trx_mysql_thread_id AS blocking_thread, LEFT(b.trx_query, 30) AS blocking_query
FROM information_schema.innodb_lock_waits AS W
INNER JOIN information_schema.innodb_trx AS b ON b.trx_id = W.blocking_trx_id
INNER JOIN information_schema.innodb_trx AS r ON r.trx_id = W.requesting_trx_id
ORDER BY blocking_thread DESC;
//发现其中为waiting_thread 为2 blocking_thread为1的记录,说明2在等待1完成
// 查看innodb_lock_wait_timeout参数配置时间,待确认
发现有超常事务,事务从下午4点多已经开始,一直没有释放,运营保障时已经接近6点。
2.2 紧急规避问题
有长事务未释放不太正常,联系运维将此事务KILL调,管理台操作正常
KILL 1
2.3 继续分析问题
KILL调进程时间段搜寻ELK日志,发现有数据库连接相关的报错,根据连接堆栈找到具体报错代码。
结合代码分析大概原因如下:
主要原因有两个:
非常大的事务
,并且在加@Transactional
没有指定timeout
- 默认情况下,
@Transactional
注解的timeout
属性值为-1,表示不设置超时时间,事务将无限期等待直到执行完成或发生其他原因导致的回滚。 - 每个视频外放操作比较复杂,需要调用风控判断视频是否能外放获取检测结果,成功后需要更新一系列缓存值,耗时较长
- 类似死锁可参考这个实例:案例1:根据字段值查询(有索引),如果不存在,则插入;否则更新 只要将insert改为update
- 死锁条件可参考这个文章:并发-基础概念
3.问题解决
此处主要讲述问题解决措施:
- 临时解决方案:kill 定时任务事务,避免再次出现大事务,与运营沟通暂停视频外放定时任务,改为人工执行
- 长期解决方案:
- 破坏死锁产生条件,更新评论数据时,按照一致的顺序更新表
- 将视频外放大的事务拆小,每个视频外放一个事务,同时
@Transactional
增加超时时间 - 单个
@Transactional
拆小,保留其中数据库更新操作,其他如查询视频审核放在事务之外
4.举一反三
团队内加大对事务使用和死锁的认知,输出案例集和加入到编程规范中。