Thread dies необъяснимо

Question

У меня есть процесс Java, который недавно начал использовать 100% процессорное время. Использование 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, thread OrderServiceScheduler-резьбовых 151389734 isn't listed in the output of threads`):

> 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 из ThreadPoolExecutor, но вместо этого нить умирает. Зачем?

Для справки это выполняется на JDK 1.7.0_07 на хосте Solaris x86.

Единственное изменение, которое я сделал, это добавление клиентской библиотеки ActiveMQ. Мое подозрение заключается в том, что это связано с добавлением slf4j (в частности, slf4j-api-1.6.6.jar и slf4j-log4j12-1.6.6.jar) к пути к классам, но я не могу это доказать.

UPDATE

Я изменил выполненное задание как отдельный класс:

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, чтобы узнать, имеет ли это значение.

UPDATE 2

Это было связано с установкой размера основного бассейна к нулю, так как Петр Lawrey коснулся его ответа. Однако вместо того, чтобы не вызвать ничего, что могло бы привести к запуску, он вызвал немедленный выход .Суть метода выглядит следующим образом:

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

Установка размера основного пула вызывает getTask вернуть null без блокировки для задачи, которые будут представлены. Это приводит к выходу цикла, processWorkerExit, затем получает вызов, который создает другой поток для замены выходящего.

Я считаю, что проблемы, которые я видел с отладчиком, были связаны с кодом JIT'ed. Я поставил в заводе Thread.sleep на фабрику нитей, чтобы замедлить создание потоков, что означало, что у меня было время подключить отладчик до того, как были применены какие-либо оптимизации.

TL; DR: Я идиот.

UPDATE 3

Для всех, кто может прийти через это в будущем ... Там другая similar question on SO что упоминает это поведение изменилось в Java 7. До изменения, имеющие размер ядра нуля будет , как предположил Питер Лоури, не создает нити, которые когда-либо создавались бы (bug report). A change был включен, чтобы создать один поток, который, по-видимому, влияет на то, что потоки будут создаваться повторно. Это можно воспроизвести с кодом, очень похожим на тестовый пример в отчете об ошибке:

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); 
    } 
} 

Answer 1

Я неправильно понял проблему. Вы предполагаете, что сам поток убивается и перезапускается? Вы задаете размер ядра 0, который вряд ли сделает то, что вы хотите. Я бы ожидал, что он не создаст нить, в этом случае ваши потоки никогда не будут выполняться, или она создаст поток для каждой задачи (я подозреваю, что нет).

Я бы не установить размер ядра на всех и просто использовать Executors.newSingleThreadScheduledExecutor (ThreadFactory threadFactory) Игра с размером ядра редко делает именно то, что вы хотели бы это сделать в моем опыте;)

Если это проблема в том, что он должен делать то же самое на вашем локальном ПК, и вам не нужно выполнять удаленную отладку.

Скорее всего, вы выбрасываете ошибку, которая отбрасывается. Это очень легко сделать, и это обычный случай, когда нити молчат. Я предлагаю вам следовать этой схеме.

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(); 
    } 
} 

Вы можете определить AbstractRunnable с помощью метода final run(), чтобы обернуть это. Это необходимо только в том случае, если вы не проверяете возвращение в будущем, чтобы проверить наличие сбоев. (Я подозреваю, что вы отбрасываете этот объект)