src/hotspot/share/gc/g1/g1GCPhaseTimes.cpp
branchdatagramsocketimpl-branch
changeset 58678 9cf78a70fa4f
parent 54843 25c329958c70
child 58679 9c3209ff7550
equal deleted inserted replaced
58677:13588c901957 58678:9cf78a70fa4f
    59   _gc_par_phases[ManagementRoots] = new WorkerDataArray<double>(max_gc_threads, "Management Roots (ms):");
    59   _gc_par_phases[ManagementRoots] = new WorkerDataArray<double>(max_gc_threads, "Management Roots (ms):");
    60   _gc_par_phases[SystemDictionaryRoots] = new WorkerDataArray<double>(max_gc_threads, "SystemDictionary Roots (ms):");
    60   _gc_par_phases[SystemDictionaryRoots] = new WorkerDataArray<double>(max_gc_threads, "SystemDictionary Roots (ms):");
    61   _gc_par_phases[CLDGRoots] = new WorkerDataArray<double>(max_gc_threads, "CLDG Roots (ms):");
    61   _gc_par_phases[CLDGRoots] = new WorkerDataArray<double>(max_gc_threads, "CLDG Roots (ms):");
    62   _gc_par_phases[JVMTIRoots] = new WorkerDataArray<double>(max_gc_threads, "JVMTI Roots (ms):");
    62   _gc_par_phases[JVMTIRoots] = new WorkerDataArray<double>(max_gc_threads, "JVMTI Roots (ms):");
    63   AOT_ONLY(_gc_par_phases[AOTCodeRoots] = new WorkerDataArray<double>(max_gc_threads, "AOT Root Scan (ms):");)
    63   AOT_ONLY(_gc_par_phases[AOTCodeRoots] = new WorkerDataArray<double>(max_gc_threads, "AOT Root Scan (ms):");)
    64   JVMCI_ONLY(_gc_par_phases[JVMCIRoots] = new WorkerDataArray<double>(max_gc_threads, "JVMCI Root Scan (ms):");)
       
    65   _gc_par_phases[CMRefRoots] = new WorkerDataArray<double>(max_gc_threads, "CM RefProcessor Roots (ms):");
    64   _gc_par_phases[CMRefRoots] = new WorkerDataArray<double>(max_gc_threads, "CM RefProcessor Roots (ms):");
    66   _gc_par_phases[WaitForStrongCLD] = new WorkerDataArray<double>(max_gc_threads, "Wait For Strong CLD (ms):");
    65   _gc_par_phases[WaitForStrongRoots] = new WorkerDataArray<double>(max_gc_threads, "Wait For Strong Roots (ms):");
    67   _gc_par_phases[WeakCLDRoots] = new WorkerDataArray<double>(max_gc_threads, "Weak CLD Roots (ms):");
    66 
    68 
    67   _gc_par_phases[MergeER] = new WorkerDataArray<double>(max_gc_threads, "Eager Reclaim (ms):");
    69   _gc_par_phases[UpdateRS] = new WorkerDataArray<double>(max_gc_threads, "Update RS (ms):");
    68 
       
    69   _gc_par_phases[MergeRS] = new WorkerDataArray<double>(max_gc_threads, "Remembered Sets (ms):");
       
    70   _merge_rs_merged_sparse = new WorkerDataArray<size_t>(max_gc_threads, "Merged Sparse:");
       
    71   _gc_par_phases[MergeRS]->link_thread_work_items(_merge_rs_merged_sparse, MergeRSMergedSparse);
       
    72   _merge_rs_merged_fine = new WorkerDataArray<size_t>(max_gc_threads, "Merged Fine:");
       
    73   _gc_par_phases[MergeRS]->link_thread_work_items(_merge_rs_merged_fine, MergeRSMergedFine);
       
    74   _merge_rs_merged_coarse = new WorkerDataArray<size_t>(max_gc_threads, "Merged Coarse:");
       
    75   _gc_par_phases[MergeRS]->link_thread_work_items(_merge_rs_merged_coarse, MergeRSMergedCoarse);
       
    76 
       
    77   _gc_par_phases[OptMergeRS] = new WorkerDataArray<double>(max_gc_threads, "Optional Remembered Sets (ms):");
       
    78   _opt_merge_rs_merged_sparse = new WorkerDataArray<size_t>(max_gc_threads, "Merged Sparse:");
       
    79   _gc_par_phases[OptMergeRS]->link_thread_work_items(_opt_merge_rs_merged_sparse, MergeRSMergedSparse);
       
    80   _opt_merge_rs_merged_fine = new WorkerDataArray<size_t>(max_gc_threads, "Merged Fine:");
       
    81   _gc_par_phases[OptMergeRS]->link_thread_work_items(_opt_merge_rs_merged_fine, MergeRSMergedFine);
       
    82   _opt_merge_rs_merged_coarse = new WorkerDataArray<size_t>(max_gc_threads, "Merged Coarse:");
       
    83   _gc_par_phases[OptMergeRS]->link_thread_work_items(_opt_merge_rs_merged_coarse, MergeRSMergedCoarse);
       
    84 
       
    85   _gc_par_phases[MergeLB] = new WorkerDataArray<double>(max_gc_threads, "Log Buffers (ms):");
    70   if (G1HotCardCache::default_use_cache()) {
    86   if (G1HotCardCache::default_use_cache()) {
    71     _gc_par_phases[ScanHCC] = new WorkerDataArray<double>(max_gc_threads, "Scan HCC (ms):");
    87     _gc_par_phases[MergeHCC] = new WorkerDataArray<double>(max_gc_threads, "Hot Card Cache (ms):");
       
    88     _merge_hcc_dirty_cards = new WorkerDataArray<size_t>(max_gc_threads, "Dirty Cards:");
       
    89     _gc_par_phases[MergeHCC]->link_thread_work_items(_merge_hcc_dirty_cards, MergeHCCDirtyCards);
       
    90     _merge_hcc_skipped_cards = new WorkerDataArray<size_t>(max_gc_threads, "Skipped Cards:");
       
    91     _gc_par_phases[MergeHCC]->link_thread_work_items(_merge_hcc_skipped_cards, MergeHCCSkippedCards);
    72   } else {
    92   } else {
    73     _gc_par_phases[ScanHCC] = NULL;
    93     _gc_par_phases[MergeHCC] = NULL;
    74   }
    94     _merge_hcc_dirty_cards = NULL;
    75   _gc_par_phases[ScanRS] = new WorkerDataArray<double>(max_gc_threads, "Scan RS (ms):");
    95     _merge_hcc_skipped_cards = NULL;
    76   _gc_par_phases[OptScanRS] = new WorkerDataArray<double>(max_gc_threads, "Optional Scan RS (ms):");
    96   }
       
    97   _gc_par_phases[ScanHR] = new WorkerDataArray<double>(max_gc_threads, "Scan Heap Roots (ms):");
       
    98   _gc_par_phases[OptScanHR] = new WorkerDataArray<double>(max_gc_threads, "Optional Scan Heap Roots (ms):");
    77   _gc_par_phases[CodeRoots] = new WorkerDataArray<double>(max_gc_threads, "Code Root Scan (ms):");
    99   _gc_par_phases[CodeRoots] = new WorkerDataArray<double>(max_gc_threads, "Code Root Scan (ms):");
    78   _gc_par_phases[OptCodeRoots] = new WorkerDataArray<double>(max_gc_threads, "Optional Code Root Scan (ms):");
   100   _gc_par_phases[OptCodeRoots] = new WorkerDataArray<double>(max_gc_threads, "Optional Code Root Scan (ms):");
    79   _gc_par_phases[ObjCopy] = new WorkerDataArray<double>(max_gc_threads, "Object Copy (ms):");
   101   _gc_par_phases[ObjCopy] = new WorkerDataArray<double>(max_gc_threads, "Object Copy (ms):");
    80   _gc_par_phases[OptObjCopy] = new WorkerDataArray<double>(max_gc_threads, "Optional Object Copy (ms):");
   102   _gc_par_phases[OptObjCopy] = new WorkerDataArray<double>(max_gc_threads, "Optional Object Copy (ms):");
    81   _gc_par_phases[Termination] = new WorkerDataArray<double>(max_gc_threads, "Termination (ms):");
   103   _gc_par_phases[Termination] = new WorkerDataArray<double>(max_gc_threads, "Termination (ms):");
    82   _gc_par_phases[OptTermination] = new WorkerDataArray<double>(max_gc_threads, "Optional Termination (ms):");
   104   _gc_par_phases[OptTermination] = new WorkerDataArray<double>(max_gc_threads, "Optional Termination (ms):");
    83   _gc_par_phases[GCWorkerTotal] = new WorkerDataArray<double>(max_gc_threads, "GC Worker Total (ms):");
   105   _gc_par_phases[GCWorkerTotal] = new WorkerDataArray<double>(max_gc_threads, "GC Worker Total (ms):");
    84   _gc_par_phases[GCWorkerEnd] = new WorkerDataArray<double>(max_gc_threads, "GC Worker End (ms):");
   106   _gc_par_phases[GCWorkerEnd] = new WorkerDataArray<double>(max_gc_threads, "GC Worker End (ms):");
    85   _gc_par_phases[Other] = new WorkerDataArray<double>(max_gc_threads, "GC Worker Other (ms):");
   107   _gc_par_phases[Other] = new WorkerDataArray<double>(max_gc_threads, "GC Worker Other (ms):");
    86 
   108 
    87   _scan_rs_scanned_cards = new WorkerDataArray<size_t>(max_gc_threads, "Scanned Cards:");
   109   _scan_hr_scanned_cards = new WorkerDataArray<size_t>(max_gc_threads, "Scanned Cards:");
    88   _gc_par_phases[ScanRS]->link_thread_work_items(_scan_rs_scanned_cards, ScanRSScannedCards);
   110   _gc_par_phases[ScanHR]->link_thread_work_items(_scan_hr_scanned_cards, ScanHRScannedCards);
    89   _scan_rs_claimed_cards = new WorkerDataArray<size_t>(max_gc_threads, "Claimed Cards:");
   111   _scan_hr_scanned_blocks = new WorkerDataArray<size_t>(max_gc_threads, "Scanned Blocks:");
    90   _gc_par_phases[ScanRS]->link_thread_work_items(_scan_rs_claimed_cards, ScanRSClaimedCards);
   112   _gc_par_phases[ScanHR]->link_thread_work_items(_scan_hr_scanned_blocks, ScanHRScannedBlocks);
    91   _scan_rs_skipped_cards = new WorkerDataArray<size_t>(max_gc_threads, "Skipped Cards:");
   113   _scan_hr_claimed_chunks = new WorkerDataArray<size_t>(max_gc_threads, "Claimed Chunks:");
    92   _gc_par_phases[ScanRS]->link_thread_work_items(_scan_rs_skipped_cards, ScanRSSkippedCards);
   114   _gc_par_phases[ScanHR]->link_thread_work_items(_scan_hr_claimed_chunks, ScanHRClaimedChunks);
    93 
   115 
    94   _opt_scan_rs_scanned_cards = new WorkerDataArray<size_t>(max_gc_threads, "Scanned Cards:");
   116   _opt_scan_hr_scanned_cards = new WorkerDataArray<size_t>(max_gc_threads, "Scanned Cards:");
    95   _gc_par_phases[OptScanRS]->link_thread_work_items(_opt_scan_rs_scanned_cards, ScanRSScannedCards);
   117   _gc_par_phases[OptScanHR]->link_thread_work_items(_opt_scan_hr_scanned_cards, ScanHRScannedCards);
    96   _opt_scan_rs_claimed_cards = new WorkerDataArray<size_t>(max_gc_threads, "Claimed Cards:");
   118   _opt_scan_hr_scanned_blocks = new WorkerDataArray<size_t>(max_gc_threads, "Scanned Blocks:");
    97   _gc_par_phases[OptScanRS]->link_thread_work_items(_opt_scan_rs_claimed_cards, ScanRSClaimedCards);
   119   _gc_par_phases[OptScanHR]->link_thread_work_items(_opt_scan_hr_scanned_blocks, ScanHRScannedBlocks);
    98   _opt_scan_rs_skipped_cards = new WorkerDataArray<size_t>(max_gc_threads, "Skipped Cards:");
   120   _opt_scan_hr_claimed_chunks = new WorkerDataArray<size_t>(max_gc_threads, "Claimed Chunks:");
    99   _gc_par_phases[OptScanRS]->link_thread_work_items(_opt_scan_rs_skipped_cards, ScanRSSkippedCards);
   121   _gc_par_phases[OptScanHR]->link_thread_work_items(_opt_scan_hr_claimed_chunks, ScanHRClaimedChunks);
   100   _opt_scan_rs_scanned_opt_refs = new WorkerDataArray<size_t>(max_gc_threads, "Scanned Refs:");
   122   _opt_scan_hr_scanned_opt_refs = new WorkerDataArray<size_t>(max_gc_threads, "Scanned Refs:");
   101   _gc_par_phases[OptScanRS]->link_thread_work_items(_opt_scan_rs_scanned_opt_refs, ScanRSScannedOptRefs);
   123   _gc_par_phases[OptScanHR]->link_thread_work_items(_opt_scan_hr_scanned_opt_refs, ScanHRScannedOptRefs);
   102   _opt_scan_rs_used_memory = new WorkerDataArray<size_t>(max_gc_threads, "Used Memory:");
   124   _opt_scan_hr_used_memory = new WorkerDataArray<size_t>(max_gc_threads, "Used Memory:");
   103   _gc_par_phases[OptScanRS]->link_thread_work_items(_opt_scan_rs_used_memory, ScanRSUsedMemory);
   125   _gc_par_phases[OptScanHR]->link_thread_work_items(_opt_scan_hr_used_memory, ScanHRUsedMemory);
   104 
   126 
   105   _update_rs_processed_buffers = new WorkerDataArray<size_t>(max_gc_threads, "Processed Buffers:");
   127   _merge_lb_dirty_cards = new WorkerDataArray<size_t>(max_gc_threads, "Dirty Cards:");
   106   _gc_par_phases[UpdateRS]->link_thread_work_items(_update_rs_processed_buffers, UpdateRSProcessedBuffers);
   128   _gc_par_phases[MergeLB]->link_thread_work_items(_merge_lb_dirty_cards, MergeLBDirtyCards);
   107   _update_rs_scanned_cards = new WorkerDataArray<size_t>(max_gc_threads, "Scanned Cards:");
   129   _merge_lb_skipped_cards = new WorkerDataArray<size_t>(max_gc_threads, "Skipped Cards:");
   108   _gc_par_phases[UpdateRS]->link_thread_work_items(_update_rs_scanned_cards, UpdateRSScannedCards);
   130   _gc_par_phases[MergeLB]->link_thread_work_items(_merge_lb_skipped_cards, MergeLBSkippedCards);
   109   _update_rs_skipped_cards = new WorkerDataArray<size_t>(max_gc_threads, "Skipped Cards:");
       
   110   _gc_par_phases[UpdateRS]->link_thread_work_items(_update_rs_skipped_cards, UpdateRSSkippedCards);
       
   111 
   131 
   112   _obj_copy_lab_waste = new WorkerDataArray<size_t>(max_gc_threads, "LAB Waste");
   132   _obj_copy_lab_waste = new WorkerDataArray<size_t>(max_gc_threads, "LAB Waste");
   113   _gc_par_phases[ObjCopy]->link_thread_work_items(_obj_copy_lab_waste, ObjCopyLABWaste);
   133   _gc_par_phases[ObjCopy]->link_thread_work_items(_obj_copy_lab_waste, ObjCopyLABWaste);
   114   _obj_copy_lab_undo_waste = new WorkerDataArray<size_t>(max_gc_threads, "LAB Undo Waste");
   134   _obj_copy_lab_undo_waste = new WorkerDataArray<size_t>(max_gc_threads, "LAB Undo Waste");
   115   _gc_par_phases[ObjCopy]->link_thread_work_items(_obj_copy_lab_undo_waste, ObjCopyLABUndoWaste);
   135   _gc_par_phases[ObjCopy]->link_thread_work_items(_obj_copy_lab_undo_waste, ObjCopyLABUndoWaste);
   146 void G1GCPhaseTimes::reset() {
   166 void G1GCPhaseTimes::reset() {
   147   _cur_collection_initial_evac_time_ms = 0.0;
   167   _cur_collection_initial_evac_time_ms = 0.0;
   148   _cur_optional_evac_ms = 0.0;
   168   _cur_optional_evac_ms = 0.0;
   149   _cur_collection_code_root_fixup_time_ms = 0.0;
   169   _cur_collection_code_root_fixup_time_ms = 0.0;
   150   _cur_strong_code_root_purge_time_ms = 0.0;
   170   _cur_strong_code_root_purge_time_ms = 0.0;
       
   171   _cur_merge_heap_roots_time_ms = 0.0;
       
   172   _cur_optional_merge_heap_roots_time_ms = 0.0;
       
   173   _cur_prepare_merge_heap_roots_time_ms = 0.0;
       
   174   _cur_optional_prepare_merge_heap_roots_time_ms = 0.0;
   151   _cur_evac_fail_recalc_used = 0.0;
   175   _cur_evac_fail_recalc_used = 0.0;
   152   _cur_evac_fail_remove_self_forwards = 0.0;
   176   _cur_evac_fail_remove_self_forwards = 0.0;
   153   _cur_string_deduplication_time_ms = 0.0;
   177   _cur_string_deduplication_time_ms = 0.0;
   154   _cur_prepare_tlab_time_ms = 0.0;
   178   _cur_prepare_tlab_time_ms = 0.0;
   155   _cur_resize_tlab_time_ms = 0.0;
   179   _cur_resize_tlab_time_ms = 0.0;
   158   _cur_expand_heap_time_ms = 0.0;
   182   _cur_expand_heap_time_ms = 0.0;
   159   _cur_ref_proc_time_ms = 0.0;
   183   _cur_ref_proc_time_ms = 0.0;
   160   _cur_collection_start_sec = 0.0;
   184   _cur_collection_start_sec = 0.0;
   161   _root_region_scan_wait_time_ms = 0.0;
   185   _root_region_scan_wait_time_ms = 0.0;
   162   _external_accounted_time_ms = 0.0;
   186   _external_accounted_time_ms = 0.0;
       
   187   _recorded_prepare_heap_roots_time_ms = 0.0;
   163   _recorded_clear_claimed_marks_time_ms = 0.0;
   188   _recorded_clear_claimed_marks_time_ms = 0.0;
   164   _recorded_young_cset_choice_time_ms = 0.0;
   189   _recorded_young_cset_choice_time_ms = 0.0;
   165   _recorded_non_young_cset_choice_time_ms = 0.0;
   190   _recorded_non_young_cset_choice_time_ms = 0.0;
   166   _recorded_redirty_logged_cards_time_ms = 0.0;
   191   _recorded_redirty_logged_cards_time_ms = 0.0;
   167   _recorded_preserve_cm_referents_time_ms = 0.0;
   192   _recorded_preserve_cm_referents_time_ms = 0.0;
   217       assert(_gc_par_phases[GCWorkerEnd]->get(i) != uninitialized, "Worker started but not ended.");
   242       assert(_gc_par_phases[GCWorkerEnd]->get(i) != uninitialized, "Worker started but not ended.");
   218       double total_worker_time = _gc_par_phases[GCWorkerEnd]->get(i) - _gc_par_phases[GCWorkerStart]->get(i);
   243       double total_worker_time = _gc_par_phases[GCWorkerEnd]->get(i) - _gc_par_phases[GCWorkerStart]->get(i);
   219       record_time_secs(GCWorkerTotal, i , total_worker_time);
   244       record_time_secs(GCWorkerTotal, i , total_worker_time);
   220 
   245 
   221       double worker_known_time = worker_time(ExtRootScan, i) +
   246       double worker_known_time = worker_time(ExtRootScan, i) +
   222                                  worker_time(ScanHCC, i) +
   247                                  worker_time(ScanHR, i) +
   223                                  worker_time(UpdateRS, i) +
       
   224                                  worker_time(ScanRS, i) +
       
   225                                  worker_time(CodeRoots, i) +
   248                                  worker_time(CodeRoots, i) +
   226                                  worker_time(ObjCopy, i) +
   249                                  worker_time(ObjCopy, i) +
   227                                  worker_time(Termination, i);
   250                                  worker_time(Termination, i);
   228 
   251 
   229       record_time_secs(Other, i, total_worker_time - worker_known_time);
   252       record_time_secs(Other, i, total_worker_time - worker_known_time);
   230     } else {
   253     } else {
   231       // Make sure all slots are uninitialized since this thread did not seem to have been started
   254       // Make sure all slots are uninitialized since this thread did not seem to have been started
   232       ASSERT_PHASE_UNINITIALIZED(GCWorkerEnd);
   255       ASSERT_PHASE_UNINITIALIZED(GCWorkerEnd);
   233       ASSERT_PHASE_UNINITIALIZED(ExtRootScan);
   256       ASSERT_PHASE_UNINITIALIZED(ExtRootScan);
   234       ASSERT_PHASE_UNINITIALIZED(ScanHCC);
   257       ASSERT_PHASE_UNINITIALIZED(MergeER);
   235       ASSERT_PHASE_UNINITIALIZED(UpdateRS);
   258       ASSERT_PHASE_UNINITIALIZED(MergeRS);
   236       ASSERT_PHASE_UNINITIALIZED(ScanRS);
   259       ASSERT_PHASE_UNINITIALIZED(OptMergeRS);
       
   260       ASSERT_PHASE_UNINITIALIZED(MergeHCC);
       
   261       ASSERT_PHASE_UNINITIALIZED(MergeLB);
       
   262       ASSERT_PHASE_UNINITIALIZED(ScanHR);
   237       ASSERT_PHASE_UNINITIALIZED(CodeRoots);
   263       ASSERT_PHASE_UNINITIALIZED(CodeRoots);
       
   264       ASSERT_PHASE_UNINITIALIZED(OptCodeRoots);
   238       ASSERT_PHASE_UNINITIALIZED(ObjCopy);
   265       ASSERT_PHASE_UNINITIALIZED(ObjCopy);
       
   266       ASSERT_PHASE_UNINITIALIZED(OptObjCopy);
   239       ASSERT_PHASE_UNINITIALIZED(Termination);
   267       ASSERT_PHASE_UNINITIALIZED(Termination);
   240     }
   268     }
   241   }
   269   }
   242 }
   270 }
   243 
   271 
   244 #undef ASSERT_PHASE_UNINITIALIZED
   272 #undef ASSERT_PHASE_UNINITIALIZED
   245 
   273 
   246 // record the time a phase took in seconds
   274 // record the time a phase took in seconds
   247 void G1GCPhaseTimes::record_time_secs(GCParPhases phase, uint worker_i, double secs) {
   275 void G1GCPhaseTimes::record_time_secs(GCParPhases phase, uint worker_id, double secs) {
   248   _gc_par_phases[phase]->set(worker_i, secs);
   276   _gc_par_phases[phase]->set(worker_id, secs);
   249 }
   277 }
   250 
   278 
   251 // add a number of seconds to a phase
   279 // add a number of seconds to a phase
   252 void G1GCPhaseTimes::add_time_secs(GCParPhases phase, uint worker_i, double secs) {
   280 void G1GCPhaseTimes::add_time_secs(GCParPhases phase, uint worker_id, double secs) {
   253   _gc_par_phases[phase]->add(worker_i, secs);
   281   _gc_par_phases[phase]->add(worker_id, secs);
   254 }
   282 }
   255 
   283 
   256 void G1GCPhaseTimes::record_or_add_time_secs(GCParPhases phase, uint worker_i, double secs) {
   284 void G1GCPhaseTimes::record_or_add_time_secs(GCParPhases phase, uint worker_id, double secs) {
   257   if (_gc_par_phases[phase]->get(worker_i) == _gc_par_phases[phase]->uninitialized()) {
   285   if (_gc_par_phases[phase]->get(worker_id) == _gc_par_phases[phase]->uninitialized()) {
   258     record_time_secs(phase, worker_i, secs);
   286     record_time_secs(phase, worker_id, secs);
   259   } else {
   287   } else {
   260     add_time_secs(phase, worker_i, secs);
   288     add_time_secs(phase, worker_id, secs);
   261   }
   289   }
   262 }
   290 }
   263 
   291 
   264 double G1GCPhaseTimes::get_time_secs(GCParPhases phase, uint worker_i) {
   292 double G1GCPhaseTimes::get_time_secs(GCParPhases phase, uint worker_id) {
   265   return _gc_par_phases[phase]->get(worker_i);
   293   return _gc_par_phases[phase]->get(worker_id);
   266 }
   294 }
   267 
   295 
   268 void G1GCPhaseTimes::record_thread_work_item(GCParPhases phase, uint worker_i, size_t count, uint index) {
   296 void G1GCPhaseTimes::record_thread_work_item(GCParPhases phase, uint worker_id, size_t count, uint index) {
   269   _gc_par_phases[phase]->set_thread_work_item(worker_i, count, index);
   297   _gc_par_phases[phase]->set_thread_work_item(worker_id, count, index);
   270 }
   298 }
   271 
   299 
   272 void G1GCPhaseTimes::record_or_add_thread_work_item(GCParPhases phase, uint worker_i, size_t count, uint index) {
   300 void G1GCPhaseTimes::record_or_add_thread_work_item(GCParPhases phase, uint worker_id, size_t count, uint index) {
   273   _gc_par_phases[phase]->set_or_add_thread_work_item(worker_i, count, index);
   301   _gc_par_phases[phase]->set_or_add_thread_work_item(worker_id, count, index);
   274 }
   302 }
   275 
   303 
   276 size_t G1GCPhaseTimes::get_thread_work_item(GCParPhases phase, uint worker_i, uint index) {
   304 size_t G1GCPhaseTimes::get_thread_work_item(GCParPhases phase, uint worker_id, uint index) {
   277   return _gc_par_phases[phase]->get_thread_work_item(worker_i, index);
   305   return _gc_par_phases[phase]->get_thread_work_item(worker_id, index);
   278 }
   306 }
   279 
   307 
   280 // return the average time for a phase in milliseconds
   308 // return the average time for a phase in milliseconds
   281 double G1GCPhaseTimes::average_time_ms(GCParPhases phase) {
   309 double G1GCPhaseTimes::average_time_ms(GCParPhases phase) {
   282   return _gc_par_phases[phase]->average() * 1000.0;
   310   return _gc_par_phases[phase]->average() * 1000.0;
   363 double G1GCPhaseTimes::print_pre_evacuate_collection_set() const {
   391 double G1GCPhaseTimes::print_pre_evacuate_collection_set() const {
   364   const double sum_ms = _root_region_scan_wait_time_ms +
   392   const double sum_ms = _root_region_scan_wait_time_ms +
   365                         _recorded_young_cset_choice_time_ms +
   393                         _recorded_young_cset_choice_time_ms +
   366                         _recorded_non_young_cset_choice_time_ms +
   394                         _recorded_non_young_cset_choice_time_ms +
   367                         _cur_region_register_time +
   395                         _cur_region_register_time +
       
   396                         _recorded_prepare_heap_roots_time_ms +
   368                         _recorded_clear_claimed_marks_time_ms;
   397                         _recorded_clear_claimed_marks_time_ms;
   369 
   398 
   370   info_time("Pre Evacuate Collection Set", sum_ms);
   399   info_time("Pre Evacuate Collection Set", sum_ms);
   371 
   400 
   372   if (_root_region_scan_wait_time_ms > 0.0) {
   401   if (_root_region_scan_wait_time_ms > 0.0) {
   378   if (G1EagerReclaimHumongousObjects) {
   407   if (G1EagerReclaimHumongousObjects) {
   379     trace_count("Humongous Total", _cur_fast_reclaim_humongous_total);
   408     trace_count("Humongous Total", _cur_fast_reclaim_humongous_total);
   380     trace_count("Humongous Candidate", _cur_fast_reclaim_humongous_candidates);
   409     trace_count("Humongous Candidate", _cur_fast_reclaim_humongous_candidates);
   381   }
   410   }
   382 
   411 
       
   412   debug_time("Prepare Heap Roots", _recorded_prepare_heap_roots_time_ms);
   383   if (_recorded_clear_claimed_marks_time_ms > 0.0) {
   413   if (_recorded_clear_claimed_marks_time_ms > 0.0) {
   384     debug_time("Clear Claimed Marks", _recorded_clear_claimed_marks_time_ms);
   414     debug_time("Clear Claimed Marks", _recorded_clear_claimed_marks_time_ms);
   385   }
   415   }
   386   return sum_ms;
   416   return sum_ms;
   387 }
   417 }
   388 
   418 
   389 double G1GCPhaseTimes::print_evacuate_optional_collection_set() const {
   419 double G1GCPhaseTimes::print_evacuate_optional_collection_set() const {
   390   const double sum_ms = _cur_optional_evac_ms;
   420   const double sum_ms = _cur_optional_evac_ms + _cur_optional_merge_heap_roots_time_ms;
   391   if (sum_ms > 0) {
   421   if (sum_ms > 0) {
   392     info_time("Evacuate Optional Collection Set", sum_ms);
   422     info_time("Merge Optional Heap Roots", _cur_optional_merge_heap_roots_time_ms);
   393     debug_phase(_gc_par_phases[OptScanRS]);
   423 
       
   424     debug_time("Prepare Optional Merge Heap Roots", _cur_optional_prepare_merge_heap_roots_time_ms);
       
   425     debug_phase(_gc_par_phases[OptMergeRS]);
       
   426 
       
   427     info_time("Evacuate Optional Collection Set", _cur_optional_evac_ms);
       
   428     debug_phase(_gc_par_phases[OptScanHR]);
   394     debug_phase(_gc_par_phases[OptObjCopy]);
   429     debug_phase(_gc_par_phases[OptObjCopy]);
   395     debug_phase(_gc_par_phases[OptCodeRoots]);
   430     debug_phase(_gc_par_phases[OptCodeRoots]);
   396     debug_phase(_gc_par_phases[OptTermination]);
   431     debug_phase(_gc_par_phases[OptTermination]);
   397   }
   432   }
   398   return sum_ms;
   433   return sum_ms;
   399 }
   434 }
   400 
   435 
   401 double G1GCPhaseTimes::print_evacuate_collection_set() const {
   436 double G1GCPhaseTimes::print_evacuate_initial_collection_set() const {
   402   const double sum_ms = _cur_collection_initial_evac_time_ms;
   437   info_time("Merge Heap Roots", _cur_merge_heap_roots_time_ms);
   403 
   438 
   404   info_time("Evacuate Collection Set", sum_ms);
   439   debug_time("Prepare Merge Heap Roots", _cur_prepare_merge_heap_roots_time_ms);
       
   440   debug_phase(_gc_par_phases[MergeER]);
       
   441   debug_phase(_gc_par_phases[MergeRS]);
       
   442   if (G1HotCardCache::default_use_cache()) {
       
   443     debug_phase(_gc_par_phases[MergeHCC]);
       
   444   }
       
   445   debug_phase(_gc_par_phases[MergeLB]);
       
   446 
       
   447   info_time("Evacuate Collection Set", _cur_collection_initial_evac_time_ms);
   405 
   448 
   406   trace_phase(_gc_par_phases[GCWorkerStart], false);
   449   trace_phase(_gc_par_phases[GCWorkerStart], false);
   407   debug_phase(_gc_par_phases[ExtRootScan]);
   450   debug_phase(_gc_par_phases[ExtRootScan]);
   408   for (int i = ExtRootScanSubPhasesFirst; i <= ExtRootScanSubPhasesLast; i++) {
   451   for (int i = ExtRootScanSubPhasesFirst; i <= ExtRootScanSubPhasesLast; i++) {
   409     trace_phase(_gc_par_phases[i]);
   452     trace_phase(_gc_par_phases[i]);
   410   }
   453   }
   411   if (G1HotCardCache::default_use_cache()) {
   454   debug_phase(_gc_par_phases[ScanHR]);
   412     debug_phase(_gc_par_phases[ScanHCC]);
       
   413   }
       
   414   debug_phase(_gc_par_phases[UpdateRS]);
       
   415   debug_phase(_gc_par_phases[ScanRS]);
       
   416   debug_phase(_gc_par_phases[CodeRoots]);
   455   debug_phase(_gc_par_phases[CodeRoots]);
   417   debug_phase(_gc_par_phases[ObjCopy]);
   456   debug_phase(_gc_par_phases[ObjCopy]);
   418   debug_phase(_gc_par_phases[Termination]);
   457   debug_phase(_gc_par_phases[Termination]);
   419   debug_phase(_gc_par_phases[Other]);
   458   debug_phase(_gc_par_phases[Other]);
   420   debug_phase(_gc_par_phases[GCWorkerTotal]);
   459   debug_phase(_gc_par_phases[GCWorkerTotal]);
   421   trace_phase(_gc_par_phases[GCWorkerEnd], false);
   460   trace_phase(_gc_par_phases[GCWorkerEnd], false);
   422 
   461 
   423   return sum_ms;
   462   return _cur_collection_initial_evac_time_ms + _cur_merge_heap_roots_time_ms;
   424 }
   463 }
   425 
   464 
   426 double G1GCPhaseTimes::print_post_evacuate_collection_set() const {
   465 double G1GCPhaseTimes::print_post_evacuate_collection_set() const {
   427   const double evac_fail_handling = _cur_evac_fail_recalc_used +
   466   const double evac_fail_handling = _cur_evac_fail_recalc_used +
   428                                     _cur_evac_fail_remove_self_forwards;
   467                                     _cur_evac_fail_remove_self_forwards;
   501     debug_time("Verify Before", _cur_verify_before_time_ms);
   540     debug_time("Verify Before", _cur_verify_before_time_ms);
   502   }
   541   }
   503 
   542 
   504   double accounted_ms = 0.0;
   543   double accounted_ms = 0.0;
   505   accounted_ms += print_pre_evacuate_collection_set();
   544   accounted_ms += print_pre_evacuate_collection_set();
   506   accounted_ms += print_evacuate_collection_set();
   545   accounted_ms += print_evacuate_initial_collection_set();
   507   accounted_ms += print_evacuate_optional_collection_set();
   546   accounted_ms += print_evacuate_optional_collection_set();
   508   accounted_ms += print_post_evacuate_collection_set();
   547   accounted_ms += print_post_evacuate_collection_set();
   509   print_other(accounted_ms);
   548   print_other(accounted_ms);
   510 
   549 
   511   if (_cur_verify_after_time_ms > 0.0) {
   550   if (_cur_verify_after_time_ms > 0.0) {
   524       "ManagementRoots",
   563       "ManagementRoots",
   525       "SystemDictionaryRoots",
   564       "SystemDictionaryRoots",
   526       "CLDGRoots",
   565       "CLDGRoots",
   527       "JVMTIRoots",
   566       "JVMTIRoots",
   528       AOT_ONLY("AOTCodeRoots" COMMA)
   567       AOT_ONLY("AOTCodeRoots" COMMA)
   529       JVMCI_ONLY("JVMCIRoots" COMMA)
       
   530       "CMRefRoots",
   568       "CMRefRoots",
   531       "WaitForStrongCLD",
   569       "WaitForStrongRoots",
   532       "WeakCLDRoots",
   570       "MergeER",
   533       "UpdateRS",
   571       "MergeRS",
   534       "ScanHCC",
   572       "OptMergeRS",
   535       "ScanRS",
   573       "MergeLB",
   536       "OptScanRS",
   574       "MergeHCC",
       
   575       "ScanHR",
       
   576       "OptScanHR",
   537       "CodeRoots",
   577       "CodeRoots",
   538       "OptCodeRoots",
   578       "OptCodeRoots",
   539       "ObjCopy",
   579       "ObjCopy",
   540       "OptObjCopy",
   580       "OptObjCopy",
   541       "Termination",
   581       "Termination",
   578   _trim_time += _pss->trim_ticks();
   618   _trim_time += _pss->trim_ticks();
   579   _pss->reset_trim_ticks();
   619   _pss->reset_trim_ticks();
   580   _stopped = true;
   620   _stopped = true;
   581 }
   621 }
   582 
   622 
   583 G1GCParPhaseTimesTracker::G1GCParPhaseTimesTracker(G1GCPhaseTimes* phase_times, G1GCPhaseTimes::GCParPhases phase, uint worker_id) :
   623 G1GCParPhaseTimesTracker::G1GCParPhaseTimesTracker(G1GCPhaseTimes* phase_times, G1GCPhaseTimes::GCParPhases phase, uint worker_id, bool must_record) :
   584   _start_time(), _phase(phase), _phase_times(phase_times), _worker_id(worker_id), _event() {
   624   _start_time(), _phase(phase), _phase_times(phase_times), _worker_id(worker_id), _event(), _must_record(must_record) {
   585   if (_phase_times != NULL) {
   625   if (_phase_times != NULL) {
   586     _start_time = Ticks::now();
   626     _start_time = Ticks::now();
   587   }
   627   }
   588 }
   628 }
   589 
   629 
   590 G1GCParPhaseTimesTracker::~G1GCParPhaseTimesTracker() {
   630 G1GCParPhaseTimesTracker::~G1GCParPhaseTimesTracker() {
   591   if (_phase_times != NULL) {
   631   if (_phase_times != NULL) {
   592     _phase_times->record_time_secs(_phase, _worker_id, (Ticks::now() - _start_time).seconds());
   632     if (_must_record) {
       
   633       _phase_times->record_time_secs(_phase, _worker_id, (Ticks::now() - _start_time).seconds());
       
   634     } else {
       
   635       _phase_times->record_or_add_time_secs(_phase, _worker_id, (Ticks::now() - _start_time).seconds());
       
   636     }
   593     _event.commit(GCId::current(), _worker_id, G1GCPhaseTimes::phase_name(_phase));
   637     _event.commit(GCId::current(), _worker_id, G1GCPhaseTimes::phase_name(_phase));
   594   }
   638   }
   595 }
   639 }
   596 
   640 
   597 G1EvacPhaseTimesTracker::G1EvacPhaseTimesTracker(G1GCPhaseTimes* phase_times,
   641 G1EvacPhaseTimesTracker::G1EvacPhaseTimesTracker(G1GCPhaseTimes* phase_times,