Почему Throwable :: printStackTrace удерживает блокировку PrintStream и вызывает тупиковую ситуацию при выходе из системы

Question

Обнаружена тупиковая ситуация при использовании e.printStackTrace() и вход в систему в разных потоках. Дампы дампов приведены ниже.

Мне кажется, что logback (используемый в потоке AsyncAppender-Worker-Thread-1) пытается получить блокировку PrintStream, которой уже владеет main thread s java.lang.Throwable$WrappedPrintStream.println. Если это так, почему printStackTrace продолжает удерживать блокировку PrintStream (как это должно быть снято после завершения печати)?

Дамп потока Для main thread.

"main@1" prio=5 tid=0x1 nid=NA waiting
  java.lang.Thread.State: WAITING
     blocks AsyncAppender-Worker-Thread-1@831
      at sun.misc.Unsafe.park(Unsafe.java:-1)
      at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
      at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
      at java.util.concurrent.ArrayBlockingQueue.put(ArrayBlockingQueue.java:353)
      at ch.qos.logback.core.AsyncAppenderBase.put(AsyncAppenderBase.java:139)
      at ch.qos.logback.core.AsyncAppenderBase.append(AsyncAppenderBase.java:130)
      at ch.qos.logback.core.UnsynchronizedAppenderBase.doAppend(UnsynchronizedAppenderBase.java:88)
      at ch.qos.logback.core.spi.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:48)
      at ch.qos.logback.classic.Logger.appendLoopOnAppenders(Logger.java:273)
      at ch.qos.logback.classic.Logger.callAppenders(Logger.java:260)
      at ch.qos.logback.classic.Logger.buildLoggingEventAndAppend(Logger.java:442)
      at ch.qos.logback.classic.Logger.filterAndLog_0_Or3Plus(Logger.java:396)
      at ch.qos.logback.classic.Logger.error(Logger.java:543)
      at com.side.stdlib.logging.StdOutErrLog$2.print(StdOutErrLog.java:43)
      at java.io.PrintStream.println(PrintStream.java:823)
      - locked <0x1183> (a com.side.stdlib.logging.StdOutErrLog$2)
      at java.lang.Throwable$WrappedPrintStream.println(Throwable.java:749)
      at java.lang.Throwable.printEnclosedStackTrace(Throwable.java:698)
      at java.lang.Throwable.printStackTrace(Throwable.java:668)
      at java.lang.Throwable.printStackTrace(Throwable.java:644)
      at java.lang.Throwable.printStackTrace(Throwable.java:635)
      at com.side.SidekApi.sideAPIExecution(SidekApi.java:175)

Дамп потока для потока AsyncAppender-Worker-Thread-1

"AsyncAppender-Worker-Thread-1@831" daemon prio=5 tid=0xe nid=NA waiting for monitor entry
  java.lang.Thread.State: BLOCKED
     waiting for main@1 to release lock on <0x1183> (a com.side.stdlib.logging.StdOutErrLog$2)
      at java.io.PrintStream.write(PrintStream.java:478)
      at java.io.FilterOutputStream.write(FilterOutputStream.java:97)
      at ch.qos.logback.core.joran.spi.ConsoleTarget$2.write(ConsoleTarget.java:55)
      at ch.qos.logback.core.encoder.LayoutWrappingEncoder.doEncode(LayoutWrappingEncoder.java:135)
      at ch.qos.logback.core.OutputStreamAppender.writeOut(OutputStreamAppender.java:194)
      at ch.qos.logback.core.OutputStreamAppender.subAppend(OutputStreamAppender.java:219)
      at ch.qos.logback.core.OutputStreamAppender.append(OutputStreamAppender.java:103)
      at ch.qos.logback.core.UnsynchronizedAppenderBase.doAppend(UnsynchronizedAppenderBase.java:88)
      at ch.qos.logback.core.spi.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:48)
      at ch.qos.logback.core.AsyncAppenderBase$Worker.run(AsyncAppenderBase.java:226)

Кажется, что ситуация немного похожа с https://bugs.openjdk.java.net/browse/JDK-6719464, но ответа нет.

Answer 1

Если рабочий поток logback не может завершить sh, это должно быть потому, что его очередь блокировки заполнена. Работник ждет, чтобы внести свою запись в журнал, и поскольку поток находится в ожидании, мы знаем, что он снял блокировку с очереди, но он все еще удерживает блокировку потока вывода. Поток записи консоли BLOCKED пытается получить блокировку потока печати, которая ему нужна для записи в консоль, поэтому они зашли в тупик.

Минимальное исправление, позволяющее избежать изменения кода, может привести к замене консоли. приложение для того, кому не нужно получать блокировку на принтстриме.

В любом случае необходимость блокировать поток печати может уменьшить выгоду от асинхронной регистрации. Долгосрочное исправление будет включать замену printlns на вызовы в логгер (например, slf4j).