index

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

Print this page
rev 7209 : 6979279


 275 
 276     // Strong code root purge time
 277     misc_time_ms += _cur_strong_code_root_purge_time_ms;
 278 
 279     if (G1StringDedup::is_enabled()) {
 280       // String dedup fixup time
 281       misc_time_ms += _cur_string_dedup_fixup_time_ms;
 282     }
 283 
 284     // Subtract the time taken to clean the card table from the
 285     // current value of "other time"
 286     misc_time_ms += _cur_clear_ct_time_ms;
 287 
 288     return misc_time_ms;
 289 }
 290 
 291 void G1GCPhaseTimes::print(double pause_time_sec) {
 292   if (_root_region_scan_wait_time_ms > 0.0) {
 293     print_stats(1, "Root Region Scan Waiting", _root_region_scan_wait_time_ms);
 294   }
 295   if (G1CollectedHeap::use_parallel_gc_threads()) {
 296     print_stats(1, "Parallel Time", _cur_collection_par_time_ms, _active_gc_threads);
 297     _last_gc_worker_start_times_ms.print(2, "GC Worker Start (ms)");
 298     _last_ext_root_scan_times_ms.print(2, "Ext Root Scanning (ms)");
 299     if (_last_satb_filtering_times_ms.sum() > 0.0) {
 300       _last_satb_filtering_times_ms.print(2, "SATB Filtering (ms)");
 301     }
 302     _last_update_rs_times_ms.print(2, "Update RS (ms)");
 303       _last_update_rs_processed_buffers.print(3, "Processed Buffers");
 304     _last_scan_rs_times_ms.print(2, "Scan RS (ms)");
 305     _last_strong_code_root_scan_times_ms.print(2, "Code Root Scanning (ms)");
 306     _last_obj_copy_times_ms.print(2, "Object Copy (ms)");
 307     _last_termination_times_ms.print(2, "Termination (ms)");
 308     if (G1Log::finest()) {
 309       _last_termination_attempts.print(3, "Termination Attempts");
 310     }
 311     _last_gc_worker_other_times_ms.print(2, "GC Worker Other (ms)");
 312     _last_gc_worker_times_ms.print(2, "GC Worker Total (ms)");
 313     _last_gc_worker_end_times_ms.print(2, "GC Worker End (ms)");
 314   } else {
 315     _last_ext_root_scan_times_ms.print(1, "Ext Root Scanning (ms)");
 316     if (_last_satb_filtering_times_ms.sum() > 0.0) {
 317       _last_satb_filtering_times_ms.print(1, "SATB Filtering (ms)");
 318     }
 319     _last_update_rs_times_ms.print(1, "Update RS (ms)");
 320       _last_update_rs_processed_buffers.print(2, "Processed Buffers");
 321     _last_scan_rs_times_ms.print(1, "Scan RS (ms)");
 322     _last_strong_code_root_scan_times_ms.print(1, "Code Root Scanning (ms)");
 323     _last_obj_copy_times_ms.print(1, "Object Copy (ms)");
 324   }
 325   print_stats(1, "Code Root Fixup", _cur_collection_code_root_fixup_time_ms);
 326   print_stats(1, "Code Root Purge", _cur_strong_code_root_purge_time_ms);
 327   if (G1StringDedup::is_enabled()) {
 328     print_stats(1, "String Dedup Fixup", _cur_string_dedup_fixup_time_ms, _active_gc_threads);
 329     _cur_string_dedup_queue_fixup_worker_times_ms.print(2, "Queue Fixup (ms)");
 330     _cur_string_dedup_table_fixup_worker_times_ms.print(2, "Table Fixup (ms)");
 331   }
 332   print_stats(1, "Clear CT", _cur_clear_ct_time_ms);
 333   double misc_time_ms = pause_time_sec * MILLIUNITS - accounted_time_ms();
 334   print_stats(1, "Other", misc_time_ms);
 335   if (_cur_verify_before_time_ms > 0.0) {
 336     print_stats(2, "Verify Before", _cur_verify_before_time_ms);
 337   }
 338   if (G1CollectedHeap::heap()->evacuation_failed()) {
 339     double evac_fail_handling = _cur_evac_fail_recalc_used + _cur_evac_fail_remove_self_forwards +
 340       _cur_evac_fail_restore_remsets;
 341     print_stats(2, "Evacuation Failure", evac_fail_handling);
 342     if (G1Log::finest()) {
 343       print_stats(3, "Recalculate Used", _cur_evac_fail_recalc_used);
 344       print_stats(3, "Remove Self Forwards", _cur_evac_fail_remove_self_forwards);




 275 
 276     // Strong code root purge time
 277     misc_time_ms += _cur_strong_code_root_purge_time_ms;
 278 
 279     if (G1StringDedup::is_enabled()) {
 280       // String dedup fixup time
 281       misc_time_ms += _cur_string_dedup_fixup_time_ms;
 282     }
 283 
 284     // Subtract the time taken to clean the card table from the
 285     // current value of "other time"
 286     misc_time_ms += _cur_clear_ct_time_ms;
 287 
 288     return misc_time_ms;
 289 }
 290 
 291 void G1GCPhaseTimes::print(double pause_time_sec) {
 292   if (_root_region_scan_wait_time_ms > 0.0) {
 293     print_stats(1, "Root Region Scan Waiting", _root_region_scan_wait_time_ms);
 294   }

 295   print_stats(1, "Parallel Time", _cur_collection_par_time_ms, _active_gc_threads);
 296   _last_gc_worker_start_times_ms.print(2, "GC Worker Start (ms)");
 297   _last_ext_root_scan_times_ms.print(2, "Ext Root Scanning (ms)");
 298   if (_last_satb_filtering_times_ms.sum() > 0.0) {
 299     _last_satb_filtering_times_ms.print(2, "SATB Filtering (ms)");
 300   }
 301   _last_update_rs_times_ms.print(2, "Update RS (ms)");
 302     _last_update_rs_processed_buffers.print(3, "Processed Buffers");
 303   _last_scan_rs_times_ms.print(2, "Scan RS (ms)");
 304   _last_strong_code_root_scan_times_ms.print(2, "Code Root Scanning (ms)");
 305   _last_obj_copy_times_ms.print(2, "Object Copy (ms)");
 306   _last_termination_times_ms.print(2, "Termination (ms)");
 307   if (G1Log::finest()) {
 308     _last_termination_attempts.print(3, "Termination Attempts");
 309   }
 310   _last_gc_worker_other_times_ms.print(2, "GC Worker Other (ms)");
 311   _last_gc_worker_times_ms.print(2, "GC Worker Total (ms)");
 312   _last_gc_worker_end_times_ms.print(2, "GC Worker End (ms)");
 313 










 314   print_stats(1, "Code Root Fixup", _cur_collection_code_root_fixup_time_ms);
 315   print_stats(1, "Code Root Purge", _cur_strong_code_root_purge_time_ms);
 316   if (G1StringDedup::is_enabled()) {
 317     print_stats(1, "String Dedup Fixup", _cur_string_dedup_fixup_time_ms, _active_gc_threads);
 318     _cur_string_dedup_queue_fixup_worker_times_ms.print(2, "Queue Fixup (ms)");
 319     _cur_string_dedup_table_fixup_worker_times_ms.print(2, "Table Fixup (ms)");
 320   }
 321   print_stats(1, "Clear CT", _cur_clear_ct_time_ms);
 322   double misc_time_ms = pause_time_sec * MILLIUNITS - accounted_time_ms();
 323   print_stats(1, "Other", misc_time_ms);
 324   if (_cur_verify_before_time_ms > 0.0) {
 325     print_stats(2, "Verify Before", _cur_verify_before_time_ms);
 326   }
 327   if (G1CollectedHeap::heap()->evacuation_failed()) {
 328     double evac_fail_handling = _cur_evac_fail_recalc_used + _cur_evac_fail_remove_self_forwards +
 329       _cur_evac_fail_restore_remsets;
 330     print_stats(2, "Evacuation Failure", evac_fail_handling);
 331     if (G1Log::finest()) {
 332       print_stats(3, "Recalculate Used", _cur_evac_fail_recalc_used);
 333       print_stats(3, "Remove Self Forwards", _cur_evac_fail_remove_self_forwards);


index