0

我有一个最近开始使用 100% CPU 时间的 Java 进程。使用jdb我发现这是由ThreadPoolExecutor重复创建线程引起的。

有问题的执行人定义为：

private final ScheduledExecutorService _scheduler = Executors.newScheduledThreadPool(0, new NamedThreadFactory("OrderServiceScheduler", true, null));

唯一计划的任务是：

_scheduler.scheduleAtFixedRate(new Runnable() { @Override public void run() {  s_log.info("Resetting order books"); _liveOrderBook.clear(); } }, 
                               midnightTodayInMs, 
                               TimeUnit.MILLISECONDS.convert(1, TimeUnit.DAYS), 
                               TimeUnit.MILLISECONDS);

日志语句永远不会被打印（我有 99% 的把握INFO为此记录器启用了级别日志记录）。

我第一次trace go methods在 jdb 中运行，看到了很多行，例如：

Method entered: "thread=OrderServiceScheduler-thread-22237794", com.kbcfp.util.NamedThreadFactory.newThread(), line=45 bci=0
Method entered: "thread=OrderServiceScheduler-thread-22237794", org.apache.log4j.helpers.ThreadLocalMap.childValue(), line=34 bci=0
Method exited: return value = null, "thread=OrderServiceScheduler-thread-22237794", org.apache.log4j.helpers.ThreadLocalMap.childValue(), line=38 bci=15
Method exited: return value = instance of java.lang.Thread(name='OrderServiceScheduler-thread-22237795', id=6388), "thread=OrderServiceScheduler-thread-22237794", com.kbcfp.util.NamedThreadFactory.newThread(), line=52 bci=68

所以我设置了一个断点org.apache.log4j.helpers.ThreadLocalMap.childValue并继续进行，直到线程意外停止执行（紧接在最后一个next, threadOrderServiceScheduler-thread-151389734 线程isn't listed in the output of之后）：

> stop in org.apache.log4j.helpers.ThreadLocalMap.childValue
Set breakpoint org.apache.log4j.helpers.ThreadLocalMap.childValue
>
Breakpoint hit: "thread=OrderServiceScheduler-thread-151389734", org.apache.log4j.helpers.ThreadLocalMap.childValue(), line=34 bci=0

OrderServiceScheduler-thread-151389734[1] clear org.apache.log4j.helpers.ThreadLocalMap.childValue
Removed: breakpoint org.apache.log4j.helpers.ThreadLocalMap.childValue
OrderServiceScheduler-thread-151389734[1] where
  [1] org.apache.log4j.helpers.ThreadLocalMap.childValue (ThreadLocalMap.java:34)
  [2] java.lang.ThreadLocal$ThreadLocalMap.<init> (ThreadLocal.java:353)
  [3] java.lang.ThreadLocal$ThreadLocalMap.<init> (ThreadLocal.java:261)
  [4] java.lang.ThreadLocal.createInheritedMap (ThreadLocal.java:236)
  [5] java.lang.Thread.init (Thread.java:401)
  [6] java.lang.Thread.<init> (Thread.java:652)
  [7] com.kbcfp.util.NamedThreadFactory.newThread (NamedThreadFactory.java:45)
  [8] java.util.concurrent.ThreadPoolExecutor$Worker.<init> (ThreadPoolExecutor.java:598)
  [9] java.util.concurrent.ThreadPoolExecutor.addWorker (ThreadPoolExecutor.java:913)
  [10] java.util.concurrent.ThreadPoolExecutor.processWorkerExit (ThreadPoolExecutor.java:992)
  [11] java.util.concurrent.ThreadPoolExecutor.runWorker (ThreadPoolExecutor.java:1,128)
  [12] java.util.concurrent.ThreadPoolExecutor$Worker.run (ThreadPoolExecutor.java:603)
  [13] java.lang.Thread.run (Thread.java:722)
OrderServiceScheduler-thread-151389734[1] next
>
Step completed: "thread=OrderServiceScheduler-thread-151389734", org.apache.log4j.helpers.ThreadLocalMap.childValue(), line=35 bci=5

OrderServiceScheduler-thread-151389734[1] next
>
Step completed: "thread=OrderServiceScheduler-thread-151389734", org.apache.log4j.helpers.ThreadLocalMap.childValue(), line=38 bci=14

OrderServiceScheduler-thread-151389734[1] next
>
Step completed: "thread=OrderServiceScheduler-thread-151389734", com.kbcfp.util.NamedThreadFactory.newThread(), line=45 bci=40

OrderServiceScheduler-thread-151389734[1] next
>
Step completed: "thread=OrderServiceScheduler-thread-151389734", com.kbcfp.util.NamedThreadFactory.newThread(), line=48 bci=41

OrderServiceScheduler-thread-151389734[1] next
>
Step completed: "thread=OrderServiceScheduler-thread-151389734", com.kbcfp.util.NamedThreadFactory.newThread(), line=49 bci=49

OrderServiceScheduler-thread-151389734[1] next
>
Step completed: "thread=OrderServiceScheduler-thread-151389734", com.kbcfp.util.NamedThreadFactory.newThread(), line=52 bci=67

OrderServiceScheduler-thread-151389734[1] next
>

我们的NamedThreadFactory班级没有做任何令人兴奋的事情：

  44: public Thread newThread(Runnable r) {
  45:   Thread t = new Thread(_group, r,
  46:       _namePrefix + _threadNumber.getAndIncrement(),
  47:       0);
  48:   t.setDaemon(_makeDaemon);
  49:   if(_overridePriority != null) {
  50:     t.setPriority(_overridePriority);
  51:   }
  52:   return t;
  53: }

据我所知，下一行执行应该是 914 of ThreadPoolExecutor，但是线程反而死掉了。为什么？

作为参考，这是在 Solaris x86 主机上的 JDK 1.7.0_07 上运行的。

我所做的唯一更改是添加了 ActiveMQ 的客户端库。我怀疑这与在类路径中添加 slf4j （特别slf4j-api-1.6.6.jar是 和slf4j-log4j12-1.6.6.jar）有关，但我无法证明这一点。

更新

我已将执行的任务更改为单独的类：

public class TestingFoo implements Runnable 
{
  private final Logger s_log;

  public TestingFoo(final Logger log)
  {
    s_log = log;
  }

  @Override 
  public void run() 
  {  
    try
    {
      s_log.info("Resetting order books"); 
  //    _liveOrderBook.clear(); 
    }
    catch (final Throwable t)
    {
      t.printStackTrace();
    }
  }
}

我jdb在该行设置了一个断点，log.info它没有被击中。此外，我没有看到在 stderr （或 log4j 文件）上打印堆栈跟踪。此外，我在s_log.info安排任务之前放了另一行，那就是行

我现在正在下载 JDK 1.7.0_21 看看这是否有所作为。

更新 2

这是由于将核心池大小设置为零，因为彼得劳里谈到了他的答案。但是，它并没有导致什么都不运行，而是导致ThreadPoolExecutor'runWorker方法立即退出。该方法的要点如下：

runWorker(Worker) {
    ...
    while (task != null || (task = getTask()) != null) {
      ...
      task.run();
      ...
    }
    processWorkerExit(..);
}

设置核心池大小会导致getTask返回null而不阻塞要提交的任务。这会导致循环退出，processWorkerExit然后被调用，从而创建另一个线程来替换退出的线程。

我相信我在调试器中看到的问题是由于 JIT 的代码。我放了一个Thread.sleep线程工厂中添加了一条语句来减慢线程的创建速度，这意味着我有时间在应用任何优化之前附加调试器。

TL;DR：我是个白痴。

更新 3

对于将来可能遇到此问题的任何人...关于 SO 的另一个类似问题提到此行为在 Java 7 中已发生变化。在更改之前，正如 Peter Lawrey 所建议的那样，核心大小为零会导致没有线程永远被创建（错误报告）。进行了一项更改以确保创建一个线程，这似乎具有导致线程被重复创建的效果。这可以使用与错误报告中的测试用例非常相似的代码来重现：

import java.util.concurrent.Executors;
import java.util.concurrent.ScheduledExecutorService;
import java.util.concurrent.TimeUnit;

class ScheduledExecutorTest {
    public static void main(String[] args) throws InterruptedException {
        final ScheduledExecutorService ex = Executors.newScheduledThreadPool(0);
        ex.scheduleWithFixedDelay(new Runnable() {
            @Override
            public void run() {
                System.out.println("hello");
            }
        }, 1, 1, TimeUnit.SECONDS);

        while (true)
            Thread.sleep(1000);
    }
}
4

1 回答 1

2

我误解了这个问题。您是在暗示线程本身被杀死并重新启动？您将核心大小设置为 0，这不太可能满足您的要求。我希望它要么不创建线程，在这种情况下你的线程将永远不会运行，要么它会为每个任务创建一个线程（我怀疑不是）。

我根本不会设置核心大小，只使用 Executors.newSingleThreadScheduledExecutor(ThreadFactory threadFactory) 玩核心大小很少完全符合我的经验；）

如果这是问题所在，它应该在您的本地 PC 上执行完全相同的操作，并且您不需要进行远程调试。

您很可能会抛出一个被丢弃的错误。这很容易完成，并且是线程静默死亡的常见情况。我建议你遵循这个模式。

new Runnable() { 
    @Override public void run() {
        try {
            run0();
        } catch(Throwable t) { // this will catch everything not just Exceptions.
            // log t or print it
        }
    }
    void run0() {
        s_log.info("Resetting order books");
        _liveOrderBook.clear(); 
    } 
}

您可以使用最终的 run() 方法定义 AbstractRunnable 来包装它。仅当您不轮询 Future 返回以检查失败时才需要它。（我怀疑你正在丢弃这个对象）

于 2013-06-05T06:23:25.560 回答