一、开场白
这是我入职公司处理的第一个事故，也是我在公司可谈的第一个故事。
项目上有个报告生成业务，开发人员把报告请求封装成任务后，放到线程池中异步生成，生成过程会向数据库写出状态，用于支持生成状态查询，前台查询到报告状态生成成功，即可下载报告。
生成过程是从数据库和接口拉取数据，填充报告模板，最后再转化成实际的报告（PDF）。报告有一块内容是绘制一个关联关系图，它通过预先定义图的节点、边的关系，并将关系集合交给一个三方工具（yed，一个强大的画图工具，不过我不太熟~）绘制，故事就由这个第三方的工具库引起。
Yed是一个非常强大的绘图工具，但有一个缺陷，绘图一旦开始，就不能取消，也不响应中断。这就给我们的绘图带来了麻烦，当关系节点、边数量非常大且存异常关系时，会偶发出现绘图进入一个无限循环，通过jstack观察，发现某个方法一直在循环调用。通过top观察发现有CPU的占用接近100%。重复提交几个相同的报告任务，会导致服务器每核都被打满，最终表现为报告生成的服务不再响应报告生成，正在生成中的报告也无任何进度信息变更。
二、尝试解决
发现问题后，项目组召集全员一同解决，大家尝试反编译源码（Yed是一个收费库，不开放源码），同时也结合数据输入做分析，希望能发现异常点，通过纠正数据输入来解决问题，最终无果。
三、最终解决
这就是今天要说的主要内容了，最后我们期望扩展线程池，把线程池中的工作线程监控起来，当然只是简单监控，当工作线程开始报告生成且时间超过一定的阈值（正常情况报告基本可以在2分钟内完成，我们将阈值设定为5分钟），则直接结束本次报告生成，然后触发一个回调，并将数据输入降一个度（绘图数据默认4度，每降一度，数据会量级减少，图形结构会更简单。后来发现4度有问题的图在3度基本可正常生成）再重新输入，再次进行生成。
基于以上考虑，便对线程池做了如下调整封装：
public class TraceThreadPoolExecutor extends ThreadPoolExecutor {
private static final Logger LOG = LoggerFactory.getLogger(TraceThreadPoolExecutor.class);
private static final int SHUTDOWN_TIMEOUT = 60;
private final Map<Runnable, Thread> tracedThreads = new ConcurrentHashMap<>();
private final ExecutorService monitor;
/**
* 提交一个任务到线程池中，并且监控任务的执行耗时，如果超过阈值，则停止任务
*/
public Future<?> submit(Runnable job,
int timeOut,
TimeUnit timeUnit,
TimeOutHandler timeOutHandler) {
Future<?> futureTaskJob = submit(job);
monitor.execute(new MonitorJob(job, futureTaskJob, timeOut, timeUnit, timeOutHandler));
return futureTaskJob;
}
public void stop() {
shutdownExecutorQuietly(monitor);
shutdownExecutorQuietly(this);
}
private void shutdownExecutorQuietly(ExecutorService executor) {
if (null != executor) {
try {
executor.shutdown();
if (!executor.isShutdown()) {
try {
executor.awaitTermination(SHUTDOWN_TIMEOUT, TimeUnit.SECONDS);
} catch (InterruptedException ignore) {
LOG.warn(ignore.getMessage(), ignore);
}
if (!executor.isShutdown()) {
executor.shutdownNow();
}
}
} catch (Exception ignore) {
LOG.warn(ignore.getMessage(), ignore);
}
}
}
@Override
protected void beforeExecute(Thread worker, Runnable job) {
/**
* 记录处理任务具体的线程
*/
recordJobWorker(job, worker);
}
@Override
protected void afterExecute(Runnable job, Throwable error) {
/**
* 任务执行完成，清理任务与工作现场的关联信息
*/
clearJobWorkerRecord(job);
}
private class MonitorJob implements Runnable {
private final Future<?> futureTaskJob;
private final Runnable originJob;
private final int timeOut;
private final TimeUnit timeUnit;
private final TimeOutHandler timeOutHandler;
public MonitorJob(Runnable originJob,
Future<?> futureTaskJob,
int timeOut,
TimeUnit timeUnit,
TimeOutHandler timeOutHandler) {
this.originJob = originJob;
this.futureTaskJob = futureTaskJob;
this.timeOut = timeOut;
this.timeUnit = timeUnit;
this.timeOutHandler = timeOutHandler;
}
@Override
public void run() {
if (null != futureTaskJob) {
try {
futureTaskJob.get(timeOut, timeUnit);
} catch (InterruptedException ignore) {
LOG.warn(ignore.getMessage(), ignore);
} catch (ExecutionException ignore) {
LOG.warn(ignore.getMessage(), ignore);
} catch (TimeoutException timeOut) {
/**
* Force stop worker
*/
Thread worker = getTracedThread((FutureTask) futureTaskJob);
if (null != worker && worker.isAlive()) {
worker.stop();
}
/**
* Do callback
*/
if (null != timeOutHandler) {
timeOutHandler.doHandle(originJob);
}
}
}
}
}
private void recordJobWorker(Runnable job, Thread worker) {
tracedThreads.put(job, worker);
}
private Thread getTracedThread(Runnable job) {
return tracedThreads.get(job);
}
private void clearJobWorkerRecord(Runnable job) {
tracedThreads.remove(job);
}
private TraceThreadPoolExecutor(int workerThreads, int monitorThreads) {
super(workerThreads, workerThreads, 0L, TimeUnit.MILLISECONDS, new LinkedBlockingQueue<>());
monitor = Executors.newFixedThreadPool(monitorThreads);
}
public static TraceThreadPoolExecutor createFixedThreadPool(int workerThreads) {
return new TraceThreadPoolExecutor(workerThreads, workerThreads);
}
}
放个测试栗子：
public class TraceThreadPoolExecutorTutorial {
public static void main(String[] args) throws InterruptedException {
TraceThreadPoolExecutor.createFixedThreadPool(1).submit(() -> {
try {
Thread.sleep(60000);
} catch (InterruptedException ignore) {
}
}, 10, TimeUnit.SECONDS, job -> System.out.println("TimeoutHandler execute!"));
Thread.sleep(20000);
System.out.println("Main thread exit!");
}
}
---------------------------------------结果输出--------------------------------------
TimeoutHandler execute!
Main thread exit!
这里可能会有一个疑问，代码中使用stop来终止一个线程的执行是否有问题？当然有，但要具体情况具体分析！
我们先理解一下Thread.stop方法的原理，抛出一个ThreadDeath的error并且释放掉所有持有的监视器锁。所以如果在一个业务中依赖了锁来处理业务，并且业务处理处于中间的非一致状态的情况下，线程被stop掉，这样其它线程就可以获取到锁，并继续业务处理，很明显这种情况可能会导致一些奇葩问题的出现。
但是这些问题，在我们的故事里都不存在。回顾一下我们的问题：
- 工作线程调用Yed工具库绘图，因为某种原因进入一个不响应中断的无限循环中；
- 报告线程与其它线程没有需要做同步的地方。
所以Thread.stop对我们来说是安全的，而且可能是我们唯一的选择。
最后业务方接受我们方案，调整之后线上运行良好，我们的问题得到解决。
四、写在最后
本文的案例存有很强的特殊性，首先工作线程执行的是一个没有出口的循环任务，其次任务无法被取消也不响应中断，在这样的背景下，我们才选择了上文阐述的解决办法，当然这也依赖于对线程池、Thread.stop方法工作原理的理解。
如果有益，请关注、收藏、点赞。个人认识有限，不准确的地方欢迎指正，谢谢！
End.
