< prev index next >

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

Print this page
rev 49826 : imported patch 6672778-partial-queue-trimming
rev 49827 : imported patch 6672778-refactoring
rev 49828 : imported patch 6672778-stefanj-review
rev 49829 : imported patch 6672778-inconsistent-time-fixes
rev 49830 : [mq]: 6672778-satb-timing-fix
rev 49831 : imported patch 8201492-properly-implement-non-contiguous-reference-processing
rev 49833 : imported patch 8202018-move-card-table-clear
rev 49836 : [mq]: 8202017-reference-processor-remove-enqueue


 112 
 113   _gc_par_phases[YoungFreeCSet] = new WorkerDataArray<double>(max_gc_threads, "Young Free Collection Set (ms):");
 114   _gc_par_phases[NonYoungFreeCSet] = new WorkerDataArray<double>(max_gc_threads, "Non-Young Free Collection Set (ms):");
 115 
 116   reset();
 117 }
 118 
 119 void G1GCPhaseTimes::reset() {
 120   _cur_collection_par_time_ms = 0.0;
 121   _cur_collection_code_root_fixup_time_ms = 0.0;
 122   _cur_strong_code_root_purge_time_ms = 0.0;
 123   _cur_evac_fail_recalc_used = 0.0;
 124   _cur_evac_fail_remove_self_forwards = 0.0;
 125   _cur_string_dedup_fixup_time_ms = 0.0;
 126   _cur_prepare_tlab_time_ms = 0.0;
 127   _cur_resize_tlab_time_ms = 0.0;
 128   _cur_derived_pointer_table_update_time_ms = 0.0;
 129   _cur_clear_ct_time_ms = 0.0;
 130   _cur_expand_heap_time_ms = 0.0;
 131   _cur_ref_proc_time_ms = 0.0;
 132   _cur_ref_enq_time_ms = 0.0;
 133   _cur_weak_ref_proc_time_ms = 0.0;
 134   _cur_collection_start_sec = 0.0;
 135   _root_region_scan_wait_time_ms = 0.0;
 136   _external_accounted_time_ms = 0.0;
 137   _recorded_clear_claimed_marks_time_ms = 0.0;
 138   _recorded_young_cset_choice_time_ms = 0.0;
 139   _recorded_non_young_cset_choice_time_ms = 0.0;
 140   _recorded_redirty_logged_cards_time_ms = 0.0;
 141   _recorded_preserve_cm_referents_time_ms = 0.0;
 142   _recorded_merge_pss_time_ms = 0.0;
 143   _recorded_start_new_cset_time_ms = 0.0;
 144   _recorded_total_free_cset_time_ms = 0.0;
 145   _recorded_serial_free_cset_time_ms = 0.0;
 146   _cur_fast_reclaim_humongous_time_ms = 0.0;
 147   _cur_fast_reclaim_humongous_register_time_ms = 0.0;
 148   _cur_fast_reclaim_humongous_total = 0;
 149   _cur_fast_reclaim_humongous_candidates = 0;
 150   _cur_fast_reclaim_humongous_reclaimed = 0;
 151   _cur_verify_before_time_ms = 0.0;
 152   _cur_verify_after_time_ms = 0.0;


 366 #if INCLUDE_AOT
 367   debug_phase(_gc_par_phases[AOTCodeRoots]);
 368 #endif
 369   debug_phase(_gc_par_phases[ObjCopy]);
 370   debug_phase(_gc_par_phases[Termination]);
 371   debug_phase(_gc_par_phases[Other]);
 372   debug_phase(_gc_par_phases[GCWorkerTotal]);
 373   trace_phase(_gc_par_phases[GCWorkerEnd], false);
 374 
 375   return sum_ms;
 376 }
 377 
 378 double G1GCPhaseTimes::print_post_evacuate_collection_set() const {
 379   const double evac_fail_handling = _cur_evac_fail_recalc_used +
 380                                     _cur_evac_fail_remove_self_forwards;
 381   const double sum_ms = evac_fail_handling +
 382                         _cur_collection_code_root_fixup_time_ms +
 383                         _recorded_preserve_cm_referents_time_ms +
 384                         _cur_ref_proc_time_ms +
 385                         _cur_weak_ref_proc_time_ms +
 386                         _cur_ref_enq_time_ms +
 387                         _cur_clear_ct_time_ms +
 388                         _recorded_merge_pss_time_ms +
 389                         _cur_strong_code_root_purge_time_ms +
 390                         _recorded_redirty_logged_cards_time_ms +
 391                         _recorded_total_free_cset_time_ms +
 392                         _cur_fast_reclaim_humongous_time_ms +
 393                         _cur_expand_heap_time_ms +
 394                         _cur_string_dedup_fixup_time_ms;
 395 
 396   info_time("Post Evacuate Collection Set", sum_ms);
 397 
 398   debug_time("Code Roots Fixup", _cur_collection_code_root_fixup_time_ms);
 399 
 400   debug_time("Clear Card Table", _cur_clear_ct_time_ms);
 401 
 402   debug_time_for_reference("Reference Processing", _cur_ref_proc_time_ms);
 403   _ref_phase_times.print_all_references(2, false);
 404 
 405   debug_time("Weak Processing", _cur_weak_ref_proc_time_ms);
 406 
 407   if (G1StringDedup::is_enabled()) {
 408     debug_time("String Dedup Fixup", _cur_string_dedup_fixup_time_ms);
 409     debug_phase(_gc_par_phases[StringDedupQueueFixup]);
 410     debug_phase(_gc_par_phases[StringDedupTableFixup]);
 411   }
 412 
 413   if (G1CollectedHeap::heap()->evacuation_failed()) {
 414     debug_time("Evacuation Failure", evac_fail_handling);
 415     trace_time("Recalculate Used", _cur_evac_fail_recalc_used);
 416     trace_time("Remove Self Forwards",_cur_evac_fail_remove_self_forwards);
 417   }
 418 
 419   debug_time_for_reference("Reference Enqueuing", _cur_ref_enq_time_ms);
 420   _ref_phase_times.print_enqueue_phase(2, false);
 421 
 422   debug_time("Merge Per-Thread State", _recorded_merge_pss_time_ms);
 423   debug_time("Code Roots Purge", _cur_strong_code_root_purge_time_ms);
 424 
 425   debug_time("Redirty Cards", _recorded_redirty_logged_cards_time_ms);
 426   trace_phase(_gc_par_phases[RedirtyCards]);
 427 #if COMPILER2_OR_JVMCI
 428   debug_time("DerivedPointerTable Update", _cur_derived_pointer_table_update_time_ms);
 429 #endif
 430 
 431   debug_time("Free Collection Set", _recorded_total_free_cset_time_ms);
 432   trace_time("Free Collection Set Serial", _recorded_serial_free_cset_time_ms);
 433   trace_phase(_gc_par_phases[YoungFreeCSet]);
 434   trace_phase(_gc_par_phases[NonYoungFreeCSet]);
 435 
 436   if (G1EagerReclaimHumongousObjects) {
 437     debug_time("Humongous Reclaim", _cur_fast_reclaim_humongous_time_ms);
 438     trace_count("Humongous Reclaimed", _cur_fast_reclaim_humongous_reclaimed);
 439   }
 440   debug_time("Start New Collection Set", _recorded_start_new_cset_time_ms);




 112 
 113   _gc_par_phases[YoungFreeCSet] = new WorkerDataArray<double>(max_gc_threads, "Young Free Collection Set (ms):");
 114   _gc_par_phases[NonYoungFreeCSet] = new WorkerDataArray<double>(max_gc_threads, "Non-Young Free Collection Set (ms):");
 115 
 116   reset();
 117 }
 118 
 119 void G1GCPhaseTimes::reset() {
 120   _cur_collection_par_time_ms = 0.0;
 121   _cur_collection_code_root_fixup_time_ms = 0.0;
 122   _cur_strong_code_root_purge_time_ms = 0.0;
 123   _cur_evac_fail_recalc_used = 0.0;
 124   _cur_evac_fail_remove_self_forwards = 0.0;
 125   _cur_string_dedup_fixup_time_ms = 0.0;
 126   _cur_prepare_tlab_time_ms = 0.0;
 127   _cur_resize_tlab_time_ms = 0.0;
 128   _cur_derived_pointer_table_update_time_ms = 0.0;
 129   _cur_clear_ct_time_ms = 0.0;
 130   _cur_expand_heap_time_ms = 0.0;
 131   _cur_ref_proc_time_ms = 0.0;

 132   _cur_weak_ref_proc_time_ms = 0.0;
 133   _cur_collection_start_sec = 0.0;
 134   _root_region_scan_wait_time_ms = 0.0;
 135   _external_accounted_time_ms = 0.0;
 136   _recorded_clear_claimed_marks_time_ms = 0.0;
 137   _recorded_young_cset_choice_time_ms = 0.0;
 138   _recorded_non_young_cset_choice_time_ms = 0.0;
 139   _recorded_redirty_logged_cards_time_ms = 0.0;
 140   _recorded_preserve_cm_referents_time_ms = 0.0;
 141   _recorded_merge_pss_time_ms = 0.0;
 142   _recorded_start_new_cset_time_ms = 0.0;
 143   _recorded_total_free_cset_time_ms = 0.0;
 144   _recorded_serial_free_cset_time_ms = 0.0;
 145   _cur_fast_reclaim_humongous_time_ms = 0.0;
 146   _cur_fast_reclaim_humongous_register_time_ms = 0.0;
 147   _cur_fast_reclaim_humongous_total = 0;
 148   _cur_fast_reclaim_humongous_candidates = 0;
 149   _cur_fast_reclaim_humongous_reclaimed = 0;
 150   _cur_verify_before_time_ms = 0.0;
 151   _cur_verify_after_time_ms = 0.0;


 365 #if INCLUDE_AOT
 366   debug_phase(_gc_par_phases[AOTCodeRoots]);
 367 #endif
 368   debug_phase(_gc_par_phases[ObjCopy]);
 369   debug_phase(_gc_par_phases[Termination]);
 370   debug_phase(_gc_par_phases[Other]);
 371   debug_phase(_gc_par_phases[GCWorkerTotal]);
 372   trace_phase(_gc_par_phases[GCWorkerEnd], false);
 373 
 374   return sum_ms;
 375 }
 376 
 377 double G1GCPhaseTimes::print_post_evacuate_collection_set() const {
 378   const double evac_fail_handling = _cur_evac_fail_recalc_used +
 379                                     _cur_evac_fail_remove_self_forwards;
 380   const double sum_ms = evac_fail_handling +
 381                         _cur_collection_code_root_fixup_time_ms +
 382                         _recorded_preserve_cm_referents_time_ms +
 383                         _cur_ref_proc_time_ms +
 384                         _cur_weak_ref_proc_time_ms +

 385                         _cur_clear_ct_time_ms +
 386                         _recorded_merge_pss_time_ms +
 387                         _cur_strong_code_root_purge_time_ms +
 388                         _recorded_redirty_logged_cards_time_ms +
 389                         _recorded_total_free_cset_time_ms +
 390                         _cur_fast_reclaim_humongous_time_ms +
 391                         _cur_expand_heap_time_ms +
 392                         _cur_string_dedup_fixup_time_ms;
 393 
 394   info_time("Post Evacuate Collection Set", sum_ms);
 395 
 396   debug_time("Code Roots Fixup", _cur_collection_code_root_fixup_time_ms);
 397 
 398   debug_time("Clear Card Table", _cur_clear_ct_time_ms);
 399 
 400   debug_time_for_reference("Reference Processing", _cur_ref_proc_time_ms);
 401   _ref_phase_times.print_all_references(2, false);
 402 
 403   debug_time("Weak Processing", _cur_weak_ref_proc_time_ms);
 404 
 405   if (G1StringDedup::is_enabled()) {
 406     debug_time("String Dedup Fixup", _cur_string_dedup_fixup_time_ms);
 407     debug_phase(_gc_par_phases[StringDedupQueueFixup]);
 408     debug_phase(_gc_par_phases[StringDedupTableFixup]);
 409   }
 410 
 411   if (G1CollectedHeap::heap()->evacuation_failed()) {
 412     debug_time("Evacuation Failure", evac_fail_handling);
 413     trace_time("Recalculate Used", _cur_evac_fail_recalc_used);
 414     trace_time("Remove Self Forwards",_cur_evac_fail_remove_self_forwards);
 415   }



 416 
 417   debug_time("Merge Per-Thread State", _recorded_merge_pss_time_ms);
 418   debug_time("Code Roots Purge", _cur_strong_code_root_purge_time_ms);
 419 
 420   debug_time("Redirty Cards", _recorded_redirty_logged_cards_time_ms);
 421   trace_phase(_gc_par_phases[RedirtyCards]);
 422 #if COMPILER2_OR_JVMCI
 423   debug_time("DerivedPointerTable Update", _cur_derived_pointer_table_update_time_ms);
 424 #endif
 425 
 426   debug_time("Free Collection Set", _recorded_total_free_cset_time_ms);
 427   trace_time("Free Collection Set Serial", _recorded_serial_free_cset_time_ms);
 428   trace_phase(_gc_par_phases[YoungFreeCSet]);
 429   trace_phase(_gc_par_phases[NonYoungFreeCSet]);
 430 
 431   if (G1EagerReclaimHumongousObjects) {
 432     debug_time("Humongous Reclaim", _cur_fast_reclaim_humongous_time_ms);
 433     trace_count("Humongous Reclaimed", _cur_fast_reclaim_humongous_reclaimed);
 434   }
 435   debug_time("Start New Collection Set", _recorded_start_new_cset_time_ms);


< prev index next >