1 /* 2 * Copyright (c) 2001, 2011, Oracle and/or its affiliates. All rights reserved. 3 * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER. 4 * 5 * This code is free software; you can redistribute it and/or modify it 6 * under the terms of the GNU General Public License version 2 only, as 7 * published by the Free Software Foundation. 8 * 9 * This code is distributed in the hope that it will be useful, but WITHOUT 10 * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or 11 * FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License 12 * version 2 for more details (a copy is included in the LICENSE file that 13 * accompanied this code). 14 * 15 * You should have received a copy of the GNU General Public License version 16 * 2 along with this work; if not, write to the Free Software Foundation, 17 * Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA. 18 * 19 * Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA 20 * or visit www.oracle.com if you need additional information or have any 21 * questions. 22 * 23 */ 24 25 #include "precompiled.hpp" 26 #include "gc_implementation/g1/concurrentG1Refine.hpp" 27 #include "gc_implementation/g1/concurrentMark.hpp" 28 #include "gc_implementation/g1/concurrentMarkThread.inline.hpp" 29 #include "gc_implementation/g1/g1CollectedHeap.inline.hpp" 30 #include "gc_implementation/g1/g1CollectorPolicy.hpp" 31 #include "gc_implementation/g1/g1ErgoVerbose.hpp" 32 #include "gc_implementation/g1/heapRegionRemSet.hpp" 33 #include "gc_implementation/shared/gcPolicyCounters.hpp" 34 #include "runtime/arguments.hpp" 35 #include "runtime/java.hpp" 36 #include "runtime/mutexLocker.hpp" 37 #include "utilities/debug.hpp" 38 39 #define PREDICTIONS_VERBOSE 0 40 41 // <NEW PREDICTION> 42 43 // Different defaults for different number of GC threads 44 // They were chosen by running GCOld and SPECjbb on debris with different 45 // numbers of GC threads and choosing them based on the results 46 47 // all the same 48 static double rs_length_diff_defaults[] = { 49 0.0, 0.0, 0.0, 0.0, 0.0, 0.0, 0.0, 0.0 50 }; 51 52 static double cost_per_card_ms_defaults[] = { 53 0.01, 0.005, 0.005, 0.003, 0.003, 0.002, 0.002, 0.0015 54 }; 55 56 // all the same 57 static double fully_young_cards_per_entry_ratio_defaults[] = { 58 1.0, 1.0, 1.0, 1.0, 1.0, 1.0, 1.0, 1.0 59 }; 60 61 static double cost_per_entry_ms_defaults[] = { 62 0.015, 0.01, 0.01, 0.008, 0.008, 0.0055, 0.0055, 0.005 63 }; 64 65 static double cost_per_byte_ms_defaults[] = { 66 0.00006, 0.00003, 0.00003, 0.000015, 0.000015, 0.00001, 0.00001, 0.000009 67 }; 68 69 // these should be pretty consistent 70 static double constant_other_time_ms_defaults[] = { 71 5.0, 5.0, 5.0, 5.0, 5.0, 5.0, 5.0, 5.0 72 }; 73 74 75 static double young_other_cost_per_region_ms_defaults[] = { 76 0.3, 0.2, 0.2, 0.15, 0.15, 0.12, 0.12, 0.1 77 }; 78 79 static double non_young_other_cost_per_region_ms_defaults[] = { 80 1.0, 0.7, 0.7, 0.5, 0.5, 0.42, 0.42, 0.30 81 }; 82 83 // </NEW PREDICTION> 84 85 // Help class for avoiding interleaved logging 86 class LineBuffer: public StackObj { 87 88 private: 89 static const int BUFFER_LEN = 1024; 90 static const int INDENT_CHARS = 3; 91 char _buffer[BUFFER_LEN]; 92 int _indent_level; 93 int _cur; 94 95 void vappend(const char* format, va_list ap) { 96 int res = vsnprintf(&_buffer[_cur], BUFFER_LEN - _cur, format, ap); 97 if (res != -1) { 98 _cur += res; 99 } else { 100 DEBUG_ONLY(warning("buffer too small in LineBuffer");) 101 _buffer[BUFFER_LEN -1] = 0; 102 _cur = BUFFER_LEN; // vsnprintf above should not add to _buffer if we are called again 103 } 104 } 105 106 public: 107 explicit LineBuffer(int indent_level): _indent_level(indent_level), _cur(0) { 108 for (; (_cur < BUFFER_LEN && _cur < (_indent_level * INDENT_CHARS)); _cur++) { 109 _buffer[_cur] = ' '; 110 } 111 } 112 113 #ifndef PRODUCT 114 ~LineBuffer() { 115 assert(_cur == _indent_level * INDENT_CHARS, "pending data in buffer - append_and_print_cr() not called?"); 116 } 117 #endif 118 119 void append(const char* format, ...) { 120 va_list ap; 121 va_start(ap, format); 122 vappend(format, ap); 123 va_end(ap); 124 } 125 126 void append_and_print_cr(const char* format, ...) { 127 va_list ap; 128 va_start(ap, format); 129 vappend(format, ap); 130 va_end(ap); 131 gclog_or_tty->print_cr("%s", _buffer); 132 _cur = _indent_level * INDENT_CHARS; 133 } 134 }; 135 136 G1CollectorPolicy::G1CollectorPolicy() : 137 _parallel_gc_threads(G1CollectedHeap::use_parallel_gc_threads() 138 ? ParallelGCThreads : 1), 139 140 _n_pauses(0), 141 _recent_rs_scan_times_ms(new TruncatedSeq(NumPrevPausesForHeuristics)), 142 _recent_pause_times_ms(new TruncatedSeq(NumPrevPausesForHeuristics)), 143 _recent_rs_sizes(new TruncatedSeq(NumPrevPausesForHeuristics)), 144 _recent_gc_times_ms(new TruncatedSeq(NumPrevPausesForHeuristics)), 145 _all_pause_times_ms(new NumberSeq()), 146 _stop_world_start(0.0), 147 _all_stop_world_times_ms(new NumberSeq()), 148 _all_yield_times_ms(new NumberSeq()), 149 _using_new_ratio_calculations(false), 150 151 _all_mod_union_times_ms(new NumberSeq()), 152 153 _summary(new Summary()), 154 155 _cur_clear_ct_time_ms(0.0), 156 157 _cur_ref_proc_time_ms(0.0), 158 _cur_ref_enq_time_ms(0.0), 159 160 #ifndef PRODUCT 161 _min_clear_cc_time_ms(-1.0), 162 _max_clear_cc_time_ms(-1.0), 163 _cur_clear_cc_time_ms(0.0), 164 _cum_clear_cc_time_ms(0.0), 165 _num_cc_clears(0L), 166 #endif 167 168 _region_num_young(0), 169 _region_num_tenured(0), 170 _prev_region_num_young(0), 171 _prev_region_num_tenured(0), 172 173 _aux_num(10), 174 _all_aux_times_ms(new NumberSeq[_aux_num]), 175 _cur_aux_start_times_ms(new double[_aux_num]), 176 _cur_aux_times_ms(new double[_aux_num]), 177 _cur_aux_times_set(new bool[_aux_num]), 178 179 _concurrent_mark_remark_times_ms(new TruncatedSeq(NumPrevPausesForHeuristics)), 180 _concurrent_mark_cleanup_times_ms(new TruncatedSeq(NumPrevPausesForHeuristics)), 181 182 // <NEW PREDICTION> 183 184 _alloc_rate_ms_seq(new TruncatedSeq(TruncatedSeqLength)), 185 _prev_collection_pause_end_ms(0.0), 186 _pending_card_diff_seq(new TruncatedSeq(TruncatedSeqLength)), 187 _rs_length_diff_seq(new TruncatedSeq(TruncatedSeqLength)), 188 _cost_per_card_ms_seq(new TruncatedSeq(TruncatedSeqLength)), 189 _fully_young_cards_per_entry_ratio_seq(new TruncatedSeq(TruncatedSeqLength)), 190 _partially_young_cards_per_entry_ratio_seq( 191 new TruncatedSeq(TruncatedSeqLength)), 192 _cost_per_entry_ms_seq(new TruncatedSeq(TruncatedSeqLength)), 193 _partially_young_cost_per_entry_ms_seq(new TruncatedSeq(TruncatedSeqLength)), 194 _cost_per_byte_ms_seq(new TruncatedSeq(TruncatedSeqLength)), 195 _cost_per_byte_ms_during_cm_seq(new TruncatedSeq(TruncatedSeqLength)), 196 _constant_other_time_ms_seq(new TruncatedSeq(TruncatedSeqLength)), 197 _young_other_cost_per_region_ms_seq(new TruncatedSeq(TruncatedSeqLength)), 198 _non_young_other_cost_per_region_ms_seq( 199 new TruncatedSeq(TruncatedSeqLength)), 200 201 _pending_cards_seq(new TruncatedSeq(TruncatedSeqLength)), 202 _scanned_cards_seq(new TruncatedSeq(TruncatedSeqLength)), 203 _rs_lengths_seq(new TruncatedSeq(TruncatedSeqLength)), 204 205 _pause_time_target_ms((double) MaxGCPauseMillis), 206 207 // </NEW PREDICTION> 208 209 _full_young_gcs(true), 210 _full_young_pause_num(0), 211 _partial_young_pause_num(0), 212 213 _during_marking(false), 214 _in_marking_window(false), 215 _in_marking_window_im(false), 216 217 _known_garbage_ratio(0.0), 218 _known_garbage_bytes(0), 219 220 _young_gc_eff_seq(new TruncatedSeq(TruncatedSeqLength)), 221 222 _recent_prev_end_times_for_all_gcs_sec(new TruncatedSeq(NumPrevPausesForHeuristics)), 223 224 _recent_CS_bytes_used_before(new TruncatedSeq(NumPrevPausesForHeuristics)), 225 _recent_CS_bytes_surviving(new TruncatedSeq(NumPrevPausesForHeuristics)), 226 227 _recent_avg_pause_time_ratio(0.0), 228 229 _all_full_gc_times_ms(new NumberSeq()), 230 231 // G1PausesBtwnConcMark defaults to -1 232 // so the hack is to do the cast QQQ FIXME 233 _pauses_btwn_concurrent_mark((size_t)G1PausesBtwnConcMark), 234 _initiate_conc_mark_if_possible(false), 235 _during_initial_mark_pause(false), 236 _should_revert_to_full_young_gcs(false), 237 _last_full_young_gc(false), 238 239 _eden_bytes_before_gc(0), 240 _survivor_bytes_before_gc(0), 241 _capacity_before_gc(0), 242 243 _prev_collection_pause_used_at_end_bytes(0), 244 245 _collection_set(NULL), 246 _collection_set_size(0), 247 _collection_set_bytes_used_before(0), 248 249 // Incremental CSet attributes 250 _inc_cset_build_state(Inactive), 251 _inc_cset_head(NULL), 252 _inc_cset_tail(NULL), 253 _inc_cset_size(0), 254 _inc_cset_young_index(0), 255 _inc_cset_bytes_used_before(0), 256 _inc_cset_max_finger(NULL), 257 _inc_cset_recorded_young_bytes(0), 258 _inc_cset_recorded_rs_lengths(0), 259 _inc_cset_predicted_elapsed_time_ms(0.0), 260 _inc_cset_predicted_bytes_to_copy(0), 261 262 #ifdef _MSC_VER // the use of 'this' below gets a warning, make it go away 263 #pragma warning( disable:4355 ) // 'this' : used in base member initializer list 264 #endif // _MSC_VER 265 266 _short_lived_surv_rate_group(new SurvRateGroup(this, "Short Lived", 267 G1YoungSurvRateNumRegionsSummary)), 268 _survivor_surv_rate_group(new SurvRateGroup(this, "Survivor", 269 G1YoungSurvRateNumRegionsSummary)), 270 // add here any more surv rate groups 271 _recorded_survivor_regions(0), 272 _recorded_survivor_head(NULL), 273 _recorded_survivor_tail(NULL), 274 _survivors_age_table(true), 275 276 _gc_overhead_perc(0.0) { 277 278 // Set up the region size and associated fields. Given that the 279 // policy is created before the heap, we have to set this up here, 280 // so it's done as soon as possible. 281 HeapRegion::setup_heap_region_size(Arguments::min_heap_size()); 282 HeapRegionRemSet::setup_remset_size(); 283 284 G1ErgoVerbose::initialize(); 285 if (PrintAdaptiveSizePolicy) { 286 // Currently, we only use a single switch for all the heuristics. 287 G1ErgoVerbose::set_enabled(true); 288 // Given that we don't currently have a verboseness level 289 // parameter, we'll hardcode this to high. This can be easily 290 // changed in the future. 291 G1ErgoVerbose::set_level(ErgoHigh); 292 } else { 293 G1ErgoVerbose::set_enabled(false); 294 } 295 296 // Verify PLAB sizes 297 const size_t region_size = HeapRegion::GrainWords; 298 if (YoungPLABSize > region_size || OldPLABSize > region_size) { 299 char buffer[128]; 300 jio_snprintf(buffer, sizeof(buffer), "%sPLABSize should be at most "SIZE_FORMAT, 301 OldPLABSize > region_size ? "Old" : "Young", region_size); 302 vm_exit_during_initialization(buffer); 303 } 304 305 _recent_prev_end_times_for_all_gcs_sec->add(os::elapsedTime()); 306 _prev_collection_pause_end_ms = os::elapsedTime() * 1000.0; 307 308 _par_last_gc_worker_start_times_ms = new double[_parallel_gc_threads]; 309 _par_last_ext_root_scan_times_ms = new double[_parallel_gc_threads]; 310 _par_last_mark_stack_scan_times_ms = new double[_parallel_gc_threads]; 311 312 _par_last_update_rs_times_ms = new double[_parallel_gc_threads]; 313 _par_last_update_rs_processed_buffers = new double[_parallel_gc_threads]; 314 315 _par_last_scan_rs_times_ms = new double[_parallel_gc_threads]; 316 317 _par_last_obj_copy_times_ms = new double[_parallel_gc_threads]; 318 319 _par_last_termination_times_ms = new double[_parallel_gc_threads]; 320 _par_last_termination_attempts = new double[_parallel_gc_threads]; 321 _par_last_gc_worker_end_times_ms = new double[_parallel_gc_threads]; 322 _par_last_gc_worker_times_ms = new double[_parallel_gc_threads]; 323 _par_last_gc_worker_other_times_ms = new double[_parallel_gc_threads]; 324 325 // start conservatively 326 _expensive_region_limit_ms = 0.5 * (double) MaxGCPauseMillis; 327 328 // <NEW PREDICTION> 329 330 int index; 331 if (ParallelGCThreads == 0) 332 index = 0; 333 else if (ParallelGCThreads > 8) 334 index = 7; 335 else 336 index = ParallelGCThreads - 1; 337 338 _pending_card_diff_seq->add(0.0); 339 _rs_length_diff_seq->add(rs_length_diff_defaults[index]); 340 _cost_per_card_ms_seq->add(cost_per_card_ms_defaults[index]); 341 _fully_young_cards_per_entry_ratio_seq->add( 342 fully_young_cards_per_entry_ratio_defaults[index]); 343 _cost_per_entry_ms_seq->add(cost_per_entry_ms_defaults[index]); 344 _cost_per_byte_ms_seq->add(cost_per_byte_ms_defaults[index]); 345 _constant_other_time_ms_seq->add(constant_other_time_ms_defaults[index]); 346 _young_other_cost_per_region_ms_seq->add( 347 young_other_cost_per_region_ms_defaults[index]); 348 _non_young_other_cost_per_region_ms_seq->add( 349 non_young_other_cost_per_region_ms_defaults[index]); 350 351 // </NEW PREDICTION> 352 353 // Below, we might need to calculate the pause time target based on 354 // the pause interval. When we do so we are going to give G1 maximum 355 // flexibility and allow it to do pauses when it needs to. So, we'll 356 // arrange that the pause interval to be pause time target + 1 to 357 // ensure that a) the pause time target is maximized with respect to 358 // the pause interval and b) we maintain the invariant that pause 359 // time target < pause interval. If the user does not want this 360 // maximum flexibility, they will have to set the pause interval 361 // explicitly. 362 363 // First make sure that, if either parameter is set, its value is 364 // reasonable. 365 if (!FLAG_IS_DEFAULT(MaxGCPauseMillis)) { 366 if (MaxGCPauseMillis < 1) { 367 vm_exit_during_initialization("MaxGCPauseMillis should be " 368 "greater than 0"); 369 } 370 } 371 if (!FLAG_IS_DEFAULT(GCPauseIntervalMillis)) { 372 if (GCPauseIntervalMillis < 1) { 373 vm_exit_during_initialization("GCPauseIntervalMillis should be " 374 "greater than 0"); 375 } 376 } 377 378 // Then, if the pause time target parameter was not set, set it to 379 // the default value. 380 if (FLAG_IS_DEFAULT(MaxGCPauseMillis)) { 381 if (FLAG_IS_DEFAULT(GCPauseIntervalMillis)) { 382 // The default pause time target in G1 is 200ms 383 FLAG_SET_DEFAULT(MaxGCPauseMillis, 200); 384 } else { 385 // We do not allow the pause interval to be set without the 386 // pause time target 387 vm_exit_during_initialization("GCPauseIntervalMillis cannot be set " 388 "without setting MaxGCPauseMillis"); 389 } 390 } 391 392 // Then, if the interval parameter was not set, set it according to 393 // the pause time target (this will also deal with the case when the 394 // pause time target is the default value). 395 if (FLAG_IS_DEFAULT(GCPauseIntervalMillis)) { 396 FLAG_SET_DEFAULT(GCPauseIntervalMillis, MaxGCPauseMillis + 1); 397 } 398 399 // Finally, make sure that the two parameters are consistent. 400 if (MaxGCPauseMillis >= GCPauseIntervalMillis) { 401 char buffer[256]; 402 jio_snprintf(buffer, 256, 403 "MaxGCPauseMillis (%u) should be less than " 404 "GCPauseIntervalMillis (%u)", 405 MaxGCPauseMillis, GCPauseIntervalMillis); 406 vm_exit_during_initialization(buffer); 407 } 408 409 double max_gc_time = (double) MaxGCPauseMillis / 1000.0; 410 double time_slice = (double) GCPauseIntervalMillis / 1000.0; 411 _mmu_tracker = new G1MMUTrackerQueue(time_slice, max_gc_time); 412 _sigma = (double) G1ConfidencePercent / 100.0; 413 414 // start conservatively (around 50ms is about right) 415 _concurrent_mark_remark_times_ms->add(0.05); 416 _concurrent_mark_cleanup_times_ms->add(0.20); 417 _tenuring_threshold = MaxTenuringThreshold; 418 // _max_survivor_regions will be calculated by 419 // update_young_list_target_length() during initialization. 420 _max_survivor_regions = 0; 421 422 assert(GCTimeRatio > 0, 423 "we should have set it to a default value set_g1_gc_flags() " 424 "if a user set it to 0"); 425 _gc_overhead_perc = 100.0 * (1.0 / (1.0 + GCTimeRatio)); 426 427 uintx reserve_perc = G1ReservePercent; 428 // Put an artificial ceiling on this so that it's not set to a silly value. 429 if (reserve_perc > 50) { 430 reserve_perc = 50; 431 warning("G1ReservePercent is set to a value that is too large, " 432 "it's been updated to %u", reserve_perc); 433 } 434 _reserve_factor = (double) reserve_perc / 100.0; 435 // This will be set when the heap is expanded 436 // for the first time during initialization. 437 _reserve_regions = 0; 438 439 initialize_all(); 440 _collectionSetChooser = new CollectionSetChooser(); 441 } 442 443 // Increment "i", mod "len" 444 static void inc_mod(int& i, int len) { 445 i++; if (i == len) i = 0; 446 } 447 448 void G1CollectorPolicy::initialize_flags() { 449 set_min_alignment(HeapRegion::GrainBytes); 450 set_max_alignment(GenRemSet::max_alignment_constraint(rem_set_name())); 451 if (SurvivorRatio < 1) { 452 vm_exit_during_initialization("Invalid survivor ratio specified"); 453 } 454 CollectorPolicy::initialize_flags(); 455 } 456 457 // The easiest way to deal with the parsing of the NewSize / 458 // MaxNewSize / etc. parameteres is to re-use the code in the 459 // TwoGenerationCollectorPolicy class. This is similar to what 460 // ParallelScavenge does with its GenerationSizer class (see 461 // ParallelScavengeHeap::initialize()). We might change this in the 462 // future, but it's a good start. 463 class G1YoungGenSizer : public TwoGenerationCollectorPolicy { 464 private: 465 size_t size_to_region_num(size_t byte_size) { 466 return MAX2((size_t) 1, byte_size / HeapRegion::GrainBytes); 467 } 468 469 public: 470 G1YoungGenSizer() { 471 initialize_flags(); 472 initialize_size_info(); 473 } 474 size_t min_young_region_num() { 475 return size_to_region_num(_min_gen0_size); 476 } 477 size_t initial_young_region_num() { 478 return size_to_region_num(_initial_gen0_size); 479 } 480 size_t max_young_region_num() { 481 return size_to_region_num(_max_gen0_size); 482 } 483 }; 484 485 void G1CollectorPolicy::update_young_list_size_using_newratio(size_t number_of_heap_regions) { 486 assert(number_of_heap_regions > 0, "Heap must be initialized"); 487 size_t young_size = number_of_heap_regions / (NewRatio + 1); 488 _min_desired_young_length = young_size; 489 _max_desired_young_length = young_size; 490 } 491 492 void G1CollectorPolicy::init() { 493 // Set aside an initial future to_space. 494 _g1 = G1CollectedHeap::heap(); 495 496 assert(Heap_lock->owned_by_self(), "Locking discipline."); 497 498 initialize_gc_policy_counters(); 499 500 G1YoungGenSizer sizer; 501 size_t initial_region_num = sizer.initial_young_region_num(); 502 _min_desired_young_length = sizer.min_young_region_num(); 503 _max_desired_young_length = sizer.max_young_region_num(); 504 505 if (FLAG_IS_CMDLINE(NewRatio)) { 506 if (FLAG_IS_CMDLINE(NewSize) || FLAG_IS_CMDLINE(MaxNewSize)) { 507 warning("-XX:NewSize and -XX:MaxNewSize override -XX:NewRatio"); 508 } else { 509 // Treat NewRatio as a fixed size that is only recalculated when the heap size changes 510 update_young_list_size_using_newratio(_g1->n_regions()); 511 _using_new_ratio_calculations = true; 512 } 513 } 514 515 // GenCollectorPolicy guarantees that min <= initial <= max. 516 // Asserting here just to state that we rely on this property. 517 assert(_min_desired_young_length <= _max_desired_young_length, "Invalid min/max young gen size values"); 518 assert(initial_region_num <= _max_desired_young_length, "Initial young gen size too large"); 519 assert(_min_desired_young_length <= initial_region_num, "Initial young gen size too small"); 520 521 set_adaptive_young_list_length(_min_desired_young_length < _max_desired_young_length); 522 if (adaptive_young_list_length()) { 523 _young_list_fixed_length = 0; 524 } else { 525 _young_list_fixed_length = initial_region_num; 526 } 527 _free_regions_at_end_of_collection = _g1->free_regions(); 528 update_young_list_target_length(); 529 _prev_eden_capacity = _young_list_target_length * HeapRegion::GrainBytes; 530 531 // We may immediately start allocating regions and placing them on the 532 // collection set list. Initialize the per-collection set info 533 start_incremental_cset_building(); 534 } 535 536 // Create the jstat counters for the policy. 537 void G1CollectorPolicy::initialize_gc_policy_counters() { 538 _gc_policy_counters = new GCPolicyCounters("GarbageFirst", 1, 3); 539 } 540 541 bool G1CollectorPolicy::predict_will_fit(size_t young_length, 542 double base_time_ms, 543 size_t base_free_regions, 544 double target_pause_time_ms) { 545 if (young_length >= base_free_regions) { 546 // end condition 1: not enough space for the young regions 547 return false; 548 } 549 550 double accum_surv_rate = accum_yg_surv_rate_pred((int)(young_length - 1)); 551 size_t bytes_to_copy = 552 (size_t) (accum_surv_rate * (double) HeapRegion::GrainBytes); 553 double copy_time_ms = predict_object_copy_time_ms(bytes_to_copy); 554 double young_other_time_ms = predict_young_other_time_ms(young_length); 555 double pause_time_ms = base_time_ms + copy_time_ms + young_other_time_ms; 556 if (pause_time_ms > target_pause_time_ms) { 557 // end condition 2: prediction is over the target pause time 558 return false; 559 } 560 561 size_t free_bytes = 562 (base_free_regions - young_length) * HeapRegion::GrainBytes; 563 if ((2.0 * sigma()) * (double) bytes_to_copy > (double) free_bytes) { 564 // end condition 3: out-of-space (conservatively!) 565 return false; 566 } 567 568 // success! 569 return true; 570 } 571 572 void G1CollectorPolicy::record_new_heap_size(size_t new_number_of_regions) { 573 // re-calculate the necessary reserve 574 double reserve_regions_d = (double) new_number_of_regions * _reserve_factor; 575 // We use ceiling so that if reserve_regions_d is > 0.0 (but 576 // smaller than 1.0) we'll get 1. 577 _reserve_regions = (size_t) ceil(reserve_regions_d); 578 579 if (_using_new_ratio_calculations) { 580 // -XX:NewRatio was specified so we need to update the 581 // young gen length when the heap size has changed. 582 update_young_list_size_using_newratio(new_number_of_regions); 583 } 584 } 585 586 size_t G1CollectorPolicy::calculate_young_list_desired_min_length( 587 size_t base_min_length) { 588 size_t desired_min_length = 0; 589 if (adaptive_young_list_length()) { 590 if (_alloc_rate_ms_seq->num() > 3) { 591 double now_sec = os::elapsedTime(); 592 double when_ms = _mmu_tracker->when_max_gc_sec(now_sec) * 1000.0; 593 double alloc_rate_ms = predict_alloc_rate_ms(); 594 desired_min_length = (size_t) ceil(alloc_rate_ms * when_ms); 595 } else { 596 // otherwise we don't have enough info to make the prediction 597 } 598 } 599 desired_min_length += base_min_length; 600 // make sure we don't go below any user-defined minimum bound 601 return MAX2(_min_desired_young_length, desired_min_length); 602 } 603 604 size_t G1CollectorPolicy::calculate_young_list_desired_max_length() { 605 // Here, we might want to also take into account any additional 606 // constraints (i.e., user-defined minimum bound). Currently, we 607 // effectively don't set this bound. 608 return _max_desired_young_length; 609 } 610 611 void G1CollectorPolicy::update_young_list_target_length(size_t rs_lengths) { 612 if (rs_lengths == (size_t) -1) { 613 // if it's set to the default value (-1), we should predict it; 614 // otherwise, use the given value. 615 rs_lengths = (size_t) get_new_prediction(_rs_lengths_seq); 616 } 617 618 // Calculate the absolute and desired min bounds. 619 620 // This is how many young regions we already have (currently: the survivors). 621 size_t base_min_length = recorded_survivor_regions(); 622 // This is the absolute minimum young length, which ensures that we 623 // can allocate one eden region in the worst-case. 624 size_t absolute_min_length = base_min_length + 1; 625 size_t desired_min_length = 626 calculate_young_list_desired_min_length(base_min_length); 627 if (desired_min_length < absolute_min_length) { 628 desired_min_length = absolute_min_length; 629 } 630 631 // Calculate the absolute and desired max bounds. 632 633 // We will try our best not to "eat" into the reserve. 634 size_t absolute_max_length = 0; 635 if (_free_regions_at_end_of_collection > _reserve_regions) { 636 absolute_max_length = _free_regions_at_end_of_collection - _reserve_regions; 637 } 638 size_t desired_max_length = calculate_young_list_desired_max_length(); 639 if (desired_max_length > absolute_max_length) { 640 desired_max_length = absolute_max_length; 641 } 642 643 size_t young_list_target_length = 0; 644 if (adaptive_young_list_length()) { 645 if (full_young_gcs()) { 646 young_list_target_length = 647 calculate_young_list_target_length(rs_lengths, 648 base_min_length, 649 desired_min_length, 650 desired_max_length); 651 _rs_lengths_prediction = rs_lengths; 652 } else { 653 // Don't calculate anything and let the code below bound it to 654 // the desired_min_length, i.e., do the next GC as soon as 655 // possible to maximize how many old regions we can add to it. 656 } 657 } else { 658 if (full_young_gcs()) { 659 young_list_target_length = _young_list_fixed_length; 660 } else { 661 // A bit arbitrary: during partially-young GCs we allocate half 662 // the young regions to try to add old regions to the CSet. 663 young_list_target_length = _young_list_fixed_length / 2; 664 // We choose to accept that we might go under the desired min 665 // length given that we intentionally ask for a smaller young gen. 666 desired_min_length = absolute_min_length; 667 } 668 } 669 670 // Make sure we don't go over the desired max length, nor under the 671 // desired min length. In case they clash, desired_min_length wins 672 // which is why that test is second. 673 if (young_list_target_length > desired_max_length) { 674 young_list_target_length = desired_max_length; 675 } 676 if (young_list_target_length < desired_min_length) { 677 young_list_target_length = desired_min_length; 678 } 679 680 assert(young_list_target_length > recorded_survivor_regions(), 681 "we should be able to allocate at least one eden region"); 682 assert(young_list_target_length >= absolute_min_length, "post-condition"); 683 _young_list_target_length = young_list_target_length; 684 685 update_max_gc_locker_expansion(); 686 } 687 688 size_t 689 G1CollectorPolicy::calculate_young_list_target_length(size_t rs_lengths, 690 size_t base_min_length, 691 size_t desired_min_length, 692 size_t desired_max_length) { 693 assert(adaptive_young_list_length(), "pre-condition"); 694 assert(full_young_gcs(), "only call this for fully-young GCs"); 695 696 // In case some edge-condition makes the desired max length too small... 697 if (desired_max_length <= desired_min_length) { 698 return desired_min_length; 699 } 700 701 // We'll adjust min_young_length and max_young_length not to include 702 // the already allocated young regions (i.e., so they reflect the 703 // min and max eden regions we'll allocate). The base_min_length 704 // will be reflected in the predictions by the 705 // survivor_regions_evac_time prediction. 706 assert(desired_min_length > base_min_length, "invariant"); 707 size_t min_young_length = desired_min_length - base_min_length; 708 assert(desired_max_length > base_min_length, "invariant"); 709 size_t max_young_length = desired_max_length - base_min_length; 710 711 double target_pause_time_ms = _mmu_tracker->max_gc_time() * 1000.0; 712 double survivor_regions_evac_time = predict_survivor_regions_evac_time(); 713 size_t pending_cards = (size_t) get_new_prediction(_pending_cards_seq); 714 size_t adj_rs_lengths = rs_lengths + predict_rs_length_diff(); 715 size_t scanned_cards = predict_young_card_num(adj_rs_lengths); 716 double base_time_ms = 717 predict_base_elapsed_time_ms(pending_cards, scanned_cards) + 718 survivor_regions_evac_time; 719 size_t available_free_regions = _free_regions_at_end_of_collection; 720 size_t base_free_regions = 0; 721 if (available_free_regions > _reserve_regions) { 722 base_free_regions = available_free_regions - _reserve_regions; 723 } 724 725 // Here, we will make sure that the shortest young length that 726 // makes sense fits within the target pause time. 727 728 if (predict_will_fit(min_young_length, base_time_ms, 729 base_free_regions, target_pause_time_ms)) { 730 // The shortest young length will fit into the target pause time; 731 // we'll now check whether the absolute maximum number of young 732 // regions will fit in the target pause time. If not, we'll do 733 // a binary search between min_young_length and max_young_length. 734 if (predict_will_fit(max_young_length, base_time_ms, 735 base_free_regions, target_pause_time_ms)) { 736 // The maximum young length will fit into the target pause time. 737 // We are done so set min young length to the maximum length (as 738 // the result is assumed to be returned in min_young_length). 739 min_young_length = max_young_length; 740 } else { 741 // The maximum possible number of young regions will not fit within 742 // the target pause time so we'll search for the optimal 743 // length. The loop invariants are: 744 // 745 // min_young_length < max_young_length 746 // min_young_length is known to fit into the target pause time 747 // max_young_length is known not to fit into the target pause time 748 // 749 // Going into the loop we know the above hold as we've just 750 // checked them. Every time around the loop we check whether 751 // the middle value between min_young_length and 752 // max_young_length fits into the target pause time. If it 753 // does, it becomes the new min. If it doesn't, it becomes 754 // the new max. This way we maintain the loop invariants. 755 756 assert(min_young_length < max_young_length, "invariant"); 757 size_t diff = (max_young_length - min_young_length) / 2; 758 while (diff > 0) { 759 size_t young_length = min_young_length + diff; 760 if (predict_will_fit(young_length, base_time_ms, 761 base_free_regions, target_pause_time_ms)) { 762 min_young_length = young_length; 763 } else { 764 max_young_length = young_length; 765 } 766 assert(min_young_length < max_young_length, "invariant"); 767 diff = (max_young_length - min_young_length) / 2; 768 } 769 // The results is min_young_length which, according to the 770 // loop invariants, should fit within the target pause time. 771 772 // These are the post-conditions of the binary search above: 773 assert(min_young_length < max_young_length, 774 "otherwise we should have discovered that max_young_length " 775 "fits into the pause target and not done the binary search"); 776 assert(predict_will_fit(min_young_length, base_time_ms, 777 base_free_regions, target_pause_time_ms), 778 "min_young_length, the result of the binary search, should " 779 "fit into the pause target"); 780 assert(!predict_will_fit(min_young_length + 1, base_time_ms, 781 base_free_regions, target_pause_time_ms), 782 "min_young_length, the result of the binary search, should be " 783 "optimal, so no larger length should fit into the pause target"); 784 } 785 } else { 786 // Even the minimum length doesn't fit into the pause time 787 // target, return it as the result nevertheless. 788 } 789 return base_min_length + min_young_length; 790 } 791 792 double G1CollectorPolicy::predict_survivor_regions_evac_time() { 793 double survivor_regions_evac_time = 0.0; 794 for (HeapRegion * r = _recorded_survivor_head; 795 r != NULL && r != _recorded_survivor_tail->get_next_young_region(); 796 r = r->get_next_young_region()) { 797 survivor_regions_evac_time += predict_region_elapsed_time_ms(r, true); 798 } 799 return survivor_regions_evac_time; 800 } 801 802 void G1CollectorPolicy::revise_young_list_target_length_if_necessary() { 803 guarantee( adaptive_young_list_length(), "should not call this otherwise" ); 804 805 size_t rs_lengths = _g1->young_list()->sampled_rs_lengths(); 806 if (rs_lengths > _rs_lengths_prediction) { 807 // add 10% to avoid having to recalculate often 808 size_t rs_lengths_prediction = rs_lengths * 1100 / 1000; 809 update_young_list_target_length(rs_lengths_prediction); 810 } 811 } 812 813 814 815 HeapWord* G1CollectorPolicy::mem_allocate_work(size_t size, 816 bool is_tlab, 817 bool* gc_overhead_limit_was_exceeded) { 818 guarantee(false, "Not using this policy feature yet."); 819 return NULL; 820 } 821 822 // This method controls how a collector handles one or more 823 // of its generations being fully allocated. 824 HeapWord* G1CollectorPolicy::satisfy_failed_allocation(size_t size, 825 bool is_tlab) { 826 guarantee(false, "Not using this policy feature yet."); 827 return NULL; 828 } 829 830 831 #ifndef PRODUCT 832 bool G1CollectorPolicy::verify_young_ages() { 833 HeapRegion* head = _g1->young_list()->first_region(); 834 return 835 verify_young_ages(head, _short_lived_surv_rate_group); 836 // also call verify_young_ages on any additional surv rate groups 837 } 838 839 bool 840 G1CollectorPolicy::verify_young_ages(HeapRegion* head, 841 SurvRateGroup *surv_rate_group) { 842 guarantee( surv_rate_group != NULL, "pre-condition" ); 843 844 const char* name = surv_rate_group->name(); 845 bool ret = true; 846 int prev_age = -1; 847 848 for (HeapRegion* curr = head; 849 curr != NULL; 850 curr = curr->get_next_young_region()) { 851 SurvRateGroup* group = curr->surv_rate_group(); 852 if (group == NULL && !curr->is_survivor()) { 853 gclog_or_tty->print_cr("## %s: encountered NULL surv_rate_group", name); 854 ret = false; 855 } 856 857 if (surv_rate_group == group) { 858 int age = curr->age_in_surv_rate_group(); 859 860 if (age < 0) { 861 gclog_or_tty->print_cr("## %s: encountered negative age", name); 862 ret = false; 863 } 864 865 if (age <= prev_age) { 866 gclog_or_tty->print_cr("## %s: region ages are not strictly increasing " 867 "(%d, %d)", name, age, prev_age); 868 ret = false; 869 } 870 prev_age = age; 871 } 872 } 873 874 return ret; 875 } 876 #endif // PRODUCT 877 878 void G1CollectorPolicy::record_full_collection_start() { 879 _cur_collection_start_sec = os::elapsedTime(); 880 // Release the future to-space so that it is available for compaction into. 881 _g1->set_full_collection(); 882 } 883 884 void G1CollectorPolicy::record_full_collection_end() { 885 // Consider this like a collection pause for the purposes of allocation 886 // since last pause. 887 double end_sec = os::elapsedTime(); 888 double full_gc_time_sec = end_sec - _cur_collection_start_sec; 889 double full_gc_time_ms = full_gc_time_sec * 1000.0; 890 891 _all_full_gc_times_ms->add(full_gc_time_ms); 892 893 update_recent_gc_times(end_sec, full_gc_time_ms); 894 895 _g1->clear_full_collection(); 896 897 // "Nuke" the heuristics that control the fully/partially young GC 898 // transitions and make sure we start with fully young GCs after the 899 // Full GC. 900 set_full_young_gcs(true); 901 _last_full_young_gc = false; 902 _should_revert_to_full_young_gcs = false; 903 clear_initiate_conc_mark_if_possible(); 904 clear_during_initial_mark_pause(); 905 _known_garbage_bytes = 0; 906 _known_garbage_ratio = 0.0; 907 _in_marking_window = false; 908 _in_marking_window_im = false; 909 910 _short_lived_surv_rate_group->start_adding_regions(); 911 // also call this on any additional surv rate groups 912 913 record_survivor_regions(0, NULL, NULL); 914 915 _prev_region_num_young = _region_num_young; 916 _prev_region_num_tenured = _region_num_tenured; 917 918 _free_regions_at_end_of_collection = _g1->free_regions(); 919 // Reset survivors SurvRateGroup. 920 _survivor_surv_rate_group->reset(); 921 update_young_list_target_length(); 922 _collectionSetChooser->updateAfterFullCollection(); 923 } 924 925 void G1CollectorPolicy::record_stop_world_start() { 926 _stop_world_start = os::elapsedTime(); 927 } 928 929 void G1CollectorPolicy::record_collection_pause_start(double start_time_sec, 930 size_t start_used) { 931 if (PrintGCDetails) { 932 gclog_or_tty->stamp(PrintGCTimeStamps); 933 gclog_or_tty->print("[GC pause"); 934 gclog_or_tty->print(" (%s)", full_young_gcs() ? "young" : "partial"); 935 } 936 937 // We only need to do this here as the policy will only be applied 938 // to the GC we're about to start. so, no point is calculating this 939 // every time we calculate / recalculate the target young length. 940 update_survivors_policy(); 941 942 assert(_g1->used() == _g1->recalculate_used(), 943 err_msg("sanity, used: "SIZE_FORMAT" recalculate_used: "SIZE_FORMAT, 944 _g1->used(), _g1->recalculate_used())); 945 946 double s_w_t_ms = (start_time_sec - _stop_world_start) * 1000.0; 947 _all_stop_world_times_ms->add(s_w_t_ms); 948 _stop_world_start = 0.0; 949 950 _cur_collection_start_sec = start_time_sec; 951 _cur_collection_pause_used_at_start_bytes = start_used; 952 _cur_collection_pause_used_regions_at_start = _g1->used_regions(); 953 _pending_cards = _g1->pending_card_num(); 954 _max_pending_cards = _g1->max_pending_card_num(); 955 956 _bytes_in_collection_set_before_gc = 0; 957 _bytes_copied_during_gc = 0; 958 959 YoungList* young_list = _g1->young_list(); 960 _eden_bytes_before_gc = young_list->eden_used_bytes(); 961 _survivor_bytes_before_gc = young_list->survivor_used_bytes(); 962 _capacity_before_gc = _g1->capacity(); 963 964 #ifdef DEBUG 965 // initialise these to something well known so that we can spot 966 // if they are not set properly 967 968 for (int i = 0; i < _parallel_gc_threads; ++i) { 969 _par_last_gc_worker_start_times_ms[i] = -1234.0; 970 _par_last_ext_root_scan_times_ms[i] = -1234.0; 971 _par_last_mark_stack_scan_times_ms[i] = -1234.0; 972 _par_last_update_rs_times_ms[i] = -1234.0; 973 _par_last_update_rs_processed_buffers[i] = -1234.0; 974 _par_last_scan_rs_times_ms[i] = -1234.0; 975 _par_last_obj_copy_times_ms[i] = -1234.0; 976 _par_last_termination_times_ms[i] = -1234.0; 977 _par_last_termination_attempts[i] = -1234.0; 978 _par_last_gc_worker_end_times_ms[i] = -1234.0; 979 _par_last_gc_worker_times_ms[i] = -1234.0; 980 _par_last_gc_worker_other_times_ms[i] = -1234.0; 981 } 982 #endif 983 984 for (int i = 0; i < _aux_num; ++i) { 985 _cur_aux_times_ms[i] = 0.0; 986 _cur_aux_times_set[i] = false; 987 } 988 989 // These are initialized to zero here and they are set during 990 // the evacuation pause if marking is in progress. 991 _cur_satb_drain_time_ms = 0.0; 992 _last_satb_drain_processed_buffers = 0; 993 994 _last_young_gc_full = false; 995 996 // do that for any other surv rate groups 997 _short_lived_surv_rate_group->stop_adding_regions(); 998 _survivors_age_table.clear(); 999 1000 assert( verify_young_ages(), "region age verification" ); 1001 } 1002 1003 void G1CollectorPolicy::record_mark_closure_time(double mark_closure_time_ms) { 1004 _mark_closure_time_ms = mark_closure_time_ms; 1005 } 1006 1007 void G1CollectorPolicy::record_concurrent_mark_init_end(double 1008 mark_init_elapsed_time_ms) { 1009 _during_marking = true; 1010 assert(!initiate_conc_mark_if_possible(), "we should have cleared it by now"); 1011 clear_during_initial_mark_pause(); 1012 _cur_mark_stop_world_time_ms = mark_init_elapsed_time_ms; 1013 } 1014 1015 void G1CollectorPolicy::record_concurrent_mark_remark_start() { 1016 _mark_remark_start_sec = os::elapsedTime(); 1017 _during_marking = false; 1018 } 1019 1020 void G1CollectorPolicy::record_concurrent_mark_remark_end() { 1021 double end_time_sec = os::elapsedTime(); 1022 double elapsed_time_ms = (end_time_sec - _mark_remark_start_sec)*1000.0; 1023 _concurrent_mark_remark_times_ms->add(elapsed_time_ms); 1024 _cur_mark_stop_world_time_ms += elapsed_time_ms; 1025 _prev_collection_pause_end_ms += elapsed_time_ms; 1026 1027 _mmu_tracker->add_pause(_mark_remark_start_sec, end_time_sec, true); 1028 } 1029 1030 void G1CollectorPolicy::record_concurrent_mark_cleanup_start() { 1031 _mark_cleanup_start_sec = os::elapsedTime(); 1032 } 1033 1034 void G1CollectorPolicy::record_concurrent_mark_cleanup_completed() { 1035 _should_revert_to_full_young_gcs = false; 1036 _last_full_young_gc = true; 1037 _in_marking_window = false; 1038 } 1039 1040 void G1CollectorPolicy::record_concurrent_pause() { 1041 if (_stop_world_start > 0.0) { 1042 double yield_ms = (os::elapsedTime() - _stop_world_start) * 1000.0; 1043 _all_yield_times_ms->add(yield_ms); 1044 } 1045 } 1046 1047 void G1CollectorPolicy::record_concurrent_pause_end() { 1048 } 1049 1050 template<class T> 1051 T sum_of(T* sum_arr, int start, int n, int N) { 1052 T sum = (T)0; 1053 for (int i = 0; i < n; i++) { 1054 int j = (start + i) % N; 1055 sum += sum_arr[j]; 1056 } 1057 return sum; 1058 } 1059 1060 void G1CollectorPolicy::print_par_stats(int level, 1061 const char* str, 1062 double* data) { 1063 double min = data[0], max = data[0]; 1064 double total = 0.0; 1065 LineBuffer buf(level); 1066 buf.append("[%s (ms):", str); 1067 for (uint i = 0; i < ParallelGCThreads; ++i) { 1068 double val = data[i]; 1069 if (val < min) 1070 min = val; 1071 if (val > max) 1072 max = val; 1073 total += val; 1074 buf.append(" %3.1lf", val); 1075 } 1076 buf.append_and_print_cr(""); 1077 double avg = total / (double) ParallelGCThreads; 1078 buf.append_and_print_cr(" Avg: %5.1lf, Min: %5.1lf, Max: %5.1lf, Diff: %5.1lf]", 1079 avg, min, max, max - min); 1080 } 1081 1082 void G1CollectorPolicy::print_par_sizes(int level, 1083 const char* str, 1084 double* data) { 1085 double min = data[0], max = data[0]; 1086 double total = 0.0; 1087 LineBuffer buf(level); 1088 buf.append("[%s :", str); 1089 for (uint i = 0; i < ParallelGCThreads; ++i) { 1090 double val = data[i]; 1091 if (val < min) 1092 min = val; 1093 if (val > max) 1094 max = val; 1095 total += val; 1096 buf.append(" %d", (int) val); 1097 } 1098 buf.append_and_print_cr(""); 1099 double avg = total / (double) ParallelGCThreads; 1100 buf.append_and_print_cr(" Sum: %d, Avg: %d, Min: %d, Max: %d, Diff: %d]", 1101 (int)total, (int)avg, (int)min, (int)max, (int)max - (int)min); 1102 } 1103 1104 void G1CollectorPolicy::print_stats(int level, 1105 const char* str, 1106 double value) { 1107 LineBuffer(level).append_and_print_cr("[%s: %5.1lf ms]", str, value); 1108 } 1109 1110 void G1CollectorPolicy::print_stats(int level, 1111 const char* str, 1112 int value) { 1113 LineBuffer(level).append_and_print_cr("[%s: %d]", str, value); 1114 } 1115 1116 double G1CollectorPolicy::avg_value(double* data) { 1117 if (G1CollectedHeap::use_parallel_gc_threads()) { 1118 double ret = 0.0; 1119 for (uint i = 0; i < ParallelGCThreads; ++i) { 1120 ret += data[i]; 1121 } 1122 return ret / (double) ParallelGCThreads; 1123 } else { 1124 return data[0]; 1125 } 1126 } 1127 1128 double G1CollectorPolicy::max_value(double* data) { 1129 if (G1CollectedHeap::use_parallel_gc_threads()) { 1130 double ret = data[0]; 1131 for (uint i = 1; i < ParallelGCThreads; ++i) { 1132 if (data[i] > ret) { 1133 ret = data[i]; 1134 } 1135 } 1136 return ret; 1137 } else { 1138 return data[0]; 1139 } 1140 } 1141 1142 double G1CollectorPolicy::sum_of_values(double* data) { 1143 if (G1CollectedHeap::use_parallel_gc_threads()) { 1144 double sum = 0.0; 1145 for (uint i = 0; i < ParallelGCThreads; i++) { 1146 sum += data[i]; 1147 } 1148 return sum; 1149 } else { 1150 return data[0]; 1151 } 1152 } 1153 1154 double G1CollectorPolicy::max_sum(double* data1, double* data2) { 1155 double ret = data1[0] + data2[0]; 1156 1157 if (G1CollectedHeap::use_parallel_gc_threads()) { 1158 for (uint i = 1; i < ParallelGCThreads; ++i) { 1159 double data = data1[i] + data2[i]; 1160 if (data > ret) { 1161 ret = data; 1162 } 1163 } 1164 } 1165 return ret; 1166 } 1167 1168 // Anything below that is considered to be zero 1169 #define MIN_TIMER_GRANULARITY 0.0000001 1170 1171 void G1CollectorPolicy::record_collection_pause_end() { 1172 double end_time_sec = os::elapsedTime(); 1173 double elapsed_ms = _last_pause_time_ms; 1174 bool parallel = G1CollectedHeap::use_parallel_gc_threads(); 1175 size_t rs_size = 1176 _cur_collection_pause_used_regions_at_start - collection_set_size(); 1177 size_t cur_used_bytes = _g1->used(); 1178 assert(cur_used_bytes == _g1->recalculate_used(), "It should!"); 1179 bool last_pause_included_initial_mark = false; 1180 bool update_stats = !_g1->evacuation_failed(); 1181 1182 #ifndef PRODUCT 1183 if (G1YoungSurvRateVerbose) { 1184 gclog_or_tty->print_cr(""); 1185 _short_lived_surv_rate_group->print(); 1186 // do that for any other surv rate groups too 1187 } 1188 #endif // PRODUCT 1189 1190 last_pause_included_initial_mark = during_initial_mark_pause(); 1191 if (last_pause_included_initial_mark) 1192 record_concurrent_mark_init_end(0.0); 1193 1194 size_t marking_initiating_used_threshold = 1195 (_g1->capacity() / 100) * InitiatingHeapOccupancyPercent; 1196 1197 if (!_g1->mark_in_progress() && !_last_full_young_gc) { 1198 assert(!last_pause_included_initial_mark, "invariant"); 1199 if (cur_used_bytes > marking_initiating_used_threshold) { 1200 if (cur_used_bytes > _prev_collection_pause_used_at_end_bytes) { 1201 assert(!during_initial_mark_pause(), "we should not see this here"); 1202 1203 ergo_verbose3(ErgoConcCycles, 1204 "request concurrent cycle initiation", 1205 ergo_format_reason("occupancy higher than threshold") 1206 ergo_format_byte("occupancy") 1207 ergo_format_byte_perc("threshold"), 1208 cur_used_bytes, 1209 marking_initiating_used_threshold, 1210 (double) InitiatingHeapOccupancyPercent); 1211 1212 // Note: this might have already been set, if during the last 1213 // pause we decided to start a cycle but at the beginning of 1214 // this pause we decided to postpone it. That's OK. 1215 set_initiate_conc_mark_if_possible(); 1216 } else { 1217 ergo_verbose2(ErgoConcCycles, 1218 "do not request concurrent cycle initiation", 1219 ergo_format_reason("occupancy lower than previous occupancy") 1220 ergo_format_byte("occupancy") 1221 ergo_format_byte("previous occupancy"), 1222 cur_used_bytes, 1223 _prev_collection_pause_used_at_end_bytes); 1224 } 1225 } 1226 } 1227 1228 _prev_collection_pause_used_at_end_bytes = cur_used_bytes; 1229 1230 _mmu_tracker->add_pause(end_time_sec - elapsed_ms/1000.0, 1231 end_time_sec, false); 1232 1233 guarantee(_cur_collection_pause_used_regions_at_start >= 1234 collection_set_size(), 1235 "Negative RS size?"); 1236 1237 // This assert is exempted when we're doing parallel collection pauses, 1238 // because the fragmentation caused by the parallel GC allocation buffers 1239 // can lead to more memory being used during collection than was used 1240 // before. Best leave this out until the fragmentation problem is fixed. 1241 // Pauses in which evacuation failed can also lead to negative 1242 // collections, since no space is reclaimed from a region containing an 1243 // object whose evacuation failed. 1244 // Further, we're now always doing parallel collection. But I'm still 1245 // leaving this here as a placeholder for a more precise assertion later. 1246 // (DLD, 10/05.) 1247 assert((true || parallel) // Always using GC LABs now. 1248 || _g1->evacuation_failed() 1249 || _cur_collection_pause_used_at_start_bytes >= cur_used_bytes, 1250 "Negative collection"); 1251 1252 size_t freed_bytes = 1253 _cur_collection_pause_used_at_start_bytes - cur_used_bytes; 1254 size_t surviving_bytes = _collection_set_bytes_used_before - freed_bytes; 1255 1256 double survival_fraction = 1257 (double)surviving_bytes/ 1258 (double)_collection_set_bytes_used_before; 1259 1260 _n_pauses++; 1261 1262 // These values are used to update the summary information that is 1263 // displayed when TraceGen0Time is enabled, and are output as part 1264 // of the PrintGCDetails output, in the non-parallel case. 1265 1266 double ext_root_scan_time = avg_value(_par_last_ext_root_scan_times_ms); 1267 double mark_stack_scan_time = avg_value(_par_last_mark_stack_scan_times_ms); 1268 double update_rs_time = avg_value(_par_last_update_rs_times_ms); 1269 double update_rs_processed_buffers = 1270 sum_of_values(_par_last_update_rs_processed_buffers); 1271 double scan_rs_time = avg_value(_par_last_scan_rs_times_ms); 1272 double obj_copy_time = avg_value(_par_last_obj_copy_times_ms); 1273 double termination_time = avg_value(_par_last_termination_times_ms); 1274 1275 double known_time = ext_root_scan_time + 1276 mark_stack_scan_time + 1277 update_rs_time + 1278 scan_rs_time + 1279 obj_copy_time; 1280 1281 double other_time_ms = elapsed_ms; 1282 1283 // Subtract the SATB drain time. It's initialized to zero at the 1284 // start of the pause and is updated during the pause if marking 1285 // is in progress. 1286 other_time_ms -= _cur_satb_drain_time_ms; 1287 1288 if (parallel) { 1289 other_time_ms -= _cur_collection_par_time_ms; 1290 } else { 1291 other_time_ms -= known_time; 1292 } 1293 1294 // Subtract the time taken to clean the card table from the 1295 // current value of "other time" 1296 other_time_ms -= _cur_clear_ct_time_ms; 1297 1298 // TraceGen0Time and TraceGen1Time summary info updating. 1299 _all_pause_times_ms->add(elapsed_ms); 1300 1301 if (update_stats) { 1302 _recent_rs_scan_times_ms->add(scan_rs_time); 1303 _recent_pause_times_ms->add(elapsed_ms); 1304 _recent_rs_sizes->add(rs_size); 1305 1306 _summary->record_total_time_ms(elapsed_ms); 1307 _summary->record_other_time_ms(other_time_ms); 1308 1309 MainBodySummary* body_summary = _summary->main_body_summary(); 1310 assert(body_summary != NULL, "should not be null!"); 1311 1312 // This will be non-zero iff marking is currently in progress (i.e. 1313 // _g1->mark_in_progress() == true) and the currrent pause was not 1314 // an initial mark pause. Since the body_summary items are NumberSeqs, 1315 // however, they have to be consistent and updated in lock-step with 1316 // each other. Therefore we unconditionally record the SATB drain 1317 // time - even if it's zero. 1318 body_summary->record_satb_drain_time_ms(_cur_satb_drain_time_ms); 1319 1320 body_summary->record_ext_root_scan_time_ms(ext_root_scan_time); 1321 body_summary->record_mark_stack_scan_time_ms(mark_stack_scan_time); 1322 body_summary->record_update_rs_time_ms(update_rs_time); 1323 body_summary->record_scan_rs_time_ms(scan_rs_time); 1324 body_summary->record_obj_copy_time_ms(obj_copy_time); 1325 1326 if (parallel) { 1327 body_summary->record_parallel_time_ms(_cur_collection_par_time_ms); 1328 body_summary->record_termination_time_ms(termination_time); 1329 1330 double parallel_known_time = known_time + termination_time; 1331 double parallel_other_time = _cur_collection_par_time_ms - parallel_known_time; 1332 body_summary->record_parallel_other_time_ms(parallel_other_time); 1333 } 1334 1335 body_summary->record_mark_closure_time_ms(_mark_closure_time_ms); 1336 body_summary->record_clear_ct_time_ms(_cur_clear_ct_time_ms); 1337 1338 // We exempt parallel collection from this check because Alloc Buffer 1339 // fragmentation can produce negative collections. Same with evac 1340 // failure. 1341 // Further, we're now always doing parallel collection. But I'm still 1342 // leaving this here as a placeholder for a more precise assertion later. 1343 // (DLD, 10/05. 1344 assert((true || parallel) 1345 || _g1->evacuation_failed() 1346 || surviving_bytes <= _collection_set_bytes_used_before, 1347 "Or else negative collection!"); 1348 1349 _recent_CS_bytes_used_before->add(_collection_set_bytes_used_before); 1350 _recent_CS_bytes_surviving->add(surviving_bytes); 1351 1352 // this is where we update the allocation rate of the application 1353 double app_time_ms = 1354 (_cur_collection_start_sec * 1000.0 - _prev_collection_pause_end_ms); 1355 if (app_time_ms < MIN_TIMER_GRANULARITY) { 1356 // This usually happens due to the timer not having the required 1357 // granularity. Some Linuxes are the usual culprits. 1358 // We'll just set it to something (arbitrarily) small. 1359 app_time_ms = 1.0; 1360 } 1361 size_t regions_allocated = 1362 (_region_num_young - _prev_region_num_young) + 1363 (_region_num_tenured - _prev_region_num_tenured); 1364 double alloc_rate_ms = (double) regions_allocated / app_time_ms; 1365 _alloc_rate_ms_seq->add(alloc_rate_ms); 1366 _prev_region_num_young = _region_num_young; 1367 _prev_region_num_tenured = _region_num_tenured; 1368 1369 double interval_ms = 1370 (end_time_sec - _recent_prev_end_times_for_all_gcs_sec->oldest()) * 1000.0; 1371 update_recent_gc_times(end_time_sec, elapsed_ms); 1372 _recent_avg_pause_time_ratio = _recent_gc_times_ms->sum()/interval_ms; 1373 if (recent_avg_pause_time_ratio() < 0.0 || 1374 (recent_avg_pause_time_ratio() - 1.0 > 0.0)) { 1375 #ifndef PRODUCT 1376 // Dump info to allow post-facto debugging 1377 gclog_or_tty->print_cr("recent_avg_pause_time_ratio() out of bounds"); 1378 gclog_or_tty->print_cr("-------------------------------------------"); 1379 gclog_or_tty->print_cr("Recent GC Times (ms):"); 1380 _recent_gc_times_ms->dump(); 1381 gclog_or_tty->print_cr("(End Time=%3.3f) Recent GC End Times (s):", end_time_sec); 1382 _recent_prev_end_times_for_all_gcs_sec->dump(); 1383 gclog_or_tty->print_cr("GC = %3.3f, Interval = %3.3f, Ratio = %3.3f", 1384 _recent_gc_times_ms->sum(), interval_ms, recent_avg_pause_time_ratio()); 1385 // In debug mode, terminate the JVM if the user wants to debug at this point. 1386 assert(!G1FailOnFPError, "Debugging data for CR 6898948 has been dumped above"); 1387 #endif // !PRODUCT 1388 // Clip ratio between 0.0 and 1.0, and continue. This will be fixed in 1389 // CR 6902692 by redoing the manner in which the ratio is incrementally computed. 1390 if (_recent_avg_pause_time_ratio < 0.0) { 1391 _recent_avg_pause_time_ratio = 0.0; 1392 } else { 1393 assert(_recent_avg_pause_time_ratio - 1.0 > 0.0, "Ctl-point invariant"); 1394 _recent_avg_pause_time_ratio = 1.0; 1395 } 1396 } 1397 } 1398 1399 for (int i = 0; i < _aux_num; ++i) { 1400 if (_cur_aux_times_set[i]) { 1401 _all_aux_times_ms[i].add(_cur_aux_times_ms[i]); 1402 } 1403 } 1404 1405 1406 if (G1PolicyVerbose > 1) { 1407 gclog_or_tty->print_cr(" Recording collection pause(%d)", _n_pauses); 1408 } 1409 1410 if (G1PolicyVerbose > 1) { 1411 gclog_or_tty->print_cr(" ET: %10.6f ms (avg: %10.6f ms)\n" 1412 " ET-RS: %10.6f ms (avg: %10.6f ms)\n" 1413 " |RS|: " SIZE_FORMAT, 1414 elapsed_ms, recent_avg_time_for_pauses_ms(), 1415 scan_rs_time, recent_avg_time_for_rs_scan_ms(), 1416 rs_size); 1417 1418 gclog_or_tty->print_cr(" Used at start: " SIZE_FORMAT"K" 1419 " At end " SIZE_FORMAT "K\n" 1420 " garbage : " SIZE_FORMAT "K" 1421 " of " SIZE_FORMAT "K\n" 1422 " survival : %6.2f%% (%6.2f%% avg)", 1423 _cur_collection_pause_used_at_start_bytes/K, 1424 _g1->used()/K, freed_bytes/K, 1425 _collection_set_bytes_used_before/K, 1426 survival_fraction*100.0, 1427 recent_avg_survival_fraction()*100.0); 1428 gclog_or_tty->print_cr(" Recent %% gc pause time: %6.2f", 1429 recent_avg_pause_time_ratio() * 100.0); 1430 } 1431 1432 // PrintGCDetails output 1433 if (PrintGCDetails) { 1434 bool print_marking_info = 1435 _g1->mark_in_progress() && !last_pause_included_initial_mark; 1436 1437 gclog_or_tty->print_cr("%s, %1.8lf secs]", 1438 (last_pause_included_initial_mark) ? " (initial-mark)" : "", 1439 elapsed_ms / 1000.0); 1440 1441 if (print_marking_info) { 1442 print_stats(1, "SATB Drain Time", _cur_satb_drain_time_ms); 1443 print_stats(2, "Processed Buffers", _last_satb_drain_processed_buffers); 1444 } 1445 1446 if (parallel) { 1447 print_stats(1, "Parallel Time", _cur_collection_par_time_ms); 1448 print_par_stats(2, "GC Worker Start", _par_last_gc_worker_start_times_ms); 1449 print_par_stats(2, "Ext Root Scanning", _par_last_ext_root_scan_times_ms); 1450 if (print_marking_info) { 1451 print_par_stats(2, "Mark Stack Scanning", _par_last_mark_stack_scan_times_ms); 1452 } 1453 print_par_stats(2, "Update RS", _par_last_update_rs_times_ms); 1454 print_par_sizes(3, "Processed Buffers", _par_last_update_rs_processed_buffers); 1455 print_par_stats(2, "Scan RS", _par_last_scan_rs_times_ms); 1456 print_par_stats(2, "Object Copy", _par_last_obj_copy_times_ms); 1457 print_par_stats(2, "Termination", _par_last_termination_times_ms); 1458 print_par_sizes(3, "Termination Attempts", _par_last_termination_attempts); 1459 print_par_stats(2, "GC Worker End", _par_last_gc_worker_end_times_ms); 1460 1461 for (int i = 0; i < _parallel_gc_threads; i++) { 1462 _par_last_gc_worker_times_ms[i] = _par_last_gc_worker_end_times_ms[i] - _par_last_gc_worker_start_times_ms[i]; 1463 1464 double worker_known_time = _par_last_ext_root_scan_times_ms[i] + 1465 _par_last_mark_stack_scan_times_ms[i] + 1466 _par_last_update_rs_times_ms[i] + 1467 _par_last_scan_rs_times_ms[i] + 1468 _par_last_obj_copy_times_ms[i] + 1469 _par_last_termination_times_ms[i]; 1470 1471 _par_last_gc_worker_other_times_ms[i] = _cur_collection_par_time_ms - worker_known_time; 1472 } 1473 print_par_stats(2, "GC Worker", _par_last_gc_worker_times_ms); 1474 print_par_stats(2, "GC Worker Other", _par_last_gc_worker_other_times_ms); 1475 } else { 1476 print_stats(1, "Ext Root Scanning", ext_root_scan_time); 1477 if (print_marking_info) { 1478 print_stats(1, "Mark Stack Scanning", mark_stack_scan_time); 1479 } 1480 print_stats(1, "Update RS", update_rs_time); 1481 print_stats(2, "Processed Buffers", (int)update_rs_processed_buffers); 1482 print_stats(1, "Scan RS", scan_rs_time); 1483 print_stats(1, "Object Copying", obj_copy_time); 1484 } 1485 print_stats(1, "Clear CT", _cur_clear_ct_time_ms); 1486 #ifndef PRODUCT 1487 print_stats(1, "Cur Clear CC", _cur_clear_cc_time_ms); 1488 print_stats(1, "Cum Clear CC", _cum_clear_cc_time_ms); 1489 print_stats(1, "Min Clear CC", _min_clear_cc_time_ms); 1490 print_stats(1, "Max Clear CC", _max_clear_cc_time_ms); 1491 if (_num_cc_clears > 0) { 1492 print_stats(1, "Avg Clear CC", _cum_clear_cc_time_ms / ((double)_num_cc_clears)); 1493 } 1494 #endif 1495 print_stats(1, "Other", other_time_ms); 1496 print_stats(2, "Choose CSet", _recorded_young_cset_choice_time_ms); 1497 print_stats(2, "Ref Proc", _cur_ref_proc_time_ms); 1498 print_stats(2, "Ref Enq", _cur_ref_enq_time_ms); 1499 1500 for (int i = 0; i < _aux_num; ++i) { 1501 if (_cur_aux_times_set[i]) { 1502 char buffer[96]; 1503 sprintf(buffer, "Aux%d", i); 1504 print_stats(1, buffer, _cur_aux_times_ms[i]); 1505 } 1506 } 1507 } 1508 1509 // Update the efficiency-since-mark vars. 1510 double proc_ms = elapsed_ms * (double) _parallel_gc_threads; 1511 if (elapsed_ms < MIN_TIMER_GRANULARITY) { 1512 // This usually happens due to the timer not having the required 1513 // granularity. Some Linuxes are the usual culprits. 1514 // We'll just set it to something (arbitrarily) small. 1515 proc_ms = 1.0; 1516 } 1517 double cur_efficiency = (double) freed_bytes / proc_ms; 1518 1519 bool new_in_marking_window = _in_marking_window; 1520 bool new_in_marking_window_im = false; 1521 if (during_initial_mark_pause()) { 1522 new_in_marking_window = true; 1523 new_in_marking_window_im = true; 1524 } 1525 1526 if (_last_full_young_gc) { 1527 if (!last_pause_included_initial_mark) { 1528 ergo_verbose2(ErgoPartiallyYoungGCs, 1529 "start partially-young GCs", 1530 ergo_format_byte_perc("known garbage"), 1531 _known_garbage_bytes, _known_garbage_ratio * 100.0); 1532 set_full_young_gcs(false); 1533 } else { 1534 ergo_verbose0(ErgoPartiallyYoungGCs, 1535 "do not start partially-young GCs", 1536 ergo_format_reason("concurrent cycle is about to start")); 1537 } 1538 _last_full_young_gc = false; 1539 } 1540 1541 if ( !_last_young_gc_full ) { 1542 if (_should_revert_to_full_young_gcs) { 1543 ergo_verbose2(ErgoPartiallyYoungGCs, 1544 "end partially-young GCs", 1545 ergo_format_reason("partially-young GCs end requested") 1546 ergo_format_byte_perc("known garbage"), 1547 _known_garbage_bytes, _known_garbage_ratio * 100.0); 1548 set_full_young_gcs(true); 1549 } else if (_known_garbage_ratio < 0.05) { 1550 ergo_verbose3(ErgoPartiallyYoungGCs, 1551 "end partially-young GCs", 1552 ergo_format_reason("known garbage percent lower than threshold") 1553 ergo_format_byte_perc("known garbage") 1554 ergo_format_perc("threshold"), 1555 _known_garbage_bytes, _known_garbage_ratio * 100.0, 1556 0.05 * 100.0); 1557 set_full_young_gcs(true); 1558 } else if (adaptive_young_list_length() && 1559 (get_gc_eff_factor() * cur_efficiency < predict_young_gc_eff())) { 1560 ergo_verbose5(ErgoPartiallyYoungGCs, 1561 "end partially-young GCs", 1562 ergo_format_reason("current GC efficiency lower than " 1563 "predicted fully-young GC efficiency") 1564 ergo_format_double("GC efficiency factor") 1565 ergo_format_double("current GC efficiency") 1566 ergo_format_double("predicted fully-young GC efficiency") 1567 ergo_format_byte_perc("known garbage"), 1568 get_gc_eff_factor(), cur_efficiency, 1569 predict_young_gc_eff(), 1570 _known_garbage_bytes, _known_garbage_ratio * 100.0); 1571 set_full_young_gcs(true); 1572 } 1573 } 1574 _should_revert_to_full_young_gcs = false; 1575 1576 if (_last_young_gc_full && !_during_marking) { 1577 _young_gc_eff_seq->add(cur_efficiency); 1578 } 1579 1580 _short_lived_surv_rate_group->start_adding_regions(); 1581 // do that for any other surv rate groupsx 1582 1583 // <NEW PREDICTION> 1584 1585 if (update_stats) { 1586 double pause_time_ms = elapsed_ms; 1587 1588 size_t diff = 0; 1589 if (_max_pending_cards >= _pending_cards) 1590 diff = _max_pending_cards - _pending_cards; 1591 _pending_card_diff_seq->add((double) diff); 1592 1593 double cost_per_card_ms = 0.0; 1594 if (_pending_cards > 0) { 1595 cost_per_card_ms = update_rs_time / (double) _pending_cards; 1596 _cost_per_card_ms_seq->add(cost_per_card_ms); 1597 } 1598 1599 size_t cards_scanned = _g1->cards_scanned(); 1600 1601 double cost_per_entry_ms = 0.0; 1602 if (cards_scanned > 10) { 1603 cost_per_entry_ms = scan_rs_time / (double) cards_scanned; 1604 if (_last_young_gc_full) 1605 _cost_per_entry_ms_seq->add(cost_per_entry_ms); 1606 else 1607 _partially_young_cost_per_entry_ms_seq->add(cost_per_entry_ms); 1608 } 1609 1610 if (_max_rs_lengths > 0) { 1611 double cards_per_entry_ratio = 1612 (double) cards_scanned / (double) _max_rs_lengths; 1613 if (_last_young_gc_full) 1614 _fully_young_cards_per_entry_ratio_seq->add(cards_per_entry_ratio); 1615 else 1616 _partially_young_cards_per_entry_ratio_seq->add(cards_per_entry_ratio); 1617 } 1618 1619 size_t rs_length_diff = _max_rs_lengths - _recorded_rs_lengths; 1620 if (rs_length_diff >= 0) 1621 _rs_length_diff_seq->add((double) rs_length_diff); 1622 1623 size_t copied_bytes = surviving_bytes; 1624 double cost_per_byte_ms = 0.0; 1625 if (copied_bytes > 0) { 1626 cost_per_byte_ms = obj_copy_time / (double) copied_bytes; 1627 if (_in_marking_window) 1628 _cost_per_byte_ms_during_cm_seq->add(cost_per_byte_ms); 1629 else 1630 _cost_per_byte_ms_seq->add(cost_per_byte_ms); 1631 } 1632 1633 double all_other_time_ms = pause_time_ms - 1634 (update_rs_time + scan_rs_time + obj_copy_time + 1635 _mark_closure_time_ms + termination_time); 1636 1637 double young_other_time_ms = 0.0; 1638 if (_recorded_young_regions > 0) { 1639 young_other_time_ms = 1640 _recorded_young_cset_choice_time_ms + 1641 _recorded_young_free_cset_time_ms; 1642 _young_other_cost_per_region_ms_seq->add(young_other_time_ms / 1643 (double) _recorded_young_regions); 1644 } 1645 double non_young_other_time_ms = 0.0; 1646 if (_recorded_non_young_regions > 0) { 1647 non_young_other_time_ms = 1648 _recorded_non_young_cset_choice_time_ms + 1649 _recorded_non_young_free_cset_time_ms; 1650 1651 _non_young_other_cost_per_region_ms_seq->add(non_young_other_time_ms / 1652 (double) _recorded_non_young_regions); 1653 } 1654 1655 double constant_other_time_ms = all_other_time_ms - 1656 (young_other_time_ms + non_young_other_time_ms); 1657 _constant_other_time_ms_seq->add(constant_other_time_ms); 1658 1659 double survival_ratio = 0.0; 1660 if (_bytes_in_collection_set_before_gc > 0) { 1661 survival_ratio = (double) _bytes_copied_during_gc / 1662 (double) _bytes_in_collection_set_before_gc; 1663 } 1664 1665 _pending_cards_seq->add((double) _pending_cards); 1666 _scanned_cards_seq->add((double) cards_scanned); 1667 _rs_lengths_seq->add((double) _max_rs_lengths); 1668 1669 double expensive_region_limit_ms = 1670 (double) MaxGCPauseMillis - predict_constant_other_time_ms(); 1671 if (expensive_region_limit_ms < 0.0) { 1672 // this means that the other time was predicted to be longer than 1673 // than the max pause time 1674 expensive_region_limit_ms = (double) MaxGCPauseMillis; 1675 } 1676 _expensive_region_limit_ms = expensive_region_limit_ms; 1677 1678 if (PREDICTIONS_VERBOSE) { 1679 gclog_or_tty->print_cr(""); 1680 gclog_or_tty->print_cr("PREDICTIONS %1.4lf %d " 1681 "REGIONS %d %d %d " 1682 "PENDING_CARDS %d %d " 1683 "CARDS_SCANNED %d %d " 1684 "RS_LENGTHS %d %d " 1685 "RS_UPDATE %1.6lf %1.6lf RS_SCAN %1.6lf %1.6lf " 1686 "SURVIVAL_RATIO %1.6lf %1.6lf " 1687 "OBJECT_COPY %1.6lf %1.6lf OTHER_CONSTANT %1.6lf %1.6lf " 1688 "OTHER_YOUNG %1.6lf %1.6lf " 1689 "OTHER_NON_YOUNG %1.6lf %1.6lf " 1690 "VTIME_DIFF %1.6lf TERMINATION %1.6lf " 1691 "ELAPSED %1.6lf %1.6lf ", 1692 _cur_collection_start_sec, 1693 (!_last_young_gc_full) ? 2 : 1694 (last_pause_included_initial_mark) ? 1 : 0, 1695 _recorded_region_num, 1696 _recorded_young_regions, 1697 _recorded_non_young_regions, 1698 _predicted_pending_cards, _pending_cards, 1699 _predicted_cards_scanned, cards_scanned, 1700 _predicted_rs_lengths, _max_rs_lengths, 1701 _predicted_rs_update_time_ms, update_rs_time, 1702 _predicted_rs_scan_time_ms, scan_rs_time, 1703 _predicted_survival_ratio, survival_ratio, 1704 _predicted_object_copy_time_ms, obj_copy_time, 1705 _predicted_constant_other_time_ms, constant_other_time_ms, 1706 _predicted_young_other_time_ms, young_other_time_ms, 1707 _predicted_non_young_other_time_ms, 1708 non_young_other_time_ms, 1709 _vtime_diff_ms, termination_time, 1710 _predicted_pause_time_ms, elapsed_ms); 1711 } 1712 1713 if (G1PolicyVerbose > 0) { 1714 gclog_or_tty->print_cr("Pause Time, predicted: %1.4lfms (predicted %s), actual: %1.4lfms", 1715 _predicted_pause_time_ms, 1716 (_within_target) ? "within" : "outside", 1717 elapsed_ms); 1718 } 1719 1720 } 1721 1722 _in_marking_window = new_in_marking_window; 1723 _in_marking_window_im = new_in_marking_window_im; 1724 _free_regions_at_end_of_collection = _g1->free_regions(); 1725 update_young_list_target_length(); 1726 1727 // Note that _mmu_tracker->max_gc_time() returns the time in seconds. 1728 double update_rs_time_goal_ms = _mmu_tracker->max_gc_time() * MILLIUNITS * G1RSetUpdatingPauseTimePercent / 100.0; 1729 adjust_concurrent_refinement(update_rs_time, update_rs_processed_buffers, update_rs_time_goal_ms); 1730 // </NEW PREDICTION> 1731 1732 assert(assertMarkedBytesDataOK(), "Marked regions not OK at pause end."); 1733 } 1734 1735 #define EXT_SIZE_FORMAT "%d%s" 1736 #define EXT_SIZE_PARAMS(bytes) \ 1737 byte_size_in_proper_unit((bytes)), \ 1738 proper_unit_for_byte_size((bytes)) 1739 1740 void G1CollectorPolicy::print_heap_transition() { 1741 if (PrintGCDetails) { 1742 YoungList* young_list = _g1->young_list(); 1743 size_t eden_bytes = young_list->eden_used_bytes(); 1744 size_t survivor_bytes = young_list->survivor_used_bytes(); 1745 size_t used_before_gc = _cur_collection_pause_used_at_start_bytes; 1746 size_t used = _g1->used(); 1747 size_t capacity = _g1->capacity(); 1748 size_t eden_capacity = 1749 (_young_list_target_length * HeapRegion::GrainBytes) - survivor_bytes; 1750 1751 gclog_or_tty->print_cr( 1752 " [Eden: "EXT_SIZE_FORMAT"("EXT_SIZE_FORMAT")->"EXT_SIZE_FORMAT"("EXT_SIZE_FORMAT") " 1753 "Survivors: "EXT_SIZE_FORMAT"->"EXT_SIZE_FORMAT" " 1754 "Heap: "EXT_SIZE_FORMAT"("EXT_SIZE_FORMAT")->" 1755 EXT_SIZE_FORMAT"("EXT_SIZE_FORMAT")]", 1756 EXT_SIZE_PARAMS(_eden_bytes_before_gc), 1757 EXT_SIZE_PARAMS(_prev_eden_capacity), 1758 EXT_SIZE_PARAMS(eden_bytes), 1759 EXT_SIZE_PARAMS(eden_capacity), 1760 EXT_SIZE_PARAMS(_survivor_bytes_before_gc), 1761 EXT_SIZE_PARAMS(survivor_bytes), 1762 EXT_SIZE_PARAMS(used_before_gc), 1763 EXT_SIZE_PARAMS(_capacity_before_gc), 1764 EXT_SIZE_PARAMS(used), 1765 EXT_SIZE_PARAMS(capacity)); 1766 1767 _prev_eden_capacity = eden_capacity; 1768 } else if (PrintGC) { 1769 _g1->print_size_transition(gclog_or_tty, 1770 _cur_collection_pause_used_at_start_bytes, 1771 _g1->used(), _g1->capacity()); 1772 } 1773 } 1774 1775 // <NEW PREDICTION> 1776 1777 void G1CollectorPolicy::adjust_concurrent_refinement(double update_rs_time, 1778 double update_rs_processed_buffers, 1779 double goal_ms) { 1780 DirtyCardQueueSet& dcqs = JavaThread::dirty_card_queue_set(); 1781 ConcurrentG1Refine *cg1r = G1CollectedHeap::heap()->concurrent_g1_refine(); 1782 1783 if (G1UseAdaptiveConcRefinement) { 1784 const int k_gy = 3, k_gr = 6; 1785 const double inc_k = 1.1, dec_k = 0.9; 1786 1787 int g = cg1r->green_zone(); 1788 if (update_rs_time > goal_ms) { 1789 g = (int)(g * dec_k); // Can become 0, that's OK. That would mean a mutator-only processing. 1790 } else { 1791 if (update_rs_time < goal_ms && update_rs_processed_buffers > g) { 1792 g = (int)MAX2(g * inc_k, g + 1.0); 1793 } 1794 } 1795 // Change the refinement threads params 1796 cg1r->set_green_zone(g); 1797 cg1r->set_yellow_zone(g * k_gy); 1798 cg1r->set_red_zone(g * k_gr); 1799 cg1r->reinitialize_threads(); 1800 1801 int processing_threshold_delta = MAX2((int)(cg1r->green_zone() * sigma()), 1); 1802 int processing_threshold = MIN2(cg1r->green_zone() + processing_threshold_delta, 1803 cg1r->yellow_zone()); 1804 // Change the barrier params 1805 dcqs.set_process_completed_threshold(processing_threshold); 1806 dcqs.set_max_completed_queue(cg1r->red_zone()); 1807 } 1808 1809 int curr_queue_size = dcqs.completed_buffers_num(); 1810 if (curr_queue_size >= cg1r->yellow_zone()) { 1811 dcqs.set_completed_queue_padding(curr_queue_size); 1812 } else { 1813 dcqs.set_completed_queue_padding(0); 1814 } 1815 dcqs.notify_if_necessary(); 1816 } 1817 1818 double 1819 G1CollectorPolicy:: 1820 predict_young_collection_elapsed_time_ms(size_t adjustment) { 1821 guarantee( adjustment == 0 || adjustment == 1, "invariant" ); 1822 1823 G1CollectedHeap* g1h = G1CollectedHeap::heap(); 1824 size_t young_num = g1h->young_list()->length(); 1825 if (young_num == 0) 1826 return 0.0; 1827 1828 young_num += adjustment; 1829 size_t pending_cards = predict_pending_cards(); 1830 size_t rs_lengths = g1h->young_list()->sampled_rs_lengths() + 1831 predict_rs_length_diff(); 1832 size_t card_num; 1833 if (full_young_gcs()) 1834 card_num = predict_young_card_num(rs_lengths); 1835 else 1836 card_num = predict_non_young_card_num(rs_lengths); 1837 size_t young_byte_size = young_num * HeapRegion::GrainBytes; 1838 double accum_yg_surv_rate = 1839 _short_lived_surv_rate_group->accum_surv_rate(adjustment); 1840 1841 size_t bytes_to_copy = 1842 (size_t) (accum_yg_surv_rate * (double) HeapRegion::GrainBytes); 1843 1844 return 1845 predict_rs_update_time_ms(pending_cards) + 1846 predict_rs_scan_time_ms(card_num) + 1847 predict_object_copy_time_ms(bytes_to_copy) + 1848 predict_young_other_time_ms(young_num) + 1849 predict_constant_other_time_ms(); 1850 } 1851 1852 double 1853 G1CollectorPolicy::predict_base_elapsed_time_ms(size_t pending_cards) { 1854 size_t rs_length = predict_rs_length_diff(); 1855 size_t card_num; 1856 if (full_young_gcs()) 1857 card_num = predict_young_card_num(rs_length); 1858 else 1859 card_num = predict_non_young_card_num(rs_length); 1860 return predict_base_elapsed_time_ms(pending_cards, card_num); 1861 } 1862 1863 double 1864 G1CollectorPolicy::predict_base_elapsed_time_ms(size_t pending_cards, 1865 size_t scanned_cards) { 1866 return 1867 predict_rs_update_time_ms(pending_cards) + 1868 predict_rs_scan_time_ms(scanned_cards) + 1869 predict_constant_other_time_ms(); 1870 } 1871 1872 double 1873 G1CollectorPolicy::predict_region_elapsed_time_ms(HeapRegion* hr, 1874 bool young) { 1875 size_t rs_length = hr->rem_set()->occupied(); 1876 size_t card_num; 1877 if (full_young_gcs()) 1878 card_num = predict_young_card_num(rs_length); 1879 else 1880 card_num = predict_non_young_card_num(rs_length); 1881 size_t bytes_to_copy = predict_bytes_to_copy(hr); 1882 1883 double region_elapsed_time_ms = 1884 predict_rs_scan_time_ms(card_num) + 1885 predict_object_copy_time_ms(bytes_to_copy); 1886 1887 if (young) 1888 region_elapsed_time_ms += predict_young_other_time_ms(1); 1889 else 1890 region_elapsed_time_ms += predict_non_young_other_time_ms(1); 1891 1892 return region_elapsed_time_ms; 1893 } 1894 1895 size_t 1896 G1CollectorPolicy::predict_bytes_to_copy(HeapRegion* hr) { 1897 size_t bytes_to_copy; 1898 if (hr->is_marked()) 1899 bytes_to_copy = hr->max_live_bytes(); 1900 else { 1901 guarantee( hr->is_young() && hr->age_in_surv_rate_group() != -1, 1902 "invariant" ); 1903 int age = hr->age_in_surv_rate_group(); 1904 double yg_surv_rate = predict_yg_surv_rate(age, hr->surv_rate_group()); 1905 bytes_to_copy = (size_t) ((double) hr->used() * yg_surv_rate); 1906 } 1907 1908 return bytes_to_copy; 1909 } 1910 1911 void 1912 G1CollectorPolicy::start_recording_regions() { 1913 _recorded_rs_lengths = 0; 1914 _recorded_young_regions = 0; 1915 _recorded_non_young_regions = 0; 1916 1917 #if PREDICTIONS_VERBOSE 1918 _recorded_marked_bytes = 0; 1919 _recorded_young_bytes = 0; 1920 _predicted_bytes_to_copy = 0; 1921 _predicted_rs_lengths = 0; 1922 _predicted_cards_scanned = 0; 1923 #endif // PREDICTIONS_VERBOSE 1924 } 1925 1926 void 1927 G1CollectorPolicy::record_cset_region_info(HeapRegion* hr, bool young) { 1928 #if PREDICTIONS_VERBOSE 1929 if (!young) { 1930 _recorded_marked_bytes += hr->max_live_bytes(); 1931 } 1932 _predicted_bytes_to_copy += predict_bytes_to_copy(hr); 1933 #endif // PREDICTIONS_VERBOSE 1934 1935 size_t rs_length = hr->rem_set()->occupied(); 1936 _recorded_rs_lengths += rs_length; 1937 } 1938 1939 void 1940 G1CollectorPolicy::record_non_young_cset_region(HeapRegion* hr) { 1941 assert(!hr->is_young(), "should not call this"); 1942 ++_recorded_non_young_regions; 1943 record_cset_region_info(hr, false); 1944 } 1945 1946 void 1947 G1CollectorPolicy::set_recorded_young_regions(size_t n_regions) { 1948 _recorded_young_regions = n_regions; 1949 } 1950 1951 void G1CollectorPolicy::set_recorded_young_bytes(size_t bytes) { 1952 #if PREDICTIONS_VERBOSE 1953 _recorded_young_bytes = bytes; 1954 #endif // PREDICTIONS_VERBOSE 1955 } 1956 1957 void G1CollectorPolicy::set_recorded_rs_lengths(size_t rs_lengths) { 1958 _recorded_rs_lengths = rs_lengths; 1959 } 1960 1961 void G1CollectorPolicy::set_predicted_bytes_to_copy(size_t bytes) { 1962 _predicted_bytes_to_copy = bytes; 1963 } 1964 1965 void 1966 G1CollectorPolicy::end_recording_regions() { 1967 // The _predicted_pause_time_ms field is referenced in code 1968 // not under PREDICTIONS_VERBOSE. Let's initialize it. 1969 _predicted_pause_time_ms = -1.0; 1970 1971 #if PREDICTIONS_VERBOSE 1972 _predicted_pending_cards = predict_pending_cards(); 1973 _predicted_rs_lengths = _recorded_rs_lengths + predict_rs_length_diff(); 1974 if (full_young_gcs()) 1975 _predicted_cards_scanned += predict_young_card_num(_predicted_rs_lengths); 1976 else 1977 _predicted_cards_scanned += 1978 predict_non_young_card_num(_predicted_rs_lengths); 1979 _recorded_region_num = _recorded_young_regions + _recorded_non_young_regions; 1980 1981 _predicted_rs_update_time_ms = 1982 predict_rs_update_time_ms(_g1->pending_card_num()); 1983 _predicted_rs_scan_time_ms = 1984 predict_rs_scan_time_ms(_predicted_cards_scanned); 1985 _predicted_object_copy_time_ms = 1986 predict_object_copy_time_ms(_predicted_bytes_to_copy); 1987 _predicted_constant_other_time_ms = 1988 predict_constant_other_time_ms(); 1989 _predicted_young_other_time_ms = 1990 predict_young_other_time_ms(_recorded_young_regions); 1991 _predicted_non_young_other_time_ms = 1992 predict_non_young_other_time_ms(_recorded_non_young_regions); 1993 1994 _predicted_pause_time_ms = 1995 _predicted_rs_update_time_ms + 1996 _predicted_rs_scan_time_ms + 1997 _predicted_object_copy_time_ms + 1998 _predicted_constant_other_time_ms + 1999 _predicted_young_other_time_ms + 2000 _predicted_non_young_other_time_ms; 2001 #endif // PREDICTIONS_VERBOSE 2002 } 2003 2004 void G1CollectorPolicy::check_if_region_is_too_expensive(double 2005 predicted_time_ms) { 2006 // I don't think we need to do this when in young GC mode since 2007 // marking will be initiated next time we hit the soft limit anyway... 2008 if (predicted_time_ms > _expensive_region_limit_ms) { 2009 ergo_verbose2(ErgoPartiallyYoungGCs, 2010 "request partially-young GCs end", 2011 ergo_format_reason("predicted region time higher than threshold") 2012 ergo_format_ms("predicted region time") 2013 ergo_format_ms("threshold"), 2014 predicted_time_ms, _expensive_region_limit_ms); 2015 // no point in doing another partial one 2016 _should_revert_to_full_young_gcs = true; 2017 } 2018 } 2019 2020 // </NEW PREDICTION> 2021 2022 2023 void G1CollectorPolicy::update_recent_gc_times(double end_time_sec, 2024 double elapsed_ms) { 2025 _recent_gc_times_ms->add(elapsed_ms); 2026 _recent_prev_end_times_for_all_gcs_sec->add(end_time_sec); 2027 _prev_collection_pause_end_ms = end_time_sec * 1000.0; 2028 } 2029 2030 double G1CollectorPolicy::recent_avg_time_for_pauses_ms() { 2031 if (_recent_pause_times_ms->num() == 0) { 2032 return (double) MaxGCPauseMillis; 2033 } 2034 return _recent_pause_times_ms->avg(); 2035 } 2036 2037 double G1CollectorPolicy::recent_avg_time_for_rs_scan_ms() { 2038 if (_recent_rs_scan_times_ms->num() == 0) { 2039 return (double)MaxGCPauseMillis/3.0; 2040 } 2041 return _recent_rs_scan_times_ms->avg(); 2042 } 2043 2044 int G1CollectorPolicy::number_of_recent_gcs() { 2045 assert(_recent_rs_scan_times_ms->num() == 2046 _recent_pause_times_ms->num(), "Sequence out of sync"); 2047 assert(_recent_pause_times_ms->num() == 2048 _recent_CS_bytes_used_before->num(), "Sequence out of sync"); 2049 assert(_recent_CS_bytes_used_before->num() == 2050 _recent_CS_bytes_surviving->num(), "Sequence out of sync"); 2051 2052 return _recent_pause_times_ms->num(); 2053 } 2054 2055 double G1CollectorPolicy::recent_avg_survival_fraction() { 2056 return recent_avg_survival_fraction_work(_recent_CS_bytes_surviving, 2057 _recent_CS_bytes_used_before); 2058 } 2059 2060 double G1CollectorPolicy::last_survival_fraction() { 2061 return last_survival_fraction_work(_recent_CS_bytes_surviving, 2062 _recent_CS_bytes_used_before); 2063 } 2064 2065 double 2066 G1CollectorPolicy::recent_avg_survival_fraction_work(TruncatedSeq* surviving, 2067 TruncatedSeq* before) { 2068 assert(surviving->num() == before->num(), "Sequence out of sync"); 2069 if (before->sum() > 0.0) { 2070 double recent_survival_rate = surviving->sum() / before->sum(); 2071 // We exempt parallel collection from this check because Alloc Buffer 2072 // fragmentation can produce negative collections. 2073 // Further, we're now always doing parallel collection. But I'm still 2074 // leaving this here as a placeholder for a more precise assertion later. 2075 // (DLD, 10/05.) 2076 assert((true || G1CollectedHeap::use_parallel_gc_threads()) || 2077 _g1->evacuation_failed() || 2078 recent_survival_rate <= 1.0, "Or bad frac"); 2079 return recent_survival_rate; 2080 } else { 2081 return 1.0; // Be conservative. 2082 } 2083 } 2084 2085 double 2086 G1CollectorPolicy::last_survival_fraction_work(TruncatedSeq* surviving, 2087 TruncatedSeq* before) { 2088 assert(surviving->num() == before->num(), "Sequence out of sync"); 2089 if (surviving->num() > 0 && before->last() > 0.0) { 2090 double last_survival_rate = surviving->last() / before->last(); 2091 // We exempt parallel collection from this check because Alloc Buffer 2092 // fragmentation can produce negative collections. 2093 // Further, we're now always doing parallel collection. But I'm still 2094 // leaving this here as a placeholder for a more precise assertion later. 2095 // (DLD, 10/05.) 2096 assert((true || G1CollectedHeap::use_parallel_gc_threads()) || 2097 last_survival_rate <= 1.0, "Or bad frac"); 2098 return last_survival_rate; 2099 } else { 2100 return 1.0; 2101 } 2102 } 2103 2104 static const int survival_min_obs = 5; 2105 static double survival_min_obs_limits[] = { 0.9, 0.7, 0.5, 0.3, 0.1 }; 2106 static const double min_survival_rate = 0.1; 2107 2108 double 2109 G1CollectorPolicy::conservative_avg_survival_fraction_work(double avg, 2110 double latest) { 2111 double res = avg; 2112 if (number_of_recent_gcs() < survival_min_obs) { 2113 res = MAX2(res, survival_min_obs_limits[number_of_recent_gcs()]); 2114 } 2115 res = MAX2(res, latest); 2116 res = MAX2(res, min_survival_rate); 2117 // In the parallel case, LAB fragmentation can produce "negative 2118 // collections"; so can evac failure. Cap at 1.0 2119 res = MIN2(res, 1.0); 2120 return res; 2121 } 2122 2123 size_t G1CollectorPolicy::expansion_amount() { 2124 double recent_gc_overhead = recent_avg_pause_time_ratio() * 100.0; 2125 double threshold = _gc_overhead_perc; 2126 if (recent_gc_overhead > threshold) { 2127 // We will double the existing space, or take 2128 // G1ExpandByPercentOfAvailable % of the available expansion 2129 // space, whichever is smaller, bounded below by a minimum 2130 // expansion (unless that's all that's left.) 2131 const size_t min_expand_bytes = 1*M; 2132 size_t reserved_bytes = _g1->max_capacity(); 2133 size_t committed_bytes = _g1->capacity(); 2134 size_t uncommitted_bytes = reserved_bytes - committed_bytes; 2135 size_t expand_bytes; 2136 size_t expand_bytes_via_pct = 2137 uncommitted_bytes * G1ExpandByPercentOfAvailable / 100; 2138 expand_bytes = MIN2(expand_bytes_via_pct, committed_bytes); 2139 expand_bytes = MAX2(expand_bytes, min_expand_bytes); 2140 expand_bytes = MIN2(expand_bytes, uncommitted_bytes); 2141 2142 ergo_verbose5(ErgoHeapSizing, 2143 "attempt heap expansion", 2144 ergo_format_reason("recent GC overhead higher than " 2145 "threshold after GC") 2146 ergo_format_perc("recent GC overhead") 2147 ergo_format_perc("threshold") 2148 ergo_format_byte("uncommitted") 2149 ergo_format_byte_perc("calculated expansion amount"), 2150 recent_gc_overhead, threshold, 2151 uncommitted_bytes, 2152 expand_bytes_via_pct, (double) G1ExpandByPercentOfAvailable); 2153 2154 return expand_bytes; 2155 } else { 2156 return 0; 2157 } 2158 } 2159 2160 class CountCSClosure: public HeapRegionClosure { 2161 G1CollectorPolicy* _g1_policy; 2162 public: 2163 CountCSClosure(G1CollectorPolicy* g1_policy) : 2164 _g1_policy(g1_policy) {} 2165 bool doHeapRegion(HeapRegion* r) { 2166 _g1_policy->_bytes_in_collection_set_before_gc += r->used(); 2167 return false; 2168 } 2169 }; 2170 2171 void G1CollectorPolicy::count_CS_bytes_used() { 2172 CountCSClosure cs_closure(this); 2173 _g1->collection_set_iterate(&cs_closure); 2174 } 2175 2176 void G1CollectorPolicy::print_summary(int level, 2177 const char* str, 2178 NumberSeq* seq) const { 2179 double sum = seq->sum(); 2180 LineBuffer(level + 1).append_and_print_cr("%-24s = %8.2lf s (avg = %8.2lf ms)", 2181 str, sum / 1000.0, seq->avg()); 2182 } 2183 2184 void G1CollectorPolicy::print_summary_sd(int level, 2185 const char* str, 2186 NumberSeq* seq) const { 2187 print_summary(level, str, seq); 2188 LineBuffer(level + 6).append_and_print_cr("(num = %5d, std dev = %8.2lf ms, max = %8.2lf ms)", 2189 seq->num(), seq->sd(), seq->maximum()); 2190 } 2191 2192 void G1CollectorPolicy::check_other_times(int level, 2193 NumberSeq* other_times_ms, 2194 NumberSeq* calc_other_times_ms) const { 2195 bool should_print = false; 2196 LineBuffer buf(level + 2); 2197 2198 double max_sum = MAX2(fabs(other_times_ms->sum()), 2199 fabs(calc_other_times_ms->sum())); 2200 double min_sum = MIN2(fabs(other_times_ms->sum()), 2201 fabs(calc_other_times_ms->sum())); 2202 double sum_ratio = max_sum / min_sum; 2203 if (sum_ratio > 1.1) { 2204 should_print = true; 2205 buf.append_and_print_cr("## CALCULATED OTHER SUM DOESN'T MATCH RECORDED ###"); 2206 } 2207 2208 double max_avg = MAX2(fabs(other_times_ms->avg()), 2209 fabs(calc_other_times_ms->avg())); 2210 double min_avg = MIN2(fabs(other_times_ms->avg()), 2211 fabs(calc_other_times_ms->avg())); 2212 double avg_ratio = max_avg / min_avg; 2213 if (avg_ratio > 1.1) { 2214 should_print = true; 2215 buf.append_and_print_cr("## CALCULATED OTHER AVG DOESN'T MATCH RECORDED ###"); 2216 } 2217 2218 if (other_times_ms->sum() < -0.01) { 2219 buf.append_and_print_cr("## RECORDED OTHER SUM IS NEGATIVE ###"); 2220 } 2221 2222 if (other_times_ms->avg() < -0.01) { 2223 buf.append_and_print_cr("## RECORDED OTHER AVG IS NEGATIVE ###"); 2224 } 2225 2226 if (calc_other_times_ms->sum() < -0.01) { 2227 should_print = true; 2228 buf.append_and_print_cr("## CALCULATED OTHER SUM IS NEGATIVE ###"); 2229 } 2230 2231 if (calc_other_times_ms->avg() < -0.01) { 2232 should_print = true; 2233 buf.append_and_print_cr("## CALCULATED OTHER AVG IS NEGATIVE ###"); 2234 } 2235 2236 if (should_print) 2237 print_summary(level, "Other(Calc)", calc_other_times_ms); 2238 } 2239 2240 void G1CollectorPolicy::print_summary(PauseSummary* summary) const { 2241 bool parallel = G1CollectedHeap::use_parallel_gc_threads(); 2242 MainBodySummary* body_summary = summary->main_body_summary(); 2243 if (summary->get_total_seq()->num() > 0) { 2244 print_summary_sd(0, "Evacuation Pauses", summary->get_total_seq()); 2245 if (body_summary != NULL) { 2246 print_summary(1, "SATB Drain", body_summary->get_satb_drain_seq()); 2247 if (parallel) { 2248 print_summary(1, "Parallel Time", body_summary->get_parallel_seq()); 2249 print_summary(2, "Ext Root Scanning", body_summary->get_ext_root_scan_seq()); 2250 print_summary(2, "Mark Stack Scanning", body_summary->get_mark_stack_scan_seq()); 2251 print_summary(2, "Update RS", body_summary->get_update_rs_seq()); 2252 print_summary(2, "Scan RS", body_summary->get_scan_rs_seq()); 2253 print_summary(2, "Object Copy", body_summary->get_obj_copy_seq()); 2254 print_summary(2, "Termination", body_summary->get_termination_seq()); 2255 print_summary(2, "Parallel Other", body_summary->get_parallel_other_seq()); 2256 { 2257 NumberSeq* other_parts[] = { 2258 body_summary->get_ext_root_scan_seq(), 2259 body_summary->get_mark_stack_scan_seq(), 2260 body_summary->get_update_rs_seq(), 2261 body_summary->get_scan_rs_seq(), 2262 body_summary->get_obj_copy_seq(), 2263 body_summary->get_termination_seq() 2264 }; 2265 NumberSeq calc_other_times_ms(body_summary->get_parallel_seq(), 2266 6, other_parts); 2267 check_other_times(2, body_summary->get_parallel_other_seq(), 2268 &calc_other_times_ms); 2269 } 2270 } else { 2271 print_summary(1, "Ext Root Scanning", body_summary->get_ext_root_scan_seq()); 2272 print_summary(1, "Mark Stack Scanning", body_summary->get_mark_stack_scan_seq()); 2273 print_summary(1, "Update RS", body_summary->get_update_rs_seq()); 2274 print_summary(1, "Scan RS", body_summary->get_scan_rs_seq()); 2275 print_summary(1, "Object Copy", body_summary->get_obj_copy_seq()); 2276 } 2277 } 2278 print_summary(1, "Mark Closure", body_summary->get_mark_closure_seq()); 2279 print_summary(1, "Clear CT", body_summary->get_clear_ct_seq()); 2280 print_summary(1, "Other", summary->get_other_seq()); 2281 { 2282 if (body_summary != NULL) { 2283 NumberSeq calc_other_times_ms; 2284 if (parallel) { 2285 // parallel 2286 NumberSeq* other_parts[] = { 2287 body_summary->get_satb_drain_seq(), 2288 body_summary->get_parallel_seq(), 2289 body_summary->get_clear_ct_seq() 2290 }; 2291 calc_other_times_ms = NumberSeq(summary->get_total_seq(), 2292 3, other_parts); 2293 } else { 2294 // serial 2295 NumberSeq* other_parts[] = { 2296 body_summary->get_satb_drain_seq(), 2297 body_summary->get_update_rs_seq(), 2298 body_summary->get_ext_root_scan_seq(), 2299 body_summary->get_mark_stack_scan_seq(), 2300 body_summary->get_scan_rs_seq(), 2301 body_summary->get_obj_copy_seq() 2302 }; 2303 calc_other_times_ms = NumberSeq(summary->get_total_seq(), 2304 6, other_parts); 2305 } 2306 check_other_times(1, summary->get_other_seq(), &calc_other_times_ms); 2307 } 2308 } 2309 } else { 2310 LineBuffer(1).append_and_print_cr("none"); 2311 } 2312 LineBuffer(0).append_and_print_cr(""); 2313 } 2314 2315 void G1CollectorPolicy::print_tracing_info() const { 2316 if (TraceGen0Time) { 2317 gclog_or_tty->print_cr("ALL PAUSES"); 2318 print_summary_sd(0, "Total", _all_pause_times_ms); 2319 gclog_or_tty->print_cr(""); 2320 gclog_or_tty->print_cr(""); 2321 gclog_or_tty->print_cr(" Full Young GC Pauses: %8d", _full_young_pause_num); 2322 gclog_or_tty->print_cr(" Partial Young GC Pauses: %8d", _partial_young_pause_num); 2323 gclog_or_tty->print_cr(""); 2324 2325 gclog_or_tty->print_cr("EVACUATION PAUSES"); 2326 print_summary(_summary); 2327 2328 gclog_or_tty->print_cr("MISC"); 2329 print_summary_sd(0, "Stop World", _all_stop_world_times_ms); 2330 print_summary_sd(0, "Yields", _all_yield_times_ms); 2331 for (int i = 0; i < _aux_num; ++i) { 2332 if (_all_aux_times_ms[i].num() > 0) { 2333 char buffer[96]; 2334 sprintf(buffer, "Aux%d", i); 2335 print_summary_sd(0, buffer, &_all_aux_times_ms[i]); 2336 } 2337 } 2338 2339 size_t all_region_num = _region_num_young + _region_num_tenured; 2340 gclog_or_tty->print_cr(" New Regions %8d, Young %8d (%6.2lf%%), " 2341 "Tenured %8d (%6.2lf%%)", 2342 all_region_num, 2343 _region_num_young, 2344 (double) _region_num_young / (double) all_region_num * 100.0, 2345 _region_num_tenured, 2346 (double) _region_num_tenured / (double) all_region_num * 100.0); 2347 } 2348 if (TraceGen1Time) { 2349 if (_all_full_gc_times_ms->num() > 0) { 2350 gclog_or_tty->print("\n%4d full_gcs: total time = %8.2f s", 2351 _all_full_gc_times_ms->num(), 2352 _all_full_gc_times_ms->sum() / 1000.0); 2353 gclog_or_tty->print_cr(" (avg = %8.2fms).", _all_full_gc_times_ms->avg()); 2354 gclog_or_tty->print_cr(" [std. dev = %8.2f ms, max = %8.2f ms]", 2355 _all_full_gc_times_ms->sd(), 2356 _all_full_gc_times_ms->maximum()); 2357 } 2358 } 2359 } 2360 2361 void G1CollectorPolicy::print_yg_surv_rate_info() const { 2362 #ifndef PRODUCT 2363 _short_lived_surv_rate_group->print_surv_rate_summary(); 2364 // add this call for any other surv rate groups 2365 #endif // PRODUCT 2366 } 2367 2368 void G1CollectorPolicy::update_region_num(bool young) { 2369 if (young) { 2370 ++_region_num_young; 2371 } else { 2372 ++_region_num_tenured; 2373 } 2374 } 2375 2376 #ifndef PRODUCT 2377 // for debugging, bit of a hack... 2378 static char* 2379 region_num_to_mbs(int length) { 2380 static char buffer[64]; 2381 double bytes = (double) (length * HeapRegion::GrainBytes); 2382 double mbs = bytes / (double) (1024 * 1024); 2383 sprintf(buffer, "%7.2lfMB", mbs); 2384 return buffer; 2385 } 2386 #endif // PRODUCT 2387 2388 size_t G1CollectorPolicy::max_regions(int purpose) { 2389 switch (purpose) { 2390 case GCAllocForSurvived: 2391 return _max_survivor_regions; 2392 case GCAllocForTenured: 2393 return REGIONS_UNLIMITED; 2394 default: 2395 ShouldNotReachHere(); 2396 return REGIONS_UNLIMITED; 2397 }; 2398 } 2399 2400 void G1CollectorPolicy::update_max_gc_locker_expansion() { 2401 size_t expansion_region_num = 0; 2402 if (GCLockerEdenExpansionPercent > 0) { 2403 double perc = (double) GCLockerEdenExpansionPercent / 100.0; 2404 double expansion_region_num_d = perc * (double) _young_list_target_length; 2405 // We use ceiling so that if expansion_region_num_d is > 0.0 (but 2406 // less than 1.0) we'll get 1. 2407 expansion_region_num = (size_t) ceil(expansion_region_num_d); 2408 } else { 2409 assert(expansion_region_num == 0, "sanity"); 2410 } 2411 _young_list_max_length = _young_list_target_length + expansion_region_num; 2412 assert(_young_list_target_length <= _young_list_max_length, "post-condition"); 2413 } 2414 2415 // Calculates survivor space parameters. 2416 void G1CollectorPolicy::update_survivors_policy() { 2417 double max_survivor_regions_d = 2418 (double) _young_list_target_length / (double) SurvivorRatio; 2419 // We use ceiling so that if max_survivor_regions_d is > 0.0 (but 2420 // smaller than 1.0) we'll get 1. 2421 _max_survivor_regions = (size_t) ceil(max_survivor_regions_d); 2422 2423 _tenuring_threshold = _survivors_age_table.compute_tenuring_threshold( 2424 HeapRegion::GrainWords * _max_survivor_regions); 2425 } 2426 2427 #ifndef PRODUCT 2428 class HRSortIndexIsOKClosure: public HeapRegionClosure { 2429 CollectionSetChooser* _chooser; 2430 public: 2431 HRSortIndexIsOKClosure(CollectionSetChooser* chooser) : 2432 _chooser(chooser) {} 2433 2434 bool doHeapRegion(HeapRegion* r) { 2435 if (!r->continuesHumongous()) { 2436 assert(_chooser->regionProperlyOrdered(r), "Ought to be."); 2437 } 2438 return false; 2439 } 2440 }; 2441 2442 bool G1CollectorPolicy::assertMarkedBytesDataOK() { 2443 HRSortIndexIsOKClosure cl(_collectionSetChooser); 2444 _g1->heap_region_iterate(&cl); 2445 return true; 2446 } 2447 #endif 2448 2449 bool G1CollectorPolicy::force_initial_mark_if_outside_cycle( 2450 GCCause::Cause gc_cause) { 2451 bool during_cycle = _g1->concurrent_mark()->cmThread()->during_cycle(); 2452 if (!during_cycle) { 2453 ergo_verbose1(ErgoConcCycles, 2454 "request concurrent cycle initiation", 2455 ergo_format_reason("requested by GC cause") 2456 ergo_format_str("GC cause"), 2457 GCCause::to_string(gc_cause)); 2458 set_initiate_conc_mark_if_possible(); 2459 return true; 2460 } else { 2461 ergo_verbose1(ErgoConcCycles, 2462 "do not request concurrent cycle initiation", 2463 ergo_format_reason("concurrent cycle already in progress") 2464 ergo_format_str("GC cause"), 2465 GCCause::to_string(gc_cause)); 2466 return false; 2467 } 2468 } 2469 2470 void 2471 G1CollectorPolicy::decide_on_conc_mark_initiation() { 2472 // We are about to decide on whether this pause will be an 2473 // initial-mark pause. 2474 2475 // First, during_initial_mark_pause() should not be already set. We 2476 // will set it here if we have to. However, it should be cleared by 2477 // the end of the pause (it's only set for the duration of an 2478 // initial-mark pause). 2479 assert(!during_initial_mark_pause(), "pre-condition"); 2480 2481 if (initiate_conc_mark_if_possible()) { 2482 // We had noticed on a previous pause that the heap occupancy has 2483 // gone over the initiating threshold and we should start a 2484 // concurrent marking cycle. So we might initiate one. 2485 2486 bool during_cycle = _g1->concurrent_mark()->cmThread()->during_cycle(); 2487 if (!during_cycle) { 2488 // The concurrent marking thread is not "during a cycle", i.e., 2489 // it has completed the last one. So we can go ahead and 2490 // initiate a new cycle. 2491 2492 set_during_initial_mark_pause(); 2493 // We do not allow non-full young GCs during marking. 2494 if (!full_young_gcs()) { 2495 set_full_young_gcs(true); 2496 ergo_verbose0(ErgoPartiallyYoungGCs, 2497 "end partially-young GCs", 2498 ergo_format_reason("concurrent cycle is about to start")); 2499 } 2500 2501 // And we can now clear initiate_conc_mark_if_possible() as 2502 // we've already acted on it. 2503 clear_initiate_conc_mark_if_possible(); 2504 2505 ergo_verbose0(ErgoConcCycles, 2506 "initiate concurrent cycle", 2507 ergo_format_reason("concurrent cycle initiation requested")); 2508 } else { 2509 // The concurrent marking thread is still finishing up the 2510 // previous cycle. If we start one right now the two cycles 2511 // overlap. In particular, the concurrent marking thread might 2512 // be in the process of clearing the next marking bitmap (which 2513 // we will use for the next cycle if we start one). Starting a 2514 // cycle now will be bad given that parts of the marking 2515 // information might get cleared by the marking thread. And we 2516 // cannot wait for the marking thread to finish the cycle as it 2517 // periodically yields while clearing the next marking bitmap 2518 // and, if it's in a yield point, it's waiting for us to 2519 // finish. So, at this point we will not start a cycle and we'll 2520 // let the concurrent marking thread complete the last one. 2521 ergo_verbose0(ErgoConcCycles, 2522 "do not initiate concurrent cycle", 2523 ergo_format_reason("concurrent cycle already in progress")); 2524 } 2525 } 2526 } 2527 2528 class KnownGarbageClosure: public HeapRegionClosure { 2529 CollectionSetChooser* _hrSorted; 2530 2531 public: 2532 KnownGarbageClosure(CollectionSetChooser* hrSorted) : 2533 _hrSorted(hrSorted) 2534 {} 2535 2536 bool doHeapRegion(HeapRegion* r) { 2537 // We only include humongous regions in collection 2538 // sets when concurrent mark shows that their contained object is 2539 // unreachable. 2540 2541 // Do we have any marking information for this region? 2542 if (r->is_marked()) { 2543 // We don't include humongous regions in collection 2544 // sets because we collect them immediately at the end of a marking 2545 // cycle. We also don't include young regions because we *must* 2546 // include them in the next collection pause. 2547 if (!r->isHumongous() && !r->is_young()) { 2548 _hrSorted->addMarkedHeapRegion(r); 2549 } 2550 } 2551 return false; 2552 } 2553 }; 2554 2555 class ParKnownGarbageHRClosure: public HeapRegionClosure { 2556 CollectionSetChooser* _hrSorted; 2557 jint _marked_regions_added; 2558 jint _chunk_size; 2559 jint _cur_chunk_idx; 2560 jint _cur_chunk_end; // Cur chunk [_cur_chunk_idx, _cur_chunk_end) 2561 int _worker; 2562 int _invokes; 2563 2564 void get_new_chunk() { 2565 _cur_chunk_idx = _hrSorted->getParMarkedHeapRegionChunk(_chunk_size); 2566 _cur_chunk_end = _cur_chunk_idx + _chunk_size; 2567 } 2568 void add_region(HeapRegion* r) { 2569 if (_cur_chunk_idx == _cur_chunk_end) { 2570 get_new_chunk(); 2571 } 2572 assert(_cur_chunk_idx < _cur_chunk_end, "postcondition"); 2573 _hrSorted->setMarkedHeapRegion(_cur_chunk_idx, r); 2574 _marked_regions_added++; 2575 _cur_chunk_idx++; 2576 } 2577 2578 public: 2579 ParKnownGarbageHRClosure(CollectionSetChooser* hrSorted, 2580 jint chunk_size, 2581 int worker) : 2582 _hrSorted(hrSorted), _chunk_size(chunk_size), _worker(worker), 2583 _marked_regions_added(0), _cur_chunk_idx(0), _cur_chunk_end(0), 2584 _invokes(0) 2585 {} 2586 2587 bool doHeapRegion(HeapRegion* r) { 2588 // We only include humongous regions in collection 2589 // sets when concurrent mark shows that their contained object is 2590 // unreachable. 2591 _invokes++; 2592 2593 // Do we have any marking information for this region? 2594 if (r->is_marked()) { 2595 // We don't include humongous regions in collection 2596 // sets because we collect them immediately at the end of a marking 2597 // cycle. 2598 // We also do not include young regions in collection sets 2599 if (!r->isHumongous() && !r->is_young()) { 2600 add_region(r); 2601 } 2602 } 2603 return false; 2604 } 2605 jint marked_regions_added() { return _marked_regions_added; } 2606 int invokes() { return _invokes; } 2607 }; 2608 2609 class ParKnownGarbageTask: public AbstractGangTask { 2610 CollectionSetChooser* _hrSorted; 2611 jint _chunk_size; 2612 G1CollectedHeap* _g1; 2613 public: 2614 ParKnownGarbageTask(CollectionSetChooser* hrSorted, jint chunk_size) : 2615 AbstractGangTask("ParKnownGarbageTask"), 2616 _hrSorted(hrSorted), _chunk_size(chunk_size), 2617 _g1(G1CollectedHeap::heap()) 2618 {} 2619 2620 void work(int i) { 2621 ParKnownGarbageHRClosure parKnownGarbageCl(_hrSorted, _chunk_size, i); 2622 // Back to zero for the claim value. 2623 _g1->heap_region_par_iterate_chunked(&parKnownGarbageCl, i, 2624 HeapRegion::InitialClaimValue); 2625 jint regions_added = parKnownGarbageCl.marked_regions_added(); 2626 _hrSorted->incNumMarkedHeapRegions(regions_added); 2627 if (G1PrintParCleanupStats) { 2628 gclog_or_tty->print_cr(" Thread %d called %d times, added %d regions to list.", 2629 i, parKnownGarbageCl.invokes(), regions_added); 2630 } 2631 } 2632 }; 2633 2634 void 2635 G1CollectorPolicy::record_concurrent_mark_cleanup_end() { 2636 double start_sec; 2637 if (G1PrintParCleanupStats) { 2638 start_sec = os::elapsedTime(); 2639 } 2640 2641 _collectionSetChooser->clearMarkedHeapRegions(); 2642 double clear_marked_end_sec; 2643 if (G1PrintParCleanupStats) { 2644 clear_marked_end_sec = os::elapsedTime(); 2645 gclog_or_tty->print_cr(" clear marked regions: %8.3f ms.", 2646 (clear_marked_end_sec - start_sec) * 1000.0); 2647 } 2648 2649 if (G1CollectedHeap::use_parallel_gc_threads()) { 2650 const size_t OverpartitionFactor = 4; 2651 const size_t MinWorkUnit = 8; 2652 const size_t WorkUnit = 2653 MAX2(_g1->n_regions() / (ParallelGCThreads * OverpartitionFactor), 2654 MinWorkUnit); 2655 _collectionSetChooser->prepareForAddMarkedHeapRegionsPar(_g1->n_regions(), 2656 WorkUnit); 2657 ParKnownGarbageTask parKnownGarbageTask(_collectionSetChooser, 2658 (int) WorkUnit); 2659 _g1->workers()->run_task(&parKnownGarbageTask); 2660 2661 assert(_g1->check_heap_region_claim_values(HeapRegion::InitialClaimValue), 2662 "sanity check"); 2663 } else { 2664 KnownGarbageClosure knownGarbagecl(_collectionSetChooser); 2665 _g1->heap_region_iterate(&knownGarbagecl); 2666 } 2667 double known_garbage_end_sec; 2668 if (G1PrintParCleanupStats) { 2669 known_garbage_end_sec = os::elapsedTime(); 2670 gclog_or_tty->print_cr(" compute known garbage: %8.3f ms.", 2671 (known_garbage_end_sec - clear_marked_end_sec) * 1000.0); 2672 } 2673 2674 _collectionSetChooser->sortMarkedHeapRegions(); 2675 double end_sec = os::elapsedTime(); 2676 if (G1PrintParCleanupStats) { 2677 gclog_or_tty->print_cr(" sorting: %8.3f ms.", 2678 (end_sec - known_garbage_end_sec) * 1000.0); 2679 } 2680 2681 double elapsed_time_ms = (end_sec - _mark_cleanup_start_sec) * 1000.0; 2682 _concurrent_mark_cleanup_times_ms->add(elapsed_time_ms); 2683 _cur_mark_stop_world_time_ms += elapsed_time_ms; 2684 _prev_collection_pause_end_ms += elapsed_time_ms; 2685 _mmu_tracker->add_pause(_mark_cleanup_start_sec, end_sec, true); 2686 } 2687 2688 // Add the heap region at the head of the non-incremental collection set 2689 void G1CollectorPolicy:: 2690 add_to_collection_set(HeapRegion* hr) { 2691 assert(_inc_cset_build_state == Active, "Precondition"); 2692 assert(!hr->is_young(), "non-incremental add of young region"); 2693 2694 if (_g1->mark_in_progress()) 2695 _g1->concurrent_mark()->registerCSetRegion(hr); 2696 2697 assert(!hr->in_collection_set(), "should not already be in the CSet"); 2698 hr->set_in_collection_set(true); 2699 hr->set_next_in_collection_set(_collection_set); 2700 _collection_set = hr; 2701 _collection_set_size++; 2702 _collection_set_bytes_used_before += hr->used(); 2703 _g1->register_region_with_in_cset_fast_test(hr); 2704 } 2705 2706 // Initialize the per-collection-set information 2707 void G1CollectorPolicy::start_incremental_cset_building() { 2708 assert(_inc_cset_build_state == Inactive, "Precondition"); 2709 2710 _inc_cset_head = NULL; 2711 _inc_cset_tail = NULL; 2712 _inc_cset_size = 0; 2713 _inc_cset_bytes_used_before = 0; 2714 2715 _inc_cset_young_index = 0; 2716 2717 _inc_cset_max_finger = 0; 2718 _inc_cset_recorded_young_bytes = 0; 2719 _inc_cset_recorded_rs_lengths = 0; 2720 _inc_cset_predicted_elapsed_time_ms = 0; 2721 _inc_cset_predicted_bytes_to_copy = 0; 2722 _inc_cset_build_state = Active; 2723 } 2724 2725 void G1CollectorPolicy::add_to_incremental_cset_info(HeapRegion* hr, size_t rs_length) { 2726 // This routine is used when: 2727 // * adding survivor regions to the incremental cset at the end of an 2728 // evacuation pause, 2729 // * adding the current allocation region to the incremental cset 2730 // when it is retired, and 2731 // * updating existing policy information for a region in the 2732 // incremental cset via young list RSet sampling. 2733 // Therefore this routine may be called at a safepoint by the 2734 // VM thread, or in-between safepoints by mutator threads (when 2735 // retiring the current allocation region) or a concurrent 2736 // refine thread (RSet sampling). 2737 2738 double region_elapsed_time_ms = predict_region_elapsed_time_ms(hr, true); 2739 size_t used_bytes = hr->used(); 2740 2741 _inc_cset_recorded_rs_lengths += rs_length; 2742 _inc_cset_predicted_elapsed_time_ms += region_elapsed_time_ms; 2743 2744 _inc_cset_bytes_used_before += used_bytes; 2745 2746 // Cache the values we have added to the aggregated informtion 2747 // in the heap region in case we have to remove this region from 2748 // the incremental collection set, or it is updated by the 2749 // rset sampling code 2750 hr->set_recorded_rs_length(rs_length); 2751 hr->set_predicted_elapsed_time_ms(region_elapsed_time_ms); 2752 2753 #if PREDICTIONS_VERBOSE 2754 size_t bytes_to_copy = predict_bytes_to_copy(hr); 2755 _inc_cset_predicted_bytes_to_copy += bytes_to_copy; 2756 2757 // Record the number of bytes used in this region 2758 _inc_cset_recorded_young_bytes += used_bytes; 2759 2760 // Cache the values we have added to the aggregated informtion 2761 // in the heap region in case we have to remove this region from 2762 // the incremental collection set, or it is updated by the 2763 // rset sampling code 2764 hr->set_predicted_bytes_to_copy(bytes_to_copy); 2765 #endif // PREDICTIONS_VERBOSE 2766 } 2767 2768 void G1CollectorPolicy::remove_from_incremental_cset_info(HeapRegion* hr) { 2769 // This routine is currently only called as part of the updating of 2770 // existing policy information for regions in the incremental cset that 2771 // is performed by the concurrent refine thread(s) as part of young list 2772 // RSet sampling. Therefore we should not be at a safepoint. 2773 2774 assert(!SafepointSynchronize::is_at_safepoint(), "should not be at safepoint"); 2775 assert(hr->is_young(), "it should be"); 2776 2777 size_t used_bytes = hr->used(); 2778 size_t old_rs_length = hr->recorded_rs_length(); 2779 double old_elapsed_time_ms = hr->predicted_elapsed_time_ms(); 2780 2781 // Subtract the old recorded/predicted policy information for 2782 // the given heap region from the collection set info. 2783 _inc_cset_recorded_rs_lengths -= old_rs_length; 2784 _inc_cset_predicted_elapsed_time_ms -= old_elapsed_time_ms; 2785 2786 _inc_cset_bytes_used_before -= used_bytes; 2787 2788 // Clear the values cached in the heap region 2789 hr->set_recorded_rs_length(0); 2790 hr->set_predicted_elapsed_time_ms(0); 2791 2792 #if PREDICTIONS_VERBOSE 2793 size_t old_predicted_bytes_to_copy = hr->predicted_bytes_to_copy(); 2794 _inc_cset_predicted_bytes_to_copy -= old_predicted_bytes_to_copy; 2795 2796 // Subtract the number of bytes used in this region 2797 _inc_cset_recorded_young_bytes -= used_bytes; 2798 2799 // Clear the values cached in the heap region 2800 hr->set_predicted_bytes_to_copy(0); 2801 #endif // PREDICTIONS_VERBOSE 2802 } 2803 2804 void G1CollectorPolicy::update_incremental_cset_info(HeapRegion* hr, size_t new_rs_length) { 2805 // Update the collection set information that is dependent on the new RS length 2806 assert(hr->is_young(), "Precondition"); 2807 2808 remove_from_incremental_cset_info(hr); 2809 add_to_incremental_cset_info(hr, new_rs_length); 2810 } 2811 2812 void G1CollectorPolicy::add_region_to_incremental_cset_common(HeapRegion* hr) { 2813 assert( hr->is_young(), "invariant"); 2814 assert( hr->young_index_in_cset() == -1, "invariant" ); 2815 assert(_inc_cset_build_state == Active, "Precondition"); 2816 2817 // We need to clear and set the cached recorded/cached collection set 2818 // information in the heap region here (before the region gets added 2819 // to the collection set). An individual heap region's cached values 2820 // are calculated, aggregated with the policy collection set info, 2821 // and cached in the heap region here (initially) and (subsequently) 2822 // by the Young List sampling code. 2823 2824 size_t rs_length = hr->rem_set()->occupied(); 2825 add_to_incremental_cset_info(hr, rs_length); 2826 2827 HeapWord* hr_end = hr->end(); 2828 _inc_cset_max_finger = MAX2(_inc_cset_max_finger, hr_end); 2829 2830 assert(!hr->in_collection_set(), "invariant"); 2831 hr->set_in_collection_set(true); 2832 assert( hr->next_in_collection_set() == NULL, "invariant"); 2833 2834 _inc_cset_size++; 2835 _g1->register_region_with_in_cset_fast_test(hr); 2836 2837 hr->set_young_index_in_cset((int) _inc_cset_young_index); 2838 ++_inc_cset_young_index; 2839 } 2840 2841 // Add the region at the RHS of the incremental cset 2842 void G1CollectorPolicy::add_region_to_incremental_cset_rhs(HeapRegion* hr) { 2843 // We should only ever be appending survivors at the end of a pause 2844 assert( hr->is_survivor(), "Logic"); 2845 2846 // Do the 'common' stuff 2847 add_region_to_incremental_cset_common(hr); 2848 2849 // Now add the region at the right hand side 2850 if (_inc_cset_tail == NULL) { 2851 assert(_inc_cset_head == NULL, "invariant"); 2852 _inc_cset_head = hr; 2853 } else { 2854 _inc_cset_tail->set_next_in_collection_set(hr); 2855 } 2856 _inc_cset_tail = hr; 2857 } 2858 2859 // Add the region to the LHS of the incremental cset 2860 void G1CollectorPolicy::add_region_to_incremental_cset_lhs(HeapRegion* hr) { 2861 // Survivors should be added to the RHS at the end of a pause 2862 assert(!hr->is_survivor(), "Logic"); 2863 2864 // Do the 'common' stuff 2865 add_region_to_incremental_cset_common(hr); 2866 2867 // Add the region at the left hand side 2868 hr->set_next_in_collection_set(_inc_cset_head); 2869 if (_inc_cset_head == NULL) { 2870 assert(_inc_cset_tail == NULL, "Invariant"); 2871 _inc_cset_tail = hr; 2872 } 2873 _inc_cset_head = hr; 2874 } 2875 2876 #ifndef PRODUCT 2877 void G1CollectorPolicy::print_collection_set(HeapRegion* list_head, outputStream* st) { 2878 assert(list_head == inc_cset_head() || list_head == collection_set(), "must be"); 2879 2880 st->print_cr("\nCollection_set:"); 2881 HeapRegion* csr = list_head; 2882 while (csr != NULL) { 2883 HeapRegion* next = csr->next_in_collection_set(); 2884 assert(csr->in_collection_set(), "bad CS"); 2885 st->print_cr(" [%08x-%08x], t: %08x, P: %08x, N: %08x, C: %08x, " 2886 "age: %4d, y: %d, surv: %d", 2887 csr->bottom(), csr->end(), 2888 csr->top(), 2889 csr->prev_top_at_mark_start(), 2890 csr->next_top_at_mark_start(), 2891 csr->top_at_conc_mark_count(), 2892 csr->age_in_surv_rate_group_cond(), 2893 csr->is_young(), 2894 csr->is_survivor()); 2895 csr = next; 2896 } 2897 } 2898 #endif // !PRODUCT 2899 2900 void G1CollectorPolicy::choose_collection_set(double target_pause_time_ms) { 2901 // Set this here - in case we're not doing young collections. 2902 double non_young_start_time_sec = os::elapsedTime(); 2903 2904 YoungList* young_list = _g1->young_list(); 2905 2906 start_recording_regions(); 2907 2908 guarantee(target_pause_time_ms > 0.0, 2909 err_msg("target_pause_time_ms = %1.6lf should be positive", 2910 target_pause_time_ms)); 2911 guarantee(_collection_set == NULL, "Precondition"); 2912 2913 double base_time_ms = predict_base_elapsed_time_ms(_pending_cards); 2914 double predicted_pause_time_ms = base_time_ms; 2915 2916 double time_remaining_ms = target_pause_time_ms - base_time_ms; 2917 2918 ergo_verbose3(ErgoCSetConstruction | ErgoHigh, 2919 "start choosing CSet", 2920 ergo_format_ms("predicted base time") 2921 ergo_format_ms("remaining time") 2922 ergo_format_ms("target pause time"), 2923 base_time_ms, time_remaining_ms, target_pause_time_ms); 2924 2925 // the 10% and 50% values are arbitrary... 2926 double threshold = 0.10 * target_pause_time_ms; 2927 if (time_remaining_ms < threshold) { 2928 double prev_time_remaining_ms = time_remaining_ms; 2929 time_remaining_ms = 0.50 * target_pause_time_ms; 2930 _within_target = false; 2931 ergo_verbose3(ErgoCSetConstruction, 2932 "adjust remaining time", 2933 ergo_format_reason("remaining time lower than threshold") 2934 ergo_format_ms("remaining time") 2935 ergo_format_ms("threshold") 2936 ergo_format_ms("adjusted remaining time"), 2937 prev_time_remaining_ms, threshold, time_remaining_ms); 2938 } else { 2939 _within_target = true; 2940 } 2941 2942 size_t expansion_bytes = _g1->expansion_regions() * HeapRegion::GrainBytes; 2943 2944 HeapRegion* hr; 2945 double young_start_time_sec = os::elapsedTime(); 2946 2947 _collection_set_bytes_used_before = 0; 2948 _collection_set_size = 0; 2949 _young_cset_length = 0; 2950 _last_young_gc_full = full_young_gcs() ? true : false; 2951 2952 if (_last_young_gc_full) { 2953 ++_full_young_pause_num; 2954 } else { 2955 ++_partial_young_pause_num; 2956 } 2957 2958 // The young list is laid with the survivor regions from the previous 2959 // pause are appended to the RHS of the young list, i.e. 2960 // [Newly Young Regions ++ Survivors from last pause]. 2961 2962 size_t survivor_region_num = young_list->survivor_length(); 2963 size_t eden_region_num = young_list->length() - survivor_region_num; 2964 size_t old_region_num = 0; 2965 hr = young_list->first_survivor_region(); 2966 while (hr != NULL) { 2967 assert(hr->is_survivor(), "badly formed young list"); 2968 hr->set_young(); 2969 hr = hr->get_next_young_region(); 2970 } 2971 2972 // Clear the fields that point to the survivor list - they are all young now. 2973 young_list->clear_survivors(); 2974 2975 if (_g1->mark_in_progress()) 2976 _g1->concurrent_mark()->register_collection_set_finger(_inc_cset_max_finger); 2977 2978 _young_cset_length = _inc_cset_young_index; 2979 _collection_set = _inc_cset_head; 2980 _collection_set_size = _inc_cset_size; 2981 _collection_set_bytes_used_before = _inc_cset_bytes_used_before; 2982 time_remaining_ms -= _inc_cset_predicted_elapsed_time_ms; 2983 predicted_pause_time_ms += _inc_cset_predicted_elapsed_time_ms; 2984 2985 ergo_verbose3(ErgoCSetConstruction | ErgoHigh, 2986 "add young regions to CSet", 2987 ergo_format_region("eden") 2988 ergo_format_region("survivors") 2989 ergo_format_ms("predicted young region time"), 2990 eden_region_num, survivor_region_num, 2991 _inc_cset_predicted_elapsed_time_ms); 2992 2993 // The number of recorded young regions is the incremental 2994 // collection set's current size 2995 set_recorded_young_regions(_inc_cset_size); 2996 set_recorded_rs_lengths(_inc_cset_recorded_rs_lengths); 2997 set_recorded_young_bytes(_inc_cset_recorded_young_bytes); 2998 #if PREDICTIONS_VERBOSE 2999 set_predicted_bytes_to_copy(_inc_cset_predicted_bytes_to_copy); 3000 #endif // PREDICTIONS_VERBOSE 3001 3002 assert(_inc_cset_size == young_list->length(), "Invariant"); 3003 3004 double young_end_time_sec = os::elapsedTime(); 3005 _recorded_young_cset_choice_time_ms = 3006 (young_end_time_sec - young_start_time_sec) * 1000.0; 3007 3008 // We are doing young collections so reset this. 3009 non_young_start_time_sec = young_end_time_sec; 3010 3011 if (!full_young_gcs()) { 3012 bool should_continue = true; 3013 NumberSeq seq; 3014 double avg_prediction = 100000000000000000.0; // something very large 3015 3016 size_t prev_collection_set_size = _collection_set_size; 3017 double prev_predicted_pause_time_ms = predicted_pause_time_ms; 3018 do { 3019 hr = _collectionSetChooser->getNextMarkedRegion(time_remaining_ms, 3020 avg_prediction); 3021 if (hr != NULL) { 3022 double predicted_time_ms = predict_region_elapsed_time_ms(hr, false); 3023 time_remaining_ms -= predicted_time_ms; 3024 predicted_pause_time_ms += predicted_time_ms; 3025 add_to_collection_set(hr); 3026 record_non_young_cset_region(hr); 3027 seq.add(predicted_time_ms); 3028 avg_prediction = seq.avg() + seq.sd(); 3029 } 3030 3031 should_continue = true; 3032 if (hr == NULL) { 3033 // No need for an ergo verbose message here, 3034 // getNextMarkRegion() does this when it returns NULL. 3035 should_continue = false; 3036 } else { 3037 if (adaptive_young_list_length()) { 3038 if (time_remaining_ms < 0.0) { 3039 ergo_verbose1(ErgoCSetConstruction, 3040 "stop adding old regions to CSet", 3041 ergo_format_reason("remaining time is lower than 0") 3042 ergo_format_ms("remaining time"), 3043 time_remaining_ms); 3044 should_continue = false; 3045 } 3046 } else { 3047 if (_collection_set_size >= _young_list_fixed_length) { 3048 ergo_verbose2(ErgoCSetConstruction, 3049 "stop adding old regions to CSet", 3050 ergo_format_reason("CSet length reached target") 3051 ergo_format_region("CSet") 3052 ergo_format_region("young target"), 3053 _collection_set_size, _young_list_fixed_length); 3054 should_continue = false; 3055 } 3056 } 3057 } 3058 } while (should_continue); 3059 3060 if (!adaptive_young_list_length() && 3061 _collection_set_size < _young_list_fixed_length) { 3062 ergo_verbose2(ErgoCSetConstruction, 3063 "request partially-young GCs end", 3064 ergo_format_reason("CSet length lower than target") 3065 ergo_format_region("CSet") 3066 ergo_format_region("young target"), 3067 _collection_set_size, _young_list_fixed_length); 3068 _should_revert_to_full_young_gcs = true; 3069 } 3070 3071 old_region_num = _collection_set_size - prev_collection_set_size; 3072 3073 ergo_verbose2(ErgoCSetConstruction | ErgoHigh, 3074 "add old regions to CSet", 3075 ergo_format_region("old") 3076 ergo_format_ms("predicted old region time"), 3077 old_region_num, 3078 predicted_pause_time_ms - prev_predicted_pause_time_ms); 3079 } 3080 3081 stop_incremental_cset_building(); 3082 3083 count_CS_bytes_used(); 3084 3085 end_recording_regions(); 3086 3087 ergo_verbose5(ErgoCSetConstruction, 3088 "finish choosing CSet", 3089 ergo_format_region("eden") 3090 ergo_format_region("survivors") 3091 ergo_format_region("old") 3092 ergo_format_ms("predicted pause time") 3093 ergo_format_ms("target pause time"), 3094 eden_region_num, survivor_region_num, old_region_num, 3095 predicted_pause_time_ms, target_pause_time_ms); 3096 3097 double non_young_end_time_sec = os::elapsedTime(); 3098 _recorded_non_young_cset_choice_time_ms = 3099 (non_young_end_time_sec - non_young_start_time_sec) * 1000.0; 3100 }