serializer icon indicating copy to clipboard operation
serializer copied to clipboard

VirtualThreads getting pinned due to serializer

Open maximevdk-tidal opened this issue 1 year ago • 1 comments

Environment Details

  • Eclipse Serializer Version: 1.2.0
  • JDK version: 21
  • OS: Linux
  • Used frameworks: Spring Boot, Memcached

Describe the bug

When spawning virtual threads they get pinned when using the serializer

2024-03-13T13:31:13.208+01:00 TRACE 32774 --- [xyz-local] [               ] o.e.s.p.binary.types.BinaryLoader        : Updating LoadItem OID=1000000000000000254, Type=30 java.lang.String
Thread[#168,ForkJoinPool-1-worker-1,5,CarrierThreads]
    java.base/java.lang.VirtualThread$VThreadContinuation.onPinned(VirtualThread.java:183)
    java.base/jdk.internal.vm.Continuation.onPinned0(Continuation.java:393)
    java.base/java.lang.VirtualThread.park(VirtualThread.java:582)
    java.base/java.lang.System$2.parkVirtualThread(System.java:2643)
    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)
Thread[#179,ForkJoinPool-1-worker-2,5,CarrierThreads]
    java.base/java.lang.VirtualThread$VThreadContinuation.onPinned(VirtualThread.java:183)
    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.debug(Logger.java:499)
    org.eclipse.serializer.persistence.types.PersistenceTypeHandlerEnsurer$Default.logHandlerCreation(PersistenceTypeHandlerEnsurer.java:269)
    org.eclipse.serializer.persistence.types.PersistenceTypeHandlerEnsurer$Default.ensureTypeHandler(PersistenceTypeHandlerEnsurer.java:252)
    org.eclipse.serializer.persistence.types.PersistenceTypeHandlerProviderCreating.ensureTypeHandler(PersistenceTypeHandlerProviderCreating.java:178)
    org.eclipse.serializer.persistence.types.PersistenceTypeHandlerProviderCreating.provideTypeHandler(PersistenceTypeHandlerProviderCreating.java:86)
    java.base/jdk.internal.vm.Continuation.onPinned0(Continuation.java:393)
    java.base/java.lang.VirtualThread.park(VirtualThread.java:582)
    java.base/java.lang.System$2.parkVirtualThread(System.java:2643)
    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)
    org.eclipse.serializer.persistence.types.PersistenceTypeHandlerManager$Default.internalEnsureTypeHandler(PersistenceTypeHandlerManager.java:608) <== monitors:1
    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.debug(Logger.java:487)
    org.eclipse.serializer.TypedSerializer$Default.deserialize(TypedSerializer.java:321) <== monitors:1

To Reproduce

Use the TypedSerializer in a VirtualThread

Expected behavior

The thread doesn't get pinned.

Additional context

We're seeing a lot of latency where the application is just waiting.

maximevdk-tidal avatar Mar 13 '24 12:03 maximevdk-tidal

Unfortunately, VirtalThreads get pinned to their carrier thread in synchronized blocks or methods as mentioned in JEP-444. To solve this, either the JDK needs to remove this limitation in future or we need to rework all synchronizations in EclipseStore and EclipseSerializer what is not yet planned.

hg-ms avatar Mar 15 '24 06:03 hg-ms

No other communication since March. I close this issue.

zdenek-jonas avatar Jul 12 '24 12:07 zdenek-jonas