26年七月13号,也即是昨天,钉钉告警群突然开始疯狂刷屏。
订单同步响应时间持续上涨,退款同步开始延迟,业务同事也陆续反馈第三方订单迟迟没有同步到下游系统。一开始我以为只是第三方接口慢了,但排查后,发现真正的问题出在我们自己的线程池。
原来是我们这边的thirdparty微服务里,订单同步、退款单同步、订单状态同步这3个方法共用同一个线程池。当天订单状态同步的流量陡增,线程池队列(容量1000)很快被打满,工作线程全部处于忙碌状态。后续提交的退款单同步和订单同步任务开始触发拒绝策略。
共享线程池 = 共享故障域。
一个非核心业务(订单状态同步)的流量峰值,把核心业务(订单同步)全部拖垮。下游系统大面积数据延迟。
当时我没有任何办法,赶紧重启服务,虽然队列里的任务全部都丢失了,好在当前写这块代码的程序员,是有将请求先落地到数据库后,再去执行程序的。
因此我可以从数据库里找到这些记录,并根据日志系统里的请求参数进行比对,再次重新把数据补充推送。
紧急bug肯定是必须当天处理的,我立刻改程序上线,杜绝这样的事情再次发生。
用四层防线把这个问题彻底解决,如下图:
第一层防线:线程池隔离
改造前,3个方法共用1个线程池:
privatefinalThreadPoolUtilspool=newThreadPoolUtils(5,20,1000,"业务同步线程池");订单状态同步的流量把队列打满后,其他业务全部排队或被拒绝。改造是按业务维度拆成3个独立池:
privatefinalThreadPoolUtilsorderSyncPool=newThreadPoolUtils(5,20,1000,"订单同步线程池");privatefinalThreadPoolUtilsrefundOrderSyncPool=newThreadPoolUtils(3,10,1000,"退款单同步线程池");privatefinalThreadPoolUtilsorderStatusSyncPool=newThreadPoolUtils(5,15,1000,"订单状态同步线程池");效果:非核心业务的流量再大,也不会影响核心业务。故障被隔离在单个业务线内,不会扩散。
不过,这时候还有一个问题。如果某个池的队列也被打满了呢?任务会被拒绝策略处理。
第二层防线:CallerRunsPolicy + 结构化告警
原来的线程池配置了一个自定义的拒绝策略,但这个策略有个致命问题:它只打日志,不抛异常,也不执行任务。
// 原拒绝策略:只log,不执行任务publicvoidrejectedExecution(Runnabler,ThreadPoolExecutore){log.warn("线程池队列已满,任务被拒绝");// 没有 super.rejectedExecution(r, e);// 任务直接丢弃,调用方无感知}队列满时,任务被静默丢弃。调用方(HTTP接口或Dubbo RPC)已经返回了接收成功的响应,但实际上订单数据根本没有处理。数据丢了,没人知道。
比任务执行失败更麻烦的是,调用方根本不知道它失败了。
我把它换成了CallerRunsPolicy:队列满时,由提交任务的线程(HTTP线程或Dubbo线程)同步执行这个任务。任务不会被丢弃,数据不会丢失。
// 自定义CallerRunsPolicy:先打ERROR日志,再同步执行任务publicclassCustomCallerRunsPolicyextendsThreadPoolExecutor.CallerRunsPolicy{privatefinalAtomicIntegercallerRunsCount=newAtomicInteger(0);@OverridepublicvoidrejectedExecution(Runnabler,ThreadPoolExecutore){intcount=callerRunsCount.incrementAndGet();// 输出结构化告警日志StructuredLog.error(log).moduleCode("THREAD_POOL").moduleName(poolName).eventCode("POOL_FULL").eventName("线程池队列已满,由调用线程同步执行").put("activeThreads",e.getActiveCount()).put("queueSize",e.getQueue().size()).put("callerRunsCount",count).status("error").log();// 调用父类方法,由调用线程同步执行任务super.rejectedExecution(r,e);}}队列满时,这条ERROR级别的日志会立刻输出,包含线程池名称、当前活跃线程数、队列大小、累计触发次数。调用方线程被阻塞去执行任务,响应时间变长,但数据不丢。
代价是系统开始向调用方施加背压。调用线程需要自己执行任务,因此接口RT会变长。但这也是一种主动限流机制:系统处理不过来,就让上游慢下来,而不是继续接收请求导致数据丢失。
我们这个场景下,数据不丢比响应快更重要,因为第三方SaaS系统只会推送一次。而且线程池已经做了隔离,一个池的压力不会传导到其他池,影响范围可控。
CallerRunsPolicy保证了数据不丢,结构化日志记录了告警信息。
不过,这时候还有一个问题。如果没人盯着日志平台,告警信息就沉在海量日志里了。
第三层防线:钉钉独立告警群(分钟级)
我这边为thirdparty这个模块建了一个独立的钉钉告警群,专门用来接收线程池相关的告警。
链路是这样的:线程池队列满 → CustomCallerRunsPolicy输出ERROR级别结构化日志 → 日志平台采集 → 配置告警规则,匹配POOL_FULL事件 → 钉钉机器人推送告警群。
从事件发生到钉钉收到告警,不超过1分钟。
告警消息里包含关键信息:哪个线程池满了、当前活跃线程数、队列大小、累计触发次数。开发人员收到告警后可以立即判断:是需要扩容、限流、还是等流量自然回落。
这样开发至少第一时间能知道出了问题。由于钉钉是有公司和名字水印的,我不好直接贴出,画一张示意图:
到这里,其实正常情况下的问题已经处理得差不多了。不过还有一种情况没覆盖:服务器重启。
第四层防线:数据补偿工具
ArrayBlockingQueue是JVM内存队列,不持久化。如果服务器在队列有积压时重启,队列里所有未处理的任务全部丢失。
CallerRunsPolicy在这种情况下也帮不上忙。
上文提到过,每次请求到达Controller之前,拦截器会把完整的请求参数写入数据库,对应的表是third_docs_record:
// 拦截器预持久化:请求参数先落库,再进入业务逻辑if(flag){ThirdDocsRecordDTOrecord=ThirdDocsRecordDTO.builder().businessNo(extractBusinessNo(params)).servletPath(servletPath).param(requestBody)// 完整请求JSON.nonce(nonce).build();thirdDocsRecordService.save(record);returntrue;}这张表记录了每一次请求的完整参数。基于它,我们构建了一个数据补偿工具类:
// 数据补偿工具:按时间范围 + 单据号列表,重新推送未处理的单据publicvoidcompensate(DatestartTime,DateendTime,List<String>docsNoList){// 1. 查询该时间范围内、且单据号在列表中的third_docs_record记录List<ThirdDocsRecordPO>records=recordMapper.selectByTimeRangeAndDocsNos(startTime,endTime,docsNoList);// 2. 逐条检查下游系统是否已收到for(ThirdDocsRecordPOrecord:records){if(isAlreadySynced(record.getBusinessNo())){continue;// 已处理,跳过}// 3. 未处理的,重新调用同步方法replaySync(record.getParam());}}输入时间范围和单据号列表,工具会查询该时间段内指定单据号的记录,逐条检查下游系统是否已经收到。未收到的,重新调用同步方法推送。
幂等性由下游系统的查重逻辑保证:订单同步和退款单同步在入库前都会检查单据号是否已存在,重复推送不会造成数据重复。
即使服务器重启导致内存队列里的任务全部丢失,也可以通过补偿工具把数据重新推回去。
小结
后续你们也用线程池的时候,也多问问自己几个问题:
- 一个业务崩了,会不会拖垮其他业务?
- 队列满了,数据会不会丢?
- 出问题以后,我能不能第一时间知道?
- 就算真的丢了,能不能补回来?
这四个问题,也就是这次事故之后留下来的四层防线:
- 线程池隔离:非核心业务的流量峰值不会影响核心业务
- CallerRunsPolicy:队列满时任务不丢,由调用线程同步执行
- 钉钉分钟级告警:故障发生1分钟内,开发人员就会收到通知
- 数据补偿工具:极端情况下数据丢失,当天可以通过补偿工具恢复
改造后的运维体验:故障发生时立刻知道(钉钉告警),当天可以处理完毕(补偿工具兜底)。