139 |
139 |
140 _summary(new Summary()), |
140 _summary(new Summary()), |
141 |
141 |
142 _cur_clear_ct_time_ms(0.0), |
142 _cur_clear_ct_time_ms(0.0), |
143 _mark_closure_time_ms(0.0), |
143 _mark_closure_time_ms(0.0), |
|
144 _root_region_scan_wait_time_ms(0.0), |
144 |
145 |
145 _cur_ref_proc_time_ms(0.0), |
146 _cur_ref_proc_time_ms(0.0), |
146 _cur_ref_enq_time_ms(0.0), |
147 _cur_ref_enq_time_ms(0.0), |
147 |
148 |
148 #ifndef PRODUCT |
149 #ifndef PRODUCT |
901 gclog_or_tty->stamp(PrintGCTimeStamps); |
902 gclog_or_tty->stamp(PrintGCTimeStamps); |
902 gclog_or_tty->print("[GC pause"); |
903 gclog_or_tty->print("[GC pause"); |
903 gclog_or_tty->print(" (%s)", gcs_are_young() ? "young" : "mixed"); |
904 gclog_or_tty->print(" (%s)", gcs_are_young() ? "young" : "mixed"); |
904 } |
905 } |
905 |
906 |
906 if (!during_initial_mark_pause()) { |
907 // We only need to do this here as the policy will only be applied |
907 // We only need to do this here as the policy will only be applied |
908 // to the GC we're about to start. so, no point is calculating this |
908 // to the GC we're about to start. so, no point is calculating this |
909 // every time we calculate / recalculate the target young length. |
909 // every time we calculate / recalculate the target young length. |
910 update_survivors_policy(); |
910 update_survivors_policy(); |
|
911 } else { |
|
912 // The marking phase has a "we only copy implicitly live |
|
913 // objects during marking" invariant. The easiest way to ensure it |
|
914 // holds is not to allocate any survivor regions and tenure all |
|
915 // objects. In the future we might change this and handle survivor |
|
916 // regions specially during marking. |
|
917 tenure_all_objects(); |
|
918 } |
|
919 |
911 |
920 assert(_g1->used() == _g1->recalculate_used(), |
912 assert(_g1->used() == _g1->recalculate_used(), |
921 err_msg("sanity, used: "SIZE_FORMAT" recalculate_used: "SIZE_FORMAT, |
913 err_msg("sanity, used: "SIZE_FORMAT" recalculate_used: "SIZE_FORMAT, |
922 _g1->used(), _g1->recalculate_used())); |
914 _g1->used(), _g1->recalculate_used())); |
923 |
915 |
965 } |
957 } |
966 |
958 |
967 // This is initialized to zero here and is set during |
959 // This is initialized to zero here and is set during |
968 // the evacuation pause if marking is in progress. |
960 // the evacuation pause if marking is in progress. |
969 _cur_satb_drain_time_ms = 0.0; |
961 _cur_satb_drain_time_ms = 0.0; |
|
962 // This is initialized to zero here and is set during the evacuation |
|
963 // pause if we actually waited for the root region scanning to finish. |
|
964 _root_region_scan_wait_time_ms = 0.0; |
970 |
965 |
971 _last_gc_was_young = false; |
966 _last_gc_was_young = false; |
972 |
967 |
973 // do that for any other surv rate groups |
968 // do that for any other surv rate groups |
974 _short_lived_surv_rate_group->stop_adding_regions(); |
969 _short_lived_surv_rate_group->stop_adding_regions(); |
1269 // Subtract the SATB drain time. It's initialized to zero at the |
1264 // Subtract the SATB drain time. It's initialized to zero at the |
1270 // start of the pause and is updated during the pause if marking |
1265 // start of the pause and is updated during the pause if marking |
1271 // is in progress. |
1266 // is in progress. |
1272 other_time_ms -= _cur_satb_drain_time_ms; |
1267 other_time_ms -= _cur_satb_drain_time_ms; |
1273 |
1268 |
|
1269 // Subtract the root region scanning wait time. It's initialized to |
|
1270 // zero at the start of the pause. |
|
1271 other_time_ms -= _root_region_scan_wait_time_ms; |
|
1272 |
1274 if (parallel) { |
1273 if (parallel) { |
1275 other_time_ms -= _cur_collection_par_time_ms; |
1274 other_time_ms -= _cur_collection_par_time_ms; |
1276 } else { |
1275 } else { |
1277 other_time_ms -= known_time; |
1276 other_time_ms -= known_time; |
1278 } |
1277 } |
1301 // an initial mark pause. Since the body_summary items are NumberSeqs, |
1300 // an initial mark pause. Since the body_summary items are NumberSeqs, |
1302 // however, they have to be consistent and updated in lock-step with |
1301 // however, they have to be consistent and updated in lock-step with |
1303 // each other. Therefore we unconditionally record the SATB drain |
1302 // each other. Therefore we unconditionally record the SATB drain |
1304 // time - even if it's zero. |
1303 // time - even if it's zero. |
1305 body_summary->record_satb_drain_time_ms(_cur_satb_drain_time_ms); |
1304 body_summary->record_satb_drain_time_ms(_cur_satb_drain_time_ms); |
|
1305 body_summary->record_root_region_scan_wait_time_ms( |
|
1306 _root_region_scan_wait_time_ms); |
1306 |
1307 |
1307 body_summary->record_ext_root_scan_time_ms(ext_root_scan_time); |
1308 body_summary->record_ext_root_scan_time_ms(ext_root_scan_time); |
1308 body_summary->record_satb_filtering_time_ms(satb_filtering_time); |
1309 body_summary->record_satb_filtering_time_ms(satb_filtering_time); |
1309 body_summary->record_update_rs_time_ms(update_rs_time); |
1310 body_summary->record_update_rs_time_ms(update_rs_time); |
1310 body_summary->record_scan_rs_time_ms(scan_rs_time); |
1311 body_summary->record_scan_rs_time_ms(scan_rs_time); |
1397 |
1398 |
1398 gclog_or_tty->print_cr("%s, %1.8lf secs]", |
1399 gclog_or_tty->print_cr("%s, %1.8lf secs]", |
1399 (last_pause_included_initial_mark) ? " (initial-mark)" : "", |
1400 (last_pause_included_initial_mark) ? " (initial-mark)" : "", |
1400 elapsed_ms / 1000.0); |
1401 elapsed_ms / 1000.0); |
1401 |
1402 |
|
1403 if (_root_region_scan_wait_time_ms > 0.0) { |
|
1404 print_stats(1, "Root Region Scan Waiting", _root_region_scan_wait_time_ms); |
|
1405 } |
1402 if (parallel) { |
1406 if (parallel) { |
1403 print_stats(1, "Parallel Time", _cur_collection_par_time_ms); |
1407 print_stats(1, "Parallel Time", _cur_collection_par_time_ms); |
1404 print_par_stats(2, "GC Worker Start", _par_last_gc_worker_start_times_ms); |
1408 print_par_stats(2, "GC Worker Start", _par_last_gc_worker_start_times_ms); |
1405 print_par_stats(2, "Ext Root Scanning", _par_last_ext_root_scan_times_ms); |
1409 print_par_stats(2, "Ext Root Scanning", _par_last_ext_root_scan_times_ms); |
1406 if (print_marking_info) { |
1410 if (print_marking_info) { |
2000 bool parallel = G1CollectedHeap::use_parallel_gc_threads(); |
2004 bool parallel = G1CollectedHeap::use_parallel_gc_threads(); |
2001 MainBodySummary* body_summary = summary->main_body_summary(); |
2005 MainBodySummary* body_summary = summary->main_body_summary(); |
2002 if (summary->get_total_seq()->num() > 0) { |
2006 if (summary->get_total_seq()->num() > 0) { |
2003 print_summary_sd(0, "Evacuation Pauses", summary->get_total_seq()); |
2007 print_summary_sd(0, "Evacuation Pauses", summary->get_total_seq()); |
2004 if (body_summary != NULL) { |
2008 if (body_summary != NULL) { |
|
2009 print_summary(1, "Root Region Scan Wait", body_summary->get_root_region_scan_wait_seq()); |
2005 if (parallel) { |
2010 if (parallel) { |
2006 print_summary(1, "Parallel Time", body_summary->get_parallel_seq()); |
2011 print_summary(1, "Parallel Time", body_summary->get_parallel_seq()); |
2007 print_summary(2, "Ext Root Scanning", body_summary->get_ext_root_scan_seq()); |
2012 print_summary(2, "Ext Root Scanning", body_summary->get_ext_root_scan_seq()); |
2008 print_summary(2, "SATB Filtering", body_summary->get_satb_filtering_seq()); |
2013 print_summary(2, "SATB Filtering", body_summary->get_satb_filtering_seq()); |
2009 print_summary(2, "Update RS", body_summary->get_update_rs_seq()); |
2014 print_summary(2, "Update RS", body_summary->get_update_rs_seq()); |
2041 NumberSeq calc_other_times_ms; |
2046 NumberSeq calc_other_times_ms; |
2042 if (parallel) { |
2047 if (parallel) { |
2043 // parallel |
2048 // parallel |
2044 NumberSeq* other_parts[] = { |
2049 NumberSeq* other_parts[] = { |
2045 body_summary->get_satb_drain_seq(), |
2050 body_summary->get_satb_drain_seq(), |
|
2051 body_summary->get_root_region_scan_wait_seq(), |
2046 body_summary->get_parallel_seq(), |
2052 body_summary->get_parallel_seq(), |
2047 body_summary->get_clear_ct_seq() |
2053 body_summary->get_clear_ct_seq() |
2048 }; |
2054 }; |
2049 calc_other_times_ms = NumberSeq(summary->get_total_seq(), |
2055 calc_other_times_ms = NumberSeq(summary->get_total_seq(), |
2050 3, other_parts); |
2056 4, other_parts); |
2051 } else { |
2057 } else { |
2052 // serial |
2058 // serial |
2053 NumberSeq* other_parts[] = { |
2059 NumberSeq* other_parts[] = { |
2054 body_summary->get_satb_drain_seq(), |
2060 body_summary->get_satb_drain_seq(), |
|
2061 body_summary->get_root_region_scan_wait_seq(), |
2055 body_summary->get_update_rs_seq(), |
2062 body_summary->get_update_rs_seq(), |
2056 body_summary->get_ext_root_scan_seq(), |
2063 body_summary->get_ext_root_scan_seq(), |
2057 body_summary->get_satb_filtering_seq(), |
2064 body_summary->get_satb_filtering_seq(), |
2058 body_summary->get_scan_rs_seq(), |
2065 body_summary->get_scan_rs_seq(), |
2059 body_summary->get_obj_copy_seq() |
2066 body_summary->get_obj_copy_seq() |
2060 }; |
2067 }; |
2061 calc_other_times_ms = NumberSeq(summary->get_total_seq(), |
2068 calc_other_times_ms = NumberSeq(summary->get_total_seq(), |
2062 6, other_parts); |
2069 7, other_parts); |
2063 } |
2070 } |
2064 check_other_times(1, summary->get_other_seq(), &calc_other_times_ms); |
2071 check_other_times(1, summary->get_other_seq(), &calc_other_times_ms); |
2065 } |
2072 } |
2066 } |
2073 } |
2067 } else { |
2074 } else { |