Mercurial > hg > graal-jvmci-8

comparison src/share/vm/gc_implementation/g1/g1CollectorPolicy.cpp @ 6628:bb3f6194fedb

Find changesets by keywords (author, files, the commit message), revision number or hash, or revset expression.
7178363: G1: Remove the serial code for PrintGCDetails and make it a special case of the parallel code Summary: Also reviewed by vitalyd@gmail.com. Introduced the WorkerDataArray class. Fixed some minor logging bugs. Reviewed-by: johnc, mgerdin
author brutisso
date Thu, 23 Aug 2012 10:21:12 +0200
parents 7383557659bd
children 37f7535e5f18
comparison
equal deleted inserted replaced
6625:153776c4cb6f 6628:bb3f6194fedb
793 793
794 double s_w_t_ms = (start_time_sec - _stop_world_start) * 1000.0; 794 double s_w_t_ms = (start_time_sec - _stop_world_start) * 1000.0;
795 _trace_gen0_time_data.record_start_collection(s_w_t_ms); 795 _trace_gen0_time_data.record_start_collection(s_w_t_ms);
796 _stop_world_start = 0.0; 796 _stop_world_start = 0.0;
797 797
798 phase_times()->_cur_collection_start_sec = start_time_sec; 798 phase_times()->record_cur_collection_start_sec(start_time_sec);
799 _cur_collection_pause_used_at_start_bytes = start_used; 799 _cur_collection_pause_used_at_start_bytes = start_used;
800 _cur_collection_pause_used_regions_at_start = _g1->used_regions(); 800 _cur_collection_pause_used_regions_at_start = _g1->used_regions();
801 _pending_cards = _g1->pending_card_num(); 801 _pending_cards = _g1->pending_card_num();
802 802
803 _collection_set_bytes_used_before = 0; 803 _collection_set_bytes_used_before = 0;
945 945
946 if (update_stats) { 946 if (update_stats) {
947 _trace_gen0_time_data.record_end_collection(pause_time_ms, phase_times()); 947 _trace_gen0_time_data.record_end_collection(pause_time_ms, phase_times());
948 // this is where we update the allocation rate of the application 948 // this is where we update the allocation rate of the application
949 double app_time_ms = 949 double app_time_ms =
950 (phase_times()->_cur_collection_start_sec * 1000.0 - _prev_collection_pause_end_ms); 950 (phase_times()->cur_collection_start_sec() * 1000.0 - _prev_collection_pause_end_ms);
951 if (app_time_ms < MIN_TIMER_GRANULARITY) { 951 if (app_time_ms < MIN_TIMER_GRANULARITY) {
952 // This usually happens due to the timer not having the required 952 // This usually happens due to the timer not having the required
953 // granularity. Some Linuxes are the usual culprits. 953 // granularity. Some Linuxes are the usual culprits.
954 // We'll just set it to something (arbitrarily) small. 954 // We'll just set it to something (arbitrarily) small.
955 app_time_ms = 1.0; 955 app_time_ms = 1.0;
1033 // do that for any other surv rate groupsx 1033 // do that for any other surv rate groupsx
1034 1034
1035 if (update_stats) { 1035 if (update_stats) {
1036 double cost_per_card_ms = 0.0; 1036 double cost_per_card_ms = 0.0;
1037 if (_pending_cards > 0) { 1037 if (_pending_cards > 0) {
1038 cost_per_card_ms = phase_times()->_update_rs_time / (double) _pending_cards; 1038 cost_per_card_ms = phase_times()->average_last_update_rs_time() / (double) _pending_cards;
1039 _cost_per_card_ms_seq->add(cost_per_card_ms); 1039 _cost_per_card_ms_seq->add(cost_per_card_ms);
1040 } 1040 }
1041 1041
1042 size_t cards_scanned = _g1->cards_scanned(); 1042 size_t cards_scanned = _g1->cards_scanned();
1043 1043
1044 double cost_per_entry_ms = 0.0; 1044 double cost_per_entry_ms = 0.0;
1045 if (cards_scanned > 10) { 1045 if (cards_scanned > 10) {
1046 cost_per_entry_ms = phase_times()->_scan_rs_time / (double) cards_scanned; 1046 cost_per_entry_ms = phase_times()->average_last_scan_rs_time() / (double) cards_scanned;
1047 if (_last_gc_was_young) { 1047 if (_last_gc_was_young) {
1048 _cost_per_entry_ms_seq->add(cost_per_entry_ms); 1048 _cost_per_entry_ms_seq->add(cost_per_entry_ms);
1049 } else { 1049 } else {
1050 _mixed_cost_per_entry_ms_seq->add(cost_per_entry_ms); 1050 _mixed_cost_per_entry_ms_seq->add(cost_per_entry_ms);
1051 } 1051 }
1081 _rs_length_diff_seq->add((double) rs_length_diff); 1081 _rs_length_diff_seq->add((double) rs_length_diff);
1082 1082
1083 size_t copied_bytes = surviving_bytes; 1083 size_t copied_bytes = surviving_bytes;
1084 double cost_per_byte_ms = 0.0; 1084 double cost_per_byte_ms = 0.0;
1085 if (copied_bytes > 0) { 1085 if (copied_bytes > 0) {
1086 cost_per_byte_ms = phase_times()->_obj_copy_time / (double) copied_bytes; 1086 cost_per_byte_ms = phase_times()->average_last_obj_copy_time() / (double) copied_bytes;
1087 if (_in_marking_window) { 1087 if (_in_marking_window) {
1088 _cost_per_byte_ms_during_cm_seq->add(cost_per_byte_ms); 1088 _cost_per_byte_ms_during_cm_seq->add(cost_per_byte_ms);
1089 } else { 1089 } else {
1090 _cost_per_byte_ms_seq->add(cost_per_byte_ms); 1090 _cost_per_byte_ms_seq->add(cost_per_byte_ms);
1091 } 1091 }
1092 } 1092 }
1093 1093
1094 double all_other_time_ms = pause_time_ms - 1094 double all_other_time_ms = pause_time_ms -
1095 (phase_times()->_update_rs_time + phase_times()->_scan_rs_time + phase_times()->_obj_copy_time + phase_times()->_termination_time); 1095 (phase_times()->average_last_update_rs_time() + phase_times()->average_last_scan_rs_time()
1096 + phase_times()->average_last_obj_copy_time() + phase_times()->average_last_termination_time());
1096 1097
1097 double young_other_time_ms = 0.0; 1098 double young_other_time_ms = 0.0;
1098 if (young_cset_region_length() > 0) { 1099 if (young_cset_region_length() > 0) {
1099 young_other_time_ms = 1100 young_other_time_ms =
1100 phase_times()->_recorded_young_cset_choice_time_ms + 1101 phase_times()->young_cset_choice_time_ms() +
1101 phase_times()->_recorded_young_free_cset_time_ms; 1102 phase_times()->young_free_cset_time_ms();
1102 _young_other_cost_per_region_ms_seq->add(young_other_time_ms / 1103 _young_other_cost_per_region_ms_seq->add(young_other_time_ms /
1103 (double) young_cset_region_length()); 1104 (double) young_cset_region_length());
1104 } 1105 }
1105 double non_young_other_time_ms = 0.0; 1106 double non_young_other_time_ms = 0.0;
1106 if (old_cset_region_length() > 0) { 1107 if (old_cset_region_length() > 0) {
1107 non_young_other_time_ms = 1108 non_young_other_time_ms =
1108 phase_times()->_recorded_non_young_cset_choice_time_ms + 1109 phase_times()->non_young_cset_choice_time_ms() +
1109 phase_times()->_recorded_non_young_free_cset_time_ms; 1110 phase_times()->non_young_free_cset_time_ms();
1110 1111
1111 _non_young_other_cost_per_region_ms_seq->add(non_young_other_time_ms / 1112 _non_young_other_cost_per_region_ms_seq->add(non_young_other_time_ms /
1112 (double) old_cset_region_length()); 1113 (double) old_cset_region_length());
1113 } 1114 }
1114 1115
1131 _free_regions_at_end_of_collection = _g1->free_regions(); 1132 _free_regions_at_end_of_collection = _g1->free_regions();
1132 update_young_list_target_length(); 1133 update_young_list_target_length();
1133 1134
1134 // Note that _mmu_tracker->max_gc_time() returns the time in seconds. 1135 // Note that _mmu_tracker->max_gc_time() returns the time in seconds.
1135 double update_rs_time_goal_ms = _mmu_tracker->max_gc_time() * MILLIUNITS * G1RSetUpdatingPauseTimePercent / 100.0; 1136 double update_rs_time_goal_ms = _mmu_tracker->max_gc_time() * MILLIUNITS * G1RSetUpdatingPauseTimePercent / 100.0;
1136 adjust_concurrent_refinement(phase_times()->_update_rs_time, phase_times()->_update_rs_processed_buffers, update_rs_time_goal_ms); 1137 adjust_concurrent_refinement(phase_times()->average_last_update_rs_time(),
1138 phase_times()->sum_last_update_rs_processed_buffers(), update_rs_time_goal_ms);
1137 1139
1138 _collectionSetChooser->verify(); 1140 _collectionSetChooser->verify();
1139 } 1141 }
1140 1142
1141 #define EXT_SIZE_FORMAT "%.1f%s" 1143 #define EXT_SIZE_FORMAT "%.1f%s"
1142 #define EXT_SIZE_PARAMS(bytes) \ 1144 #define EXT_SIZE_PARAMS(bytes) \
1143 byte_size_in_proper_unit((double)(bytes)), \ 1145 byte_size_in_proper_unit((double)(bytes)), \
1144 proper_unit_for_byte_size((bytes)) 1146 proper_unit_for_byte_size((bytes))
1145 1147
1146 void G1CollectorPolicy::print_heap_transition() { 1148 void G1CollectorPolicy::print_heap_transition() {
1147 if (G1Log::finer()) { 1149 _g1->print_size_transition(gclog_or_tty,
1150 _cur_collection_pause_used_at_start_bytes, _g1->used(), _g1->capacity());
1151 }
1152
1153 void G1CollectorPolicy::print_detailed_heap_transition() {
1148 YoungList* young_list = _g1->young_list(); 1154 YoungList* young_list = _g1->young_list();
1149 size_t eden_bytes = young_list->eden_used_bytes(); 1155 size_t eden_bytes = young_list->eden_used_bytes();
1150 size_t survivor_bytes = young_list->survivor_used_bytes(); 1156 size_t survivor_bytes = young_list->survivor_used_bytes();
1151 size_t used_before_gc = _cur_collection_pause_used_at_start_bytes; 1157 size_t used_before_gc = _cur_collection_pause_used_at_start_bytes;
1152 size_t used = _g1->used(); 1158 size_t used = _g1->used();
1169 EXT_SIZE_PARAMS(_capacity_before_gc), 1175 EXT_SIZE_PARAMS(_capacity_before_gc),
1170 EXT_SIZE_PARAMS(used), 1176 EXT_SIZE_PARAMS(used),
1171 EXT_SIZE_PARAMS(capacity)); 1177 EXT_SIZE_PARAMS(capacity));
1172 1178
1173 _prev_eden_capacity = eden_capacity; 1179 _prev_eden_capacity = eden_capacity;
1174 } else if (G1Log::fine()) {
1175 _g1->print_size_transition(gclog_or_tty,
1176 _cur_collection_pause_used_at_start_bytes,
1177 _g1->used(), _g1->capacity());
1178 }
1179 } 1180 }
1180 1181
1181 void G1CollectorPolicy::adjust_concurrent_refinement(double update_rs_time, 1182 void G1CollectorPolicy::adjust_concurrent_refinement(double update_rs_time,
1182 double update_rs_processed_buffers, 1183 double update_rs_processed_buffers,
1183 double goal_ms) { 1184 double goal_ms) {
1898 // The number of recorded young regions is the incremental 1899 // The number of recorded young regions is the incremental
1899 // collection set's current size 1900 // collection set's current size
1900 set_recorded_rs_lengths(_inc_cset_recorded_rs_lengths); 1901 set_recorded_rs_lengths(_inc_cset_recorded_rs_lengths);
1901 1902
1902 double young_end_time_sec = os::elapsedTime(); 1903 double young_end_time_sec = os::elapsedTime();
1903 phase_times()->_recorded_young_cset_choice_time_ms = 1904 phase_times()->record_young_cset_choice_time_ms((young_end_time_sec - young_start_time_sec) * 1000.0);
1904 (young_end_time_sec - young_start_time_sec) * 1000.0;
1905 1905
1906 // Set the start of the non-young choice time. 1906 // Set the start of the non-young choice time.
1907 double non_young_start_time_sec = young_end_time_sec; 1907 double non_young_start_time_sec = young_end_time_sec;
1908 1908
1909 if (!gcs_are_young()) { 1909 if (!gcs_are_young()) {
2013 eden_region_length, survivor_region_length, 2013 eden_region_length, survivor_region_length,
2014 old_cset_region_length(), 2014 old_cset_region_length(),
2015 predicted_pause_time_ms, target_pause_time_ms); 2015 predicted_pause_time_ms, target_pause_time_ms);
2016 2016
2017 double non_young_end_time_sec = os::elapsedTime(); 2017 double non_young_end_time_sec = os::elapsedTime();
2018 phase_times()->_recorded_non_young_cset_choice_time_ms = 2018 phase_times()->record_non_young_cset_choice_time_ms((non_young_end_time_sec - non_young_start_time_sec) * 1000.0);
2019 (non_young_end_time_sec - non_young_start_time_sec) * 1000.0;
2020 } 2019 }
2021 2020
2022 void TraceGen0TimeData::record_start_collection(double time_to_stop_the_world_ms) { 2021 void TraceGen0TimeData::record_start_collection(double time_to_stop_the_world_ms) {
2023 if(TraceGen0Time) { 2022 if(TraceGen0Time) {
2024 _all_stop_world_times_ms.add(time_to_stop_the_world_ms); 2023 _all_stop_world_times_ms.add(time_to_stop_the_world_ms);
2033 2032
2034 void TraceGen0TimeData::record_end_collection(double pause_time_ms, G1GCPhaseTimes* phase_times) { 2033 void TraceGen0TimeData::record_end_collection(double pause_time_ms, G1GCPhaseTimes* phase_times) {
2035 if(TraceGen0Time) { 2034 if(TraceGen0Time) {
2036 _total.add(pause_time_ms); 2035 _total.add(pause_time_ms);
2037 _other.add(pause_time_ms - phase_times->accounted_time_ms()); 2036 _other.add(pause_time_ms - phase_times->accounted_time_ms());
2038 _root_region_scan_wait.add(phase_times->_root_region_scan_wait_time_ms); 2037 _root_region_scan_wait.add(phase_times->root_region_scan_wait_time_ms());
2039 _parallel.add(phase_times->_cur_collection_par_time_ms); 2038 _parallel.add(phase_times->cur_collection_par_time_ms());
2040 _ext_root_scan.add(phase_times->_ext_root_scan_time); 2039 _ext_root_scan.add(phase_times->average_last_ext_root_scan_time());
2041 _satb_filtering.add(phase_times->_satb_filtering_time); 2040 _satb_filtering.add(phase_times->average_last_satb_filtering_times_ms());
2042 _update_rs.add(phase_times->_update_rs_time); 2041 _update_rs.add(phase_times->average_last_update_rs_time());
2043 _scan_rs.add(phase_times->_scan_rs_time); 2042 _scan_rs.add(phase_times->average_last_scan_rs_time());
2044 _obj_copy.add(phase_times->_obj_copy_time); 2043 _obj_copy.add(phase_times->average_last_obj_copy_time());
2045 _termination.add(phase_times->_termination_time); 2044 _termination.add(phase_times->average_last_termination_time());
2046 2045
2047 double parallel_known_time = phase_times->_ext_root_scan_time + 2046 double parallel_known_time = phase_times->average_last_ext_root_scan_time() +
2048 phase_times->_satb_filtering_time + 2047 phase_times->average_last_satb_filtering_times_ms() +
2049 phase_times->_update_rs_time + 2048 phase_times->average_last_update_rs_time() +
2050 phase_times->_scan_rs_time + 2049 phase_times->average_last_scan_rs_time() +
2051 phase_times->_obj_copy_time + 2050 phase_times->average_last_obj_copy_time() +
2052 + phase_times->_termination_time; 2051 + phase_times->average_last_termination_time();
2053 2052
2054 double parallel_other_time = phase_times->_cur_collection_par_time_ms - parallel_known_time; 2053 double parallel_other_time = phase_times->cur_collection_par_time_ms() - parallel_known_time;
2055 _parallel_other.add(parallel_other_time); 2054 _parallel_other.add(parallel_other_time);
2056 _clear_ct.add(phase_times->_cur_clear_ct_time_ms); 2055 _clear_ct.add(phase_times->cur_clear_ct_time_ms());
2057 } 2056 }
2058 } 2057 }
2059 2058
2060 void TraceGen0TimeData::increment_young_collection_count() { 2059 void TraceGen0TimeData::increment_young_collection_count() {
2061 if(TraceGen0Time) { 2060 if(TraceGen0Time) {