8257602: Introduce JFR Event Throttling and new jdk.ObjectAllocationS…

…ample event (enabled by default)

Co-authored-by: Jaroslav Bachorik <jbachorik@openjdk.org>
Reviewed-by: egahlin, jbachorik

make/src/classes/build/tools/jfr/GenerateJfrFiles.java

@@ -172,6 +172,7 @@ public static void main(String... args) throws Exception {
         boolean startTime;
         String period = "";
         boolean cutoff;
+        boolean throttle;
         boolean experimental;
         long id;
         boolean isEvent;
@@ -194,6 +195,7 @@ public void persist(DataOutputStream pos) throws IOException {
             pos.writeBoolean(startTime);
             pos.writeUTF(period);
             pos.writeBoolean(cutoff);
+            pos.writeBoolean(throttle);
             pos.writeBoolean(experimental);
             pos.writeLong(id);
             pos.writeBoolean(isEvent);
@@ -490,6 +492,7 @@ public void startElement(String uri, String localName, String qName, Attributes
                 currentType.startTime = getBoolean(attributes, "startTime", true);
                 currentType.period = getString(attributes, "period");
                 currentType.cutoff = getBoolean(attributes, "cutoff", false);
+                currentType.throttle = getBoolean(attributes, "throttle", false);
                 currentType.commitState = getString(attributes, "commitState");
                 currentType.isEvent = "Event".equals(qName);
                 currentType.isRelation = "Relation".equals(qName);
@@ -759,6 +762,7 @@ private static void printJfrEventClassesHpp(Metadata metadata, File outputFile)
             out.write("  void set_starttime(const Ticks&) const {}");
             out.write("  void set_endtime(const Ticks&) const {}");
             out.write("  bool should_commit() const { return false; }");
+            out.write("  bool is_started() const { return false; }");
             out.write("  static bool is_enabled() { return false; }");
             out.write("  void commit() {}");
             out.write("};");
@@ -820,6 +824,7 @@ private static void printEvent(Printer out, TypeElement event, boolean empty) {
             out.write("  static const bool hasStackTrace = " + event.stackTrace + ";");
             out.write("  static const bool isInstant = " + !event.startTime + ";");
             out.write("  static const bool hasCutoff = " + event.cutoff + ";");
+            out.write("  static const bool hasThrottle = " + event.throttle + ";");
             out.write("  static const bool isRequestable = " + !event.period.isEmpty() + ";");
             out.write("  static const JfrEventId eventId = Jfr" + event.name + "Event;");
             out.write("");

src/hotspot/share/gc/shared/allocTracer.cpp

@@ -1,5 +1,5 @@
 /*
- * Copyright (c) 2013, 2018, Oracle and/or its affiliates. All rights reserved.
+ * Copyright (c) 2013, 2020, Oracle and/or its affiliates. All rights reserved.
  * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
  *
  * This code is free software; you can redistribute it and/or modify it
@@ -24,14 +24,86 @@
 
 #include "precompiled.hpp"
 #include "gc/shared/allocTracer.hpp"
+#include "gc/shared/threadLocalAllocBuffer.inline.hpp"
 #include "jfr/jfrEvents.hpp"
-#include "runtime/handles.hpp"
 #include "utilities/globalDefinitions.hpp"
 #include "utilities/macros.hpp"
 #if INCLUDE_JFR
 #include "jfr/support/jfrAllocationTracer.hpp"
 #endif
 
+static THREAD_LOCAL int64_t _last_allocated_bytes = 0;
+
+inline void send_allocation_sample(const Klass* klass, int64_t allocated_bytes) {
+  assert(allocated_bytes > 0, "invariant");
+  EventObjectAllocationSample event;
+  if (event.should_commit()) {
+    const size_t weight = allocated_bytes - _last_allocated_bytes;
+    assert(weight > 0, "invariant");
+    event.set_objectClass(klass);
+    event.set_weight(weight);
+    event.commit();
+    _last_allocated_bytes = allocated_bytes;
+  }
+}
+
+inline bool send_allocation_sample_with_result(const Klass* klass, int64_t allocated_bytes) {
+  assert(allocated_bytes > 0, "invariant");
+  EventObjectAllocationSample event;
+  if (event.should_commit()) {
+    const size_t weight = allocated_bytes - _last_allocated_bytes;
+    assert(weight > 0, "invariant");
+    event.set_objectClass(klass);
+    event.set_weight(weight);
+    event.commit();
+    _last_allocated_bytes = allocated_bytes;
+    return true;
+  }
+  return false;
+}
+
+inline intptr_t estimate_tlab_size_bytes(Thread* thread) {
+  assert(thread != NULL, "invariant");
+  const size_t desired_tlab_size_bytes = thread->tlab().desired_size() * HeapWordSize;
+  const size_t alignment_reserve_bytes = thread->tlab().alignment_reserve_in_bytes();
+  assert(desired_tlab_size_bytes > alignment_reserve_bytes, "invariant");
+  return static_cast<intptr_t>(desired_tlab_size_bytes - alignment_reserve_bytes);
+}
+
+inline int64_t load_allocated_bytes(Thread* thread) {
+  const int64_t allocated_bytes = thread->allocated_bytes();
+  if (allocated_bytes < _last_allocated_bytes) {
+    // A hw thread can detach and reattach to the VM, and when it does,
+    // it gets a new JavaThread representation. The thread local variable
+    // tracking _last_allocated_bytes is mapped to the existing hw thread,
+    // so it needs to be reset.
+    _last_allocated_bytes = 0;
+  }
+  return allocated_bytes == _last_allocated_bytes ? 0 : allocated_bytes;
+}
+
+// To avoid large objects from being undersampled compared to the regular TLAB samples,
+// the data amount is normalized as if it was a TLAB, giving a number of TLAB sampling attempts to the large object.
+static void normalize_as_tlab_and_send_allocation_samples(Klass* klass, intptr_t obj_alloc_size_bytes, Thread* thread) {
+  const int64_t allocated_bytes = load_allocated_bytes(thread);
+  assert(allocated_bytes > 0, "invariant"); // obj_alloc_size_bytes is already attributed to allocated_bytes at this point.
+  if (!UseTLAB) {
+    send_allocation_sample(klass, allocated_bytes);
+    return;
+  }
+  const intptr_t tlab_size_bytes = estimate_tlab_size_bytes(thread);
+  if (allocated_bytes - _last_allocated_bytes < tlab_size_bytes) {
+    return;
+  }
+  assert(obj_alloc_size_bytes > 0, "invariant");
+  do {
+    if (send_allocation_sample_with_result(klass, allocated_bytes)) {
+      return;
+    }
+    obj_alloc_size_bytes -= tlab_size_bytes;
+  } while (obj_alloc_size_bytes > 0);
+}
+
 void AllocTracer::send_allocation_outside_tlab(Klass* klass, HeapWord* obj, size_t alloc_size, Thread* thread) {
   JFR_ONLY(JfrAllocationTracer tracer(obj, alloc_size, thread);)
   EventObjectAllocationOutsideTLAB event;
@@ -40,6 +112,7 @@ void AllocTracer::send_allocation_outside_tlab(Klass* klass, HeapWord* obj, size
     event.set_allocationSize(alloc_size);
     event.commit();
   }
+  normalize_as_tlab_and_send_allocation_samples(klass, static_cast<intptr_t>(alloc_size), thread);
 }
 
 void AllocTracer::send_allocation_in_new_tlab(Klass* klass, HeapWord* obj, size_t tlab_size, size_t alloc_size, Thread* thread) {
@@ -51,6 +124,11 @@ void AllocTracer::send_allocation_in_new_tlab(Klass* klass, HeapWord* obj, size_
     event.set_tlabSize(tlab_size);
     event.commit();
   }
+  const int64_t allocated_bytes = load_allocated_bytes(thread);
+  if (allocated_bytes == 0) {
+    return;
+  }
+  send_allocation_sample(klass, allocated_bytes);
 }
 
 void AllocTracer::send_allocation_requiring_gc_event(size_t size, uint gcId) {

src/hotspot/share/jfr/jni/jfrJniMethod.cpp

@@ -35,6 +35,7 @@
 #include "jfr/recorder/repository/jfrRepository.hpp"
 #include "jfr/recorder/repository/jfrChunkRotation.hpp"
 #include "jfr/recorder/repository/jfrChunkWriter.hpp"
+#include "jfr/recorder/service/jfrEventThrottler.hpp"
 #include "jfr/recorder/service/jfrOptionSet.hpp"
 #include "jfr/recorder/stacktrace/jfrStackTraceRepository.hpp"
 #include "jfr/recorder/stringpool/jfrStringPool.hpp"
@@ -175,6 +176,11 @@ NO_TRANSITION(jboolean, jfr_set_cutoff(JNIEnv* env, jobject jvm, jlong event_typ
   return JfrEventSetting::set_cutoff(event_type_id, cutoff_ticks) ? JNI_TRUE : JNI_FALSE;
 NO_TRANSITION_END
 
+NO_TRANSITION(jboolean, jfr_set_throttle(JNIEnv* env, jobject jvm, jlong event_type_id, jlong event_sample_size, jlong period_ms))
+  JfrEventThrottler::configure(static_cast<JfrEventId>(event_type_id), event_sample_size, period_ms);
+  return JNI_TRUE;
+NO_TRANSITION_END
+
 NO_TRANSITION(jboolean, jfr_should_rotate_disk(JNIEnv* env, jobject jvm))
   return JfrChunkRotation::should_rotate() ? JNI_TRUE : JNI_FALSE;
 NO_TRANSITION_END

src/hotspot/share/jfr/jni/jfrJniMethod.hpp

@@ -132,6 +132,8 @@ jlong JNICALL jfr_get_unloaded_event_classes_count(JNIEnv* env, jobject jvm);
 
 jboolean JNICALL jfr_set_cutoff(JNIEnv* env, jobject jvm, jlong event_type_id, jlong cutoff_ticks);
 
+jboolean JNICALL jfr_set_throttle(JNIEnv* env, jobject jvm, jlong event_type_id, jlong event_sample_size, jlong period_ms);
+
 void JNICALL jfr_emit_old_object_samples(JNIEnv* env, jobject jvm, jlong cutoff_ticks, jboolean, jboolean);
 
 jboolean JNICALL jfr_should_rotate_disk(JNIEnv* env, jobject jvm);

src/hotspot/share/jfr/jni/jfrJniMethodRegistration.cpp

@@ -81,6 +81,7 @@ JfrJniMethodRegistration::JfrJniMethodRegistration(JNIEnv* env) {
       (char*)"setForceInstrumentation", (char*)"(Z)V", (void*)jfr_set_force_instrumentation,
       (char*)"getUnloadedEventClassCount", (char*)"()J", (void*)jfr_get_unloaded_event_classes_count,
       (char*)"setCutoff", (char*)"(JJ)Z", (void*)jfr_set_cutoff,
+      (char*)"setThrottle", (char*)"(JJJ)Z", (void*)jfr_set_throttle,
       (char*)"emitOldObjectSamples", (char*)"(JZZ)V", (void*)jfr_emit_old_object_samples,
       (char*)"shouldRotateDisk", (char*)"()Z", (void*)jfr_should_rotate_disk,
       (char*)"exclude", (char*)"(Ljava/lang/Thread;)V", (void*)jfr_exclude_thread,

src/hotspot/share/jfr/leakprofiler/sampling/objectSampler.cpp

@@ -175,7 +175,7 @@ void ObjectSampler::sample(HeapWord* obj, size_t allocated, JavaThread* thread)
   record_stacktrace(thread);
   // try enter critical section
   JfrTryLock tryLock(&_lock);
-  if (!tryLock.has_lock()) {
+  if (!tryLock.acquired()) {
     log_trace(jfr, oldobject, sampling)("Skipping old object sample due to lock contention");
     return;
   }

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

@@ -614,6 +614,12 @@
     <Field type="ulong" contentType="bytes" name="allocationSize" label="Allocation Size" />
   </Event>
 
+  <Event name="ObjectAllocationSample" category="Java Application" label="Object Allocation Sample" thread="true" stackTrace="true" startTime="false" throttle="true">
+    <Field type="Class" name="objectClass" label="Object Class" description="Class of allocated object" />
+    <Field type="long" contentType="bytes" name="weight" label="Sample Weight"
+      description="The relative weight of the sample. Aggregating the weights for a large number of samples, for a particular class, thread or stack trace, gives a statistically accurate representation of the allocation pressure" />
+  </Event>
+
   <Event name="OldObjectSample" category="Java Virtual Machine, Profiling" label="Old Object Sample" description="A potential memory leak" stackTrace="true" thread="true"
     startTime="false" cutoff="true">
     <Field type="Ticks" name="allocationTime" label="Allocation Time" />

src/hotspot/share/jfr/metadata/metadata.xsd

@@ -70,6 +70,7 @@
               <xs:attribute name="stackTrace" type="xs:boolean" use="optional" />
               <xs:attribute name="period" type="periodType" use="optional" />
               <xs:attribute name="cutoff" type="xs:boolean" use="optional" />
+              <xs:attribute name="throttle" type="xs:boolean" use="optional" />
               <xs:attribute name="commitState" type="xs:string" use="optional" />
             </xs:complexType>
           </xs:element>

src/hotspot/share/jfr/recorder/jfrRecorder.cpp

@@ -33,6 +33,7 @@
 #include "jfr/recorder/jfrRecorder.hpp"
 #include "jfr/recorder/checkpoint/jfrCheckpointManager.hpp"
 #include "jfr/recorder/repository/jfrRepository.hpp"
+#include "jfr/recorder/service/jfrEventThrottler.hpp"
 #include "jfr/recorder/service/jfrOptionSet.hpp"
 #include "jfr/recorder/service/jfrPostBox.hpp"
 #include "jfr/recorder/service/jfrRecorderService.hpp"
@@ -289,6 +290,9 @@ bool JfrRecorder::create_components() {
   if (!create_thread_sampling()) {
     return false;
   }
+  if (!create_event_throttler()) {
+    return false;
+  }
   return true;
 }
 
@@ -362,6 +366,10 @@ bool JfrRecorder::create_thread_sampling() {
   return _thread_sampling != NULL;
 }
 
+bool JfrRecorder::create_event_throttler() {
+  return JfrEventThrottler::create();
+}
+
 void JfrRecorder::destroy_components() {
   JfrJvmtiAgent::destroy();
   if (_post_box != NULL) {
@@ -396,6 +404,7 @@ void JfrRecorder::destroy_components() {
     JfrThreadSampling::destroy();
     _thread_sampling = NULL;
   }
+  JfrEventThrottler::destroy();
 }
 
 bool JfrRecorder::create_recorder_thread() {

src/hotspot/share/jfr/recorder/jfrRecorder.hpp

@@ -53,6 +53,7 @@ class JfrRecorder : public JfrCHeapObj {
   static bool create_storage();
   static bool create_stringpool();
   static bool create_thread_sampling();
+  static bool create_event_throttler();
   static bool create_components();
   static void destroy_components();
   static void on_recorder_thread_exit();

src/hotspot/share/jfr/recorder/service/jfrEvent.hpp

@@ -1,5 +1,5 @@
 /*
- * Copyright (c) 2012, 2019, Oracle and/or its affiliates. All rights reserved.
+ * Copyright (c) 2012, 2020, Oracle and/or its affiliates. All rights reserved.
  * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
  *
  * This code is free software; you can redistribute it and/or modify it
@@ -26,6 +26,7 @@
 #define SHARE_JFR_RECORDER_SERVICE_JFREVENT_HPP
 
 #include "jfr/recorder/jfrEventSetting.inline.hpp"
+#include "jfr/recorder/service/jfrEventThrottler.hpp"
 #include "jfr/recorder/stacktrace/jfrStackTraceRepository.hpp"
 #include "jfr/utilities/jfrTime.hpp"
 #include "jfr/utilities/jfrTypes.hpp"
@@ -63,9 +64,14 @@ class JfrEvent {
   jlong _start_time;
   jlong _end_time;
   bool _started;
+  bool _untimed;
+  bool _should_commit;
+  bool _evaluated;
 
  protected:
-  JfrEvent(EventStartTime timing=TIMED) : _start_time(0), _end_time(0), _started(false)
+  JfrEvent(EventStartTime timing=TIMED) : _start_time(0), _end_time(0),
+                                          _started(false), _untimed(timing == UNTIMED),
+                                          _should_commit(false), _evaluated(false)
 #ifdef ASSERT
   , _verifier()
 #endif
@@ -79,19 +85,12 @@ class JfrEvent {
   }
 
   void commit() {
-    if (!should_commit()) {
-      return;
-    }
     assert(!_verifier.committed(), "event already committed");
-    if (_start_time == 0) {
-      set_starttime(JfrTicks::now());
-    } else if (_end_time == 0) {
-      set_endtime(JfrTicks::now());
-    }
-    if (should_write()) {
-      write_event();
-      DEBUG_ONLY(_verifier.set_committed();)
+    if (!should_write()) {
+      return;
     }
+    write_event();
+    DEBUG_ONLY(_verifier.set_committed();)
   }
 
  public:
@@ -147,16 +146,44 @@ class JfrEvent {
     return T::hasStackTrace;
   }
 
-  bool should_commit() {
+  bool is_started() const {
     return _started;
   }
 
+  bool should_commit() {
+    if (!_started) {
+      return false;
+    }
+    if (_untimed) {
+      return true;
+    }
+    if (_evaluated) {
+      return _should_commit;
+    }
+    _should_commit = evaluate();
+    _evaluated = true;
+    return _should_commit;
+  }
+
  private:
   bool should_write() {
-    if (T::isInstant || T::isRequestable || T::hasCutoff) {
-      return true;
+    return _started && (_evaluated ? _should_commit : evaluate());
+  }
+
+  bool evaluate() {
+    assert(_started, "invariant");
+    if (_start_time == 0) {
+      set_starttime(JfrTicks::now());
+    } else if (_end_time == 0) {
+      set_endtime(JfrTicks::now());
+    }
+    if (T::isInstant || T::isRequestable) {
+      return T::hasThrottle ? JfrEventThrottler::accept(T::eventId, _untimed ? 0 : _start_time) : true;
+    }
+    if (_end_time - _start_time < JfrEventSetting::threshold(T::eventId)) {
+      return false;
     }
-    return (_end_time - _start_time) >= JfrEventSetting::threshold(T::eventId);
+    return T::hasThrottle ? JfrEventThrottler::accept(T::eventId, _untimed ? 0 : _end_time) : true;
   }
 
   void write_event() {