comparison src/share/vm/gc_implementation/g1/g1CollectorPolicy.cpp @ 1707:0ce1569c90e5

6963209: G1: remove the concept of abandoned pauses Summary: As part of 6944166 we disabled the concept of abandoned pauses (i.e., if the collection set is empty, we would still try to do a pause even if it is to update the RSets and scan the roots). This changeset removes the code and structures associated with abandoned pauses. Reviewed-by: iveresov, johnc
author tonyp
date Wed, 04 Aug 2010 13:03:23 -0400
parents 2d160770d2e5
children 6eddcbe17c83
comparison
equal deleted inserted replaced
1706:9d7a8ab3736b 1707:0ce1569c90e5
86 _all_yield_times_ms(new NumberSeq()), 86 _all_yield_times_ms(new NumberSeq()),
87 87
88 _all_mod_union_times_ms(new NumberSeq()), 88 _all_mod_union_times_ms(new NumberSeq()),
89 89
90 _summary(new Summary()), 90 _summary(new Summary()),
91 _abandoned_summary(new AbandonedSummary()),
92 91
93 #ifndef PRODUCT 92 #ifndef PRODUCT
94 _cur_clear_ct_time_ms(0.0), 93 _cur_clear_ct_time_ms(0.0),
95 _min_clear_cc_time_ms(-1.0), 94 _min_clear_cc_time_ms(-1.0),
96 _max_clear_cc_time_ms(-1.0), 95 _max_clear_cc_time_ms(-1.0),
1122 } 1121 }
1123 1122
1124 // Anything below that is considered to be zero 1123 // Anything below that is considered to be zero
1125 #define MIN_TIMER_GRANULARITY 0.0000001 1124 #define MIN_TIMER_GRANULARITY 0.0000001
1126 1125
1127 void G1CollectorPolicy::record_collection_pause_end(bool abandoned) { 1126 void G1CollectorPolicy::record_collection_pause_end() {
1128 double end_time_sec = os::elapsedTime(); 1127 double end_time_sec = os::elapsedTime();
1129 double elapsed_ms = _last_pause_time_ms; 1128 double elapsed_ms = _last_pause_time_ms;
1130 bool parallel = ParallelGCThreads > 0; 1129 bool parallel = ParallelGCThreads > 0;
1131 double evac_ms = (end_time_sec - _cur_G1_strong_roots_end_sec) * 1000.0; 1130 double evac_ms = (end_time_sec - _cur_G1_strong_roots_end_sec) * 1000.0;
1132 size_t rs_size = 1131 size_t rs_size =
1133 _cur_collection_pause_used_regions_at_start - collection_set_size(); 1132 _cur_collection_pause_used_regions_at_start - collection_set_size();
1134 size_t cur_used_bytes = _g1->used(); 1133 size_t cur_used_bytes = _g1->used();
1135 assert(cur_used_bytes == _g1->recalculate_used(), "It should!"); 1134 assert(cur_used_bytes == _g1->recalculate_used(), "It should!");
1136 bool last_pause_included_initial_mark = false; 1135 bool last_pause_included_initial_mark = false;
1137 bool update_stats = !abandoned && !_g1->evacuation_failed(); 1136 bool update_stats = !_g1->evacuation_failed();
1138 1137
1139 #ifndef PRODUCT 1138 #ifndef PRODUCT
1140 if (G1YoungSurvRateVerbose) { 1139 if (G1YoungSurvRateVerbose) {
1141 gclog_or_tty->print_cr(""); 1140 gclog_or_tty->print_cr("");
1142 _short_lived_surv_rate_group->print(); 1141 _short_lived_surv_rate_group->print();
1271 1270
1272 if (G1PolicyVerbose > 1) { 1271 if (G1PolicyVerbose > 1) {
1273 gclog_or_tty->print_cr(" Recording collection pause(%d)", _n_pauses); 1272 gclog_or_tty->print_cr(" Recording collection pause(%d)", _n_pauses);
1274 } 1273 }
1275 1274
1276 PauseSummary* summary; 1275 PauseSummary* summary = _summary;
1277 if (abandoned) {
1278 summary = _abandoned_summary;
1279 } else {
1280 summary = _summary;
1281 }
1282 1276
1283 double ext_root_scan_time = avg_value(_par_last_ext_root_scan_times_ms); 1277 double ext_root_scan_time = avg_value(_par_last_ext_root_scan_times_ms);
1284 double mark_stack_scan_time = avg_value(_par_last_mark_stack_scan_times_ms); 1278 double mark_stack_scan_time = avg_value(_par_last_mark_stack_scan_times_ms);
1285 double update_rs_time = avg_value(_par_last_update_rs_times_ms); 1279 double update_rs_time = avg_value(_par_last_update_rs_times_ms);
1286 double update_rs_processed_buffers = 1280 double update_rs_processed_buffers =
1344 recent_avg_pause_time_ratio() * 100.0); 1338 recent_avg_pause_time_ratio() * 100.0);
1345 } 1339 }
1346 1340
1347 double other_time_ms = elapsed_ms; 1341 double other_time_ms = elapsed_ms;
1348 1342
1349 if (!abandoned) { 1343 if (_satb_drain_time_set) {
1350 if (_satb_drain_time_set) 1344 other_time_ms -= _cur_satb_drain_time_ms;
1351 other_time_ms -= _cur_satb_drain_time_ms; 1345 }
1352 1346
1353 if (parallel) 1347 if (parallel) {
1354 other_time_ms -= _cur_collection_par_time_ms + _cur_clear_ct_time_ms; 1348 other_time_ms -= _cur_collection_par_time_ms + _cur_clear_ct_time_ms;
1355 else 1349 } else {
1356 other_time_ms -= 1350 other_time_ms -=
1357 update_rs_time + 1351 update_rs_time +
1358 ext_root_scan_time + mark_stack_scan_time + 1352 ext_root_scan_time + mark_stack_scan_time +
1359 scan_rs_time + obj_copy_time; 1353 scan_rs_time + obj_copy_time;
1360 } 1354 }
1361 1355
1362 if (PrintGCDetails) { 1356 if (PrintGCDetails) {
1363 gclog_or_tty->print_cr("%s%s, %1.8lf secs]", 1357 gclog_or_tty->print_cr("%s, %1.8lf secs]",
1364 abandoned ? " (abandoned)" : "",
1365 (last_pause_included_initial_mark) ? " (initial-mark)" : "", 1358 (last_pause_included_initial_mark) ? " (initial-mark)" : "",
1366 elapsed_ms / 1000.0); 1359 elapsed_ms / 1000.0);
1367 1360
1368 if (!abandoned) { 1361 if (_satb_drain_time_set) {
1369 if (_satb_drain_time_set) { 1362 print_stats(1, "SATB Drain Time", _cur_satb_drain_time_ms);
1370 print_stats(1, "SATB Drain Time", _cur_satb_drain_time_ms); 1363 }
1371 } 1364 if (_last_satb_drain_processed_buffers >= 0) {
1372 if (_last_satb_drain_processed_buffers >= 0) { 1365 print_stats(2, "Processed Buffers", _last_satb_drain_processed_buffers);
1373 print_stats(2, "Processed Buffers", _last_satb_drain_processed_buffers); 1366 }
1374 } 1367 if (parallel) {
1375 if (parallel) { 1368 print_stats(1, "Parallel Time", _cur_collection_par_time_ms);
1376 print_stats(1, "Parallel Time", _cur_collection_par_time_ms); 1369 print_par_stats(2, "GC Worker Start Time",
1377 print_par_stats(2, "GC Worker Start Time", 1370 _par_last_gc_worker_start_times_ms, false);
1378 _par_last_gc_worker_start_times_ms, false); 1371 print_par_stats(2, "Update RS", _par_last_update_rs_times_ms);
1379 print_par_stats(2, "Update RS", _par_last_update_rs_times_ms); 1372 print_par_sizes(3, "Processed Buffers",
1380 print_par_sizes(3, "Processed Buffers", 1373 _par_last_update_rs_processed_buffers, true);
1381 _par_last_update_rs_processed_buffers, true); 1374 print_par_stats(2, "Ext Root Scanning",
1382 print_par_stats(2, "Ext Root Scanning", 1375 _par_last_ext_root_scan_times_ms);
1383 _par_last_ext_root_scan_times_ms); 1376 print_par_stats(2, "Mark Stack Scanning",
1384 print_par_stats(2, "Mark Stack Scanning", 1377 _par_last_mark_stack_scan_times_ms);
1385 _par_last_mark_stack_scan_times_ms); 1378 print_par_stats(2, "Scan RS", _par_last_scan_rs_times_ms);
1386 print_par_stats(2, "Scan RS", _par_last_scan_rs_times_ms); 1379 print_par_stats(2, "Object Copy", _par_last_obj_copy_times_ms);
1387 print_par_stats(2, "Object Copy", _par_last_obj_copy_times_ms); 1380 print_par_stats(2, "Termination", _par_last_termination_times_ms);
1388 print_par_stats(2, "Termination", _par_last_termination_times_ms); 1381 print_par_sizes(3, "Termination Attempts",
1389 print_par_sizes(3, "Termination Attempts", 1382 _par_last_termination_attempts, true);
1390 _par_last_termination_attempts, true); 1383 print_par_stats(2, "GC Worker End Time",
1391 print_par_stats(2, "GC Worker End Time", 1384 _par_last_gc_worker_end_times_ms, false);
1392 _par_last_gc_worker_end_times_ms, false); 1385 print_stats(2, "Other", parallel_other_time);
1393 print_stats(2, "Other", parallel_other_time); 1386 print_stats(1, "Clear CT", _cur_clear_ct_time_ms);
1394 print_stats(1, "Clear CT", _cur_clear_ct_time_ms); 1387 } else {
1395 } else { 1388 print_stats(1, "Update RS", update_rs_time);
1396 print_stats(1, "Update RS", update_rs_time); 1389 print_stats(2, "Processed Buffers",
1397 print_stats(2, "Processed Buffers", 1390 (int)update_rs_processed_buffers);
1398 (int)update_rs_processed_buffers); 1391 print_stats(1, "Ext Root Scanning", ext_root_scan_time);
1399 print_stats(1, "Ext Root Scanning", ext_root_scan_time); 1392 print_stats(1, "Mark Stack Scanning", mark_stack_scan_time);
1400 print_stats(1, "Mark Stack Scanning", mark_stack_scan_time); 1393 print_stats(1, "Scan RS", scan_rs_time);
1401 print_stats(1, "Scan RS", scan_rs_time); 1394 print_stats(1, "Object Copying", obj_copy_time);
1402 print_stats(1, "Object Copying", obj_copy_time);
1403 }
1404 } 1395 }
1405 #ifndef PRODUCT 1396 #ifndef PRODUCT
1406 print_stats(1, "Cur Clear CC", _cur_clear_cc_time_ms); 1397 print_stats(1, "Cur Clear CC", _cur_clear_cc_time_ms);
1407 print_stats(1, "Cum Clear CC", _cum_clear_cc_time_ms); 1398 print_stats(1, "Cum Clear CC", _cum_clear_cc_time_ms);
1408 print_stats(1, "Min Clear CC", _min_clear_cc_time_ms); 1399 print_stats(1, "Min Clear CC", _min_clear_cc_time_ms);
2174 } 2165 }
2175 } 2166 }
2176 print_summary(1, "Other", summary->get_other_seq()); 2167 print_summary(1, "Other", summary->get_other_seq());
2177 { 2168 {
2178 NumberSeq calc_other_times_ms; 2169 NumberSeq calc_other_times_ms;
2179 if (body_summary != NULL) { 2170 if (parallel) {
2180 // not abandoned 2171 // parallel
2181 if (parallel) { 2172 NumberSeq* other_parts[] = {
2182 // parallel 2173 body_summary->get_satb_drain_seq(),
2183 NumberSeq* other_parts[] = { 2174 body_summary->get_parallel_seq(),
2184 body_summary->get_satb_drain_seq(), 2175 body_summary->get_clear_ct_seq()
2185 body_summary->get_parallel_seq(), 2176 };
2186 body_summary->get_clear_ct_seq() 2177 calc_other_times_ms = NumberSeq(summary->get_total_seq(),
2187 }; 2178 3, other_parts);
2188 calc_other_times_ms = NumberSeq(summary->get_total_seq(),
2189 3, other_parts);
2190 } else {
2191 // serial
2192 NumberSeq* other_parts[] = {
2193 body_summary->get_satb_drain_seq(),
2194 body_summary->get_update_rs_seq(),
2195 body_summary->get_ext_root_scan_seq(),
2196 body_summary->get_mark_stack_scan_seq(),
2197 body_summary->get_scan_rs_seq(),
2198 body_summary->get_obj_copy_seq()
2199 };
2200 calc_other_times_ms = NumberSeq(summary->get_total_seq(),
2201 7, other_parts);
2202 }
2203 } else { 2179 } else {
2204 // abandoned 2180 // serial
2205 calc_other_times_ms = NumberSeq(); 2181 NumberSeq* other_parts[] = {
2182 body_summary->get_satb_drain_seq(),
2183 body_summary->get_update_rs_seq(),
2184 body_summary->get_ext_root_scan_seq(),
2185 body_summary->get_mark_stack_scan_seq(),
2186 body_summary->get_scan_rs_seq(),
2187 body_summary->get_obj_copy_seq()
2188 };
2189 calc_other_times_ms = NumberSeq(summary->get_total_seq(),
2190 7, other_parts);
2206 } 2191 }
2207 check_other_times(1, summary->get_other_seq(), &calc_other_times_ms); 2192 check_other_times(1, summary->get_other_seq(), &calc_other_times_ms);
2208 } 2193 }
2209 } else { 2194 } else {
2210 print_indent(0); 2195 print_indent(0);
2211 gclog_or_tty->print_cr("none"); 2196 gclog_or_tty->print_cr("none");
2212 } 2197 }
2213 gclog_or_tty->print_cr(""); 2198 gclog_or_tty->print_cr("");
2214 }
2215
2216 void
2217 G1CollectorPolicy::print_abandoned_summary(PauseSummary* summary) const {
2218 bool printed = false;
2219 if (summary->get_total_seq()->num() > 0) {
2220 printed = true;
2221 print_summary(summary);
2222 }
2223 if (!printed) {
2224 print_indent(0);
2225 gclog_or_tty->print_cr("none");
2226 gclog_or_tty->print_cr("");
2227 }
2228 } 2199 }
2229 2200
2230 void G1CollectorPolicy::print_tracing_info() const { 2201 void G1CollectorPolicy::print_tracing_info() const {
2231 if (TraceGen0Time) { 2202 if (TraceGen0Time) {
2232 gclog_or_tty->print_cr("ALL PAUSES"); 2203 gclog_or_tty->print_cr("ALL PAUSES");
2237 gclog_or_tty->print_cr(" Partial Young GC Pauses: %8d", _partial_young_pause_num); 2208 gclog_or_tty->print_cr(" Partial Young GC Pauses: %8d", _partial_young_pause_num);
2238 gclog_or_tty->print_cr(""); 2209 gclog_or_tty->print_cr("");
2239 2210
2240 gclog_or_tty->print_cr("EVACUATION PAUSES"); 2211 gclog_or_tty->print_cr("EVACUATION PAUSES");
2241 print_summary(_summary); 2212 print_summary(_summary);
2242
2243 gclog_or_tty->print_cr("ABANDONED PAUSES");
2244 print_abandoned_summary(_abandoned_summary);
2245 2213
2246 gclog_or_tty->print_cr("MISC"); 2214 gclog_or_tty->print_cr("MISC");
2247 print_summary_sd(0, "Stop World", _all_stop_world_times_ms); 2215 print_summary_sd(0, "Stop World", _all_stop_world_times_ms);
2248 print_summary_sd(0, "Yields", _all_yield_times_ms); 2216 print_summary_sd(0, "Yields", _all_yield_times_ms);
2249 for (int i = 0; i < _aux_num; ++i) { 2217 for (int i = 0; i < _aux_num; ++i) {
2866 csr = next; 2834 csr = next;
2867 } 2835 }
2868 } 2836 }
2869 #endif // !PRODUCT 2837 #endif // !PRODUCT
2870 2838
2871 bool 2839 void
2872 G1CollectorPolicy_BestRegionsFirst::choose_collection_set( 2840 G1CollectorPolicy_BestRegionsFirst::choose_collection_set(
2873 double target_pause_time_ms) { 2841 double target_pause_time_ms) {
2874 // Set this here - in case we're not doing young collections. 2842 // Set this here - in case we're not doing young collections.
2875 double non_young_start_time_sec = os::elapsedTime(); 2843 double non_young_start_time_sec = os::elapsedTime();
2876
2877 // The result that this routine will return. This will be set to
2878 // false if:
2879 // * we're doing a young or partially young collection and we
2880 // have added the youg regions to collection set, or
2881 // * we add old regions to the collection set.
2882 bool abandon_collection = true;
2883 2844
2884 start_recording_regions(); 2845 start_recording_regions();
2885 2846
2886 guarantee(target_pause_time_ms > 0.0, 2847 guarantee(target_pause_time_ms > 0.0,
2887 err_msg("target_pause_time_ms = %1.6lf should be positive", 2848 err_msg("target_pause_time_ms = %1.6lf should be positive",
2982 gclog_or_tty->print_cr(" (" SIZE_FORMAT " KB left in heap.)", 2943 gclog_or_tty->print_cr(" (" SIZE_FORMAT " KB left in heap.)",
2983 max_live_bytes/K); 2944 max_live_bytes/K);
2984 } 2945 }
2985 2946
2986 assert(_inc_cset_size == _g1->young_list()->length(), "Invariant"); 2947 assert(_inc_cset_size == _g1->young_list()->length(), "Invariant");
2987 if (_inc_cset_size > 0) {
2988 assert(_collection_set != NULL, "Invariant");
2989 abandon_collection = false;
2990 }
2991 2948
2992 double young_end_time_sec = os::elapsedTime(); 2949 double young_end_time_sec = os::elapsedTime();
2993 _recorded_young_cset_choice_time_ms = 2950 _recorded_young_cset_choice_time_ms =
2994 (young_end_time_sec - young_start_time_sec) * 1000.0; 2951 (young_end_time_sec - young_start_time_sec) * 1000.0;
2995 2952
3006 2963
3007 if (!in_young_gc_mode() || !full_young_gcs()) { 2964 if (!in_young_gc_mode() || !full_young_gcs()) {
3008 bool should_continue = true; 2965 bool should_continue = true;
3009 NumberSeq seq; 2966 NumberSeq seq;
3010 double avg_prediction = 100000000000000000.0; // something very large 2967 double avg_prediction = 100000000000000000.0; // something very large
3011
3012 // Save the current size of the collection set to detect
3013 // if we actually added any old regions.
3014 size_t n_young_regions = _collection_set_size;
3015 2968
3016 do { 2969 do {
3017 hr = _collectionSetChooser->getNextMarkedRegion(time_remaining_ms, 2970 hr = _collectionSetChooser->getNextMarkedRegion(time_remaining_ms,
3018 avg_prediction); 2971 avg_prediction);
3019 if (hr != NULL) { 2972 if (hr != NULL) {
3037 } while (should_continue); 2990 } while (should_continue);
3038 2991
3039 if (!adaptive_young_list_length() && 2992 if (!adaptive_young_list_length() &&
3040 _collection_set_size < _young_list_fixed_length) 2993 _collection_set_size < _young_list_fixed_length)
3041 _should_revert_to_full_young_gcs = true; 2994 _should_revert_to_full_young_gcs = true;
3042
3043 if (_collection_set_size > n_young_regions) {
3044 // We actually added old regions to the collection set
3045 // so we are not abandoning this collection.
3046 abandon_collection = false;
3047 }
3048 } 2995 }
3049 2996
3050 choose_collection_set_end: 2997 choose_collection_set_end:
3051 stop_incremental_cset_building(); 2998 stop_incremental_cset_building();
3052 2999
3055 end_recording_regions(); 3002 end_recording_regions();
3056 3003
3057 double non_young_end_time_sec = os::elapsedTime(); 3004 double non_young_end_time_sec = os::elapsedTime();
3058 _recorded_non_young_cset_choice_time_ms = 3005 _recorded_non_young_cset_choice_time_ms =
3059 (non_young_end_time_sec - non_young_start_time_sec) * 1000.0; 3006 (non_young_end_time_sec - non_young_start_time_sec) * 1000.0;
3060
3061 // Here we are supposed to return whether the pause should be
3062 // abandoned or not (i.e., whether the collection set is empty or
3063 // not). However, this introduces a subtle issue when a pause is
3064 // initiated explicitly with System.gc() and
3065 // +ExplicitGCInvokesConcurrent (see Comment #2 in CR 6944166), it's
3066 // supposed to start a marking cycle, and it's abandoned. So, by
3067 // returning false here we are telling the caller never to consider
3068 // a pause to be abandoned. We'll actually remove all the code
3069 // associated with abandoned pauses as part of CR 6963209, but we are
3070 // just disabling them this way for the moment to avoid increasing
3071 // further the amount of changes for CR 6944166.
3072 return false;
3073 } 3007 }
3074 3008
3075 void G1CollectorPolicy_BestRegionsFirst::record_full_collection_end() { 3009 void G1CollectorPolicy_BestRegionsFirst::record_full_collection_end() {
3076 G1CollectorPolicy::record_full_collection_end(); 3010 G1CollectorPolicy::record_full_collection_end();
3077 _collectionSetChooser->updateAfterFullCollection(); 3011 _collectionSetChooser->updateAfterFullCollection();
3082 size_t expansion_bytes = numRegions * HeapRegion::GrainBytes; 3016 size_t expansion_bytes = numRegions * HeapRegion::GrainBytes;
3083 _g1->expand(expansion_bytes); 3017 _g1->expand(expansion_bytes);
3084 } 3018 }
3085 3019
3086 void G1CollectorPolicy_BestRegionsFirst:: 3020 void G1CollectorPolicy_BestRegionsFirst::
3087 record_collection_pause_end(bool abandoned) { 3021 record_collection_pause_end() {
3088 G1CollectorPolicy::record_collection_pause_end(abandoned); 3022 G1CollectorPolicy::record_collection_pause_end();
3089 assert(assertMarkedBytesDataOK(), "Marked regions not OK at pause end."); 3023 assert(assertMarkedBytesDataOK(), "Marked regions not OK at pause end.");
3090 } 3024 }