6855834: G1: minimize the output when -XX:+PrintHeapAtGC is set

Summary: Changing the behavior of -XX:+PrintHeapAtGC for G1 from printing lengthy, per-region information to instead printing a concise summary.
Reviewed-by: ysr, apetrusenko, jcoomes

src/share/vm/gc_implementation/g1/g1CollectedHeap.cpp

@@ -902,6 +902,10 @@ void G1CollectedHeap::do_collection(bool full, bool clear_all_soft_refs,
                                     size_t word_size) {
   ResourceMark rm;
 
+  if (PrintHeapAtGC) {
+    Universe::print_heap_before_gc();
+  }
+
   if (full && DisableExplicitGC) {
     gclog_or_tty->print("\n\n\nDisabling Explicit GC\n\n\n");
     return;
@@ -927,7 +931,7 @@ void G1CollectedHeap::do_collection(bool full, bool clear_all_soft_refs,
     g1_policy()->record_full_collection_start();
 
     gc_prologue(true);
-    increment_total_collections();
+    increment_total_collections(true /* full gc */);
 
     size_t g1h_prev_used = used();
     assert(used() == recalculate_used(), "Should be equal");
@@ -1066,6 +1070,10 @@ void G1CollectedHeap::do_collection(bool full, bool clear_all_soft_refs,
     assert( check_young_list_empty(false, false),
             "young list should be empty at this point");
   }
+
+  if (PrintHeapAtGC) {
+    Universe::print_heap_after_gc();
+  }
 }
 
 void G1CollectedHeap::do_full_collection(bool clear_all_soft_refs) {
@@ -2325,9 +2333,37 @@ public:
   }
 };
 
-void G1CollectedHeap::print() const { print_on(gclog_or_tty); }
+void G1CollectedHeap::print() const { print_on(tty); }
 
 void G1CollectedHeap::print_on(outputStream* st) const {
+  print_on(st, PrintHeapAtGCExtended);
+}
+
+void G1CollectedHeap::print_on(outputStream* st, bool extended) const {
+  st->print(" %-20s", "garbage-first heap");
+  st->print(" total " SIZE_FORMAT "K, used " SIZE_FORMAT "K",
+            capacity()/K, used()/K);
+  st->print(" [" INTPTR_FORMAT ", " INTPTR_FORMAT ", " INTPTR_FORMAT ")",
+            _g1_storage.low_boundary(),
+            _g1_storage.high(),
+            _g1_storage.high_boundary());
+  st->cr();
+  st->print("  region size " SIZE_FORMAT "K, ",
+            HeapRegion::GrainBytes/K);
+  size_t young_regions = _young_list->length();
+  st->print(SIZE_FORMAT " young (" SIZE_FORMAT "K), ",
+            young_regions, young_regions * HeapRegion::GrainBytes / K);
+  size_t survivor_regions = g1_policy()->recorded_survivor_regions();
+  st->print(SIZE_FORMAT " survivors (" SIZE_FORMAT "K)",
+            survivor_regions, survivor_regions * HeapRegion::GrainBytes / K);
+  st->cr();
+  perm()->as_gen()->print_on(st);
+  if (extended) {
+    print_on_extended(st);
+  }
+}
+
+void G1CollectedHeap::print_on_extended(outputStream* st) const {
   PrintRegionClosure blk(st);
   _hrs->iterate(&blk);
 }
@@ -2408,10 +2444,6 @@ G1CollectedHeap* G1CollectedHeap::heap() {
 }
 
 void G1CollectedHeap::gc_prologue(bool full /* Ignored */) {
-  if (PrintHeapAtGC){
-    gclog_or_tty->print_cr(" {Heap before GC collections=%d:", total_collections());
-    Universe::print();
-  }
   assert(InlineCacheBuffer::is_empty(), "should have cleaned up ICBuffer");
   // Call allocation profiler
   AllocationProfiler::iterate_since_last_gc();
@@ -2425,12 +2457,6 @@ void G1CollectedHeap::gc_epilogue(bool full /* Ignored */) {
   // is set.
   COMPILER2_PRESENT(assert(DerivedPointerTable::is_empty(),
                         "derived pointer present"));
-
-  if (PrintHeapAtGC){
-    gclog_or_tty->print_cr(" Heap after GC collections=%d:", total_collections());
-    Universe::print();
-    gclog_or_tty->print("} ");
-  }
 }
 
 void G1CollectedHeap::do_collection_pause() {
@@ -2559,6 +2585,11 @@ G1CollectedHeap::cleanup_surviving_young_words() {
 
 void
 G1CollectedHeap::do_collection_pause_at_safepoint() {
+  if (PrintHeapAtGC) {
+    Universe::print_heap_before_gc();
+  }
+
+  {
     char verbose_str[128];
     sprintf(verbose_str, "GC pause ");
     if (g1_policy()->in_young_gc_mode()) {
@@ -2601,7 +2632,7 @@ G1CollectedHeap::do_collection_pause_at_safepoint() {
       IsGCActiveMark x;
 
       gc_prologue(false);
-    increment_total_collections();
+      increment_total_collections(false /* full gc */);
 
 #if G1_REM_SET_LOGGING
       gclog_or_tty->print_cr("\nJust chose CS, heap:");
@@ -2668,7 +2699,6 @@ G1CollectedHeap::do_collection_pause_at_safepoint() {
         _cm->drainAllSATBBuffers();
         double finish_mark_ms = (os::elapsedTime() - start_time_sec) * 1000.0;
         g1_policy()->record_satb_drain_time(finish_mark_ms);
-
       }
       // Record the number of elements currently on the mark stack, so we
       // only iterate over these.  (Since evacuation may add to the mark
@@ -2795,6 +2825,11 @@ G1CollectedHeap::do_collection_pause_at_safepoint() {
       print_tracing_info();
       vm_exit(-1);
     }
+  }
+
+  if (PrintHeapAtGC) {
+    Universe::print_heap_after_gc();
+  }
 }
 
 void G1CollectedHeap::set_gc_alloc_region(int purpose, HeapRegion* r) {
@@ -5357,7 +5392,7 @@ void G1CollectedHeap::tear_down_region_lists() {
   assert(_free_region_list == NULL, "Postcondition of loop.");
   if (_free_region_list_size != 0) {
     gclog_or_tty->print_cr("Size is %d.", _free_region_list_size);
-    print();
+    print_on(gclog_or_tty, true /* extended */);
   }
   assert(_free_region_list_size == 0, "Postconditions of loop.");
 }

src/share/vm/gc_implementation/g1/g1CollectedHeap.hpp

@@ -1061,8 +1061,14 @@ public:
 
   // Override; it uses the "prev" marking information
   virtual void verify(bool allow_dirty, bool silent);
+  // Default behavior by calling print(tty);
   virtual void print() const;
+  // This calls print_on(st, PrintHeapAtGCExtended).
   virtual void print_on(outputStream* st) const;
+  // If extended is true, it will print out information for all
+  // regions in the heap by calling print_on_extended(st).
+  virtual void print_on(outputStream* st, bool extended) const;
+  virtual void print_on_extended(outputStream* st) const;
 
   virtual void print_gc_threads_on(outputStream* st) const;
   virtual void gc_threads_do(ThreadClosure* tc) const;

src/share/vm/gc_implementation/g1/g1CollectorPolicy.hpp

@@ -1097,6 +1097,10 @@ public:
     _recorded_survivor_tail    = tail;
   }
 
+  size_t recorded_survivor_regions() {
+    return _recorded_survivor_regions;
+  }
+
   void record_thread_age_table(ageTable* age_table)
   {
     _survivors_age_table.merge_par(age_table);

src/share/vm/gc_implementation/g1/heapRegion.cpp

@@ -703,7 +703,7 @@ void HeapRegion::verify(bool allow_dirty, bool use_prev_marking) const {
   }
   if (vl_cl.failures()) {
     gclog_or_tty->print_cr("Heap:");
-    G1CollectedHeap::heap()->print();
+    G1CollectedHeap::heap()->print_on(gclog_or_tty, true /* extended */);
     gclog_or_tty->print_cr("");
   }
   if (VerifyDuringGC &&

src/share/vm/runtime/globals.hpp

@@ -1994,6 +1994,10 @@ class CommandLineFlags {
   product_rw(bool, PrintHeapAtGC, false,                                    \
           "Print heap layout before and after each GC")                     \
                                                                             \
+  product_rw(bool, PrintHeapAtGCExtended, false,                            \
+          "Prints extended information about the layout of the heap "       \
+          "when -XX:+PrintHeapAtGC is set")                                 \
+                                                                            \
   product(bool, PrintHeapAtSIGBREAK, true,                                  \
           "Print heap layout in response to SIGBREAK")                      \
                                                                             \