线程池如何打印堆栈信息？

前言

本文隶属于专栏《100个问题搞定Java并发》，该专栏为笔者原创，引用请注明来源，不足和错误之处请在评论区帮忙指出，谢谢！

本专栏目录结构和参考文献请见100个问题搞定Java并发

正文

简单的例子

先从一个简单的例子入手，首先，我们有一个 Runnable 接口，它用来计算两个数的商。

public class DivTask implements Runnable {
    int a,b;
    public DivTask(int a,int b){
        this.a=a;
        this.b=b;
    }
    @Override
    public void run() {
        double re=a/b;
        System.out.println(re);
    }
}

如果程序运行了这个任务,那么我们期望它可以打印出给定两个数的商。

现在我们构造几个这样的任务,希望程序可以计算一组给定数组的商。

import java.util.concurrent.ExecutionException;
import java.util.concurrent.SynchronousQueue;
import java.util.concurrent.ThreadPoolExecutor;
import java.util.concurrent.TimeUnit;

/**
 * submit吃掉异常
 * 1. 用Future.get()获得异常
 * 2. try-catch
 * @author Shockang
 *
 */
public class CatchExceptionMain {
    public static void main(String[] args) throws InterruptedException, ExecutionException {
        ThreadPoolExecutor pools=new ThreadPoolExecutor(0, Integer.MAX_VALUE,
                0L, TimeUnit.SECONDS,
                new SynchronousQueue<Runnable>());
        
        for(int i=0;i<5;i++){
            pools.submit(new DivTask(100,i));
        }
    }
}

上述代码将 DivTask 提交到线程池，从 for 循环来看，我们应该会得到 5 个结果，分别是 100 除以给定的 i 后的商。

但如果你真的运行程序，那么得到的全部结果是:

100.0
25.0
33.0
50.0

只有 4 个输出，也就是说程序漏算了一组数据，但更不幸的是，程序没有任何日志，也没有任何错误提示，就好像一切正常一样。

在这个简单的案例中，只要你稍有经验就能发现，作为除数的 i 取到了 0 ，这个缺失的值很可能是由于除以 0 导致的。

但在稍复杂的业务场景中，这种错误足可以让你几天萎靡不振。

因此，使用线程池虽然是件好事，但是还是得处处留意这些“坑”。

线程池很有可能会“吃”掉程序抛出的异常，导致我们对程序的错误一无所知。

异常堆栈对于程序员的重要性就好像指南针对于航行在茫茫大海上的轮船。

没有指南针，轮船只能更艰难地寻找方向，没有异常堆栈，排查问题时，也只能慢慢琢磨了。

这里我们将和大家讨论向线程池讨回异常堆栈的方法。

execute

一种最简单的方法就是放弃 submit()方法，改用 execute()方法。 将上述的任务提交代码改成:

import java.util.concurrent.ExecutionException;
import java.util.concurrent.SynchronousQueue;
import java.util.concurrent.ThreadPoolExecutor;
import java.util.concurrent.TimeUnit;

/**
 * submit吃掉异常
 * 1. 用Future.get()获得异常
 * 2. try-catch
 *
 * @author Shockang
 */
public class CatchExceptionMain2 {
	public static void main(String[] args) throws InterruptedException, ExecutionException {
		ThreadPoolExecutor pools = new ThreadPoolExecutor(0, Integer.MAX_VALUE,
				0L, TimeUnit.SECONDS,
				new SynchronousQueue<Runnable>());

		for (int i = 0; i < 5; i++) {
			pools.execute(new DivTask(100, i));
		}
	}
}

或者使用下面的代码：

import java.util.concurrent.*;

/**
 * submit吃掉异常
 * 1. 用Future.get()获得异常
 * 2. try-catch
 *
 * @author Shockang
 */
public class CatchExceptionMain3 {
	public static void main(String[] args) throws InterruptedException, ExecutionException {
		ThreadPoolExecutor pools = new ThreadPoolExecutor(0, Integer.MAX_VALUE,
				0L, TimeUnit.SECONDS,
				new SynchronousQueue<Runnable>());

		for (int i = 0; i < 5; i++) {
			Future re = pools.submit(new DivTask(100, i));
			re.get();
		}
	}
}

上面两种方法都可以得到部分堆栈信息，如下所示:

Exception in thread "pool-1-thread-1" java.lang.ArithmeticException: / by zero
	at com.shockang.study.java.concurrent.trace.DivTask.run(DivTask.java:11)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)
100.0
25.0
33.0
50.0

注意了，我这里说的是部分。

这是因为从这两个异常堆栈中我们只能知道异常是在哪里抛出的(这里是 DivTask 的第 11 行)。

但是我们还希望得到另外一个更重要的信息，那就是这个任务到底是在哪里提交的?

而任务的具体提交位置已经被线程池完全淹没了。

顺着堆栈，我们最多只能找到线程池中的调度流程，而这对于我们几乎是没有价值的。

既然这样，我们只能自己动手，丰衣足食啦!

为了今后少加几天班，非常有必要将堆栈的信息彻底挖出来!

扩展我们的 ThreadPoolExecutor 线程池，让它在调度任务之前，先保存一下提交任务线程的堆栈信息。

扩展 ThreadPoolExecutor

import java.util.concurrent.BlockingQueue;
import java.util.concurrent.Future;
import java.util.concurrent.ThreadPoolExecutor;
import java.util.concurrent.TimeUnit;

public class TraceThreadPoolExecutor extends ThreadPoolExecutor {
	public TraceThreadPoolExecutor(int corePoolSize, int maximumPoolSize,
								   long keepAliveTime, TimeUnit unit, BlockingQueue<Runnable> workQueue) {
		super(corePoolSize, maximumPoolSize, keepAliveTime, unit, workQueue);
	}

	@Override
	public void execute(Runnable task) {
		super.execute(wrap(task, clientTrace(), Thread.currentThread()
				.getName()));
	}

	@Override
	public Future<?> submit(Runnable task) {
		return super.submit(wrap(task, clientTrace(), Thread.currentThread()
				.getName()));
	}

	private Exception clientTrace() {
		return new Exception("Client stack trace");
	}

	private Runnable wrap(final Runnable task, final Exception clientStack,
						  String clientThreadName) {
		return new Runnable() {
			@Override
			public void run() {
				try {
					task.run();
				} catch (Exception e) {
					clientStack.printStackTrace();
					throw e;
				}
			}
		};
	}
}

在第 28 行代码中， wrap 方法的第 2 个参数为一个异常，里面保存着提交任务的线程的堆栈信息。

该方法将我们传入的 Runnable 任务进行一层包装，使之能处理异常信息。

当任务发生异常时，这个异常会被打印。

好了，现在可以使用我们的新成员( TraceThreadPoolExecutor )来尝试执行这段代码了。

import java.util.concurrent.SynchronousQueue;
import java.util.concurrent.ThreadPoolExecutor;
import java.util.concurrent.TimeUnit;


public class TraceMain {

	public static void main(String[] args) {
		ThreadPoolExecutor pools = new TraceThreadPoolExecutor(0, Integer.MAX_VALUE,
				0L, TimeUnit.SECONDS,
				new SynchronousQueue<Runnable>());
		for (int i = 0; i < 5; i++) {
			pools.execute(new DivTask(100, i));
		}
	}

}

执行上述代码，就可以得到以下信息:

java.lang.Exception: Client stack trace
	at com.shockang.study.java.concurrent.trace.TraceThreadPoolExecutor.clientTrace(TraceThreadPoolExecutor.java:27)
	at com.shockang.study.java.concurrent.trace.TraceThreadPoolExecutor.execute(TraceThreadPoolExecutor.java:16)
	at com.shockang.study.java.concurrent.trace.TraceMain.main(TraceMain.java:15)
Exception in thread "pool-1-thread-1" java.lang.ArithmeticException: / by zero
	at com.shockang.study.java.concurrent.trace.DivTask.run(DivTask.java:11)
	at com.shockang.study.java.concurrent.trace.TraceThreadPoolExecutor$1.run(TraceThreadPoolExecutor.java:36)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)
100.0
25.0
33.0
50.0