# HG changeset patch
# User brutisso
# Date 1345710072 -7200
# Node ID bb3f6194fedb0cf65a117c783d43b046627a4977
# Parent  153776c4cb6f90d81428dfc48486e515b2f3cc3c
7178363: G1: Remove the serial code for PrintGCDetails and make it a special case of the parallel code
Summary: Also reviewed by vitalyd@gmail.com. Introduced the WorkerDataArray class. Fixed some minor logging bugs.
Reviewed-by: johnc, mgerdin

diff -r 153776c4cb6f -r bb3f6194fedb src/share/vm/gc_implementation/g1/g1CollectedHeap.cpp
--- a/src/share/vm/gc_implementation/g1/g1CollectedHeap.cpp	Fri Aug 24 16:23:59 2012 -0700
+++ b/src/share/vm/gc_implementation/g1/g1CollectedHeap.cpp	Thu Aug 23 10:21:12 2012 +0200
@@ -1246,6 +1246,31 @@
   heap_region_iterate(&cl);
 }
 
+double G1CollectedHeap::verify(bool guard, const char* msg) {
+  double verify_time_ms = 0.0;
+
+  if (guard && total_collections() >= VerifyGCStartAt) {
+    double verify_start = os::elapsedTime();
+    HandleMark hm;  // Discard invalid handles created during verification
+    gclog_or_tty->print(msg);
+    prepare_for_verify();
+    Universe::verify(false /* silent */, VerifyOption_G1UsePrevMarking);
+    verify_time_ms = (os::elapsedTime() - verify_start) * 1000;
+  }
+
+  return verify_time_ms;
+}
+
+void G1CollectedHeap::verify_before_gc() {
+  double verify_time_ms = verify(VerifyBeforeGC, " VerifyBeforeGC:");
+  g1_policy()->phase_times()->record_verify_before_time_ms(verify_time_ms);
+}
+
+void G1CollectedHeap::verify_after_gc() {
+  double verify_time_ms = verify(VerifyAfterGC, " VerifyAfterGC:");
+  g1_policy()->phase_times()->record_verify_after_time_ms(verify_time_ms);
+}
+
 bool G1CollectedHeap::do_collection(bool explicit_gc,
                                     bool clear_all_soft_refs,
                                     size_t word_size) {
@@ -1304,14 +1329,8 @@
     size_t g1h_prev_used = used();
     assert(used() == recalculate_used(), "Should be equal");
 
-    if (VerifyBeforeGC && total_collections() >= VerifyGCStartAt) {
-      HandleMark hm;  // Discard invalid handles created during verification
-      gclog_or_tty->print(" VerifyBeforeGC:");
-      prepare_for_verify();
-      Universe::verify(/* silent      */ false,
-                       /* option      */ VerifyOption_G1UsePrevMarking);
-
-    }
+    verify_before_gc();
+
     pre_full_gc_dump();
 
     COMPILER2_PRESENT(DerivedPointerTable::clear());
@@ -1378,14 +1397,7 @@
 
     MemoryService::track_memory_usage();
 
-    if (VerifyAfterGC && total_collections() >= VerifyGCStartAt) {
-      HandleMark hm;  // Discard invalid handles created during verification
-      gclog_or_tty->print(" VerifyAfterGC:");
-      prepare_for_verify();
-      Universe::verify(/* silent      */ false,
-                       /* option      */ VerifyOption_G1UsePrevMarking);
-
-    }
+    verify_after_gc();
 
     assert(!ref_processor_stw()->discovery_enabled(), "Postcondition");
     ref_processor_stw()->verify_no_references_recorded();
@@ -2327,8 +2339,7 @@
   while (dcqs.apply_closure_to_completed_buffer(cl, worker_i, 0, true)) {
     n_completed_buffers++;
   }
-  g1_policy()->phase_times()->record_update_rs_processed_buffers(worker_i,
-                                                  (double) n_completed_buffers);
+  g1_policy()->phase_times()->record_update_rs_processed_buffers(worker_i, n_completed_buffers);
   dcqs.clear_n_completed_buffers();
   assert(!dcqs.completed_buffers_exist_dirty(), "Completed buffers exist!");
 }
@@ -3735,8 +3746,9 @@
 
     int active_workers = (G1CollectedHeap::use_parallel_gc_threads() ?
                                 workers()->active_workers() : 1);
-    g1_policy()->phase_times()->note_gc_start(os::elapsedTime(), active_workers,
-      g1_policy()->gcs_are_young(), g1_policy()->during_initial_mark_pause(), gc_cause());
+    double pause_start_sec = os::elapsedTime();
+    g1_policy()->phase_times()->note_gc_start(active_workers);
+    bool initial_mark_gc = g1_policy()->during_initial_mark_pause();
 
     TraceCollectorStats tcs(g1mm()->incremental_collection_counters());
     TraceMemoryManagerStats tms(false /* fullGC */, gc_cause());
@@ -3765,13 +3777,7 @@
       increment_total_collections(false /* full gc */);
       increment_gc_time_stamp();
 
-      if (VerifyBeforeGC && total_collections() >= VerifyGCStartAt) {
-        HandleMark hm;  // Discard invalid handles created during verification
-        gclog_or_tty->print(" VerifyBeforeGC:");
-        prepare_for_verify();
-        Universe::verify(/* silent      */ false,
-                         /* option      */ VerifyOption_G1UsePrevMarking);
-      }
+      verify_before_gc();
 
       COMPILER2_PRESENT(DerivedPointerTable::clear());
 
@@ -3984,10 +3990,6 @@
                                  true  /* verify_fingers */);
         _cm->note_end_of_gc();
 
-        // Collect thread local data to allow the ergonomics to use
-        // the collected information
-        g1_policy()->phase_times()->collapse_par_times();
-
         // This timing is only used by the ergonomics to handle our pause target.
         // It is unclear why this should not include the full pause. We will
         // investigate this in CR 7178365.
@@ -4020,13 +4022,7 @@
         // scanning cards (see CR 7039627).
         increment_gc_time_stamp();
 
-        if (VerifyAfterGC && total_collections() >= VerifyGCStartAt) {
-          HandleMark hm;  // Discard invalid handles created during verification
-          gclog_or_tty->print(" VerifyAfterGC:");
-          prepare_for_verify();
-          Universe::verify(/* silent      */ false,
-                           /* option      */ VerifyOption_G1UsePrevMarking);
-        }
+        verify_after_gc();
 
         assert(!ref_processor_stw()->discovery_enabled(), "Postcondition");
         ref_processor_stw()->verify_no_references_recorded();
@@ -4050,10 +4046,35 @@
 
       gc_epilogue(false);
 
-      g1_policy()->phase_times()->note_gc_end(os::elapsedTime());
-
-      // We have to do this after we decide whether to expand the heap or not.
+      if (G1Log::fine()) {
+        if (PrintGCTimeStamps) {
+          gclog_or_tty->stamp();
+          gclog_or_tty->print(": ");
+        }
+
+        GCCauseString gc_cause_str = GCCauseString("GC pause", gc_cause())
+          .append(g1_policy()->gcs_are_young() ? " (young)" : " (mixed)")
+          .append(initial_mark_gc ? " (initial-mark)" : "");
+
+        double pause_time_sec = os::elapsedTime() - pause_start_sec;
+
+        if (G1Log::finer()) {
+          if (evacuation_failed()) {
+            gc_cause_str.append(" (to-space exhausted)");
+          }
+          gclog_or_tty->print_cr("[%s, %3.7f secs]", (const char*)gc_cause_str, pause_time_sec);
+          g1_policy()->phase_times()->note_gc_end();
+          g1_policy()->phase_times()->print(pause_time_sec);
+          g1_policy()->print_detailed_heap_transition();
+        } else {
+          if (evacuation_failed()) {
+            gc_cause_str.append("--");
+          }
+          gclog_or_tty->print("[%s", (const char*)gc_cause_str);
       g1_policy()->print_heap_transition();
+          gclog_or_tty->print_cr(", %3.7f secs]", pause_time_sec);
+        }
+      }
     }
 
     // It is not yet to safe to tell the concurrent mark to
@@ -4863,7 +4884,7 @@
         evac.do_void();
         double elapsed_ms = (os::elapsedTime()-start)*1000.0;
         double term_ms = pss.term_time()*1000.0;
-        _g1h->g1_policy()->phase_times()->record_obj_copy_time(worker_id, elapsed_ms-term_ms);
+        _g1h->g1_policy()->phase_times()->add_obj_copy_time(worker_id, elapsed_ms-term_ms);
         _g1h->g1_policy()->phase_times()->record_termination(worker_id, term_ms, pss.term_attempts());
       }
       _g1h->g1_policy()->record_thread_age_table(pss.age_table());
@@ -4991,27 +5012,28 @@
   buf_scan_non_heap_roots.done();
   buf_scan_perm.done();
 
-  double ext_roots_end = os::elapsedTime();
-
-  g1_policy()->phase_times()->reset_obj_copy_time(worker_i);
   double obj_copy_time_sec = buf_scan_perm.closure_app_seconds() +
                                 buf_scan_non_heap_roots.closure_app_seconds();
   g1_policy()->phase_times()->record_obj_copy_time(worker_i, obj_copy_time_sec * 1000.0);
 
   double ext_root_time_ms =
-    ((ext_roots_end - ext_roots_start) - obj_copy_time_sec) * 1000.0;
+    ((os::elapsedTime() - ext_roots_start) - obj_copy_time_sec) * 1000.0;
 
   g1_policy()->phase_times()->record_ext_root_scan_time(worker_i, ext_root_time_ms);
 
   // During conc marking we have to filter the per-thread SATB buffers
   // to make sure we remove any oops into the CSet (which will show up
   // as implicitly live).
+  double satb_filtering_ms = 0.0;
   if (!_process_strong_tasks->is_task_claimed(G1H_PS_filter_satb_buffers)) {
     if (mark_in_progress()) {
+      double satb_filter_start = os::elapsedTime();
+
       JavaThread::satb_mark_queue_set().filter_thread_buffers();
+
+      satb_filtering_ms = (os::elapsedTime() - satb_filter_start) * 1000.0;
     }
   }
-  double satb_filtering_ms = (os::elapsedTime() - ext_roots_end) * 1000.0;
   g1_policy()->phase_times()->record_satb_filtering_time(worker_i, satb_filtering_ms);
 
   // Now scan the complement of the collection set.
@@ -5647,11 +5669,6 @@
 
   if (evacuation_failed()) {
     remove_self_forwarding_pointers();
-    if (G1Log::finer()) {
-      gclog_or_tty->print(" (to-space exhausted)");
-    } else if (G1Log::fine()) {
-      gclog_or_tty->print("--");
-    }
   }
 
   // Enqueue any remaining references remaining on the STW
diff -r 153776c4cb6f -r bb3f6194fedb src/share/vm/gc_implementation/g1/g1CollectedHeap.hpp
--- a/src/share/vm/gc_implementation/g1/g1CollectedHeap.hpp	Fri Aug 24 16:23:59 2012 -0700
+++ b/src/share/vm/gc_implementation/g1/g1CollectedHeap.hpp	Thu Aug 23 10:21:12 2012 +0200
@@ -405,6 +405,10 @@
   // heap after a compaction.
   void print_hrs_post_compaction();
 
+  double verify(bool guard, const char* msg);
+  void verify_before_gc();
+  void verify_after_gc();
+
   // These are macros so that, if the assert fires, we get the correct
   // line number, file, etc.
 
diff -r 153776c4cb6f -r bb3f6194fedb src/share/vm/gc_implementation/g1/g1CollectorPolicy.cpp
--- a/src/share/vm/gc_implementation/g1/g1CollectorPolicy.cpp	Fri Aug 24 16:23:59 2012 -0700
+++ b/src/share/vm/gc_implementation/g1/g1CollectorPolicy.cpp	Thu Aug 23 10:21:12 2012 +0200
@@ -795,7 +795,7 @@
   _trace_gen0_time_data.record_start_collection(s_w_t_ms);
   _stop_world_start = 0.0;
 
-  phase_times()->_cur_collection_start_sec = start_time_sec;
+  phase_times()->record_cur_collection_start_sec(start_time_sec);
   _cur_collection_pause_used_at_start_bytes = start_used;
   _cur_collection_pause_used_regions_at_start = _g1->used_regions();
   _pending_cards = _g1->pending_card_num();
@@ -947,7 +947,7 @@
     _trace_gen0_time_data.record_end_collection(pause_time_ms, phase_times());
     // this is where we update the allocation rate of the application
     double app_time_ms =
-      (phase_times()->_cur_collection_start_sec * 1000.0 - _prev_collection_pause_end_ms);
+      (phase_times()->cur_collection_start_sec() * 1000.0 - _prev_collection_pause_end_ms);
     if (app_time_ms < MIN_TIMER_GRANULARITY) {
       // This usually happens due to the timer not having the required
       // granularity. Some Linuxes are the usual culprits.
@@ -1035,7 +1035,7 @@
   if (update_stats) {
     double cost_per_card_ms = 0.0;
     if (_pending_cards > 0) {
-      cost_per_card_ms = phase_times()->_update_rs_time / (double) _pending_cards;
+      cost_per_card_ms = phase_times()->average_last_update_rs_time() / (double) _pending_cards;
       _cost_per_card_ms_seq->add(cost_per_card_ms);
     }
 
@@ -1043,7 +1043,7 @@
 
     double cost_per_entry_ms = 0.0;
     if (cards_scanned > 10) {
-      cost_per_entry_ms = phase_times()->_scan_rs_time / (double) cards_scanned;
+      cost_per_entry_ms = phase_times()->average_last_scan_rs_time() / (double) cards_scanned;
       if (_last_gc_was_young) {
         _cost_per_entry_ms_seq->add(cost_per_entry_ms);
       } else {
@@ -1083,7 +1083,7 @@
     size_t copied_bytes = surviving_bytes;
     double cost_per_byte_ms = 0.0;
     if (copied_bytes > 0) {
-      cost_per_byte_ms = phase_times()->_obj_copy_time / (double) copied_bytes;
+      cost_per_byte_ms = phase_times()->average_last_obj_copy_time() / (double) copied_bytes;
       if (_in_marking_window) {
         _cost_per_byte_ms_during_cm_seq->add(cost_per_byte_ms);
       } else {
@@ -1092,21 +1092,22 @@
     }
 
     double all_other_time_ms = pause_time_ms -
-      (phase_times()->_update_rs_time + phase_times()->_scan_rs_time + phase_times()->_obj_copy_time + phase_times()->_termination_time);
+      (phase_times()->average_last_update_rs_time() + phase_times()->average_last_scan_rs_time()
+      + phase_times()->average_last_obj_copy_time() + phase_times()->average_last_termination_time());
 
     double young_other_time_ms = 0.0;
     if (young_cset_region_length() > 0) {
       young_other_time_ms =
-        phase_times()->_recorded_young_cset_choice_time_ms +
-        phase_times()->_recorded_young_free_cset_time_ms;
+        phase_times()->young_cset_choice_time_ms() +
+        phase_times()->young_free_cset_time_ms();
       _young_other_cost_per_region_ms_seq->add(young_other_time_ms /
                                           (double) young_cset_region_length());
     }
     double non_young_other_time_ms = 0.0;
     if (old_cset_region_length() > 0) {
       non_young_other_time_ms =
-        phase_times()->_recorded_non_young_cset_choice_time_ms +
-        phase_times()->_recorded_non_young_free_cset_time_ms;
+        phase_times()->non_young_cset_choice_time_ms() +
+        phase_times()->non_young_free_cset_time_ms();
 
       _non_young_other_cost_per_region_ms_seq->add(non_young_other_time_ms /
                                             (double) old_cset_region_length());
@@ -1133,7 +1134,8 @@
 
   // Note that _mmu_tracker->max_gc_time() returns the time in seconds.
   double update_rs_time_goal_ms = _mmu_tracker->max_gc_time() * MILLIUNITS * G1RSetUpdatingPauseTimePercent / 100.0;
-  adjust_concurrent_refinement(phase_times()->_update_rs_time, phase_times()->_update_rs_processed_buffers, update_rs_time_goal_ms);
+  adjust_concurrent_refinement(phase_times()->average_last_update_rs_time(),
+                               phase_times()->sum_last_update_rs_processed_buffers(), update_rs_time_goal_ms);
 
   _collectionSetChooser->verify();
 }
@@ -1144,7 +1146,11 @@
   proper_unit_for_byte_size((bytes))
 
 void G1CollectorPolicy::print_heap_transition() {
-  if (G1Log::finer()) {
+  _g1->print_size_transition(gclog_or_tty,
+    _cur_collection_pause_used_at_start_bytes, _g1->used(), _g1->capacity());
+}
+
+void G1CollectorPolicy::print_detailed_heap_transition() {
     YoungList* young_list = _g1->young_list();
     size_t eden_bytes = young_list->eden_used_bytes();
     size_t survivor_bytes = young_list->survivor_used_bytes();
@@ -1171,11 +1177,6 @@
       EXT_SIZE_PARAMS(capacity));
 
     _prev_eden_capacity = eden_capacity;
-  } else if (G1Log::fine()) {
-    _g1->print_size_transition(gclog_or_tty,
-                               _cur_collection_pause_used_at_start_bytes,
-                               _g1->used(), _g1->capacity());
-  }
 }
 
 void G1CollectorPolicy::adjust_concurrent_refinement(double update_rs_time,
@@ -1900,8 +1901,7 @@
   set_recorded_rs_lengths(_inc_cset_recorded_rs_lengths);
 
   double young_end_time_sec = os::elapsedTime();
-  phase_times()->_recorded_young_cset_choice_time_ms =
-    (young_end_time_sec - young_start_time_sec) * 1000.0;
+  phase_times()->record_young_cset_choice_time_ms((young_end_time_sec - young_start_time_sec) * 1000.0);
 
   // Set the start of the non-young choice time.
   double non_young_start_time_sec = young_end_time_sec;
@@ -2015,8 +2015,7 @@
                 predicted_pause_time_ms, target_pause_time_ms);
 
   double non_young_end_time_sec = os::elapsedTime();
-  phase_times()->_recorded_non_young_cset_choice_time_ms =
-    (non_young_end_time_sec - non_young_start_time_sec) * 1000.0;
+  phase_times()->record_non_young_cset_choice_time_ms((non_young_end_time_sec - non_young_start_time_sec) * 1000.0);
 }
 
 void TraceGen0TimeData::record_start_collection(double time_to_stop_the_world_ms) {
@@ -2035,25 +2034,25 @@
   if(TraceGen0Time) {
     _total.add(pause_time_ms);
     _other.add(pause_time_ms - phase_times->accounted_time_ms());
-    _root_region_scan_wait.add(phase_times->_root_region_scan_wait_time_ms);
-    _parallel.add(phase_times->_cur_collection_par_time_ms);
-    _ext_root_scan.add(phase_times->_ext_root_scan_time);
-    _satb_filtering.add(phase_times->_satb_filtering_time);
-    _update_rs.add(phase_times->_update_rs_time);
-    _scan_rs.add(phase_times->_scan_rs_time);
-    _obj_copy.add(phase_times->_obj_copy_time);
-    _termination.add(phase_times->_termination_time);
+    _root_region_scan_wait.add(phase_times->root_region_scan_wait_time_ms());
+    _parallel.add(phase_times->cur_collection_par_time_ms());
+    _ext_root_scan.add(phase_times->average_last_ext_root_scan_time());
+    _satb_filtering.add(phase_times->average_last_satb_filtering_times_ms());
+    _update_rs.add(phase_times->average_last_update_rs_time());
+    _scan_rs.add(phase_times->average_last_scan_rs_time());
+    _obj_copy.add(phase_times->average_last_obj_copy_time());
+    _termination.add(phase_times->average_last_termination_time());
 
-    double parallel_known_time = phase_times->_ext_root_scan_time +
-      phase_times->_satb_filtering_time +
-      phase_times->_update_rs_time +
-      phase_times->_scan_rs_time +
-      phase_times->_obj_copy_time +
-      + phase_times->_termination_time;
+    double parallel_known_time = phase_times->average_last_ext_root_scan_time() +
+      phase_times->average_last_satb_filtering_times_ms() +
+      phase_times->average_last_update_rs_time() +
+      phase_times->average_last_scan_rs_time() +
+      phase_times->average_last_obj_copy_time() +
+      + phase_times->average_last_termination_time();
 
-    double parallel_other_time = phase_times->_cur_collection_par_time_ms - parallel_known_time;
+    double parallel_other_time = phase_times->cur_collection_par_time_ms() - parallel_known_time;
     _parallel_other.add(parallel_other_time);
-    _clear_ct.add(phase_times->_cur_clear_ct_time_ms);
+    _clear_ct.add(phase_times->cur_clear_ct_time_ms());
   }
 }
 
diff -r 153776c4cb6f -r bb3f6194fedb src/share/vm/gc_implementation/g1/g1CollectorPolicy.hpp
--- a/src/share/vm/gc_implementation/g1/g1CollectorPolicy.hpp	Fri Aug 24 16:23:59 2012 -0700
+++ b/src/share/vm/gc_implementation/g1/g1CollectorPolicy.hpp	Thu Aug 23 10:21:12 2012 +0200
@@ -683,6 +683,7 @@
 
   void record_collection_pause_end(double pause_time);
   void print_heap_transition();
+  void print_detailed_heap_transition();
 
   // Record the fact that a full collection occurred.
   void record_full_collection_start();
diff -r 153776c4cb6f -r bb3f6194fedb src/share/vm/gc_implementation/g1/g1GCPhaseTimes.cpp
--- a/src/share/vm/gc_implementation/g1/g1GCPhaseTimes.cpp	Fri Aug 24 16:23:59 2012 -0700
+++ b/src/share/vm/gc_implementation/g1/g1GCPhaseTimes.cpp	Thu Aug 23 10:21:12 2012 +0200
@@ -79,119 +79,145 @@
   }
 };
 
+template <class T>
+void WorkerDataArray<T>::print(int level, const char* title) {
+  if (_length == 1) {
+    // No need for min, max, average and sum for only one worker
+    LineBuffer buf(level);
+    buf.append("[%s:  ", title);
+    buf.append(_print_format, _data[0]);
+    buf.append_and_print_cr("]");
+    return;
+  }
+
+  T min = _data[0];
+  T max = _data[0];
+  T sum = 0;
+
+  LineBuffer buf(level);
+  buf.append("[%s:", title);
+  for (uint i = 0; i < _length; ++i) {
+    T val = _data[i];
+    min = MIN2(val, min);
+    max = MAX2(val, max);
+    sum += val;
+    if (G1Log::finest()) {
+      buf.append("  ");
+      buf.append(_print_format, val);
+    }
+  }
+
+  if (G1Log::finest()) {
+    buf.append_and_print_cr("");
+  }
+
+  double avg = (double)sum / (double)_length;
+  buf.append(" Min: ");
+  buf.append(_print_format, min);
+  buf.append(", Avg: ");
+  buf.append("%.1lf", avg); // Always print average as a double
+  buf.append(", Max: ");
+  buf.append(_print_format, max);
+  buf.append(", Diff: ");
+  buf.append(_print_format, max - min);
+  if (_print_sum) {
+    // for things like the start and end times the sum is not
+    // that relevant
+    buf.append(", Sum: ");
+    buf.append(_print_format, sum);
+  }
+  buf.append_and_print_cr("]");
+}
+
+#ifdef ASSERT
+
+template <class T>
+void WorkerDataArray<T>::reset() {
+  for (uint i = 0; i < _length; i++) {
+    _data[i] = (T)-1;
+  }
+}
+
+template <class T>
+void WorkerDataArray<T>::verify() {
+  for (uint i = 0; i < _length; i++) {
+    assert(_data[i] >= (T)0, err_msg("Invalid data for worker %d", i));
+  }
+}
+
+#endif
+
 G1GCPhaseTimes::G1GCPhaseTimes(uint max_gc_threads) :
   _max_gc_threads(max_gc_threads),
   _min_clear_cc_time_ms(-1.0),
   _max_clear_cc_time_ms(-1.0),
   _cur_clear_cc_time_ms(0.0),
   _cum_clear_cc_time_ms(0.0),
-  _num_cc_clears(0L)
+  _num_cc_clears(0L),
+  _last_gc_worker_start_times_ms(_max_gc_threads, "%.1lf", false),
+  _last_ext_root_scan_times_ms(_max_gc_threads, "%.1lf"),
+  _last_satb_filtering_times_ms(_max_gc_threads, "%.1lf"),
+  _last_update_rs_times_ms(_max_gc_threads, "%.1lf"),
+  _last_update_rs_processed_buffers(_max_gc_threads, "%d"),
+  _last_scan_rs_times_ms(_max_gc_threads, "%.1lf"),
+  _last_obj_copy_times_ms(_max_gc_threads, "%.1lf"),
+  _last_termination_times_ms(_max_gc_threads, "%.1lf"),
+  _last_termination_attempts(_max_gc_threads, SIZE_FORMAT),
+  _last_gc_worker_end_times_ms(_max_gc_threads, "%.1lf", false),
+  _last_gc_worker_times_ms(_max_gc_threads, "%.1lf"),
+  _last_gc_worker_other_times_ms(_max_gc_threads, "%.1lf")
 {
   assert(max_gc_threads > 0, "Must have some GC threads");
-  _par_last_gc_worker_start_times_ms = new double[_max_gc_threads];
-  _par_last_ext_root_scan_times_ms = new double[_max_gc_threads];
-  _par_last_satb_filtering_times_ms = new double[_max_gc_threads];
-  _par_last_update_rs_times_ms = new double[_max_gc_threads];
-  _par_last_update_rs_processed_buffers = new double[_max_gc_threads];
-  _par_last_scan_rs_times_ms = new double[_max_gc_threads];
-  _par_last_obj_copy_times_ms = new double[_max_gc_threads];
-  _par_last_termination_times_ms = new double[_max_gc_threads];
-  _par_last_termination_attempts = new double[_max_gc_threads];
-  _par_last_gc_worker_end_times_ms = new double[_max_gc_threads];
-  _par_last_gc_worker_times_ms = new double[_max_gc_threads];
-  _par_last_gc_worker_other_times_ms = new double[_max_gc_threads];
 }
 
-void G1GCPhaseTimes::note_gc_start(double pause_start_time_sec, uint active_gc_threads,
-  bool is_young_gc, bool is_initial_mark_gc, GCCause::Cause gc_cause) {
+void G1GCPhaseTimes::note_gc_start(uint active_gc_threads) {
   assert(active_gc_threads > 0, "The number of threads must be > 0");
   assert(active_gc_threads <= _max_gc_threads, "The number of active threads must be <= the max nubmer of threads");
   _active_gc_threads = active_gc_threads;
-  _pause_start_time_sec = pause_start_time_sec;
-  _is_young_gc = is_young_gc;
-  _is_initial_mark_gc = is_initial_mark_gc;
-  _gc_cause = gc_cause;
 
-#ifdef ASSERT
-  // initialise the timing data to something well known so that we can spot
-  // if something is not set properly
-
-  for (uint i = 0; i < _max_gc_threads; ++i) {
-    _par_last_gc_worker_start_times_ms[i] = -1234.0;
-    _par_last_ext_root_scan_times_ms[i] = -1234.0;
-    _par_last_satb_filtering_times_ms[i] = -1234.0;
-    _par_last_update_rs_times_ms[i] = -1234.0;
-    _par_last_update_rs_processed_buffers[i] = -1234.0;
-    _par_last_scan_rs_times_ms[i] = -1234.0;
-    _par_last_obj_copy_times_ms[i] = -1234.0;
-    _par_last_termination_times_ms[i] = -1234.0;
-    _par_last_termination_attempts[i] = -1234.0;
-    _par_last_gc_worker_end_times_ms[i] = -1234.0;
-    _par_last_gc_worker_times_ms[i] = -1234.0;
-    _par_last_gc_worker_other_times_ms[i] = -1234.0;
-  }
-#endif
+  _last_gc_worker_start_times_ms.reset();
+  _last_ext_root_scan_times_ms.reset();
+  _last_satb_filtering_times_ms.reset();
+  _last_update_rs_times_ms.reset();
+  _last_update_rs_processed_buffers.reset();
+  _last_scan_rs_times_ms.reset();
+  _last_obj_copy_times_ms.reset();
+  _last_termination_times_ms.reset();
+  _last_termination_attempts.reset();
+  _last_gc_worker_end_times_ms.reset();
+  _last_gc_worker_times_ms.reset();
+  _last_gc_worker_other_times_ms.reset();
 }
 
-void G1GCPhaseTimes::note_gc_end(double pause_end_time_sec) {
-  if (G1Log::fine()) {
-    double pause_time_ms = (pause_end_time_sec - _pause_start_time_sec) * MILLIUNITS;
+void G1GCPhaseTimes::note_gc_end() {
+  _last_gc_worker_start_times_ms.verify();
+  _last_ext_root_scan_times_ms.verify();
+  _last_satb_filtering_times_ms.verify();
+  _last_update_rs_times_ms.verify();
+  _last_update_rs_processed_buffers.verify();
+  _last_scan_rs_times_ms.verify();
+  _last_obj_copy_times_ms.verify();
+  _last_termination_times_ms.verify();
+  _last_termination_attempts.verify();
+  _last_gc_worker_end_times_ms.verify();
 
     for (uint i = 0; i < _active_gc_threads; i++) {
-      _par_last_gc_worker_times_ms[i] = _par_last_gc_worker_end_times_ms[i] -
-        _par_last_gc_worker_start_times_ms[i];
+      double worker_time = _last_gc_worker_end_times_ms.get(i) - _last_gc_worker_start_times_ms.get(i);
+      _last_gc_worker_times_ms.set(i, worker_time);
 
-      double worker_known_time = _par_last_ext_root_scan_times_ms[i] +
-        _par_last_satb_filtering_times_ms[i] +
-        _par_last_update_rs_times_ms[i] +
-        _par_last_scan_rs_times_ms[i] +
-        _par_last_obj_copy_times_ms[i] +
-        _par_last_termination_times_ms[i];
+      double worker_known_time = _last_ext_root_scan_times_ms.get(i) +
+        _last_satb_filtering_times_ms.get(i) +
+        _last_update_rs_times_ms.get(i) +
+        _last_scan_rs_times_ms.get(i) +
+        _last_obj_copy_times_ms.get(i) +
+        _last_termination_times_ms.get(i);
 
-      _par_last_gc_worker_other_times_ms[i] = _par_last_gc_worker_times_ms[i] -
-        worker_known_time;
+      double worker_other_time = worker_time - worker_known_time;
+      _last_gc_worker_other_times_ms.set(i, worker_other_time);
     }
 
-    print(pause_time_ms);
-  }
-
-}
-
-void G1GCPhaseTimes::print_par_stats(int level,
-                                        const char* str,
-                                        double* data,
-                                        bool showDecimals) {
-  double min = data[0], max = data[0];
-  double total = 0.0;
-  LineBuffer buf(level);
-  buf.append("[%s (ms):", str);
-  for (uint i = 0; i < _active_gc_threads; ++i) {
-    double val = data[i];
-    if (val < min)
-      min = val;
-    if (val > max)
-      max = val;
-    total += val;
-    if (G1Log::finest()) {
-      if (showDecimals) {
-        buf.append("  %.1lf", val);
-      } else {
-        buf.append("  %d", (int)val);
-      }
-    }
-  }
-
-  if (G1Log::finest()) {
-    buf.append_and_print_cr("");
-  }
-  double avg = total / (double) _active_gc_threads;
-  if (showDecimals) {
-    buf.append_and_print_cr(" Min: %.1lf, Avg: %.1lf, Max: %.1lf, Diff: %.1lf, Sum: %.1lf]",
-      min, avg, max, max - min, total);
-  } else {
-    buf.append_and_print_cr(" Min: %d, Avg: %d, Max: %d, Diff: %d, Sum: %d]",
-      (int)min, (int)avg, (int)max, (int)max - (int)min, (int)total);
-  }
+  _last_gc_worker_times_ms.verify();
+  _last_gc_worker_other_times_ms.verify();
 }
 
 void G1GCPhaseTimes::print_stats(int level, const char* str, double value) {
@@ -202,73 +228,6 @@
   LineBuffer(level).append_and_print_cr("[%s: %.1lf ms, GC Workers: %d]", str, value, workers);
 }
 
-void G1GCPhaseTimes::print_stats(int level, const char* str, int value) {
-  LineBuffer(level).append_and_print_cr("[%s: %d]", str, value);
-}
-
-double G1GCPhaseTimes::avg_value(double* data) {
-  if (G1CollectedHeap::use_parallel_gc_threads()) {
-    double ret = 0.0;
-    for (uint i = 0; i < _active_gc_threads; ++i) {
-      ret += data[i];
-    }
-    return ret / (double) _active_gc_threads;
-  } else {
-    return data[0];
-  }
-}
-
-double G1GCPhaseTimes::max_value(double* data) {
-  if (G1CollectedHeap::use_parallel_gc_threads()) {
-    double ret = data[0];
-    for (uint i = 1; i < _active_gc_threads; ++i) {
-      if (data[i] > ret) {
-        ret = data[i];
-      }
-    }
-    return ret;
-  } else {
-    return data[0];
-  }
-}
-
-double G1GCPhaseTimes::sum_of_values(double* data) {
-  if (G1CollectedHeap::use_parallel_gc_threads()) {
-    double sum = 0.0;
-    for (uint i = 0; i < _active_gc_threads; i++) {
-      sum += data[i];
-    }
-    return sum;
-  } else {
-    return data[0];
-  }
-}
-
-double G1GCPhaseTimes::max_sum(double* data1, double* data2) {
-  double ret = data1[0] + data2[0];
-
-  if (G1CollectedHeap::use_parallel_gc_threads()) {
-    for (uint i = 1; i < _active_gc_threads; ++i) {
-      double data = data1[i] + data2[i];
-      if (data > ret) {
-        ret = data;
-      }
-    }
-  }
-  return ret;
-}
-
-void G1GCPhaseTimes::collapse_par_times() {
-    _ext_root_scan_time = avg_value(_par_last_ext_root_scan_times_ms);
-    _satb_filtering_time = avg_value(_par_last_satb_filtering_times_ms);
-    _update_rs_time = avg_value(_par_last_update_rs_times_ms);
-    _update_rs_processed_buffers =
-      sum_of_values(_par_last_update_rs_processed_buffers);
-    _scan_rs_time = avg_value(_par_last_scan_rs_times_ms);
-    _obj_copy_time = avg_value(_par_last_obj_copy_times_ms);
-    _termination_time = avg_value(_par_last_termination_times_ms);
-}
-
 double G1GCPhaseTimes::accounted_time_ms() {
     // Subtract the root region scanning wait time. It's initialized to
     // zero at the start of the pause.
@@ -286,58 +245,37 @@
     return misc_time_ms;
 }
 
-void G1GCPhaseTimes::print(double pause_time_ms) {
-
-  if (PrintGCTimeStamps) {
-    gclog_or_tty->stamp();
-    gclog_or_tty->print(": ");
-  }
-
-  GCCauseString gc_cause_str = GCCauseString("GC pause", _gc_cause)
-    .append(_is_young_gc ? " (young)" : " (mixed)")
-    .append(_is_initial_mark_gc ? " (initial-mark)" : "");
-  gclog_or_tty->print_cr("[%s, %3.7f secs]", (const char*)gc_cause_str, pause_time_ms / 1000.0);
-
-  if (!G1Log::finer()) {
-    return;
-  }
-
+void G1GCPhaseTimes::print(double pause_time_sec) {
   if (_root_region_scan_wait_time_ms > 0.0) {
     print_stats(1, "Root Region Scan Waiting", _root_region_scan_wait_time_ms);
   }
   if (G1CollectedHeap::use_parallel_gc_threads()) {
     print_stats(1, "Parallel Time", _cur_collection_par_time_ms, _active_gc_threads);
-    print_par_stats(2, "GC Worker Start", _par_last_gc_worker_start_times_ms);
-    print_par_stats(2, "Ext Root Scanning", _par_last_ext_root_scan_times_ms);
-    if (_satb_filtering_time > 0.0) {
-      print_par_stats(2, "SATB Filtering", _par_last_satb_filtering_times_ms);
+    _last_gc_worker_start_times_ms.print(2, "GC Worker Start (ms)");
+    _last_ext_root_scan_times_ms.print(2, "Ext Root Scanning (ms)");
+    if (_last_satb_filtering_times_ms.sum() > 0.0) {
+      _last_satb_filtering_times_ms.print(2, "SATB Filtering (ms)");
     }
-    print_par_stats(2, "Update RS", _par_last_update_rs_times_ms);
-    if (G1Log::finest()) {
-      print_par_stats(3, "Processed Buffers", _par_last_update_rs_processed_buffers,
-        false /* showDecimals */);
-    }
-    print_par_stats(2, "Scan RS", _par_last_scan_rs_times_ms);
-    print_par_stats(2, "Object Copy", _par_last_obj_copy_times_ms);
-    print_par_stats(2, "Termination", _par_last_termination_times_ms);
+    _last_update_rs_times_ms.print(2, "Update RS (ms)");
+      _last_update_rs_processed_buffers.print(3, "Processed Buffers");
+    _last_scan_rs_times_ms.print(2, "Scan RS (ms)");
+    _last_obj_copy_times_ms.print(2, "Object Copy (ms)");
+    _last_termination_times_ms.print(2, "Termination (ms)");
     if (G1Log::finest()) {
-      print_par_stats(3, "Termination Attempts", _par_last_termination_attempts,
-        false /* showDecimals */);
+      _last_termination_attempts.print(3, "Termination Attempts");
     }
-    print_par_stats(2, "GC Worker Other", _par_last_gc_worker_other_times_ms);
-    print_par_stats(2, "GC Worker Total", _par_last_gc_worker_times_ms);
-    print_par_stats(2, "GC Worker End", _par_last_gc_worker_end_times_ms);
+    _last_gc_worker_other_times_ms.print(2, "GC Worker Other (ms)");
+    _last_gc_worker_times_ms.print(2, "GC Worker Total (ms)");
+    _last_gc_worker_end_times_ms.print(2, "GC Worker End (ms)");
   } else {
-    print_stats(1, "Ext Root Scanning", _ext_root_scan_time);
-    if (_satb_filtering_time > 0.0) {
-      print_stats(1, "SATB Filtering", _satb_filtering_time);
+    _last_ext_root_scan_times_ms.print(1, "Ext Root Scanning (ms)");
+    if (_last_satb_filtering_times_ms.sum() > 0.0) {
+      _last_satb_filtering_times_ms.print(1, "SATB Filtering (ms)");
     }
-    print_stats(1, "Update RS", _update_rs_time);
-    if (G1Log::finest()) {
-      print_stats(2, "Processed Buffers", (int)_update_rs_processed_buffers);
-    }
-    print_stats(1, "Scan RS", _scan_rs_time);
-    print_stats(1, "Object Copying", _obj_copy_time);
+    _last_update_rs_times_ms.print(1, "Update RS (ms)");
+      _last_update_rs_processed_buffers.print(2, "Processed Buffers");
+    _last_scan_rs_times_ms.print(1, "Scan RS (ms)");
+    _last_obj_copy_times_ms.print(1, "Object Copy (ms)");
   }
   print_stats(1, "Code Root Fixup", _cur_collection_code_root_fixup_time_ms);
   print_stats(1, "Clear CT", _cur_clear_ct_time_ms);
@@ -350,8 +288,11 @@
       print_stats(1, "Avg Clear CC", _cum_clear_cc_time_ms / ((double)_num_cc_clears));
     }
   }
-  double misc_time_ms = pause_time_ms - accounted_time_ms();
+  double misc_time_ms = pause_time_sec * MILLIUNITS - accounted_time_ms();
   print_stats(1, "Other", misc_time_ms);
+  if (_cur_verify_before_time_ms > 0.0) {
+    print_stats(2, "Verify Before", _cur_verify_before_time_ms);
+  }
   print_stats(2, "Choose CSet",
     (_recorded_young_cset_choice_time_ms +
     _recorded_non_young_cset_choice_time_ms));
@@ -360,6 +301,9 @@
   print_stats(2, "Free CSet",
     (_recorded_young_free_cset_time_ms +
     _recorded_non_young_free_cset_time_ms));
+  if (_cur_verify_after_time_ms > 0.0) {
+    print_stats(2, "Verify After", _cur_verify_after_time_ms);
+  }
 }
 
 void G1GCPhaseTimes::record_cc_clear_time_ms(double ms) {
diff -r 153776c4cb6f -r bb3f6194fedb src/share/vm/gc_implementation/g1/g1GCPhaseTimes.hpp
--- a/src/share/vm/gc_implementation/g1/g1GCPhaseTimes.hpp	Fri Aug 24 16:23:59 2012 -0700
+++ b/src/share/vm/gc_implementation/g1/g1GCPhaseTimes.hpp	Thu Aug 23 10:21:12 2012 +0200
@@ -28,52 +28,109 @@
 #include "memory/allocation.hpp"
 #include "gc_interface/gcCause.hpp"
 
+template <class T>
+class WorkerDataArray  : public CHeapObj<mtGC> {
+  T*          _data;
+  uint        _length;
+  const char* _print_format;
+  bool        _print_sum;
+
+  // We are caching the sum and average to only have to calculate them once.
+  // This is not done in an MT-safe way. It is intetened to allow single
+  // threaded code to call sum() and average() multiple times in any order
+  // without having to worry about the cost.
+  bool   _has_new_data;
+  T      _sum;
+  double _average;
+
+ public:
+  WorkerDataArray(uint length, const char* print_format, bool print_sum = true) :
+  _length(length), _print_format(print_format), _print_sum(print_sum), _has_new_data(true) {
+    assert(length > 0, "Must have some workers to store data for");
+    _data = NEW_C_HEAP_ARRAY(T, _length, mtGC);
+  }
+
+  ~WorkerDataArray() {
+    FREE_C_HEAP_ARRAY(T, _data, mtGC);
+  }
+
+  void set(uint worker_i, T value) {
+    assert(worker_i < _length, err_msg("Worker %d is greater than max: %d", worker_i, _length));
+    assert(_data[worker_i] == (T)-1, err_msg("Overwriting data for worker %d", worker_i));
+    _data[worker_i] = value;
+    _has_new_data = true;
+  }
+
+  T get(uint worker_i) {
+    assert(worker_i < _length, err_msg("Worker %d is greater than max: %d", worker_i, _length));
+    assert(_data[worker_i] != (T)-1, err_msg("No data to add to for worker %d", worker_i));
+    return _data[worker_i];
+  }
+
+  void add(uint worker_i, T value) {
+    assert(worker_i < _length, err_msg("Worker %d is greater than max: %d", worker_i, _length));
+    assert(_data[worker_i] != (T)-1, err_msg("No data to add to for worker %d", worker_i));
+    _data[worker_i] += value;
+    _has_new_data = true;
+  }
+
+  double average(){
+    if (_has_new_data) {
+      calculate_totals();
+    }
+    return _average;
+  }
+
+  T sum() {
+    if (_has_new_data) {
+      calculate_totals();
+    }
+    return _sum;
+  }
+
+  void print(int level, const char* title);
+
+  void reset() PRODUCT_RETURN;
+  void verify() PRODUCT_RETURN;
+
+ private:
+
+  void calculate_totals(){
+    _sum = (T)0;
+    for (uint i = 0; i < _length; ++i) {
+      _sum += _data[i];
+    }
+    _average = (double)_sum / (double)_length;
+    _has_new_data = false;
+  }
+};
+
 class G1GCPhaseTimes : public CHeapObj<mtGC> {
-  friend class G1CollectorPolicy;
-  friend class TraceGen0TimeData;
 
  private:
   uint _active_gc_threads;
   uint _max_gc_threads;
 
-  GCCause::Cause _gc_cause;
-  bool           _is_young_gc;
-  bool           _is_initial_mark_gc;
-
-  double _pause_start_time_sec;
-
-  double* _par_last_gc_worker_start_times_ms;
-  double* _par_last_ext_root_scan_times_ms;
-  double* _par_last_satb_filtering_times_ms;
-  double* _par_last_update_rs_times_ms;
-  double* _par_last_update_rs_processed_buffers;
-  double* _par_last_scan_rs_times_ms;
-  double* _par_last_obj_copy_times_ms;
-  double* _par_last_termination_times_ms;
-  double* _par_last_termination_attempts;
-  double* _par_last_gc_worker_end_times_ms;
-  double* _par_last_gc_worker_times_ms;
-  double* _par_last_gc_worker_other_times_ms;
+  WorkerDataArray<double> _last_gc_worker_start_times_ms;
+  WorkerDataArray<double> _last_ext_root_scan_times_ms;
+  WorkerDataArray<double> _last_satb_filtering_times_ms;
+  WorkerDataArray<double> _last_update_rs_times_ms;
+  WorkerDataArray<int>    _last_update_rs_processed_buffers;
+  WorkerDataArray<double> _last_scan_rs_times_ms;
+  WorkerDataArray<double> _last_obj_copy_times_ms;
+  WorkerDataArray<double> _last_termination_times_ms;
+  WorkerDataArray<size_t> _last_termination_attempts;
+  WorkerDataArray<double> _last_gc_worker_end_times_ms;
+  WorkerDataArray<double> _last_gc_worker_times_ms;
+  WorkerDataArray<double> _last_gc_worker_other_times_ms;
 
   double _cur_collection_par_time_ms;
-
   double _cur_collection_code_root_fixup_time_ms;
 
   double _cur_clear_ct_time_ms;
   double _cur_ref_proc_time_ms;
   double _cur_ref_enq_time_ms;
 
-  // Helper methods for detailed logging
-  void print_par_stats(int level, const char* str, double* data, bool showDecimals = true);
-  void print_stats(int level, const char* str, double value);
-  void print_stats(int level, const char* str, double value, int workers);
-  void print_stats(int level, const char* str, int value);
-  double avg_value(double* data);
-  double max_value(double* data);
-  double sum_of_values(double* data);
-  double max_sum(double* data1, double* data2);
-  double accounted_time_ms();
-
   // Card Table Count Cache stats
   double _min_clear_cc_time_ms;         // min
   double _max_clear_cc_time_ms;         // max
@@ -81,19 +138,6 @@
   double _cum_clear_cc_time_ms;         // cummulative clearing time
   jlong  _num_cc_clears;                // number of times the card count cache has been cleared
 
-  // The following insance variables are directly accessed by G1CollectorPolicy
-  // and TraceGen0TimeData. This is why those classes are declared friends.
-  // An alternative is to add getters and setters for all of these fields.
-  // It might also be possible to restructure the code to reduce these
-  // dependencies.
-  double _ext_root_scan_time;
-  double _satb_filtering_time;
-  double _update_rs_time;
-  double _update_rs_processed_buffers;
-  double _scan_rs_time;
-  double _obj_copy_time;
-  double _termination_time;
-
   double _cur_collection_start_sec;
   double _root_region_scan_wait_time_ms;
 
@@ -103,79 +147,58 @@
   double _recorded_young_free_cset_time_ms;
   double _recorded_non_young_free_cset_time_ms;
 
-  void print(double pause_time_ms);
+  double _cur_verify_before_time_ms;
+  double _cur_verify_after_time_ms;
+
+  // Helper methods for detailed logging
+  void print_stats(int level, const char* str, double value);
+  void print_stats(int level, const char* str, double value, int workers);
 
  public:
   G1GCPhaseTimes(uint max_gc_threads);
-  void note_gc_start(double pause_start_time_sec, uint active_gc_threads,
-    bool is_young_gc, bool is_initial_mark_gc, GCCause::Cause gc_cause);
-  void note_gc_end(double pause_end_time_sec);
-  void collapse_par_times();
+  void note_gc_start(uint active_gc_threads);
+  void note_gc_end();
+  void print(double pause_time_sec);
 
   void record_gc_worker_start_time(uint worker_i, double ms) {
-    assert(worker_i >= 0, "worker index must be > 0");
-    assert(worker_i < _active_gc_threads, "worker index out of bounds");
-    _par_last_gc_worker_start_times_ms[worker_i] = ms;
+    _last_gc_worker_start_times_ms.set(worker_i, ms);
   }
 
   void record_ext_root_scan_time(uint worker_i, double ms) {
-    assert(worker_i >= 0, "worker index must be > 0");
-    assert(worker_i < _active_gc_threads, "worker index out of bounds");
-    _par_last_ext_root_scan_times_ms[worker_i] = ms;
+    _last_ext_root_scan_times_ms.set(worker_i, ms);
   }
 
   void record_satb_filtering_time(uint worker_i, double ms) {
-    assert(worker_i >= 0, "worker index must be > 0");
-    assert(worker_i < _active_gc_threads, "worker index out of bounds");
-    _par_last_satb_filtering_times_ms[worker_i] = ms;
+    _last_satb_filtering_times_ms.set(worker_i, ms);
   }
 
   void record_update_rs_time(uint worker_i, double ms) {
-    assert(worker_i >= 0, "worker index must be > 0");
-    assert(worker_i < _active_gc_threads, "worker index out of bounds");
-    _par_last_update_rs_times_ms[worker_i] = ms;
+    _last_update_rs_times_ms.set(worker_i, ms);
   }
 
-  void record_update_rs_processed_buffers (uint worker_i,
-                                           double processed_buffers) {
-    assert(worker_i >= 0, "worker index must be > 0");
-    assert(worker_i < _active_gc_threads, "worker index out of bounds");
-    _par_last_update_rs_processed_buffers[worker_i] = processed_buffers;
+  void record_update_rs_processed_buffers(uint worker_i, int processed_buffers) {
+    _last_update_rs_processed_buffers.set(worker_i, processed_buffers);
   }
 
   void record_scan_rs_time(uint worker_i, double ms) {
-    assert(worker_i >= 0, "worker index must be > 0");
-    assert(worker_i < _active_gc_threads, "worker index out of bounds");
-    _par_last_scan_rs_times_ms[worker_i] = ms;
-  }
-
-  void reset_obj_copy_time(uint worker_i) {
-    assert(worker_i >= 0, "worker index must be > 0");
-    assert(worker_i < _active_gc_threads, "worker index out of bounds");
-    _par_last_obj_copy_times_ms[worker_i] = 0.0;
-  }
-
-  void reset_obj_copy_time() {
-    reset_obj_copy_time(0);
+    _last_scan_rs_times_ms.set(worker_i, ms);
   }
 
   void record_obj_copy_time(uint worker_i, double ms) {
-    assert(worker_i >= 0, "worker index must be > 0");
-    assert(worker_i < _active_gc_threads, "worker index out of bounds");
-    _par_last_obj_copy_times_ms[worker_i] += ms;
+    _last_obj_copy_times_ms.set(worker_i, ms);
+  }
+
+  void add_obj_copy_time(uint worker_i, double ms) {
+    _last_obj_copy_times_ms.add(worker_i, ms);
   }
 
   void record_termination(uint worker_i, double ms, size_t attempts) {
-    assert(worker_i >= 0, "worker index must be > 0");
-    assert(worker_i < _active_gc_threads, "worker index out of bounds");
-    _par_last_termination_times_ms[worker_i] = ms;
-    _par_last_termination_attempts[worker_i] = (double) attempts;
+    _last_termination_times_ms.set(worker_i, ms);
+    _last_termination_attempts.set(worker_i, attempts);
   }
 
   void record_gc_worker_end_time(uint worker_i, double ms) {
-    assert(worker_i >= 0, "worker index must be > 0");
-    assert(worker_i < _active_gc_threads, "worker index out of bounds");
-    _par_last_gc_worker_end_times_ms[worker_i] = ms;
+    _last_gc_worker_end_times_ms.set(worker_i, ms);
   }
 
   void record_clear_ct_time(double ms) {
@@ -211,6 +234,88 @@
   void record_non_young_free_cset_time_ms(double time_ms) {
     _recorded_non_young_free_cset_time_ms = time_ms;
   }
+
+  void record_young_cset_choice_time_ms(double time_ms) {
+    _recorded_young_cset_choice_time_ms = time_ms;
+  }
+
+  void record_non_young_cset_choice_time_ms(double time_ms) {
+    _recorded_non_young_cset_choice_time_ms = time_ms;
+  }
+
+  void record_cur_collection_start_sec(double time_ms) {
+    _cur_collection_start_sec = time_ms;
+  }
+
+  void record_verify_before_time_ms(double time_ms) {
+    _cur_verify_before_time_ms = time_ms;
+  }
+
+  void record_verify_after_time_ms(double time_ms) {
+    _cur_verify_after_time_ms = time_ms;
+  }
+
+  double accounted_time_ms();
+
+  double cur_collection_start_sec() {
+    return _cur_collection_start_sec;
+  }
+
+  double cur_collection_par_time_ms() {
+    return _cur_collection_par_time_ms;
+  }
+
+  double cur_clear_ct_time_ms() {
+    return _cur_clear_ct_time_ms;
+  }
+
+  double root_region_scan_wait_time_ms() {
+    return _root_region_scan_wait_time_ms;
+  }
+
+  double young_cset_choice_time_ms() {
+    return _recorded_young_cset_choice_time_ms;
+  }
+
+  double young_free_cset_time_ms() {
+    return _recorded_young_free_cset_time_ms;
+  }
+
+  double non_young_cset_choice_time_ms() {
+    return _recorded_non_young_cset_choice_time_ms;
+  }
+
+  double non_young_free_cset_time_ms() {
+    return _recorded_non_young_free_cset_time_ms;
+  }
+
+  double average_last_update_rs_time() {
+    return _last_update_rs_times_ms.average();
+  }
+
+  int sum_last_update_rs_processed_buffers() {
+    return _last_update_rs_processed_buffers.sum();
+  }
+
+  double average_last_scan_rs_time(){
+    return _last_scan_rs_times_ms.average();
+  }
+
+  double average_last_obj_copy_time() {
+    return _last_obj_copy_times_ms.average();
+  }
+
+  double average_last_termination_time() {
+    return _last_termination_times_ms.average();
+  }
+
+  double average_last_ext_root_scan_time() {
+    return _last_ext_root_scan_times_ms.average();
+  }
+
+  double average_last_satb_filtering_times_ms() {
+    return _last_satb_filtering_times_ms.average();
+  }
 };
 
 #endif // SHARE_VM_GC_IMPLEMENTATION_G1_G1GCPHASETIMESLOG_HPP
diff -r 153776c4cb6f -r bb3f6194fedb src/share/vm/gc_implementation/g1/g1RemSet.cpp
--- a/src/share/vm/gc_implementation/g1/g1RemSet.cpp	Fri Aug 24 16:23:59 2012 -0700
+++ b/src/share/vm/gc_implementation/g1/g1RemSet.cpp	Thu Aug 23 10:21:12 2012 +0200
@@ -324,7 +324,7 @@
   if (G1UseParallelRSetUpdating || (worker_i == 0)) {
     updateRS(&into_cset_dcq, worker_i);
   } else {
-    _g1p->phase_times()->record_update_rs_processed_buffers(worker_i, 0.0);
+    _g1p->phase_times()->record_update_rs_processed_buffers(worker_i, 0);
     _g1p->phase_times()->record_update_rs_time(worker_i, 0.0);
   }
   if (G1UseParallelRSetScanning || (worker_i == 0)) {
diff -r 153776c4cb6f -r bb3f6194fedb src/share/vm/runtime/arguments.cpp
--- a/src/share/vm/runtime/arguments.cpp	Fri Aug 24 16:23:59 2012 -0700
+++ b/src/share/vm/runtime/arguments.cpp	Thu Aug 23 10:21:12 2012 +0200
@@ -1916,7 +1916,7 @@
       (ExplicitGCInvokesConcurrent ||
        ExplicitGCInvokesConcurrentAndUnloadsClasses)) {
     jio_fprintf(defaultStream::error_stream(),
-                "error: +ExplictGCInvokesConcurrent[AndUnloadsClasses] conflicts"
+                "error: +ExplicitGCInvokesConcurrent[AndUnloadsClasses] conflicts"
                 " with -UseAsyncConcMarkSweepGC");
     status = false;
   }