8148736: Let the G1 heap transition log regions instead of bytes
authorbrutisso
Tue, 02 Feb 2016 12:13:05 +0100
changeset 35909 cf5f3c85e179
parent 35908 cb12f847b199
child 35910 73277e369d4b
8148736: Let the G1 heap transition log regions instead of bytes Reviewed-by: sjohanss, david
hotspot/src/share/vm/gc/g1/g1CollectedHeap.cpp
hotspot/src/share/vm/gc/g1/g1CollectedHeap.hpp
hotspot/src/share/vm/gc/g1/g1CollectorPolicy.cpp
hotspot/src/share/vm/gc/g1/g1CollectorPolicy.hpp
hotspot/src/share/vm/gc/g1/g1HeapTransition.cpp
hotspot/src/share/vm/gc/g1/g1HeapTransition.hpp
--- a/hotspot/src/share/vm/gc/g1/g1CollectedHeap.cpp	Tue Feb 02 12:12:17 2016 +0100
+++ b/hotspot/src/share/vm/gc/g1/g1CollectedHeap.cpp	Tue Feb 02 12:13:05 2016 +0100
@@ -38,6 +38,7 @@
 #include "gc/g1/g1CollectorState.hpp"
 #include "gc/g1/g1EvacStats.inline.hpp"
 #include "gc/g1/g1GCPhaseTimes.hpp"
+#include "gc/g1/g1HeapTransition.hpp"
 #include "gc/g1/g1HeapVerifier.hpp"
 #include "gc/g1/g1MarkSweep.hpp"
 #include "gc/g1/g1OopClosures.inline.hpp"
@@ -1250,6 +1251,7 @@
       TraceCollectorStats tcs(g1mm()->full_collection_counters());
       TraceMemoryManagerStats tms(true /* fullGC */, gc_cause());
 
+      G1HeapTransition heap_transition(this);
       g1_policy()->record_full_collection_start();
 
       // Note: When we have a more flexible GC logging framework that
@@ -1442,15 +1444,15 @@
       g1mm()->update_sizes();
 
       gc_epilogue(true);
+
+      heap_transition.print();
+
+      print_heap_after_gc();
+      trace_heap_after_gc(gc_tracer);
+
+      post_full_gc_dump(gc_timer);
     }
 
-    g1_policy()->print_detailed_heap_transition();
-
-    print_heap_after_gc();
-    trace_heap_after_gc(gc_tracer);
-
-    post_full_gc_dump(gc_timer);
-
     gc_timer->register_gc_end();
     gc_tracer->report_gc_end(gc_timer->gc_end(), gc_timer->time_partitions());
   }
@@ -3169,17 +3171,6 @@
 }
 #endif // TASKQUEUE_STATS
 
-void G1CollectedHeap::log_gc_footer() {
-  if (evacuation_failed()) {
-    log_info(gc)("To-space exhausted");
-  }
-
-  g1_policy()->print_phases();
-
-  g1_policy()->print_detailed_heap_transition();
-}
-
-
 void G1CollectedHeap::wait_for_root_region_scanning() {
   double scan_wait_start = os::elapsedTime();
   // We have to wait until the CM threads finish scanning the
@@ -3281,6 +3272,9 @@
       append_secondary_free_list_if_not_empty_with_lock();
     }
 
+    G1HeapTransition heap_transition(this);
+    size_t heap_used_bytes_before_gc = used();
+
     assert(check_young_list_well_formed(), "young list should be well formed");
 
     // Don't dynamically change the number of GC threads this early.  A value of
@@ -3474,7 +3468,7 @@
         double sample_end_time_sec = os::elapsedTime();
         double pause_time_ms = (sample_end_time_sec - sample_start_time_sec) * MILLIUNITS;
         size_t total_cards_scanned = per_thread_states.total_cards_scanned();
-        g1_policy()->record_collection_pause_end(pause_time_ms, total_cards_scanned);
+        g1_policy()->record_collection_pause_end(pause_time_ms, total_cards_scanned, heap_used_bytes_before_gc);
 
         evacuation_info.set_collectionset_used_before(g1_policy()->collection_set_bytes_used_before());
         evacuation_info.set_bytes_copied(g1_policy()->bytes_copied_during_gc());
@@ -3527,7 +3521,12 @@
     }
 
     // Print the remainder of the GC log output.
-    log_gc_footer();
+    if (evacuation_failed()) {
+      log_info(gc)("To-space exhausted");
+    }
+
+    g1_policy()->print_phases();
+    heap_transition.print();
 
     // It is not yet to safe to tell the concurrent mark to
     // start as we have some optional output below. We don't want the
--- a/hotspot/src/share/vm/gc/g1/g1CollectedHeap.hpp	Tue Feb 02 12:12:17 2016 +0100
+++ b/hotspot/src/share/vm/gc/g1/g1CollectedHeap.hpp	Tue Feb 02 12:13:05 2016 +0100
@@ -291,8 +291,6 @@
                                                          size_t size,
                                                          size_t translation_factor);
 
-  void log_gc_footer();
-
   void trace_heap(GCWhen::Type when, const GCTracer* tracer);
 
   void process_weak_jni_handles();
--- a/hotspot/src/share/vm/gc/g1/g1CollectorPolicy.cpp	Tue Feb 02 12:12:17 2016 +0100
+++ b/hotspot/src/share/vm/gc/g1/g1CollectorPolicy.cpp	Tue Feb 02 12:13:05 2016 +0100
@@ -117,15 +117,6 @@
   _rs_lengths_prediction(0),
   _max_survivor_regions(0),
 
-  _eden_used_bytes_before_gc(0),
-  _survivor_used_bytes_before_gc(0),
-  _old_used_bytes_before_gc(0),
-  _humongous_used_bytes_before_gc(0),
-  _heap_used_bytes_before_gc(0),
-  _metaspace_used_bytes_before_gc(0),
-  _eden_capacity_bytes_before_gc(0),
-  _heap_capacity_bytes_before_gc(0),
-
   _eden_cset_region_length(0),
   _survivor_cset_region_length(0),
   _old_cset_region_length(0),
@@ -809,7 +800,6 @@
 
 void G1CollectorPolicy::record_full_collection_start() {
   _full_collection_start_sec = os::elapsedTime();
-  record_heap_size_info_at_start(true /* full */);
   // Release the future to-space so that it is available for compaction into.
   collector_state()->set_full_collection(true);
 }
@@ -871,8 +861,6 @@
   _trace_young_gen_time_data.record_start_collection(s_w_t_ms);
   _stop_world_start = 0.0;
 
-  record_heap_size_info_at_start(false /* full */);
-
   phase_times()->record_cur_collection_start_sec(start_time_sec);
   _pending_cards = _g1->pending_card_num();
 
@@ -987,7 +975,7 @@
 // Anything below that is considered to be zero
 #define MIN_TIMER_GRANULARITY 0.0000001
 
-void G1CollectorPolicy::record_collection_pause_end(double pause_time_ms, size_t cards_scanned) {
+void G1CollectorPolicy::record_collection_pause_end(double pause_time_ms, size_t cards_scanned, size_t heap_used_bytes_before_gc) {
   double end_time_sec = os::elapsedTime();
 
   size_t cur_used_bytes = _g1->used();
@@ -1138,7 +1126,7 @@
     }
     _rs_length_diff_seq->add((double) rs_length_diff);
 
-    size_t freed_bytes = _heap_used_bytes_before_gc - cur_used_bytes;
+    size_t freed_bytes = heap_used_bytes_before_gc - cur_used_bytes;
     size_t copied_bytes = _collection_set_bytes_used_before - freed_bytes;
     double cost_per_byte_ms = 0.0;
 
@@ -1260,49 +1248,6 @@
   _ihop_control->print();
 }
 
-#define EXT_SIZE_FORMAT "%.1f%s"
-#define EXT_SIZE_PARAMS(bytes)                                  \
-  byte_size_in_proper_unit((double)(bytes)),                    \
-  proper_unit_for_byte_size((bytes))
-
-void G1CollectorPolicy::record_heap_size_info_at_start(bool full) {
-  YoungList* young_list = _g1->young_list();
-  _eden_used_bytes_before_gc = young_list->eden_used_bytes();
-  _survivor_used_bytes_before_gc = young_list->survivor_used_bytes();
-  _heap_capacity_bytes_before_gc = _g1->capacity();
-  _old_used_bytes_before_gc = _g1->old_regions_count() * HeapRegion::GrainBytes;
-  _humongous_used_bytes_before_gc = _g1->humongous_regions_count() * HeapRegion::GrainBytes;
-  _heap_used_bytes_before_gc = _g1->used();
-  _eden_capacity_bytes_before_gc = (_young_list_target_length * HeapRegion::GrainBytes) - _survivor_used_bytes_before_gc;
-  _metaspace_used_bytes_before_gc = MetaspaceAux::used_bytes();
-}
-
-void G1CollectorPolicy::print_detailed_heap_transition() const {
-  YoungList* young_list = _g1->young_list();
-
-  size_t eden_used_bytes_after_gc = young_list->eden_used_bytes();
-  size_t survivor_used_bytes_after_gc = young_list->survivor_used_bytes();
-  size_t heap_used_bytes_after_gc = _g1->used();
-  size_t old_used_bytes_after_gc = _g1->old_regions_count() * HeapRegion::GrainBytes;
-  size_t humongous_used_bytes_after_gc = _g1->humongous_regions_count() * HeapRegion::GrainBytes;
-
-  size_t heap_capacity_bytes_after_gc = _g1->capacity();
-  size_t eden_capacity_bytes_after_gc =
-    (_young_list_target_length * HeapRegion::GrainBytes) - survivor_used_bytes_after_gc;
-  size_t survivor_capacity_bytes_after_gc = _max_survivor_regions * HeapRegion::GrainBytes;
-
-  log_info(gc, heap)("Eden: " SIZE_FORMAT "K->" SIZE_FORMAT "K("  SIZE_FORMAT "K)",
-                     _eden_used_bytes_before_gc / K, eden_used_bytes_after_gc /K, eden_capacity_bytes_after_gc /K);
-  log_info(gc, heap)("Survivor: " SIZE_FORMAT "K->" SIZE_FORMAT "K("  SIZE_FORMAT "K)",
-                     _survivor_used_bytes_before_gc / K, survivor_used_bytes_after_gc /K, survivor_capacity_bytes_after_gc /K);
-  log_info(gc, heap)("Old: " SIZE_FORMAT "K->" SIZE_FORMAT "K",
-                     _old_used_bytes_before_gc / K, old_used_bytes_after_gc /K);
-  log_info(gc, heap)("Humongous: " SIZE_FORMAT "K->" SIZE_FORMAT "K",
-                     _humongous_used_bytes_before_gc / K, humongous_used_bytes_after_gc /K);
-
-  MetaspaceAux::print_metaspace_change(_metaspace_used_bytes_before_gc);
-}
-
 void G1CollectorPolicy::print_phases() {
   phase_times()->print();
 }
--- a/hotspot/src/share/vm/gc/g1/g1CollectorPolicy.hpp	Tue Feb 02 12:12:17 2016 +0100
+++ b/hotspot/src/share/vm/gc/g1/g1CollectorPolicy.hpp	Tue Feb 02 12:13:05 2016 +0100
@@ -636,7 +636,7 @@
 
   // Record the start and end of an evacuation pause.
   void record_collection_pause_start(double start_time_sec);
-  void record_collection_pause_end(double pause_time_ms, size_t cards_scanned);
+  void record_collection_pause_end(double pause_time_ms, size_t cards_scanned, size_t heap_used_bytes_before_gc);
 
   // Record the start and end of a full collection.
   void record_full_collection_start();
@@ -654,14 +654,6 @@
   void record_concurrent_mark_cleanup_end();
   void record_concurrent_mark_cleanup_completed();
 
-  // Records the information about the heap size for reporting in
-  // print_detailed_heap_transition
-  void record_heap_size_info_at_start(bool full);
-
-  // Print heap sizing transition (with less and more detail).
-
-  void print_detailed_heap_transition() const;
-
   virtual void print_phases();
 
   void record_stop_world_start();
@@ -825,16 +817,6 @@
   // The value of _heap_bytes_before_gc is also used to calculate
   // the cost of copying.
 
-  size_t _eden_used_bytes_before_gc;         // Eden occupancy before GC
-  size_t _survivor_used_bytes_before_gc;     // Survivor occupancy before GC
-  size_t _old_used_bytes_before_gc;          // Old occupancy before GC
-  size_t _humongous_used_bytes_before_gc;    // Humongous occupancy before GC
-  size_t _heap_used_bytes_before_gc;         // Heap occupancy before GC
-  size_t _metaspace_used_bytes_before_gc;    // Metaspace occupancy before GC
-
-  size_t _eden_capacity_bytes_before_gc;     // Eden capacity before GC
-  size_t _heap_capacity_bytes_before_gc;     // Heap capacity before GC
-
   // The amount of survivor regions after a collection.
   uint _recorded_survivor_regions;
   // List of survivor regions.
@@ -846,6 +828,10 @@
 public:
   uint tenuring_threshold() const { return _tenuring_threshold; }
 
+  uint max_survivor_regions() {
+    return _max_survivor_regions;
+  }
+
   static const uint REGIONS_UNLIMITED = (uint) -1;
 
   uint max_regions(InCSetState dest) const {
--- /dev/null	Thu Jan 01 00:00:00 1970 +0000
+++ b/hotspot/src/share/vm/gc/g1/g1HeapTransition.cpp	Tue Feb 02 12:13:05 2016 +0100
@@ -0,0 +1,122 @@
+/*
+ * Copyright (c) 2016, Oracle and/or its affiliates. All rights reserved.
+ * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
+ *
+ * This code is free software; you can redistribute it and/or modify it
+ * under the terms of the GNU General Public License version 2 only, as
+ * published by the Free Software Foundation.
+ *
+ * This code is distributed in the hope that it will be useful, but WITHOUT
+ * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or
+ * FITNESS FOR A PARTICULAR PURPOSE.  See the GNU General Public License
+ * version 2 for more details (a copy is included in the LICENSE file that
+ * accompanied this code).
+ *
+ * You should have received a copy of the GNU General Public License version
+ * 2 along with this work; if not, write to the Free Software Foundation,
+ * Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA.
+ *
+ * Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA
+ * or visit www.oracle.com if you need additional information or have any
+ * questions.
+ *
+ */
+
+#include "precompiled.hpp"
+#include "gc/g1/g1CollectedHeap.hpp"
+#include "gc/g1/g1CollectorPolicy.hpp"
+#include "gc/g1/g1HeapTransition.hpp"
+#include "logging/log.hpp"
+#include "memory/metaspace.hpp"
+
+G1HeapTransition::Data::Data(G1CollectedHeap* g1_heap) {
+  YoungList* young_list = g1_heap->young_list();
+  _eden_length = young_list->eden_length();
+  _survivor_length = young_list->survivor_length();
+  _old_length = g1_heap->old_regions_count();
+  _humongous_length = g1_heap->humongous_regions_count();
+  _metaspace_used_bytes = MetaspaceAux::used_bytes();
+}
+
+G1HeapTransition::G1HeapTransition(G1CollectedHeap* g1_heap) : _g1_heap(g1_heap), _before(g1_heap) { }
+
+struct DetailedUsage : public StackObj {
+  size_t _eden_used;
+  size_t _survivor_used;
+  size_t _old_used;
+  size_t _humongous_used;
+
+  size_t _eden_region_count;
+  size_t _survivor_region_count;
+  size_t _old_region_count;
+  size_t _humongous_region_count;
+
+  DetailedUsage() :
+    _eden_used(0), _survivor_used(0), _old_used(0), _humongous_used(0),
+    _eden_region_count(0), _survivor_region_count(0), _old_region_count(0), _humongous_region_count(0) {}
+};
+
+class DetailedUsageClosure: public HeapRegionClosure {
+public:
+  DetailedUsage _usage;
+  bool doHeapRegion(HeapRegion* r) {
+    if (r->is_old()) {
+      _usage._old_used += r->used();
+      _usage._old_region_count++;
+    } else if (r->is_survivor()) {
+      _usage._survivor_used += r->used();
+      _usage._survivor_region_count++;
+    } else if (r->is_eden()) {
+      _usage._eden_used += r->used();
+      _usage._eden_region_count++;
+    } else if (r->is_humongous()) {
+      _usage._humongous_used += r->used();
+      _usage._humongous_region_count++;
+    } else {
+      assert(r->used() == 0, "Expected used to be 0 but it was " SIZE_FORMAT, r->used());
+    }
+    return false;
+  }
+};
+
+void G1HeapTransition::print() {
+  Data after(_g1_heap);
+
+  size_t eden_capacity_bytes_after_gc = _g1_heap->g1_policy()->young_list_target_length() - after._survivor_length;
+  size_t survivor_capacity_bytes_after_gc = _g1_heap->g1_policy()->max_survivor_regions();
+
+  DetailedUsage usage;
+  if (log_is_enabled(Trace, gc, heap)) {
+    DetailedUsageClosure blk;
+    _g1_heap->heap_region_iterate(&blk);
+    usage = blk._usage;
+    assert(usage._eden_region_count == 0, "Expected no eden regions, but got " SIZE_FORMAT, usage._eden_region_count);
+    assert(usage._survivor_region_count == after._survivor_length, "Expected survivors to be " SIZE_FORMAT " but was " SIZE_FORMAT,
+        after._survivor_length, usage._survivor_region_count);
+    assert(usage._old_region_count == after._old_length, "Expected old to be " SIZE_FORMAT " but was " SIZE_FORMAT,
+        after._old_length, usage._old_region_count);
+    assert(usage._humongous_region_count == after._humongous_length, "Expected humongous to be " SIZE_FORMAT " but was " SIZE_FORMAT,
+        after._humongous_length, usage._humongous_region_count);
+  }
+
+  log_info(gc, heap)("Eden regions: " SIZE_FORMAT "->" SIZE_FORMAT "("  SIZE_FORMAT ")",
+                     _before._eden_length, after._eden_length, eden_capacity_bytes_after_gc);
+  log_trace(gc, heap)(" Used: 0K, Waste: 0K");
+
+  log_info(gc, heap)("Survivor regions: " SIZE_FORMAT "->" SIZE_FORMAT "("  SIZE_FORMAT ")",
+                     _before._survivor_length, after._survivor_length, survivor_capacity_bytes_after_gc);
+  log_trace(gc, heap)(" Used: " SIZE_FORMAT "K, Waste: " SIZE_FORMAT "K",
+      usage._survivor_used / K, ((after._survivor_length * HeapRegion::GrainBytes) - usage._survivor_used) / K);
+
+  log_info(gc, heap)("Old regions: " SIZE_FORMAT "->" SIZE_FORMAT,
+                     _before._old_length, after._old_length);
+  log_trace(gc, heap)(" Used: " SIZE_FORMAT "K, Waste: " SIZE_FORMAT "K",
+      usage._old_used / K, ((after._old_length * HeapRegion::GrainBytes) - usage._old_used) / K);
+
+  log_info(gc, heap)("Humongous regions: " SIZE_FORMAT "->" SIZE_FORMAT,
+                     _before._humongous_length, after._humongous_length);
+  log_trace(gc, heap)(" Used: " SIZE_FORMAT "K, Waste: " SIZE_FORMAT "K",
+      usage._humongous_used / K, ((after._humongous_length * HeapRegion::GrainBytes) - usage._humongous_used) / K);
+
+  MetaspaceAux::print_metaspace_change(_before._metaspace_used_bytes);
+}
--- /dev/null	Thu Jan 01 00:00:00 1970 +0000
+++ b/hotspot/src/share/vm/gc/g1/g1HeapTransition.hpp	Tue Feb 02 12:13:05 2016 +0100
@@ -0,0 +1,52 @@
+/*
+ * Copyright (c) 2016, Oracle and/or its affiliates. All rights reserved.
+ * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
+ *
+ * This code is free software; you can redistribute it and/or modify it
+ * under the terms of the GNU General Public License version 2 only, as
+ * published by the Free Software Foundation.
+ *
+ * This code is distributed in the hope that it will be useful, but WITHOUT
+ * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or
+ * FITNESS FOR A PARTICULAR PURPOSE.  See the GNU General Public License
+ * version 2 for more details (a copy is included in the LICENSE file that
+ * accompanied this code).
+ *
+ * You should have received a copy of the GNU General Public License version
+ * 2 along with this work; if not, write to the Free Software Foundation,
+ * Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA.
+ *
+ * Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA
+ * or visit www.oracle.com if you need additional information or have any
+ * questions.
+ *
+ */
+
+#ifndef SHARE_VM_GC_G1_G1HEAPTRANSITION_HPP
+#define SHARE_VM_GC_G1_G1HEAPTRANSITION_HPP
+
+#include "gc/shared/plab.hpp"
+
+class G1CollectedHeap;
+
+class G1HeapTransition {
+  struct Data {
+    size_t _eden_length;
+    size_t _survivor_length;
+    size_t _old_length;
+    size_t _humongous_length;
+    size_t _metaspace_used_bytes;
+
+    Data(G1CollectedHeap* g1_heap);
+  };
+
+  G1CollectedHeap* _g1_heap;
+  Data _before;
+
+public:
+  G1HeapTransition(G1CollectedHeap* g1_heap);
+
+  void print();
+};
+
+#endif // SHARE_VM_GC_G1_G1HEAPTRANSITION_HPP