changeset 60823:13e20575efe1

8241984: Shenandoah: enhance GCTimer and JFR support Reviewed-by: rkennke
author zgu
date Wed, 08 Apr 2020 08:13:22 -0400
parents 9e3539baac38
children db8ac4690d6a
files src/hotspot/share/gc/shenandoah/shenandoahConcurrentMark.cpp src/hotspot/share/gc/shenandoah/shenandoahHeap.cpp src/hotspot/share/gc/shenandoah/shenandoahHeap.hpp src/hotspot/share/gc/shenandoah/shenandoahUnload.cpp src/hotspot/share/gc/shenandoah/shenandoahUtils.cpp src/hotspot/share/gc/shenandoah/shenandoahUtils.hpp
diffstat 6 files changed, 155 insertions(+), 96 deletions(-) [+]
line wrap: on
line diff
--- a/src/hotspot/share/gc/shenandoah/shenandoahConcurrentMark.cpp	Wed Apr 08 13:44:58 2020 +0200
+++ b/src/hotspot/share/gc/shenandoah/shenandoahConcurrentMark.cpp	Wed Apr 08 08:13:22 2020 -0400
@@ -30,6 +30,7 @@
 
 #include "gc/shared/weakProcessor.inline.hpp"
 #include "gc/shared/gcTimer.hpp"
+#include "gc/shared/gcTrace.hpp"
 #include "gc/shared/referenceProcessor.hpp"
 #include "gc/shared/referenceProcessorPhaseTimes.hpp"
 #include "gc/shared/strongRootsScope.hpp"
@@ -687,16 +688,18 @@
 
     if (_heap->has_forwarded_objects()) {
       ShenandoahCMKeepAliveUpdateClosure keep_alive(get_queue(serial_worker_id));
-      rp->process_discovered_references(is_alive.is_alive_closure(), &keep_alive,
-                                        &complete_gc, &executor,
-                                        &pt);
-
+      const ReferenceProcessorStats& stats =
+        rp->process_discovered_references(is_alive.is_alive_closure(), &keep_alive,
+                                          &complete_gc, &executor,
+                                          &pt);
+       _heap->tracer()->report_gc_reference_stats(stats);
     } else {
       ShenandoahCMKeepAliveClosure keep_alive(get_queue(serial_worker_id));
-      rp->process_discovered_references(is_alive.is_alive_closure(), &keep_alive,
-                                        &complete_gc, &executor,
-                                        &pt);
-
+      const ReferenceProcessorStats& stats =
+        rp->process_discovered_references(is_alive.is_alive_closure(), &keep_alive,
+                                          &complete_gc, &executor,
+                                          &pt);
+      _heap->tracer()->report_gc_reference_stats(stats);
     }
 
     pt.print_all_references();
--- a/src/hotspot/share/gc/shenandoah/shenandoahHeap.cpp	Wed Apr 08 13:44:58 2020 +0200
+++ b/src/hotspot/share/gc/shenandoah/shenandoahHeap.cpp	Wed Apr 08 08:13:22 2020 -0400
@@ -1408,12 +1408,12 @@
   set_concurrent_mark_in_progress(true);
   // We need to reset all TLABs because we'd lose marks on all objects allocated in them.
   {
-    ShenandoahGCPhase phase(ShenandoahPhaseTimings::make_parsable);
+    ShenandoahGCSubPhase phase(ShenandoahPhaseTimings::make_parsable);
     make_parsable(true);
   }
 
   {
-    ShenandoahGCPhase phase(ShenandoahPhaseTimings::init_update_region_states);
+    ShenandoahGCSubPhase phase(ShenandoahPhaseTimings::init_update_region_states);
     ShenandoahInitMarkUpdateRegionStateClosure cl;
     parallel_heap_region_iterate(&cl);
   }
@@ -1424,7 +1424,7 @@
   concurrent_mark()->mark_roots(ShenandoahPhaseTimings::scan_roots);
 
   if (UseTLAB) {
-    ShenandoahGCPhase phase(ShenandoahPhaseTimings::resize_tlabs);
+    ShenandoahGCSubPhase phase(ShenandoahPhaseTimings::resize_tlabs);
     resize_tlabs();
   }
 
@@ -1513,7 +1513,7 @@
     }
 
     {
-      ShenandoahGCPhase phase(ShenandoahPhaseTimings::final_update_region_states);
+      ShenandoahGCSubPhase phase(ShenandoahPhaseTimings::final_update_region_states);
       ShenandoahFinalMarkUpdateRegionStateClosure cl;
       parallel_heap_region_iterate(&cl);
 
@@ -1522,19 +1522,19 @@
 
     // Force the threads to reacquire their TLABs outside the collection set.
     {
-      ShenandoahGCPhase phase(ShenandoahPhaseTimings::retire_tlabs);
+      ShenandoahGCSubPhase phase(ShenandoahPhaseTimings::retire_tlabs);
       make_parsable(true);
     }
 
     {
-      ShenandoahGCPhase phase(ShenandoahPhaseTimings::choose_cset);
+      ShenandoahGCSubPhase phase(ShenandoahPhaseTimings::choose_cset);
       ShenandoahHeapLocker locker(lock());
       _collection_set->clear();
       heuristics()->choose_collection_set(_collection_set);
     }
 
     {
-      ShenandoahGCPhase phase(ShenandoahPhaseTimings::final_rebuild_freeset);
+      ShenandoahGCSubPhase phase(ShenandoahPhaseTimings::final_rebuild_freeset);
       ShenandoahHeapLocker locker(lock());
       _free_set->rebuild();
     }
@@ -1547,7 +1547,7 @@
     // If collection set has candidates, start evacuation.
     // Otherwise, bypass the rest of the cycle.
     if (!collection_set()->is_empty()) {
-      ShenandoahGCPhase init_evac(ShenandoahPhaseTimings::init_evac);
+      ShenandoahGCSubPhase init_evac(ShenandoahPhaseTimings::init_evac);
 
       if (ShenandoahVerify) {
         verifier()->verify_before_evacuation();
@@ -1808,7 +1808,7 @@
 
   full_gc()->do_it(cause);
   if (UseTLAB) {
-    ShenandoahGCPhase phase(ShenandoahPhaseTimings::full_gc_resize_tlabs);
+    ShenandoahGCSubPhase phase(ShenandoahPhaseTimings::full_gc_resize_tlabs);
     resize_all_tlabs();
   }
 
@@ -2104,16 +2104,16 @@
 
   // Unload classes and purge SystemDictionary.
   {
-    ShenandoahGCPhase phase(full_gc ?
-                            ShenandoahPhaseTimings::full_gc_purge_class_unload :
-                            ShenandoahPhaseTimings::purge_class_unload);
+    ShenandoahGCSubPhase phase(full_gc ?
+                               ShenandoahPhaseTimings::full_gc_purge_class_unload :
+                               ShenandoahPhaseTimings::purge_class_unload);
     purged_class = SystemDictionary::do_unloading(gc_timer());
   }
 
   {
-    ShenandoahGCPhase phase(full_gc ?
-                            ShenandoahPhaseTimings::full_gc_purge_par :
-                            ShenandoahPhaseTimings::purge_par);
+    ShenandoahGCSubPhase phase(full_gc ?
+                               ShenandoahPhaseTimings::full_gc_purge_par :
+                               ShenandoahPhaseTimings::purge_par);
     ShenandoahIsAliveSelector is_alive;
     uint num_workers = _workers->active_workers();
     ShenandoahClassUnloadingTask unlink_task(is_alive.is_alive_closure(), num_workers, purged_class);
@@ -2121,9 +2121,9 @@
   }
 
   {
-    ShenandoahGCPhase phase(full_gc ?
-                            ShenandoahPhaseTimings::full_gc_purge_cldg :
-                            ShenandoahPhaseTimings::purge_cldg);
+    ShenandoahGCSubPhase phase(full_gc ?
+                               ShenandoahPhaseTimings::full_gc_purge_cldg :
+                               ShenandoahPhaseTimings::purge_cldg);
     ClassLoaderDataGraph::purge();
   }
   // Resize and verify metaspace
@@ -2136,14 +2136,14 @@
 // However, we do need to "null" dead oops in the roots, if can not be done
 // in concurrent cycles.
 void ShenandoahHeap::stw_process_weak_roots(bool full_gc) {
-  ShenandoahGCPhase root_phase(full_gc ?
-                               ShenandoahPhaseTimings::full_gc_purge :
-                               ShenandoahPhaseTimings::purge);
+  ShenandoahGCSubPhase root_phase(full_gc ?
+                                  ShenandoahPhaseTimings::full_gc_purge :
+                                  ShenandoahPhaseTimings::purge);
   uint num_workers = _workers->active_workers();
   ShenandoahPhaseTimings::Phase timing_phase = full_gc ?
                                                ShenandoahPhaseTimings::full_gc_purge_par :
                                                ShenandoahPhaseTimings::purge_par;
-  ShenandoahGCPhase phase(timing_phase);
+  ShenandoahGCSubPhase phase(timing_phase);
   ShenandoahGCWorkerPhase worker_phase(timing_phase);
 
   // Cleanup weak roots
@@ -2286,7 +2286,7 @@
 }
 #endif
 
-GCTimer* ShenandoahHeap::gc_timer() const {
+ConcurrentGCTimer* ShenandoahHeap::gc_timer() const {
   return _gc_timer;
 }
 
@@ -2398,7 +2398,7 @@
   set_evacuation_in_progress(false);
 
   {
-    ShenandoahGCPhase phase(ShenandoahPhaseTimings::init_update_refs_retire_gclabs);
+    ShenandoahGCSubPhase phase(ShenandoahPhaseTimings::init_update_refs_retire_gclabs);
     retire_and_reset_gclabs();
   }
 
@@ -2412,7 +2412,7 @@
   set_update_refs_in_progress(true);
 
   {
-    ShenandoahGCPhase phase(ShenandoahPhaseTimings::init_update_refs_prepare);
+    ShenandoahGCSubPhase phase(ShenandoahPhaseTimings::init_update_refs_prepare);
 
     make_parsable(true);
 
@@ -2461,7 +2461,7 @@
 
   // Check if there is left-over work, and finish it
   if (_update_refs_iterator.has_next()) {
-    ShenandoahGCPhase phase(ShenandoahPhaseTimings::final_update_refs_finish_work);
+    ShenandoahGCSubPhase phase(ShenandoahPhaseTimings::final_update_refs_finish_work);
 
     // Finish updating references where we left off.
     clear_cancelled_gc();
@@ -2491,7 +2491,7 @@
   }
 
   {
-    ShenandoahGCPhase phase(ShenandoahPhaseTimings::final_update_refs_update_region_states);
+    ShenandoahGCSubPhase phase(ShenandoahPhaseTimings::final_update_refs_update_region_states);
     ShenandoahFinalUpdateRefsUpdateRegionStateClosure cl;
     parallel_heap_region_iterate(&cl);
 
@@ -2499,7 +2499,7 @@
   }
 
   {
-    ShenandoahGCPhase phase(ShenandoahPhaseTimings::final_update_refs_trash_cset);
+    ShenandoahGCSubPhase phase(ShenandoahPhaseTimings::final_update_refs_trash_cset);
     trash_cset_regions();
   }
 
@@ -2515,7 +2515,7 @@
   }
 
   {
-    ShenandoahGCPhase phase(ShenandoahPhaseTimings::final_update_refs_rebuild_freeset);
+    ShenandoahGCSubPhase phase(ShenandoahPhaseTimings::final_update_refs_rebuild_freeset);
     ShenandoahHeapLocker locker(lock());
     _free_set->rebuild();
   }
@@ -2661,11 +2661,12 @@
 }
 
 void ShenandoahHeap::entry_init_mark() {
+  const char* msg = init_mark_event_message();
+  ShenandoahPausePhase gc_phase(msg);
+  EventMark em("%s", msg);
+
   ShenandoahGCPhase total_phase(ShenandoahPhaseTimings::total_pause);
   ShenandoahGCPhase phase(ShenandoahPhaseTimings::init_mark);
-  const char* msg = init_mark_event_message();
-  GCTraceTime(Info, gc) time(msg, gc_timer());
-  EventMark em("%s", msg);
 
   ShenandoahWorkerScope scope(workers(),
                               ShenandoahWorkerPolicy::calc_workers_for_init_marking(),
@@ -2675,11 +2676,12 @@
 }
 
 void ShenandoahHeap::entry_final_mark() {
+  const char* msg = final_mark_event_message();
+  ShenandoahPausePhase gc_phase(msg);
+  EventMark em("%s", msg);
+
   ShenandoahGCPhase total_phase(ShenandoahPhaseTimings::total_pause);
   ShenandoahGCPhase phase(ShenandoahPhaseTimings::final_mark);
-  const char* msg = final_mark_event_message();
-  GCTraceTime(Info, gc) time(msg, gc_timer());
-  EventMark em("%s", msg);
 
   ShenandoahWorkerScope scope(workers(),
                               ShenandoahWorkerPolicy::calc_workers_for_final_marking(),
@@ -2689,26 +2691,26 @@
 }
 
 void ShenandoahHeap::entry_init_updaterefs() {
+  static const char* msg = "Pause Init Update Refs";
+  ShenandoahPausePhase gc_phase(msg);
+  EventMark em("%s", msg);
+
   ShenandoahGCPhase total_phase(ShenandoahPhaseTimings::total_pause);
   ShenandoahGCPhase phase(ShenandoahPhaseTimings::init_update_refs);
 
-  static const char* msg = "Pause Init Update Refs";
-  GCTraceTime(Info, gc) time(msg, gc_timer());
-  EventMark em("%s", msg);
-
   // No workers used in this phase, no setup required
 
   op_init_updaterefs();
 }
 
 void ShenandoahHeap::entry_final_updaterefs() {
+  static const char* msg = "Pause Final Update Refs";
+  ShenandoahPausePhase gc_phase(msg);
+  EventMark em("%s", msg);
+
   ShenandoahGCPhase total_phase(ShenandoahPhaseTimings::total_pause);
   ShenandoahGCPhase phase(ShenandoahPhaseTimings::final_update_refs);
 
-  static const char* msg = "Pause Final Update Refs";
-  GCTraceTime(Info, gc) time(msg, gc_timer());
-  EventMark em("%s", msg);
-
   ShenandoahWorkerScope scope(workers(),
                               ShenandoahWorkerPolicy::calc_workers_for_final_update_ref(),
                               "final reference update");
@@ -2717,13 +2719,13 @@
 }
 
 void ShenandoahHeap::entry_full(GCCause::Cause cause) {
+  static const char* msg = "Pause Full";
+  ShenandoahPausePhase gc_phase(msg);
+  EventMark em("%s", msg);
+
   ShenandoahGCPhase total_phase(ShenandoahPhaseTimings::total_pause);
   ShenandoahGCPhase phase(ShenandoahPhaseTimings::full_gc);
 
-  static const char* msg = "Pause Full";
-  GCTraceTime(Info, gc) time(msg, gc_timer(), cause, true);
-  EventMark em("%s", msg);
-
   ShenandoahWorkerScope scope(workers(),
                               ShenandoahWorkerPolicy::calc_workers_for_fullgc(),
                               "full gc");
@@ -2732,14 +2734,14 @@
 }
 
 void ShenandoahHeap::entry_degenerated(int point) {
+  ShenandoahDegenPoint dpoint = (ShenandoahDegenPoint)point;
+  const char* msg = degen_event_message(dpoint);
+  ShenandoahPausePhase gc_phase(msg);
+  EventMark em("%s", msg);
+
   ShenandoahGCPhase total_phase(ShenandoahPhaseTimings::total_pause);
   ShenandoahGCPhase phase(ShenandoahPhaseTimings::degen_gc);
 
-  ShenandoahDegenPoint dpoint = (ShenandoahDegenPoint)point;
-  const char* msg = degen_event_message(dpoint);
-  GCTraceTime(Info, gc) time(msg, NULL, GCCause::_no_gc, true);
-  EventMark em("%s", msg);
-
   ShenandoahWorkerScope scope(workers(),
                               ShenandoahWorkerPolicy::calc_workers_for_stw_degenerated(),
                               "stw degenerated gc");
@@ -2753,9 +2755,11 @@
   TraceCollectorStats tcs(monitoring_support()->concurrent_collection_counters());
 
   const char* msg = conc_mark_event_message();
-  GCTraceTime(Info, gc) time(msg);
+  ShenandoahConcurrentPhase gc_phase(msg);
   EventMark em("%s", msg);
 
+  ShenandoahGCPhase conc_mark_phase(ShenandoahPhaseTimings::conc_mark);
+
   ShenandoahWorkerScope scope(workers(),
                               ShenandoahWorkerPolicy::calc_workers_for_conc_marking(),
                               "concurrent marking");
@@ -2765,12 +2769,13 @@
 }
 
 void ShenandoahHeap::entry_evac() {
+  TraceCollectorStats tcs(monitoring_support()->concurrent_collection_counters());
+
+  static const char* msg = "Concurrent evacuation";
+  ShenandoahConcurrentPhase gc_phase(msg);
+  EventMark em("%s", msg);
+
   ShenandoahGCPhase conc_evac_phase(ShenandoahPhaseTimings::conc_evac);
-  TraceCollectorStats tcs(monitoring_support()->concurrent_collection_counters());
-
-  static const char* msg = "Concurrent evacuation";
-  GCTraceTime(Info, gc) time(msg);
-  EventMark em("%s", msg);
 
   ShenandoahWorkerScope scope(workers(),
                               ShenandoahWorkerPolicy::calc_workers_for_conc_evac(),
@@ -2781,12 +2786,12 @@
 }
 
 void ShenandoahHeap::entry_updaterefs() {
+  static const char* msg = "Concurrent update references";
+  ShenandoahConcurrentPhase gc_phase(msg);
+  EventMark em("%s", msg);
+
   ShenandoahGCPhase phase(ShenandoahPhaseTimings::conc_update_refs);
 
-  static const char* msg = "Concurrent update references";
-  GCTraceTime(Info, gc) time(msg);
-  EventMark em("%s", msg);
-
   ShenandoahWorkerScope scope(workers(),
                               ShenandoahWorkerPolicy::calc_workers_for_conc_update_ref(),
                               "concurrent reference update");
@@ -2796,12 +2801,12 @@
 }
 
 void ShenandoahHeap::entry_roots() {
+  static const char* msg = "Concurrent roots processing";
+  ShenandoahConcurrentPhase gc_phase(msg);
+  EventMark em("%s", msg);
+
   ShenandoahGCPhase phase(ShenandoahPhaseTimings::conc_roots);
 
-  static const char* msg = "Concurrent roots processing";
-  GCTraceTime(Info, gc) time(msg);
-  EventMark em("%s", msg);
-
   ShenandoahWorkerScope scope(workers(),
                               ShenandoahWorkerPolicy::calc_workers_for_conc_root_processing(),
                               "concurrent root processing");
@@ -2811,12 +2816,12 @@
 }
 
 void ShenandoahHeap::entry_cleanup() {
-  ShenandoahGCPhase phase(ShenandoahPhaseTimings::conc_cleanup);
-
   static const char* msg = "Concurrent cleanup";
-  GCTraceTime(Info, gc) time(msg, NULL, GCCause::_no_gc, true);
+  ShenandoahConcurrentPhase gc_phase(msg);
   EventMark em("%s", msg);
 
+  ShenandoahGCSubPhase phase(ShenandoahPhaseTimings::conc_cleanup);
+
   // This phase does not use workers, no need for setup
 
   try_inject_alloc_failure();
@@ -2824,12 +2829,12 @@
 }
 
 void ShenandoahHeap::entry_reset() {
-  ShenandoahGCPhase phase(ShenandoahPhaseTimings::conc_reset);
-
   static const char* msg = "Concurrent reset";
-  GCTraceTime(Info, gc) time(msg);
+  ShenandoahConcurrentPhase gc_phase(msg);
   EventMark em("%s", msg);
 
+  ShenandoahGCSubPhase phase(ShenandoahPhaseTimings::conc_reset);
+
   ShenandoahWorkerScope scope(workers(),
                               ShenandoahWorkerPolicy::calc_workers_for_conc_reset(),
                               "concurrent reset");
@@ -2841,10 +2846,10 @@
 void ShenandoahHeap::entry_preclean() {
   if (ShenandoahPreclean && process_references()) {
     static const char* msg = "Concurrent precleaning";
-    GCTraceTime(Info, gc) time(msg);
+    ShenandoahConcurrentPhase gc_phase(msg);
     EventMark em("%s", msg);
 
-    ShenandoahGCPhase conc_preclean(ShenandoahPhaseTimings::conc_preclean);
+    ShenandoahGCSubPhase conc_preclean(ShenandoahPhaseTimings::conc_preclean);
 
     ShenandoahWorkerScope scope(workers(),
                                 ShenandoahWorkerPolicy::calc_workers_for_conc_preclean(),
@@ -2858,10 +2863,10 @@
 
 void ShenandoahHeap::entry_uncommit(double shrink_before) {
   static const char *msg = "Concurrent uncommit";
-  GCTraceTime(Info, gc) time(msg, NULL, GCCause::_no_gc, true);
+  ShenandoahConcurrentPhase gc_phase(msg);
   EventMark em("%s", msg);
 
-  ShenandoahGCPhase phase(ShenandoahPhaseTimings::conc_uncommit);
+  ShenandoahGCSubPhase phase(ShenandoahPhaseTimings::conc_uncommit);
 
   op_uncommit(shrink_before);
 }
--- a/src/hotspot/share/gc/shenandoah/shenandoahHeap.hpp	Wed Apr 08 13:44:58 2020 +0200
+++ b/src/hotspot/share/gc/shenandoah/shenandoahHeap.hpp	Wed Apr 08 08:13:22 2020 -0400
@@ -479,7 +479,7 @@
   GrowableArray<MemoryPool*> memory_pools();
   MemoryUsage memory_usage();
   GCTracer* tracer();
-  GCTimer* gc_timer() const;
+  ConcurrentGCTimer* gc_timer() const;
 
 // ---------- Reference processing
 //
--- a/src/hotspot/share/gc/shenandoah/shenandoahUnload.cpp	Wed Apr 08 13:44:58 2020 +0200
+++ b/src/hotspot/share/gc/shenandoah/shenandoahUnload.cpp	Wed Apr 08 08:13:22 2020 -0400
@@ -140,7 +140,7 @@
   ShenandoahHeap* const heap = ShenandoahHeap::heap();
   {
     MutexLocker cldg_ml(ClassLoaderDataGraph_lock);
-    unloading_occurred = SystemDictionary::do_unloading(NULL /* gc_timer */);
+    unloading_occurred = SystemDictionary::do_unloading(heap->gc_timer());
   }
 
   Klass::clean_weak_klass_links(unloading_occurred);
--- a/src/hotspot/share/gc/shenandoah/shenandoahUtils.cpp	Wed Apr 08 13:44:58 2020 +0200
+++ b/src/hotspot/share/gc/shenandoah/shenandoahUtils.cpp	Wed Apr 08 08:13:22 2020 -0400
@@ -26,7 +26,6 @@
 
 #include "jfr/jfrEvents.hpp"
 #include "gc/shared/gcCause.hpp"
-#include "gc/shared/gcTimer.hpp"
 #include "gc/shared/gcTrace.hpp"
 #include "gc/shared/gcWhen.hpp"
 #include "gc/shenandoah/shenandoahCollectorPolicy.hpp"
@@ -47,7 +46,7 @@
   _heap->set_gc_cause(cause);
   _timer->register_gc_start();
   _tracer->report_gc_start(cause, _timer->gc_start());
-  _heap->trace_heap(GCWhen::BeforeGC, _tracer);
+  _heap->trace_heap_before_gc(_tracer);
 
   _heap->shenandoah_policy()->record_cycle_start();
   _heap->heuristics()->record_cycle_start();
@@ -66,7 +65,7 @@
 ShenandoahGCSession::~ShenandoahGCSession() {
   _heap->heuristics()->record_cycle_end();
   _timer->register_gc_end();
-  _heap->trace_heap(GCWhen::AfterGC, _tracer);
+  _heap->trace_heap_after_gc(_tracer);
   _tracer->report_gc_end(_timer->gc_end(), _timer->time_partitions());
   assert(!ShenandoahGCPhase::is_current_phase_valid(), "No current GC phase");
   _heap->set_gc_cause(GCCause::_no_gc);
@@ -74,10 +73,6 @@
 
 ShenandoahGCPauseMark::ShenandoahGCPauseMark(uint gc_id, SvcGCMarker::reason_type type) :
   _heap(ShenandoahHeap::heap()), _gc_id_mark(gc_id), _svc_gc_mark(type), _is_gc_active_mark() {
-
-  // FIXME: It seems that JMC throws away level 0 events, which are the Shenandoah
-  // pause events. Create this pseudo level 0 event to push real events to level 1.
-  _heap->gc_timer()->register_gc_pause_start("Shenandoah", Ticks::now());
   _trace_pause.initialize(_heap->stw_memory_manager(), _heap->gc_cause(),
           /* allMemoryPoolsAffected */    true,
           /* recordGCBeginTime = */       true,
@@ -93,11 +88,30 @@
 }
 
 ShenandoahGCPauseMark::~ShenandoahGCPauseMark() {
-  _heap->gc_timer()->register_gc_pause_end(Ticks::now());
   _heap->heuristics()->record_gc_end();
 }
 
-ShenandoahGCPhase::ShenandoahGCPhase(const ShenandoahPhaseTimings::Phase phase) :
+ShenandoahPausePhase::ShenandoahPausePhase(const char* title) :
+  GCTraceTimeWrapper<LogLevel::Info, LOG_TAGS(gc)>(title),
+  _timer(ShenandoahHeap::heap()->gc_timer()) {
+  _timer->register_gc_pause_start(title);
+}
+
+ShenandoahPausePhase::~ShenandoahPausePhase() {
+  _timer->register_gc_pause_end();
+}
+
+ShenandoahConcurrentPhase::ShenandoahConcurrentPhase(const char* title) :
+  GCTraceConcTimeImpl<LogLevel::Info, LOG_TAGS(gc)>(title),
+  _timer(ShenandoahHeap::heap()->gc_timer()) {
+  _timer->register_gc_concurrent_start(title);
+}
+
+ShenandoahConcurrentPhase::~ShenandoahConcurrentPhase() {
+  _timer->register_gc_concurrent_end();
+}
+
+ShenandoahGCPhase::ShenandoahGCPhase(ShenandoahPhaseTimings::Phase phase) :
   _timings(ShenandoahHeap::heap()->phase_timings()), _phase(phase) {
   assert(!Thread::current()->is_Worker_thread() &&
               (Thread::current()->is_VM_thread() ||
@@ -131,6 +145,16 @@
   }
 }
 
+ShenandoahGCSubPhase::ShenandoahGCSubPhase(ShenandoahPhaseTimings::Phase phase) :
+  ShenandoahGCPhase(phase),
+  _timer(ShenandoahHeap::heap()->gc_timer()) {
+  _timer->register_gc_phase_start(ShenandoahPhaseTimings::phase_name(phase), Ticks::now());
+}
+
+ShenandoahGCSubPhase::~ShenandoahGCSubPhase() {
+  _timer->register_gc_phase_end(Ticks::now());
+}
+
 ShenandoahGCWorkerPhase::ShenandoahGCWorkerPhase(const ShenandoahPhaseTimings::Phase phase) :
     _timings(ShenandoahHeap::heap()->phase_timings()), _phase(phase) {
   _timings->record_workers_start(_phase);
--- a/src/hotspot/share/gc/shenandoah/shenandoahUtils.hpp	Wed Apr 08 13:44:58 2020 +0200
+++ b/src/hotspot/share/gc/shenandoah/shenandoahUtils.hpp	Wed Apr 08 08:13:22 2020 -0400
@@ -26,6 +26,7 @@
 #define SHARE_GC_SHENANDOAH_SHENANDOAHUTILS_HPP
 
 #include "gc/shared/gcCause.hpp"
+#include "gc/shared/gcTraceTime.inline.hpp"
 #include "gc/shared/gcVMOperations.hpp"
 #include "gc/shared/isGCActiveMark.hpp"
 #include "gc/shared/suspendibleThreadSet.hpp"
@@ -40,7 +41,6 @@
 #include "services/memoryService.hpp"
 
 class GCTimer;
-class GCTracer;
 
 class ShenandoahGCSession : public StackObj {
 private:
@@ -54,6 +54,24 @@
   ~ShenandoahGCSession();
 };
 
+class ShenandoahPausePhase : public GCTraceTimeWrapper<LogLevel::Info, LOG_TAGS(gc)> {
+private:
+  ConcurrentGCTimer* const _timer;
+
+public:
+  ShenandoahPausePhase(const char* title);
+  ~ShenandoahPausePhase();
+};
+
+class ShenandoahConcurrentPhase : public GCTraceConcTimeImpl<LogLevel::Info, LOG_TAGS(gc)> {
+private:
+  ConcurrentGCTimer* const _timer;
+
+public:
+  ShenandoahConcurrentPhase(const char* title);
+  ~ShenandoahConcurrentPhase();
+};
+
 class ShenandoahGCPhase : public StackObj {
 private:
   static ShenandoahPhaseTimings::Phase  _current_phase;
@@ -73,6 +91,15 @@
   static bool is_root_work_phase();
 };
 
+class ShenandoahGCSubPhase: public ShenandoahGCPhase {
+private:
+  ConcurrentGCTimer* const _timer;
+
+public:
+  ShenandoahGCSubPhase(ShenandoahPhaseTimings::Phase phase);
+  ~ShenandoahGCSubPhase();
+};
+
 class ShenandoahGCWorkerPhase : public StackObj {
 private:
   ShenandoahPhaseTimings* const       _timings;