7050392: G1: Introduce flag to generate a log of the G1 ergonomic decisions

Summary: It introduces ergonomic decision logging in G1 for the following heuristics: heap sizing, collection set construction, concurrent cycle initiation, and partially-young GC start/end. The code has a bit of refactoring in a few places to make the decision logging possible. It also replaces alternative ad-hoc logging that we have under different parameters and switches (G1_DEBUG, G1PolicyVerbose).
Reviewed-by: johnc, ysr

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

 /*
- * Copyright (c) 2001, 2010, Oracle and/or its affiliates. All rights reserved.
+ * Copyright (c) 2001, 2011, 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
@@ -26,6 +26,7 @@
 #include "gc_implementation/g1/collectionSetChooser.hpp"
 #include "gc_implementation/g1/g1CollectedHeap.inline.hpp"
 #include "gc_implementation/g1/g1CollectorPolicy.hpp"
+#include "gc_implementation/g1/g1ErgoVerbose.hpp"
 #include "memory/space.inline.hpp"
 
 CSetChooserCache::CSetChooserCache() {
@@ -358,6 +359,9 @@ CollectionSetChooser::getNextMarkedRegion(double time_remaining,
   if (_cache.is_empty()) {
     assert(_curMarkedIndex == _numMarkedRegions,
            "if cache is empty, list should also be empty");
+    ergo_verbose0(ErgoCSetConstruction,
+                  "stop adding old regions to CSet",
+                  ergo_format_reason("cache is empty"));
     return NULL;
   }
 
@@ -368,10 +372,23 @@ CollectionSetChooser::getNextMarkedRegion(double time_remaining,
   if (g1p->adaptive_young_list_length()) {
     if (time_remaining - predicted_time < 0.0) {
       g1h->check_if_region_is_too_expensive(predicted_time);
+      ergo_verbose2(ErgoCSetConstruction,
+                    "stop adding old regions to CSet",
+                    ergo_format_reason("predicted old region time higher than remaining time")
+                    ergo_format_ms("predicted old region time")
+                    ergo_format_ms("remaining time"),
+                    predicted_time, time_remaining);
       return NULL;
     }
   } else {
-    if (predicted_time > 2.0 * avg_prediction) {
+    double threshold = 2.0 * avg_prediction;
+    if (predicted_time > threshold) {
+      ergo_verbose2(ErgoCSetConstruction,
+                    "stop adding old regions to CSet",
+                    ergo_format_reason("predicted old region time higher than threshold")
+                    ergo_format_ms("predicted old region time")
+                    ergo_format_ms("threshold"),
+                    predicted_time, threshold);
       return NULL;
     }
   }

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

@@ -28,6 +28,7 @@
 #include "gc_implementation/g1/concurrentMarkThread.inline.hpp"
 #include "gc_implementation/g1/g1CollectedHeap.inline.hpp"
 #include "gc_implementation/g1/g1CollectorPolicy.hpp"
+#include "gc_implementation/g1/g1ErgoVerbose.hpp"
 #include "gc_implementation/g1/g1OopClosures.inline.hpp"
 #include "gc_implementation/g1/g1RemSet.hpp"
 #include "gc_implementation/g1/heapRegionRemSet.hpp"
@@ -1727,18 +1728,21 @@ void ConcurrentMark::cleanup() {
 
   size_t known_garbage_bytes =
     g1_par_count_task.used_bytes() - g1_par_count_task.live_bytes();
-#if 0
-  gclog_or_tty->print_cr("used %1.2lf, live %1.2lf, garbage %1.2lf",
-                         (double) g1_par_count_task.used_bytes() / (double) (1024 * 1024),
-                         (double) g1_par_count_task.live_bytes() / (double) (1024 * 1024),
-                         (double) known_garbage_bytes / (double) (1024 * 1024));
-#endif // 0
   g1p->set_known_garbage_bytes(known_garbage_bytes);
 
   size_t start_used_bytes = g1h->used();
   _at_least_one_mark_complete = true;
   g1h->set_marking_complete();
 
+  ergo_verbose4(ErgoConcCycles,
+           "finish cleanup",
+           ergo_format_byte("occupancy")
+           ergo_format_byte("capacity")
+           ergo_format_byte_perc("known garbage"),
+           start_used_bytes, g1h->capacity(),
+           known_garbage_bytes,
+           ((double) known_garbage_bytes / (double) g1h->capacity()) * 100.0);
+
   double count_end = os::elapsedTime();
   double this_final_counting_time = (count_end - start);
   if (G1PrintParCleanupStats) {

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

@@ -31,6 +31,7 @@
 #include "gc_implementation/g1/g1AllocRegion.inline.hpp"
 #include "gc_implementation/g1/g1CollectedHeap.inline.hpp"
 #include "gc_implementation/g1/g1CollectorPolicy.hpp"
+#include "gc_implementation/g1/g1ErgoVerbose.hpp"
 #include "gc_implementation/g1/g1MarkSweep.hpp"
 #include "gc_implementation/g1/g1OopClosures.inline.hpp"
 #include "gc_implementation/g1/g1RemSet.inline.hpp"
@@ -577,6 +578,11 @@ HeapRegion* G1CollectedHeap::new_region(size_t word_size, bool do_expand) {
     res = new_region_try_secondary_free_list();
   }
   if (res == NULL && do_expand) {
+    ergo_verbose1(ErgoHeapSizing,
+                  "attempt heap expansion",
+                  ergo_format_reason("region allocation request failed")
+                  ergo_format_byte("allocation request"),
+                  word_size * HeapWordSize);
     if (expand(word_size * HeapWordSize)) {
       // Even though the heap was expanded, it might not have reached
       // the desired size. So, we cannot assume that the allocation
@@ -790,6 +796,11 @@ HeapWord* G1CollectedHeap::humongous_obj_allocate(size_t word_size) {
       // room available.
       assert(num_regions > fs, "earlier allocation should have succeeded");
 
+      ergo_verbose1(ErgoHeapSizing,
+                    "attempt heap expansion",
+                    ergo_format_reason("humongous allocation request failed")
+                    ergo_format_byte("allocation request"),
+                    word_size * HeapWordSize);
       if (expand((num_regions - fs) * HeapRegion::GrainBytes)) {
         // Even though the heap was expanded, it might not have
         // reached the desired size. So, we cannot assume that the
@@ -906,6 +917,8 @@ HeapWord* G1CollectedHeap::attempt_allocation_slow(size_t word_size,
 
       if (GC_locker::is_active_and_needs_gc()) {
         if (g1_policy()->can_expand_young_list()) {
+          // No need for an ergo verbose message here,
+          // can_expand_young_list() does this when it returns true.
           result = _mutator_alloc_region.attempt_allocation_force(word_size,
                                                       false /* bot_updates */);
           if (result != NULL) {
@@ -1477,63 +1490,34 @@ resize_if_necessary_after_full_collection(size_t word_size) {
   // we'll try to make the capacity smaller than it, not greater).
   maximum_desired_capacity =  MAX2(maximum_desired_capacity, min_heap_size);
 
-  if (PrintGC && Verbose) {
-    const double free_percentage =
-      (double) free_after_gc / (double) capacity_after_gc;
-    gclog_or_tty->print_cr("Computing new size after full GC ");
-    gclog_or_tty->print_cr("  "
-                           "  minimum_free_percentage: %6.2f",
-                           minimum_free_percentage);
-    gclog_or_tty->print_cr("  "
-                           "  maximum_free_percentage: %6.2f",
-                           maximum_free_percentage);
-    gclog_or_tty->print_cr("  "
-                           "  capacity: %6.1fK"
-                           "  minimum_desired_capacity: %6.1fK"
-                           "  maximum_desired_capacity: %6.1fK",
-                           (double) capacity_after_gc / (double) K,
-                           (double) minimum_desired_capacity / (double) K,
-                           (double) maximum_desired_capacity / (double) K);
-    gclog_or_tty->print_cr("  "
-                           "  free_after_gc: %6.1fK"
-                           "  used_after_gc: %6.1fK",
-                           (double) free_after_gc / (double) K,
-                           (double) used_after_gc / (double) K);
-    gclog_or_tty->print_cr("  "
-                           "   free_percentage: %6.2f",
-                           free_percentage);
-  }
   if (capacity_after_gc < minimum_desired_capacity) {
     // Don't expand unless it's significant
     size_t expand_bytes = minimum_desired_capacity - capacity_after_gc;
-    if (expand(expand_bytes)) {
-      if (PrintGC && Verbose) {
-        gclog_or_tty->print_cr("  "
-                               "  expanding:"
-                               "  max_heap_size: %6.1fK"
-                               "  minimum_desired_capacity: %6.1fK"
-                               "  expand_bytes: %6.1fK",
-                               (double) max_heap_size / (double) K,
-                               (double) minimum_desired_capacity / (double) K,
-                               (double) expand_bytes / (double) K);
-      }
-    }
+    ergo_verbose4(ErgoHeapSizing,
+                  "attempt heap expansion",
+                  ergo_format_reason("capacity lower than "
+                                     "min desired capacity after Full GC")
+                  ergo_format_byte("capacity")
+                  ergo_format_byte("occupancy")
+                  ergo_format_byte_perc("min desired capacity"),
+                  capacity_after_gc, used_after_gc,
+                  minimum_desired_capacity, (double) MinHeapFreeRatio);
+    expand(expand_bytes);
 
     // No expansion, now see if we want to shrink
   } else if (capacity_after_gc > maximum_desired_capacity) {
     // Capacity too large, compute shrinking size
     size_t shrink_bytes = capacity_after_gc - maximum_desired_capacity;
+    ergo_verbose4(ErgoHeapSizing,
+                  "attempt heap shrinking",
+                  ergo_format_reason("capacity higher than "
+                                     "max desired capacity after Full GC")
+                  ergo_format_byte("capacity")
+                  ergo_format_byte("occupancy")
+                  ergo_format_byte_perc("max desired capacity"),
+                  capacity_after_gc, used_after_gc,
+                  maximum_desired_capacity, (double) MaxHeapFreeRatio);
     shrink(shrink_bytes);
-    if (PrintGC && Verbose) {
-      gclog_or_tty->print_cr("  "
-                             "  shrinking:"
-                             "  min_heap_size: %6.1fK"
-                             "  maximum_desired_capacity: %6.1fK"
-                             "  shrink_bytes: %6.1fK",
-                             (double) min_heap_size / (double) K,
-                             (double) maximum_desired_capacity / (double) K,
-                             (double) shrink_bytes / (double) K);
-    }
   }
 }
 
@@ -1619,6 +1603,11 @@ HeapWord* G1CollectedHeap::expand_and_allocate(size_t word_size) {
   verify_region_sets_optional();
 
   size_t expand_bytes = MAX2(word_size * HeapWordSize, MinHeapDeltaBytes);
+  ergo_verbose1(ErgoHeapSizing,
+                "attempt heap expansion",
+                ergo_format_reason("allocation request failed")
+                ergo_format_byte("allocation request"),
+                word_size * HeapWordSize);
   if (expand(expand_bytes)) {
     _hrs.verify_optional();
     verify_region_sets_optional();
@@ -1646,11 +1635,11 @@ bool G1CollectedHeap::expand(size_t expand_bytes) {
   size_t aligned_expand_bytes = ReservedSpace::page_align_size_up(expand_bytes);
   aligned_expand_bytes = align_size_up(aligned_expand_bytes,
                                        HeapRegion::GrainBytes);
-
-  if (Verbose && PrintGC) {
-    gclog_or_tty->print("Expanding garbage-first heap from %ldK by %ldK",
-                           old_mem_size/K, aligned_expand_bytes/K);
-  }
+  ergo_verbose2(ErgoHeapSizing,
+                "expand the heap",
+                ergo_format_byte("requested expansion amount")
+                ergo_format_byte("attempted expansion amount"),
+                expand_bytes, aligned_expand_bytes);
 
   // First commit the memory.
   HeapWord* old_end = (HeapWord*) _g1_storage.high();
@@ -1694,6 +1683,9 @@ bool G1CollectedHeap::expand(size_t expand_bytes) {
       assert(curr == mr.end(), "post-condition");
     }
   } else {
+    ergo_verbose0(ErgoHeapSizing,
+                  "did not expand the heap",
+                  ergo_format_reason("heap expansion operation failed"));
     // The expansion of the virtual storage space was unsuccessful.
     // Let's see if it was because we ran out of swap.
     if (G1ExitOnExpansionFailure &&
@@ -1702,13 +1694,6 @@ bool G1CollectedHeap::expand(size_t expand_bytes) {
       vm_exit_out_of_memory(aligned_expand_bytes, "G1 heap expansion");
     }
   }
-
-  if (Verbose && PrintGC) {
-    size_t new_mem_size = _g1_storage.committed_size();
-    gclog_or_tty->print_cr("...%s, expanded to %ldK",
-                           (successful ? "Successful" : "Failed"),
-                           new_mem_size/K);
-  }
   return successful;
 }
 
@@ -1722,6 +1707,13 @@ void G1CollectedHeap::shrink_helper(size_t shrink_bytes) {
   MemRegion mr = _hrs.shrink_by(aligned_shrink_bytes, &num_regions_deleted);
   HeapWord* old_end = (HeapWord*) _g1_storage.high();
   assert(mr.end() == old_end, "post-condition");
+
+  ergo_verbose3(ErgoHeapSizing,
+                "shrink the heap",
+                ergo_format_byte("requested shrinking amount")
+                ergo_format_byte("aligned shrinking amount")
+                ergo_format_byte("attempted shrinking amount"),
+                shrink_bytes, aligned_shrink_bytes, mr.byte_size());
   if (mr.byte_size() > 0) {
     if (_hr_printer.is_active()) {
       HeapWord* curr = mr.end();
@@ -1740,13 +1732,10 @@ void G1CollectedHeap::shrink_helper(size_t shrink_bytes) {
     _expansion_regions += num_regions_deleted;
     update_committed_space(old_end, new_end);
     HeapRegionRemSet::shrink_heap(n_regions());
-
-    if (Verbose && PrintGC) {
-      size_t new_mem_size = _g1_storage.committed_size();
-      gclog_or_tty->print_cr("Shrinking garbage-first heap from %ldK by %ldK to %ldK",
-                             old_mem_size/K, aligned_shrink_bytes/K,
-                             new_mem_size/K);
-    }
+  } else {
+    ergo_verbose0(ErgoHeapSizing,
+                  "did not shrink the heap",
+                  ergo_format_reason("heap shrinking operation failed"));
   }
 }
 
@@ -3579,6 +3568,8 @@ G1CollectedHeap::do_collection_pause_at_safepoint(double target_pause_time_ms) {
         size_t expand_bytes = g1_policy()->expansion_amount();
         if (expand_bytes > 0) {
           size_t bytes_before = capacity();
+          // No need for an ergo verbose message here,
+          // expansion_amount() does this when it returns a value > 0.
           if (!expand(expand_bytes)) {
             // We failed to expand the heap so let's verify that
             // committed/uncommitted amount match the backing store
@@ -3732,13 +3723,6 @@ public:
   bool do_object_b(oop p) {
     // It is reachable if it is outside the collection set, or is inside
     // and forwarded.
-
-#ifdef G1_DEBUG
-    gclog_or_tty->print_cr("is alive "PTR_FORMAT" in CS %d forwarded %d overall %d",
-                           (void*) p, _g1->obj_in_cs(p), p->is_forwarded(),
-                           !_g1->obj_in_cs(p) || p->is_forwarded());
-#endif // G1_DEBUG
-
     return !_g1->obj_in_cs(p) || p->is_forwarded();
   }
 };
@@ -3750,20 +3734,9 @@ public:
   void do_oop(narrowOop* p) { guarantee(false, "Not needed"); }
   void do_oop(      oop* p) {
     oop obj = *p;
-#ifdef G1_DEBUG
-    if (PrintGC && Verbose) {
-      gclog_or_tty->print_cr("keep alive *"PTR_FORMAT" = "PTR_FORMAT" "PTR_FORMAT,
-                             p, (void*) obj, (void*) *p);
-    }
-#endif // G1_DEBUG
-
     if (_g1->obj_in_cs(obj)) {
       assert( obj->is_forwarded(), "invariant" );
       *p = obj->forwardee();
-#ifdef G1_DEBUG
-      gclog_or_tty->print_cr("     in CSet: moved "PTR_FORMAT" -> "PTR_FORMAT,
-                             (void*) obj, (void*) *p);
-#endif // G1_DEBUG
     }
   }
 };

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

@@ -493,7 +493,6 @@ public:
 
   // </NEW PREDICTION>
 
-public:
   void cset_regions_freed() {
     bool propagate = _last_young_gc_full && !_in_marking_window;
     _short_lived_surv_rate_group->all_surviving_words_recorded(propagate);
@@ -1045,7 +1044,7 @@ public:
   // new cycle, as long as we are not already in one. It's best if it
   // is called during a safepoint when the test whether a cycle is in
   // progress or not is stable.
-  bool force_initial_mark_if_outside_cycle();
+  bool force_initial_mark_if_outside_cycle(GCCause::Cause gc_cause);
 
   // This is called at the very beginning of an evacuation pause (it
   // has to be the first thing that the pause does). If
@@ -1234,8 +1233,6 @@ public:
 
 class G1CollectorPolicy_BestRegionsFirst: public G1CollectorPolicy {
   CollectionSetChooser* _collectionSetChooser;
-  // If the estimated is less then desirable, resize if possible.
-  void expand_if_possible(size_t numRegions);
 
   virtual void choose_collection_set(double target_pause_time_ms);
   virtual void record_collection_pause_start(double start_time_sec,
@@ -1269,8 +1266,4 @@ inline double variance(int n, double sum_of_squares, double sum) {
   return (sum_of_squares - 2.0 * avg * sum + n_d * avg * avg) / n_d;
 }
 
-// Local Variables: ***
-// c-indentation-style: gnu ***
-// End: ***
-
 #endif // SHARE_VM_GC_IMPLEMENTATION_G1_G1COLLECTORPOLICY_HPP

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

+/*
+ * Copyright (c) 2011, 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_implementation/g1/g1ErgoVerbose.hpp"
+#include "utilities/ostream.hpp"
+
+ErgoLevel G1ErgoVerbose::_level;
+bool G1ErgoVerbose::_enabled[ErgoHeuristicNum];
+
+void G1ErgoVerbose::initialize() {
+  set_level(ErgoLow);
+  set_enabled(false);
+}
+
+void G1ErgoVerbose::set_level(ErgoLevel level) {
+  _level = level;
+}
+
+void G1ErgoVerbose::set_enabled(ErgoHeuristic n, bool enabled) {
+  assert(0 <= n && n < ErgoHeuristicNum, "pre-condition");
+  _enabled[n] = enabled;
+}
+
+void G1ErgoVerbose::set_enabled(bool enabled) {
+  for (int n = 0; n < ErgoHeuristicNum; n += 1) {
+    set_enabled((ErgoHeuristic) n, enabled);
+  }
+}
+
+const char* G1ErgoVerbose::to_string(int tag) {
+  ErgoHeuristic n = extract_heuristic(tag);
+  switch (n) {
+  case ErgoHeapSizing:            return "Heap Sizing";
+  case ErgoCSetConstruction:      return "CSet Construction";
+  case ErgoConcCycles:            return "Concurrent Cycles";
+  case ErgoPartiallyYoungGCs:     return "Partially-Young GCs";
+  default:
+    ShouldNotReachHere();
+    // Keep the Windows compiler happy
+    return NULL;
+  }
+}
+

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

+/*
+ * Copyright (c) 2011, 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_IMPLEMENTATION_G1_G1ERGOVERBOSE_HPP
+#define SHARE_VM_GC_IMPLEMENTATION_G1_G1ERGOVERBOSE_HPP
+
+#include "memory/allocation.hpp"
+#include "utilities/debug.hpp"
+
+// The log of G1's heuristic decisions comprises of a series of
+// records which have a similar format in order to maintain
+// consistency across records and ultimately easier parsing of the
+// output, if we ever choose to do that. Each record consists of:
+// * A time stamp to be able to easily correlate each record with
+// other events.
+// * A unique string to allow us to easily identify such records.
+// * The name of the heuristic the record corresponds to.
+// * An action string which describes the action that G1 did or is
+// about to do.
+// * An optional reason string which describes the reason for the
+// action.
+// * An optional number of name/value pairs which contributed to the
+// decision to take the action described in the record.
+//
+// Each record is associated with a "tag" which is the combination of
+// the heuristic the record corresponds to, as well as the min level
+// of verboseness at which the record should be printed. The tag is
+// checked against the current settings to determine whether the record
+// should be printed or not.
+
+// The available verboseness levels.
+typedef enum {
+  // Determine which part of the tag is occupied by the level.
+  ErgoLevelShift = 8,
+  ErgoLevelMask = ~((1 << ErgoLevelShift) - 1),
+
+  // ErgoLow is 0 so that we don't have to explicitly or a heuristic
+  // id with ErgoLow to keep its use simpler.
+  ErgoLow = 0,
+  ErgoHigh = 1 << ErgoLevelShift,
+} ErgoLevel;
+
+// The available heuristics.
+typedef enum {
+  // Determines which part of the tag is occupied by the heuristic id.
+  ErgoHeuristicMask = ~ErgoLevelMask,
+
+  ErgoHeapSizing = 0,
+  ErgoCSetConstruction,
+  ErgoConcCycles,
+  ErgoPartiallyYoungGCs,
+
+  ErgoHeuristicNum
+} ErgoHeuristic;
+
+class G1ErgoVerbose : AllStatic {
+private:
+  // Determines the minimum verboseness level at which records will be
+  // printed.
+  static ErgoLevel _level;
+  // Determines which heuristics are currently enabled.
+  static bool _enabled[ErgoHeuristicNum];
+
+  static ErgoLevel extract_level(int tag) {
+    return (ErgoLevel) (tag & ErgoLevelMask);
+  }
+
+  static ErgoHeuristic extract_heuristic(int tag) {
+    return (ErgoHeuristic) (tag & ErgoHeuristicMask);
+  }
+
+public:
+  // Needs to be explicitly called at GC initialization.
+  static void initialize();
+
+  static void set_level(ErgoLevel level);
+  static void set_enabled(ErgoHeuristic h, bool enabled);
+  // It is applied to all heuristics.
+  static void set_enabled(bool enabled);
+
+  static bool enabled(int tag) {
+    ErgoLevel level = extract_level(tag);
+    ErgoHeuristic n = extract_heuristic(tag);
+    return level <= _level && _enabled[n];
+  }
+
+  // Extract the heuristic id from the tag and return a string with
+  // its name.
+  static const char* to_string(int tag);
+};
+
+// The macros below generate the format string for values of different
+// types and/or metrics.
+
+// The reason for the action is optional and is handled specially: the
+// reason string is concatenated here so it's not necessary to pass it
+// as a parameter.
+#define ergo_format_reason(_reason_) ", reason: " _reason_
+
+// Single parameter format strings
+#define ergo_format_str(_name_)      ", " _name_ ": %s"
+#define ergo_format_region(_name_)   ", " _name_ ": "SIZE_FORMAT" regions"
+#define ergo_format_byte(_name_)     ", " _name_ ": "SIZE_FORMAT" bytes"
+#define ergo_format_double(_name_)   ", " _name_ ": %1.2f"
+#define ergo_format_perc(_name_)     ", " _name_ ": %1.2f %%"
+#define ergo_format_ms(_name_)       ", " _name_ ": %1.2f ms"
+
+// Double parameter format strings
+#define ergo_format_byte_perc(_name_)                                   \
+                             ", " _name_ ": "SIZE_FORMAT" bytes (%1.2f %%)"
+
+// Generates the format string
+#define ergo_format(_action_, _extra_format_)                   \
+  " %1.3f: [G1Ergonomics (%s) " _action_ _extra_format_ "]"
+
+// Conditionally, prints an ergonomic decision record. _extra_format_
+// is the format string for the optional items we'd like to print
+// (i.e., the decision's reason and any associated values). This
+// string should be built up using the ergo_*_format macros (see
+// above) to ensure consistency.
+//
+// Since we cannot rely on the compiler supporting variable argument
+// macros, this macro accepts a fixed number of arguments and passes
+// them to the print method. For convenience, we have wrapper macros
+// below which take a specific number of arguments and set the rest to
+// a default value.
+#define ergo_verbose_common(_tag_, _action_, _extra_format_,            \
+                            _arg0_, _arg1_, _arg2_, _arg3_, _arg4_, _arg5_) \
+  do {                                                                  \
+    if (G1ErgoVerbose::enabled((_tag_))) {                              \
+      gclog_or_tty->print_cr(ergo_format(_action_, _extra_format_),     \
+                             os::elapsedTime(),                         \
+                             G1ErgoVerbose::to_string((_tag_)),         \
+                             (_arg0_), (_arg1_), (_arg2_),              \
+                             (_arg3_), (_arg4_), (_arg5_));             \
+    }                                                                   \
+  } while (0)
+
+
+#define ergo_verbose(_tag_, _action_)                           \
+  ergo_verbose_common(_tag_, _action_, "", 0, 0, 0, 0, 0, 0)
+
+#define ergo_verbose0(_tag_, _action_, _extra_format_)                  \
+  ergo_verbose_common(_tag_, _action_, _extra_format_, 0, 0, 0, 0, 0, 0)
+
+#define ergo_verbose1(_tag_, _action_, _extra_format_,                  \
+                      _arg0_)                                           \
+  ergo_verbose_common(_tag_, _action_, _extra_format_,                  \
+                      _arg0_, 0, 0, 0, 0, 0)
+
+#define ergo_verbose2(_tag_, _action_, _extra_format_,                  \
+                      _arg0_, _arg1_)                                   \
+  ergo_verbose_common(_tag_, _action_, _extra_format_,                  \
+                      _arg0_, _arg1_, 0, 0, 0, 0)
+
+#define ergo_verbose3(_tag_, _action_, _extra_format_,                  \
+                      _arg0_, _arg1_, _arg2_)                           \
+  ergo_verbose_common(_tag_, _action_, _extra_format_,                  \
+                      _arg0_, _arg1_, _arg2_, 0, 0, 0)
+
+#define ergo_verbose4(_tag_, _action_, _extra_format_,                  \
+                      _arg0_, _arg1_, _arg2_, _arg3_)                   \
+  ergo_verbose_common(_tag_, _action_, _extra_format_,                  \
+                      _arg0_, _arg1_, _arg2_, _arg3_, 0, 0)
+
+#define ergo_verbose5(_tag_, _action_, _extra_format_,                  \
+                      _arg0_, _arg1_, _arg2_, _arg3_, _arg4_)           \
+  ergo_verbose_common(_tag_, _action_, _extra_format_,                  \
+                      _arg0_, _arg1_, _arg2_, _arg3_, _arg4_, 0)
+
+#define ergo_verbose6(_tag_, _action_, _extra_format_,                  \
+                      _arg0_, _arg1_, _arg2_, _arg3_, _arg4_, _arg5_)   \
+  ergo_verbose_common(_tag_, _action_, _extra_format_,                  \
+                      _arg0_, _arg1_, _arg2_, _arg3_, _arg4_, _arg5_)
+
+#endif // SHARE_VM_GC_IMPLEMENTATION_G1_G1ERGOVERBOSE_HPP

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

 /*
- * Copyright (c) 2001, 2010, Oracle and/or its affiliates. All rights reserved.
+ * Copyright (c) 2001, 2011, 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
@@ -97,10 +97,6 @@ void G1MMUTrackerQueue::add_pause(double start, double end, bool gc_thread) {
     // or performance (we are GC'ing most of the time anyway!),
     // simply overwrite the oldest entry in the tracker.
 
-    if (G1PolicyVerbose > 1) {
-      warning("MMU Tracker Queue overflow. Replacing earliest entry.");
-    }
-
     _head_index = trim_index(_head_index + 1);
     assert(_head_index == _tail_index, "Because we have a full circular buffer");
     _tail_index = trim_index(_tail_index + 1);

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

@@ -98,7 +98,7 @@ void VM_G1IncCollectionPause::doit() {
 
     // At this point we are supposed to start a concurrent cycle. We
     // will do so if one is not already in progress.
-    bool res = g1h->g1_policy()->force_initial_mark_if_outside_cycle();
+    bool res = g1h->g1_policy()->force_initial_mark_if_outside_cycle(_gc_cause);
 
     // The above routine returns true if we were able to force the
     // next GC pause to be an initial mark; it returns false if a