8324334: Shenandoah: Improve end of process report

Reviewed-by: kdnilsen, ysr

src/hotspot/share/gc/shenandoah/heuristics/shenandoahHeuristics.cpp

@@ -45,8 +45,6 @@ int ShenandoahHeuristics::compare_by_garbage(RegionData a, RegionData b) {
 ShenandoahHeuristics::ShenandoahHeuristics(ShenandoahSpaceInfo* space_info) :
   _space_info(space_info),
   _region_data(nullptr),
-  _degenerated_cycles_in_a_row(0),
-  _successful_cycles_in_a_row(0),
   _cycle_start(os::elapsedTime()),
   _last_cycle_end(0),
   _gc_times_learned(0),
@@ -199,7 +197,7 @@ bool ShenandoahHeuristics::should_start_gc() {
 }
 
 bool ShenandoahHeuristics::should_degenerate_cycle() {
-  return _degenerated_cycles_in_a_row <= ShenandoahFullGCThreshold;
+  return ShenandoahHeap::heap()->shenandoah_policy()->consecutive_degenerated_gc_count() <= ShenandoahFullGCThreshold;
 }
 
 void ShenandoahHeuristics::adjust_penalty(intx step) {
@@ -220,9 +218,6 @@ void ShenandoahHeuristics::adjust_penalty(intx step) {
 }
 
 void ShenandoahHeuristics::record_success_concurrent() {
-  _degenerated_cycles_in_a_row = 0;
-  _successful_cycles_in_a_row++;
-
   _gc_time_history->add(time_since_last_gc());
   _gc_times_learned++;
 
@@ -230,16 +225,10 @@ void ShenandoahHeuristics::record_success_concurrent() {
 }
 
 void ShenandoahHeuristics::record_success_degenerated() {
-  _degenerated_cycles_in_a_row++;
-  _successful_cycles_in_a_row = 0;
-
   adjust_penalty(Degenerated_Penalty);
 }
 
 void ShenandoahHeuristics::record_success_full() {
-  _degenerated_cycles_in_a_row = 0;
-  _successful_cycles_in_a_row++;
-
   adjust_penalty(Full_Penalty);
 }
 
@@ -254,8 +243,7 @@ void ShenandoahHeuristics::record_requested_gc() {
 }
 
 bool ShenandoahHeuristics::can_unload_classes() {
-  if (!ClassUnloading) return false;
+  return ClassUnloading;
-  return true;
 }
 
 bool ShenandoahHeuristics::should_unload_classes() {

src/hotspot/share/gc/shenandoah/heuristics/shenandoahHeuristics.hpp

@@ -80,9 +80,6 @@ protected:
 
   RegionData* _region_data;
 
-  uint _degenerated_cycles_in_a_row;
-  uint _successful_cycles_in_a_row;
-
   double _cycle_start;
   double _last_cycle_end;
 

src/hotspot/share/gc/shenandoah/shenandoahCollectorPolicy.cpp

@@ -31,21 +31,22 @@
 
 ShenandoahCollectorPolicy::ShenandoahCollectorPolicy() :
   _success_concurrent_gcs(0),
+  _abbreviated_concurrent_gcs(0),
   _success_degenerated_gcs(0),
+  _abbreviated_degenerated_gcs(0),
   _success_full_gcs(0),
+  _consecutive_degenerated_gcs(0),
   _alloc_failure_degenerated(0),
   _alloc_failure_degenerated_upgrade_to_full(0),
   _alloc_failure_full(0),
   _explicit_concurrent(0),
   _explicit_full(0),
   _implicit_concurrent(0),
-  _implicit_full(0),
+  _implicit_full(0) {
-  _cycle_counter(0) {
 
   Copy::zero_to_bytes(_degen_points, sizeof(size_t) * ShenandoahGC::_DEGENERATED_LIMIT);
 
   _tracer = new ShenandoahTracer();
-
 }
 
 void ShenandoahCollectorPolicy::record_explicit_to_concurrent() {
@@ -75,29 +76,31 @@ void ShenandoahCollectorPolicy::record_alloc_failure_to_degenerated(ShenandoahGC
 }
 
 void ShenandoahCollectorPolicy::record_degenerated_upgrade_to_full() {
+  _consecutive_degenerated_gcs = 0;
   _alloc_failure_degenerated_upgrade_to_full++;
 }
 
-void ShenandoahCollectorPolicy::record_success_concurrent() {
+void ShenandoahCollectorPolicy::record_success_concurrent(bool is_abbreviated) {
+  _consecutive_degenerated_gcs = 0;
   _success_concurrent_gcs++;
+  if (is_abbreviated) {
+    _abbreviated_concurrent_gcs++;
+  }
 }
 
-void ShenandoahCollectorPolicy::record_success_degenerated() {
+void ShenandoahCollectorPolicy::record_success_degenerated(bool is_abbreviated) {
   _success_degenerated_gcs++;
+  _consecutive_degenerated_gcs++;
+  if (is_abbreviated) {
+    _abbreviated_degenerated_gcs++;
+  }
 }
 
 void ShenandoahCollectorPolicy::record_success_full() {
+  _consecutive_degenerated_gcs = 0;
   _success_full_gcs++;
 }
 
-size_t ShenandoahCollectorPolicy::cycle_counter() const {
-  return _cycle_counter;
-}
-
-void ShenandoahCollectorPolicy::record_cycle_start() {
-  _cycle_counter++;
-}
-
 void ShenandoahCollectorPolicy::record_shutdown() {
   _in_shutdown.set();
 }
@@ -110,28 +113,34 @@ void ShenandoahCollectorPolicy::print_gc_stats(outputStream* out) const {
   out->print_cr("Under allocation pressure, concurrent cycles may cancel, and either continue cycle");
   out->print_cr("under stop-the-world pause or result in stop-the-world Full GC. Increase heap size,");
   out->print_cr("tune GC heuristics, set more aggressive pacing delay, or lower allocation rate");
-  out->print_cr("to avoid Degenerated and Full GC cycles.");
+  out->print_cr("to avoid Degenerated and Full GC cycles. Abbreviated cycles are those which found");
+  out->print_cr("enough regions with no live objects to skip evacuation.");
   out->cr();
 
-  out->print_cr(SIZE_FORMAT_W(5) " successful concurrent GCs",         _success_concurrent_gcs);
+  size_t completed_gcs = _success_full_gcs + _success_degenerated_gcs + _success_concurrent_gcs;
-  out->print_cr("  " SIZE_FORMAT_W(5) " invoked explicitly",           _explicit_concurrent);
+  out->print_cr(SIZE_FORMAT_W(5) " Completed GCs", completed_gcs);
-  out->print_cr("  " SIZE_FORMAT_W(5) " invoked implicitly",           _implicit_concurrent);
+  out->print_cr(SIZE_FORMAT_W(5) " Successful Concurrent GCs (%.2f%%)",  _success_concurrent_gcs, percent_of(_success_concurrent_gcs, completed_gcs));
+  out->print_cr("  " SIZE_FORMAT_W(5) " invoked explicitly (%.2f%%)",    _explicit_concurrent, percent_of(_explicit_concurrent, _success_concurrent_gcs));
+  out->print_cr("  " SIZE_FORMAT_W(5) " invoked implicitly (%.2f%%)",    _implicit_concurrent, percent_of(_implicit_concurrent, _success_concurrent_gcs));
+  out->print_cr("  " SIZE_FORMAT_W(5) " abbreviated (%.2f%%)",           _abbreviated_concurrent_gcs, percent_of(_abbreviated_concurrent_gcs, _success_concurrent_gcs));
   out->cr();
 
-  out->print_cr(SIZE_FORMAT_W(5) " Degenerated GCs",                   _success_degenerated_gcs);
+  size_t degenerated_gcs = _alloc_failure_degenerated_upgrade_to_full + _success_degenerated_gcs;
-  out->print_cr("  " SIZE_FORMAT_W(5) " caused by allocation failure", _alloc_failure_degenerated);
+  out->print_cr(SIZE_FORMAT_W(5) " Degenerated GCs (%.2f%%)", degenerated_gcs, percent_of(degenerated_gcs, completed_gcs));
+  out->print_cr("  " SIZE_FORMAT_W(5) " upgraded to Full GC (%.2f%%)",          _alloc_failure_degenerated_upgrade_to_full, percent_of(_alloc_failure_degenerated_upgrade_to_full, degenerated_gcs));
+  out->print_cr("  " SIZE_FORMAT_W(5) " caused by allocation failure (%.2f%%)", _alloc_failure_degenerated, percent_of(_alloc_failure_degenerated, degenerated_gcs));
+  out->print_cr("  " SIZE_FORMAT_W(5) " abbreviated (%.2f%%)",                  _abbreviated_degenerated_gcs, percent_of(_abbreviated_degenerated_gcs, degenerated_gcs));
   for (int c = 0; c < ShenandoahGC::_DEGENERATED_LIMIT; c++) {
     if (_degen_points[c] > 0) {
       const char* desc = ShenandoahGC::degen_point_to_string((ShenandoahGC::ShenandoahDegenPoint)c);
       out->print_cr("    " SIZE_FORMAT_W(5) " happened at %s",         _degen_points[c], desc);
     }
   }
-  out->print_cr("  " SIZE_FORMAT_W(5) " upgraded to Full GC",          _alloc_failure_degenerated_upgrade_to_full);
   out->cr();
 
-  out->print_cr(SIZE_FORMAT_W(5) " Full GCs",                          _success_full_gcs + _alloc_failure_degenerated_upgrade_to_full);
+  out->print_cr(SIZE_FORMAT_W(5) " Full GCs (%.2f%%)",                          _success_full_gcs, percent_of(_success_full_gcs, completed_gcs));
-  out->print_cr("  " SIZE_FORMAT_W(5) " invoked explicitly",           _explicit_full);
+  out->print_cr("  " SIZE_FORMAT_W(5) " invoked explicitly (%.2f%%)",           _explicit_full, percent_of(_explicit_full, _success_full_gcs));
-  out->print_cr("  " SIZE_FORMAT_W(5) " invoked implicitly",           _implicit_full);
+  out->print_cr("  " SIZE_FORMAT_W(5) " invoked implicitly (%.2f%%)",           _implicit_full, percent_of(_implicit_full, _success_full_gcs));
-  out->print_cr("  " SIZE_FORMAT_W(5) " caused by allocation failure", _alloc_failure_full);
+  out->print_cr("  " SIZE_FORMAT_W(5) " caused by allocation failure (%.2f%%)", _alloc_failure_full, percent_of(_alloc_failure_full, _success_full_gcs));
-  out->print_cr("  " SIZE_FORMAT_W(5) " upgraded from Degenerated GC", _alloc_failure_degenerated_upgrade_to_full);
+  out->print_cr("  " SIZE_FORMAT_W(5) " upgraded from Degenerated GC (%.2f%%)", _alloc_failure_degenerated_upgrade_to_full, percent_of(_alloc_failure_degenerated_upgrade_to_full, _success_full_gcs));
 }

src/hotspot/share/gc/shenandoah/shenandoahCollectorPolicy.hpp

@@ -39,9 +39,12 @@ public:
 class ShenandoahCollectorPolicy : public CHeapObj<mtGC> {
 private:
   size_t _success_concurrent_gcs;
+  size_t _abbreviated_concurrent_gcs;
   size_t _success_degenerated_gcs;
+  size_t _abbreviated_degenerated_gcs;
   // Written by control thread, read by mutators
   volatile size_t _success_full_gcs;
+  uint _consecutive_degenerated_gcs;
   size_t _alloc_failure_degenerated;
   size_t _alloc_failure_degenerated_upgrade_to_full;
   size_t _alloc_failure_full;
@@ -52,20 +55,19 @@ private:
   size_t _degen_points[ShenandoahGC::_DEGENERATED_LIMIT];
 
   ShenandoahSharedFlag _in_shutdown;
-
   ShenandoahTracer* _tracer;
 
-  size_t _cycle_counter;
 
 public:
   ShenandoahCollectorPolicy();
 
-  // TODO: This is different from gc_end: that one encompasses one VM operation.
+  // A collection cycle may be "abbreviated" if Shenandoah finds a sufficient percentage
-  // These two encompass the entire cycle.
+  // of regions that contain no live objects (ShenandoahImmediateThreshold). These cycles
-  void record_cycle_start();
+  // end after final mark, skipping the evacuation and reference-updating phases. Such
-
+  // cycles are very efficient and are worth tracking. Note that both degenerated and
-  void record_success_concurrent();
+  // concurrent cycles can be abbreviated.
-  void record_success_degenerated();
+  void record_success_concurrent(bool is_abbreviated);
+  void record_success_degenerated(bool is_abbreviated);
   void record_success_full();
   void record_alloc_failure_to_degenerated(ShenandoahGC::ShenandoahDegenPoint point);
   void record_alloc_failure_to_full();
@@ -80,13 +82,18 @@ public:
 
   ShenandoahTracer* tracer() {return _tracer;}
 
-  size_t cycle_counter() const;
-
   void print_gc_stats(outputStream* out) const;
 
   size_t full_gc_count() const {
     return _success_full_gcs + _alloc_failure_degenerated_upgrade_to_full;
   }
+
+  // If the heuristics find that the number of consecutive degenerated cycles is above
+  // ShenandoahFullGCThreshold, then they will initiate a Full GC upon an allocation
+  // failure.
+  inline size_t consecutive_degenerated_gc_count() const {
+    return _consecutive_degenerated_gcs;
+  }
 };
 
 #endif // SHARE_GC_SHENANDOAH_SHENANDOAHCOLLECTORPOLICY_HPP

src/hotspot/share/gc/shenandoah/shenandoahConcurrentGC.cpp

@@ -87,7 +87,8 @@ public:
 
 ShenandoahConcurrentGC::ShenandoahConcurrentGC() :
   _mark(),
-  _degen_point(ShenandoahDegenPoint::_degenerated_unset) {
+  _degen_point(ShenandoahDegenPoint::_degenerated_unset),
+  _abbreviated(false) {
 }
 
 ShenandoahGC::ShenandoahDegenPoint ShenandoahConcurrentGC::degen_point() const {
@@ -188,6 +189,7 @@ bool ShenandoahConcurrentGC::collect(GCCause::Cause cause) {
     entry_cleanup_complete();
   } else {
     vmop_entry_final_roots();
+    _abbreviated = true;
   }
 
   return true;

src/hotspot/share/gc/shenandoah/shenandoahConcurrentGC.hpp

@@ -45,12 +45,16 @@ class ShenandoahConcurrentGC : public ShenandoahGC {
 private:
   ShenandoahConcurrentMark  _mark;
   ShenandoahDegenPoint      _degen_point;
+  bool                      _abbreviated;
 
 public:
   ShenandoahConcurrentGC();
   bool collect(GCCause::Cause cause);
   ShenandoahDegenPoint degen_point() const;
 
+  // Return true if this cycle found enough immediate garbage to skip evacuation
+  bool abbreviated() const { return _abbreviated; }
+
   // Cancel ongoing concurrent GC
   static void cancel();
 private:

src/hotspot/share/gc/shenandoah/shenandoahControlThread.cpp

@@ -396,7 +396,7 @@ void ShenandoahControlThread::service_concurrent_normal_cycle(GCCause::Cause cau
   if (gc.collect(cause)) {
     // Cycle is complete
     heap->heuristics()->record_success_concurrent();
-    heap->shenandoah_policy()->record_success_concurrent();
+    heap->shenandoah_policy()->record_success_concurrent(gc.abbreviated());
   } else {
     assert(heap->cancelled_gc(), "Must have been cancelled");
     check_cancellation_or_degen(gc.degen_point());
@@ -427,10 +427,6 @@ void ShenandoahControlThread::service_stw_full_cycle(GCCause::Cause cause) {
 
   ShenandoahFullGC gc;
   gc.collect(cause);
-
-  ShenandoahHeap* const heap = ShenandoahHeap::heap();
-  heap->heuristics()->record_success_full();
-  heap->shenandoah_policy()->record_success_full();
 }
 
 void ShenandoahControlThread::service_stw_degenerated_cycle(GCCause::Cause cause, ShenandoahGC::ShenandoahDegenPoint point) {
@@ -441,10 +437,6 @@ void ShenandoahControlThread::service_stw_degenerated_cycle(GCCause::Cause cause
 
   ShenandoahDegenGC gc(point);
   gc.collect(cause);
-
-  ShenandoahHeap* const heap = ShenandoahHeap::heap();
-  heap->heuristics()->record_success_degenerated();
-  heap->shenandoah_policy()->record_success_degenerated();
 }
 
 void ShenandoahControlThread::service_uncommit(double shrink_before, size_t shrink_until) {

src/hotspot/share/gc/shenandoah/shenandoahDegeneratedGC.cpp

@@ -44,7 +44,8 @@
 
 ShenandoahDegenGC::ShenandoahDegenGC(ShenandoahDegenPoint degen_point) :
   ShenandoahGC(),
-  _degen_point(degen_point) {
+  _degen_point(degen_point),
+  _abbreviated(false) {
 }
 
 bool ShenandoahDegenGC::collect(GCCause::Cause cause) {
@@ -193,6 +194,8 @@ void ShenandoahDegenGC::op_degenerated() {
       if (heap->has_forwarded_objects()) {
         op_init_updaterefs();
         assert(!heap->cancelled_gc(), "STW reference update can not OOM");
+      } else {
+        _abbreviated = true;
       }
 
     case _degenerated_updaterefs:
@@ -230,6 +233,8 @@ void ShenandoahDegenGC::op_degenerated() {
     op_degenerated_futile();
   } else {
     heap->notify_gc_progress();
+    heap->shenandoah_policy()->record_success_degenerated(_abbreviated);
+    heap->heuristics()->record_success_degenerated();
   }
 }
 
@@ -343,17 +348,11 @@ void ShenandoahDegenGC::op_cleanup_complete() {
 }
 
 void ShenandoahDegenGC::op_degenerated_fail() {
-  log_info(gc)("Cannot finish degeneration, upgrading to Full GC");
+  upgrade_to_full();
-  ShenandoahHeap::heap()->shenandoah_policy()->record_degenerated_upgrade_to_full();
-
-  ShenandoahFullGC full_gc;
-  full_gc.op_full(GCCause::_shenandoah_upgrade_to_full_gc);
 }
 
 void ShenandoahDegenGC::op_degenerated_futile() {
-  ShenandoahHeap::heap()->shenandoah_policy()->record_degenerated_upgrade_to_full();
+  upgrade_to_full();
-  ShenandoahFullGC full_gc;
-  full_gc.op_full(GCCause::_shenandoah_upgrade_to_full_gc);
 }
 
 const char* ShenandoahDegenGC::degen_event_message(ShenandoahDegenPoint point) const {
@@ -373,3 +372,10 @@ const char* ShenandoahDegenGC::degen_event_message(ShenandoahDegenPoint point) c
       return "ERROR";
   }
 }
+
+void ShenandoahDegenGC::upgrade_to_full() {
+  log_info(gc)("Degenerated GC upgrading to Full GC");
+  ShenandoahHeap::heap()->shenandoah_policy()->record_degenerated_upgrade_to_full();
+  ShenandoahFullGC full_gc;
+  full_gc.op_full(GCCause::_shenandoah_upgrade_to_full_gc);
+}

src/hotspot/share/gc/shenandoah/shenandoahDegeneratedGC.hpp

@@ -33,6 +33,7 @@ class ShenandoahDegenGC : public ShenandoahGC {
   friend class VM_ShenandoahDegeneratedGC;
 private:
   const ShenandoahDegenPoint  _degen_point;
+  bool _abbreviated;
 
 public:
   ShenandoahDegenGC(ShenandoahDegenPoint degen_point);
@@ -48,6 +49,7 @@ private:
   void op_finish_mark();
   void op_prepare_evacuation();
   void op_cleanup_early();
+
   void op_evacuate();
   void op_init_updaterefs();
   void op_updaterefs();
@@ -58,6 +60,9 @@ private:
   void op_degenerated_futile();
   void op_degenerated_fail();
 
+  // Turns this degenerated cycle into a full gc without leaving the safepoint
+  void upgrade_to_full();
+
   const char* degen_event_message(ShenandoahDegenPoint point) const;
 };
 

src/hotspot/share/gc/shenandoah/shenandoahFullGC.cpp

@@ -31,6 +31,7 @@
 #include "gc/shared/tlab_globals.hpp"
 #include "gc/shared/workerThread.hpp"
 #include "gc/shenandoah/heuristics/shenandoahHeuristics.hpp"
+#include "gc/shenandoah/shenandoahCollectorPolicy.hpp"
 #include "gc/shenandoah/shenandoahConcurrentGC.hpp"
 #include "gc/shenandoah/shenandoahCollectionSet.hpp"
 #include "gc/shenandoah/shenandoahFreeSet.hpp"
@@ -105,15 +106,21 @@ void ShenandoahFullGC::op_full(GCCause::Cause cause) {
   // Perform full GC
   do_it(cause);
 
+  ShenandoahHeap* const heap = ShenandoahHeap::heap();
+
   metrics.snap_after();
 
   if (metrics.is_good_progress()) {
-    ShenandoahHeap::heap()->notify_gc_progress();
+    heap->notify_gc_progress();
   } else {
     // Nothing to do. Tell the allocation path that we have failed to make
     // progress, and it can finally fail.
-    ShenandoahHeap::heap()->notify_gc_no_progress();
+    heap->notify_gc_no_progress();
   }
+
+  // Regardless if progress was made, we record that we completed a "successful" full GC.
+  heap->heuristics()->record_success_full();
+  heap->shenandoah_policy()->record_success_full();
 }
 
 void ShenandoahFullGC::do_it(GCCause::Cause gc_cause) {

src/hotspot/share/gc/shenandoah/shenandoahUtils.cpp

@@ -49,7 +49,6 @@ ShenandoahGCSession::ShenandoahGCSession(GCCause::Cause cause) :
   _tracer->report_gc_start(cause, _timer->gc_start());
   _heap->trace_heap_before_gc(_tracer);
 
-  _heap->shenandoah_policy()->record_cycle_start();
   _heap->heuristics()->record_cycle_start();
   _trace_cycle.initialize(_heap->cycle_memory_manager(), cause,
           "end of GC cycle",