src/share/vm/gc/g1/g1GCPhaseTimes.cpp

rev 13328 : [mq]: webrev.0b
rev 13330 : imported patch webrev.2
rev 13331 : imported patch webrev.3b
rev 13332 : [mq]: webrev.4

@@ -35,14 +35,15 @@
 #include "runtime/os.hpp"
 #include "utilities/macros.hpp"
 
 static const char* Indents[5] = {"", "  ", "    ", "      ", "        "};
 
-G1GCPhaseTimes::G1GCPhaseTimes(uint max_gc_threads) :
+G1GCPhaseTimes::G1GCPhaseTimes(STWGCTimer* gc_timer, uint max_gc_threads) :
   _max_gc_threads(max_gc_threads),
   _gc_start_counter(0),
-  _gc_pause_time_ms(0.0)
+  _gc_pause_time_ms(0.0),
+  _ref_phase_times((GCTimer*)gc_timer, max_gc_threads)
 {
   assert(max_gc_threads > 0, "Must have some GC threads");
 
   _gc_par_phases[GCWorkerStart] = new WorkerDataArray<double>(max_gc_threads, "GC Worker Start (ms):");
   _gc_par_phases[ExtRootScan] = new WorkerDataArray<double>(max_gc_threads, "Ext Root Scanning (ms):");

@@ -150,10 +151,12 @@
   for (int i = 0; i < GCParPhasesSentinel; i++) {
     if (_gc_par_phases[i] != NULL) {
       _gc_par_phases[i]->reset();
     }
   }
+
+  _ref_phase_times.reset();
 }
 
 void G1GCPhaseTimes::note_gc_start() {
   _gc_start_counter = os::elapsed_counter();
   reset();

@@ -283,17 +286,19 @@
 void G1GCPhaseTimes::debug_time(const char* name, double value) const {
   log_debug(gc, phases)("%s%s: " TIME_FORMAT, Indents[2], name, value);
 }
 
 void G1GCPhaseTimes::debug_time_for_reference(const char* name, double value) const {
-  Log(gc, phases) log;
-  Log(gc, phases, ref) log2;
-  if ((log.is_level(LogLevel::Debug) && !log2.is_level(LogLevel::Debug)) ||
-      (log.is_level(LogLevel::Debug) && log2.is_level(LogLevel::Debug))) {
-    log.debug_stream()->print_cr("%s%s: " TIME_FORMAT, Indents[2], name, value);
-  } else if (!log.is_level(LogLevel::Debug) && log2.is_level(LogLevel::Debug)) {
-    log2.debug_stream()->print_cr("%s%s: " TIME_FORMAT, Indents[2], name, value);
+  LogTarget(Debug, gc, phases) lt;
+  LogTarget(Debug, gc, phases, ref) lt2;
+
+  if (lt.is_enabled()) {
+    LogStream ls(lt);
+    ls.print_cr("%s%s: " TIME_FORMAT, Indents[2], name, value);
+  } else if (lt2.is_enabled()) {
+    LogStream ls(lt2);
+    ls.print_cr("%s%s: " TIME_FORMAT, Indents[2], name, value);
   }
 }
 
 void G1GCPhaseTimes::trace_time(const char* name, double value) const {
   log_trace(gc, phases)("%s%s: " TIME_FORMAT, Indents[3], name, value);

@@ -380,11 +385,11 @@
 
   debug_time("Preserve CM Refs", _recorded_preserve_cm_referents_time_ms);
   trace_phase(_gc_par_phases[PreserveCMReferents]);
 
   debug_time_for_reference("Reference Processing", _cur_ref_proc_time_ms);
-  G1CollectedHeap::heap()->ref_phase_times()->print_all_references(2, false);
+  _ref_phase_times.print_all_references(2, false);
 
   if (G1StringDedup::is_enabled()) {
     debug_time("String Dedup Fixup", _cur_string_dedup_fixup_time_ms);
     debug_phase(_gc_par_phases[StringDedupQueueFixup]);
     debug_phase(_gc_par_phases[StringDedupTableFixup]);

@@ -397,11 +402,11 @@
     trace_time("Recalculate Used", _cur_evac_fail_recalc_used);
     trace_time("Remove Self Forwards",_cur_evac_fail_remove_self_forwards);
   }
 
   debug_time_for_reference("Reference Enqueuing", _cur_ref_enq_time_ms);
-  G1CollectedHeap::heap()->ref_phase_times()->print_enqueue_phase(2, false);
+  _ref_phase_times.print_enqueue_phase(2, false);
 
   debug_time("Merge Per-Thread State", _recorded_merge_pss_time_ms);
   debug_time("Code Roots Purge", _cur_strong_code_root_purge_time_ms);
 
   debug_time("Redirty Cards", _recorded_redirty_logged_cards_time_ms);