Mercurial > hg > graal-jvmci-8
comparison src/share/vm/gc_implementation/g1/g1GCPhaseTimes.hpp @ 22908:c3fcc09c9239
8074037: Refactor the G1GCPhaseTime logging to make it easier to add new phases
Reviewed-by: tschatzl, mgerdin, ecaspole
author | brutisso |
---|---|
date | Thu, 26 Mar 2015 13:19:32 +0100 |
parents | 7baf47cb97cb |
children | 3ca53859c3c7 |
comparison
equal
deleted
inserted
replaced
22907:93a69595b807 | 22908:c3fcc09c9239 |
---|---|
24 | 24 |
25 #ifndef SHARE_VM_GC_IMPLEMENTATION_G1_G1GCPHASETIMESLOG_HPP | 25 #ifndef SHARE_VM_GC_IMPLEMENTATION_G1_G1GCPHASETIMESLOG_HPP |
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 |
30 | 30 class LineBuffer; |
31 template <class T> | 31 |
32 class WorkerDataArray : public CHeapObj<mtGC> { | 32 template <class T> class WorkerDataArray; |
33 T* _data; | |
34 uint _length; | |
35 const char* _print_format; | |
36 bool _print_sum; | |
37 | |
38 NOT_PRODUCT(static const T _uninitialized;) | |
39 | |
40 // We are caching the sum and average to only have to calculate them once. | |
41 // This is not done in an MT-safe way. It is intended to allow single | |
42 // threaded code to call sum() and average() multiple times in any order | |
43 // without having to worry about the cost. | |
44 bool _has_new_data; | |
45 T _sum; | |
46 double _average; | |
47 | |
48 public: | |
49 WorkerDataArray(uint length, const char* print_format, bool print_sum = true) : | |
50 _length(length), _print_format(print_format), _print_sum(print_sum), _has_new_data(true) { | |
51 assert(length > 0, "Must have some workers to store data for"); | |
52 _data = NEW_C_HEAP_ARRAY(T, _length, mtGC); | |
53 } | |
54 | |
55 ~WorkerDataArray() { | |
56 FREE_C_HEAP_ARRAY(T, _data, mtGC); | |
57 } | |
58 | |
59 void set(uint worker_i, T value) { | |
60 assert(worker_i < _length, err_msg("Worker %d is greater than max: %d", worker_i, _length)); | |
61 assert(_data[worker_i] == (T)-1, err_msg("Overwriting data for worker %d", worker_i)); | |
62 _data[worker_i] = value; | |
63 _has_new_data = true; | |
64 } | |
65 | |
66 T get(uint worker_i) { | |
67 assert(worker_i < _length, err_msg("Worker %d is greater than max: %d", worker_i, _length)); | |
68 assert(_data[worker_i] != (T)-1, err_msg("No data to add to for worker %d", worker_i)); | |
69 return _data[worker_i]; | |
70 } | |
71 | |
72 void add(uint worker_i, T value) { | |
73 assert(worker_i < _length, err_msg("Worker %d is greater than max: %d", worker_i, _length)); | |
74 assert(_data[worker_i] != (T)-1, err_msg("No data to add to for worker %d", worker_i)); | |
75 _data[worker_i] += value; | |
76 _has_new_data = true; | |
77 } | |
78 | |
79 double average(){ | |
80 if (_has_new_data) { | |
81 calculate_totals(); | |
82 } | |
83 return _average; | |
84 } | |
85 | |
86 T sum() { | |
87 if (_has_new_data) { | |
88 calculate_totals(); | |
89 } | |
90 return _sum; | |
91 } | |
92 | |
93 void print(int level, const char* title); | |
94 | |
95 void reset() PRODUCT_RETURN; | |
96 void verify() PRODUCT_RETURN; | |
97 | |
98 private: | |
99 | |
100 void calculate_totals(){ | |
101 _sum = (T)0; | |
102 for (uint i = 0; i < _length; ++i) { | |
103 _sum += _data[i]; | |
104 } | |
105 _average = (double)_sum / (double)_length; | |
106 _has_new_data = false; | |
107 } | |
108 }; | |
109 | 33 |
110 class G1GCPhaseTimes : public CHeapObj<mtGC> { | 34 class G1GCPhaseTimes : public CHeapObj<mtGC> { |
111 | 35 friend class G1GCParPhasePrinter; |
112 private: | 36 |
113 uint _active_gc_threads; | 37 uint _active_gc_threads; |
114 uint _max_gc_threads; | 38 uint _max_gc_threads; |
115 | 39 |
116 WorkerDataArray<double> _last_gc_worker_start_times_ms; | 40 public: |
117 WorkerDataArray<double> _last_ext_root_scan_times_ms; | 41 enum GCParPhases { |
118 WorkerDataArray<double> _last_satb_filtering_times_ms; | 42 GCWorkerStart, |
119 WorkerDataArray<double> _last_update_rs_times_ms; | 43 ExtRootScan, |
120 WorkerDataArray<int> _last_update_rs_processed_buffers; | 44 SATBFiltering, |
121 WorkerDataArray<double> _last_scan_rs_times_ms; | 45 UpdateRS, |
122 WorkerDataArray<double> _last_strong_code_root_scan_times_ms; | 46 ScanRS, |
123 WorkerDataArray<double> _last_obj_copy_times_ms; | 47 CodeRoots, |
124 WorkerDataArray<double> _last_termination_times_ms; | 48 ObjCopy, |
125 WorkerDataArray<size_t> _last_termination_attempts; | 49 Termination, |
126 WorkerDataArray<double> _last_gc_worker_end_times_ms; | 50 Other, |
127 WorkerDataArray<double> _last_gc_worker_times_ms; | 51 GCWorkerTotal, |
128 WorkerDataArray<double> _last_gc_worker_other_times_ms; | 52 GCWorkerEnd, |
53 StringDedupQueueFixup, | |
54 StringDedupTableFixup, | |
55 RedirtyCards, | |
56 GCParPhasesSentinel | |
57 }; | |
58 | |
59 private: | |
60 // Markers for grouping the phases in the GCPhases enum above | |
61 static const int GCMainParPhasesLast = GCWorkerEnd; | |
62 static const int StringDedupPhasesFirst = StringDedupQueueFixup; | |
63 static const int StringDedupPhasesLast = StringDedupTableFixup; | |
64 | |
65 WorkerDataArray<double>* _gc_par_phases[GCParPhasesSentinel]; | |
66 WorkerDataArray<size_t>* _update_rs_processed_buffers; | |
67 WorkerDataArray<size_t>* _termination_attempts; | |
68 WorkerDataArray<size_t>* _redirtied_cards; | |
129 | 69 |
130 double _cur_collection_par_time_ms; | 70 double _cur_collection_par_time_ms; |
131 double _cur_collection_code_root_fixup_time_ms; | 71 double _cur_collection_code_root_fixup_time_ms; |
132 double _cur_strong_code_root_purge_time_ms; | 72 double _cur_strong_code_root_purge_time_ms; |
133 | 73 |
134 double _cur_evac_fail_recalc_used; | 74 double _cur_evac_fail_recalc_used; |
135 double _cur_evac_fail_restore_remsets; | 75 double _cur_evac_fail_restore_remsets; |
136 double _cur_evac_fail_remove_self_forwards; | 76 double _cur_evac_fail_remove_self_forwards; |
137 | 77 |
138 double _cur_string_dedup_fixup_time_ms; | 78 double _cur_string_dedup_fixup_time_ms; |
139 WorkerDataArray<double> _cur_string_dedup_queue_fixup_worker_times_ms; | |
140 WorkerDataArray<double> _cur_string_dedup_table_fixup_worker_times_ms; | |
141 | 79 |
142 double _cur_clear_ct_time_ms; | 80 double _cur_clear_ct_time_ms; |
143 double _cur_ref_proc_time_ms; | 81 double _cur_ref_proc_time_ms; |
144 double _cur_ref_enq_time_ms; | 82 double _cur_ref_enq_time_ms; |
145 | 83 |
147 double _root_region_scan_wait_time_ms; | 85 double _root_region_scan_wait_time_ms; |
148 | 86 |
149 double _recorded_young_cset_choice_time_ms; | 87 double _recorded_young_cset_choice_time_ms; |
150 double _recorded_non_young_cset_choice_time_ms; | 88 double _recorded_non_young_cset_choice_time_ms; |
151 | 89 |
152 WorkerDataArray<double> _last_redirty_logged_cards_time_ms; | |
153 WorkerDataArray<size_t> _last_redirty_logged_cards_processed_cards; | |
154 double _recorded_redirty_logged_cards_time_ms; | 90 double _recorded_redirty_logged_cards_time_ms; |
155 | 91 |
156 double _recorded_young_free_cset_time_ms; | 92 double _recorded_young_free_cset_time_ms; |
157 double _recorded_non_young_free_cset_time_ms; | 93 double _recorded_non_young_free_cset_time_ms; |
158 | 94 |
169 void print_stats(int level, const char* str, size_t value); | 105 void print_stats(int level, const char* str, size_t value); |
170 void print_stats(int level, const char* str, double value, uint workers); | 106 void print_stats(int level, const char* str, double value, uint workers); |
171 | 107 |
172 public: | 108 public: |
173 G1GCPhaseTimes(uint max_gc_threads); | 109 G1GCPhaseTimes(uint max_gc_threads); |
174 void note_gc_start(uint active_gc_threads); | 110 void note_gc_start(uint active_gc_threads, bool mark_in_progress); |
175 void note_gc_end(); | 111 void note_gc_end(); |
176 void print(double pause_time_sec); | 112 void print(double pause_time_sec); |
177 | 113 |
178 void record_gc_worker_start_time(uint worker_i, double ms) { | 114 // record the time a phase took in seconds |
179 _last_gc_worker_start_times_ms.set(worker_i, ms); | 115 void record_time_secs(GCParPhases phase, uint worker_i, double secs); |
180 } | 116 |
181 | 117 // add a number of seconds to a phase |
182 void record_ext_root_scan_time(uint worker_i, double ms) { | 118 void add_time_secs(GCParPhases phase, uint worker_i, double secs); |
183 _last_ext_root_scan_times_ms.set(worker_i, ms); | 119 |
184 } | 120 void record_thread_work_item(GCParPhases phase, uint worker_i, size_t count); |
185 | 121 |
186 void record_satb_filtering_time(uint worker_i, double ms) { | 122 // return the average time for a phase in milliseconds |
187 _last_satb_filtering_times_ms.set(worker_i, ms); | 123 double average_time_ms(GCParPhases phase); |
188 } | 124 |
189 | 125 size_t sum_thread_work_items(GCParPhases phase); |
190 void record_update_rs_time(uint worker_i, double ms) { | 126 |
191 _last_update_rs_times_ms.set(worker_i, ms); | 127 private: |
192 } | 128 double get_time_ms(GCParPhases phase, uint worker_i); |
193 | 129 double sum_time_ms(GCParPhases phase); |
194 void record_update_rs_processed_buffers(uint worker_i, int processed_buffers) { | 130 double min_time_ms(GCParPhases phase); |
195 _last_update_rs_processed_buffers.set(worker_i, processed_buffers); | 131 double max_time_ms(GCParPhases phase); |
196 } | 132 size_t get_thread_work_item(GCParPhases phase, uint worker_i); |
197 | 133 double average_thread_work_items(GCParPhases phase); |
198 void record_scan_rs_time(uint worker_i, double ms) { | 134 size_t min_thread_work_items(GCParPhases phase); |
199 _last_scan_rs_times_ms.set(worker_i, ms); | 135 size_t max_thread_work_items(GCParPhases phase); |
200 } | 136 |
201 | 137 public: |
202 void record_strong_code_root_scan_time(uint worker_i, double ms) { | |
203 _last_strong_code_root_scan_times_ms.set(worker_i, ms); | |
204 } | |
205 | |
206 void record_obj_copy_time(uint worker_i, double ms) { | |
207 _last_obj_copy_times_ms.set(worker_i, ms); | |
208 } | |
209 | |
210 void add_obj_copy_time(uint worker_i, double ms) { | |
211 _last_obj_copy_times_ms.add(worker_i, ms); | |
212 } | |
213 | |
214 void record_termination(uint worker_i, double ms, size_t attempts) { | |
215 _last_termination_times_ms.set(worker_i, ms); | |
216 _last_termination_attempts.set(worker_i, attempts); | |
217 } | |
218 | |
219 void record_gc_worker_end_time(uint worker_i, double ms) { | |
220 _last_gc_worker_end_times_ms.set(worker_i, ms); | |
221 } | |
222 | 138 |
223 void record_clear_ct_time(double ms) { | 139 void record_clear_ct_time(double ms) { |
224 _cur_clear_ct_time_ms = ms; | 140 _cur_clear_ct_time_ms = ms; |
225 } | 141 } |
226 | 142 |
246 | 162 |
247 void record_evac_fail_remove_self_forwards(double ms) { | 163 void record_evac_fail_remove_self_forwards(double ms) { |
248 _cur_evac_fail_remove_self_forwards = ms; | 164 _cur_evac_fail_remove_self_forwards = ms; |
249 } | 165 } |
250 | 166 |
251 void note_string_dedup_fixup_start(); | |
252 void note_string_dedup_fixup_end(); | |
253 | |
254 void record_string_dedup_fixup_time(double ms) { | 167 void record_string_dedup_fixup_time(double ms) { |
255 _cur_string_dedup_fixup_time_ms = ms; | 168 _cur_string_dedup_fixup_time_ms = ms; |
256 } | |
257 | |
258 void record_string_dedup_queue_fixup_worker_time(uint worker_id, double ms) { | |
259 _cur_string_dedup_queue_fixup_worker_times_ms.set(worker_id, ms); | |
260 } | |
261 | |
262 void record_string_dedup_table_fixup_worker_time(uint worker_id, double ms) { | |
263 _cur_string_dedup_table_fixup_worker_times_ms.set(worker_id, ms); | |
264 } | 169 } |
265 | 170 |
266 void record_ref_proc_time(double ms) { | 171 void record_ref_proc_time(double ms) { |
267 _cur_ref_proc_time_ms = ms; | 172 _cur_ref_proc_time_ms = ms; |
268 } | 173 } |
299 | 204 |
300 void record_non_young_cset_choice_time_ms(double time_ms) { | 205 void record_non_young_cset_choice_time_ms(double time_ms) { |
301 _recorded_non_young_cset_choice_time_ms = time_ms; | 206 _recorded_non_young_cset_choice_time_ms = time_ms; |
302 } | 207 } |
303 | 208 |
304 void record_redirty_logged_cards_time_ms(uint worker_i, double time_ms) { | |
305 _last_redirty_logged_cards_time_ms.set(worker_i, time_ms); | |
306 } | |
307 | |
308 void record_redirty_logged_cards_processed_cards(uint worker_i, size_t processed_buffers) { | |
309 _last_redirty_logged_cards_processed_cards.set(worker_i, processed_buffers); | |
310 } | |
311 | |
312 void record_redirty_logged_cards_time_ms(double time_ms) { | 209 void record_redirty_logged_cards_time_ms(double time_ms) { |
313 _recorded_redirty_logged_cards_time_ms = time_ms; | 210 _recorded_redirty_logged_cards_time_ms = time_ms; |
314 } | 211 } |
315 | 212 |
316 void record_cur_collection_start_sec(double time_ms) { | 213 void record_cur_collection_start_sec(double time_ms) { |
360 } | 257 } |
361 | 258 |
362 double fast_reclaim_humongous_time_ms() { | 259 double fast_reclaim_humongous_time_ms() { |
363 return _cur_fast_reclaim_humongous_time_ms; | 260 return _cur_fast_reclaim_humongous_time_ms; |
364 } | 261 } |
365 | |
366 double average_last_update_rs_time() { | |
367 return _last_update_rs_times_ms.average(); | |
368 } | |
369 | |
370 int sum_last_update_rs_processed_buffers() { | |
371 return _last_update_rs_processed_buffers.sum(); | |
372 } | |
373 | |
374 double average_last_scan_rs_time(){ | |
375 return _last_scan_rs_times_ms.average(); | |
376 } | |
377 | |
378 double average_last_strong_code_root_scan_time(){ | |
379 return _last_strong_code_root_scan_times_ms.average(); | |
380 } | |
381 | |
382 double average_last_obj_copy_time() { | |
383 return _last_obj_copy_times_ms.average(); | |
384 } | |
385 | |
386 double average_last_termination_time() { | |
387 return _last_termination_times_ms.average(); | |
388 } | |
389 | |
390 double average_last_ext_root_scan_time() { | |
391 return _last_ext_root_scan_times_ms.average(); | |
392 } | |
393 | |
394 double average_last_satb_filtering_times_ms() { | |
395 return _last_satb_filtering_times_ms.average(); | |
396 } | |
397 }; | 262 }; |
398 | 263 |
264 class G1GCParPhaseTimesTracker : public StackObj { | |
265 double _start_time; | |
266 G1GCPhaseTimes::GCParPhases _phase; | |
267 G1GCPhaseTimes* _phase_times; | |
268 uint _worker_id; | |
269 public: | |
270 G1GCParPhaseTimesTracker(G1GCPhaseTimes* phase_times, G1GCPhaseTimes::GCParPhases phase, uint worker_id); | |
271 ~G1GCParPhaseTimesTracker(); | |
272 }; | |
273 | |
399 #endif // SHARE_VM_GC_IMPLEMENTATION_G1_G1GCPHASETIMESLOG_HPP | 274 #endif // SHARE_VM_GC_IMPLEMENTATION_G1_G1GCPHASETIMESLOG_HPP |