Java 虚拟线程导致应用程序挂在 logback 中的 ReentrantLocks 上

Question

使用 Spring Boot 3.2.1 和 Tomcat 10 从 java 17 迁移到 java 21 后遇到问题。启用并使用虚拟线程（例如，我可以看到 tomcat 在处理请求时生成新的虚拟线程，执行 spring 计划任务在虚拟线程内）。

问题完全随机发生。在某些时候，应用程序会停止响应任何 HTTP 请求，包括弹簧执行器上的运行状况检查。我使用 jcmd 进行了线程转储，我注意到一些线程卡在 logback 可重入锁上。这包括虚拟和非虚拟线程。以下是一些示例：

#124 "org.springframework.kafka.KafkaListenerEndpointContainer#4-1-C-1"
      java.base/jdk.internal.misc.Unsafe.park(Native Method)
      java.base/java.util.concurrent.locks.LockSupport.park(LockSupport.java:221)
      java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:754)
      java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:990)
      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.OutputStreamAppender.writeBytes(OutputStreamAppender.java:200)
      ch.qos.logback.core.OutputStreamAppender.writeOut(OutputStreamAppender.java:193)
      ch.qos.logback.core.OutputStreamAppender.subAppend(OutputStreamAppender.java:237)
      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_0_Or3Plus(Logger.java:386)
      ch.qos.logback.classic.Logger.log(Logger.java:780)
      org.apache.kafka.common.utils.LogContext$LocationAwareKafkaLogger.writeLog(LogContext.java:434)
      org.apache.kafka.common.utils.LogContext$LocationAwareKafkaLogger.info(LogContext.java:382)

#229434 "scheduling-4181" virtual
      java.base/java.lang.VirtualThread.park(VirtualThread.java:582)
      java.base/java.lang.System$2.parkVirtualThread(System.java:2639)
      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:754)
      java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:990)
      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.OutputStreamAppender.writeBytes(OutputStreamAppender.java:200)
      ch.qos.logback.core.OutputStreamAppender.writeOut(OutputStreamAppender.java:193)
      ch.qos.logback.core.OutputStreamAppender.subAppend(OutputStreamAppender.java:237)
      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_0_Or3Plus(Logger.java:386)
      ch.qos.logback.classic.Logger.log(Logger.java:780)
      org.apache.kafka.common.utils.LogContext$LocationAwareKafkaLogger.writeLog(LogContext.java:434)
      org.apache.kafka.common.utils.LogContext$LocationAwareKafkaLogger.info(LogContext.java:382)
      org.apache.kafka.clients.consumer.KafkaConsumer.subscribe(KafkaConsumer.java:912)
      org.apache.kafka.clients.consumer.KafkaConsumer.subscribe(KafkaConsumer.java:944)

有一些 Kafka 消费者与 Spring 上下文一起启动，还有一些仅在 Spring 计划任务期间启动（这些消费者绑定到虚拟线程）。

此外，我可以看到很多具有完全空堆栈帧的tomcat虚拟线程，例如：

#230463 "tomcat-handler-109939" virtual

本来应该承载虚拟线程的线程并没有100%被利用，我可以看到其中一些确实承载了虚拟线程：

#241 "ForkJoinPool-3-worker-4"
      java.base/jdk.internal.vm.Continuation.run(Continuation.java:251)
      java.base/java.lang.VirtualThread.runContinuation(VirtualThread.java:221)
      java.base/java.util.concurrent.ForkJoinTask$RunnableExecuteAction.exec(ForkJoinTask.java:1423)
      java.base/java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:387)
      java.base/java.util.concurrent.ForkJoinPool$WorkQueue.topLevelExec(ForkJoinPool.java:1312)
      java.base/java.util.concurrent.ForkJoinPool.scan(ForkJoinPool.java:1843)
      java.base/java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1808)
      java.base/java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:188)

当有些闲置时：

#249 "ForkJoinPool-3-worker-5"
      java.base/jdk.internal.misc.Unsafe.park(Native Method)
      java.base/java.util.concurrent.locks.LockSupport.park(LockSupport.java:371)
      java.base/java.util.concurrent.ForkJoinPool.awaitWork(ForkJoinPool.java:1893)
      java.base/java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1809)
      java.base/java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:188)

我可以简单地禁用 Spring 的虚拟线程支持，但我想了解这个问题。这是某种僵局吗？如何追踪？

Answer 1

你能解决这个问题吗？还是仍然面临着虚拟线程？