138 _all_yield_times_ms(new NumberSeq()), |
138 _all_yield_times_ms(new NumberSeq()), |
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), |
|
144 _root_region_scan_wait_time_ms(0.0), |
143 _root_region_scan_wait_time_ms(0.0), |
145 |
144 |
146 _cur_ref_proc_time_ms(0.0), |
145 _cur_ref_proc_time_ms(0.0), |
147 _cur_ref_enq_time_ms(0.0), |
146 _cur_ref_enq_time_ms(0.0), |
148 |
147 |
942 for (int i = 0; i < _aux_num; ++i) { |
941 for (int i = 0; i < _aux_num; ++i) { |
943 _cur_aux_times_ms[i] = 0.0; |
942 _cur_aux_times_ms[i] = 0.0; |
944 _cur_aux_times_set[i] = false; |
943 _cur_aux_times_set[i] = false; |
945 } |
944 } |
946 |
945 |
947 // This is initialized to zero here and is set during |
|
948 // the evacuation pause if marking is in progress. |
|
949 _cur_satb_drain_time_ms = 0.0; |
|
950 // This is initialized to zero here and is set during the evacuation |
946 // This is initialized to zero here and is set during the evacuation |
951 // pause if we actually waited for the root region scanning to finish. |
947 // pause if we actually waited for the root region scanning to finish. |
952 _root_region_scan_wait_time_ms = 0.0; |
948 _root_region_scan_wait_time_ms = 0.0; |
953 |
949 |
954 _last_gc_was_young = false; |
950 _last_gc_was_young = false; |
1266 |
1257 |
1267 // Subtract the time taken to clean the card table from the |
1258 // Subtract the time taken to clean the card table from the |
1268 // current value of "other time" |
1259 // current value of "other time" |
1269 other_time_ms -= _cur_clear_ct_time_ms; |
1260 other_time_ms -= _cur_clear_ct_time_ms; |
1270 |
1261 |
1271 // Subtract the time spent completing marking in the collection |
|
1272 // set. Note if marking is not in progress during the pause |
|
1273 // the value of _mark_closure_time_ms will be zero. |
|
1274 other_time_ms -= _mark_closure_time_ms; |
|
1275 |
|
1276 // TraceGen0Time and TraceGen1Time summary info updating. |
1262 // TraceGen0Time and TraceGen1Time summary info updating. |
1277 _all_pause_times_ms->add(elapsed_ms); |
1263 _all_pause_times_ms->add(elapsed_ms); |
1278 |
1264 |
1279 if (update_stats) { |
1265 if (update_stats) { |
1280 _summary->record_total_time_ms(elapsed_ms); |
1266 _summary->record_total_time_ms(elapsed_ms); |
1281 _summary->record_other_time_ms(other_time_ms); |
1267 _summary->record_other_time_ms(other_time_ms); |
1282 |
1268 |
1283 MainBodySummary* body_summary = _summary->main_body_summary(); |
1269 MainBodySummary* body_summary = _summary->main_body_summary(); |
1284 assert(body_summary != NULL, "should not be null!"); |
1270 assert(body_summary != NULL, "should not be null!"); |
1285 |
1271 |
1286 // This will be non-zero iff marking is currently in progress (i.e. |
|
1287 // _g1->mark_in_progress() == true) and the currrent pause was not |
|
1288 // an initial mark pause. Since the body_summary items are NumberSeqs, |
|
1289 // however, they have to be consistent and updated in lock-step with |
|
1290 // each other. Therefore we unconditionally record the SATB drain |
|
1291 // time - even if it's zero. |
|
1292 body_summary->record_satb_drain_time_ms(_cur_satb_drain_time_ms); |
|
1293 body_summary->record_root_region_scan_wait_time_ms( |
1272 body_summary->record_root_region_scan_wait_time_ms( |
1294 _root_region_scan_wait_time_ms); |
1273 _root_region_scan_wait_time_ms); |
1295 |
|
1296 body_summary->record_ext_root_scan_time_ms(ext_root_scan_time); |
1274 body_summary->record_ext_root_scan_time_ms(ext_root_scan_time); |
1297 body_summary->record_satb_filtering_time_ms(satb_filtering_time); |
1275 body_summary->record_satb_filtering_time_ms(satb_filtering_time); |
1298 body_summary->record_update_rs_time_ms(update_rs_time); |
1276 body_summary->record_update_rs_time_ms(update_rs_time); |
1299 body_summary->record_scan_rs_time_ms(scan_rs_time); |
1277 body_summary->record_scan_rs_time_ms(scan_rs_time); |
1300 body_summary->record_obj_copy_time_ms(obj_copy_time); |
1278 body_summary->record_obj_copy_time_ms(obj_copy_time); |
1306 double parallel_known_time = known_time + termination_time; |
1284 double parallel_known_time = known_time + termination_time; |
1307 double parallel_other_time = _cur_collection_par_time_ms - parallel_known_time; |
1285 double parallel_other_time = _cur_collection_par_time_ms - parallel_known_time; |
1308 body_summary->record_parallel_other_time_ms(parallel_other_time); |
1286 body_summary->record_parallel_other_time_ms(parallel_other_time); |
1309 } |
1287 } |
1310 |
1288 |
1311 body_summary->record_mark_closure_time_ms(_mark_closure_time_ms); |
|
1312 body_summary->record_clear_ct_time_ms(_cur_clear_ct_time_ms); |
1289 body_summary->record_clear_ct_time_ms(_cur_clear_ct_time_ms); |
1313 |
1290 |
1314 // We exempt parallel collection from this check because Alloc Buffer |
1291 // We exempt parallel collection from this check because Alloc Buffer |
1315 // fragmentation can produce negative collections. Same with evac |
1292 // fragmentation can produce negative collections. Same with evac |
1316 // failure. |
1293 // failure. |
1432 print_stats(2, "Processed Buffers", (int)update_rs_processed_buffers); |
1409 print_stats(2, "Processed Buffers", (int)update_rs_processed_buffers); |
1433 print_stats(1, "Scan RS", scan_rs_time); |
1410 print_stats(1, "Scan RS", scan_rs_time); |
1434 print_stats(1, "Object Copying", obj_copy_time); |
1411 print_stats(1, "Object Copying", obj_copy_time); |
1435 } |
1412 } |
1436 print_stats(1, "Code Root Fixup", _cur_collection_code_root_fixup_time_ms); |
1413 print_stats(1, "Code Root Fixup", _cur_collection_code_root_fixup_time_ms); |
1437 if (print_marking_info) { |
|
1438 print_stats(1, "Complete CSet Marking", _mark_closure_time_ms); |
|
1439 } |
|
1440 print_stats(1, "Clear CT", _cur_clear_ct_time_ms); |
1414 print_stats(1, "Clear CT", _cur_clear_ct_time_ms); |
1441 #ifndef PRODUCT |
1415 #ifndef PRODUCT |
1442 print_stats(1, "Cur Clear CC", _cur_clear_cc_time_ms); |
1416 print_stats(1, "Cur Clear CC", _cur_clear_cc_time_ms); |
1443 print_stats(1, "Cum Clear CC", _cum_clear_cc_time_ms); |
1417 print_stats(1, "Cum Clear CC", _cum_clear_cc_time_ms); |
1444 print_stats(1, "Min Clear CC", _min_clear_cc_time_ms); |
1418 print_stats(1, "Min Clear CC", _min_clear_cc_time_ms); |
1582 _cost_per_byte_ms_seq->add(cost_per_byte_ms); |
1556 _cost_per_byte_ms_seq->add(cost_per_byte_ms); |
1583 } |
1557 } |
1584 } |
1558 } |
1585 |
1559 |
1586 double all_other_time_ms = pause_time_ms - |
1560 double all_other_time_ms = pause_time_ms - |
1587 (update_rs_time + scan_rs_time + obj_copy_time + |
1561 (update_rs_time + scan_rs_time + obj_copy_time + termination_time); |
1588 _mark_closure_time_ms + termination_time); |
|
1589 |
1562 |
1590 double young_other_time_ms = 0.0; |
1563 double young_other_time_ms = 0.0; |
1591 if (young_cset_region_length() > 0) { |
1564 if (young_cset_region_length() > 0) { |
1592 young_other_time_ms = |
1565 young_other_time_ms = |
1593 _recorded_young_cset_choice_time_ms + |
1566 _recorded_young_cset_choice_time_ms + |
1708 dcqs.set_completed_queue_padding(curr_queue_size); |
1681 dcqs.set_completed_queue_padding(curr_queue_size); |
1709 } else { |
1682 } else { |
1710 dcqs.set_completed_queue_padding(0); |
1683 dcqs.set_completed_queue_padding(0); |
1711 } |
1684 } |
1712 dcqs.notify_if_necessary(); |
1685 dcqs.notify_if_necessary(); |
1713 } |
|
1714 |
|
1715 double |
|
1716 G1CollectorPolicy:: |
|
1717 predict_young_collection_elapsed_time_ms(size_t adjustment) { |
|
1718 guarantee( adjustment == 0 || adjustment == 1, "invariant" ); |
|
1719 |
|
1720 G1CollectedHeap* g1h = G1CollectedHeap::heap(); |
|
1721 size_t young_num = g1h->young_list()->length(); |
|
1722 if (young_num == 0) |
|
1723 return 0.0; |
|
1724 |
|
1725 young_num += adjustment; |
|
1726 size_t pending_cards = predict_pending_cards(); |
|
1727 size_t rs_lengths = g1h->young_list()->sampled_rs_lengths() + |
|
1728 predict_rs_length_diff(); |
|
1729 size_t card_num; |
|
1730 if (gcs_are_young()) { |
|
1731 card_num = predict_young_card_num(rs_lengths); |
|
1732 } else { |
|
1733 card_num = predict_non_young_card_num(rs_lengths); |
|
1734 } |
|
1735 size_t young_byte_size = young_num * HeapRegion::GrainBytes; |
|
1736 double accum_yg_surv_rate = |
|
1737 _short_lived_surv_rate_group->accum_surv_rate(adjustment); |
|
1738 |
|
1739 size_t bytes_to_copy = |
|
1740 (size_t) (accum_yg_surv_rate * (double) HeapRegion::GrainBytes); |
|
1741 |
|
1742 return |
|
1743 predict_rs_update_time_ms(pending_cards) + |
|
1744 predict_rs_scan_time_ms(card_num) + |
|
1745 predict_object_copy_time_ms(bytes_to_copy) + |
|
1746 predict_young_other_time_ms(young_num) + |
|
1747 predict_constant_other_time_ms(); |
|
1748 } |
1686 } |
1749 |
1687 |
1750 double |
1688 double |
1751 G1CollectorPolicy::predict_base_elapsed_time_ms(size_t pending_cards) { |
1689 G1CollectorPolicy::predict_base_elapsed_time_ms(size_t pending_cards) { |
1752 size_t rs_length = predict_rs_length_diff(); |
1690 size_t rs_length = predict_rs_length_diff(); |
1978 print_summary(1, "Update RS", body_summary->get_update_rs_seq()); |
1916 print_summary(1, "Update RS", body_summary->get_update_rs_seq()); |
1979 print_summary(1, "Scan RS", body_summary->get_scan_rs_seq()); |
1917 print_summary(1, "Scan RS", body_summary->get_scan_rs_seq()); |
1980 print_summary(1, "Object Copy", body_summary->get_obj_copy_seq()); |
1918 print_summary(1, "Object Copy", body_summary->get_obj_copy_seq()); |
1981 } |
1919 } |
1982 } |
1920 } |
1983 print_summary(1, "Mark Closure", body_summary->get_mark_closure_seq()); |
|
1984 print_summary(1, "Clear CT", body_summary->get_clear_ct_seq()); |
1921 print_summary(1, "Clear CT", body_summary->get_clear_ct_seq()); |
1985 print_summary(1, "Other", summary->get_other_seq()); |
1922 print_summary(1, "Other", summary->get_other_seq()); |
1986 { |
1923 { |
1987 if (body_summary != NULL) { |
1924 if (body_summary != NULL) { |
1988 NumberSeq calc_other_times_ms; |
1925 NumberSeq calc_other_times_ms; |
1989 if (parallel) { |
1926 if (parallel) { |
1990 // parallel |
1927 // parallel |
1991 NumberSeq* other_parts[] = { |
1928 NumberSeq* other_parts[] = { |
1992 body_summary->get_satb_drain_seq(), |
|
1993 body_summary->get_root_region_scan_wait_seq(), |
1929 body_summary->get_root_region_scan_wait_seq(), |
1994 body_summary->get_parallel_seq(), |
1930 body_summary->get_parallel_seq(), |
1995 body_summary->get_clear_ct_seq() |
1931 body_summary->get_clear_ct_seq() |
1996 }; |
1932 }; |
1997 calc_other_times_ms = NumberSeq(summary->get_total_seq(), |
1933 calc_other_times_ms = NumberSeq(summary->get_total_seq(), |
1998 4, other_parts); |
1934 3, other_parts); |
1999 } else { |
1935 } else { |
2000 // serial |
1936 // serial |
2001 NumberSeq* other_parts[] = { |
1937 NumberSeq* other_parts[] = { |
2002 body_summary->get_satb_drain_seq(), |
|
2003 body_summary->get_root_region_scan_wait_seq(), |
1938 body_summary->get_root_region_scan_wait_seq(), |
2004 body_summary->get_update_rs_seq(), |
1939 body_summary->get_update_rs_seq(), |
2005 body_summary->get_ext_root_scan_seq(), |
1940 body_summary->get_ext_root_scan_seq(), |
2006 body_summary->get_satb_filtering_seq(), |
1941 body_summary->get_satb_filtering_seq(), |
2007 body_summary->get_scan_rs_seq(), |
1942 body_summary->get_scan_rs_seq(), |
2008 body_summary->get_obj_copy_seq() |
1943 body_summary->get_obj_copy_seq() |
2009 }; |
1944 }; |
2010 calc_other_times_ms = NumberSeq(summary->get_total_seq(), |
1945 calc_other_times_ms = NumberSeq(summary->get_total_seq(), |
2011 7, other_parts); |
1946 6, other_parts); |
2012 } |
1947 } |
2013 check_other_times(1, summary->get_other_seq(), &calc_other_times_ms); |
1948 check_other_times(1, summary->get_other_seq(), &calc_other_times_ms); |
2014 } |
1949 } |
2015 } |
1950 } |
2016 } else { |
1951 } else { |