Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

All threads blocked #786

Open
koszta5 opened this issue Mar 4, 2024 · 6 comments
Open

All threads blocked #786

koszta5 opened this issue Mar 4, 2024 · 6 comments

Comments

@koszta5
Copy link

koszta5 commented Mar 4, 2024

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(java.base@11.0.19/Native Method) - parking to wait for <0x00000000e0c37af0> (a java.util.concurrent.locks.ReentrantLock$NonfairSync) at java.util.concurrent.locks.LockSupport.park(java.base@11.0.19/LockSupport.java:194) at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(java.base@11.0.19/AbstractQueuedSynchronizer.java:885) at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(java.base@11.0.19/AbstractQueuedSynchronizer.java:917) at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(java.base@11.0.19/AbstractQueuedSynchronizer.java:1240) at java.util.concurrent.locks.ReentrantLock.lock(java.base@11.0.19/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: #767
@sunl888
Copy link

sunl888 commented Apr 3, 2024

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

@koszta5
Copy link
Author

koszta5 commented Apr 3, 2024

well that is not resolving this problem :(

@ceki
Copy link
Member

ceki commented Apr 3, 2024 •
edited

@koszta5 Under which JDK version is this occurring?

@koszta5
Copy link
Author

koszta5 commented Apr 4, 2024

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)

@jinshuai86
Copy link

jinshuai86 commented Apr 16, 2024 •
edited

@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)

@koszta5
Copy link
Author

koszta5 commented May 2, 2024

Sorry, but no - if you examine e.g. my very recent thread dump here:
https://jstack.review/

You will find out that all my threads are simply WAITING for a lock that is now lost (no other thread is holding it)
stuckLogback.threads.txt

Lock 0x0000000701dc5ff0 is completely lost to the JVM :( Causing the whole app to get stuck

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
4 participants
@ceki @koszta5 @sunl888 @jinshuai86