[logback-dev] [JIRA] (LOGBACK-1711) Deadlock when using Virtual Threads

[QOS.CH (JIRA)]

Title: Message Title

Gili commented on LOGBACK-1711   Re: Deadlock when using Virtual Threads I think I got something. I enabled -Djdk.tracePinnedThreads=full as Alan suggested and it flagged one problematic stack trace: Thread[#87,ForkJoinPool-1-worker-5,5,CarrierThreads] java.base/java.lang.VirtualThread$VThreadContinuation.onPinned(VirtualThread.java:180) java.base/jdk.internal.vm.Continuation.onPinned0(Continuation.java:398) java.base/jdk.internal.vm.Continuation.yield0(Continuation.java:390) java.base/jdk.internal.vm.Continuation.yield(Continuation.java:357) java.base/java.lang.VirtualThread.yieldContinuation(VirtualThread.java:370) java.base/java.lang.VirtualThread.park(VirtualThread.java:499) java.base/java.lang.System$2.parkVirtualThread(System.java:2606) java.base/jdk.internal.misc.VirtualThreads.park(VirtualThreads.java:54) java.base/java.util.concurrent.locks.LockSupport.park(LockSupport.java:219) java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:715) java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:938) java.base/java.util.concurrent.locks.ReentrantLock$Sync.lock(ReentrantLock.java:153) java.base/java.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:322) ch.qos.logback.core.rolling.RollingFileAppender.rollover(RollingFileAppender.java:186) ch.qos.logback.core.rolling.RollingFileAppender.subAppend(RollingFileAppender.java:236) <== monitors:1 ch.qos.logback.core.OutputStreamAppender.append(OutputStreamAppender.java:102) ch.qos.logback.core.UnsynchronizedAppenderBase.doAppend(UnsynchronizedAppenderBase.java:85) ch.qos.logback.core.spi.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:51) ch.qos.logback.classic.Logger.appendLoopOnAppenders(Logger.java:272) ch.qos.logback.classic.Logger.callAppenders(Logger.java:259) ch.qos.logback.classic.Logger.buildLoggingEventAndAppend(Logger.java:426) ch.qos.logback.classic.Logger.filterAndLog_1(Logger.java:402) ch.qos.logback.classic.Logger.debug(Logger.java:491) Testcase.lambda$run$0(Testcase.java:37) java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:577) java.base/java.util.concurrent.ThreadPerTaskExecutor$ThreadBoundFuture.run(ThreadPerTaskExecutor.java:352) java.base/java.lang.VirtualThread.run(VirtualThread.java:287) java.base/java.lang.VirtualThread$VThreadContinuation.lambda$new$0(VirtualThread.java:174) java.base/jdk.internal.vm.Continuation.enter0(Continuation.java:327) java.base/jdk.internal.vm.Continuation.enter(Continuation.java:320) Here is my interpretation of what is going on: A virtual thread acquires a monitor (synchronized lock) at ch.qos.logback.core.rolling.RollingFileAppender.subAppend(RollingFileAppender.java:236) It then attempts to rollover() the log file, but this attempts to acquire a ReentrantLock. For reasons I cannot explain, another thread seems to be holding the ReentrantLock. Because the carrier thread is pinned, it is forced to block. So the deadlock situation is as follows: One virtual thread is holding the monitor and waiting on the ReentrantLock, and all other threads are waiting to acquire the monitor. What I don't understand is who is holding onto the ReentrantLock. It's probably another appender, but I can't tell which. This thread must have locked the ReentrantLock first and is now trying to acquire the monitor. Hence, the deadlock. Add Comment   This message was sent by Atlassian Jira (v8.8.0#808000-sha1:e2c7e59)

_______________________________________________
logback-dev mailing list
logback-dev@qos.ch
https://mailman.qos.ch/cgi-bin/mailman/listinfo/logback-dev