0

我们有一个 ThreadPoolExecutor-back 任务执行模块。有些任务显然在应用程序代码中完成了,但是工作代码以某种方式跳过了所有的 try/catch/finally 并继续执行下一个任务,导致前一个任务错过了重要的状态报告代码。

就像在这个例子中一样,257832:5 被线程 8 拾取,但这个线程最终只是启动了另一个任务。

2012-07-11 15:53:39,389 信息 [pool-1-thread-6]:任务 (258861:5):开始。
2012-07-11 15:53:39,389 信息 [pool-1-thread-6]: 运行的任务 ### 由应用程序逻辑记录
2012-07-11 15:54:18,186 信息 [pool-1-thread-6]:任务 (258868:5):开始。###突然捡到一个!
2012-07-11 15:54:18,186 信息 [pool-1-thread-6]: 运行的任务 ### 由应用程序逻辑记录
2012-07-11 15:54:18,445 信息 [pool-1-thread-6]:任务 (258868:5):从 Task.doWork 返回。
2012-07-11 15:54:18,446 信息 [pool-1-thread-6]:任务 (258868:5):完成。
2012-07-11 15:54:18,487 信息 [pool-1-thread-6]:任务 (258868:5):通知状态结果:200。
2012-07-11 15:54:18,487 信息 [pool-1-thread-6]:任务 (258868:5):已完成

ThreadPoolExecutor 的 Runnable 看起来不错。看起来像

public void run() {
    log.info(String.format("Task (%s:%s) : Starting.", wfId, taskId));
    try {
        Object result = task.doWork(...); // call the application codes
        log.info(String.format("Task (%s:%s) : returned from Task.doWork.", wfId, taskId));
        status = "DONE";
    } catch (Throwable t) {
        log.error("Error executing task: " + taskId + " - " + className);
    } finally {
        log.info(String.format("Task (%s:%s) : finalizing.", wfId, taskId));
        // notify status to a server
        log.info(String.format("Task (%s:%s) : Finished", wfId, taskId));
    }
}
    // the task framework looks like
    // Use a queue size larger than numThreads, since the ThreadPoolExecutor#getActiveCount() call only returns an approximate count
    this.executor = new ThreadPoolExecutor(numThreads, numThreads, 60, TimeUnit.SECONDS, new ArrayBlockingQueue<Runnable>(numThreads * 2));
    executor.execute(new TaskRunnable(...));

笔记:

  1. 我们捕获了最终的 Throwable 但两个任务之间没有记录异常
  2. 没有迹象表明 exit() 被调用或程序重新启动
  3. 第一个跳过所有日志行,无论是在调用应用程序代码之后的那个还是在 catch 和 finally 块中的那个,并跳过状态报告代码
  4. 这只会以低概率随机发生;但是由于执行的任务量很大,还是让我们很头疼。

就好像线程池执行器只是神奇地驱逐了正在运行的可运行对象(否则它需要一个 InterruptedException,它会被捕获为 Throwable;Java 线程不会以非合作方式停止,除非在关闭/退出期间)并跳过所有块。我检查了 ThreeadPoolExecutor javadoc,没有什么会导致这样的事件发生。

可能发生了什么?

4

1 回答 1

0

没有出现 finally 块的日志消息的一种可能解释是,在 finally 块执行时引发了异常:

  • 如果log当时为空,您将获得 NPE。(如果log声明为final您可以将其作为可能的原因消除。)

  • 根据对象是什么,您可能会在wfIdortaskId对象的toString()方法中获得未经检查的异常。

  • Logger物体可能被破坏...


您也可能出于某种原因查看了错误的源代码。


另一个理论上的可能性是 Android 平台实现Thread.destroy()了实际做某事,并且在线程上调用了它。如果这个 DEPRECATED 方法是根据原始 javadoc 实现的,你会发现finally块没有被执行。也可以从 JVM 外部执行等效的操作。但如果这是发生的事情,所有的赌注都没有了!!

于 2012-07-12T02:43:53.893 回答