hotspot/src/share/vm/gc/g1/g1GCPhaseTimes.cpp
changeset 37214 bc4e0e0995e6
parent 37209 c2920cd096aa
child 37242 91e5f98fff6f
--- a/hotspot/src/share/vm/gc/g1/g1GCPhaseTimes.cpp	Thu Mar 31 11:21:20 2016 +0000
+++ b/hotspot/src/share/vm/gc/g1/g1GCPhaseTimes.cpp	Thu Mar 31 17:05:29 2016 +0200
@@ -33,7 +33,7 @@
 #include "runtime/timer.hpp"
 #include "runtime/os.hpp"
 
-static const char* Indents[5] = {"", "  ", "    ", "     ", "       "};
+static const char* Indents[5] = {"", "  ", "    ", "      ", "        "};
 
 G1GCPhaseTimes::G1GCPhaseTimes(uint max_gc_threads) :
   _max_gc_threads(max_gc_threads)
@@ -94,11 +94,8 @@
   _gc_par_phases[PreserveCMReferents] = new WorkerDataArray<double>(max_gc_threads, "Parallel Preserve CM Refs (ms):");
 }
 
-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 number of threads");
+void G1GCPhaseTimes::note_gc_start() {
   _gc_start_counter = os::elapsed_counter();
-  _active_gc_threads = active_gc_threads;
   _cur_expand_heap_time_ms = 0.0;
   _external_accounted_time_ms = 0.0;
 
@@ -109,31 +106,55 @@
   }
 }
 
+#define ASSERT_PHASE_UNINITIALIZED(phase) \
+    assert(_gc_par_phases[phase]->get(i) == uninitialized, "Phase " #phase " reported for thread that was not started");
+
+double G1GCPhaseTimes::worker_time(GCParPhases phase, uint worker) {
+  double value = _gc_par_phases[phase]->get(worker);
+  if (value != WorkerDataArray<double>::uninitialized()) {
+    return value;
+  }
+  return 0.0;
+}
+
 void G1GCPhaseTimes::note_gc_end() {
   _gc_pause_time_ms = TimeHelper::counter_to_millis(os::elapsed_counter() - _gc_start_counter);
-  for (uint i = 0; i < _active_gc_threads; i++) {
-    double worker_time = _gc_par_phases[GCWorkerEnd]->get(i) - _gc_par_phases[GCWorkerStart]->get(i);
-    record_time_secs(GCWorkerTotal, i , worker_time);
+
+  double uninitialized = WorkerDataArray<double>::uninitialized();
+
+  for (uint i = 0; i < _max_gc_threads; i++) {
+    double worker_start = _gc_par_phases[GCWorkerStart]->get(i);
+    if (worker_start != uninitialized) {
+      assert(_gc_par_phases[GCWorkerEnd]->get(i) != uninitialized, "Worker started but not ended.");
+      double total_worker_time = _gc_par_phases[GCWorkerEnd]->get(i) - _gc_par_phases[GCWorkerStart]->get(i);
+      record_time_secs(GCWorkerTotal, i , total_worker_time);
 
-    double worker_known_time =
-        _gc_par_phases[ExtRootScan]->get(i) +
-        _gc_par_phases[SATBFiltering]->get(i) +
-        _gc_par_phases[UpdateRS]->get(i) +
-        _gc_par_phases[ScanRS]->get(i) +
-        _gc_par_phases[CodeRoots]->get(i) +
-        _gc_par_phases[ObjCopy]->get(i) +
-        _gc_par_phases[Termination]->get(i);
+      double worker_known_time =
+          worker_time(ExtRootScan, i)
+          + worker_time(SATBFiltering, i)
+          + worker_time(UpdateRS, i)
+          + worker_time(ScanRS, i)
+          + worker_time(CodeRoots, i)
+          + worker_time(ObjCopy, i)
+          + worker_time(Termination, i);
 
-    record_time_secs(Other, i, worker_time - worker_known_time);
-  }
-
-  for (int i = 0; i < GCParPhasesSentinel; i++) {
-    if (_gc_par_phases[i] != NULL) {
-      _gc_par_phases[i]->verify(_active_gc_threads);
+      record_time_secs(Other, i, total_worker_time - worker_known_time);
+    } else {
+      // Make sure all slots are uninitialized since this thread did not seem to have been started
+      ASSERT_PHASE_UNINITIALIZED(GCWorkerEnd);
+      ASSERT_PHASE_UNINITIALIZED(ExtRootScan);
+      ASSERT_PHASE_UNINITIALIZED(SATBFiltering);
+      ASSERT_PHASE_UNINITIALIZED(UpdateRS);
+      ASSERT_PHASE_UNINITIALIZED(ScanRS);
+      ASSERT_PHASE_UNINITIALIZED(CodeRoots);
+      ASSERT_PHASE_UNINITIALIZED(ObjCopy);
+      ASSERT_PHASE_UNINITIALIZED(Termination);
     }
   }
 }
 
+#undef ASSERT_PHASE_UNINITIALIZED
+
 // record the time a phase took in seconds
 void G1GCPhaseTimes::record_time_secs(GCParPhases phase, uint worker_i, double secs) {
   _gc_par_phases[phase]->set(worker_i, secs);
@@ -150,12 +171,12 @@
 
 // return the average time for a phase in milliseconds
 double G1GCPhaseTimes::average_time_ms(GCParPhases phase) {
-  return _gc_par_phases[phase]->average(_active_gc_threads) * 1000.0;
+  return _gc_par_phases[phase]->average() * 1000.0;
 }
 
 size_t G1GCPhaseTimes::sum_thread_work_items(GCParPhases phase) {
   assert(_gc_par_phases[phase]->thread_work_items() != NULL, "No sub count");
-  return _gc_par_phases[phase]->thread_work_items()->sum(_active_gc_threads);
+  return _gc_par_phases[phase]->thread_work_items()->sum();
 }
 
 template <class T>
@@ -164,19 +185,19 @@
   if (log.is_level(LogLevel::Trace)) {
     outputStream* trace_out = log.trace_stream();
     trace_out->print("%s", indent);
-    phase->print_details_on(trace_out, _active_gc_threads);
+    phase->print_details_on(trace_out);
   }
 }
 
 void G1GCPhaseTimes::log_phase(WorkerDataArray<double>* phase, uint indent, outputStream* out, bool print_sum) {
   out->print("%s", Indents[indent]);
-  phase->print_summary_on(out, _active_gc_threads, print_sum);
+  phase->print_summary_on(out, print_sum);
   details(phase, Indents[indent]);
 
   WorkerDataArray<size_t>* work_items = phase->thread_work_items();
   if (work_items != NULL) {
     out->print("%s", Indents[indent + 1]);
-    work_items->print_summary_on(out, _active_gc_threads, true);
+    work_items->print_summary_on(out, true);
     details(work_items, Indents[indent + 1]);
   }
 }