Mercurial > hg > truffle
comparison src/share/vm/gc_implementation/g1/g1GCPhaseTimes.hpp @ 6628:bb3f6194fedb
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 | 3a431b605145 |
children | 7df93f7c14a5 |
comparison
equal
deleted
inserted
replaced
6625:153776c4cb6f | 6628:bb3f6194fedb |
---|---|
26 #define SHARE_VM_GC_IMPLEMENTATION_G1_G1GCPHASETIMESLOG_HPP | 26 #define SHARE_VM_GC_IMPLEMENTATION_G1_G1GCPHASETIMESLOG_HPP |
27 | 27 |
28 #include "memory/allocation.hpp" | 28 #include "memory/allocation.hpp" |
29 #include "gc_interface/gcCause.hpp" | 29 #include "gc_interface/gcCause.hpp" |
30 | 30 |
31 template <class T> | |
32 class WorkerDataArray : public CHeapObj<mtGC> { | |
33 T* _data; | |
34 uint _length; | |
35 const char* _print_format; | |
36 bool _print_sum; | |
37 | |
38 // We are caching the sum and average to only have to calculate them once. | |
39 // This is not done in an MT-safe way. It is intetened to allow single | |
40 // threaded code to call sum() and average() multiple times in any order | |
41 // without having to worry about the cost. | |
42 bool _has_new_data; | |
43 T _sum; | |
44 double _average; | |
45 | |
46 public: | |
47 WorkerDataArray(uint length, const char* print_format, bool print_sum = true) : | |
48 _length(length), _print_format(print_format), _print_sum(print_sum), _has_new_data(true) { | |
49 assert(length > 0, "Must have some workers to store data for"); | |
50 _data = NEW_C_HEAP_ARRAY(T, _length, mtGC); | |
51 } | |
52 | |
53 ~WorkerDataArray() { | |
54 FREE_C_HEAP_ARRAY(T, _data, mtGC); | |
55 } | |
56 | |
57 void set(uint worker_i, T value) { | |
58 assert(worker_i < _length, err_msg("Worker %d is greater than max: %d", worker_i, _length)); | |
59 assert(_data[worker_i] == (T)-1, err_msg("Overwriting data for worker %d", worker_i)); | |
60 _data[worker_i] = value; | |
61 _has_new_data = true; | |
62 } | |
63 | |
64 T get(uint worker_i) { | |
65 assert(worker_i < _length, err_msg("Worker %d is greater than max: %d", worker_i, _length)); | |
66 assert(_data[worker_i] != (T)-1, err_msg("No data to add to for worker %d", worker_i)); | |
67 return _data[worker_i]; | |
68 } | |
69 | |
70 void add(uint worker_i, T value) { | |
71 assert(worker_i < _length, err_msg("Worker %d is greater than max: %d", worker_i, _length)); | |
72 assert(_data[worker_i] != (T)-1, err_msg("No data to add to for worker %d", worker_i)); | |
73 _data[worker_i] += value; | |
74 _has_new_data = true; | |
75 } | |
76 | |
77 double average(){ | |
78 if (_has_new_data) { | |
79 calculate_totals(); | |
80 } | |
81 return _average; | |
82 } | |
83 | |
84 T sum() { | |
85 if (_has_new_data) { | |
86 calculate_totals(); | |
87 } | |
88 return _sum; | |
89 } | |
90 | |
91 void print(int level, const char* title); | |
92 | |
93 void reset() PRODUCT_RETURN; | |
94 void verify() PRODUCT_RETURN; | |
95 | |
96 private: | |
97 | |
98 void calculate_totals(){ | |
99 _sum = (T)0; | |
100 for (uint i = 0; i < _length; ++i) { | |
101 _sum += _data[i]; | |
102 } | |
103 _average = (double)_sum / (double)_length; | |
104 _has_new_data = false; | |
105 } | |
106 }; | |
107 | |
31 class G1GCPhaseTimes : public CHeapObj<mtGC> { | 108 class G1GCPhaseTimes : public CHeapObj<mtGC> { |
32 friend class G1CollectorPolicy; | |
33 friend class TraceGen0TimeData; | |
34 | 109 |
35 private: | 110 private: |
36 uint _active_gc_threads; | 111 uint _active_gc_threads; |
37 uint _max_gc_threads; | 112 uint _max_gc_threads; |
38 | 113 |
39 GCCause::Cause _gc_cause; | 114 WorkerDataArray<double> _last_gc_worker_start_times_ms; |
40 bool _is_young_gc; | 115 WorkerDataArray<double> _last_ext_root_scan_times_ms; |
41 bool _is_initial_mark_gc; | 116 WorkerDataArray<double> _last_satb_filtering_times_ms; |
42 | 117 WorkerDataArray<double> _last_update_rs_times_ms; |
43 double _pause_start_time_sec; | 118 WorkerDataArray<int> _last_update_rs_processed_buffers; |
44 | 119 WorkerDataArray<double> _last_scan_rs_times_ms; |
45 double* _par_last_gc_worker_start_times_ms; | 120 WorkerDataArray<double> _last_obj_copy_times_ms; |
46 double* _par_last_ext_root_scan_times_ms; | 121 WorkerDataArray<double> _last_termination_times_ms; |
47 double* _par_last_satb_filtering_times_ms; | 122 WorkerDataArray<size_t> _last_termination_attempts; |
48 double* _par_last_update_rs_times_ms; | 123 WorkerDataArray<double> _last_gc_worker_end_times_ms; |
49 double* _par_last_update_rs_processed_buffers; | 124 WorkerDataArray<double> _last_gc_worker_times_ms; |
50 double* _par_last_scan_rs_times_ms; | 125 WorkerDataArray<double> _last_gc_worker_other_times_ms; |
51 double* _par_last_obj_copy_times_ms; | |
52 double* _par_last_termination_times_ms; | |
53 double* _par_last_termination_attempts; | |
54 double* _par_last_gc_worker_end_times_ms; | |
55 double* _par_last_gc_worker_times_ms; | |
56 double* _par_last_gc_worker_other_times_ms; | |
57 | 126 |
58 double _cur_collection_par_time_ms; | 127 double _cur_collection_par_time_ms; |
59 | |
60 double _cur_collection_code_root_fixup_time_ms; | 128 double _cur_collection_code_root_fixup_time_ms; |
61 | 129 |
62 double _cur_clear_ct_time_ms; | 130 double _cur_clear_ct_time_ms; |
63 double _cur_ref_proc_time_ms; | 131 double _cur_ref_proc_time_ms; |
64 double _cur_ref_enq_time_ms; | 132 double _cur_ref_enq_time_ms; |
65 | |
66 // Helper methods for detailed logging | |
67 void print_par_stats(int level, const char* str, double* data, bool showDecimals = true); | |
68 void print_stats(int level, const char* str, double value); | |
69 void print_stats(int level, const char* str, double value, int workers); | |
70 void print_stats(int level, const char* str, int value); | |
71 double avg_value(double* data); | |
72 double max_value(double* data); | |
73 double sum_of_values(double* data); | |
74 double max_sum(double* data1, double* data2); | |
75 double accounted_time_ms(); | |
76 | 133 |
77 // Card Table Count Cache stats | 134 // Card Table Count Cache stats |
78 double _min_clear_cc_time_ms; // min | 135 double _min_clear_cc_time_ms; // min |
79 double _max_clear_cc_time_ms; // max | 136 double _max_clear_cc_time_ms; // max |
80 double _cur_clear_cc_time_ms; // clearing time during current pause | 137 double _cur_clear_cc_time_ms; // clearing time during current pause |
81 double _cum_clear_cc_time_ms; // cummulative clearing time | 138 double _cum_clear_cc_time_ms; // cummulative clearing time |
82 jlong _num_cc_clears; // number of times the card count cache has been cleared | 139 jlong _num_cc_clears; // number of times the card count cache has been cleared |
83 | 140 |
84 // The following insance variables are directly accessed by G1CollectorPolicy | |
85 // and TraceGen0TimeData. This is why those classes are declared friends. | |
86 // An alternative is to add getters and setters for all of these fields. | |
87 // It might also be possible to restructure the code to reduce these | |
88 // dependencies. | |
89 double _ext_root_scan_time; | |
90 double _satb_filtering_time; | |
91 double _update_rs_time; | |
92 double _update_rs_processed_buffers; | |
93 double _scan_rs_time; | |
94 double _obj_copy_time; | |
95 double _termination_time; | |
96 | |
97 double _cur_collection_start_sec; | 141 double _cur_collection_start_sec; |
98 double _root_region_scan_wait_time_ms; | 142 double _root_region_scan_wait_time_ms; |
99 | 143 |
100 double _recorded_young_cset_choice_time_ms; | 144 double _recorded_young_cset_choice_time_ms; |
101 double _recorded_non_young_cset_choice_time_ms; | 145 double _recorded_non_young_cset_choice_time_ms; |
102 | 146 |
103 double _recorded_young_free_cset_time_ms; | 147 double _recorded_young_free_cset_time_ms; |
104 double _recorded_non_young_free_cset_time_ms; | 148 double _recorded_non_young_free_cset_time_ms; |
105 | 149 |
106 void print(double pause_time_ms); | 150 double _cur_verify_before_time_ms; |
151 double _cur_verify_after_time_ms; | |
152 | |
153 // Helper methods for detailed logging | |
154 void print_stats(int level, const char* str, double value); | |
155 void print_stats(int level, const char* str, double value, int workers); | |
107 | 156 |
108 public: | 157 public: |
109 G1GCPhaseTimes(uint max_gc_threads); | 158 G1GCPhaseTimes(uint max_gc_threads); |
110 void note_gc_start(double pause_start_time_sec, uint active_gc_threads, | 159 void note_gc_start(uint active_gc_threads); |
111 bool is_young_gc, bool is_initial_mark_gc, GCCause::Cause gc_cause); | 160 void note_gc_end(); |
112 void note_gc_end(double pause_end_time_sec); | 161 void print(double pause_time_sec); |
113 void collapse_par_times(); | |
114 | 162 |
115 void record_gc_worker_start_time(uint worker_i, double ms) { | 163 void record_gc_worker_start_time(uint worker_i, double ms) { |
116 assert(worker_i >= 0, "worker index must be > 0"); | 164 _last_gc_worker_start_times_ms.set(worker_i, ms); |
117 assert(worker_i < _active_gc_threads, "worker index out of bounds"); | |
118 _par_last_gc_worker_start_times_ms[worker_i] = ms; | |
119 } | 165 } |
120 | 166 |
121 void record_ext_root_scan_time(uint worker_i, double ms) { | 167 void record_ext_root_scan_time(uint worker_i, double ms) { |
122 assert(worker_i >= 0, "worker index must be > 0"); | 168 _last_ext_root_scan_times_ms.set(worker_i, ms); |
123 assert(worker_i < _active_gc_threads, "worker index out of bounds"); | |
124 _par_last_ext_root_scan_times_ms[worker_i] = ms; | |
125 } | 169 } |
126 | 170 |
127 void record_satb_filtering_time(uint worker_i, double ms) { | 171 void record_satb_filtering_time(uint worker_i, double ms) { |
128 assert(worker_i >= 0, "worker index must be > 0"); | 172 _last_satb_filtering_times_ms.set(worker_i, ms); |
129 assert(worker_i < _active_gc_threads, "worker index out of bounds"); | |
130 _par_last_satb_filtering_times_ms[worker_i] = ms; | |
131 } | 173 } |
132 | 174 |
133 void record_update_rs_time(uint worker_i, double ms) { | 175 void record_update_rs_time(uint worker_i, double ms) { |
134 assert(worker_i >= 0, "worker index must be > 0"); | 176 _last_update_rs_times_ms.set(worker_i, ms); |
135 assert(worker_i < _active_gc_threads, "worker index out of bounds"); | 177 } |
136 _par_last_update_rs_times_ms[worker_i] = ms; | 178 |
137 } | 179 void record_update_rs_processed_buffers(uint worker_i, int processed_buffers) { |
138 | 180 _last_update_rs_processed_buffers.set(worker_i, processed_buffers); |
139 void record_update_rs_processed_buffers (uint worker_i, | |
140 double processed_buffers) { | |
141 assert(worker_i >= 0, "worker index must be > 0"); | |
142 assert(worker_i < _active_gc_threads, "worker index out of bounds"); | |
143 _par_last_update_rs_processed_buffers[worker_i] = processed_buffers; | |
144 } | 181 } |
145 | 182 |
146 void record_scan_rs_time(uint worker_i, double ms) { | 183 void record_scan_rs_time(uint worker_i, double ms) { |
147 assert(worker_i >= 0, "worker index must be > 0"); | 184 _last_scan_rs_times_ms.set(worker_i, ms); |
148 assert(worker_i < _active_gc_threads, "worker index out of bounds"); | |
149 _par_last_scan_rs_times_ms[worker_i] = ms; | |
150 } | |
151 | |
152 void reset_obj_copy_time(uint worker_i) { | |
153 assert(worker_i >= 0, "worker index must be > 0"); | |
154 assert(worker_i < _active_gc_threads, "worker index out of bounds"); | |
155 _par_last_obj_copy_times_ms[worker_i] = 0.0; | |
156 } | |
157 | |
158 void reset_obj_copy_time() { | |
159 reset_obj_copy_time(0); | |
160 } | 185 } |
161 | 186 |
162 void record_obj_copy_time(uint worker_i, double ms) { | 187 void record_obj_copy_time(uint worker_i, double ms) { |
163 assert(worker_i >= 0, "worker index must be > 0"); | 188 _last_obj_copy_times_ms.set(worker_i, ms); |
164 assert(worker_i < _active_gc_threads, "worker index out of bounds"); | 189 } |
165 _par_last_obj_copy_times_ms[worker_i] += ms; | 190 |
191 void add_obj_copy_time(uint worker_i, double ms) { | |
192 _last_obj_copy_times_ms.add(worker_i, ms); | |
166 } | 193 } |
167 | 194 |
168 void record_termination(uint worker_i, double ms, size_t attempts) { | 195 void record_termination(uint worker_i, double ms, size_t attempts) { |
169 assert(worker_i >= 0, "worker index must be > 0"); | 196 _last_termination_times_ms.set(worker_i, ms); |
170 assert(worker_i < _active_gc_threads, "worker index out of bounds"); | 197 _last_termination_attempts.set(worker_i, attempts); |
171 _par_last_termination_times_ms[worker_i] = ms; | |
172 _par_last_termination_attempts[worker_i] = (double) attempts; | |
173 } | 198 } |
174 | 199 |
175 void record_gc_worker_end_time(uint worker_i, double ms) { | 200 void record_gc_worker_end_time(uint worker_i, double ms) { |
176 assert(worker_i >= 0, "worker index must be > 0"); | 201 _last_gc_worker_end_times_ms.set(worker_i, ms); |
177 assert(worker_i < _active_gc_threads, "worker index out of bounds"); | |
178 _par_last_gc_worker_end_times_ms[worker_i] = ms; | |
179 } | 202 } |
180 | 203 |
181 void record_clear_ct_time(double ms) { | 204 void record_clear_ct_time(double ms) { |
182 _cur_clear_ct_time_ms = ms; | 205 _cur_clear_ct_time_ms = ms; |
183 } | 206 } |
209 } | 232 } |
210 | 233 |
211 void record_non_young_free_cset_time_ms(double time_ms) { | 234 void record_non_young_free_cset_time_ms(double time_ms) { |
212 _recorded_non_young_free_cset_time_ms = time_ms; | 235 _recorded_non_young_free_cset_time_ms = time_ms; |
213 } | 236 } |
237 | |
238 void record_young_cset_choice_time_ms(double time_ms) { | |
239 _recorded_young_cset_choice_time_ms = time_ms; | |
240 } | |
241 | |
242 void record_non_young_cset_choice_time_ms(double time_ms) { | |
243 _recorded_non_young_cset_choice_time_ms = time_ms; | |
244 } | |
245 | |
246 void record_cur_collection_start_sec(double time_ms) { | |
247 _cur_collection_start_sec = time_ms; | |
248 } | |
249 | |
250 void record_verify_before_time_ms(double time_ms) { | |
251 _cur_verify_before_time_ms = time_ms; | |
252 } | |
253 | |
254 void record_verify_after_time_ms(double time_ms) { | |
255 _cur_verify_after_time_ms = time_ms; | |
256 } | |
257 | |
258 double accounted_time_ms(); | |
259 | |
260 double cur_collection_start_sec() { | |
261 return _cur_collection_start_sec; | |
262 } | |
263 | |
264 double cur_collection_par_time_ms() { | |
265 return _cur_collection_par_time_ms; | |
266 } | |
267 | |
268 double cur_clear_ct_time_ms() { | |
269 return _cur_clear_ct_time_ms; | |
270 } | |
271 | |
272 double root_region_scan_wait_time_ms() { | |
273 return _root_region_scan_wait_time_ms; | |
274 } | |
275 | |
276 double young_cset_choice_time_ms() { | |
277 return _recorded_young_cset_choice_time_ms; | |
278 } | |
279 | |
280 double young_free_cset_time_ms() { | |
281 return _recorded_young_free_cset_time_ms; | |
282 } | |
283 | |
284 double non_young_cset_choice_time_ms() { | |
285 return _recorded_non_young_cset_choice_time_ms; | |
286 } | |
287 | |
288 double non_young_free_cset_time_ms() { | |
289 return _recorded_non_young_free_cset_time_ms; | |
290 } | |
291 | |
292 double average_last_update_rs_time() { | |
293 return _last_update_rs_times_ms.average(); | |
294 } | |
295 | |
296 int sum_last_update_rs_processed_buffers() { | |
297 return _last_update_rs_processed_buffers.sum(); | |
298 } | |
299 | |
300 double average_last_scan_rs_time(){ | |
301 return _last_scan_rs_times_ms.average(); | |
302 } | |
303 | |
304 double average_last_obj_copy_time() { | |
305 return _last_obj_copy_times_ms.average(); | |
306 } | |
307 | |
308 double average_last_termination_time() { | |
309 return _last_termination_times_ms.average(); | |
310 } | |
311 | |
312 double average_last_ext_root_scan_time() { | |
313 return _last_ext_root_scan_times_ms.average(); | |
314 } | |
315 | |
316 double average_last_satb_filtering_times_ms() { | |
317 return _last_satb_filtering_times_ms.average(); | |
318 } | |
214 }; | 319 }; |
215 | 320 |
216 #endif // SHARE_VM_GC_IMPLEMENTATION_G1_G1GCPHASETIMESLOG_HPP | 321 #endif // SHARE_VM_GC_IMPLEMENTATION_G1_G1GCPHASETIMESLOG_HPP |