Logback вызывает замораживание потока при входе в систему из дочернего процесса

#java #logback #slf4j

Вопрос:

Я столкнулся со странной проблемой с logback, которая ЗАМОРАЖИВАЕТ поток при попытке входа в созданный дочерний java-процесс. Кратко описано, как показано ниже:

Родительский процесс создает 1 дочерний процесс
В дочернем процессе use logback печатает 1000 строк.

Примечание:

Ведение журнала выводится на консоль
Замораживание приложения
Проблема не возникает, когда: запускайте непосредственно дочерний процесс (без родительского процесса); или регистрируйтесь только в файле (без журнала консоли)

Я нажимаю простой код, который вызывает это явление: https://github.com/huymluu/logbackfreeze

РЕДАКТИРОВАТЬ: добавить дамп потока

 "process reaper@687" daemon prio=10 tid=0xc nid=NA runnable
  java.lang.Thread.State: RUNNABLE
      at java.lang.UNIXProcess.waitForProcessExit(UNIXProcess.java:-1)
      at java.lang.UNIXProcess.lambda$initStreams$3(UNIXProcess.java:290)
      at java.lang.UNIXProcess$$Lambda$7.687241927.run(Unknown Source:-1)
      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)

"main@1" prio=5 tid=0x1 nid=NA waiting
  java.lang.Thread.State: WAITING
      at java.lang.Object.wait(Object.java:-1)
      at java.lang.Object.wait(Object.java:502)
      at java.lang.UNIXProcess.waitFor(UNIXProcess.java:396)
      at parent.ParentProcess.main(ParentProcess.java:20)

"Finalizer@689" daemon prio=8 tid=0x3 nid=NA waiting
  java.lang.Thread.State: WAITING
      at java.lang.Object.wait(Object.java:-1)
      at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:143)
      at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:164)
      at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:209)

"Reference Handler@690" daemon prio=10 tid=0x2 nid=NA waiting
  java.lang.Thread.State: WAITING
      at java.lang.Object.wait(Object.java:-1)
      at java.lang.Object.wait(Object.java:502)
      at java.lang.ref.Reference.tryHandlePending(Reference.java:191)
      at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:153)

"Signal Dispatcher@688" daemon prio=9 tid=0x4 nid=NA runnable
  java.lang.Thread.State: RUNNABLE

1. Это довольно интересно, похоже System.out.println на взаимоблокировку или что-то в этом роде. Не могли бы вы добавить дамп потока после зависания приложения? Один для родительского процесса и один для дочернего процесса. Для дочернего процесса было бы много потоков, но большинство из них должны быть практически одинаковыми; нам нужны уникальные трассировки стека.

Ответ №1:

Я думаю, что у logback есть проблема с консольным выводом дочернего процесса. Просто не знаю подробностей, почему это произошло.

Попытка перенаправить вывод дочернего процесса решит эту проблему. например redirectOutput() , использование ProcessBuilder :

 ProcessBuilder.redirectOutput(new File("/dev/null"));