src/hotspot/share/gc/g1/g1GCPhaseTimes.cpp
branchdatagramsocketimpl-branch
changeset 58678 9cf78a70fa4f
parent 54843 25c329958c70
child 58679 9c3209ff7550
--- a/src/hotspot/share/gc/g1/g1GCPhaseTimes.cpp	Thu Oct 17 20:27:44 2019 +0100
+++ b/src/hotspot/share/gc/g1/g1GCPhaseTimes.cpp	Thu Oct 17 20:53:35 2019 +0100
@@ -61,19 +61,41 @@
   _gc_par_phases[CLDGRoots] = new WorkerDataArray<double>(max_gc_threads, "CLDG Roots (ms):");
   _gc_par_phases[JVMTIRoots] = new WorkerDataArray<double>(max_gc_threads, "JVMTI Roots (ms):");
   AOT_ONLY(_gc_par_phases[AOTCodeRoots] = new WorkerDataArray<double>(max_gc_threads, "AOT Root Scan (ms):");)
-  JVMCI_ONLY(_gc_par_phases[JVMCIRoots] = new WorkerDataArray<double>(max_gc_threads, "JVMCI Root Scan (ms):");)
   _gc_par_phases[CMRefRoots] = new WorkerDataArray<double>(max_gc_threads, "CM RefProcessor Roots (ms):");
-  _gc_par_phases[WaitForStrongCLD] = new WorkerDataArray<double>(max_gc_threads, "Wait For Strong CLD (ms):");
-  _gc_par_phases[WeakCLDRoots] = new WorkerDataArray<double>(max_gc_threads, "Weak CLD Roots (ms):");
+  _gc_par_phases[WaitForStrongRoots] = new WorkerDataArray<double>(max_gc_threads, "Wait For Strong Roots (ms):");
+
+  _gc_par_phases[MergeER] = new WorkerDataArray<double>(max_gc_threads, "Eager Reclaim (ms):");
 
-  _gc_par_phases[UpdateRS] = new WorkerDataArray<double>(max_gc_threads, "Update RS (ms):");
+  _gc_par_phases[MergeRS] = new WorkerDataArray<double>(max_gc_threads, "Remembered Sets (ms):");
+  _merge_rs_merged_sparse = new WorkerDataArray<size_t>(max_gc_threads, "Merged Sparse:");
+  _gc_par_phases[MergeRS]->link_thread_work_items(_merge_rs_merged_sparse, MergeRSMergedSparse);
+  _merge_rs_merged_fine = new WorkerDataArray<size_t>(max_gc_threads, "Merged Fine:");
+  _gc_par_phases[MergeRS]->link_thread_work_items(_merge_rs_merged_fine, MergeRSMergedFine);
+  _merge_rs_merged_coarse = new WorkerDataArray<size_t>(max_gc_threads, "Merged Coarse:");
+  _gc_par_phases[MergeRS]->link_thread_work_items(_merge_rs_merged_coarse, MergeRSMergedCoarse);
+
+  _gc_par_phases[OptMergeRS] = new WorkerDataArray<double>(max_gc_threads, "Optional Remembered Sets (ms):");
+  _opt_merge_rs_merged_sparse = new WorkerDataArray<size_t>(max_gc_threads, "Merged Sparse:");
+  _gc_par_phases[OptMergeRS]->link_thread_work_items(_opt_merge_rs_merged_sparse, MergeRSMergedSparse);
+  _opt_merge_rs_merged_fine = new WorkerDataArray<size_t>(max_gc_threads, "Merged Fine:");
+  _gc_par_phases[OptMergeRS]->link_thread_work_items(_opt_merge_rs_merged_fine, MergeRSMergedFine);
+  _opt_merge_rs_merged_coarse = new WorkerDataArray<size_t>(max_gc_threads, "Merged Coarse:");
+  _gc_par_phases[OptMergeRS]->link_thread_work_items(_opt_merge_rs_merged_coarse, MergeRSMergedCoarse);
+
+  _gc_par_phases[MergeLB] = new WorkerDataArray<double>(max_gc_threads, "Log Buffers (ms):");
   if (G1HotCardCache::default_use_cache()) {
-    _gc_par_phases[ScanHCC] = new WorkerDataArray<double>(max_gc_threads, "Scan HCC (ms):");
+    _gc_par_phases[MergeHCC] = new WorkerDataArray<double>(max_gc_threads, "Hot Card Cache (ms):");
+    _merge_hcc_dirty_cards = new WorkerDataArray<size_t>(max_gc_threads, "Dirty Cards:");
+    _gc_par_phases[MergeHCC]->link_thread_work_items(_merge_hcc_dirty_cards, MergeHCCDirtyCards);
+    _merge_hcc_skipped_cards = new WorkerDataArray<size_t>(max_gc_threads, "Skipped Cards:");
+    _gc_par_phases[MergeHCC]->link_thread_work_items(_merge_hcc_skipped_cards, MergeHCCSkippedCards);
   } else {
-    _gc_par_phases[ScanHCC] = NULL;
+    _gc_par_phases[MergeHCC] = NULL;
+    _merge_hcc_dirty_cards = NULL;
+    _merge_hcc_skipped_cards = NULL;
   }
-  _gc_par_phases[ScanRS] = new WorkerDataArray<double>(max_gc_threads, "Scan RS (ms):");
-  _gc_par_phases[OptScanRS] = new WorkerDataArray<double>(max_gc_threads, "Optional Scan RS (ms):");
+  _gc_par_phases[ScanHR] = new WorkerDataArray<double>(max_gc_threads, "Scan Heap Roots (ms):");
+  _gc_par_phases[OptScanHR] = new WorkerDataArray<double>(max_gc_threads, "Optional Scan Heap Roots (ms):");
   _gc_par_phases[CodeRoots] = new WorkerDataArray<double>(max_gc_threads, "Code Root Scan (ms):");
   _gc_par_phases[OptCodeRoots] = new WorkerDataArray<double>(max_gc_threads, "Optional Code Root Scan (ms):");
   _gc_par_phases[ObjCopy] = new WorkerDataArray<double>(max_gc_threads, "Object Copy (ms):");
@@ -84,30 +106,28 @@
   _gc_par_phases[GCWorkerEnd] = new WorkerDataArray<double>(max_gc_threads, "GC Worker End (ms):");
   _gc_par_phases[Other] = new WorkerDataArray<double>(max_gc_threads, "GC Worker Other (ms):");
 
-  _scan_rs_scanned_cards = new WorkerDataArray<size_t>(max_gc_threads, "Scanned Cards:");
-  _gc_par_phases[ScanRS]->link_thread_work_items(_scan_rs_scanned_cards, ScanRSScannedCards);
-  _scan_rs_claimed_cards = new WorkerDataArray<size_t>(max_gc_threads, "Claimed Cards:");
-  _gc_par_phases[ScanRS]->link_thread_work_items(_scan_rs_claimed_cards, ScanRSClaimedCards);
-  _scan_rs_skipped_cards = new WorkerDataArray<size_t>(max_gc_threads, "Skipped Cards:");
-  _gc_par_phases[ScanRS]->link_thread_work_items(_scan_rs_skipped_cards, ScanRSSkippedCards);
+  _scan_hr_scanned_cards = new WorkerDataArray<size_t>(max_gc_threads, "Scanned Cards:");
+  _gc_par_phases[ScanHR]->link_thread_work_items(_scan_hr_scanned_cards, ScanHRScannedCards);
+  _scan_hr_scanned_blocks = new WorkerDataArray<size_t>(max_gc_threads, "Scanned Blocks:");
+  _gc_par_phases[ScanHR]->link_thread_work_items(_scan_hr_scanned_blocks, ScanHRScannedBlocks);
+  _scan_hr_claimed_chunks = new WorkerDataArray<size_t>(max_gc_threads, "Claimed Chunks:");
+  _gc_par_phases[ScanHR]->link_thread_work_items(_scan_hr_claimed_chunks, ScanHRClaimedChunks);
 
-  _opt_scan_rs_scanned_cards = new WorkerDataArray<size_t>(max_gc_threads, "Scanned Cards:");
-  _gc_par_phases[OptScanRS]->link_thread_work_items(_opt_scan_rs_scanned_cards, ScanRSScannedCards);
-  _opt_scan_rs_claimed_cards = new WorkerDataArray<size_t>(max_gc_threads, "Claimed Cards:");
-  _gc_par_phases[OptScanRS]->link_thread_work_items(_opt_scan_rs_claimed_cards, ScanRSClaimedCards);
-  _opt_scan_rs_skipped_cards = new WorkerDataArray<size_t>(max_gc_threads, "Skipped Cards:");
-  _gc_par_phases[OptScanRS]->link_thread_work_items(_opt_scan_rs_skipped_cards, ScanRSSkippedCards);
-  _opt_scan_rs_scanned_opt_refs = new WorkerDataArray<size_t>(max_gc_threads, "Scanned Refs:");
-  _gc_par_phases[OptScanRS]->link_thread_work_items(_opt_scan_rs_scanned_opt_refs, ScanRSScannedOptRefs);
-  _opt_scan_rs_used_memory = new WorkerDataArray<size_t>(max_gc_threads, "Used Memory:");
-  _gc_par_phases[OptScanRS]->link_thread_work_items(_opt_scan_rs_used_memory, ScanRSUsedMemory);
+  _opt_scan_hr_scanned_cards = new WorkerDataArray<size_t>(max_gc_threads, "Scanned Cards:");
+  _gc_par_phases[OptScanHR]->link_thread_work_items(_opt_scan_hr_scanned_cards, ScanHRScannedCards);
+  _opt_scan_hr_scanned_blocks = new WorkerDataArray<size_t>(max_gc_threads, "Scanned Blocks:");
+  _gc_par_phases[OptScanHR]->link_thread_work_items(_opt_scan_hr_scanned_blocks, ScanHRScannedBlocks);
+  _opt_scan_hr_claimed_chunks = new WorkerDataArray<size_t>(max_gc_threads, "Claimed Chunks:");
+  _gc_par_phases[OptScanHR]->link_thread_work_items(_opt_scan_hr_claimed_chunks, ScanHRClaimedChunks);
+  _opt_scan_hr_scanned_opt_refs = new WorkerDataArray<size_t>(max_gc_threads, "Scanned Refs:");
+  _gc_par_phases[OptScanHR]->link_thread_work_items(_opt_scan_hr_scanned_opt_refs, ScanHRScannedOptRefs);
+  _opt_scan_hr_used_memory = new WorkerDataArray<size_t>(max_gc_threads, "Used Memory:");
+  _gc_par_phases[OptScanHR]->link_thread_work_items(_opt_scan_hr_used_memory, ScanHRUsedMemory);
 
-  _update_rs_processed_buffers = new WorkerDataArray<size_t>(max_gc_threads, "Processed Buffers:");
-  _gc_par_phases[UpdateRS]->link_thread_work_items(_update_rs_processed_buffers, UpdateRSProcessedBuffers);
-  _update_rs_scanned_cards = new WorkerDataArray<size_t>(max_gc_threads, "Scanned Cards:");
-  _gc_par_phases[UpdateRS]->link_thread_work_items(_update_rs_scanned_cards, UpdateRSScannedCards);
-  _update_rs_skipped_cards = new WorkerDataArray<size_t>(max_gc_threads, "Skipped Cards:");
-  _gc_par_phases[UpdateRS]->link_thread_work_items(_update_rs_skipped_cards, UpdateRSSkippedCards);
+  _merge_lb_dirty_cards = new WorkerDataArray<size_t>(max_gc_threads, "Dirty Cards:");
+  _gc_par_phases[MergeLB]->link_thread_work_items(_merge_lb_dirty_cards, MergeLBDirtyCards);
+  _merge_lb_skipped_cards = new WorkerDataArray<size_t>(max_gc_threads, "Skipped Cards:");
+  _gc_par_phases[MergeLB]->link_thread_work_items(_merge_lb_skipped_cards, MergeLBSkippedCards);
 
   _obj_copy_lab_waste = new WorkerDataArray<size_t>(max_gc_threads, "LAB Waste");
   _gc_par_phases[ObjCopy]->link_thread_work_items(_obj_copy_lab_waste, ObjCopyLABWaste);
@@ -148,6 +168,10 @@
   _cur_optional_evac_ms = 0.0;
   _cur_collection_code_root_fixup_time_ms = 0.0;
   _cur_strong_code_root_purge_time_ms = 0.0;
+  _cur_merge_heap_roots_time_ms = 0.0;
+  _cur_optional_merge_heap_roots_time_ms = 0.0;
+  _cur_prepare_merge_heap_roots_time_ms = 0.0;
+  _cur_optional_prepare_merge_heap_roots_time_ms = 0.0;
   _cur_evac_fail_recalc_used = 0.0;
   _cur_evac_fail_remove_self_forwards = 0.0;
   _cur_string_deduplication_time_ms = 0.0;
@@ -160,6 +184,7 @@
   _cur_collection_start_sec = 0.0;
   _root_region_scan_wait_time_ms = 0.0;
   _external_accounted_time_ms = 0.0;
+  _recorded_prepare_heap_roots_time_ms = 0.0;
   _recorded_clear_claimed_marks_time_ms = 0.0;
   _recorded_young_cset_choice_time_ms = 0.0;
   _recorded_non_young_cset_choice_time_ms = 0.0;
@@ -219,9 +244,7 @@
       record_time_secs(GCWorkerTotal, i , total_worker_time);
 
       double worker_known_time = worker_time(ExtRootScan, i) +
-                                 worker_time(ScanHCC, i) +
-                                 worker_time(UpdateRS, i) +
-                                 worker_time(ScanRS, i) +
+                                 worker_time(ScanHR, i) +
                                  worker_time(CodeRoots, i) +
                                  worker_time(ObjCopy, i) +
                                  worker_time(Termination, i);
@@ -231,11 +254,16 @@
       // 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(ScanHCC);
-      ASSERT_PHASE_UNINITIALIZED(UpdateRS);
-      ASSERT_PHASE_UNINITIALIZED(ScanRS);
+      ASSERT_PHASE_UNINITIALIZED(MergeER);
+      ASSERT_PHASE_UNINITIALIZED(MergeRS);
+      ASSERT_PHASE_UNINITIALIZED(OptMergeRS);
+      ASSERT_PHASE_UNINITIALIZED(MergeHCC);
+      ASSERT_PHASE_UNINITIALIZED(MergeLB);
+      ASSERT_PHASE_UNINITIALIZED(ScanHR);
       ASSERT_PHASE_UNINITIALIZED(CodeRoots);
+      ASSERT_PHASE_UNINITIALIZED(OptCodeRoots);
       ASSERT_PHASE_UNINITIALIZED(ObjCopy);
+      ASSERT_PHASE_UNINITIALIZED(OptObjCopy);
       ASSERT_PHASE_UNINITIALIZED(Termination);
     }
   }
@@ -244,37 +272,37 @@
 #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);
+void G1GCPhaseTimes::record_time_secs(GCParPhases phase, uint worker_id, double secs) {
+  _gc_par_phases[phase]->set(worker_id, secs);
 }
 
 // add a number of seconds to a phase
-void G1GCPhaseTimes::add_time_secs(GCParPhases phase, uint worker_i, double secs) {
-  _gc_par_phases[phase]->add(worker_i, secs);
+void G1GCPhaseTimes::add_time_secs(GCParPhases phase, uint worker_id, double secs) {
+  _gc_par_phases[phase]->add(worker_id, secs);
 }
 
-void G1GCPhaseTimes::record_or_add_time_secs(GCParPhases phase, uint worker_i, double secs) {
-  if (_gc_par_phases[phase]->get(worker_i) == _gc_par_phases[phase]->uninitialized()) {
-    record_time_secs(phase, worker_i, secs);
+void G1GCPhaseTimes::record_or_add_time_secs(GCParPhases phase, uint worker_id, double secs) {
+  if (_gc_par_phases[phase]->get(worker_id) == _gc_par_phases[phase]->uninitialized()) {
+    record_time_secs(phase, worker_id, secs);
   } else {
-    add_time_secs(phase, worker_i, secs);
+    add_time_secs(phase, worker_id, secs);
   }
 }
 
-double G1GCPhaseTimes::get_time_secs(GCParPhases phase, uint worker_i) {
-  return _gc_par_phases[phase]->get(worker_i);
+double G1GCPhaseTimes::get_time_secs(GCParPhases phase, uint worker_id) {
+  return _gc_par_phases[phase]->get(worker_id);
 }
 
-void G1GCPhaseTimes::record_thread_work_item(GCParPhases phase, uint worker_i, size_t count, uint index) {
-  _gc_par_phases[phase]->set_thread_work_item(worker_i, count, index);
+void G1GCPhaseTimes::record_thread_work_item(GCParPhases phase, uint worker_id, size_t count, uint index) {
+  _gc_par_phases[phase]->set_thread_work_item(worker_id, count, index);
 }
 
-void G1GCPhaseTimes::record_or_add_thread_work_item(GCParPhases phase, uint worker_i, size_t count, uint index) {
-  _gc_par_phases[phase]->set_or_add_thread_work_item(worker_i, count, index);
+void G1GCPhaseTimes::record_or_add_thread_work_item(GCParPhases phase, uint worker_id, size_t count, uint index) {
+  _gc_par_phases[phase]->set_or_add_thread_work_item(worker_id, count, index);
 }
 
-size_t G1GCPhaseTimes::get_thread_work_item(GCParPhases phase, uint worker_i, uint index) {
-  return _gc_par_phases[phase]->get_thread_work_item(worker_i, index);
+size_t G1GCPhaseTimes::get_thread_work_item(GCParPhases phase, uint worker_id, uint index) {
+  return _gc_par_phases[phase]->get_thread_work_item(worker_id, index);
 }
 
 // return the average time for a phase in milliseconds
@@ -365,6 +393,7 @@
                         _recorded_young_cset_choice_time_ms +
                         _recorded_non_young_cset_choice_time_ms +
                         _cur_region_register_time +
+                        _recorded_prepare_heap_roots_time_ms +
                         _recorded_clear_claimed_marks_time_ms;
 
   info_time("Pre Evacuate Collection Set", sum_ms);
@@ -380,6 +409,7 @@
     trace_count("Humongous Candidate", _cur_fast_reclaim_humongous_candidates);
   }
 
+  debug_time("Prepare Heap Roots", _recorded_prepare_heap_roots_time_ms);
   if (_recorded_clear_claimed_marks_time_ms > 0.0) {
     debug_time("Clear Claimed Marks", _recorded_clear_claimed_marks_time_ms);
   }
@@ -387,10 +417,15 @@
 }
 
 double G1GCPhaseTimes::print_evacuate_optional_collection_set() const {
-  const double sum_ms = _cur_optional_evac_ms;
+  const double sum_ms = _cur_optional_evac_ms + _cur_optional_merge_heap_roots_time_ms;
   if (sum_ms > 0) {
-    info_time("Evacuate Optional Collection Set", sum_ms);
-    debug_phase(_gc_par_phases[OptScanRS]);
+    info_time("Merge Optional Heap Roots", _cur_optional_merge_heap_roots_time_ms);
+
+    debug_time("Prepare Optional Merge Heap Roots", _cur_optional_prepare_merge_heap_roots_time_ms);
+    debug_phase(_gc_par_phases[OptMergeRS]);
+
+    info_time("Evacuate Optional Collection Set", _cur_optional_evac_ms);
+    debug_phase(_gc_par_phases[OptScanHR]);
     debug_phase(_gc_par_phases[OptObjCopy]);
     debug_phase(_gc_par_phases[OptCodeRoots]);
     debug_phase(_gc_par_phases[OptTermination]);
@@ -398,21 +433,25 @@
   return sum_ms;
 }
 
-double G1GCPhaseTimes::print_evacuate_collection_set() const {
-  const double sum_ms = _cur_collection_initial_evac_time_ms;
+double G1GCPhaseTimes::print_evacuate_initial_collection_set() const {
+  info_time("Merge Heap Roots", _cur_merge_heap_roots_time_ms);
 
-  info_time("Evacuate Collection Set", sum_ms);
+  debug_time("Prepare Merge Heap Roots", _cur_prepare_merge_heap_roots_time_ms);
+  debug_phase(_gc_par_phases[MergeER]);
+  debug_phase(_gc_par_phases[MergeRS]);
+  if (G1HotCardCache::default_use_cache()) {
+    debug_phase(_gc_par_phases[MergeHCC]);
+  }
+  debug_phase(_gc_par_phases[MergeLB]);
+
+  info_time("Evacuate Collection Set", _cur_collection_initial_evac_time_ms);
 
   trace_phase(_gc_par_phases[GCWorkerStart], false);
   debug_phase(_gc_par_phases[ExtRootScan]);
   for (int i = ExtRootScanSubPhasesFirst; i <= ExtRootScanSubPhasesLast; i++) {
     trace_phase(_gc_par_phases[i]);
   }
-  if (G1HotCardCache::default_use_cache()) {
-    debug_phase(_gc_par_phases[ScanHCC]);
-  }
-  debug_phase(_gc_par_phases[UpdateRS]);
-  debug_phase(_gc_par_phases[ScanRS]);
+  debug_phase(_gc_par_phases[ScanHR]);
   debug_phase(_gc_par_phases[CodeRoots]);
   debug_phase(_gc_par_phases[ObjCopy]);
   debug_phase(_gc_par_phases[Termination]);
@@ -420,7 +459,7 @@
   debug_phase(_gc_par_phases[GCWorkerTotal]);
   trace_phase(_gc_par_phases[GCWorkerEnd], false);
 
-  return sum_ms;
+  return _cur_collection_initial_evac_time_ms + _cur_merge_heap_roots_time_ms;
 }
 
 double G1GCPhaseTimes::print_post_evacuate_collection_set() const {
@@ -503,7 +542,7 @@
 
   double accounted_ms = 0.0;
   accounted_ms += print_pre_evacuate_collection_set();
-  accounted_ms += print_evacuate_collection_set();
+  accounted_ms += print_evacuate_initial_collection_set();
   accounted_ms += print_evacuate_optional_collection_set();
   accounted_ms += print_post_evacuate_collection_set();
   print_other(accounted_ms);
@@ -526,14 +565,15 @@
       "CLDGRoots",
       "JVMTIRoots",
       AOT_ONLY("AOTCodeRoots" COMMA)
-      JVMCI_ONLY("JVMCIRoots" COMMA)
       "CMRefRoots",
-      "WaitForStrongCLD",
-      "WeakCLDRoots",
-      "UpdateRS",
-      "ScanHCC",
-      "ScanRS",
-      "OptScanRS",
+      "WaitForStrongRoots",
+      "MergeER",
+      "MergeRS",
+      "OptMergeRS",
+      "MergeLB",
+      "MergeHCC",
+      "ScanHR",
+      "OptScanHR",
       "CodeRoots",
       "OptCodeRoots",
       "ObjCopy",
@@ -580,8 +620,8 @@
   _stopped = true;
 }
 
-G1GCParPhaseTimesTracker::G1GCParPhaseTimesTracker(G1GCPhaseTimes* phase_times, G1GCPhaseTimes::GCParPhases phase, uint worker_id) :
-  _start_time(), _phase(phase), _phase_times(phase_times), _worker_id(worker_id), _event() {
+G1GCParPhaseTimesTracker::G1GCParPhaseTimesTracker(G1GCPhaseTimes* phase_times, G1GCPhaseTimes::GCParPhases phase, uint worker_id, bool must_record) :
+  _start_time(), _phase(phase), _phase_times(phase_times), _worker_id(worker_id), _event(), _must_record(must_record) {
   if (_phase_times != NULL) {
     _start_time = Ticks::now();
   }
@@ -589,7 +629,11 @@
 
 G1GCParPhaseTimesTracker::~G1GCParPhaseTimesTracker() {
   if (_phase_times != NULL) {
-    _phase_times->record_time_secs(_phase, _worker_id, (Ticks::now() - _start_time).seconds());
+    if (_must_record) {
+      _phase_times->record_time_secs(_phase, _worker_id, (Ticks::now() - _start_time).seconds());
+    } else {
+      _phase_times->record_or_add_time_secs(_phase, _worker_id, (Ticks::now() - _start_time).seconds());
+    }
     _event.commit(GCId::current(), _worker_id, G1GCPhaseTimes::phase_name(_phase));
   }
 }