ThreadPoolExecutor执行任务，异常日志缺失问题

之前在使用自定义线程池异步执行耗时任务时，一直记着如果业务方法抛出异常没有捕获，那么是看不到日志框架输出的异常日志的，所以总是在业务方法中包裹一层try-catch捕获可能发生的异常。也未去深入为什么没有打印异常日志和解决方法，这里记录下自己的总结。

1、示例

@Slf4j
@SpringBootTest
@RunWith(SpringRunner.class)
public class ThreadPoolExecutorTest {
    //这里直接使用ThreadPoolExecutor类，这里没有自定义ThreadFactory，默认使用的是Executors.defaultThreadFactory()
    private ThreadPoolExecutor threadPool = new ThreadPoolExecutor(1, 1, 1, TimeUnit.MINUTES, new LinkedBlockingQueue<>(10));
 
    @Test
    public void testSubmitTask() throws InterruptedException {
        log.info("开始提交任务");
        threadPool.execute(this::doSomeThing);
        log.info("提交任务完成");
        TimeUnit.SECONDS.sleep(10);
    }
 
    private void doSomeThing() {
        int value = 10 / 0;
    }
}

我们在IDEA运行时，控制台是有打印出错误日志的(注意此时并没有设置日志输出到控制台的Appender)，实际线上环境我们一般也只配置日志框架输出到日志文件的，那么这个日志是谁打印的呢？这里先不去深追，后面详解。

控制台输出日志：

Exception in thread "pool-1-thread-1" java.lang.ArithmeticException: / by zero
    at org.layman.study.javainaction.ThreadPoolExecutorTest.doSomeThing(ThreadPoolExecutorTest.java:33)
    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)

上面的日志输出结果去我们配置的日志文件查找是找不到的，那么我之前的做法是在doSomeThing方法中使用try-catch包裹：

private void doSomeThing() {
        try {
            int value = 10 / 0;
        } catch (RuntimeException e) {
            log.error("执行异常:", e);
        }
 }

这次执行结果如下，看日志输出我们能明确知道 logger 为org.layman.study.javainaction.ThreadPoolExecutorTest类（注意第3行日志，可以对比下上面的日志输出结果）：

2019-09-05 11:04:32.161 logback [main] INFO  o.l.s.j.ThreadPoolExecutorTest - 开始提交任务
2019-09-05 11:04:32.162 logback [main] INFO  o.l.s.j.ThreadPoolExecutorTest - 提交任务完成
2019-09-05 11:04:32.164 logback [pool-1-thread-1] ERROR o.l.s.j.ThreadPoolExecutorTest - 执行异常:
java.lang.ArithmeticException: / by zero
    at org.layman.study.javainaction.ThreadPoolExecutorTest.doSomeThing(ThreadPoolExecutorTest.java:40)
    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)

2、溯源

通常我们提交给线程池的任务后，真正帮我们执行的是Thread.Worker这个类，该类是Thread的内部类，且实现了Runnable接口，直接看run方法实现：

如果不熟悉线程池内部原理，可以去Google下

//Thread$Worker.java
public void run() {
   runWorker(this);
}
 
//Thread.java
final void runWorker(Worker w) {
        Thread wt = Thread.currentThread();
        Runnable task = w.firstTask;
        //省略代码。。。
        try {
            while (task != null || (task = getTask()) != null) {
                //省略代码。。。
                try {
                    beforeExecute(wt, task); //㈠任务的前置处理
                    Throwable thrown = null;
                    //重要关注点
                    try {
                        //㈡ 调用我们业务方法
                        task.run();
                    } catch (RuntimeException x) { //㈢ 捕获RuntimeException 类型异常
                        thrown = x; throw x;
                    } catch (Error x) { //㈣ 捕获Error 类型异常
                        thrown = x; throw x;
                    } catch (Throwable x) {//㈤ 捕获Throwable 类型异常,重新抛出Error异常
                        thrown = x; throw new Error(x);
                    } finally {
                        afterExecute(task, thrown); // ㈥ 任务的后置处理
                    }
                } finally {
                    //省略代码。。。
                }
            }
            completedAbruptly = false;
        } finally {
            processWorkerExit(w, completedAbruptly);
        }
    }

㈠：执行任务的前置处理，空实现。

㈡：调用执行我们提交的任务，但是 Runnable task = w.firstTask获取的task可能是包装我们提交task的包装类。

㈢、㈣、㈤：从这里可以发现线程池内部捕获并记录异常后重新抛出，在重新抛出捕获的异常前，会把捕获的异常交由afterExecute(task, thrown)处理。

㈥：执行任务的后置处理，空实现。

在注释㈡处 task.run() 就是执行我们的业务方法，按理我们业务方法抛出异常后，这里也会重新抛出，那么我们查看日志时为什么没有看到打印出错误日志呢？

　　补充：评论区有同学说没有找到这里的答案，那我先贴出来结论：

　　这里的task有可能不是我们提交给线程池的Runnable 或者 Callable，可能是包装类 --> FutureTask，所以这里调用的run()也不是我们的业务代码，业务抛出的异常可能被捕获，我们要搞清楚这里的task具体实现，就需要回到我们提交任务给线程池的几种方式。

submit()方式提交的任务被包装为FutureTask会返给我们一个Future，如果业务方法有抛出异常，只有当我们调用java.util.concurrent.Future#get()方法时才会抛出包装业务异常的java.util.concurrent.ExecutionException。
execute()方式提交的任务，这里会继续往上层抛异常最终抛给jvm，jvm根据Thread类中设置的UncaughtExceptionHandler (未捕获异常处理器)处理异常，默认是使用System.err.print("Exception in thread \"" + t.getName() + "\" ")输出日志，这里是输出到标准异常终端，对应到线上环境是tomcat的话最终会打到catalina.out文件中。

所以接下来我们就要分析向线程池提交任务的两种方式：

public void execute(Runnable command),及其重载方法
public <T> Future<T> submit(Callable<T> task),及其重载方法

我们先从简单的来，先从submit(Callable<T> task) 下手。

2.1、java.util.concurrent.AbstractExecutorService#submit(java.util.concurrent.Callable<T>)

public <T> Future<T> submit(Callable<T> task) {
   if (task == null) throw new NullPointerException();
      RunnableFuture<T> ftask = newTaskFor(task); // ㈠
      execute(ftask); //㈡
      return ftask;
}
 
protected <T> RunnableFuture<T> newTaskFor(Callable<T> callable) {
    return new FutureTask<T>(callable);
}

㈠：调用newTaskFor()方法将我们提交的task包装为了FutureTask。

㈡：调用execute方法提交任务，最终线程池会调用FutureTask的run方法。

FutureTask实现了Runnable接口，所以这里能够传递给execute()方法。

2.1.1 java.util.concurrent.FutureTask

run方法实现：

//FutureTask.java
public void run() {
        // 省略部分代码。。。。
        try {
            Callable<V> c = callable; //我们提交task的引用
            if (c != null && state == NEW) {
                V result;
                boolean ran;
                try {
                    result = c.call(); //㈠ 执行我们提交的task
                    ran = true;
                } catch (Throwable ex) { // ㈡重点关注处
                    result = null;
                    ran = false;
                    setException(ex); // ㈢
                }
                if (ran)
                    set(result);
            }
        } finally {
            //省略部分代码。。。
        }
}

㈠：调用执行我们实际提交的task

㈡：当我们提交的task 抛出异常时，这里进行了捕获并且没有重新抛出。

㈢：调用setException(ex)方法保存异常和设置执行状态，详情见2.1.2 java.util.concurrent.FutureTask#setException。

2.1.2、java.util.concurrent.FutureTask#setException(ex)

//FutureTask.java
 
/** The result to return or exception to throw from get() */
//保存要返回的结果或异常，在调用get()时如果有异常(通过状态判断)则抛出异常，否则返回执行结果。
private Object outcome; // non-volatile, protected by state reads/writes
 
protected void setException(Throwable t) {
        if (UNSAFE.compareAndSwapInt(this, stateOffset, NEW, COMPLETING)) {
            outcome = t; //㈠ 将异常信息设置给outcome对象
            UNSAFE.putOrderedInt(this, stateOffset, EXCEPTIONAL); // final state ㈡ 设置最终状态为EXCEPTIONAL
            finishCompletion();
        }
}

㈠：处使用outcome保存抛出的异常信息

㈡：处将FutureTask的执行状态设置为EXCEPTIONAL

2.1.3、java.util.concurrent.FutureTask#get()

//FutureTask.java
 
private static final int COMPLETING   = 1;
private static final int NORMAL       = 2;
private static final int EXCEPTIONAL  = 3;
private static final int CANCELLED    = 4;
 
/**
 * @throws CancellationException {@inheritDoc}
 */
public V get() throws InterruptedException, ExecutionException {
   int s = state; //㈠ state = EXCEPTIONAL状态
   if (s <= COMPLETING)
      s = awaitDone(false, 0L);
   return report(s);
}
 
private V report(int s) throws ExecutionException {
        Object x = outcome;
        if (s == NORMAL)
            return (V)x;
        if (s >= CANCELLED)
            throw new CancellationException();
        throw new ExecutionException((Throwable)x); //㈡ 最终执行到这里抛出异常
}

㈠：在setException方法中已经将状态设置为了EXCEPTIONAL，所以这里 s = EXCEPTIONAL，后续调用report方法。

㈡：在report方法中s 都不满足两个if条件，最后会将业务抛出的异常包装为ExecutionException 后重新抛出。

2.1.4 小结

通过submit方法提交任务时，线程池内部会将我们提交的task包装为FutureTask。
FutureTask的run方法捕获了我们业务方法抛出的异常，在调用java.util.concurrent.FutureTask#get()方法时抛出异常。

2.2 java.util.concurrent.ThreadPoolExecutor#execute

在“示例”中就是使用的该种方式提交task，从结果来看，当业务方法抛出异常后控制台打印日志而日志文件中却没有错误日志，那么这里我们来看下究竟是谁打印的异常日志。

这里我首先怀疑是Thread类打印的，去翻看Thread类定义时找到一些蛛丝马迹，Thread类中有一个 setUncaughtExceptionHandler(UncaughtExceptionHandler eh)方法。

2.2.1 java.lang.Thread#setUncaughtExceptionHandler

/**
 * Set the handler invoked when this thread abruptly terminates due to an uncaught exception.// ㈠
 * <p>A thread can take full control of how it responds to uncaught
 * exceptions by having its uncaught exception handler explicitly set.
 * If no such handler is set then the thread's <tt>ThreadGroup</tt>
 * object acts as its handler.
 * @param eh the object to use as this thread's uncaught exception
 * handler. If <tt>null</tt> then this thread has no explicit handler.
 * @throws  SecurityException  if the current thread is not allowed to
 *          modify this thread.
 * @see #setDefaultUncaughtExceptionHandler
 * @see ThreadGroup#uncaughtException
 * @since 1.5
 */
public void setUncaughtExceptionHandler(UncaughtExceptionHandler eh) {
    checkAccess();
    uncaughtExceptionHandler = eh;
}

㈠：“设置当此线程由于未捕获异常突然终止时调用的处理程序”。方法注释已经明确告知我们方法的用途了，并且还告诉我们，如果我们没有设置该handler那么ThreadGroup将充当handler进行处理，那么我们在看下在哪里调用了getter方法。

其实Thread类中还有另一个设置处理器的方法，java.lang.Thread#setDefaultUncaughtExceptionHandler，这是一个静态方法，设置的handler是一个全局处理器，及当我们没有设置handler时，回去找这个默认的handler，如果还是没有的话ThreadGroup会进行处理。

2.2.2 java.lang.Thread#dispatchUncaughtException

/**
 * Dispatch an uncaught exception to the handler.
 * This method is intended to be called only by the JVM.
 */
private void dispatchUncaughtException(Throwable e) {
    getUncaughtExceptionHandler().uncaughtException(this, e);
}
 
 
/**
 * Returns the handler invoked when this thread abruptly terminates
 * due to an uncaught exception. If this thread has not had an
 * uncaught exception handler explicitly set then this thread's
 * <tt>ThreadGroup</tt> object is returned, unless this thread
 * has terminated, in which case <tt>null</tt> is returned.
 * @since 1.5
 * @return the uncaught exception handler for this thread
 */
public UncaughtExceptionHandler getUncaughtExceptionHandler() {
    return uncaughtExceptionHandler != null ?
        uncaughtExceptionHandler : group;
}

最终在dispatchUncaughtException方法中找到调用了getUncaughtExceptionHandler方法，但是想再继续找Thread 内部谁调用了dispatchUncaughtException时，却没有找到任何调用的地方，并且该方法为private 修饰那么外部是不可能调用的。

当看到方法注释后如醍醐灌顶，"调用处理器处理异常，该方法只有JVM调用"，划重点了。（JVM老大，你说啥就是啥，你想怎么调都行）

默认情况下我们是没有设置handler的，所以这里会返回ThreadGroup的实例，所以我们直接来看ThreadGroup类中uncaughtException的实现

2.2.3 java.lang.ThreadGroup#uncaughtException

/**
 * Called by the Java Virtual Machine when a thread in this
 * thread group stops because of an uncaught exception, and the thread
 * does not have a specific {@link Thread.UncaughtExceptionHandler}
 * installed.
 * <p>
 * The <code>uncaughtException</code> method of
 * <code>ThreadGroup</code> does the following:
 * <ul>
 * <li>If this thread group has a parent thread group, the
 *     <code>uncaughtException</code> method of that parent is called
 *     with the same two arguments.
 * <li>Otherwise, this method checks to see if there is a
 *     {@linkplain Thread#getDefaultUncaughtExceptionHandler default
 *     uncaught exception handler} installed, and if so, its
 *     <code>uncaughtException</code> method is called with the same
 *     two arguments.
 * <li>Otherwise, this method determines if the <code>Throwable</code>
 *     argument is an instance of {@link ThreadDeath}. If so, nothing
 *     special is done. Otherwise, a message containing the
 *     thread's name, as returned from the thread's {@link
 *     Thread#getName getName} method, and a stack backtrace,
 *     using the <code>Throwable</code>'s {@link
 *     Throwable#printStackTrace printStackTrace} method, is
 *     printed to the {@linkplain System#err standard error stream}.
 * </ul>
 * <p>
* Applications can override this method in subclasses of
* <code>ThreadGroup</code> to provide alternative handling of
* uncaught exceptions.
*
* @param   t   the thread that is about to exit.
* @param   e   the uncaught exception.
* @since   JDK1.0
*/
public void uncaughtException(Thread t, Throwable e) {
    if (parent != null) {
        parent.uncaughtException(t, e);
    } else {
        Thread.UncaughtExceptionHandler ueh =
            Thread.getDefaultUncaughtExceptionHandler();
        if (ueh != null) {
            ueh.uncaughtException(t, e);
        } else if (!(e instanceof ThreadDeath)) {
            // 该日志是不会记录到日志文件中的，如果环境是tomcat的话最终会打到catalina.out，在本地的话标准异常输出就对应着我们的控制台，正如示例中我们在控制台看到了日志输出。
            System.err.print("Exception in thread \""
                             + t.getName() + "\" ");
            e.printStackTrace(System.err);
        }
    }
}

方法注释很长，但是传递给我们的信息确是非常重要的，这里阐述了该方法的执行机制：

当线程因为未捕获异常终止切没有设置异常处理器时，会调用该方法。
如果ThreadGroup有parent，则调用parent.uncaughtException()。
如果ThreadGroup没有parent时

>调用Thread.getDefaultUncaughtExceptionHandler()获取全局处理器，如果获取到则进行处理

>如果没有获取到全局处理器且异常不是ThreadDeath类型，通过System.err.print()打印日志，且打印了堆栈信息，该输出日志不会打印到日志文件中，如果环境是tomcat的话最终会打到catalina.out。这里就和我们“示例”程序中的输出对应上了，是不是非(hui)常开心

方法上也说明，我们可以自定义类继承ThreadGroup来覆写uncaughtException 方法提供额外的处理。

3、异常处理

通过以上代码的跟踪与梳理，我们至少可以采用如四种方式进行异常处理

3.1、最简单的方式

直接在我们的业务方法中直接try-catch捕获所有的异常，直接在catch块中进行异常处理。

3.2、自定义ThreadPoolExecutor类

public class CustomThreadPoolExecutor extends ThreadPoolExecutor {
    @Override
    protected void afterExecute(Runnable r, Throwable t) {
        super.afterExecute(r, t);
        //自定义异常的处理逻辑
    }
}

java.util.concurrent.ThreadPoolExecutor.Worker 是线程池内部正真干事儿的，最终会调用java.util.concurrent.ThreadPoolExecutor#runWorker，该方法在调用执行业务方法前后都有回调方法，在finally块中会回调afterExecute(Runnable r, Throwable t)，所以我们可以利用这个回调方法处理可能抛出的异常。

3.3、自定义ThreadGroup类

public class CustomThreadGroup extends ThreadGroup {
    @Override
    public void uncaughtException(Thread t, Throwable e) {
        super.uncaughtException(t, e);
        //自定义异常的处理逻辑
    }
}
 
//创建线程池时自定义创建线程，并给线程设置自定义的CustomThreadGroup
ThreadPoolExecutor threadPool = new ThreadPoolExecutor(1, 1, 1, TimeUnit.MINUTES, new LinkedBlockingQueue<>(10), new ThreadFactory() {
        @Override
        public Thread newThread(Runnable r) {
            return new Thread(new CustomThreadGroup("CustomThreadGroup"), r);
        }
});

在我们没有设置UncaughtExceptionHandler时，最终会有ThreadGroup来处理未捕获的异常，所以我们可以自定义ThreadGroup类覆写uncaughtException方法添加额外的异常处理。

3.4、设置UncaughtExceptionHandler

public class CustomUncaughtExceptionHandler implements UncaughtExceptionHandler {
 
    @Override
    public void uncaughtException(Thread t, Throwable e) {
        //自定义异常处理逻辑
    }
}
 
//创建线程池时自定义创建线程，并给线程设置自定义的UncaughtExceptionHandler
ThreadPoolExecutor threadPool = new ThreadPoolExecutor(1, 1, 1, TimeUnit.MINUTES, new LinkedBlockingQueue<>(10), new ThreadFactory() {
        @Override
        public Thread newThread(Runnable r) {
            Thread thread = new Thread(r);
            thread.setUncaughtExceptionHandler(new CustomUncaughtExceptionHandler());
             
            return thread;
        }
});

这种方式设置异常处理器更加灵活，我更倾向于使用该种方式，另外我们也可以调用java.lang.Thread#setDefaultUncaughtExceptionHandler 设置一个全局的默认异常处理器，但是通过给每个线程设置异常处理器更加便于我们管理，这个我们可以酌情使用。

4、总结

java线程池会捕获任务抛出的异常和错误，处理策略会受到我们提交任务的方式而不同。
submit()方式提交的任务会返给我们一个Future，如果业务方法有抛出异常，当我们调用java.util.concurrent.Future#get()方法时会抛出包装后的java.util.concurrent.ExecutionException。
execute()方式提交的任务，java处理的默认策略是使用System.err.print("Exception in thread \"" + t.getName() + "\" ")输出日志，但是该日志不会打印到我们的日志文件中，如果线上环境是tomcat的话最终会打到catalina.out文件中。
可以修改java线程池的默认处理策略，具体修改方式见上面 “第3点、异常处理”

至此，对java线程池内部针对异常处理有了一个深入的了解。

posted @ 2019-09-05 14:40 Laymen 阅读(6750) 评论(3) 编辑收藏举报

会员力量，点亮园子希望

刷新页面返回顶部

Laymen