前面的文章已经讲了和,这篇文章来了解线程池出错的堆栈信息的打印,毕竟异常堆栈信息的重要性对于程序员来说就像是指南针对于茫茫大海上的船只一样,没有指南针船只只能更加艰难的寻找方向,没有异常堆栈信息,排查问题时,也就只能像大海捞针一样,慢慢琢磨了。
看下面的例子:
1 public class DivTask implements Runnable { 2 3 int a,b; 4 public DivTask(int a,int b){ 5 this.a = a; 6 this.b = b; 7 } 8 @Override 9 public void run() {10 double re = a / b;11 System.out.println(re);12 }13 //测试14 public static void main(String[] args){15 ThreadPoolExecutor poolExecutor = new ThreadPoolExecutor(0,Integer.MAX_VALUE,0L, TimeUnit.SECONDS,new SynchronousQueue());16 for (int i = 0;i < 5;i++){17 poolExecutor.submit(new DivTask(100,i));18 }19 }20 }
上述代码是将DivTask提交到线程池,从第16行for循环来看,我们会得到5个结果,分别是100除以i的商,下面就是这段代码的输出结果:
100.025.033.050.0
你没有看错,就只有4个结果,也就是说程序漏算了一组数据,但是更加不幸的是,没有任何的错误提示,就好像一切正常一样。但是在这个简单的案例中,只要你稍有经验,就能发现,作为除数i取到了0,这个缺失的值很可能是由于这个0导致的,但是如果是在稍微复杂的业务场景中,这种简单的错误足以让你几天萎靡不振。
也就是说:使用线程池虽然是件好事,但是得处处留意坑。线程池很可能会“吃”掉程序抛出的异常,导致我们对程序的错误一无所知。
改正方法:
1 最简单的方法,弃用submit(),改用execute()方法
将上述代码第17行修改为:
poolExecutor.execute(new DivTask(100,i));
这样执行代码后,你将得到部分堆栈信息,执行结果如下:
100.050.033.025.0Exception in thread "pool-1-thread-1" java.lang.ArithmeticException: / by zero at CurrentJava.DivTask.run(DivTask.java:10) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:745)
注意了这里说的部分堆栈信息。这是因为从这两个异常堆栈中我们只知道异常在哪里抛出的(这里说的是第10行);但是我们还希望得到另外一个更重要的信息,那就是这个任务是在哪里提交的?而任务的具体提交位置已经被线程池给完全淹没了,顺着堆栈,我们最多只能找到线程调度的调度流程,而这对于我们来说几乎没有价值。
2 改造submit()方法
将上述代码第17行修改为:
Future re = poolExecutor.submit(new DivTask(100,i));re.get();
执行后得到输出结果:
Exception in thread "main" java.util.concurrent.ExecutionException: java.lang.ArithmeticException: / by zero at java.util.concurrent.FutureTask.report(FutureTask.java:122) at java.util.concurrent.FutureTask.get(FutureTask.java:192) at CurrentJava.DivTask.main(DivTask.java:17)Caused by: java.lang.ArithmeticException: / by zero at CurrentJava.DivTask.run(DivTask.java:10) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) at java.util.concurrent.FutureTask.run(FutureTask.java:266) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:745)
可以看出得到的堆栈信息与上面使用execute()方法几乎一致,都只能知道异常在哪里抛出的。
3 扩展 ThreadPoolExecutor
我们扩展ThreadPoolExecutor 线程池,让它在调度任务之前,先保存一下提交任务线程的堆栈信息,如下所示:
1 public class TraceThreadPoolExecutor extends ThreadPoolExecutor { 2 3 public TraceThreadPoolExecutor(int corePoolSize, int maximumPoolSize, long keepAliveTime, TimeUnit unit, BlockingQueueworkQueue) { 4 super(corePoolSize, maximumPoolSize, keepAliveTime, unit, workQueue); 5 } 6 7 @Override 8 public void execute(Runnable task) { 9 super.execute(wrap(task,clientTrace(),Thread.currentThread().getName()));10 }11 12 @Override13 public Future submit(Runnable task) {14 return super.submit(wrap(task,clientTrace(),Thread.currentThread().getName()));15 }16 17 private Exception clientTrace(){18 return new Exception("Client stack trace!");19 }20 21 private Runnable wrap(final Runnable task,final Exception clientStack,String clientThreadName){22 return new Runnable() {23 @Override24 public void run() {25 try {26 task.run();27 }catch (Exception e){28 clientStack.printStackTrace();29 throw e;30 }31 }32 };33 }34 }
上述代码第21行,wrap()方法的第二个参数为一个异常,里面保存着提交任务的线程堆栈信息。该方法将我们传入的Runnable对象进行一层包装,使之能处理异常信息,当任务发生异常时,这个异常就会被打印(第28行)。
将第一个例子的main方法修改为:
1 //测试2 public static void main(String[] args){3 ThreadPoolExecutor poolExecutor = new TraceThreadPoolExecutor(0,Integer.MAX_VALUE,0L,TimeUnit.SECONDS,new SynchronousQueue());4 5 for (int i =0;i < 5;i++){6 poolExecutor.execute(new DivTask(100,i));7 }8 }
执行,就可以得到下面的信息:
java.lang.Exception: Client stack trace! at CurrentJava.TraceThreadPoolExecutor.clientTrace(TraceThreadPoolExecutor.java:22) at CurrentJava.TraceThreadPoolExecutor.execute(TraceThreadPoolExecutor.java:13) at CurrentJava.DivTask.main(DivTask.java:22)Exception in thread "pool-1-thread-1" java.lang.ArithmeticException: / by zero at CurrentJava.DivTask.run(DivTask.java:14) at CurrentJava.TraceThreadPoolExecutor$1.run(TraceThreadPoolExecutor.java:30) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:745)100.050.033.025.0
可以看出,熟悉的异常又回来了!现在我们不仅可以得到异常发生的Runnable实现内的信息,我们也知道了这个任务是在哪里提交的。这样丰富的信息,我相信可以帮助我们瞬间定位问题。
参考: 《Java高并发程序设计》 葛一鸣 郭超 编著: