1.1 --- a/src/share/vm/gc_implementation/g1/g1CollectorPolicy.cpp Fri Aug 24 16:23:59 2012 -0700
1.2 +++ b/src/share/vm/gc_implementation/g1/g1CollectorPolicy.cpp Thu Aug 23 10:21:12 2012 +0200
1.3 @@ -795,7 +795,7 @@
1.4 _trace_gen0_time_data.record_start_collection(s_w_t_ms);
1.5 _stop_world_start = 0.0;
1.6
1.7 - phase_times()->_cur_collection_start_sec = start_time_sec;
1.8 + phase_times()->record_cur_collection_start_sec(start_time_sec);
1.9 _cur_collection_pause_used_at_start_bytes = start_used;
1.10 _cur_collection_pause_used_regions_at_start = _g1->used_regions();
1.11 _pending_cards = _g1->pending_card_num();
1.12 @@ -947,7 +947,7 @@
1.13 _trace_gen0_time_data.record_end_collection(pause_time_ms, phase_times());
1.14 // this is where we update the allocation rate of the application
1.15 double app_time_ms =
1.16 - (phase_times()->_cur_collection_start_sec * 1000.0 - _prev_collection_pause_end_ms);
1.17 + (phase_times()->cur_collection_start_sec() * 1000.0 - _prev_collection_pause_end_ms);
1.18 if (app_time_ms < MIN_TIMER_GRANULARITY) {
1.19 // This usually happens due to the timer not having the required
1.20 // granularity. Some Linuxes are the usual culprits.
1.21 @@ -1035,7 +1035,7 @@
1.22 if (update_stats) {
1.23 double cost_per_card_ms = 0.0;
1.24 if (_pending_cards > 0) {
1.25 - cost_per_card_ms = phase_times()->_update_rs_time / (double) _pending_cards;
1.26 + cost_per_card_ms = phase_times()->average_last_update_rs_time() / (double) _pending_cards;
1.27 _cost_per_card_ms_seq->add(cost_per_card_ms);
1.28 }
1.29
1.30 @@ -1043,7 +1043,7 @@
1.31
1.32 double cost_per_entry_ms = 0.0;
1.33 if (cards_scanned > 10) {
1.34 - cost_per_entry_ms = phase_times()->_scan_rs_time / (double) cards_scanned;
1.35 + cost_per_entry_ms = phase_times()->average_last_scan_rs_time() / (double) cards_scanned;
1.36 if (_last_gc_was_young) {
1.37 _cost_per_entry_ms_seq->add(cost_per_entry_ms);
1.38 } else {
1.39 @@ -1083,7 +1083,7 @@
1.40 size_t copied_bytes = surviving_bytes;
1.41 double cost_per_byte_ms = 0.0;
1.42 if (copied_bytes > 0) {
1.43 - cost_per_byte_ms = phase_times()->_obj_copy_time / (double) copied_bytes;
1.44 + cost_per_byte_ms = phase_times()->average_last_obj_copy_time() / (double) copied_bytes;
1.45 if (_in_marking_window) {
1.46 _cost_per_byte_ms_during_cm_seq->add(cost_per_byte_ms);
1.47 } else {
1.48 @@ -1092,21 +1092,22 @@
1.49 }
1.50
1.51 double all_other_time_ms = pause_time_ms -
1.52 - (phase_times()->_update_rs_time + phase_times()->_scan_rs_time + phase_times()->_obj_copy_time + phase_times()->_termination_time);
1.53 + (phase_times()->average_last_update_rs_time() + phase_times()->average_last_scan_rs_time()
1.54 + + phase_times()->average_last_obj_copy_time() + phase_times()->average_last_termination_time());
1.55
1.56 double young_other_time_ms = 0.0;
1.57 if (young_cset_region_length() > 0) {
1.58 young_other_time_ms =
1.59 - phase_times()->_recorded_young_cset_choice_time_ms +
1.60 - phase_times()->_recorded_young_free_cset_time_ms;
1.61 + phase_times()->young_cset_choice_time_ms() +
1.62 + phase_times()->young_free_cset_time_ms();
1.63 _young_other_cost_per_region_ms_seq->add(young_other_time_ms /
1.64 (double) young_cset_region_length());
1.65 }
1.66 double non_young_other_time_ms = 0.0;
1.67 if (old_cset_region_length() > 0) {
1.68 non_young_other_time_ms =
1.69 - phase_times()->_recorded_non_young_cset_choice_time_ms +
1.70 - phase_times()->_recorded_non_young_free_cset_time_ms;
1.71 + phase_times()->non_young_cset_choice_time_ms() +
1.72 + phase_times()->non_young_free_cset_time_ms();
1.73
1.74 _non_young_other_cost_per_region_ms_seq->add(non_young_other_time_ms /
1.75 (double) old_cset_region_length());
1.76 @@ -1133,7 +1134,8 @@
1.77
1.78 // Note that _mmu_tracker->max_gc_time() returns the time in seconds.
1.79 double update_rs_time_goal_ms = _mmu_tracker->max_gc_time() * MILLIUNITS * G1RSetUpdatingPauseTimePercent / 100.0;
1.80 - adjust_concurrent_refinement(phase_times()->_update_rs_time, phase_times()->_update_rs_processed_buffers, update_rs_time_goal_ms);
1.81 + adjust_concurrent_refinement(phase_times()->average_last_update_rs_time(),
1.82 + phase_times()->sum_last_update_rs_processed_buffers(), update_rs_time_goal_ms);
1.83
1.84 _collectionSetChooser->verify();
1.85 }
1.86 @@ -1144,7 +1146,11 @@
1.87 proper_unit_for_byte_size((bytes))
1.88
1.89 void G1CollectorPolicy::print_heap_transition() {
1.90 - if (G1Log::finer()) {
1.91 + _g1->print_size_transition(gclog_or_tty,
1.92 + _cur_collection_pause_used_at_start_bytes, _g1->used(), _g1->capacity());
1.93 +}
1.94 +
1.95 +void G1CollectorPolicy::print_detailed_heap_transition() {
1.96 YoungList* young_list = _g1->young_list();
1.97 size_t eden_bytes = young_list->eden_used_bytes();
1.98 size_t survivor_bytes = young_list->survivor_used_bytes();
1.99 @@ -1171,11 +1177,6 @@
1.100 EXT_SIZE_PARAMS(capacity));
1.101
1.102 _prev_eden_capacity = eden_capacity;
1.103 - } else if (G1Log::fine()) {
1.104 - _g1->print_size_transition(gclog_or_tty,
1.105 - _cur_collection_pause_used_at_start_bytes,
1.106 - _g1->used(), _g1->capacity());
1.107 - }
1.108 }
1.109
1.110 void G1CollectorPolicy::adjust_concurrent_refinement(double update_rs_time,
1.111 @@ -1900,8 +1901,7 @@
1.112 set_recorded_rs_lengths(_inc_cset_recorded_rs_lengths);
1.113
1.114 double young_end_time_sec = os::elapsedTime();
1.115 - phase_times()->_recorded_young_cset_choice_time_ms =
1.116 - (young_end_time_sec - young_start_time_sec) * 1000.0;
1.117 + phase_times()->record_young_cset_choice_time_ms((young_end_time_sec - young_start_time_sec) * 1000.0);
1.118
1.119 // Set the start of the non-young choice time.
1.120 double non_young_start_time_sec = young_end_time_sec;
1.121 @@ -2015,8 +2015,7 @@
1.122 predicted_pause_time_ms, target_pause_time_ms);
1.123
1.124 double non_young_end_time_sec = os::elapsedTime();
1.125 - phase_times()->_recorded_non_young_cset_choice_time_ms =
1.126 - (non_young_end_time_sec - non_young_start_time_sec) * 1000.0;
1.127 + phase_times()->record_non_young_cset_choice_time_ms((non_young_end_time_sec - non_young_start_time_sec) * 1000.0);
1.128 }
1.129
1.130 void TraceGen0TimeData::record_start_collection(double time_to_stop_the_world_ms) {
1.131 @@ -2035,25 +2034,25 @@
1.132 if(TraceGen0Time) {
1.133 _total.add(pause_time_ms);
1.134 _other.add(pause_time_ms - phase_times->accounted_time_ms());
1.135 - _root_region_scan_wait.add(phase_times->_root_region_scan_wait_time_ms);
1.136 - _parallel.add(phase_times->_cur_collection_par_time_ms);
1.137 - _ext_root_scan.add(phase_times->_ext_root_scan_time);
1.138 - _satb_filtering.add(phase_times->_satb_filtering_time);
1.139 - _update_rs.add(phase_times->_update_rs_time);
1.140 - _scan_rs.add(phase_times->_scan_rs_time);
1.141 - _obj_copy.add(phase_times->_obj_copy_time);
1.142 - _termination.add(phase_times->_termination_time);
1.143 + _root_region_scan_wait.add(phase_times->root_region_scan_wait_time_ms());
1.144 + _parallel.add(phase_times->cur_collection_par_time_ms());
1.145 + _ext_root_scan.add(phase_times->average_last_ext_root_scan_time());
1.146 + _satb_filtering.add(phase_times->average_last_satb_filtering_times_ms());
1.147 + _update_rs.add(phase_times->average_last_update_rs_time());
1.148 + _scan_rs.add(phase_times->average_last_scan_rs_time());
1.149 + _obj_copy.add(phase_times->average_last_obj_copy_time());
1.150 + _termination.add(phase_times->average_last_termination_time());
1.151
1.152 - double parallel_known_time = phase_times->_ext_root_scan_time +
1.153 - phase_times->_satb_filtering_time +
1.154 - phase_times->_update_rs_time +
1.155 - phase_times->_scan_rs_time +
1.156 - phase_times->_obj_copy_time +
1.157 - + phase_times->_termination_time;
1.158 + double parallel_known_time = phase_times->average_last_ext_root_scan_time() +
1.159 + phase_times->average_last_satb_filtering_times_ms() +
1.160 + phase_times->average_last_update_rs_time() +
1.161 + phase_times->average_last_scan_rs_time() +
1.162 + phase_times->average_last_obj_copy_time() +
1.163 + + phase_times->average_last_termination_time();
1.164
1.165 - double parallel_other_time = phase_times->_cur_collection_par_time_ms - parallel_known_time;
1.166 + double parallel_other_time = phase_times->cur_collection_par_time_ms() - parallel_known_time;
1.167 _parallel_other.add(parallel_other_time);
1.168 - _clear_ct.add(phase_times->_cur_clear_ct_time_ms);
1.169 + _clear_ct.add(phase_times->cur_clear_ct_time_ms());
1.170 }
1.171 }
1.172
