入职多年,面对生产环境,尽管都是小心翼翼,慎之又慎,还是难免捅出篓子。轻则满头大汗,面红耳赤。重则系统停摆,损失资金。每一个生产事故的背后,都是宝贵的经验和教训,都是项目成员的血泪史。为了更好地防范和遏制今后的各类事故,特开此专题,长期更新和记录大大小小的各类事故。有些是亲身经历,有些是经人耳传口授,但无一例外都是真实案例。
注意:为了避免不必要的麻烦和商密问题,文中提到的特定名称都将是化名、代称。
0x00 大纲
- 0x00 大纲
- 0x01 事故背景
- 0x02 事故分析
- 0x03 事故原因
- 0x04 事故复盘
- 0x05 事故影响
0x01 事故背景
2025年7月9日17时有余,笔者正准备结束疲惫的一天,关机走人之时,桌面右下角安静了一天的内部通讯软件图标突然亮起,内心顿感不妙……打开一看,原来是运维小哥找过来了,说是某接口服务连续多次调用超时或失败,触发告警阈值,具体原因不明,请求支援。(临下班出事似乎已成为一种规律)
0x02 事故分析
该服务是一个基于 SpringBoot + JDK 1.8 的 API 服务,提供了几个信息查询接口,没有复杂的业务逻辑,也不涉及第三方接口调用,仅依赖于数据库进行简单的 CURD 操作。
第一时间让运维拷贝和固定了事故系统日志及生产版本应用包。发现该服务在一周前升级部署过,不排除是版本升级引起的问题。于是先留一手,招呼运维小哥做好随时进行版本回退的准备,以免不能及时修复问题。
运维小哥已经排除了是网络和线路的问题,也尝试按照常见故障应对手册重启过应用,服务短暂恢复正常,但是随着请求压力上来以后,又会频繁失败触发告警。为了避免事故进一步扩大,运维小哥选择迅速摇人。
秉着先易后难的顺序,先快速扫描了一遍应用日志,常规日志未见明显ERROR、WARN以及Exception等信息,SQL日志未见慢查询和连接池异常。随后检查数据库压力,发现数据库活跃连接数不高,也未见死锁和异常会话。
jps找到服务进程对应的PID,使用top命令查看进程的资源占用情况,发现服务的 CPU 和内存资源占用不高。ss -antp|grep :9999| wc -l查看对应端口的连接情况,大约两百多个活跃连接,属于正常范围内。磁盘监控未见明显压力,看来基本可以确定是应用本身的问题。
于是使用jstack -l保存了第一次线程快照,然后让运维小哥重启接口服务,果然如小哥所说,接口调用短暂正常以后很快又出现异常。为了排除偶然因素干扰,这时做了第二次线程快照用于对照分析,同时使用jmap抓取了 dump 文件备用。完成以上步骤以后,果断让运维小哥将服务回退到历史版本,应急解决故障。
仔细分析两次抓取的线程快照,发现大量的线程处于BLOCKED状态,且拥有高度相似的调用栈:
"thread-3197" Id=4959 BLOCKED on java.util.concurrent.ConcurrentHashMap$ReservationNode@1b1f101f owned by "TaskExecutor-827" Id=936at java.util.concurrent.ConcurrentHashMap.compute(ConcurrentHashMap.java:1868)- blocked on java.util.concurrent.ConcurrentHashMap$ReservationNode@1b1f101fat com.github.benmanes.caffeine.cache.BoundedLocalCache.doComputeIfAbsent(BoundedLocalCache.java:2404)at com.github.benmanes.caffeine.cache.BoundedLocalCache.computeIfAbsent(BoundedLocalCache.java:2387)at com.github.benmanes.caffeine.cache.LocalCache.computeIfAbsent(LocalCache.java:108)at com.github.benmanes.caffeine.cache.LocalLoadingCache.get(LocalLoadingCache.java:56)(这里省略部分信息)
看起来是高并发的时候 Caffeine 缓存的处理出现了竞态争抢,问题初步定位,需要进一步分析事故原因。
0x03 事故原因
简单 review 了一下变更的代码,发现同事A为某个关键系统参数的查询添加了秒级的短时缓存,减少高并发下的数据库查询调用,并且使用有界的LoadingCache来加载和刷新相关数据,关键的Bean定义如下:
@Bean
@ConditionalOnBean(ParameterRepository.class)
public LoadingCache<String, ParameterEntity> parameterCache(ParameterRepository parameterRepository,Executor refreshExecutor) {return Caffeine.newBuilder().maximumSize(256).refreshAfterWrite(Duration.ofSeconds(3)).expireAfterAccess(Duration.ofSeconds(7)).executor(refreshExecutor).build(bssSysparmRepository::getById);
}
乍看之下似乎很合理。但是为何会出问题呢?在高并发场景下,多个线程同时请求缓存中不存在的数据,导致多个线程都需要去加载数据,而LoadingCache的刷新策略是按需刷新,即只有当缓存中的数据过期时才会触发刷新。如果多个线程同时触发刷新,就会导致多个线程同时去加载数据,并使用相同的Key值调用ConcurrentHashMap.compute方法加载和刷新数据,从而导致竞态争抢。这种机理导致LoadingCache或者说ConcurrentHashMap(在JDK1.8里面)并不适合用在需要高并发频繁刷新的缓存场景。
有意思的是,这个锅其实跟JDK中ConcurrentHashMap的实现机制有关,存在同样问题的还有computeIfPresent方法,具体可见。
解决的方法不难,就是使用AsyncLoadingCache来代替LoadingCache,异步加载数据,避免竞态争抢。修改下代码:
@Bean
@ConditionalOnBean(ParameterRepository.class)
public AsyncLoadingCache<String, ParameterEntity> parameterCache(ParameterRepository parameterRepository,Executor refreshExecutor) {return Caffeine.newBuilder().maximumSize(256).refreshAfterWrite(Duration.ofSeconds(3)).expireAfterAccess(Duration.ofSeconds(7)).executor(refreshExecutor).buildAsync(parameterRepository::getById);
}
取用时,从LoadingCache.get()方法改为AsyncLoadingCache.synchronous().get()方法即可。优化版本上线后,各方人员情绪稳定。
0x04 事故复盘
比起追究责任,更重要的是带给我们的启发:
- 没有基准的性能优化都是耍流氓;
- 上线前需要先进行性能回归,确认优化后的性能是否符合预期。
0x05 事故影响
生产系统紧急回滚一次,所幸的是没有收到客诉(那就是没有问题)。A公司相关负责人连夜编写事故报告一份,并通知其他项目组未雨绸缪。