RFR: 8308614: Enabling JVMTI ClassLoad event slows down vthread creation by factor 10 [v3]

[Serguei Spitsyn]

On Sun, 19 Nov 2023 03:47:45 GMT, Daniel D. Daugherty <dcubed at openjdk.org> wrote:

>> Thank you for the comment, Dan!
>> Agreed, the comment needs to be corrected in two aspects.
>> I tried to simplify it but failed to do it correctly.
>> It is interesting that there is a `ThreadsListHandle` farther up the stack but it does not help sometimes.
>> It is observed that a `JavaThread` (of a carrier thread) referenced from the  `JvmtiThreadState` object can be just created, so we need a `ThreadsListHandle` to avoid possible asserts. With this fix in place I do not see the asserts fired anymore.
>
> @sspitsyn - Please point me at the code where these JavaThreads are newly created?

@dcubed-ojdk
I don't know FJP implementation well enough to point at the code where it happens. However, I observe that new `JavaThread `is being created between two points of the execution path.
 - First point is in the `JvmtiEventControllerPrivate::recompute_enabled()` at the line where a `ThreadsListHandle` is set. I've added a trap checking if any `JavaThread` pointed by `state->get_thread()` is not protected by the `tlh`. I can see this trap is not fired (I can't say it has never been fired).
 - Second point is in the `JvmtiEventControllerPrivate::enter_interp_only_mode()`. If  a `ThreadsListHandle` is NOT set then I can observe a `JavaThread` referenced by the state->get_thread() which is not protected by any TLH. It a TLH added into `JvmtiEventControllerPrivate::enter_interp_only_mode()` then this `JavaThread` is observed as protected by TLH.
I can provide a full stack trace for this `JavaThread` consisting of two parts: carrier thread and virtual thread frames. The name of carrier thread is  `ForkJoinPool-1-worker-1`. The virtual thread is a tested virtual thread. 
The thread dump looks las below:

DBG: enter_interp_only_mode: target: 0x7f93f8043d00  <NO-NAME> virt: 1 carrier: ForkJoinPool-1-worker-1
DBG: ##### NATIVE stacktrace of JavaThread: 0x7f93f8043d00 #####
Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native code)
j  fieldacc02.check(Ljava/lang/Object;)I+0
j  fieldacc02.lambda$testVirtualThread$0()V+12
j  fieldacc02$$Lambda+0x00007f943b001428.run()V+0
j  java.lang.Thread.runWith(Ljava/lang/Object;Ljava/lang/Runnable;)V+5 java.base at 22-internal
j  java.lang.VirtualThread.run(Ljava/lang/Runnable;)V+66 java.base at 22-internal
j  java.lang.VirtualThread$VThreadContinuation$1.run()V+8 java.base at 22-internal
j  jdk.internal.vm.Continuation.enter0()V+4 java.base at 22-internal
j  jdk.internal.vm.Continuation.enter(Ljdk/internal/vm/Continuation;Z)V+1 java.base at 22-internal
J 124  jdk.internal.vm.Continuation.enterSpecial(Ljdk/internal/vm/Continuation;ZZ)V java.base at 22-internal (0 bytes) @ 0x00007f94c7cdf744 [0x00007f94c7cdf5e0+0x0000000000000164]
j  jdk.internal.vm.Continuation.run()V+122 java.base at 22-internal
j  java.lang.VirtualThread.runContinuation()V+70 java.base at 22-internal
j  java.lang.VirtualThread$$Lambda+0x00007f943b0496c0.run()V+4 java.base at 22-internal
j  java.util.concurrent.ForkJoinTask$RunnableExecuteAction.compute()Ljava/lang/Void;+4 java.base at 22-internal
j  java.util.concurrent.ForkJoinTask$RunnableExecuteAction.compute()Ljava/lang/Object;+1 java.base at 22-internal
j  java.util.concurrent.ForkJoinTask$InterruptibleTask.exec()Z+51 java.base at 22-internal
j  java.util.concurrent.ForkJoinTask.doExec()V+10 java.base at 22-internal
j  java.util.concurrent.ForkJoinPool$WorkQueue.topLevelExec(Ljava/util/concurrent/ForkJoinTask;Ljava/util/concurrent/ForkJoinPool$WorkQueue;I)V+49 java.base at 22-internal
j  java.util.concurrent.ForkJoinPool.scan(Ljava/util/concurrent/ForkJoinPool$WorkQueue;JI)J+271 java.base at 22-internal
j  java.util.concurrent.ForkJoinPool.runWorker(Ljava/util/concurrent/ForkJoinPool$WorkQueue;)V+68 java.base at 22-internal
j  java.util.concurrent.ForkJoinWorkerThread.run()V+31 java.base at 22-internal
v  ~StubRoutines::call_stub 0x00007f94c7505d21
V  [libjvm.so+0xe7b719]  JavaCalls::call_helper(JavaValue*, methodHandle const&, JavaCallArguments*, JavaThread*)+0x4a9  (javaCalls.cpp:415)
V  [libjvm.so+0xe7bdd5]  JavaCalls::call_virtual(JavaValue*, Klass*, Symbol*, Symbol*, JavaCallArguments*, JavaThread*)+0x345  (javaCalls.cpp:329)
V  [libjvm.so+0xe7bff6]  JavaCalls::call_virtual(JavaValue*, Handle, Klass*, Symbol*, Symbol*, JavaThread*)+0x76  (javaCalls.cpp:191)
V  [libjvm.so+0xfd9723]  thread_entry(JavaThread*, JavaThread*)+0x93  (jvm.cpp:2937)
V  [libjvm.so+0xeb06ac]  JavaThread::thread_main_inner()+0xcc  (javaThread.cpp:720)
V  [libjvm.so+0x1789496]  Thread::call_run()+0xb6  (thread.cpp:220)
V  [libjvm.so+0x1493b27]  thread_native_entry(Thread*)+0x127  (os_linux.cpp:787)


The observed `JavaThead` does not look as a garbage because no crashes has ever been observed. Apparently, it has been recently created because it is not protected by the TLH which was set in the `JvmtiEventControllerPrivate::recompute_enabled()`. I guess, it has to be possible to find out where exactly in the FJP code it is created but it will take time. I'm not sure why do you need it though.

-------------

PR Review Comment: https://git.openjdk.org/jdk/pull/16686#discussion_r1398362375