logback icon indicating copy to clipboard operation
logback copied to clipboard

Published 20 hours ago • verified publisher icon qos-ch

All threads blocked

Open koszta5 opened this issue 4 months ago • 5 comments

Logback version :1.2.11 Springboot version: 2.7.4

Apparently in some cases all locks are lost and logback is just "stuck" - only restart helps. Thread dump is attached StuckLogback.threads.txt

All threads remain in this state WAITING for lock endlessly "http-nio-8184-exec-1" #139 daemon prio=5 os_prio=0 cpu=53544.34ms elapsed=232090.85s tid=0x00002af5d1b77800 nid=0x15fe7 waiting on condition [0x00002af676207000] java.lang.Thread.State: WAITING (parking) at jdk.internal.misc.Unsafe.park([email protected]/Native Method) - parking to wait for <0x00000000e0c37af0> (a java.util.concurrent.locks.ReentrantLock$NonfairSync) at java.util.concurrent.locks.LockSupport.park([email protected]/LockSupport.java:194) at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt([email protected]/AbstractQueuedSynchronizer.java:885) at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued([email protected]/AbstractQueuedSynchronizer.java:917) at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire([email protected]/AbstractQueuedSynchronizer.java:1240) at java.util.concurrent.locks.ReentrantLock.lock([email protected]/ReentrantLock.java:267) at ch.qos.logback.core.OutputStreamAppender.writeBytes(OutputStreamAppender.java:197) at ch.qos.logback.core.OutputStreamAppender.subAppend(OutputStreamAppender.java:231) at ch.qos.logback.core.OutputStreamAppender.append(OutputStreamAppender.java:102) at ch.qos.logback.core.UnsynchronizedAppenderBase.doAppend(UnsynchronizedAppenderBase.java:84) at ch.qos.logback.core.spi.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:51) at ch.qos.logback.classic.Logger.appendLoopOnAppenders(Logger.java:270) at ch.qos.logback.classic.Logger.callAppenders(Logger.java:257) at ch.qos.logback.classic.Logger.buildLoggingEventAndAppend(Logger.java:421) at ch.qos.logback.classic.Logger.filterAndLog_1(Logger.java:398) at ch.qos.logback.classic.Logger.debug(Logger.java:486) at com.ourcomapany.integration.distribution.v2.delivery.TokenService.addToCache(TokenService.java:233)

This bug is very closely related to issue originally reported here: https://jira.qos.ch/projects/LOGBACK/issues/LOGBACK-1406?filter=allopenissues (same thing really). It is also similar to this: https://github.com/qos-ch/logback/issues/767

koszta5 avatar Mar 04 '24 09:03 koszta5

I also encountered this issue, it will be resolved after restarting jstack.txt

sunl888 avatar Apr 03 '24 09:04 sunl888

well that is not resolving this problem :(

koszta5 avatar Apr 03 '24 09:04 koszta5

@koszta5 Under which JDK version is this occurring?

ceki avatar Apr 03 '24 09:04 ceki

openjdk version "11.0.19" 2023-04-18 OpenJDK Runtime Environment Temurin-11.0.19+7 (build 11.0.19+7) OpenJDK 64-Bit Server VM Temurin-11.0.19+7 (build 11.0.19+7, mixed mode)

koszta5 avatar Apr 04 '24 08:04 koszta5

@koszta5 Under which JDK version is this occurring?

Can you take a look at the problem in the link? https://jira.qos.ch/browse/LOGBACK-1406

It's very similar to this issue, I've also encountered this problem. only one thread(Thread 507 belows) BLOCKED in FileOutputStream.writeBytes() , other threads(Thread 402 belows) BLOCKED in OutputStreamAppender.subAppend()

Thread 507: (state = BLOCKED)

  • java.io.FileOutputStream.writeBytes(byte[], int, int, boolean) @bci=0 (Compiled frame; information may be imprecise)
  • java.io.FileOutputStream.write(byte[], int, int) @bci=8, line=326 (Compiled frame)
  • java.io.BufferedOutputStream.write(byte[], int, int) @bci=20, line=122 (Compiled frame)
  • java.io.PrintStream.write(byte[], int, int) @bci=16, line=480 (Compiled frame)
  • java.io.FilterOutputStream.write(byte[]) @bci=5, line=97 (Compiled frame)
  • ch.qos.logback.core.joran.spi.ConsoleTarget$1.write(byte[]) @bci=4, line=37 (Compiled frame)
  • ch.qos.logback.core.encoder.LayoutWrappingEncoder.doEncode(java.lang.Object) @bci=20, line=131 (Compiled frame)
  • ch.qos.logback.core.OutputStreamAppender.writeOut(java.lang.Object) @bci=5, line=187 (Compiled frame)
  • ch.qos.logback.core.OutputStreamAppender.subAppend(java.lang.Object) @bci=33, line=212 (Compiled frame)
  • ch.qos.logback.core.OutputStreamAppender.append(java.lang.Object) @bci=10, line=100 (Compiled frame)
  • ch.qos.logback.core.UnsynchronizedAppenderBase.doAppend(java.lang.Object) @bci=123, line=84 (Compiled frame)
  • ch.qos.logback.core.spi.AppenderAttachableImpl.appendLoopOnAppenders(java.lang.Object) @bci=32, line=51 (Compiled frame)
  • ch.qos.logback.classic.Logger.appendLoopOnAppenders(ch.qos.logback.classic.spi.ILoggingEvent) @bci=12, line=270 (Compiled frame)
  • ch.qos.logback.classic.Logger.callAppenders(ch.qos.logback.classic.spi.ILoggingEvent) @bci=10, line=257 (Compiled frame)
  • ch.qos.logback.classic.Logger.buildLoggingEventAndAppend(java.lang.String, org.slf4j.Marker, ch.qos.logback.classic.Level, java.lang.String, java.lang.Object[], java.lang.Throwable) @bci=27, line=421 (Compiled frame)
  • ch.qos.logback.classic.Logger.filterAndLog_1(java.lang.String, org.slf4j.Marker, ch.qos.logback.classic.Level, java.lang.String, java.lang.Object, java.lang.Throwable) @bci=64, line=398 (Compiled frame)
  • ch.qos.logback.classic.Logger.info(java.lang.String, java.lang.Object) @bci=11, line=583 (Compiled frame)

Thread 402: (state = BLOCKED)

  • sun.misc.Unsafe.park(boolean, long) @bci=0 (Compiled frame; information may be imprecise)
  • java.util.concurrent.locks.LockSupport.park(java.lang.Object) @bci=14, line=175 (Compiled frame)
  • java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt() @bci=1, line=836 (Compiled frame)
  • java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(java.util.concurrent.locks.AbstractQueuedSynchronizer$Node, int) @bci=67, line=870 (Compiled frame)
  • java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(int) @bci=17, line=1199 (Compiled frame)
  • java.util.concurrent.locks.ReentrantLock$NonfairSync.lock() @bci=21, line=209 (Compiled frame)
  • java.util.concurrent.locks.ReentrantLock.lock() @bci=4, line=285 (Compiled frame)
  • ch.qos.logback.core.OutputStreamAppender.subAppend(java.lang.Object) @bci=28, line=210 (Compiled frame)
  • ch.qos.logback.core.OutputStreamAppender.append(java.lang.Object) @bci=10, line=100 (Compiled frame)
  • ch.qos.logback.core.UnsynchronizedAppenderBase.doAppend(java.lang.Object) @bci=123, line=84 (Compiled frame)
  • ch.qos.logback.core.spi.AppenderAttachableImpl.appendLoopOnAppenders(java.lang.Object) @bci=32, line=51 (Compiled frame)

jinshuai86 avatar Apr 16 '24 16:04 jinshuai86