1059 } 1060 _last_young_gc = false; 1061 } 1062 1063 if (!_last_gc_was_young) { 1064 // This is a mixed GC. Here we decide whether to continue doing 1065 // mixed GCs or not. 1066 1067 if (!next_gc_should_be_mixed("continue mixed GCs", 1068 "do not continue mixed GCs")) { 1069 set_gcs_are_young(true); 1070 } 1071 } 1072 1073 _short_lived_surv_rate_group->start_adding_regions(); 1074 // Do that for any other surv rate groups 1075 1076 if (update_stats) { 1077 double cost_per_card_ms = 0.0; 1078 if (_pending_cards > 0) { 1079 cost_per_card_ms = phase_times()->average_last_update_rs_time() / (double) _pending_cards; 1080 _cost_per_card_ms_seq->add(cost_per_card_ms); 1081 } 1082 1083 size_t cards_scanned = _g1->cards_scanned(); 1084 1085 double cost_per_entry_ms = 0.0; 1086 if (cards_scanned > 10) { 1087 cost_per_entry_ms = phase_times()->average_last_scan_rs_time() / (double) cards_scanned; 1088 if (_last_gc_was_young) { 1089 _cost_per_entry_ms_seq->add(cost_per_entry_ms); 1090 } else { 1091 _mixed_cost_per_entry_ms_seq->add(cost_per_entry_ms); 1092 } 1093 } 1094 1095 if (_max_rs_lengths > 0) { 1096 double cards_per_entry_ratio = 1097 (double) cards_scanned / (double) _max_rs_lengths; 1098 if (_last_gc_was_young) { 1099 _young_cards_per_entry_ratio_seq->add(cards_per_entry_ratio); 1100 } else { 1101 _mixed_cards_per_entry_ratio_seq->add(cards_per_entry_ratio); 1102 } 1103 } 1104 1105 // This is defensive. For a while _max_rs_lengths could get 1106 // smaller than _recorded_rs_lengths which was causing 1107 // rs_length_diff to get very large and mess up the RSet length 1109 // _inc_cset_recorded_rs_lengths field which the code below guards 1110 // against (see CR 7118202). This bug has now been fixed (see CR 1111 // 7119027). However, I'm still worried that 1112 // _inc_cset_recorded_rs_lengths might still end up somewhat 1113 // inaccurate. The concurrent refinement thread calculates an 1114 // RSet's length concurrently with other CR threads updating it 1115 // which might cause it to calculate the length incorrectly (if, 1116 // say, it's in mid-coarsening). So I'll leave in the defensive 1117 // conditional below just in case. 1118 size_t rs_length_diff = 0; 1119 if (_max_rs_lengths > _recorded_rs_lengths) { 1120 rs_length_diff = _max_rs_lengths - _recorded_rs_lengths; 1121 } 1122 _rs_length_diff_seq->add((double) rs_length_diff); 1123 1124 size_t freed_bytes = _heap_used_bytes_before_gc - cur_used_bytes; 1125 size_t copied_bytes = _collection_set_bytes_used_before - freed_bytes; 1126 double cost_per_byte_ms = 0.0; 1127 1128 if (copied_bytes > 0) { 1129 cost_per_byte_ms = phase_times()->average_last_obj_copy_time() / (double) copied_bytes; 1130 if (_in_marking_window) { 1131 _cost_per_byte_ms_during_cm_seq->add(cost_per_byte_ms); 1132 } else { 1133 _cost_per_byte_ms_seq->add(cost_per_byte_ms); 1134 } 1135 } 1136 1137 double all_other_time_ms = pause_time_ms - 1138 (phase_times()->average_last_update_rs_time() + phase_times()->average_last_scan_rs_time() 1139 + phase_times()->average_last_obj_copy_time() + phase_times()->average_last_termination_time()); 1140 1141 double young_other_time_ms = 0.0; 1142 if (young_cset_region_length() > 0) { 1143 young_other_time_ms = 1144 phase_times()->young_cset_choice_time_ms() + 1145 phase_times()->young_free_cset_time_ms(); 1146 _young_other_cost_per_region_ms_seq->add(young_other_time_ms / 1147 (double) young_cset_region_length()); 1148 } 1149 double non_young_other_time_ms = 0.0; 1150 if (old_cset_region_length() > 0) { 1151 non_young_other_time_ms = 1152 phase_times()->non_young_cset_choice_time_ms() + 1153 phase_times()->non_young_free_cset_time_ms(); 1154 1155 _non_young_other_cost_per_region_ms_seq->add(non_young_other_time_ms / 1156 (double) old_cset_region_length()); 1157 } 1158 1159 double constant_other_time_ms = all_other_time_ms - 1160 (young_other_time_ms + non_young_other_time_ms); 1161 _constant_other_time_ms_seq->add(constant_other_time_ms); 1162 1163 double survival_ratio = 0.0; 1164 if (_collection_set_bytes_used_before > 0) { 1165 survival_ratio = (double) _bytes_copied_during_gc / 1166 (double) _collection_set_bytes_used_before; 1167 } 1168 1169 _pending_cards_seq->add((double) _pending_cards); 1170 _rs_lengths_seq->add((double) _max_rs_lengths); 1171 } 1172 1173 _in_marking_window = new_in_marking_window; 1174 _in_marking_window_im = new_in_marking_window_im; 1175 _free_regions_at_end_of_collection = _g1->num_free_regions(); 1176 update_young_list_target_length(); 1177 1178 // Note that _mmu_tracker->max_gc_time() returns the time in seconds. 1179 double update_rs_time_goal_ms = _mmu_tracker->max_gc_time() * MILLIUNITS * G1RSetUpdatingPauseTimePercent / 100.0; 1180 adjust_concurrent_refinement(phase_times()->average_last_update_rs_time(), 1181 phase_times()->sum_last_update_rs_processed_buffers(), update_rs_time_goal_ms); 1182 1183 _collectionSetChooser->verify(); 1184 } 1185 1186 #define EXT_SIZE_FORMAT "%.1f%s" 1187 #define EXT_SIZE_PARAMS(bytes) \ 1188 byte_size_in_proper_unit((double)(bytes)), \ 1189 proper_unit_for_byte_size((bytes)) 1190 1191 void G1CollectorPolicy::record_heap_size_info_at_start(bool full) { 1192 YoungList* young_list = _g1->young_list(); 1193 _eden_used_bytes_before_gc = young_list->eden_used_bytes(); 1194 _survivor_used_bytes_before_gc = young_list->survivor_used_bytes(); 1195 _heap_capacity_bytes_before_gc = _g1->capacity(); 1196 _heap_used_bytes_before_gc = _g1->used(); 1197 _cur_collection_pause_used_regions_at_start = _g1->num_used_regions(); 1198 1199 _eden_capacity_bytes_before_gc = 1200 (_young_list_target_length * HeapRegion::GrainBytes) - _survivor_used_bytes_before_gc; 1201 2103 } 2104 2105 void TraceYoungGenTimeData::record_start_collection(double time_to_stop_the_world_ms) { 2106 if(TraceYoungGenTime) { 2107 _all_stop_world_times_ms.add(time_to_stop_the_world_ms); 2108 } 2109 } 2110 2111 void TraceYoungGenTimeData::record_yield_time(double yield_time_ms) { 2112 if(TraceYoungGenTime) { 2113 _all_yield_times_ms.add(yield_time_ms); 2114 } 2115 } 2116 2117 void TraceYoungGenTimeData::record_end_collection(double pause_time_ms, G1GCPhaseTimes* phase_times) { 2118 if(TraceYoungGenTime) { 2119 _total.add(pause_time_ms); 2120 _other.add(pause_time_ms - phase_times->accounted_time_ms()); 2121 _root_region_scan_wait.add(phase_times->root_region_scan_wait_time_ms()); 2122 _parallel.add(phase_times->cur_collection_par_time_ms()); 2123 _ext_root_scan.add(phase_times->average_last_ext_root_scan_time()); 2124 _satb_filtering.add(phase_times->average_last_satb_filtering_times_ms()); 2125 _update_rs.add(phase_times->average_last_update_rs_time()); 2126 _scan_rs.add(phase_times->average_last_scan_rs_time()); 2127 _obj_copy.add(phase_times->average_last_obj_copy_time()); 2128 _termination.add(phase_times->average_last_termination_time()); 2129 2130 double parallel_known_time = phase_times->average_last_ext_root_scan_time() + 2131 phase_times->average_last_satb_filtering_times_ms() + 2132 phase_times->average_last_update_rs_time() + 2133 phase_times->average_last_scan_rs_time() + 2134 phase_times->average_last_obj_copy_time() + 2135 + phase_times->average_last_termination_time(); 2136 2137 double parallel_other_time = phase_times->cur_collection_par_time_ms() - parallel_known_time; 2138 _parallel_other.add(parallel_other_time); 2139 _clear_ct.add(phase_times->cur_clear_ct_time_ms()); 2140 } 2141 } 2142 2143 void TraceYoungGenTimeData::increment_young_collection_count() { 2144 if(TraceYoungGenTime) { 2145 ++_young_pause_num; 2146 } 2147 } 2148 2149 void TraceYoungGenTimeData::increment_mixed_collection_count() { 2150 if(TraceYoungGenTime) { 2151 ++_mixed_pause_num; 2152 } 2153 } 2154 2155 void TraceYoungGenTimeData::print_summary(const char* str, | 1059 } 1060 _last_young_gc = false; 1061 } 1062 1063 if (!_last_gc_was_young) { 1064 // This is a mixed GC. Here we decide whether to continue doing 1065 // mixed GCs or not. 1066 1067 if (!next_gc_should_be_mixed("continue mixed GCs", 1068 "do not continue mixed GCs")) { 1069 set_gcs_are_young(true); 1070 } 1071 } 1072 1073 _short_lived_surv_rate_group->start_adding_regions(); 1074 // Do that for any other surv rate groups 1075 1076 if (update_stats) { 1077 double cost_per_card_ms = 0.0; 1078 if (_pending_cards > 0) { 1079 cost_per_card_ms = phase_times()->average_time_ms(G1GCPhaseTimes::UpdateRS) / (double) _pending_cards; 1080 _cost_per_card_ms_seq->add(cost_per_card_ms); 1081 } 1082 1083 size_t cards_scanned = _g1->cards_scanned(); 1084 1085 double cost_per_entry_ms = 0.0; 1086 if (cards_scanned > 10) { 1087 cost_per_entry_ms = phase_times()->average_time_ms(G1GCPhaseTimes::ScanRS) / (double) cards_scanned; 1088 if (_last_gc_was_young) { 1089 _cost_per_entry_ms_seq->add(cost_per_entry_ms); 1090 } else { 1091 _mixed_cost_per_entry_ms_seq->add(cost_per_entry_ms); 1092 } 1093 } 1094 1095 if (_max_rs_lengths > 0) { 1096 double cards_per_entry_ratio = 1097 (double) cards_scanned / (double) _max_rs_lengths; 1098 if (_last_gc_was_young) { 1099 _young_cards_per_entry_ratio_seq->add(cards_per_entry_ratio); 1100 } else { 1101 _mixed_cards_per_entry_ratio_seq->add(cards_per_entry_ratio); 1102 } 1103 } 1104 1105 // This is defensive. For a while _max_rs_lengths could get 1106 // smaller than _recorded_rs_lengths which was causing 1107 // rs_length_diff to get very large and mess up the RSet length 1109 // _inc_cset_recorded_rs_lengths field which the code below guards 1110 // against (see CR 7118202). This bug has now been fixed (see CR 1111 // 7119027). However, I'm still worried that 1112 // _inc_cset_recorded_rs_lengths might still end up somewhat 1113 // inaccurate. The concurrent refinement thread calculates an 1114 // RSet's length concurrently with other CR threads updating it 1115 // which might cause it to calculate the length incorrectly (if, 1116 // say, it's in mid-coarsening). So I'll leave in the defensive 1117 // conditional below just in case. 1118 size_t rs_length_diff = 0; 1119 if (_max_rs_lengths > _recorded_rs_lengths) { 1120 rs_length_diff = _max_rs_lengths - _recorded_rs_lengths; 1121 } 1122 _rs_length_diff_seq->add((double) rs_length_diff); 1123 1124 size_t freed_bytes = _heap_used_bytes_before_gc - cur_used_bytes; 1125 size_t copied_bytes = _collection_set_bytes_used_before - freed_bytes; 1126 double cost_per_byte_ms = 0.0; 1127 1128 if (copied_bytes > 0) { 1129 cost_per_byte_ms = phase_times()->average_time_ms(G1GCPhaseTimes::ObjCopy) / (double) copied_bytes; 1130 if (_in_marking_window) { 1131 _cost_per_byte_ms_during_cm_seq->add(cost_per_byte_ms); 1132 } else { 1133 _cost_per_byte_ms_seq->add(cost_per_byte_ms); 1134 } 1135 } 1136 1137 double all_other_time_ms = pause_time_ms - 1138 (phase_times()->average_time_ms(G1GCPhaseTimes::UpdateRS) + phase_times()->average_time_ms(G1GCPhaseTimes::ScanRS) 1139 + phase_times()->average_time_ms(G1GCPhaseTimes::ObjCopy) + phase_times()->average_time_ms(G1GCPhaseTimes::Termination)); 1140 1141 double young_other_time_ms = 0.0; 1142 if (young_cset_region_length() > 0) { 1143 young_other_time_ms = 1144 phase_times()->young_cset_choice_time_ms() + 1145 phase_times()->young_free_cset_time_ms(); 1146 _young_other_cost_per_region_ms_seq->add(young_other_time_ms / 1147 (double) young_cset_region_length()); 1148 } 1149 double non_young_other_time_ms = 0.0; 1150 if (old_cset_region_length() > 0) { 1151 non_young_other_time_ms = 1152 phase_times()->non_young_cset_choice_time_ms() + 1153 phase_times()->non_young_free_cset_time_ms(); 1154 1155 _non_young_other_cost_per_region_ms_seq->add(non_young_other_time_ms / 1156 (double) old_cset_region_length()); 1157 } 1158 1159 double constant_other_time_ms = all_other_time_ms - 1160 (young_other_time_ms + non_young_other_time_ms); 1161 _constant_other_time_ms_seq->add(constant_other_time_ms); 1162 1163 double survival_ratio = 0.0; 1164 if (_collection_set_bytes_used_before > 0) { 1165 survival_ratio = (double) _bytes_copied_during_gc / 1166 (double) _collection_set_bytes_used_before; 1167 } 1168 1169 _pending_cards_seq->add((double) _pending_cards); 1170 _rs_lengths_seq->add((double) _max_rs_lengths); 1171 } 1172 1173 _in_marking_window = new_in_marking_window; 1174 _in_marking_window_im = new_in_marking_window_im; 1175 _free_regions_at_end_of_collection = _g1->num_free_regions(); 1176 update_young_list_target_length(); 1177 1178 // Note that _mmu_tracker->max_gc_time() returns the time in seconds. 1179 double update_rs_time_goal_ms = _mmu_tracker->max_gc_time() * MILLIUNITS * G1RSetUpdatingPauseTimePercent / 100.0; 1180 adjust_concurrent_refinement(phase_times()->average_time_ms(G1GCPhaseTimes::UpdateRS), 1181 phase_times()->sub_count_sum(G1GCPhaseTimes::UpdateRS), update_rs_time_goal_ms); 1182 1183 _collectionSetChooser->verify(); 1184 } 1185 1186 #define EXT_SIZE_FORMAT "%.1f%s" 1187 #define EXT_SIZE_PARAMS(bytes) \ 1188 byte_size_in_proper_unit((double)(bytes)), \ 1189 proper_unit_for_byte_size((bytes)) 1190 1191 void G1CollectorPolicy::record_heap_size_info_at_start(bool full) { 1192 YoungList* young_list = _g1->young_list(); 1193 _eden_used_bytes_before_gc = young_list->eden_used_bytes(); 1194 _survivor_used_bytes_before_gc = young_list->survivor_used_bytes(); 1195 _heap_capacity_bytes_before_gc = _g1->capacity(); 1196 _heap_used_bytes_before_gc = _g1->used(); 1197 _cur_collection_pause_used_regions_at_start = _g1->num_used_regions(); 1198 1199 _eden_capacity_bytes_before_gc = 1200 (_young_list_target_length * HeapRegion::GrainBytes) - _survivor_used_bytes_before_gc; 1201 2103 } 2104 2105 void TraceYoungGenTimeData::record_start_collection(double time_to_stop_the_world_ms) { 2106 if(TraceYoungGenTime) { 2107 _all_stop_world_times_ms.add(time_to_stop_the_world_ms); 2108 } 2109 } 2110 2111 void TraceYoungGenTimeData::record_yield_time(double yield_time_ms) { 2112 if(TraceYoungGenTime) { 2113 _all_yield_times_ms.add(yield_time_ms); 2114 } 2115 } 2116 2117 void TraceYoungGenTimeData::record_end_collection(double pause_time_ms, G1GCPhaseTimes* phase_times) { 2118 if(TraceYoungGenTime) { 2119 _total.add(pause_time_ms); 2120 _other.add(pause_time_ms - phase_times->accounted_time_ms()); 2121 _root_region_scan_wait.add(phase_times->root_region_scan_wait_time_ms()); 2122 _parallel.add(phase_times->cur_collection_par_time_ms()); 2123 _ext_root_scan.add(phase_times->average_time_ms(G1GCPhaseTimes::ExtRootScan)); 2124 _satb_filtering.add(phase_times->average_time_ms(G1GCPhaseTimes::SATBFiltering)); 2125 _update_rs.add(phase_times->average_time_ms(G1GCPhaseTimes::UpdateRS)); 2126 _scan_rs.add(phase_times->average_time_ms(G1GCPhaseTimes::ScanRS)); 2127 _obj_copy.add(phase_times->average_time_ms(G1GCPhaseTimes::ObjCopy)); 2128 _termination.add(phase_times->average_time_ms(G1GCPhaseTimes::Termination)); 2129 2130 double parallel_known_time = phase_times->average_time_ms(G1GCPhaseTimes::ExtRootScan) + 2131 phase_times->average_time_ms(G1GCPhaseTimes::SATBFiltering) + 2132 phase_times->average_time_ms(G1GCPhaseTimes::UpdateRS) + 2133 phase_times->average_time_ms(G1GCPhaseTimes::ScanRS) + 2134 phase_times->average_time_ms(G1GCPhaseTimes::ObjCopy) + 2135 phase_times->average_time_ms(G1GCPhaseTimes::Termination); 2136 2137 double parallel_other_time = phase_times->cur_collection_par_time_ms() - parallel_known_time; 2138 _parallel_other.add(parallel_other_time); 2139 _clear_ct.add(phase_times->cur_clear_ct_time_ms()); 2140 } 2141 } 2142 2143 void TraceYoungGenTimeData::increment_young_collection_count() { 2144 if(TraceYoungGenTime) { 2145 ++_young_pause_num; 2146 } 2147 } 2148 2149 void TraceYoungGenTimeData::increment_mixed_collection_count() { 2150 if(TraceYoungGenTime) { 2151 ++_mixed_pause_num; 2152 } 2153 } 2154 2155 void TraceYoungGenTimeData::print_summary(const char* str, |