132 } |
132 } |
133 }; |
133 }; |
134 |
134 |
135 G1CollectorPolicy::G1CollectorPolicy() : |
135 G1CollectorPolicy::G1CollectorPolicy() : |
136 _parallel_gc_threads(G1CollectedHeap::use_parallel_gc_threads() |
136 _parallel_gc_threads(G1CollectedHeap::use_parallel_gc_threads() |
137 ? ParallelGCThreads : 1), |
137 ? ParallelGCThreads : 1), |
138 |
|
139 |
138 |
140 _n_pauses(0), |
139 _n_pauses(0), |
141 _recent_CH_strong_roots_times_ms(new TruncatedSeq(NumPrevPausesForHeuristics)), |
140 _recent_rs_scan_times_ms(new TruncatedSeq(NumPrevPausesForHeuristics)), |
142 _recent_G1_strong_roots_times_ms(new TruncatedSeq(NumPrevPausesForHeuristics)), |
|
143 _recent_evac_times_ms(new TruncatedSeq(NumPrevPausesForHeuristics)), |
|
144 _recent_pause_times_ms(new TruncatedSeq(NumPrevPausesForHeuristics)), |
141 _recent_pause_times_ms(new TruncatedSeq(NumPrevPausesForHeuristics)), |
145 _recent_rs_sizes(new TruncatedSeq(NumPrevPausesForHeuristics)), |
142 _recent_rs_sizes(new TruncatedSeq(NumPrevPausesForHeuristics)), |
146 _recent_gc_times_ms(new TruncatedSeq(NumPrevPausesForHeuristics)), |
143 _recent_gc_times_ms(new TruncatedSeq(NumPrevPausesForHeuristics)), |
147 _all_pause_times_ms(new NumberSeq()), |
144 _all_pause_times_ms(new NumberSeq()), |
148 _stop_world_start(0.0), |
145 _stop_world_start(0.0), |
1048 } |
1045 } |
1049 |
1046 |
1050 void G1CollectorPolicy::record_concurrent_pause_end() { |
1047 void G1CollectorPolicy::record_concurrent_pause_end() { |
1051 } |
1048 } |
1052 |
1049 |
1053 void G1CollectorPolicy::record_collection_pause_end_CH_strong_roots() { |
|
1054 _cur_CH_strong_roots_end_sec = os::elapsedTime(); |
|
1055 _cur_CH_strong_roots_dur_ms = |
|
1056 (_cur_CH_strong_roots_end_sec - _cur_collection_start_sec) * 1000.0; |
|
1057 } |
|
1058 |
|
1059 void G1CollectorPolicy::record_collection_pause_end_G1_strong_roots() { |
|
1060 _cur_G1_strong_roots_end_sec = os::elapsedTime(); |
|
1061 _cur_G1_strong_roots_dur_ms = |
|
1062 (_cur_G1_strong_roots_end_sec - _cur_CH_strong_roots_end_sec) * 1000.0; |
|
1063 } |
|
1064 |
|
1065 template<class T> |
1050 template<class T> |
1066 T sum_of(T* sum_arr, int start, int n, int N) { |
1051 T sum_of(T* sum_arr, int start, int n, int N) { |
1067 T sum = (T)0; |
1052 T sum = (T)0; |
1068 for (int i = 0; i < n; i++) { |
1053 for (int i = 0; i < n; i++) { |
1069 int j = (start + i) % N; |
1054 int j = (start + i) % N; |
1181 |
1166 |
1182 void G1CollectorPolicy::record_collection_pause_end() { |
1167 void G1CollectorPolicy::record_collection_pause_end() { |
1183 double end_time_sec = os::elapsedTime(); |
1168 double end_time_sec = os::elapsedTime(); |
1184 double elapsed_ms = _last_pause_time_ms; |
1169 double elapsed_ms = _last_pause_time_ms; |
1185 bool parallel = G1CollectedHeap::use_parallel_gc_threads(); |
1170 bool parallel = G1CollectedHeap::use_parallel_gc_threads(); |
1186 double evac_ms = (end_time_sec - _cur_G1_strong_roots_end_sec) * 1000.0; |
|
1187 size_t rs_size = |
1171 size_t rs_size = |
1188 _cur_collection_pause_used_regions_at_start - collection_set_size(); |
1172 _cur_collection_pause_used_regions_at_start - collection_set_size(); |
1189 size_t cur_used_bytes = _g1->used(); |
1173 size_t cur_used_bytes = _g1->used(); |
1190 assert(cur_used_bytes == _g1->recalculate_used(), "It should!"); |
1174 assert(cur_used_bytes == _g1->recalculate_used(), "It should!"); |
1191 bool last_pause_included_initial_mark = false; |
1175 bool last_pause_included_initial_mark = false; |
1254 (double)surviving_bytes/ |
1238 (double)surviving_bytes/ |
1255 (double)_collection_set_bytes_used_before; |
1239 (double)_collection_set_bytes_used_before; |
1256 |
1240 |
1257 _n_pauses++; |
1241 _n_pauses++; |
1258 |
1242 |
|
1243 double ext_root_scan_time = avg_value(_par_last_ext_root_scan_times_ms); |
|
1244 double mark_stack_scan_time = avg_value(_par_last_mark_stack_scan_times_ms); |
|
1245 double update_rs_time = avg_value(_par_last_update_rs_times_ms); |
|
1246 double update_rs_processed_buffers = |
|
1247 sum_of_values(_par_last_update_rs_processed_buffers); |
|
1248 double scan_rs_time = avg_value(_par_last_scan_rs_times_ms); |
|
1249 double obj_copy_time = avg_value(_par_last_obj_copy_times_ms); |
|
1250 double termination_time = avg_value(_par_last_termination_times_ms); |
|
1251 |
|
1252 double parallel_known_time = update_rs_time + |
|
1253 ext_root_scan_time + |
|
1254 mark_stack_scan_time + |
|
1255 scan_rs_time + |
|
1256 obj_copy_time + |
|
1257 termination_time; |
|
1258 |
|
1259 double parallel_other_time = _cur_collection_par_time_ms - parallel_known_time; |
|
1260 |
|
1261 PauseSummary* summary = _summary; |
|
1262 |
1259 if (update_stats) { |
1263 if (update_stats) { |
1260 _recent_CH_strong_roots_times_ms->add(_cur_CH_strong_roots_dur_ms); |
1264 _recent_rs_scan_times_ms->add(scan_rs_time); |
1261 _recent_G1_strong_roots_times_ms->add(_cur_G1_strong_roots_dur_ms); |
|
1262 _recent_evac_times_ms->add(evac_ms); |
|
1263 _recent_pause_times_ms->add(elapsed_ms); |
1265 _recent_pause_times_ms->add(elapsed_ms); |
1264 |
|
1265 _recent_rs_sizes->add(rs_size); |
1266 _recent_rs_sizes->add(rs_size); |
|
1267 |
|
1268 MainBodySummary* body_summary = summary->main_body_summary(); |
|
1269 guarantee(body_summary != NULL, "should not be null!"); |
|
1270 |
|
1271 if (_satb_drain_time_set) |
|
1272 body_summary->record_satb_drain_time_ms(_cur_satb_drain_time_ms); |
|
1273 else |
|
1274 body_summary->record_satb_drain_time_ms(0.0); |
|
1275 |
|
1276 body_summary->record_ext_root_scan_time_ms(ext_root_scan_time); |
|
1277 body_summary->record_mark_stack_scan_time_ms(mark_stack_scan_time); |
|
1278 body_summary->record_update_rs_time_ms(update_rs_time); |
|
1279 body_summary->record_scan_rs_time_ms(scan_rs_time); |
|
1280 body_summary->record_obj_copy_time_ms(obj_copy_time); |
|
1281 if (parallel) { |
|
1282 body_summary->record_parallel_time_ms(_cur_collection_par_time_ms); |
|
1283 body_summary->record_clear_ct_time_ms(_cur_clear_ct_time_ms); |
|
1284 body_summary->record_termination_time_ms(termination_time); |
|
1285 body_summary->record_parallel_other_time_ms(parallel_other_time); |
|
1286 } |
|
1287 body_summary->record_mark_closure_time_ms(_mark_closure_time_ms); |
1266 |
1288 |
1267 // We exempt parallel collection from this check because Alloc Buffer |
1289 // We exempt parallel collection from this check because Alloc Buffer |
1268 // fragmentation can produce negative collections. Same with evac |
1290 // fragmentation can produce negative collections. Same with evac |
1269 // failure. |
1291 // failure. |
1270 // Further, we're now always doing parallel collection. But I'm still |
1292 // Further, we're now always doing parallel collection. But I'm still |
1326 |
1348 |
1327 if (G1PolicyVerbose > 1) { |
1349 if (G1PolicyVerbose > 1) { |
1328 gclog_or_tty->print_cr(" Recording collection pause(%d)", _n_pauses); |
1350 gclog_or_tty->print_cr(" Recording collection pause(%d)", _n_pauses); |
1329 } |
1351 } |
1330 |
1352 |
1331 PauseSummary* summary = _summary; |
|
1332 |
|
1333 double ext_root_scan_time = avg_value(_par_last_ext_root_scan_times_ms); |
|
1334 double mark_stack_scan_time = avg_value(_par_last_mark_stack_scan_times_ms); |
|
1335 double update_rs_time = avg_value(_par_last_update_rs_times_ms); |
|
1336 double update_rs_processed_buffers = |
|
1337 sum_of_values(_par_last_update_rs_processed_buffers); |
|
1338 double scan_rs_time = avg_value(_par_last_scan_rs_times_ms); |
|
1339 double obj_copy_time = avg_value(_par_last_obj_copy_times_ms); |
|
1340 double termination_time = avg_value(_par_last_termination_times_ms); |
|
1341 |
|
1342 double parallel_other_time = _cur_collection_par_time_ms - |
|
1343 (update_rs_time + ext_root_scan_time + mark_stack_scan_time + |
|
1344 scan_rs_time + obj_copy_time + termination_time); |
|
1345 if (update_stats) { |
|
1346 MainBodySummary* body_summary = summary->main_body_summary(); |
|
1347 guarantee(body_summary != NULL, "should not be null!"); |
|
1348 |
|
1349 if (_satb_drain_time_set) |
|
1350 body_summary->record_satb_drain_time_ms(_cur_satb_drain_time_ms); |
|
1351 else |
|
1352 body_summary->record_satb_drain_time_ms(0.0); |
|
1353 body_summary->record_ext_root_scan_time_ms(ext_root_scan_time); |
|
1354 body_summary->record_mark_stack_scan_time_ms(mark_stack_scan_time); |
|
1355 body_summary->record_update_rs_time_ms(update_rs_time); |
|
1356 body_summary->record_scan_rs_time_ms(scan_rs_time); |
|
1357 body_summary->record_obj_copy_time_ms(obj_copy_time); |
|
1358 if (parallel) { |
|
1359 body_summary->record_parallel_time_ms(_cur_collection_par_time_ms); |
|
1360 body_summary->record_clear_ct_time_ms(_cur_clear_ct_time_ms); |
|
1361 body_summary->record_termination_time_ms(termination_time); |
|
1362 body_summary->record_parallel_other_time_ms(parallel_other_time); |
|
1363 } |
|
1364 body_summary->record_mark_closure_time_ms(_mark_closure_time_ms); |
|
1365 } |
|
1366 |
|
1367 if (G1PolicyVerbose > 1) { |
1353 if (G1PolicyVerbose > 1) { |
1368 gclog_or_tty->print_cr(" ET: %10.6f ms (avg: %10.6f ms)\n" |
1354 gclog_or_tty->print_cr(" ET: %10.6f ms (avg: %10.6f ms)\n" |
1369 " CH Strong: %10.6f ms (avg: %10.6f ms)\n" |
|
1370 " G1 Strong: %10.6f ms (avg: %10.6f ms)\n" |
|
1371 " Evac: %10.6f ms (avg: %10.6f ms)\n" |
|
1372 " ET-RS: %10.6f ms (avg: %10.6f ms)\n" |
1355 " ET-RS: %10.6f ms (avg: %10.6f ms)\n" |
1373 " |RS|: " SIZE_FORMAT, |
1356 " |RS|: " SIZE_FORMAT, |
1374 elapsed_ms, recent_avg_time_for_pauses_ms(), |
1357 elapsed_ms, recent_avg_time_for_pauses_ms(), |
1375 _cur_CH_strong_roots_dur_ms, recent_avg_time_for_CH_strong_ms(), |
1358 scan_rs_time, recent_avg_time_for_rs_scan_ms(), |
1376 _cur_G1_strong_roots_dur_ms, recent_avg_time_for_G1_strong_ms(), |
|
1377 evac_ms, recent_avg_time_for_evac_ms(), |
|
1378 scan_rs_time, |
|
1379 recent_avg_time_for_pauses_ms() - |
|
1380 recent_avg_time_for_G1_strong_ms(), |
|
1381 rs_size); |
1359 rs_size); |
1382 |
1360 |
1383 gclog_or_tty->print_cr(" Used at start: " SIZE_FORMAT"K" |
1361 gclog_or_tty->print_cr(" Used at start: " SIZE_FORMAT"K" |
1384 " At end " SIZE_FORMAT "K\n" |
1362 " At end " SIZE_FORMAT "K\n" |
1385 " garbage : " SIZE_FORMAT "K" |
1363 " garbage : " SIZE_FORMAT "K" |
1436 for (int i = 0; i < _parallel_gc_threads; i++) { |
1414 for (int i = 0; i < _parallel_gc_threads; i++) { |
1437 _par_last_gc_worker_times_ms[i] = _par_last_gc_worker_end_times_ms[i] - _par_last_gc_worker_start_times_ms[i]; |
1415 _par_last_gc_worker_times_ms[i] = _par_last_gc_worker_end_times_ms[i] - _par_last_gc_worker_start_times_ms[i]; |
1438 } |
1416 } |
1439 print_par_stats(2, "GC Worker Times", _par_last_gc_worker_times_ms); |
1417 print_par_stats(2, "GC Worker Times", _par_last_gc_worker_times_ms); |
1440 |
1418 |
1441 print_stats(2, "Other", parallel_other_time); |
1419 print_stats(2, "Parallel Other", parallel_other_time); |
1442 print_stats(1, "Clear CT", _cur_clear_ct_time_ms); |
1420 print_stats(1, "Clear CT", _cur_clear_ct_time_ms); |
1443 } else { |
1421 } else { |
1444 print_stats(1, "Update RS", update_rs_time); |
1422 print_stats(1, "Update RS", update_rs_time); |
1445 print_stats(2, "Processed Buffers", |
1423 print_stats(2, "Processed Buffers", |
1446 (int)update_rs_processed_buffers); |
1424 (int)update_rs_processed_buffers); |
1965 _recent_prev_end_times_for_all_gcs_sec->add(end_time_sec); |
1943 _recent_prev_end_times_for_all_gcs_sec->add(end_time_sec); |
1966 _prev_collection_pause_end_ms = end_time_sec * 1000.0; |
1944 _prev_collection_pause_end_ms = end_time_sec * 1000.0; |
1967 } |
1945 } |
1968 |
1946 |
1969 double G1CollectorPolicy::recent_avg_time_for_pauses_ms() { |
1947 double G1CollectorPolicy::recent_avg_time_for_pauses_ms() { |
1970 if (_recent_pause_times_ms->num() == 0) return (double) MaxGCPauseMillis; |
1948 if (_recent_pause_times_ms->num() == 0) { |
1971 else return _recent_pause_times_ms->avg(); |
1949 return (double) MaxGCPauseMillis; |
1972 } |
1950 } |
1973 |
1951 return _recent_pause_times_ms->avg(); |
1974 double G1CollectorPolicy::recent_avg_time_for_CH_strong_ms() { |
1952 } |
1975 if (_recent_CH_strong_roots_times_ms->num() == 0) |
1953 |
|
1954 double G1CollectorPolicy::recent_avg_time_for_rs_scan_ms() { |
|
1955 if (_recent_rs_scan_times_ms->num() == 0) { |
1976 return (double)MaxGCPauseMillis/3.0; |
1956 return (double)MaxGCPauseMillis/3.0; |
1977 else return _recent_CH_strong_roots_times_ms->avg(); |
1957 } |
1978 } |
1958 return _recent_rs_scan_times_ms->avg(); |
1979 |
|
1980 double G1CollectorPolicy::recent_avg_time_for_G1_strong_ms() { |
|
1981 if (_recent_G1_strong_roots_times_ms->num() == 0) |
|
1982 return (double)MaxGCPauseMillis/3.0; |
|
1983 else return _recent_G1_strong_roots_times_ms->avg(); |
|
1984 } |
|
1985 |
|
1986 double G1CollectorPolicy::recent_avg_time_for_evac_ms() { |
|
1987 if (_recent_evac_times_ms->num() == 0) return (double)MaxGCPauseMillis/3.0; |
|
1988 else return _recent_evac_times_ms->avg(); |
|
1989 } |
1959 } |
1990 |
1960 |
1991 int G1CollectorPolicy::number_of_recent_gcs() { |
1961 int G1CollectorPolicy::number_of_recent_gcs() { |
1992 assert(_recent_CH_strong_roots_times_ms->num() == |
1962 assert(_recent_rs_scan_times_ms->num() == |
1993 _recent_G1_strong_roots_times_ms->num(), "Sequence out of sync"); |
|
1994 assert(_recent_G1_strong_roots_times_ms->num() == |
|
1995 _recent_evac_times_ms->num(), "Sequence out of sync"); |
|
1996 assert(_recent_evac_times_ms->num() == |
|
1997 _recent_pause_times_ms->num(), "Sequence out of sync"); |
1963 _recent_pause_times_ms->num(), "Sequence out of sync"); |
1998 assert(_recent_pause_times_ms->num() == |
1964 assert(_recent_pause_times_ms->num() == |
1999 _recent_CS_bytes_used_before->num(), "Sequence out of sync"); |
1965 _recent_CS_bytes_used_before->num(), "Sequence out of sync"); |
2000 assert(_recent_CS_bytes_used_before->num() == |
1966 assert(_recent_CS_bytes_used_before->num() == |
2001 _recent_CS_bytes_surviving->num(), "Sequence out of sync"); |
1967 _recent_CS_bytes_surviving->num(), "Sequence out of sync"); |
|
1968 |
2002 return _recent_pause_times_ms->num(); |
1969 return _recent_pause_times_ms->num(); |
2003 } |
1970 } |
2004 |
1971 |
2005 double G1CollectorPolicy::recent_avg_survival_fraction() { |
1972 double G1CollectorPolicy::recent_avg_survival_fraction() { |
2006 return recent_avg_survival_fraction_work(_recent_CS_bytes_surviving, |
1973 return recent_avg_survival_fraction_work(_recent_CS_bytes_surviving, |