线上问题——2021-12-27 父子线程共用线程池导致死锁故障

一、事故现象

从早上6点开始edu-wings-admin的timer-task和mq就开始报警任务堆积，且数量持续上升，到6点50左右mq也开始告警，8点左右发现问题，开始排查，直到11点才找到问题，任务开始正常消费。

二、事故影响范围

从27号0点4分到早上11点4分班级专栏、表彰发放以及监听mq的班级、完课事件都被堵住，11点04分修改配置重启后任务才陆续执行完毕。

三、事故原因分析

我们的任务是每秒扫描执行的，正常情况下，高峰期即使堆积也会立马被消费，除非有大任务卡住情况（一般卡住的都是timer-task，而这次mq-task也同步出现问题，不过当时没有意识到这个问题），所以根据以往经验，查数据库发现0点的任务就没有执行了，而这批任务都是给用户发表彰，但是从日志上没有找到问题，数据库也没有慢sql，后面从应用行为大盘上只能看到xxl-job从0点开始就没有执行了，也就是从0点开始任务就堵住了，由于任务堆积超过2000条才会告警，所以直到6点群里才开始报警。

数据库、pod CPU都很正常，但业务线程却卡住，于是开始怀疑业务上是不是产生了死锁，下载线程堆栈进行分析。



从上图我们可以发现线程最终都是卡在了ParallelUtils.invokeAll方法上（看到这个其实应该立马反应过来线程池中线程被卡住了，导致线程资源耗尽，但实际上我们还走了不少弯路），这个类是我们执行并行任务的一个工具类，里面维护了一个单例的线程池。

核心线程数只有8个，最大线程数虽然设置了200，但队列长度设置为50000，而我们并行任务是达不到50000的，所以一直都只会有8个线程在跑，但是为什么线程会卡住呢？
从上面堆栈日志图中可以看到UserRpcClient.listUserBabyInfo这个方法，在发用户表彰时就需要调用这个方法查询宝贝昵称，而这个方法之前是串行调用的，由于单次传入参数太多，所以使用IterateUtil.spiltIterateParallel并行分批调用，问题就在这里，spiltIterateParallel内部也是调用工具类方法ParallelUtils.invokeAll，这就相当于是在父任务中开辟了子任务，父子任务用的又是同一个线程池，同一时间只要有8个父任务在执行，那子任务去获取线程就会卡住，而父任务又要等子任务返回，导致死锁。

四、解决方案

1. 临时解决方案：修改timer-task占用线程数为1，默认配置为8，重启。这样在同一个pod上同一时间只会有一个父任务在跑，也就只会占用一个线程，剩余7个留给子任务
2. 最终解决方案：修改公用组件，隔离timer-task、mq-task和业务线程的线程池，避免相互影响。目前wings-admin已升级并上线，其余服务后续逐步升级发布。

五、反思

1. 这次问题其实在0点就发生了，但经过了6小时才告警，这是由于异步任务告警阈值目前仅根据数量（固定2000）触发，需要加入任务执行时间等因素。
2. 使用线程池时需要考虑使用场景，核心线程数、最大线程数、阻塞队列长度、拒绝策略的配置以及是否需要隔离线程。，此次事故中最大线程数完全没起作用就是因为阻塞队列长度过长导致。后续考虑实现动态可监测线程池，做到线程池统一管理、可动态配置，出现问题及时告警等