前几日下午,突然收到很多超时的反馈,查了下开发者反馈的一些请求,基本都是在毫秒级处理完成的,但是开发者反馈是超时很严重的,于是首先怀疑网络问题,但是反馈的开发者上面ping到服务器的延迟都非常小,稳定且没有丢包。

所以怀疑本身服务出现问题了,登上nginx上面 反馈的某段时间都是转发的请求的耗时都非常高,耗时30s以上的非常多,tail -f了下日志,发现日志滚的很慢,但是看了几条请求处理也是非常快的。苦思无果后,紧急把http 服务的进程扩了一倍,超时现象好转了些许,不过依然不能解决问题,过了两个小时后,超时现象更严重了,net -an|grep 8080后 发现服务上的连接越来越多 一分钟左右居然暴涨到一个进程1w,但是结合之前tail的日志,本身处理请求很快的说,于是怀疑起jettty aceptor是否出问题了,于是摘掉生产的一个超时严重的节点,用ab压测了下,处理正常的不行,没有丝毫延迟的现象。无奈只能翻着日志,看有没有新的思路。

当翻到请求黑名单列表的时候,发现黑名单的请求都非常慢,黑名单列表这个功能是通过ice 调用dbagent(封装mysql调用的rpc服务)的,于是把黑名单的日志都过滤出来,发现反馈超时的时候黑名单都非常慢,最长的时候居然超过60s了,问题就出在这里了,黑名单慢到都把线程给堵住了,于是紧急把这个功能的请求下掉 返回个空的黑名单列表。 超时暂时得以解决。

关于事故的思考和处理

1.ice client的请求默认是不超时的,使用堵塞调用的话,一旦超时,势必波及到其他业务的,所以把现有服务的堵塞查询都改成异步查。

2.告警覆盖不全,dbagent的调用超时这部分都没加上相关的告警,一旦出问题也不能立马感知和排查,所以加了相关的超时告警覆盖

3.关于告警的问题,之前只是小部分的在couchbase上加了告警,还有一些服务未知异常的告警,但是经过这次坎坷的定位之后,决定在对单个http请求的超时和调用其他服务的时候都加上相关的告警,比如说发送mq 消费 mq 查redis这些,一旦出现异常都把相关的信息发送出来,及时感知和定位。虽然是个繁杂的体力活,但是效果感人。