为什么Throwable::printStackTrace持有PrintStream的锁并导致logback的死锁?

在使用 e.printStackTrace() 并在不同的线程中进行logback。线程转储如下。

在我看来,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.netbrowseJDK-6719464。但没有答案。

解决方案:

如果logback工作线程不能完成,一定是因为它的阻塞队列已满。工作线程正在等待存入它的日志条目,由于线程是waiting,我们知道它释放了队列的锁,但它仍然持有打印流的锁。控制台写入线程在试图获取打印流上的锁时被锁住了,而它需要这个锁来写入控制台,因此它们是死锁的。

一个最小的修复方法是将控制台应用程序换成不需要获取打印流上的锁的程序,这样可以避免代码变化。

在任何情况下,需要获取打印流上的锁可能会减少异步日志的好处。长期的修复方法是用调用日志记录器(如 slf4j)来代替 printlns。

给TA打赏
共{{data.count}}人
人已打赏
未分类

在PHP本地soapClient中的SoapRequest格式化。

2022-9-9 3:40:19

未分类

最多匹配两个词的Regex [关闭] 。

2022-9-9 3:40:21

0 条回复 A文章作者 M管理员
    暂无讨论,说说你的看法吧
个人中心
购物车
优惠劵
今日签到
有新私信 私信列表
搜索