# HG changeset patch
# User Roman Kennke <rkennke@redhat.com>
# Date 1423674339 -3600
# Node ID a5cdb779dc9c45cff04d2f7aac8c75c3b4c2d002
# Parent  0f18b2da554c8cf2c2fcec274b45eec7c6d95d88
Refactor timing code to be more generic and easier to extend.

diff -r 0f18b2da554c -r a5cdb779dc9c src/share/vm/gc_implementation/shenandoah/shenandoahCollectorPolicy.cpp
--- a/src/share/vm/gc_implementation/shenandoah/shenandoahCollectorPolicy.cpp	Tue Feb 03 18:59:00 2015 +0100
+++ b/src/share/vm/gc_implementation/shenandoah/shenandoahCollectorPolicy.cpp	Wed Feb 11 18:05:39 2015 +0100
@@ -1,38 +1,11 @@
 #include "gc_implementation/shenandoah/shenandoahCollectorPolicy.hpp"
 #include "gc_implementation/shenandoah/shenandoahHeap.hpp"
-#include "utilities/numberSeq.hpp"
 
 class ShenandoahHeuristics : public CHeapObj<mtGC> {
-private:
-  NumberSeq _init_mark_ms;
-  NumberSeq _final_mark_ms;
-  NumberSeq _final_evac_ms;
-  NumberSeq _final_uprefs_ms;
-
-  NumberSeq _fullgc_ms;
-
-  NumberSeq _concurrent_mark_times_ms;
-  NumberSeq _concurrent_evacuation_times_ms;
 
   NumberSeq _allocation_rate_bytes;
   NumberSeq _reclamation_rate_bytes;
 
-  double _init_mark_start;
-  double _concurrent_mark_start;
-  double _final_mark_start;
-  double _final_evac_start;
-  double _final_uprefs_start;
-  double _concurrent_evacuation_start; 
-  double _fullgc_start; 
-
-  int _init_mark_count;
-  int _final_mark_count;
-  int _final_evac_count;
-  int _final_uprefs_count;
-  int _concurrent_evacuation_count;
-  int _concurrent_mark_count;
-  int _fullgc_count;
-
   size_t _bytes_allocated_since_CM;
   size_t _bytes_reclaimed_this_cycle;
 
@@ -40,20 +13,6 @@
 
   ShenandoahHeuristics();
 
-  void record_init_mark_start();
-  void record_init_mark_end();
-  void record_concurrent_mark_start();
-  void record_concurrent_mark_end();
-  void record_final_mark_start();
-  void record_final_mark_end();
-  void record_final_evacuation_start();
-  void record_final_evacuation_end();
-  void record_final_update_refs_start();
-  void record_final_update_refs_end();
-  void record_concurrent_evacuation_start();
-  void record_concurrent_evacuation_end();  
-  void record_fullgc_start();
-  void record_fullgc_end();
   void record_bytes_allocated(size_t bytes);
   void record_bytes_reclaimed(size_t bytes);
 
@@ -65,108 +24,26 @@
 };
 
 ShenandoahHeuristics::ShenandoahHeuristics() :
-  _init_mark_start(0),
-  _concurrent_mark_start(0),
-  _final_mark_start(0),
-  _final_evac_start(0),
-  _final_uprefs_start(0),
-  _concurrent_evacuation_start(0),
-  _fullgc_start(0),
   _bytes_allocated_since_CM(0),
-  _bytes_reclaimed_this_cycle(0),
-  _init_mark_count(0),
-  _final_mark_count(0),
-  _final_evac_count(0),
-  _final_uprefs_count(0),
-  _fullgc_count(0),
-  _concurrent_mark_count(0),
-  _concurrent_evacuation_count(0)
+  _bytes_reclaimed_this_cycle(0)
 {
   if (PrintGCDetails)
     tty->print_cr("initializing heuristics");
 }
 
-void ShenandoahHeuristics::record_init_mark_start() { 
-  _init_mark_start = os::elapsedTime();
-}
-
-void ShenandoahHeuristics::record_init_mark_end()   { 
-  double end = os::elapsedTime();
-
-  double elapsed = (os::elapsedTime() - _init_mark_start); 
-  _init_mark_ms.add(elapsed * 1000);
-  if (ShenandoahGCVerbose && PrintGCDetails)
-    tty->print_cr("PolicyPrint: InitialMark %d took %lf ms", _init_mark_count++, elapsed * 1000);
-}
-
-void ShenandoahHeuristics::record_final_mark_start() { 
-  _final_mark_start = os::elapsedTime();
-}
-
-void ShenandoahHeuristics::record_final_mark_end()   { 
-  double elapsed = os::elapsedTime() - _final_mark_start;
-  _final_mark_ms.add(elapsed * 1000);
-  if (ShenandoahGCVerbose && PrintGCDetails)
-    tty->print_cr("PolicyPrint: FinalMark %d took %lf ms", _final_mark_count++, elapsed * 1000);
-}
-
-void ShenandoahHeuristics::record_final_evacuation_start() {
-  _final_evac_start = os::elapsedTime();
-}
-
-void ShenandoahHeuristics::record_final_evacuation_end() {
-  double elapsed = os::elapsedTime() - _final_evac_start;
-  _final_evac_ms.add(elapsed * 1000);
-  if (ShenandoahGCVerbose && PrintGCDetails) {
-    tty->print_cr("PolicyPrint: FinalEvacuation "INT32_FORMAT" took %lf ms", _final_evac_count++, elapsed * 1000);
-  }
-}
-
-void ShenandoahHeuristics::record_final_update_refs_start() { 
-  _final_uprefs_start = os::elapsedTime();
+void ShenandoahCollectorPolicy::record_phase_start(TimingPhase phase) { 
+  _timing_data[phase]._start = os::elapsedTime();
 }
 
-void ShenandoahHeuristics::record_final_update_refs_end()   { 
-  double elapsed = os::elapsedTime() - _final_uprefs_start;
-  _final_uprefs_ms.add(elapsed * 1000);
-  if (ShenandoahGCVerbose && PrintGCDetails)
-    tty->print_cr("PolicyPrint: FinalUpdateRefs "INT32_FORMAT" took %lf ms", _final_uprefs_count++, elapsed * 1000);
-}
-
-void ShenandoahHeuristics::record_concurrent_evacuation_start() { 
-  _concurrent_evacuation_start = os::elapsedTime();
-}
-
-void ShenandoahHeuristics::record_concurrent_evacuation_end()   { 
-  double elapsed = os::elapsedTime() - _concurrent_evacuation_start;
-  _concurrent_evacuation_times_ms.add(elapsed * 1000);
-  if (ShenandoahGCVerbose && PrintGCDetails)
-    tty->print_cr("PolicyPrint: Concurrent Evacuation %d took %lf ms", 
-		  _concurrent_evacuation_count++, elapsed * 1000);
-}
+void ShenandoahCollectorPolicy::record_phase_end(TimingPhase phase) {
+  double end = os::elapsedTime();
 
-void ShenandoahHeuristics::record_concurrent_mark_start() { 
-  _concurrent_mark_start = os::elapsedTime();
-}
-
-void ShenandoahHeuristics::record_concurrent_mark_end()   { 
-  double elapsed = os::elapsedTime() - _concurrent_mark_start;
-  _concurrent_mark_times_ms.add(elapsed * 1000);
-  if (ShenandoahGCVerbose && PrintGCDetails)
-    tty->print_cr("PolicyPrint: Concurrent Marking "INT32_FORMAT" took %lf ms", 
-		  _concurrent_mark_count++, elapsed * 1000);
-}
-
-void ShenandoahHeuristics::record_fullgc_start() { 
-  _fullgc_start = os::elapsedTime();
-}
-
-void ShenandoahHeuristics::record_fullgc_end()   { 
-  double elapsed = os::elapsedTime() - _fullgc_start;
-  _fullgc_ms.add(elapsed * 1000);
-  if (ShenandoahGCVerbose && PrintGCDetails)
-    tty->print_cr("PolicyPrint: Full GC "INT32_FORMAT" took %lf ms", 
-		  _fullgc_count++, elapsed * 1000);
+  double elapsed = end - _timing_data[phase]._start;
+  _timing_data[phase]._ms.add(elapsed * 1000);
+  if (ShenandoahGCVerbose && PrintGCDetails) {
+    tty->print_cr("PolicyPrint: %s %d took %lf ms", _phase_names[phase],
+                  _timing_data[phase]._count++, elapsed * 1000);
+  }
 }
 
 void ShenandoahHeuristics::record_bytes_allocated(size_t bytes) {
@@ -487,6 +364,15 @@
 
 ShenandoahCollectorPolicy::ShenandoahCollectorPolicy() {
   initialize_all();
+
+  _phase_names[init_mark] = "InitMark";
+  _phase_names[final_mark] = "FinalMark";
+  _phase_names[final_evac] = "FinalEvacuation";
+  _phase_names[final_uprefs] = "FinalUpdateRefs";
+  _phase_names[full_gc] = "FullGC";
+  _phase_names[conc_mark] = "ConcurrentMark";
+  _phase_names[conc_evac] = "ConcurrentEvacuation";
+
   if (ShenandoahGCHeuristics != NULL) {
     if (strcmp(ShenandoahGCHeuristics, "aggressive") == 0) {
       if (ShenandoahLogConfig) {
@@ -568,61 +454,6 @@
   // Nothing to do here (yet).
 }
 
-void ShenandoahCollectorPolicy::record_init_mark_start()  { 
-  _heuristics->record_init_mark_start();
-}
-
-void ShenandoahCollectorPolicy::record_init_mark_end() { 
-  _heuristics->record_init_mark_end();
-}
-void ShenandoahCollectorPolicy::record_final_mark_start() { 
-  _heuristics->record_final_mark_start();
-}
-
-void ShenandoahCollectorPolicy::record_final_mark_end() { 
-  _heuristics->record_final_mark_end();
-}
-
-void ShenandoahCollectorPolicy::record_final_evacuation_start() { 
-  _heuristics->record_final_evacuation_start();
-}
-
-void ShenandoahCollectorPolicy::record_final_evacuation_end() { 
-  _heuristics->record_final_evacuation_end();
-}
-
-void ShenandoahCollectorPolicy::record_final_update_refs_start() { 
-  _heuristics->record_final_update_refs_start();
-}
-
-void ShenandoahCollectorPolicy::record_final_update_refs_end() { 
-  _heuristics->record_final_update_refs_end();
-}
-
-void ShenandoahCollectorPolicy::record_concurrent_evacuation_start() { 
-    _heuristics->record_concurrent_evacuation_start();
-}
-
-void ShenandoahCollectorPolicy::record_concurrent_evacuation_end()   { 
-    _heuristics->record_concurrent_evacuation_end();
-}
-
-void ShenandoahCollectorPolicy::record_concurrent_mark_start() { 
-    _heuristics->record_concurrent_mark_start();
-}
-
-void ShenandoahCollectorPolicy::record_concurrent_mark_end()   { 
-    _heuristics->record_concurrent_mark_end();
-}
-
-void ShenandoahCollectorPolicy::record_fullgc_start() { 
-    _heuristics->record_fullgc_start();
-}
-
-void ShenandoahCollectorPolicy::record_fullgc_end()   { 
-    _heuristics->record_fullgc_end();
-}
-
 void ShenandoahCollectorPolicy::record_bytes_allocated(size_t bytes) {
   _heuristics->record_bytes_allocated(bytes);
 }
@@ -644,32 +475,24 @@
 }
 
 void ShenandoahCollectorPolicy::print_tracing_info() {
-  _heuristics->print_tracing_info();
+  print_summary_sd("Initial Mark Pauses", &(_timing_data[init_mark]._ms));
+  print_summary_sd("Final Mark Pauses", &(_timing_data[final_mark]._ms));
+  print_summary_sd("Final Evacuation Pauses", &(_timing_data[final_evac]._ms));
+  print_summary_sd("Final Update Refs Pauses", &(_timing_data[final_uprefs]._ms));
+  print_summary_sd("Concurrent Marking Times", &(_timing_data[conc_mark]._ms));
+  print_summary_sd("Concurrent Evacuation Times", &(_timing_data[conc_evac]._ms));
+  print_summary_sd("Full GC Times", &(_timing_data[full_gc]._ms));
 }
 
-void print_summary(const char* str,
-		   const NumberSeq* seq)  {
+void ShenandoahCollectorPolicy::print_summary(const char* str, const NumberSeq* seq)  {
   double sum = seq->sum();
   gclog_or_tty->print_cr("%-27s = %8.2lf s (avg = %8.2lf ms)",
-                str, sum / 1000.0, seq->avg());
+                         str, sum / 1000.0, seq->avg());
 }
 
-void print_summary_sd(const char* str,
-		      const NumberSeq* seq) {
+void ShenandoahCollectorPolicy::print_summary_sd(const char* str, const NumberSeq* seq) {
   print_summary(str, seq);
   gclog_or_tty->print_cr("(num = %5d, std dev = %8.2lf ms, max = %8.2lf ms)",
-                seq->num(), seq->sd(), seq->maximum());
+                         seq->num(), seq->sd(), seq->maximum());
 }
 
-void ShenandoahHeuristics::print_tracing_info() {
-  print_summary_sd("Initial Mark Pauses", &_init_mark_ms);
-  print_summary_sd("Final Mark Pauses", &_final_mark_ms);
-  print_summary_sd("Final Evacuation Pauses", &_final_evac_ms);
-  print_summary_sd("Final Update Refs Pauses", &_final_uprefs_ms);
-  print_summary_sd("Concurrent Marking Times", 
-		   &_concurrent_mark_times_ms);
-  print_summary_sd("Concurrent Evacuation Times", 
-		   &_concurrent_evacuation_times_ms);
-  print_summary_sd("Full GC Times", 
-		   &_fullgc_ms);
-}
diff -r 0f18b2da554c -r a5cdb779dc9c src/share/vm/gc_implementation/shenandoah/shenandoahCollectorPolicy.hpp
--- a/src/share/vm/gc_implementation/shenandoah/shenandoahCollectorPolicy.hpp	Tue Feb 03 18:59:00 2015 +0100
+++ b/src/share/vm/gc_implementation/shenandoah/shenandoahCollectorPolicy.hpp	Wed Feb 11 18:05:39 2015 +0100
@@ -8,11 +8,38 @@
 #include "gc_implementation/shenandoah/shenandoahHeapRegionSet.hpp"
 #include "memory/collectorPolicy.hpp"
 #include "runtime/arguments.hpp"
+#include "utilities/numberSeq.hpp"
 
 class ShenandoahHeap;
 class ShenandoahHeuristics;
 
 class ShenandoahCollectorPolicy: public CollectorPolicy {
+
+public:
+  enum TimingPhase {
+    init_mark,
+    final_mark,
+    final_evac,
+    final_uprefs,
+
+    full_gc,
+    conc_mark,
+    conc_evac,
+
+    _num_phases
+  };
+
+private:
+  struct TimingData {
+    NumberSeq _ms;
+    double _start;
+    size_t _count;
+  };
+
+private:
+  TimingData _timing_data[_num_phases];
+  const char* _phase_names[_num_phases];
+
   ShenandoahHeap* _pgc;
   ShenandoahHeuristics* _heuristics;
 
@@ -37,20 +64,9 @@
 
   void post_heap_initialize();
 
-  void record_init_mark_start();
-  void record_init_mark_end();
-  void record_concurrent_mark_start();
-  void record_concurrent_mark_end();
-  void record_final_mark_start();
-  void record_final_mark_end();
-  void record_final_evacuation_start();
-  void record_final_evacuation_end();
-  void record_final_update_refs_start();
-  void record_final_update_refs_end();
-  void record_concurrent_evacuation_start();
-  void record_concurrent_evacuation_end();
-  void record_fullgc_start();
-  void record_fullgc_end();
+  void record_phase_start(TimingPhase phase);
+  void record_phase_end(TimingPhase phase);
+
   void record_bytes_allocated(size_t bytes);
   void record_bytes_reclaimed(size_t bytes);
   bool should_start_concurrent_mark(size_t used, size_t capacity);
@@ -59,6 +75,10 @@
                                        ShenandoahHeapRegionSet* free_set);
 
   void print_tracing_info();
+
+private:
+  void print_summary(const char* str, const NumberSeq* seq);
+  void print_summary_sd(const char* str, const NumberSeq* seq);
 };
 
 
diff -r 0f18b2da554c -r a5cdb779dc9c src/share/vm/gc_implementation/shenandoah/shenandoahConcurrentMark.cpp
--- a/src/share/vm/gc_implementation/shenandoah/shenandoahConcurrentMark.cpp	Tue Feb 03 18:59:00 2015 +0100
+++ b/src/share/vm/gc_implementation/shenandoah/shenandoahConcurrentMark.cpp	Wed Feb 11 18:05:39 2015 +0100
@@ -389,7 +389,7 @@
 
   ShenandoahHeap* sh = (ShenandoahHeap *) Universe::heap();
 
-  sh->shenandoahPolicy()->record_concurrent_mark_start();
+  sh->shenandoahPolicy()->record_phase_start(ShenandoahCollectorPolicy::conc_mark);
 
   uint max_workers = full_gc ? _max_worker_id : _max_conc_worker_id;
   ParallelTaskTerminator terminator(max_workers, _task_queues);
@@ -414,7 +414,7 @@
     TASKQUEUE_STATS_ONLY(reset_taskqueue_stats());
   }
 
-  sh->shenandoahPolicy()->record_concurrent_mark_end();
+  sh->shenandoahPolicy()->record_phase_end(ShenandoahCollectorPolicy::conc_mark);
 }
 
 class FinishDrainSATBBuffersTask : public AbstractGangTask {
diff -r 0f18b2da554c -r a5cdb779dc9c src/share/vm/gc_implementation/shenandoah/shenandoahHeap.cpp
--- a/src/share/vm/gc_implementation/shenandoah/shenandoahHeap.cpp	Tue Feb 03 18:59:00 2015 +0100
+++ b/src/share/vm/gc_implementation/shenandoah/shenandoahHeap.cpp	Wed Feb 11 18:05:39 2015 +0100
@@ -1361,7 +1361,7 @@
     //    heap_region_iterate(&pc1);
   }
 
-  _shenandoah_policy->record_concurrent_evacuation_start();
+  _shenandoah_policy->record_phase_start(ShenandoahCollectorPolicy::conc_evac);
 
   if (ShenandoahGCVerbose) {
     tty->print("Printing all available regions");
@@ -1396,7 +1396,7 @@
     print_heap_regions();
   }
 
-  _shenandoah_policy->record_concurrent_evacuation_end();
+  _shenandoah_policy->record_phase_end(ShenandoahCollectorPolicy::conc_evac);
 }
 
 class VerifyEvacuationClosure: public ExtendedOopClosure {
diff -r 0f18b2da554c -r a5cdb779dc9c src/share/vm/gc_implementation/shenandoah/shenandoahMarkCompact.cpp
--- a/src/share/vm/gc_implementation/shenandoah/shenandoahMarkCompact.cpp	Tue Feb 03 18:59:00 2015 +0100
+++ b/src/share/vm/gc_implementation/shenandoah/shenandoahMarkCompact.cpp	Wed Feb 11 18:05:39 2015 +0100
@@ -31,7 +31,7 @@
   assert(!_heap->is_evacuation_in_progress(), "can't do full-GC while evacuation is in progress");
   assert(!_heap->is_update_references_in_progress(), "can't do full-GC while updating of references is in progress");
 
-  _heap->shenandoahPolicy()->record_fullgc_start();
+  _heap->shenandoahPolicy()->record_phase_start(ShenandoahCollectorPolicy::full_gc);
 
   if (ShenandoahVerify) {
     // Full GC should only be called between regular concurrent cycles, therefore
@@ -69,7 +69,7 @@
 
   _heap->reset_mark_bitmap();
 
-  _heap->shenandoahPolicy()->record_fullgc_end();
+  _heap->shenandoahPolicy()->record_phase_end(ShenandoahCollectorPolicy::full_gc);
 }
 
 void ShenandoahMarkCompact::phase1_mark_heap() {
diff -r 0f18b2da554c -r a5cdb779dc9c src/share/vm/gc_implementation/shenandoah/vm_operations_shenandoah.cpp
--- a/src/share/vm/gc_implementation/shenandoah/vm_operations_shenandoah.cpp	Tue Feb 03 18:59:00 2015 +0100
+++ b/src/share/vm/gc_implementation/shenandoah/vm_operations_shenandoah.cpp	Wed Feb 11 18:05:39 2015 +0100
@@ -16,11 +16,11 @@
 
 void VM_ShenandoahInitMark::doit() {
   ShenandoahHeap *sh = (ShenandoahHeap*) Universe::heap();
-  sh->shenandoahPolicy()->record_init_mark_start();
+  sh->shenandoahPolicy()->record_phase_start(ShenandoahCollectorPolicy::init_mark);
   if (ShenandoahGCVerbose)
     tty->print("vm_ShenandoahInitMark\n");
   sh->start_concurrent_marking();
-  sh->shenandoahPolicy()->record_init_mark_end();
+  sh->shenandoahPolicy()->record_phase_end(ShenandoahCollectorPolicy::init_mark);
 
   if (! ShenandoahConcurrentMarking) {
     sh->concurrentMark()->mark_from_roots(! ShenandoahUpdateRefsEarly);
@@ -100,10 +100,10 @@
   if (ShenandoahGCVerbose)
     tty->print("vm_ShenandoahFinalMark\n");
 
-  sh->shenandoahPolicy()->record_final_mark_start();  
+  sh->shenandoahPolicy()->record_phase_start(ShenandoahCollectorPolicy::final_mark);
   sh->concurrentMark()->finish_mark_from_roots();
   sh->stop_concurrent_marking();
-  sh->shenandoahPolicy()->record_final_mark_end();    
+  sh->shenandoahPolicy()->record_phase_end(ShenandoahCollectorPolicy::final_mark);
 
   sh->prepare_for_concurrent_evacuation();
   sh->set_evacuation_in_progress(true);
@@ -203,7 +203,7 @@
 
   ShenandoahHeap *sh = ShenandoahHeap::heap();
 
-  sh->shenandoahPolicy()->record_final_update_refs_start();
+  sh->shenandoahPolicy()->record_phase_start(ShenandoahCollectorPolicy::final_uprefs);
 
   sh->update_roots();
 
@@ -221,7 +221,7 @@
 
   sh->resize_all_tlabs();
 
-  sh->shenandoahPolicy()->record_final_update_refs_end();
+  sh->shenandoahPolicy()->record_phase_end(ShenandoahCollectorPolicy::final_uprefs);
 }
 
 VM_Operation::VMOp_Type VM_ShenandoahUpdateRefs::type() const {
@@ -237,9 +237,9 @@
     tty->print("vm_ShenandoahUpdateRefs\n");
 
   ShenandoahHeap *sh = ShenandoahHeap::heap();
-  sh->shenandoahPolicy()->record_final_evacuation_start();
+  sh->shenandoahPolicy()->record_phase_start(ShenandoahCollectorPolicy::final_evac);
   sh->set_evacuation_in_progress(false);
   sh->prepare_for_update_references();
   assert(ShenandoahConcurrentUpdateRefs, "only do this when concurrent update references is turned on");
-  sh->shenandoahPolicy()->record_final_evacuation_end();
+  sh->shenandoahPolicy()->record_phase_end(ShenandoahCollectorPolicy::final_evac);
 }