7027766: G1: introduce flag to dump the liveness information per region at the end of marking
authortonyp
Mon, 04 Apr 2011 14:23:17 -0400
changeset 8930 52368505ee8e
parent 8929 33175c0c6b9b
child 8931 8e2b610bc48f
7027766: G1: introduce flag to dump the liveness information per region at the end of marking Summary: Repurpose the existing flag G1PrintRegionLivenessInfo to print out the liveness distribution across the regions in the heap at the end of marking. Reviewed-by: iveresov, jwilhelm
hotspot/src/share/vm/gc_implementation/g1/collectionSetChooser.cpp
hotspot/src/share/vm/gc_implementation/g1/collectionSetChooser.hpp
hotspot/src/share/vm/gc_implementation/g1/concurrentMark.cpp
hotspot/src/share/vm/gc_implementation/g1/concurrentMark.hpp
hotspot/src/share/vm/gc_implementation/g1/g1CollectedHeap.hpp
hotspot/src/share/vm/gc_implementation/g1/g1_globals.hpp
hotspot/src/share/vm/gc_implementation/g1/heapRegion.hpp
--- a/hotspot/src/share/vm/gc_implementation/g1/collectionSetChooser.cpp	Mon Apr 04 13:18:35 2011 -0400
+++ b/hotspot/src/share/vm/gc_implementation/g1/collectionSetChooser.cpp	Mon Apr 04 14:23:17 2011 -0400
@@ -262,39 +262,18 @@
   for (int i = 0; i < _numMarkedRegions; i++) {
     assert(_markedRegions.at(i) != NULL, "Should be true by sorting!");
     _markedRegions.at(i)->set_sort_index(i);
-    if (G1PrintRegionLivenessInfo > 0) {
-      if (i == 0) gclog_or_tty->print_cr("Sorted marked regions:");
-      if (i < G1PrintRegionLivenessInfo ||
-          (_numMarkedRegions-i) < G1PrintRegionLivenessInfo) {
-        HeapRegion* hr = _markedRegions.at(i);
-        size_t u = hr->used();
-        gclog_or_tty->print_cr("  Region %d: %d used, %d max live, %5.2f%%.",
-                      i, u, hr->max_live_bytes(),
-                      100.0*(float)hr->max_live_bytes()/(float)u);
-      }
+  }
+  if (G1PrintRegionLivenessInfo) {
+    G1PrintRegionLivenessInfoClosure cl(gclog_or_tty, "Post-Sorting");
+    for (int i = 0; i < _numMarkedRegions; ++i) {
+      HeapRegion* r = _markedRegions.at(i);
+      cl.doHeapRegion(r);
     }
   }
-  if (G1PolicyVerbose > 1)
-    printSortedHeapRegions();
   assert(verify(), "should now be sorted");
 }
 
 void
-printHeapRegion(HeapRegion *hr) {
-  if (hr->isHumongous())
-    gclog_or_tty->print("H: ");
-  if (hr->in_collection_set())
-    gclog_or_tty->print("CS: ");
-  gclog_or_tty->print_cr("Region " PTR_FORMAT " (%s%s) "
-                         "[" PTR_FORMAT ", " PTR_FORMAT"] "
-                         "Used: " SIZE_FORMAT "K, garbage: " SIZE_FORMAT "K.",
-                         hr, hr->is_young() ? "Y " : "  ",
-                         hr->is_marked()? "M1" : "M0",
-                         hr->bottom(), hr->end(),
-                         hr->used()/K, hr->garbage_bytes()/K);
-}
-
-void
 CollectionSetChooser::addMarkedHeapRegion(HeapRegion* hr) {
   assert(!hr->isHumongous(),
          "Humongous regions shouldn't be added to the collection set");
@@ -351,27 +330,9 @@
 
 void
 CollectionSetChooser::updateAfterFullCollection() {
-  G1CollectedHeap* g1h = G1CollectedHeap::heap();
   clearMarkedHeapRegions();
 }
 
-void
-CollectionSetChooser::printSortedHeapRegions() {
-  gclog_or_tty->print_cr("Printing %d Heap Regions sorted by amount of known garbage",
-                _numMarkedRegions);
-
-  DEBUG_ONLY(int marked_count = 0;)
-  for (int i = 0; i < _markedRegions.length(); i++) {
-    HeapRegion* r = _markedRegions.at(i);
-    if (r != NULL) {
-      printHeapRegion(r);
-      DEBUG_ONLY(marked_count++;)
-    }
-  }
-  assert(marked_count == _numMarkedRegions, "must be");
-  gclog_or_tty->print_cr("Done sorted heap region print");
-}
-
 void CollectionSetChooser::removeRegion(HeapRegion *hr) {
   int si = hr->sort_index();
   assert(si == -1 || hr->is_marked(), "Sort index not valid.");
--- a/hotspot/src/share/vm/gc_implementation/g1/collectionSetChooser.hpp	Mon Apr 04 13:18:35 2011 -0400
+++ b/hotspot/src/share/vm/gc_implementation/g1/collectionSetChooser.hpp	Mon Apr 04 14:23:17 2011 -0400
@@ -100,8 +100,6 @@
 
   CollectionSetChooser();
 
-  void printSortedHeapRegions();
-
   void sortMarkedHeapRegions();
   void fillCache();
   bool addRegionToCache(void);
--- a/hotspot/src/share/vm/gc_implementation/g1/concurrentMark.cpp	Mon Apr 04 13:18:35 2011 -0400
+++ b/hotspot/src/share/vm/gc_implementation/g1/concurrentMark.cpp	Mon Apr 04 14:23:17 2011 -0400
@@ -1204,7 +1204,6 @@
   g1p->record_concurrent_mark_remark_end();
 }
 
-
 #define CARD_BM_TEST_MODE 0
 
 class CalcLiveObjectsClosure: public HeapRegionClosure {
@@ -1726,6 +1725,11 @@
   }
   _total_counting_time += this_final_counting_time;
 
+  if (G1PrintRegionLivenessInfo) {
+    G1PrintRegionLivenessInfoClosure cl(gclog_or_tty, "Post-Marking");
+    _g1h->heap_region_iterate(&cl);
+  }
+
   // Install newly created mark bitMap as "prev".
   swapMarkBitMaps();
 
@@ -4423,3 +4427,175 @@
 
   _marking_step_diffs_ms.add(0.5);
 }
+
+// These are formatting macros that are used below to ensure
+// consistent formatting. The *_H_* versions are used to format the
+// header for a particular value and they should be kept consistent
+// with the corresponding macro. Also note that most of the macros add
+// the necessary white space (as a prefix) which makes them a bit
+// easier to compose.
+
+// All the output lines are prefixed with this string to be able to
+// identify them easily in a large log file.
+#define G1PPRL_LINE_PREFIX            "###"
+
+#define G1PPRL_ADDR_BASE_FORMAT    " "PTR_FORMAT"-"PTR_FORMAT
+#ifdef _LP64
+#define G1PPRL_ADDR_BASE_H_FORMAT  " %37s"
+#else // _LP64
+#define G1PPRL_ADDR_BASE_H_FORMAT  " %21s"
+#endif // _LP64
+
+// For per-region info
+#define G1PPRL_TYPE_FORMAT            "   %-4s"
+#define G1PPRL_TYPE_H_FORMAT          "   %4s"
+#define G1PPRL_BYTE_FORMAT            "  "SIZE_FORMAT_W(9)
+#define G1PPRL_BYTE_H_FORMAT          "  %9s"
+#define G1PPRL_DOUBLE_FORMAT          "  %14.1f"
+#define G1PPRL_DOUBLE_H_FORMAT        "  %14s"
+
+// For summary info
+#define G1PPRL_SUM_ADDR_FORMAT(tag)    "  "tag":"G1PPRL_ADDR_BASE_FORMAT
+#define G1PPRL_SUM_BYTE_FORMAT(tag)    "  "tag": "SIZE_FORMAT
+#define G1PPRL_SUM_MB_FORMAT(tag)      "  "tag": %1.2f MB"
+#define G1PPRL_SUM_MB_PERC_FORMAT(tag) G1PPRL_SUM_MB_FORMAT(tag)" / %1.2f %%"
+
+G1PrintRegionLivenessInfoClosure::
+G1PrintRegionLivenessInfoClosure(outputStream* out, const char* phase_name)
+  : _out(out),
+    _total_used_bytes(0), _total_capacity_bytes(0),
+    _total_prev_live_bytes(0), _total_next_live_bytes(0),
+    _hum_used_bytes(0), _hum_capacity_bytes(0),
+    _hum_prev_live_bytes(0), _hum_next_live_bytes(0) {
+  G1CollectedHeap* g1h = G1CollectedHeap::heap();
+  MemRegion g1_committed = g1h->g1_committed();
+  MemRegion g1_reserved = g1h->g1_reserved();
+  double now = os::elapsedTime();
+
+  // Print the header of the output.
+  _out->cr();
+  _out->print_cr(G1PPRL_LINE_PREFIX" PHASE %s @ %1.3f", phase_name, now);
+  _out->print_cr(G1PPRL_LINE_PREFIX" HEAP"
+                 G1PPRL_SUM_ADDR_FORMAT("committed")
+                 G1PPRL_SUM_ADDR_FORMAT("reserved")
+                 G1PPRL_SUM_BYTE_FORMAT("region-size"),
+                 g1_committed.start(), g1_committed.end(),
+                 g1_reserved.start(), g1_reserved.end(),
+                 HeapRegion::GrainBytes);
+  _out->print_cr(G1PPRL_LINE_PREFIX);
+  _out->print_cr(G1PPRL_LINE_PREFIX
+                 G1PPRL_TYPE_H_FORMAT
+                 G1PPRL_ADDR_BASE_H_FORMAT
+                 G1PPRL_BYTE_H_FORMAT
+                 G1PPRL_BYTE_H_FORMAT
+                 G1PPRL_BYTE_H_FORMAT
+                 G1PPRL_DOUBLE_H_FORMAT,
+                 "type", "address-range",
+                 "used", "prev-live", "next-live", "gc-eff");
+}
+
+// It takes as a parameter a reference to one of the _hum_* fields, it
+// deduces the corresponding value for a region in a humongous region
+// series (either the region size, or what's left if the _hum_* field
+// is < the region size), and updates the _hum_* field accordingly.
+size_t G1PrintRegionLivenessInfoClosure::get_hum_bytes(size_t* hum_bytes) {
+  size_t bytes = 0;
+  // The > 0 check is to deal with the prev and next live bytes which
+  // could be 0.
+  if (*hum_bytes > 0) {
+    bytes = MIN2((size_t) HeapRegion::GrainBytes, *hum_bytes);
+    *hum_bytes -= bytes;
+  }
+  return bytes;
+}
+
+// It deduces the values for a region in a humongous region series
+// from the _hum_* fields and updates those accordingly. It assumes
+// that that _hum_* fields have already been set up from the "starts
+// humongous" region and we visit the regions in address order.
+void G1PrintRegionLivenessInfoClosure::get_hum_bytes(size_t* used_bytes,
+                                                     size_t* capacity_bytes,
+                                                     size_t* prev_live_bytes,
+                                                     size_t* next_live_bytes) {
+  assert(_hum_used_bytes > 0 && _hum_capacity_bytes > 0, "pre-condition");
+  *used_bytes      = get_hum_bytes(&_hum_used_bytes);
+  *capacity_bytes  = get_hum_bytes(&_hum_capacity_bytes);
+  *prev_live_bytes = get_hum_bytes(&_hum_prev_live_bytes);
+  *next_live_bytes = get_hum_bytes(&_hum_next_live_bytes);
+}
+
+bool G1PrintRegionLivenessInfoClosure::doHeapRegion(HeapRegion* r) {
+  const char* type = "";
+  HeapWord* bottom       = r->bottom();
+  HeapWord* end          = r->end();
+  size_t capacity_bytes  = r->capacity();
+  size_t used_bytes      = r->used();
+  size_t prev_live_bytes = r->live_bytes();
+  size_t next_live_bytes = r->next_live_bytes();
+  double gc_eff          = r->gc_efficiency();
+  if (r->used() == 0) {
+    type = "FREE";
+  } else if (r->is_survivor()) {
+    type = "SURV";
+  } else if (r->is_young()) {
+    type = "EDEN";
+  } else if (r->startsHumongous()) {
+    type = "HUMS";
+
+    assert(_hum_used_bytes == 0 && _hum_capacity_bytes == 0 &&
+           _hum_prev_live_bytes == 0 && _hum_next_live_bytes == 0,
+           "they should have been zeroed after the last time we used them");
+    // Set up the _hum_* fields.
+    _hum_capacity_bytes  = capacity_bytes;
+    _hum_used_bytes      = used_bytes;
+    _hum_prev_live_bytes = prev_live_bytes;
+    _hum_next_live_bytes = next_live_bytes;
+    get_hum_bytes(&used_bytes, &capacity_bytes,
+                  &prev_live_bytes, &next_live_bytes);
+    end = bottom + HeapRegion::GrainWords;
+  } else if (r->continuesHumongous()) {
+    type = "HUMC";
+    get_hum_bytes(&used_bytes, &capacity_bytes,
+                  &prev_live_bytes, &next_live_bytes);
+    assert(end == bottom + HeapRegion::GrainWords, "invariant");
+  } else {
+    type = "OLD";
+  }
+
+  _total_used_bytes      += used_bytes;
+  _total_capacity_bytes  += capacity_bytes;
+  _total_prev_live_bytes += prev_live_bytes;
+  _total_next_live_bytes += next_live_bytes;
+
+  // Print a line for this particular region.
+  _out->print_cr(G1PPRL_LINE_PREFIX
+                 G1PPRL_TYPE_FORMAT
+                 G1PPRL_ADDR_BASE_FORMAT
+                 G1PPRL_BYTE_FORMAT
+                 G1PPRL_BYTE_FORMAT
+                 G1PPRL_BYTE_FORMAT
+                 G1PPRL_DOUBLE_FORMAT,
+                 type, bottom, end,
+                 used_bytes, prev_live_bytes, next_live_bytes, gc_eff);
+
+  return false;
+}
+
+G1PrintRegionLivenessInfoClosure::~G1PrintRegionLivenessInfoClosure() {
+  // Print the footer of the output.
+  _out->print_cr(G1PPRL_LINE_PREFIX);
+  _out->print_cr(G1PPRL_LINE_PREFIX
+                 " SUMMARY"
+                 G1PPRL_SUM_MB_FORMAT("capacity")
+                 G1PPRL_SUM_MB_PERC_FORMAT("used")
+                 G1PPRL_SUM_MB_PERC_FORMAT("prev-live")
+                 G1PPRL_SUM_MB_PERC_FORMAT("next-live"),
+                 bytes_to_mb(_total_capacity_bytes),
+                 bytes_to_mb(_total_used_bytes),
+                 perc(_total_used_bytes, _total_capacity_bytes),
+                 bytes_to_mb(_total_prev_live_bytes),
+                 perc(_total_prev_live_bytes, _total_capacity_bytes),
+                 bytes_to_mb(_total_next_live_bytes),
+                 perc(_total_next_live_bytes, _total_capacity_bytes));
+  _out->cr();
+}
--- a/hotspot/src/share/vm/gc_implementation/g1/concurrentMark.hpp	Mon Apr 04 13:18:35 2011 -0400
+++ b/hotspot/src/share/vm/gc_implementation/g1/concurrentMark.hpp	Mon Apr 04 14:23:17 2011 -0400
@@ -1149,4 +1149,54 @@
 #endif // _MARKING_STATS_
 };
 
+// Class that's used to to print out per-region liveness
+// information. It's currently used at the end of marking and also
+// after we sort the old regions at the end of the cleanup operation.
+class G1PrintRegionLivenessInfoClosure: public HeapRegionClosure {
+private:
+  outputStream* _out;
+
+  // Accumulators for these values.
+  size_t _total_used_bytes;
+  size_t _total_capacity_bytes;
+  size_t _total_prev_live_bytes;
+  size_t _total_next_live_bytes;
+
+  // These are set up when we come across a "stars humongous" region
+  // (as this is where most of this information is stored, not in the
+  // subsequent "continues humongous" regions). After that, for every
+  // region in a given humongous region series we deduce the right
+  // values for it by simply subtracting the appropriate amount from
+  // these fields. All these values should reach 0 after we've visited
+  // the last region in the series.
+  size_t _hum_used_bytes;
+  size_t _hum_capacity_bytes;
+  size_t _hum_prev_live_bytes;
+  size_t _hum_next_live_bytes;
+
+  static double perc(size_t val, size_t total) {
+    if (total == 0) {
+      return 0.0;
+    } else {
+      return 100.0 * ((double) val / (double) total);
+    }
+  }
+
+  static double bytes_to_mb(size_t val) {
+    return (double) val / (double) M;
+  }
+
+  // See the .cpp file.
+  size_t get_hum_bytes(size_t* hum_bytes);
+  void get_hum_bytes(size_t* used_bytes, size_t* capacity_bytes,
+                     size_t* prev_live_bytes, size_t* next_live_bytes);
+
+public:
+  // The header and footer are printed in the constructor and
+  // destructor respectively.
+  G1PrintRegionLivenessInfoClosure(outputStream* out, const char* phase_name);
+  virtual bool doHeapRegion(HeapRegion* r);
+  ~G1PrintRegionLivenessInfoClosure();
+};
+
 #endif // SHARE_VM_GC_IMPLEMENTATION_G1_CONCURRENTMARK_HPP
--- a/hotspot/src/share/vm/gc_implementation/g1/g1CollectedHeap.hpp	Mon Apr 04 13:18:35 2011 -0400
+++ b/hotspot/src/share/vm/gc_implementation/g1/g1CollectedHeap.hpp	Mon Apr 04 14:23:17 2011 -0400
@@ -1057,7 +1057,13 @@
     return _g1_reserved.contains(p);
   }
 
-  // Returns a MemRegion that corresponds to the space that  has been
+  // Returns a MemRegion that corresponds to the space that has been
+  // reserved for the heap
+  MemRegion g1_reserved() {
+    return _g1_reserved;
+  }
+
+  // Returns a MemRegion that corresponds to the space that has been
   // committed in the heap
   MemRegion g1_committed() {
     return _g1_committed;
--- a/hotspot/src/share/vm/gc_implementation/g1/g1_globals.hpp	Mon Apr 04 13:18:35 2011 -0400
+++ b/hotspot/src/share/vm/gc_implementation/g1/g1_globals.hpp	Mon Apr 04 14:23:17 2011 -0400
@@ -138,9 +138,9 @@
   develop(bool, G1RSCountHisto, false,                                      \
           "If true, print a histogram of RS occupancies after each pause")  \
                                                                             \
-  develop(intx, G1PrintRegionLivenessInfo, 0,                               \
-          "When > 0, print the occupancies of the <n> best and worst"       \
-          "regions.")                                                       \
+  product(bool, G1PrintRegionLivenessInfo, false,                           \
+          "Prints the liveness information for all regions in the heap "    \
+          "at the end of a marking cycle.")                                 \
                                                                             \
   develop(bool, G1PrintParCleanupStats, false,                              \
           "When true, print extra stats about parallel cleanup.")           \
--- a/hotspot/src/share/vm/gc_implementation/g1/heapRegion.hpp	Mon Apr 04 13:18:35 2011 -0400
+++ b/hotspot/src/share/vm/gc_implementation/g1/heapRegion.hpp	Mon Apr 04 14:23:17 2011 -0400
@@ -398,13 +398,16 @@
 
   // The number of bytes marked live in the region in the last marking phase.
   size_t marked_bytes()    { return _prev_marked_bytes; }
+  size_t live_bytes() {
+    return (top() - prev_top_at_mark_start()) * HeapWordSize + marked_bytes();
+  }
+
   // The number of bytes counted in the next marking.
   size_t next_marked_bytes() { return _next_marked_bytes; }
   // The number of bytes live wrt the next marking.
   size_t next_live_bytes() {
-    return (top() - next_top_at_mark_start())
-      * HeapWordSize
-      + next_marked_bytes();
+    return
+      (top() - next_top_at_mark_start()) * HeapWordSize + next_marked_bytes();
   }
 
   // A lower bound on the amount of garbage bytes in the region.