一个线程池拒绝策略引发的问题
extends:严选库存稳定性治理系列：一个线程池拒绝策略引发的血案 (qq.com), 虽然是我遇到的一个棘手的生产问题，但是我写出来之后，就是你的了。 - why技术 - 博客园 (cnblogs.com)
你好呀，是歪歪。
前几天，就在大家还沉浸在等待春节到来的喜悦氛围的时候，在一个核心链路上的核心系统中，我踩到一个坑的一比的坑，要不是我沉着冷静，解决思路忙中有序，处理手段雷厉风行，把它给扼杀在萌芽阶段了，那这玩意肯定得引发一个比较严重的生产问题。
从问题出现到定位到这个问题的根本原因，我大概是花了两天半的时间。
所以写篇文章给大家复盘一下啊，这个案例就是一个纯技术的问题导致的，和业务的相关度其实并不大，所以你拿过去直接添油加醋，稍微改改，往自己的服务上套一下，那就是你的了。
我再说一次：虽然现在不是你的，但是你看完之后就是你的了，你明白我意思吧？
表象
事情是这样的，我这边有一个服务，你可以把这个服务粗暴的理解为是一个商城一样的服务。有商城肯定就有下单嘛。
然后接到上游服务反馈，说调用下单接口偶尔有调用超时的情况出现，断断续续的出现好几次了，给了几笔流水号，让我看一下啥情况。当时我的第一反应是不可能是我这边服务的问题，因为这个服务上次上线都至少是一个多月前的事情了，所以不可能是由于近期服务投产导致的。
但是下单接口，你听名字就知道了，核心链接上的核心功能，不能有一点麻痹大意。
每一个请求都很重要，客户下单体验不好，可能就不买了，造成交易损失。
交易上不去营业额就上不去，营业额上不去利润就上不去，利润上不去年终就上不去。
想到这一层关系之后，我立马就登陆到服务器上，开始定位问题。
一看日志，确实是我这边接口请求处理慢了，导致的调用方超时。
为什么会慢呢？
于是按照常规思路先根据日志判断了一下下单接口中调用其他服务的接口相应是否正常，从数据库获取数据的时间是否正常。
这些判断没问题之后，我转而把目光放到了 gc 上，通过监控发现那个时间点触发了一次耗时接近 1s 的 full gc，导致响应慢了。
由于我们监控只采集服务近一周的 gc 数据，所以我把时间拉长后发现 full gc 在这一周的时间内出现的频率还有点高，虽然我还没定位到问题的根本原因，但是我定位到了问题的表面原因，就是触发了 full gc。
因为是核心链路，核心流程，所以此时不应该急着去定位根本原因，而是先缓解问题。
好在我们提前准备了各种原因的应急预案，其中就包含这个场景。预案的内容就是扩大应用堆内存，延缓 full gc 的出现。
所以我当即进行操作报备并联系运维，按照紧急预案执行，把服务的堆内存由 8G 扩大一倍，提升到 16G。
虽然这个方法简单粗暴，但是既解决了当前的调用超时的问题，也给了我足够的排查问题的时间。
定位原因
当时我其实一点都不慌的，因为问题在萌芽阶段的时候我就把它给干掉了。
不就是 full gc 吗，哦，我的老朋友。
先大胆假设一波：程序里面某个逻辑不小心搞出了大对象，触发了 full gc。
所以我先是双手插兜，带着监控图和日志请求，闲庭信步的走进项目代码里面，想要凭借肉眼找出一点蛛丝马迹......
没有任何收获，因为下单服务涉及到的逻辑真的是太多了，服务里面 List 和 Map 随处可见，我很难找到到底哪里是大对象。
但是我还是一点都不慌，因为这半天都没有再次发生 Full GC，说明此时留给我的时间还是比较充足的，
所以我请求了场外援助，让 DBA 帮我导出一下服务的慢查询 SQL，因为我想可能是从数据库里面一次性取的数据太多了，而程序里面也没有做控制导致的。
我之前就踩过类似的坑。
一个根据客户号查询客户有多少订单的内部使用接口，接口的返回是 List<订单>，看起来没啥毛病，对不对？
一般来说一个个人客户就几十上百，多一点的上千，顶天了的上万个订单，一次性拿出来也不是不可以。
但是有一个客户不知道咋回事，特别钟爱我们的平台，也是我们平台的老客户了，一个人居然有接近 10w 的订单。
然后这么多订单对象搞到到项目里面，本来响应就有点慢，上游再发起几次重试，直接触发 Full gc，降低了服务响应时间。
所以，经过这个事件，我们定了一个规矩：用 List、Map 来作为返回对象的时候，必须要考虑一下极端情况下会返回多少数据回去。即使是内部使用，也最好是进行分页查询。
好了，话说回来，我拿到慢查询 SQL 之后，根据几个 Full gc 时间点，对比之后提取出了几条看起来有点问题的 SQL。
然后拿到数据库执行了一下，发现返回的数据量其实也都不大。
此刻我还是一点都不慌，反正内存够用，而且针对这类问题，我还有一个场外援助没有使用呢。
第二天我开始找运维同事帮我每隔 8 小时 Dump 一次内存文件，然后第三天我开始拿着内存文件慢慢分析。
但是第二天我也没闲着，根据现有的线索反复分析、推理可能的原因。
然后在观看 GC 回收内存大小监控的时候，发现了一点点端倪。因为触发 Full GC 之后，发现被回收的堆内存也不是特别多。
当时就想到了除了大对象之外，还有一个现象有可能会导致这个现象：内存泄露。
巧的是在第二天又发生了一次 Full gc，这样我拿到的 Dump 文件就更有分析的价值了。基于前面的猜想，我分析的时候直接就冲着内存泄漏的方向去查了。
我拿着 5 个 Dump 文件，分析了在 5 个 Dump 文件中对象数量一直在增加的对象，这样的对象也不少，但是最终定位到了 FutureTask 对象，就是它：
找到这玩意了再回去定位对应部分的代码就比较容易。
但是你以为定位了代码就完事了吗？
不是的，到这里才刚刚开始，朋友。
因为我发现这个代码对应的 Bug 隐藏的还是比较深的，而且也不是我最开始假象的内存泄露，就是一个纯粹的内存溢出。
所以值得拿出来仔细嗦一嗦。
示例代码
为了让你沉浸式体验找 BUG 的过程，我高低得给你整一个可复现的 Demo 出来，你拿过去就可以跑的那种。
首先，我们得搞一个线程池：
需要说明一下的是，上面这个线程池的核心线程数、最大线程数和队列长度我都取的 1，只是为了方便演示问题，在实际项目中是一个比较合理的值。
然后重点看一下线程池里面有一个自定义的叫做 MyThreadFactory 的线程工厂类和一个自定义的叫做 MyRejectedPolicy 的拒绝策略。
在我的服务里面就是有这样一个叫做 product 的线程池，用的也是这个自定义拒绝策略。
其中 MyThreadFactory 的代码是这样的：
它和默认的线程工厂之间唯一的区别就是我加了一个 threadFactoryName 字段，方便给线程池里面的线程取一个合适的名字。
更直观的表示一下区别就是下面这个玩意：
原生：pool-1-thread-1
自定义：product-pool-1-thread-1
接下来看自定义的拒绝策略：
这里的逻辑很简单，就是当 product 线程池满了，触发了拒绝策略的时候打印一行日志，方便后续定位。
然后接着看其他部分的代码：
标号为 ① 的地方是线程池里面运行的任务，我这里只是一个示意，所以逻辑非常简单，就是把 i 扩大 10 倍。实际项目中运行的任务业务逻辑，会复杂一点，但是也是有一个 Future 返回。
标号为 ② 的地方就是把返回的 Future 放到 list 集合中，在标号为 ③ 的地方循环处理这个 list 对象里面的 Future。
需要注意的是因为实例中的线程池最多容纳两个任务，但是这里却有五个任务。我这样写的目的就是为了方便触发拒绝策略。
然后在实际的项目里面刚刚提到的这一坨逻辑是通过定时任务触发的，所以我这里用一个死循环加手动开启线程来示意：
整个完整的代码就是这样的，你直接粘过去就可以跑，这个案例就可以完全复现我在生产上遇到的问题：
public class MainTest {
public static void main(String[] args) throws Exception {
ThreadPoolExecutor productThreadPoolExecutor = new ThreadPoolExecutor(1,
1,
1,
TimeUnit.SECONDS,
new LinkedBlockingQueue<>(1),
new MyThreadFactory("product"),
new MyRejectedPolicy());
while (true){
TimeUnit.SECONDS.sleep(1);
new Thread(()->{
ArrayList<Future<Integer>> futureList = new ArrayList<>();
//从数据库获取产品信息
int productNum = 5;
for (int i = 0; i < productNum; i++) {
try {
int finalI = i;
Future<Integer> future = productThreadPoolExecutor.submit(() -> {
System.out.println("Thread.currentThread().getName() = " + Thread.currentThread().getName());
return finalI * 10;
});
futureList.add(future);
} catch (Exception e) {
e.printStackTrace();
}
}
for (Future<Integer> integerFuture : futureList) {
try {
Integer integer = integerFuture.get();
System.out.println(integer);
System.out.println("future.get() = " + integer);
} catch (Exception e) {
e.printStackTrace();
}
}
}).start();
}
}
static class MyThreadFactory implements ThreadFactory {
private static final AtomicInteger poolNumber = new AtomicInteger(1);
private final ThreadGroup group;
private final AtomicInteger threadNumber = new AtomicInteger(1);
private final String namePrefix;
private final String threadFactoryName;
public String getThreadFactoryName() {
return threadFactoryName;
}
MyThreadFactory(String threadStartName) {
SecurityManager s = System.getSecurityManager();
group = (s != null) ? s.getThreadGroup() :
Thread.currentThread().getThreadGroup();
namePrefix = threadStartName + "-pool-" +
poolNumber.getAndIncrement() +
"-thread-";
threadFactoryName = threadStartName;
}
public Thread newThread(Runnable r) {
Thread t = new Thread(group, r,
namePrefix + threadNumber.getAndIncrement(),
0);
if (t.isDaemon())
t.setDaemon(false);
if (t.getPriority() != Thread.NORM_PRIORITY)
t.setPriority(Thread.NORM_PRIORITY);
return t;
}
}
public static class MyRejectedPolicy implements RejectedExecutionHandler {
@Override
public void rejectedExecution(Runnable r, ThreadPoolExecutor e) {
if (e.getThreadFactory() instanceof MyThreadFactory) {
MyThreadFactory myThreadFactory = (MyThreadFactory) e.getThreadFactory();
if ("product".equals(myThreadFactory.getThreadFactoryName())) {
System.out.println(THREAD_FACTORY_NAME_PRODUCT + "线程池有任务被拒绝了,请关注");
}
}
}
}
}
你跑的时候可以把堆内存设置的小一点，比如我设置为 10m：
-Xmx10m -Xms10m
然后用 jconsole 监控，你会发现内存走势图是这样的：
哦，我的老天爷啊，这个该死的图，也是我的老伙计了，一个缓慢的持续上升的内存趋势图， 最后疯狂的触发 gc，但是并没有内存被回收，最后程序直接崩掉：
这绝大概率就是内存泄漏了啊。
但是在生产上的内存走势图完全看不出来这个趋势，我前面说了，主要因为 GC 情况的数据只会保留一周时间，所以就算把整个图放出来也不是那么直观。
其次不是因为我牛逼嘛，萌芽阶段就干掉了这个问题，所以没有遇到最后频繁触发 gc，但是没啥回收的，导致 OOM 的情况。
所以我再带着你看看另外一个视角，这是我真正定位到问题的视角。就是分析内存 Dump 文件。
分析内存 Dump 文件的工具以及相关的文章非常的多，我就不赘述了，你随便找个工具玩一玩就行。我这里主要是分享一个思路，所以就直接使用 idea 里面的 Profiler 插件了，方便。
我用上面的代码，启动起来之后在四个时间点分别 Dump 之后，观察内存文件。内存泄露的思路就是找文件里面哪个对象的个数和占用空间是在持续上升嘛，特别是中间还发生过 full gc，这个过程其实是一个比较枯燥且复杂的过程，在生产项目中可能会分析出很多个这样的对象，然后都要到代码里面去定位相关逻辑。
但是我这里极大的简化了程序，所以很容易就会发现这个 FutureTask 对象特别的抢眼，数量在持续增加，而且还是名列前茅的：
然后这个工具还可以看对象占用大小，大概是这个意思：
所以我还可以看看在这几个文件中 FutureTask 对象大小的变化，也是持续增加：
就它了，准没错。
好，问题已经能复现了，GC 图和内存 Dump 的图也都给你看了。
到这里，如果有人已经看出来问题的原因了，可以直接拉到文末点个赞，感谢大佬阅读我的文章。
如果你还没看出端倪来，那么我先给你说问题的根本原因：
问题的根本原因就出在 MyRejectedPolicy 这个自定义拒绝策略上。
在带你细嗦这个问题之前，我先问一个问题：
JDK 自带的线程池拒绝策略有哪些？
这玩意，老八股文了，存在的时间比我从业的时间都长，得张口就来：
- AbortPolicy：丢弃任务并抛出 RejectedExecutionException 异常，这是默认的策略。
- DiscardOldestPolicy：丢弃队列最前面的任务，执行后面的任务
- CallerRunsPolicy：由调用线程处理该任务
- DiscardPolicy：也是丢弃任务，但是不抛出异常，相当于静默处理。
然后你再回头看看我的自定义拒绝策略，是不是和 DiscardPolicy 非常像，也没有抛出异常。只是比它更高级一点，打印了一点日志。
当我们使用默认的策略的时候：
或者我们把框起来这行代码粘到我们的 MyRejectedPolicy 策略里面：
再次运行，不管是观察 gc 情况，还是 Dump 内存，你会发现程序正常了，没毛病了。
下面这个走势图就是在拒绝策略中是否抛出异常对应的内存走势对比图：
在拒绝策略中抛出异常就没毛病了，为啥？
探索
首先，我们来看一下没有抛出异常的时候，发生了什么事情。
没有抛出异常时，我们前面分析了，出现了非常多的 FutureTask 对象，所以我们就找程序里面这个对象是哪里出来的，定位到这个地方：
future 没有被回收，说明 futureList 对象没有被回收，而这两个对象对应的 GC Root 都是new 出来的这个线程，因为一个活跃线程是 GC Root。
进一步说明对应 new 出来的线程没有被回收。
所以我给你看一下前面两个案例对应的线程数对比图：
没有在拒绝策略中抛出异常的线程非常的多，看起来每一个都没有被回收，这个地方肯定就是有问题的。
然后随机选一个查看详情，可以看到线程在第 39 行卡着的：
也就是这样一行代码：
这个方法大家应该熟悉，因为也没有给等待时间嘛，所以如果等不到 Future 的结果，线程就会在这里死等。
也就导致线程不会运行结束，所以不会被回收。
对应着源码说就是有 Future 的 state 字段，即状态不正确，导致线程阻塞在这个 if 里面：
if 里面的 awaitDone 逻辑稍微有一点点复杂，这个地方其实还有一个 BUG，在 JDK 9 进行了修复，这一点我在之前的文章中写过，所以就不赘述了，你有兴趣可以去看看：《Doug Lea在J.U.C包里面写的BUG又被网友发现了。》
总之，在我们的案例下，最终会走到我框起来的代码：
也就是当前线程会在这里阻塞住，等到唤醒。
那么问题就来了，谁来唤醒它呢？
巧了，这个问题我之前也写过，在这篇文章中，有这样一句话：《关于多线程中抛异常的这个面试题我再说最后一次！》
如果子线程捕获了异常，该异常不会被封装到 Future 里面。是通过 FutureTask 的 run 方法里面的 setException 和 set 方法实现的。在这两个方法里面完成了 FutureTask 里面的 outcome 变量的设置，同时完成了从 NEW 到 NORMAL 或者 EXCEPTIONAL 状态的流转。
带你看一眼 FutureTask 的 run 方法：
也就是说 FutureTask 状态变化的逻辑是被封装到它的 run 方法里面的。
知道了它在哪里等待，在哪里唤醒，揭晓答案之前，还得带你去看一下它在哪里诞生。
它的出生地，就是线程池的 submit 方法：
java.util.concurrent.AbstractExecutorService#submit
但是，朋友，注意，我要说但是了。
首先，我们看一下当线程池的 execute 方法，当线程池满了之后，再次提交任务会触发 reject 方法，而当前的任务并不会被放到队列里面去：
也就是说当 submit 方法不抛出异常就会把正常返回的这个状态为 NEW 的 future 放到 futureList 里面去，即下面编号为 ① 的地方。然后被标号为 ② 的循环方法处理：
那么问题就来了：被拒绝了的任务，还会被线程池触发 run 方法吗？
肯定是不会的，都被拒绝了，还触发个毛线啊。
不会被触发 run 方法，那么这个 future 的状态就不会从 NEW 变化到 EXCEPTION 或者 NORMAL。
所以调用 Future.get() 方法就一定一直阻塞。又因为是定时任务触发的逻辑，所以导致 Future 对象越来越多，形成一种内存泄露。
submit 方法如果抛出异常则会被标号为 ② 的地方捕获到异常。
不会执行标号为 ① 的地方，也就不会导致内存泄露：
道理就是这么一个道理。
解决方案
知道问题的根本原因了，解决方案也很简单。
定位到这个问题之后，我发现项目中的线程池参数配置的并不合理，每次定时任务触发之后，因为数据库里面的数据较多，所以都会触发拒绝策略。
所以首先是调整了线程池的参数，让它更加的合理。当时如果你要用这个案例，这个地方你也可以包装一下，动态线程池，高大上，对吧，以前讲过。
然后是调用 Future.get() 方法的时候，给一个超时时间，这样至少能帮我们兜个底。资源能及时释放，比死等好。
最后就是一个教训：自定义线程池拒绝策略的时候，一定一定记得要考虑到这个场景。
比如我前面抛出异常的自定义拒绝策略其实还是有问题的，我故意留下了一个坑：
抛出异常的前提是要满足最开始的 if 条件：
e.getThreadFactory() instanceof MyThreadFactory
如果别人误用了这个拒绝策略，导致这个 if 条件不成立的话，那么这个拒绝策略还是有问题。
所以，应该把抛出异常的逻辑移到 if 之外。
同时在排查问题的过程中，在项目里面看到了类似这样的写法：
不要这样写，好吗？
一个是因为 submit 是有返回值的，你要是不用返回值，直接用 execute 方法不香吗？
另外一个是因为你这样写，如果线程池里面的任务执行的时候出异常了，会把异常封装到 Future 里面去，而你又不关心 Future，相当于把异常给吞了，排查问题的时候你就哭去吧。
这些都是编码过程中的一些小坑和小注意点。
反转
这一小节的题目为什么要叫反转？
因为以上的内容，除了技术原理是真的，我铺垫的所有和背景相关的东西，全部都是假的。
整篇文章从第二句开始就是假的，我根本就没有遇到过这样的一个生产问题，也谈不上扼杀在摇篮里，更谈不上是我去解决的了。
但是我在开始的时候说了这样一句话，也是全文唯一一句加粗的话：
虽然现在不是你的，但是你看完之后就是你的了，你明白我意思吧？
所以这个背景其实我前几天看到了“严选技术”发布的这篇文章《严选库存稳定性治理系列：一个线程池拒绝策略引发的血案》。
看完他们的这篇文章之后，我想起了我之前写过的这篇文章：《看起来是线程池的BUG，但是我认为是源码设计不合理。》
我写的这篇就是单纯从技术角度去解析的这个问题，而“严选技术”则是从真实场景出发，层层剥茧，抵达了问题的核心。
但是这两篇文章遇到的问题的核心原因其实是一模一样的。
我在我的文章中的最后就有这样一段话：
巧了，这不是和“严选技术”里面这句话遥相呼应起来了吗：
在我反复阅读了他们的文章，了解到了背景和原因之后，我润色了一下，写了这篇文章来“骗”你。
如果你有那么几个瞬间被我“骗”到了，那么我问你一个问题：假设你是面试官，你问我工作中有没有遇到过比较棘手的问题？
而我是一个只有三年工作经验的求职者。
我用这篇文章中我假想出来的生产问题处理过程，并辅以技术细节，你能看出来这是我“包装”的吗？
然后在描述完事件之后，再体现一下对于事件的复盘，可以说一下基于这个事情，后面自己对监控层面进行了丰富，比如接口超时率监控、GC 导致的 STW 时间监控啥的。然后也在公司内形成了“经验教训”文档，主动同步给了其他的同事，以防反复踩坑，巴拉巴拉巴拉...
反正吧，以后看到自己觉得好的案例，不要看完之后就完了，多想想怎么学一学，包装成自己的东西。
---
1. 事件回顾
从7.27号开始主站、分销等业务方开始反馈下单偶发超时现象，我们开始分析排查问题原因，震惊地发现线上偶发full gc，如下图所示。如果继续放任下去，势必影响严选交易下单核心链路及用户体验，造成交易损失。库存中心开发迅速响应，积极排查并解决问题，把问题在萌芽状态处理掉，避免造成资损。
因此，我们紧急排查，并把排查及解决问题的过程用时间轴方式展示如下，后续会一一介绍解决方案及问题原因。
2. 紧急止血
对于频繁full gc，根据经验，我们大胆猜测可能由于某些接口产生大对象并且调用频率较高引起，在紧急情况下，首先保证系统核心功能不受影响，然后再排查问题。一般有三种手段，如下：
- 扩容扩容一般有两种方式，一是提高堆内存大小，二是对应用机器扩容；本质上都是延缓full gc出现的次数和频率，尽力保证核心业务，然后再排查问题。
- 限流限流可以认为服务降级的一种，限流就是限制系统的输入和输出流量已达到保护系统的目的，一般可以在代理层和应用层做限流。
- 重启相对比较暴力的一种方式，稍微不注意免会带来数据不一致问题，除非必要否则不建议。
我们应用限流是针对应用接口层面得，由于不知道问题具体原因且问题还在萌芽状态，所以就没有直接限流，而是直接扩容，顺带重启。我们临时紧急对堆内存扩容，将部分机器堆内存大小由6g提升至22g，并对应用进行重启，使配置参数生效。7.27号紧急对部分机器(73和74)扩容后，我们可以发现扩容后2天内没有发生full gc，为我们进一步排查提供了容错时间；
3. 问题分析
3.1 现状挑战
由于没有OOM，所以没有现场内存快照，不好确定问题原因，而库存主服务涉及的逻辑太多（核心业务逻辑有十几万行代码，都是日常在运行的），且业务逻辑复杂、调用量大，并且存在少量慢请求，增加了排查问题难度。由于没有相对完善的基建设施，我们没有一个全局的调用监控平台去观察full gc前后应用到底发生了什么，只能通过在问题机器上分析链路调用情况，去一点点寻找问题真相。
3.2 表象原因
本质上，我们要看下发生full gc时应用系统做了什么事情，也就是说找到压死骆驼最后一根稻草是什么？我们对发生full gc前时间点应用日志进行了大量分析，结合慢sql分析，只要业务在一段时间频繁操作【内外部采购出库】业务，系统就会触发一次full gc，时间点比较吻合，因此，初步判定可能由于内外部采购出库业务操作引起得，通过分析业务代码分析发现，该库存变更经过干预拦截会将10w条数据load到内存中，共计300M左右，感觉一下子看到了希望！对此我们7.28号紧急联系dba将该部分业务数据紧急迁移到其他数据库，避免进一步对业务造成影响，后续再对业务流程进行优化！！
迁移后我们发现当天并没有出现full gc，也没有业务反馈接口超时，7.29号我们发现73这台机器(升级配置)没有full gc，而154这台机器，在7.29号继续出现full gc，观察每次gc可回收的内存大小并不多，也就是说内存并没有及时释放，极有可能存在泄漏问题！
3.3 问题根因
当时我们多次dump了内存快照，并没有发现类似问题，庆幸地是155这台机器最后才升级(备用机，主要用于处理定时任务，留作参照对比效果)，让我们进一步接近了问题根因。为进一步分析原因，我们对其中一台机器(155)堆内存快照进行了分析，发现了一个比较有意思的现象，即存在大量的线程阻塞等待线程；每一个阻塞线程会持有大约14M的内存，正是这些线程导致了内存泄漏，至此我们终于找到了问题原因，同时验证了我们的猜想，即发生了内存泄漏！
3.4 原因分析
3.4.1 业务描述
从4.2我们定位到问题代码，为方便理解我们对这部分业务（从数据库中拉取sku数量信息，每500个sku组成一个SyncTask，然后缓存到redis中，供其他业务方使用，每5min执行一次）做下概述，并把主要的代码片段罗列如下：
3.4.2 业务代码
public String sync(String tableName) {// 生成数据版本号DateFormat dateFormat = new SimpleDateFormat("YYYYMMdd_HHmmss_SSS");// 启动Leader线程完成执行和监控String threadName = "SyncCache-Leader-" + dateFormat.format(new Date());Runnable wrapper = ThreadHelperUtil.wrap(new PrimaryRunnable(cacheVersion, tableName,syncCachePool));Thread core = new Thread(wrapper, threadName); // 新建线程，处理同步同步core.start();return cacheVersion;}private static class PrimaryRunnable implements Runnable {private String cacheVersion;private String tableName;private ExecutorService syncCachePool;public PrimaryRunnable(String cacheVersion, String tableName,ExecutorService syncCachePool) {this.cacheVersion = cacheVersion;this.tableName = tableName;this.syncCachePool = syncCachePool;}public void run() {....try {exec();CacheLogger.doFinishLog(cacheVersion, System.currentTimeMillis() - leaderStart);} catch (Throwable t) {CacheLogger.doExecErrorLog(cacheVersion, System.currentTimeMillis() - leaderStart, t);}}public void exec() {// 查询数据并构建同步任务List<SyncTask> syncTasks = buildSyncTask(cacheVersion, tableName);// 同步任务提交线程池Map<SyncTask, Future> futureMap = Maps.newHashMap();for (SyncTask task: syncTasks) {futureMap.put(task, syncCachePool.submit(new Runnable() {public void run() {task.run();}}));}// 等待执行完成for (Map.Entry<SyncTask, Future> futureEntry: futureMap.entrySet()) {try {futureEntry.getValue().get(); // 阻塞获取同步任务结果} catch (Throwable t) {CacheLogger.doFutureFailedLog(cacheVersion, futureEntry.getKey());throw new RuntimeException(t);}}}}/*** 拒绝策略类*/private static class RejectedPolicy implements RejectedExecutionHandler {static RejectedPolicy singleton = new RejectedPolicy();private RejectedPolicy() {}public void rejectedExecution(Runnable runnable, ThreadPoolExecutor executor) {if (runnable instanceof SyncTask) {SyncTask task = (SyncTask) runnable;CacheLogger.doRejectLog(task);}}}
当前队列大小为1000，最大线程数为20，也就是说线程池最少可以处理51w数据，而目前sku个数大约为54w，如果任务耗时，剩余任务可能全部都会放入队列中，可能存在线程池队列不足的情况。队列大小不足，会触发拒绝策略，目前我们项目中的拒绝策略是类似于DiscardPolicy(当新任务被提交后直接被丢弃掉，也不会给你任何的通知)，但是为什么会出现线程(name：SyncCache-Leader-时间戳)会阻塞等待的问题，需要我们进一步结合submit方法及业务代码继续分析。
3.4.3 源码分析
- java.util.concurrent.AbstractExecutorService#submit(java.lang.Runnable)
public Future<?> submit(Runnable task) {if (task == null) throw new NullPointerException();RunnableFuture<Void> ftask = newTaskFor(task, null); //execute(ftask); //执行excute方法return ftask; // 返回task，状态为NEW}public FutureTask(Runnable runnable, V result) {this.callable = Executors.callable(runnable, result);this.state = NEW; // ensure visibility of callable}
- sumbit方法就是通过调用FutureTask的构造器返回FutureTask实例的。
- 可以看到传递进来的Runnable任务也会通过Executors.callable(runnable, result)工厂方法转换为Callable类型的任务，这是一种设计模式—适配器模式，而FutureTask对callable任务的包装也是一种适配器模式——转换为Runnable类型。
- 构造器仅仅是初始化callable属性，以及FutureTask状态为NEW。
- java.util.concurrent.ThreadPoolExecutor#execute
public void execute(Runnable command) {if (command == null)throw new NullPointerException();int c = ctl.get();if (workerCountOf(c) < corePoolSize) {if (addWorker(command, true))return;c = ctl.get();}if (isRunning(c) && workQueue.offer(command)) {int recheck = ctl.get();if (! isRunning(recheck) && remove(command))reject(command);else if (workerCountOf(recheck) == 0)addWorker(null, false);}else if (!addWorker(command, false))// 走到这一步说明核心线程数满了，要尝试往队列里面加，// 调用的workQueue.offer(command)返回false，说明队列满了，执行拒绝策略reject(command);}
走到这里，其实这段代码并没有加入到队列中，submit方法直接返回一个state为NEW的FutureTask实例！！！紧接着我们看到业务代码futureEntry.getValue().get()，从futureTask中阻塞获取结果，下面我们看到这段代码：
// 等待执行完成for (Map.Entry<SyncTask, Future> futureEntry: futureMap.entrySet()) {try {futureEntry.getValue().get(); // 阻塞获取同步任务结果} catch (Throwable t) {CacheLogger.doLeaderFutureFailedLog(cacheVersion, futureEntry.getKey());throw new InventoryException(t);}}
public V get() throws InterruptedException, ExecutionException {int s = state;// 执行submit后执行拒绝策略的任务虽然没有加入到队列，但返回的FutureTask// 状态仍然为NEW，会尝试获取结果；if (s <= COMPLETING)s = awaitDone(false, 0L);return report(s);}
private int awaitDone(boolean timed, long nanos)throws InterruptedException {final long deadline = timed ? System.nanoTime() + nanos : 0L;WaitNode q = null;boolean queued = false;for (;;) {if (Thread.interrupted()) {removeWaiter(q);throw new InterruptedException();}int s = state;if (s > COMPLETING) {if (q != null)q.thread = null;return s;}else if (s == COMPLETING) // cannot time out yetThread.yield();else if (q == null) //第一次进for循环时q==null，进入到这个分支q = new WaitNode();else if (!queued) // 第二次进for循环时queued为false，则使用CAS将q置为waiters的头结点queued = UNSAFE.compareAndSwapObject(this, waitersOffset,q.next = waiters, q);else if (timed) {nanos = deadline - System.nanoTime();if (nanos <= 0L) {removeWaiter(q);return state;}LockSupport.parkNanos(this, nanos);}else// 将q置为头结点后，最终会进入这里调用park()方法，阻塞当前线程.// 也就是说走到这里，同步线程SyncCache-Leader-时间戳阻塞等待唤醒LockSupport.park(this);}
分析到这里，我们总结问题原因如下：
- 首先当任务提交到线程池，触发了拒绝策略，则FutureTask的状态处于New状态，调用get()方法会到达LockSupport.park(this)处，将当前线程阻塞，导致了内存泄漏；
- 究其原因，其实主要还是线程池使用不当，主要有两点问题，一是拒绝策略选择上有问题，二是程序中submit提交线程，但是获取结果时却没有使用超时时间，可以使程序超时抛异常终止(另外，项目中不需要获取任务结果，其实也没有必要用submit方法提交任务)。
3.4.4 刨根问底
分析到这里，我们可以说是找到了问题原因，也就是说FutureTask获取执行结果时调用了LockSupport.park(this)阻塞了主线程，什么时候才会将当前线程唤醒？我们继续看代码。那就是当存在工作线程Worker目前分配的任务执行完成后，其会去调用Worker类的getTask()方法从阻塞队列中拿到该任务，并执行该任务的run()方法，下面是FutureTask的run()方法：
public void run() {if (state != NEW ||!UNSAFE.compareAndSwapObject(this, runnerOffset,null, Thread.currentThread()))return;try {Callable<V> c = callable;if (c != null && state == NEW) {V result;boolean ran;try {result = c.call();ran = true;} catch (Throwable ex) {result = null;ran = false;setException(ex);}if (ran)set(result); //如果任务执行成功，则调用set(V result)方法}} finally {// runner must be non-null until state is settled to// prevent concurrent calls to run()runner = null;// state must be re-read after nulling runner to prevent// leaked interruptsint s = state;if (s >= INTERRUPTING)handlePossibleCancellationInterrupt(s);}}
protected void set(V v) {if (UNSAFE.compareAndSwapInt(this, stateOffset, NEW, COMPLETING)) {outcome = v;UNSAFE.putOrderedInt(this, stateOffset, NORMAL); // final statefinishCompletion();}}
private void finishCompletion() {// assert state > COMPLETING;for (WaitNode q; (q = waiters) != null;) {if (UNSAFE.compareAndSwapObject(this, waitersOffset, q, null)) {for (;;) {Thread t = q.thread; //q在await()方法中设置的，其值为调用get()方法的线程if (t != null) {q.thread = null;LockSupport.unpark(t); // 唤起因get()而阻塞的线程。}WaitNode next = q.next;if (next == null)break;q.next = null; // unlink to help gcq = next;}break;}}done();callable = null; // to reduce footprint}
也就是说如果run方法正常返回，最终FutureTask会将结果保存并且唤醒当前阻塞线程，但是应用中我们的任务压根就没有执行run方法，也就是说会被一直阻塞！
4. 问题解决
通过优化线程池配置和业务流程l，如调高线程池队列大小、修复拒绝策略、优化业务流程规避大对象、任务错峰执行等一系列组合措施，保证了任务稳定执行。
4.1 线程池配置优化
调高线程池队列大小、修复拒绝策略
4.1.1 修改拒绝策略
- 项目中使用的自定义拒绝策略，主要目的其实就是想打印出拒绝任务中包含的任务信息如skuId等，然后手动进行更新，防止提供给其他服务的库存数据异常；
- 由前文我们已经runnable类型是FutureTask，因此图片中的if判断永远不会成立，这种自定义的拒绝策略像线程池中默认的拒绝策略DiscardPolicy（当新任务被提交后直接被丢弃掉，也不会给你任何的通知，相对而言存在一定的风险，因为我们提交的时候根本不知道这个任务会被丢弃，可能造成数据丢失）；
- 修改后，队列满之后，会立即触发拒绝策略，抛出异常，父线程才不会一直阻塞获取该FutureTask的结果了。
ps：项目中目前对线程中的Runnable进行了包装，如果使用原生类，可以通过反射获取拒绝策略中被拒绝的任务情况。只是获取拒绝任务信息，可以忽略不看。
4.1.2 调高队列大小
- 线程池最大线程数是20，队列大小是1000，目前sku个数是54w，每个任务有500个skuId，每个人任务执行时间稍长的话，最多只能只能处理51w sku，加之3个任务公用线程池，设置队列大小为3000；
- 队列调整后，可避免部分sku没有及时将库存数据同步到缓存中。
4.2 业务流程优化
针对内外部采购出现的大对象进行优化，减少每次请求300M大对象问题，同时对公用线程池的三种定时任务执行时间进行错峰，避免sku增多后任务间相互干扰。
5. 总结沉淀
5.1 full gc解决思路总结
- 遇到频繁full gc这种线上，我们该怎么办？首先想到的是要先紧急处理，然后再分析原因，紧急处理我们大概有三种可选方案：重启、限流、扩容 三板斧；
- 其次，明确方向，一般来说，引起full gc的主要原因有两大类，一是应用资源配置问题，二是程序问题。资源配置这块，我们要检查jvm参数配置是否合理；大部分full gc都是由程序问题引起得，主要有两方面原因，一是程序存在大对象，二是存在内存泄漏；
- 最重要的一点，分析dump文件，但是要保证取得事发时内存快照，分析软件可以用MAT和VisualVM，对于我们遇到的这个问题，其实还可以用jstack获取当前进程所有的线程进行分析；
- full gc时要及时告警，避免开发响应滞后于业务，另外，在实践中我们要合理设置JVM参数，这样也可以尽量避免full gc，此次问题排查，我们也对jvm参数进行了调整，后续会有相应文章发布。
5.2 线程池使用注意事项
- 如果不需要同步获取任务结果，尽量使用execute方式提交任务，并且对于异常要谨慎处理，防止频繁销毁和创建线程；
- 如果需要使用submit方式提交任务，同步获取结果时尽量使用超时获取方式，避免出现一直阻塞问题导致内存泄漏的问题；
- 谨慎使用拒绝策略，熟悉拒绝策略和线程提交方式配合使用可能存在的问题，如DiscardPolicy和submit方式提交任务就可能存在获取结果阻塞等待情况；
- 线程池线程要有辨识度，也就是有自己的命名规则，方便问题排查。
