Improve JFR pinned reason in event

Author: pchilano

src/hotspot/share/include/jvm.h

@@ -1146,7 +1146,7 @@ JNIEXPORT void JNICALL
 JVM_VirtualThreadDisableSuspend(JNIEnv* env, jclass clazz, jboolean enter);
 
 JNIEXPORT void JNICALL
-JVM_VirtualThreadPinnedEvent(jint reasonCode, jstring reasonString);
+JVM_VirtualThreadPinnedEvent(JNIEnv* env, jclass clazz, jstring op);
 
 JNIEXPORT jobject JNICALL
 JVM_TakeVirtualThreadListToUnblock(JNIEnv* env, jclass ignored);

src/hotspot/share/jfr/metadata/metadata.xml

@@ -156,7 +156,8 @@
     <Field type="ulong" name="id" label="Continuation ID" />
   </Event>
 
-  <Event name="VirtualThreadPinned" category="Java Virtual Machine, Runtime" label="Virtual Thread Pinned" thread="true" stackTrace="true" startTime="false">
+  <Event name="VirtualThreadPinned" category="Java Virtual Machine, Runtime" label="Virtual Thread Pinned" thread="true" stackTrace="true">
+    <Field type="string" name="blockingOperation" label="Blocking operation" />
     <Field type="string" name="pinnedReason" label="Pinned Reason" />
     <Field type="Thread" name="carrierThread" label="Carrier Thread" />
   </Event>

src/hotspot/share/oops/instanceKlass.cpp

@@ -1105,22 +1105,6 @@ void InstanceKlass::initialize_impl(TRAPS) {
       }
       wait = true;
       jt->set_class_to_be_initialized(this);
-
-#if INCLUDE_JFR
-      ContinuationEntry* ce = jt->last_continuation();
-      if (ce != nullptr && ce->is_virtual_thread()) {
-        EventVirtualThreadPinned e;
-        if (e.should_commit()) {
-          ResourceMark rm(jt);
-          char reason[256];
-          jio_snprintf(reason, sizeof reason, "Waiting for initialization of klass %s", external_name());
-          e.set_pinnedReason(reason);
-          e.set_carrierThread(JFR_JVM_THREAD_ID(THREAD));
-          e.commit();
-        }
-      }
- #endif
-
       ol.wait_uninterruptibly(jt);
       jt->set_class_to_be_initialized(nullptr);
     }
@@ -1619,6 +1603,7 @@ void InstanceKlass::call_class_initializer(TRAPS) {
                 THREAD->name());
   }
   if (h_method() != nullptr) {
+    ThreadInClassInitializer ticl(THREAD, this); // Track class being initialized
     JavaCallArguments args; // No arguments
     JavaValue result(T_VOID);
     JavaCalls::call(&result, h_method, &args, CHECK); // Static call (no args)

src/hotspot/share/prims/jvm.cpp

@@ -3959,16 +3959,16 @@ JVM_ENTRY(void, JVM_VirtualThreadDisableSuspend(JNIEnv* env, jclass clazz, jbool
 #endif
 JVM_END
 
-JVM_ENTRY_NO_ENV(void, JVM_VirtualThreadPinnedEvent(jint reasonCode, jstring reasonString))
+JVM_ENTRY(void, JVM_VirtualThreadPinnedEvent(JNIEnv* env, jclass ignored, jstring op))
 #if INCLUDE_JFR
-  EventVirtualThreadPinned e;
-  if (e.should_commit()) {
+  freeze_result result = THREAD->last_freeze_fail_result();
+  assert(result != freeze_ok, "sanity check");
+  EventVirtualThreadPinned event(UNTIMED);
+  event.set_starttime(THREAD->last_freeze_fail_time());
+  if (event.should_commit()) {
     ResourceMark rm(THREAD);
-    // ignore reason code for now
-    const char *reason = java_lang_String::as_utf8_string(JNIHandles::resolve_non_null(reasonString));
-    e.set_pinnedReason(reason);
-    e.set_carrierThread(JFR_JVM_THREAD_ID(THREAD));
-    e.commit();
+    const char *str = java_lang_String::as_utf8_string(JNIHandles::resolve_non_null(op));
+    THREAD->post_vthread_pinned_event(&event, str, result);
   }
 #endif
 JVM_END

src/hotspot/share/runtime/continuationFreezeThaw.cpp

@@ -1676,6 +1676,7 @@ static inline freeze_result freeze_epilog(ContinuationWrapper& cont) {
 
 static freeze_result freeze_epilog(JavaThread* thread, ContinuationWrapper& cont, freeze_result res) {
   if (UNLIKELY(res != freeze_ok)) {
+    JFR_ONLY(thread->set_last_freeze_fail_result(res);)
     verify_continuation(cont.continuation());
     log_develop_trace(continuations)("=== end of freeze (fail %d)", res);
     return res;

src/hotspot/share/runtime/javaThread.cpp

@@ -515,6 +515,7 @@ JavaThread::JavaThread(MemTag mem_tag) :
   _parker(),
 
   _class_to_be_initialized(nullptr),
+  _class_being_initialized(nullptr),
 
   _SleepEvent(ParkEvent::Allocate(this)),
 
@@ -2327,3 +2328,38 @@ void JavaThread::add_oop_handles_for_release() {
   _oop_handle_list = new_head;
   Service_lock->notify_all();
 }
+
+#if INCLUDE_JFR
+void JavaThread::set_last_freeze_fail_result(freeze_result result) {
+  assert(result != freeze_ok, "sanity check");
+  _last_freeze_fail_result = result;
+  _last_freeze_fail_time = Ticks::now();
+}
+
+// Post jdk.VirtualThreadPinned event
+void JavaThread::post_vthread_pinned_event(EventVirtualThreadPinned* event, const char* op, freeze_result result) {
+  assert(result != freeze_ok, "sanity check");
+  if (event->should_commit()) {
+    char reason[256];
+    if (class_to_be_initialized() != nullptr) {
+      ResourceMark rm(this);
+      jio_snprintf(reason, sizeof reason, "Waited for initialization of %s by another thread",
+                   class_to_be_initialized()->external_name());
+      event->set_pinnedReason(reason);
+    } else if (class_being_initialized() != nullptr) {
+      ResourceMark rm(this);
+      jio_snprintf(reason, sizeof(reason), "VM call to %s.<clinit> on stack",
+                   class_being_initialized()->external_name());
+      event->set_pinnedReason(reason);
+    } else if (result == freeze_pinned_native) {
+      event->set_pinnedReason("Native or VM frame on stack");
+    } else {
+      jio_snprintf(reason, sizeof(reason), "Freeze or preempt failed (%d)", result);
+      event->set_pinnedReason(reason);
+    }
+    event->set_blockingOperation(op);
+    event->set_carrierThread(JFR_JVM_THREAD_ID(this));
+    event->commit();
+  }
+}
+#endif

src/hotspot/share/runtime/javaThread.hpp

@@ -49,6 +49,7 @@
 #include "utilities/macros.hpp"
 #if INCLUDE_JFR
 #include "jfr/support/jfrThreadExtension.hpp"
+#include "utilities/ticks.hpp"
 #endif
 
 class AsyncExceptionHandshake;
@@ -78,6 +79,8 @@ class javaVFrame;
 class JavaThread;
 typedef void (*ThreadFunction)(JavaThread*, TRAPS);
 
+class EventVirtualThreadPinned;
+
 class JavaThread: public Thread {
   friend class VMStructs;
   friend class JVMCIVMStructs;
@@ -1212,11 +1215,23 @@ class JavaThread: public Thread {
   void set_class_to_be_initialized(InstanceKlass* k);
   InstanceKlass* class_to_be_initialized() const;
 
+  // Track executing class initializer, see ThreadInClassInitializer
+  void set_class_being_initialized(InstanceKlass* k);
+  InstanceKlass* class_being_initialized() const;
+
 private:
   InstanceKlass* _class_to_be_initialized;
+  InstanceKlass* _class_being_initialized;
 
   // java.lang.Thread.sleep support
   ParkEvent * _SleepEvent;
+
+#if INCLUDE_JFR
+  // Support for jdk.VirtualThreadPinned event
+  freeze_result _last_freeze_fail_result;
+  Ticks _last_freeze_fail_time;
+#endif
+
 public:
   bool sleep(jlong millis);
   bool sleep_nanos(jlong nanos);
@@ -1225,6 +1240,15 @@ class JavaThread: public Thread {
   void interrupt();
   bool is_interrupted(bool clear_interrupted);
 
+#if INCLUDE_JFR
+  // Support for jdk.VirtualThreadPinned event
+  freeze_result last_freeze_fail_result() { return _last_freeze_fail_result; }
+  Ticks& last_freeze_fail_time() { return _last_freeze_fail_time; }
+  void set_last_freeze_fail_result(freeze_result result);
+#endif
+  void post_vthread_pinned_event(EventVirtualThreadPinned* event, const char* op, freeze_result result) NOT_JFR_RETURN();
+
+
   // This is only for use by JVMTI RawMonitorWait. It emulates the actions of
   // the Java code in Object::wait which are not present in RawMonitorWait.
   bool get_and_clear_interrupted();
@@ -1331,4 +1355,17 @@ class ThreadOnMonitorWaitedEvent {
   ~ThreadOnMonitorWaitedEvent() { JVMTI_ONLY(_thread->set_on_monitor_waited_event(false);) }
 };
 
+class ThreadInClassInitializer : public StackObj {
+  JavaThread* _thread;
+  InstanceKlass* _previous;
+ public:
+  ThreadInClassInitializer(JavaThread* thread, InstanceKlass* ik) : _thread(thread) {
+    _previous = _thread->class_being_initialized();
+    _thread->set_class_being_initialized(ik);
+  }
+  ~ThreadInClassInitializer() {
+    _thread->set_class_being_initialized(_previous);
+  }
+};
+
 #endif // SHARE_RUNTIME_JAVATHREAD_HPP

src/hotspot/share/runtime/javaThread.inline.hpp

@@ -241,6 +241,16 @@ inline InstanceKlass* JavaThread::class_to_be_initialized() const {
   return _class_to_be_initialized;
 }
 
+inline void JavaThread::set_class_being_initialized(InstanceKlass* k) {
+  assert(k != nullptr || _class_being_initialized != nullptr, "incorrect usage");
+  assert(this == Thread::current(), "Only the current thread can set this field");
+  _class_being_initialized = k;
+}
+
+inline InstanceKlass* JavaThread::class_being_initialized() const {
+  return _class_being_initialized;
+}
+
 inline void JavaThread::om_set_monitor_cache(ObjectMonitor* monitor) {
   assert(UseObjectMonitorTable, "must be");
   assert(monitor != nullptr, "use om_clear_monitor_cache to clear");

src/hotspot/share/runtime/objectMonitor.cpp

@@ -119,15 +119,6 @@ OopStorage* ObjectMonitor::_oop_storage = nullptr;
 OopHandle ObjectMonitor::_vthread_cxq_head;
 ParkEvent* ObjectMonitor::_vthread_unparker_ParkEvent = nullptr;
 
-static void post_virtual_thread_pinned_event(JavaThread* current, const char* reason) {
-  EventVirtualThreadPinned e;
-  if (e.should_commit()) {
-    e.set_pinnedReason(reason);
-    e.set_carrierThread(JFR_JVM_THREAD_ID(current));
-    e.commit();
-  }
-}
-
 // -----------------------------------------------------------------------------
 // Theory of operations -- Monitors lists, thread residency, etc:
 //
@@ -489,14 +480,17 @@ void ObjectMonitor::enter_with_contention_mark(JavaThread *current, ObjectMonito
   assert(!is_being_async_deflated(), "must be");
 
   JFR_ONLY(JfrConditionalFlush<EventJavaMonitorEnter> flush(current);)
-  EventJavaMonitorEnter event;
-  if (event.is_started()) {
-    event.set_monitorClass(object()->klass());
+  EventJavaMonitorEnter enter_event;
+  if (enter_event.is_started()) {
+    enter_event.set_monitorClass(object()->klass());
     // Set an address that is 'unique enough', such that events close in
     // time and with the same address are likely (but not guaranteed) to
     // belong to the same object.
-    event.set_address((uintptr_t)this);
+    enter_event.set_address((uintptr_t)this);
   }
+  EventVirtualThreadPinned vthread_pinned_event;
+
+  freeze_result result;
 
   { // Change java thread status to indicate blocked on monitor enter.
     JavaThreadBlockedOnMonitorEnterState jtbmes(current, this);
@@ -517,7 +511,7 @@ void ObjectMonitor::enter_with_contention_mark(JavaThread *current, ObjectMonito
 
     ContinuationEntry* ce = current->last_continuation();
     if (ce != nullptr && ce->is_virtual_thread()) {
-      freeze_result result = Continuation::try_preempt(current, ce->cont_oop(current));
+      result = Continuation::try_preempt(current, ce->cont_oop(current));
       if (result == freeze_ok) {
         bool acquired = VThreadMonitorEnter(current);
         if (acquired) {
@@ -537,11 +531,6 @@ void ObjectMonitor::enter_with_contention_mark(JavaThread *current, ObjectMonito
                (!acquired && !current->preemption_cancelled() && state == java_lang_VirtualThread::BLOCKING), "invariant");
         return;
       }
-      if (result == freeze_pinned_native) {
-        post_virtual_thread_pinned_event(current, "Native frame or <clinit> on stack");
-      } else if (result == freeze_unsupported) {
-        post_virtual_thread_pinned_event(current, "Native frame or <clinit> or monitors on stack");
-      }
     }
 
     OSThreadContendState osts(current->osthread());
@@ -603,10 +592,17 @@ void ObjectMonitor::enter_with_contention_mark(JavaThread *current, ObjectMonito
     // event handler consumed an unpark() issued by the thread that
     // just exited the monitor.
   }
-  if (event.should_commit()) {
-    event.set_previousOwner(_previous_owner_tid);
-    event.commit();
+  if (enter_event.should_commit()) {
+    enter_event.set_previousOwner(_previous_owner_tid);
+    enter_event.commit();
+  }
+
+  ContinuationEntry* ce = current->last_continuation();
+  if (ce != nullptr && ce->is_virtual_thread()) {
+    assert(result != freeze_ok, "sanity check");
+    current->post_vthread_pinned_event(&vthread_pinned_event, "Contended monitor enter", result);
   }
+
   OM_PERFDATA_OP(ContendedLockAttempts, inc());
 }
 
@@ -1662,7 +1658,8 @@ void ObjectMonitor::wait(jlong millis, bool interruptible, TRAPS) {
 
   CHECK_OWNER();  // Throws IMSE if not owner.
 
-  EventJavaMonitorWait event;
+  EventJavaMonitorWait wait_event;
+  EventVirtualThreadPinned vthread_pinned_event;
 
   // check for a pending interrupt
   if (interruptible && current->is_interrupted(true) && !HAS_PENDING_EXCEPTION) {
@@ -1680,33 +1677,24 @@ void ObjectMonitor::wait(jlong millis, bool interruptible, TRAPS) {
       // consume an unpark() meant for the ParkEvent associated with
       // this ObjectMonitor.
     }
-    if (event.should_commit()) {
-      post_monitor_wait_event(&event, this, 0, millis, false);
+    if (wait_event.should_commit()) {
+      post_monitor_wait_event(&wait_event, this, 0, millis, false);
     }
     THROW(vmSymbols::java_lang_InterruptedException());
     return;
   }
 
   current->set_current_waiting_monitor(this);
 
+  freeze_result result;
   ContinuationEntry* ce = current->last_continuation();
   if (ce != nullptr && ce->is_virtual_thread()) {
-    freeze_result result = Continuation::try_preempt(current, ce->cont_oop(current));
+    result = Continuation::try_preempt(current, ce->cont_oop(current));
     if (result == freeze_ok) {
       VThreadWait(current, millis);
       current->set_current_waiting_monitor(nullptr);
       return;
     }
-    if (result == freeze_pinned_native || result == freeze_unsupported) {
-      const Klass* monitor_klass = object()->klass();
-      if (!is_excluded(monitor_klass)) {
-        if (result == freeze_pinned_native) {
-          post_virtual_thread_pinned_event(current,"Native frame or <clinit> on stack");
-        } else if (result == freeze_unsupported) {
-          post_virtual_thread_pinned_event(current, "Native frame or <clinit> or monitors on stack");
-        }
-      }
-    }
   }
 
   // create a node to be put into the queue
@@ -1832,8 +1820,13 @@ void ObjectMonitor::wait(jlong millis, bool interruptible, TRAPS) {
       }
     }
 
-    if (event.should_commit()) {
-      post_monitor_wait_event(&event, this, node._notifier_tid, millis, ret == OS_TIMEOUT);
+    if (wait_event.should_commit()) {
+      post_monitor_wait_event(&wait_event, this, node._notifier_tid, millis, ret == OS_TIMEOUT);
+    }
+
+    if (ce != nullptr && ce->is_virtual_thread()) {
+      assert(result != freeze_ok, "sanity check");
+      current->post_vthread_pinned_event(&vthread_pinned_event, "Object.wait", result);
     }
 
     OrderAccess::fence();
@@ -2065,9 +2058,9 @@ bool ObjectMonitor::VThreadWaitReenter(JavaThread* current, ObjectWaiter* node,
   node->_interrupted = !was_notified && current->is_interrupted(false);
 
   // Post JFR and JVMTI events.
-  EventJavaMonitorWait event;
-  if (event.should_commit() || JvmtiExport::should_post_monitor_waited()) {
-    vthread_monitor_waited_event(current, node, cont, &event, !was_notified && !node->_interrupted);
+  EventJavaMonitorWait wait_event;
+  if (wait_event.should_commit() || JvmtiExport::should_post_monitor_waited()) {
+    vthread_monitor_waited_event(current, node, cont, &wait_event, !was_notified && !node->_interrupted);
   }
 
   // Mark that we are at reenter so that we don't call this method again.

src/java.base/share/classes/java/lang/VirtualThread.java

@@ -242,8 +242,6 @@ private static class VThreadContinuation extends Continuation {
         }
         @Override
         protected void onPinned(Continuation.Pinned reason) {
-            // emit JFR event
-            virtualThreadPinnedEvent(reason.reasonCode(), reason.reasonString());
         }
         private static Runnable wrap(VirtualThread vthread, Runnable task) {
             return new Runnable() {
@@ -261,13 +259,6 @@ public void run() {
         }
     }
 
-    /**
-     * jdk.VirtualThreadPinned is emitted by HotSpot VM when pinned. Call into VM to
-     * emit event to avoid having a JFR event in Java with the same name (but different ID)
-     * to events emitted by the VM.
-     */
-    private static native void virtualThreadPinnedEvent(int reason, String reasonString);
-
     /**
      * Runs or continues execution on the current thread. The virtual thread is mounted
      * on the current thread before the task runs or continues. It unmounts when the
@@ -833,8 +824,19 @@ private void parkOnCarrierThread(boolean timed, long nanos) {
 
         // consume parking permit
         setParkPermit(false);
+
+        // JFR jdk.VirtualThreadPinned event
+        postPinnedEvent("LockSupport.park");
     }
 
+    /**
+     * Call into VM when pinned to record a JFR jdk.VirtualThreadPinned event.
+     * Recording the event in the VM avoids having JFR event recorded in Java
+     * with the same name, but different ID, to events recorded by the VM.
+     */
+    @Hidden
+    private static native void postPinnedEvent(String op);
+
     /**
      * Re-enables this virtual thread for scheduling. If this virtual thread is parked
      * then its task is scheduled to continue, otherwise its next call to {@code park} or

src/java.base/share/classes/jdk/internal/vm/Continuation.java

@@ -57,22 +57,10 @@ public class Continuation {
 
     /** Reason for pinning */
     public enum Pinned {
-        NATIVE(2, "Native frame or <clinit> on stack"),
-        MONITOR(3, "Monitor held"),
-        CRITICAL_SECTION(4, "In critical section");
-
-        private final int reasonCode;
-        private final String reasonString;
-        Pinned(int reasonCode, String reasonString) {
-            this.reasonCode = reasonCode;
-            this.reasonString = reasonString;
-        }
-        public int reasonCode() {
-            return reasonCode;
-        }
-        public String reasonString() {
-            return reasonString;
-        }
+        /** Native frame on stack */ NATIVE,
+        /** Monitor held */          MONITOR,
+        /** In critical section */   CRITICAL_SECTION,
+        /** Exception (OOME/SOE) */  EXCEPTION
     }
 
     /** Preemption attempt result */
@@ -99,6 +87,7 @@ private static Pinned pinnedReason(int reason) {
             case 2 -> Pinned.CRITICAL_SECTION;
             case 3 -> Pinned.NATIVE;
             case 4 -> Pinned.MONITOR;
+            case 5 -> Pinned.EXCEPTION;
             default -> throw new AssertionError("Unknown pinned reason: " + reason);
         };
     }

src/java.base/share/native/libjava/VirtualThread.c

@@ -28,7 +28,7 @@
 #include "jvm.h"
 #include "java_lang_VirtualThread.h"
 
-#define THREAD "Ljava/lang/Thread;"
+#define STR  "Ljava/lang/String;"
 #define VIRTUAL_THREAD  "Ljava/lang/VirtualThread;"
 
 static JNINativeMethod methods[] = {
@@ -37,17 +37,11 @@ static JNINativeMethod methods[] = {
     { "notifyJvmtiMount",          "(Z)V", (void *)&JVM_VirtualThreadMount },
     { "notifyJvmtiUnmount",        "(Z)V", (void *)&JVM_VirtualThreadUnmount },
     { "notifyJvmtiDisableSuspend", "(Z)V", (void *)&JVM_VirtualThreadDisableSuspend },
+    { "postPinnedEvent",           "(" STR ")V", (void *)&JVM_VirtualThreadPinnedEvent },
     { "takeVirtualThreadListToUnblock", "()" VIRTUAL_THREAD, (void *)&JVM_TakeVirtualThreadListToUnblock},
 };
 
 JNIEXPORT void JNICALL
 Java_java_lang_VirtualThread_registerNatives(JNIEnv *env, jclass clazz) {
     (*env)->RegisterNatives(env, clazz, methods, (sizeof(methods)/sizeof(methods[0])));
 }
-
-JNIEXPORT void JNICALL
-Java_java_lang_VirtualThread_virtualThreadPinnedEvent(JNIEnv *env, jclass ignored,
-                                                      jint reasonCode, jstring reasonString)
-{
-    JVM_VirtualThreadPinnedEvent(reasonCode, reasonString);
-}

src/jdk.jfr/share/conf/jfr/default.jfc

@@ -75,6 +75,7 @@
     <event name="jdk.VirtualThreadPinned">
       <setting name="enabled">true</setting>
       <setting name="stackTrace">true</setting>
+      <setting name="threshold">20 ms</setting>
     </event>
 
     <event name="jdk.VirtualThreadSubmitFailed">

src/jdk.jfr/share/conf/jfr/profile.jfc

@@ -75,6 +75,7 @@
     <event name="jdk.VirtualThreadPinned">
       <setting name="enabled">true</setting>
       <setting name="stackTrace">true</setting>
+      <setting name="threshold">20 ms</setting>
     </event>
 
     <event name="jdk.VirtualThreadSubmitFailed">