changeset 8665:97f63e5ca070

8078901: Add trace event for G1 MMU information Reviewed-by: ehelin, mlarsson
author sjohanss
date Thu, 30 Apr 2015 13:33:23 +0200
parents 660fa1b69f63
children 90e332204e4d
files src/share/vm/gc/g1/g1CollectedHeap.hpp src/share/vm/gc/g1/g1CollectorPolicy.cpp src/share/vm/gc/g1/g1MMUTracker.cpp src/share/vm/gc/g1/g1MMUTracker.hpp src/share/vm/gc/shared/gcTrace.cpp src/share/vm/gc/shared/gcTrace.hpp src/share/vm/gc/shared/gcTraceSend.cpp src/share/vm/trace/trace.xml
diffstat 8 files changed, 45 insertions(+), 6 deletions(-) [+]
line wrap: on
line diff
--- a/src/share/vm/gc/g1/g1CollectedHeap.hpp	Tue Jun 30 15:26:20 2015 -0700
+++ b/src/share/vm/gc/g1/g1CollectedHeap.hpp	Thu Apr 30 13:33:23 2015 +0200
@@ -1109,6 +1109,8 @@
   // The STW reference processor....
   ReferenceProcessor* ref_processor_stw() const { return _ref_processor_stw; }
 
+  G1NewTracer* gc_tracer_stw() const { return _gc_tracer_stw; }
+
   // The Concurrent Marking reference processor...
   ReferenceProcessor* ref_processor_cm() const { return _ref_processor_cm; }
 
--- a/src/share/vm/gc/g1/g1CollectorPolicy.cpp	Tue Jun 30 15:26:20 2015 -0700
+++ b/src/share/vm/gc/g1/g1CollectorPolicy.cpp	Thu Apr 30 13:33:23 2015 +0200
@@ -865,7 +865,7 @@
   _cur_mark_stop_world_time_ms += elapsed_time_ms;
   _prev_collection_pause_end_ms += elapsed_time_ms;
 
-  _mmu_tracker->add_pause(_mark_remark_start_sec, end_time_sec, true);
+  _mmu_tracker->add_pause(_mark_remark_start_sec, end_time_sec, _g1->gc_tracer_cm()->gc_id());
 }
 
 void G1CollectorPolicy::record_concurrent_mark_cleanup_start() {
@@ -961,7 +961,7 @@
   }
 
   _mmu_tracker->add_pause(end_time_sec - pause_time_ms/1000.0,
-                          end_time_sec, false);
+                          end_time_sec, _g1->gc_tracer_stw()->gc_id());
 
   evacuation_info.set_collectionset_used_before(_collection_set_bytes_used_before);
   evacuation_info.set_bytes_copied(_bytes_copied_during_gc);
@@ -1597,7 +1597,7 @@
   _concurrent_mark_cleanup_times_ms->add(elapsed_time_ms);
   _cur_mark_stop_world_time_ms += elapsed_time_ms;
   _prev_collection_pause_end_ms += elapsed_time_ms;
-  _mmu_tracker->add_pause(_mark_cleanup_start_sec, end_sec, true);
+  _mmu_tracker->add_pause(_mark_cleanup_start_sec, end_sec, _g1->gc_tracer_cm()->gc_id());
 }
 
 // Add the heap region at the head of the non-incremental collection set
--- a/src/share/vm/gc/g1/g1MMUTracker.cpp	Tue Jun 30 15:26:20 2015 -0700
+++ b/src/share/vm/gc/g1/g1MMUTracker.cpp	Thu Apr 30 13:33:23 2015 +0200
@@ -24,6 +24,7 @@
 
 #include "precompiled.hpp"
 #include "gc/g1/g1MMUTracker.hpp"
+#include "gc/shared/gcTrace.hpp"
 #include "runtime/mutexLocker.hpp"
 #include "utilities/ostream.hpp"
 
@@ -75,7 +76,7 @@
   return gc_time;
 }
 
-void G1MMUTrackerQueue::add_pause(double start, double end, bool gc_thread) {
+void G1MMUTrackerQueue::add_pause(double start, double end, const GCId& gcId) {
   double duration = end - start;
 
   remove_expired_entries(end);
@@ -102,6 +103,10 @@
     ++_no_entries;
   }
   _array[_head_index] = G1MMUTrackerQueueElem(start, end);
+
+  // Current entry needs to be added before calculating the value
+  double slice_time = calculate_gc_time(end);
+  G1MMUTracer::report_mmu(gcId, _time_slice, slice_time, _max_gc_time);
 }
 
 // basically the _internal call does not remove expired entries
--- a/src/share/vm/gc/g1/g1MMUTracker.hpp	Tue Jun 30 15:26:20 2015 -0700
+++ b/src/share/vm/gc/g1/g1MMUTracker.hpp	Thu Apr 30 13:33:23 2015 +0200
@@ -25,6 +25,7 @@
 #ifndef SHARE_VM_GC_G1_G1MMUTRACKER_HPP
 #define SHARE_VM_GC_G1_G1MMUTRACKER_HPP
 
+#include "gc/shared/gcId.hpp"
 #include "memory/allocation.hpp"
 #include "utilities/debug.hpp"
 
@@ -42,7 +43,7 @@
 public:
   G1MMUTracker(double time_slice, double max_gc_time);
 
-  virtual void add_pause(double start, double end, bool gc_thread) = 0;
+  virtual void add_pause(double start, double end, const GCId& gcId) = 0;
   virtual double when_sec(double current_time, double pause_time) = 0;
 
   double max_gc_time() {
@@ -126,7 +127,7 @@
 public:
   G1MMUTrackerQueue(double time_slice, double max_gc_time);
 
-  virtual void add_pause(double start, double end, bool gc_thread);
+  virtual void add_pause(double start, double end, const GCId& gcId);
 
   virtual double when_sec(double current_time, double pause_time);
 };
--- a/src/share/vm/gc/shared/gcTrace.cpp	Tue Jun 30 15:26:20 2015 -0700
+++ b/src/share/vm/gc/shared/gcTrace.cpp	Thu Apr 30 13:33:23 2015 +0200
@@ -221,6 +221,12 @@
 }
 
 #if INCLUDE_ALL_GCS
+void G1MMUTracer::report_mmu(const GCId& gcId, double timeSlice, double gcTime, double maxTime) {
+  assert(!gcId.is_undefined(), "Undefined GC id");
+
+  send_g1_mmu_event(gcId, timeSlice, gcTime, maxTime);
+}
+
 void G1NewTracer::report_yc_type(G1YCType type) {
   assert_set_gc_id();
 
--- a/src/share/vm/gc/shared/gcTrace.hpp	Tue Jun 30 15:26:20 2015 -0700
+++ b/src/share/vm/gc/shared/gcTrace.hpp	Thu Apr 30 13:33:23 2015 +0200
@@ -239,6 +239,13 @@
 };
 
 #if INCLUDE_ALL_GCS
+class G1MMUTracer : public AllStatic {
+  static void send_g1_mmu_event(const GCId& gcId, double timeSlice, double gcTime, double maxTime);
+
+ public:
+  static void report_mmu(const GCId& gcId, double timeSlice, double gcTime, double maxTime);
+};
+
 class G1NewTracer : public YoungGCTracer {
   G1YoungGCInfo _g1_young_gc_info;
 
--- a/src/share/vm/gc/shared/gcTraceSend.cpp	Tue Jun 30 15:26:20 2015 -0700
+++ b/src/share/vm/gc/shared/gcTraceSend.cpp	Thu Apr 30 13:33:23 2015 +0200
@@ -199,6 +199,17 @@
   }
 }
 
+void G1MMUTracer::send_g1_mmu_event(const GCId& gcId, double timeSlice, double gcTime, double maxTime) {
+  EventGCG1MMU e;
+  if (e.should_commit()) {
+    e.set_gcId(gcId.id());
+    e.set_timeSlice(timeSlice);
+    e.set_gcTime(gcTime);
+    e.set_maxGcTime(maxTime);
+    e.commit();
+  }
+}
+
 void G1NewTracer::send_evacuation_info_event(EvacuationInfo* info) {
   EventEvacuationInfo e;
   if (e.should_commit()) {
--- a/src/share/vm/trace/trace.xml	Tue Jun 30 15:26:20 2015 -0700
+++ b/src/share/vm/trace/trace.xml	Thu Apr 30 13:33:23 2015 +0200
@@ -305,6 +305,13 @@
       <value type="G1YCTYPE" field="type" label="Type" />
     </event>
 
+    <event id="GCG1MMU" path="vm/gc/detailed/g1_mmu_info" label="G1 MMU Information" is_instant="true">
+      <value type="UINT" field="gcId" label="GC ID" relation="GC_ID"/>
+      <value type="DOUBLE" field="timeSlice" label="Time slice used to calculate MMU"/>
+      <value type="DOUBLE" field="gcTime" label="Time spent on GC during last time slice"/>
+      <value type="DOUBLE" field="maxGcTime" label="Max time allowed to be spent on GC during last time slice"/>
+    </event>
+
     <event id="EvacuationInfo" path="vm/gc/detailed/evacuation_info" label="Evacuation Information" is_instant="true">
       <value type="UINT" field="gcId" label="GC ID" relation="GC_ID"/>
       <value type="UINT" field="cSetRegions" label="Collection Set Regions"/>