以下文章来源于yes的练级攻略 ,作者是Yes呀
用接地气的话来分享一些后端技术或写一些想写的。
相信大家面试的时候都会被问到是否有过线上排查问题的经历。
今天我就给大家分享个热乎的,好吧也不热了,已经过了快两周了,哈哈哈,不过不影响。
我把这次问题的前因后果都说清楚,大家可以直接当做自己的经历拿去面试用,不用跟我客气。
开始咱们的表演。
那是一个阳光明媚的早晨,我却拖着疲惫的身躯来公司上班。
一到公司,屁股还没坐热,一个钉钉就发了过来:“线上连接池爆了!”
我一听麻了,啥都不用想,当机立断直接重启大法,稳如老狗。
好了,一切恢复正常。
全文完。
哈哈,开个玩笑,不过重启之后应用确实是恢复了正常,说明是某个突发的情况导致连接池爆了。
既然线上已经止损了,我们就可以安心的来排查排查这个问题。
连接池满无非就是...连接都被占用了,一般有两种情况会导致连接池满了:
这次事故产生的原因就是第二种情况!
DBA 当时发来一条 sql,说就是这条 sql 被频繁地执行。
我从 kibana 上面搜索了一下这条语句的执行情况,发现其实不止早上8点多有高峰,凌晨竟然有更高峰!然后再看看这个 sql 执行的频率,这时间排的整整齐齐的,一丝都不带变的。
并且这条 sql 也不复杂,就是一个带主键的单表查询,表也不会很大。
所以我断定这次突发的情况就是:高并发下频繁地请求数据库导致的
那现在问题来了,为啥在某个时候会频繁的请求这条 sql ?是人性的扭曲还是道德的沦丧?
我直接定位了这条 sql 的请求代码,发现这个查询其实是先走缓存,缓存找不到才会去查数据库。
我仔细看了看代码,确定了这个业务逻辑是用来给前端展示任务进度的。
就是后台会跑一个任务,前端需要实时展示一个进度条,这样用户使用的时候才不会干着急。
我和前端同事确认了一下,按理前端应该 2s 才会请求一次进度,所以即使是直接查询数据库,也不至于一个用户如此高频地调用请求。
所以我先甩了个锅,你前端代码有问题,并没有遵循 2s 去查,快去看看代码!
然后我继续查询为啥这个缓存会消失的问题。
按理来说,具体逻辑是这样的:
按照这个逻辑,缓存不可能在查询的时候不存在的啊!
然后我就开始疑神疑鬼了,难道是 redis 抽了把这个 key 删了?不至于啊看了看缓存负载也不高。
难道是调用的 redis client 接口有 bug?过期时间没给我整对?
然后我模拟了一下,执行了一次任务,查询了一下缓存里的进度,我直接好家伙!
可以看到过期时间竟然只有 5 分钟?我明明设置的是一天啊!
我兴致勃勃地深入了调用的 redis client 源码,想着好家伙,来素材了难道!
看了半天,我反应了过来,觉得不可能有问题,要有问题不应该只有这个功能会出现这个情况,别的早都爆了。
所以我又把目光移向了更新进度的那个后台任务!是不是这个 b 把缓存的过期时间改了?
由于这个任务不是我写的,于是我就去找了负责这个任务的同事,果不其然!
他执行任务更新进度的时候,过期时间设置的值都为 5 分钟 !
伪代码如下:
while(任务没结束) {
执行逻辑
更新缓存中的任务进度++,设置过期时间为5分钟
}
他这样的设置过期时间也没毛病,因为当任务结束了也就是进度到 100% 了之后,不会再有获取任务进度的行为,所以 5 分钟就让它过期可以的。
而我之所以设置 1 天,是想着如果发生点啥问题可以保留一下案发现场的数据看看。
那按照这个逻辑看下来,应该是没问题的,为啥会发生这个情况?
我猜想了一下,心里有了个 B 树。
我问他这个任务是不是有可能会有阻塞的情况,导致超过 5 分钟才会更新缓存,这样在这个阻塞时间内,前 5 分钟更新的缓存就过期了,缓存里就没这个键了,此时的查询就会直接命中数据库,也就重现了上面的那个情况了!
再来看下伪代码:
while(任务没结束) {
//有时候执行的时长超过了5分钟,缓存已过期
执行逻辑
更新缓存中的任务进度++,设置过期时间为5分钟
}
他回答到有可能,因为这个任务会频繁调用第三方的接口,并且会包含一些很复杂的合并逻辑,所以有可能超过5分钟才会继续更新缓存。
好了,终于破案了!这也解释了为什么这个状况是偶发的,因为第三方接口是不是会不稳定,就可能阻塞超过了五分钟。
解决办法也很简单:让前端排查下代码的问题然后修复下,并且也将缓存过期的时间延长至10分钟,一阶段任务的执行时间几乎不可能超过 10 分钟。
好了,讲完了,这次的问题不难排查,根据对应的现象定位到相应的代码,然后再进行前后端业务场景的分析即可。
其实所有的排查都是如此,先止损(看情况不妙就得先重启),定位代码,分析情况。
有些难排查的得打 log,有些难重现的还得持续观察好几天。
虽说出了问题总是不好的,但是大家要把握还这样的机会,及时记录,这都是以后的谈资。