8269914: Factor out heap printing for G1 young and full gc

src/hotspot/share/gc/g1/g1CollectedHeap.cpp

@@ -980,7 +980,11 @@ class PostCompactionPrinterClosure: public HeapRegionClosure {
     : _hr_printer(hr_printer) { }
 };
 
-void G1CollectedHeap::print_hrm_post_compaction() {
+void G1CollectedHeap::print_heap_after_full_collection() {
+  // Post collection region logging.
+  // We should do this after we potentially resize the heap so
+  // that all the COMMIT / UNCOMMIT events are generated before
+  // the compaction events.
   if (_hr_printer.is_active()) {
     PostCompactionPrinterClosure cl(hr_printer());
     heap_region_iterate(&cl);
@@ -1092,17 +1096,6 @@ void G1CollectedHeap::verify_after_full_collection() {
   _ref_processor_cm->verify_no_references_recorded();
 }
 
-void G1CollectedHeap::print_heap_after_full_collection(G1HeapTransition* heap_transition) {
-  // Post collection logging.
-  // We should do this after we potentially resize the heap so
-  // that all the COMMIT / UNCOMMIT events are generated before
-  // the compaction events.
-  print_hrm_post_compaction();
-  heap_transition->print();
-  print_heap_after_gc();
-  print_heap_regions();
-}
-
 bool G1CollectedHeap::do_full_collection(bool explicit_gc,
                                          bool clear_all_soft_refs,
                                          bool do_maximum_compaction) {
@@ -2572,9 +2565,6 @@ void G1CollectedHeap::trace_heap(GCWhen::Type when, const GCTracer* gc_tracer) {
 void G1CollectedHeap::gc_prologue(bool full) {
   assert(InlineCacheBuffer::is_empty(), "should have cleaned up ICBuffer");
 
-  // This summary needs to be printed before incrementing total collections.
-  rem_set()->print_periodic_summary_info("Before GC RS summary", total_collections());
-
   // Update common counters.
   increment_total_collections(full /* full gc */);
   if (full || collector_state()->in_concurrent_start_gc()) {
@@ -2607,9 +2597,6 @@ void G1CollectedHeap::gc_epilogue(bool full) {
     increment_old_marking_cycles_completed(false /* concurrent */, true /* liveness_completed */);
   }
 
-  // We are at the end of the GC. Total collections has already been increased.
-  rem_set()->print_periodic_summary_info("After GC RS summary", total_collections() - 1);
-
 #if COMPILER2_OR_JVMCI
   assert(DerivedPointerTable::is_empty(), "derived pointer present");
 #endif
@@ -2622,9 +2609,6 @@ void G1CollectedHeap::gc_epilogue(bool full) {
   // policy with the new heap occupancy
   Universe::heap()->update_capacity_and_used_at_gc();
 
-  // Print NUMA statistics.
-  _numa->print_statistics();
-
   _collection_pause_end = Ticks::now();
 
   _free_card_set_memory_task->notify_new_stats(&_young_gen_card_set_stats,
@@ -2946,6 +2930,64 @@ class G1YoungGCTraceTime {
   }
 };
 
+G1HeapPrinterMark::G1HeapPrinterMark(G1CollectedHeap* g1h) : _g1h(g1h), _heap_transition(g1h) {
+  // This summary needs to be printed before incrementing total collections.
+  _g1h->rem_set()->print_periodic_summary_info("Before GC RS summary", _g1h->total_collections());
+  _g1h->print_heap_before_gc();
+  _g1h->print_heap_regions();
+}
+
+G1HeapPrinterMark::~G1HeapPrinterMark() {
+  _g1h->policy()->print_age_table();
+  _g1h->rem_set()->print_coarsen_stats();
+
+  _heap_transition.print();
+  _g1h->print_heap_regions();
+  _g1h->print_heap_after_gc();
+  // We are at the end of the GC. Total collections has already been increased.
+  _g1h->rem_set()->print_periodic_summary_info("After GC RS summary", _g1h->total_collections() - 1);
+  // Print NUMA statistics.
+  _g1h->numa()->print_statistics();
+}
+
+G1JFRTracerMark::G1JFRTracerMark(STWGCTimer* timer, GCTracer* tracer) :
+  _timer(timer), _tracer(tracer) {
+
+  _timer->register_gc_start();
+  _tracer->report_gc_start(G1CollectedHeap::heap()->gc_cause(), _timer->gc_start());
+  G1CollectedHeap::heap()->trace_heap_before_gc(_tracer);
+}
+
+G1JFRTracerMark::~G1JFRTracerMark() {
+  G1CollectedHeap::heap()->trace_heap_after_gc(_tracer);
+  _timer->register_gc_end();
+  _tracer->report_gc_end(_timer->gc_end(), _timer->time_partitions());
+}
+
+class G1YoungGCJFRTracerMark : public G1JFRTracerMark {
+  G1EvacuationInfo _evacuation_info;
+
+  G1NewTracer* tracer() const { return (G1NewTracer*)_tracer; }
+
+public:
+
+  G1EvacuationInfo* evacuation_info() { return &_evacuation_info; }
+
+  G1YoungGCJFRTracerMark(STWGCTimer* gc_timer_stw, G1NewTracer* gc_tracer_stw, GCCause::Cause cause) :
+    G1JFRTracerMark(gc_timer_stw, gc_tracer_stw), _evacuation_info() { }
+
+  void report_pause_type(G1GCPauseType type) {
+    tracer()->report_young_gc_pause(type);
+  }
+
+  ~G1YoungGCJFRTracerMark() {
+    G1CollectedHeap* g1h = G1CollectedHeap::heap();
+
+    tracer()->report_evacuation_info(&_evacuation_info);
+    tracer()->report_tenuring_threshold(g1h->policy()->tenuring_threshold());
+  }
+};
+
 void G1CollectedHeap::do_collection_pause_at_safepoint_helper(double target_pause_time_ms) {
   GCIdMark gc_id_mark;
 
@@ -2954,14 +2996,8 @@ void G1CollectedHeap::do_collection_pause_at_safepoint_helper(double target_paus
 
   policy()->note_gc_start();
 
-  gc_tracer_report_gc_start();
-
   wait_for_root_region_scanning();
 
-  print_heap_before_gc();
-  print_heap_regions();
-  trace_heap_before_gc(_gc_tracer_stw);
-
   // We should not be doing concurrent start unless the concurrent mark thread is running
   if (!_cm_thread->should_terminate()) {
     // This call will decide whether this pause is a concurrent start
@@ -2984,8 +3020,6 @@ void G1CollectedHeap::do_collection_pause_at_safepoint_helper(double target_paus
 
   // Inner scope for scope based logging, timers, and stats collection
   {
-    G1EvacuationInfo evacuation_info;
-
     GCTraceCPUTime tcpu;
 
     G1YoungGCTraceTime tm(gc_cause());
@@ -2996,12 +3030,14 @@ void G1CollectedHeap::do_collection_pause_at_safepoint_helper(double target_paus
     active_workers = workers()->update_active_workers(active_workers);
     log_info(gc,task)("Using %u workers of %u for evacuation", active_workers, workers()->total_workers());
 
+    // JFR
+    G1YoungGCJFRTracerMark jtm(_gc_timer_stw, _gc_tracer_stw, gc_cause());
     // JStat/MXBeans
     G1MonitoringScope ms(g1mm(),
                          false /* full_gc */,
                          collector_state()->in_mixed_phase() /* all_memory_pools_affected */);
 
-    G1HeapTransition heap_transition(this);
+    G1HeapPrinterMark hpm(this);
 
     {
       IsGCActiveMark x;
@@ -3031,15 +3067,15 @@ void G1CollectedHeap::do_collection_pause_at_safepoint_helper(double target_paus
         // of the collection set!).
         _allocator->release_mutator_alloc_regions();
 
-        calculate_collection_set(evacuation_info, target_pause_time_ms);
+        calculate_collection_set(*jtm.evacuation_info(), target_pause_time_ms);
 
         G1RedirtyCardsQueueSet rdcqs(G1BarrierSet::dirty_card_queue_set().allocator());
         G1ParScanThreadStateSet per_thread_states(this,
                                                   &rdcqs,
                                                   workers()->active_workers(),
                                                   collection_set()->young_region_length(),
                                                   collection_set()->optional_region_length());
-        pre_evacuate_collection_set(evacuation_info, &per_thread_states);
+        pre_evacuate_collection_set(*jtm.evacuation_info(), &per_thread_states);
 
         bool may_do_optional_evacuation = _collection_set.optional_region_length() != 0;
         // Actually do the work...
@@ -3048,7 +3084,7 @@ void G1CollectedHeap::do_collection_pause_at_safepoint_helper(double target_paus
         if (may_do_optional_evacuation) {
           evacuate_optional_collection_set(&per_thread_states);
         }
-        post_evacuate_collection_set(evacuation_info, &rdcqs, &per_thread_states);
+        post_evacuate_collection_set(*jtm.evacuation_info(), &rdcqs, &per_thread_states);
 
         start_new_collection_set();
 
@@ -3080,16 +3116,9 @@ void G1CollectedHeap::do_collection_pause_at_safepoint_helper(double target_paus
     }
 
     policy()->print_phases();
-    heap_transition.print();
 
     TASKQUEUE_STATS_ONLY(print_taskqueue_stats());
     TASKQUEUE_STATS_ONLY(reset_taskqueue_stats());
-
-    print_heap_after_gc();
-    print_heap_regions();
-    trace_heap_after_gc(_gc_tracer_stw);
-
-    gc_tracer_report_gc_end(concurrent_operation_is_full_mark, evacuation_info);
   }
   // It should now be safe to tell the concurrent mark thread to start
   // without its logging output interfering with the logging output
@@ -3819,9 +3848,6 @@ void G1CollectedHeap::post_evacuate_collection_set(G1EvacuationInfo& evacuation_
 
   evacuation_info.set_collectionset_used_before(collection_set()->bytes_used_before());
   evacuation_info.set_bytes_used(_bytes_used_during_gc);
-
-  policy()->print_age_table();
-  rem_set()->print_coarsen_stats();
 }
 
 void G1CollectedHeap::record_obj_copy_mem_stats() {

src/hotspot/share/gc/g1/g1CollectedHeap.hpp

@@ -153,6 +153,7 @@ class G1CollectedHeap : public CollectedHeap {
   friend class G1PLABAllocator;
 
   // Other related classes.
+  friend class G1HeapPrinterMark;
   friend class HeapRegionClaimer;
 
   // Testing classes.
@@ -317,10 +318,6 @@ class G1CollectedHeap : public CollectedHeap {
   // this method will be found dead by the marking cycle).
   void allocate_dummy_regions() PRODUCT_RETURN;
 
-  // If the HR printer is active, dump the state of the regions in the
-  // heap after a compaction.
-  void print_hrm_post_compaction();
-
   // Create a memory mapper for auxiliary data structures of the given size and
   // translation factor.
   static G1RegionToSpaceMapper* create_aux_memory_mapper(const char* description,
@@ -537,7 +534,7 @@ class G1CollectedHeap : public CollectedHeap {
   void prepare_heap_for_mutators();
   void abort_refinement();
   void verify_after_full_collection();
-  void print_heap_after_full_collection(G1HeapTransition* heap_transition);
+  void print_heap_after_full_collection();
 
   // Helper method for satisfy_failed_allocation()
   HeapWord* satisfy_failed_allocation_helper(size_t word_size,
@@ -1476,6 +1473,7 @@ class G1CollectedHeap : public CollectedHeap {
   void print_regions_on(outputStream* st) const;
 
 public:
+
   virtual void print_on(outputStream* st) const;
   virtual void print_extended_on(outputStream* st) const;
   virtual void print_on_error(outputStream* st) const;
@@ -1493,6 +1491,28 @@ class G1CollectedHeap : public CollectedHeap {
   virtual bool print_location(outputStream* st, void* addr) const;
 };
 
+// Scoped object that performs common pre- and post-gc heap printing operations.
+class G1HeapPrinterMark : public StackObj {
+  G1CollectedHeap* _g1h;
+  G1HeapTransition _heap_transition;
+
+public:
+  G1HeapPrinterMark(G1CollectedHeap* g1h);
+  ~G1HeapPrinterMark();
+};
+
+// Scoped object that performs common pre- and post-gc operations related to
+// JFR events.
+class G1JFRTracerMark : public StackObj {
+protected:
+  STWGCTimer* _timer;
+  GCTracer* _tracer;
+
+public:
+  G1JFRTracerMark(STWGCTimer* timer, GCTracer* tracer);
+  ~G1JFRTracerMark();
+};
+
 class G1ParEvacuateFollowersClosure : public VoidClosure {
 private:
   double _start_term;

src/hotspot/share/gc/g1/g1FullCollector.cpp

@@ -170,9 +170,6 @@ class PrepareRegionsClosure : public HeapRegionClosure {
 void G1FullCollector::prepare_collection() {
   _heap->policy()->record_full_collection_start();
 
-  _heap->print_heap_before_gc();
-  _heap->print_heap_regions();
-
   _heap->abort_concurrent_cycle();
   _heap->verify_before_full_collection(scope()->is_explicit_gc());
 
@@ -221,7 +218,7 @@ void G1FullCollector::complete_collection() {
 
   _heap->verify_after_full_collection();
 
-  _heap->print_heap_after_full_collection(scope()->heap_transition());
+  _heap->print_heap_after_full_collection();
 }
 
 void G1FullCollector::before_marking_update_attribute_table(HeapRegion* hr) {

src/hotspot/share/gc/g1/g1FullGCScope.cpp

@@ -25,6 +25,16 @@
 #include "precompiled.hpp"
 #include "gc/g1/g1FullGCScope.hpp"
 
+G1FullGCJFRTracerMark::G1FullGCJFRTracerMark(STWGCTimer* timer, GCTracer* tracer)
+  : G1JFRTracerMark(timer, tracer) {
+
+  G1CollectedHeap::heap()->pre_full_gc_dump(_timer);
+}
+
+G1FullGCJFRTracerMark::~G1FullGCJFRTracerMark() {
+  G1CollectedHeap::heap()->post_full_gc_dump(_timer);
+}
+
 G1FullGCScope::G1FullGCScope(G1MonitoringSupport* monitoring_support,
                              bool explicit_gc,
                              bool clear_soft,
@@ -38,24 +48,13 @@ G1FullGCScope::G1FullGCScope(G1MonitoringSupport* monitoring_support,
     _tracer(),
     _active(),
     _cpu_time(),
+    _tracer_mark(&_timer, &_tracer),
     _soft_refs(clear_soft, _g1h->soft_ref_policy()),
     _monitoring_scope(monitoring_support, true /* full_gc */, true /* all_memory_pools_affected */),
-    _heap_transition(_g1h),
+    _heap_printer(_g1h),
     _region_compaction_threshold(do_maximum_compaction ?
                                  HeapRegion::GrainWords :
-                                 (1 - MarkSweepDeadRatio / 100.0) * HeapRegion::GrainWords) {
-  _timer.register_gc_start();
-  _tracer.report_gc_start(_g1h->gc_cause(), _timer.gc_start());
-  _g1h->pre_full_gc_dump(&_timer);
-  _g1h->trace_heap_before_gc(&_tracer);
-}
-
-G1FullGCScope::~G1FullGCScope() {
-  _g1h->trace_heap_after_gc(&_tracer);
-  _g1h->post_full_gc_dump(&_timer);
-  _timer.register_gc_end();
-  _tracer.report_gc_end(_timer.gc_end(), _timer.time_partitions());
-}
+                                 (1 - MarkSweepDeadRatio / 100.0) * HeapRegion::GrainWords) { }
 
 bool G1FullGCScope::is_explicit_gc() {
   return _explicit_gc;
@@ -73,10 +72,6 @@ G1FullGCTracer* G1FullGCScope::tracer() {
   return &_tracer;
 }
 
-G1HeapTransition* G1FullGCScope::heap_transition() {
-  return &_heap_transition;
-}
-
 size_t G1FullGCScope::region_compaction_threshold() {
   return _region_compaction_threshold;
 }

src/hotspot/share/gc/g1/g1FullGCScope.hpp

@@ -39,6 +39,13 @@
 
 class GCMemoryManager;
 
+class G1FullGCJFRTracerMark : public G1JFRTracerMark {
+public:
+
+  G1FullGCJFRTracerMark(STWGCTimer* timer, GCTracer* tracer);
+  ~G1FullGCJFRTracerMark();
+};
+
 // Class used to group scoped objects used in the Full GC together.
 class G1FullGCScope : public StackObj {
   ResourceMark            _rm;
@@ -50,17 +57,18 @@ class G1FullGCScope : public StackObj {
   G1FullGCTracer          _tracer;
   IsGCActiveMark          _active;
   GCTraceCPUTime          _cpu_time;
+  G1FullGCJFRTracerMark   _tracer_mark;
   ClearedAllSoftRefs      _soft_refs;
   G1MonitoringScope       _monitoring_scope;
-  G1HeapTransition        _heap_transition;
+  G1HeapPrinterMark       _heap_printer;
   size_t                  _region_compaction_threshold;
 
 public:
   G1FullGCScope(G1MonitoringSupport* monitoring_support,
                 bool explicit_gc,
                 bool clear_soft,
                 bool do_maximal_compaction);
-  ~G1FullGCScope();
+  ~G1FullGCScope() { }
 
   bool is_explicit_gc();
   bool should_clear_soft_refs();