1 /*
2 * Copyright (c) 2013, 2019, Oracle and/or its affiliates. All rights reserved.
3 * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
4 *
5 * This code is free software; you can redistribute it and/or modify it
6 * under the terms of the GNU General Public License version 2 only, as
7 * published by the Free Software Foundation.
8 *
9 * This code is distributed in the hope that it will be useful, but WITHOUT
10 * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or
11 * FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License
12 * version 2 for more details (a copy is included in the LICENSE file that
13 * accompanied this code).
14 *
15 * You should have received a copy of the GNU General Public License version
16 * 2 along with this work; if not, write to the Free Software Foundation,
17 * Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA.
18 *
19 * Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA
20 * or visit www.oracle.com if you need additional information or have any
21 * questions.
22 *
23 */
24
25 #ifndef SHARE_GC_G1_G1GCPHASETIMES_HPP
26 #define SHARE_GC_G1_G1GCPHASETIMES_HPP
27
28 #include "gc/shared/referenceProcessorPhaseTimes.hpp"
29 #include "gc/shared/weakProcessorPhaseTimes.hpp"
30 #include "jfr/jfrEvents.hpp"
31 #include "logging/logLevel.hpp"
32 #include "memory/allocation.hpp"
33 #include "utilities/macros.hpp"
34
35 class LineBuffer;
36 class G1ParScanThreadState;
37 class STWGCTimer;
38
39 template <class T> class WorkerDataArray;
40
41 class G1GCPhaseTimes : public CHeapObj<mtGC> {
42 uint _max_gc_threads;
43 jlong _gc_start_counter;
44 double _gc_pause_time_ms;
45
46 public:
47 enum GCParPhases {
48 GCWorkerStart,
49 ExtRootScan,
50 ThreadRoots,
51 UniverseRoots,
52 JNIRoots,
53 ObjectSynchronizerRoots,
54 ManagementRoots,
55 SystemDictionaryRoots,
56 CLDGRoots,
57 JVMTIRoots,
58 AOT_ONLY(AOTCodeRoots COMMA)
59 CMRefRoots,
60 MergeER,
61 MergeRS,
62 OptMergeRS,
63 MergeLB,
64 MergeHCC,
65 ScanHR,
66 OptScanHR,
67 CodeRoots,
68 OptCodeRoots,
69 ObjCopy,
70 OptObjCopy,
71 Termination,
72 OptTermination,
73 Other,
74 GCWorkerTotal,
75 GCWorkerEnd,
76 StringDedupQueueFixup,
77 StringDedupTableFixup,
78 RedirtyCards,
79 ParFreeCSet,
80 YoungFreeCSet,
81 NonYoungFreeCSet,
82 RebuildFreeList,
83 MergePSS,
84 GCParPhasesSentinel
85 };
86
87 static const GCParPhases ExtRootScanSubPhasesFirst = ThreadRoots;
88 static const GCParPhases ExtRootScanSubPhasesLast = CMRefRoots;
89
90 enum GCMergeRSWorkTimes {
91 MergeRSMergedSparse,
92 MergeRSMergedFine,
93 MergeRSMergedCoarse,
94 MergeRSDirtyCards
95 };
96
97 enum GCScanHRWorkItems {
98 ScanHRScannedCards,
99 ScanHRScannedBlocks,
100 ScanHRClaimedChunks,
101 ScanHRScannedOptRefs,
102 ScanHRUsedMemory
103 };
104
105 enum GCMergeHCCWorkItems {
106 MergeHCCDirtyCards,
107 MergeHCCSkippedCards
108 };
109
110 enum GCMergeLBWorkItems {
111 MergeLBDirtyCards,
112 MergeLBSkippedCards
113 };
114
115 enum GCMergePSSWorkItems {
116 MergePSSCopiedBytes,
117 MergePSSLABWasteBytes,
118 MergePSSLABUndoWasteBytes
119 };
120
121 private:
122 // Markers for grouping the phases in the GCPhases enum above
123 static const int GCMainParPhasesLast = GCWorkerEnd;
124
125 WorkerDataArray<double>* _gc_par_phases[GCParPhasesSentinel];
126
127 double _cur_collection_initial_evac_time_ms;
128 double _cur_optional_evac_time_ms;
129 double _cur_collection_code_root_fixup_time_ms;
130 double _cur_strong_code_root_purge_time_ms;
131
132 double _cur_evac_fail_recalc_used;
133 double _cur_evac_fail_remove_self_forwards;
134
135 double _cur_string_deduplication_time_ms;
136
137 double _cur_merge_heap_roots_time_ms;
138 double _cur_optional_merge_heap_roots_time_ms;
139
140 double _cur_prepare_merge_heap_roots_time_ms;
141 double _cur_optional_prepare_merge_heap_roots_time_ms;
142
143 double _cur_prepare_tlab_time_ms;
144 double _cur_resize_tlab_time_ms;
145
146 double _cur_derived_pointer_table_update_time_ms;
147
148 double _cur_clear_ct_time_ms;
149 double _cur_expand_heap_time_ms;
150 double _cur_ref_proc_time_ms;
151 double _cur_adjust_heap_time_ms;
152
153 double _cur_collection_start_sec;
154 double _root_region_scan_wait_time_ms;
155
156 double _external_accounted_time_ms;
157
158 double _recorded_prepare_heap_roots_time_ms;
159
160 double _recorded_clear_claimed_marks_time_ms;
161
162 double _recorded_young_cset_choice_time_ms;
163 double _recorded_non_young_cset_choice_time_ms;
164
165 double _recorded_redirty_logged_cards_time_ms;
166
167 double _recorded_preserve_cm_referents_time_ms;
168
169 double _recorded_merge_pss_time_ms;
170
171 double _recorded_start_new_cset_time_ms;
172
173 double _recorded_total_free_cset_time_ms;
174
175 double _recorded_serial_free_cset_time_ms;
176
177 double _recorded_total_rebuild_freelist_time_ms;
178
179 double _recorded_serial_rebuild_freelist_time_ms;
180
181 double _cur_region_register_time;
182
183 double _cur_fast_reclaim_humongous_time_ms;
184 size_t _cur_fast_reclaim_humongous_total;
185 size_t _cur_fast_reclaim_humongous_candidates;
186 size_t _cur_fast_reclaim_humongous_reclaimed;
187
188 double _cur_verify_before_time_ms;
189 double _cur_verify_after_time_ms;
190
191 ReferenceProcessorPhaseTimes _ref_phase_times;
192 WeakProcessorPhaseTimes _weak_phase_times;
193
194 double worker_time(GCParPhases phase, uint worker);
195 void note_gc_end();
196 void reset();
197
198 template <class T>
199 void details(T* phase, const char* indent_str) const;
200
201 void log_work_items(WorkerDataArray<double>* phase, uint indent, outputStream* out) const;
202 void log_phase(WorkerDataArray<double>* phase, uint indent_level, outputStream* out, bool print_sum) const;
203 void debug_serial_phase(WorkerDataArray<double>* phase, uint extra_indent = 0) const;
204 void debug_phase(WorkerDataArray<double>* phase, uint extra_indent = 0) const;
205 void trace_phase(WorkerDataArray<double>* phase, bool print_sum = true, uint extra_indent = 0) const;
206
207 void info_time(const char* name, double value) const;
208 void debug_time(const char* name, double value) const;
209 // This will print logs for both 'gc+phases' and 'gc+phases+ref'.
210 void debug_time_for_reference(const char* name, double value) const;
211 void trace_time(const char* name, double value) const;
212 void trace_count(const char* name, size_t value) const;
213
214 double print_pre_evacuate_collection_set() const;
215 double print_merge_heap_roots_time() const;
216 double print_evacuate_initial_collection_set() const;
217 double print_evacuate_optional_collection_set() const;
218 double print_post_evacuate_collection_set() const;
219 void print_other(double accounted_ms) const;
220
221 public:
222 G1GCPhaseTimes(STWGCTimer* gc_timer, uint max_gc_threads);
223 void note_gc_start();
224 void print();
225 static const char* phase_name(GCParPhases phase);
226
227 // record the time a phase took in seconds
228 void record_time_secs(GCParPhases phase, uint worker_id, double secs);
229
230 // add a number of seconds to a phase
231 void add_time_secs(GCParPhases phase, uint worker_id, double secs);
232
233 void record_or_add_time_secs(GCParPhases phase, uint worker_id, double secs);
234
235 double get_time_secs(GCParPhases phase, uint worker_id);
236
237 void record_thread_work_item(GCParPhases phase, uint worker_id, size_t count, uint index = 0);
238
239 void record_or_add_thread_work_item(GCParPhases phase, uint worker_id, size_t count, uint index = 0);
240
241 size_t get_thread_work_item(GCParPhases phase, uint worker_id, uint index = 0);
242
243 // return the average time for a phase in milliseconds
244 double average_time_ms(GCParPhases phase);
245
246 size_t sum_thread_work_items(GCParPhases phase, uint index = 0);
247
248 void record_prepare_tlab_time_ms(double ms) {
249 _cur_prepare_tlab_time_ms = ms;
250 }
251
252 void record_resize_tlab_time_ms(double ms) {
253 _cur_resize_tlab_time_ms = ms;
254 }
255
256 void record_derived_pointer_table_update_time(double ms) {
257 _cur_derived_pointer_table_update_time_ms = ms;
258 }
259
260 void record_clear_ct_time(double ms) {
261 _cur_clear_ct_time_ms = ms;
262 }
263
264 void record_expand_heap_time(double ms) {
265 _cur_expand_heap_time_ms = ms;
266 }
267
268 void record_or_add_adjust_heap_time(double ms) {
269 _cur_adjust_heap_time_ms += ms;
270 }
271
272 void record_initial_evac_time(double ms) {
273 _cur_collection_initial_evac_time_ms = ms;
274 }
275
276 void record_or_add_optional_evac_time(double ms) {
277 _cur_optional_evac_time_ms += ms;
278 }
279
280 void record_or_add_code_root_fixup_time(double ms) {
281 _cur_collection_code_root_fixup_time_ms += ms;
282 }
283
284 void record_strong_code_root_purge_time(double ms) {
285 _cur_strong_code_root_purge_time_ms = ms;
286 }
287
288 void record_merge_heap_roots_time(double ms) {
289 _cur_merge_heap_roots_time_ms += ms;
290 }
291
292 void record_or_add_optional_merge_heap_roots_time(double ms) {
293 _cur_optional_merge_heap_roots_time_ms += ms;
294 }
295
296 void record_prepare_merge_heap_roots_time(double ms) {
297 _cur_prepare_merge_heap_roots_time_ms += ms;
298 }
299
300 void record_or_add_optional_prepare_merge_heap_roots_time(double ms) {
301 _cur_optional_prepare_merge_heap_roots_time_ms += ms;
302 }
303
304 void record_evac_fail_recalc_used_time(double ms) {
305 _cur_evac_fail_recalc_used = ms;
306 }
307
308 void record_evac_fail_remove_self_forwards(double ms) {
309 _cur_evac_fail_remove_self_forwards = ms;
310 }
311
312 void record_string_deduplication_time(double ms) {
313 _cur_string_deduplication_time_ms = ms;
314 }
315
316 void record_ref_proc_time(double ms) {
317 _cur_ref_proc_time_ms = ms;
318 }
319
320 void record_root_region_scan_wait_time(double time_ms) {
321 _root_region_scan_wait_time_ms = time_ms;
322 }
323
324 void record_total_free_cset_time_ms(double time_ms) {
325 _recorded_total_free_cset_time_ms = time_ms;
326 }
327
328 void record_serial_free_cset_time_ms(double time_ms) {
329 _recorded_serial_free_cset_time_ms = time_ms;
330 }
331
332 void record_total_rebuild_freelist_time_ms(double time_ms) {
333 _recorded_total_rebuild_freelist_time_ms = time_ms;
334 }
335
336 void record_serial_rebuild_freelist_time_ms(double time_ms) {
337 _recorded_serial_rebuild_freelist_time_ms = time_ms;
338 }
339
340 void record_register_regions(double time_ms, size_t total, size_t candidates) {
341 _cur_region_register_time = time_ms;
342 _cur_fast_reclaim_humongous_total = total;
343 _cur_fast_reclaim_humongous_candidates = candidates;
344 }
345
346 void record_fast_reclaim_humongous_time_ms(double value, size_t reclaimed) {
347 _cur_fast_reclaim_humongous_time_ms = value;
348 _cur_fast_reclaim_humongous_reclaimed = reclaimed;
349 }
350
351 void record_young_cset_choice_time_ms(double time_ms) {
352 _recorded_young_cset_choice_time_ms = time_ms;
353 }
354
355 void record_non_young_cset_choice_time_ms(double time_ms) {
356 _recorded_non_young_cset_choice_time_ms = time_ms;
357 }
358
359 void record_redirty_logged_cards_time_ms(double time_ms) {
360 _recorded_redirty_logged_cards_time_ms = time_ms;
361 }
362
363 void record_preserve_cm_referents_time_ms(double time_ms) {
364 _recorded_preserve_cm_referents_time_ms = time_ms;
365 }
366
367 void record_start_new_cset_time_ms(double time_ms) {
368 _recorded_start_new_cset_time_ms = time_ms;
369 }
370
371 void record_cur_collection_start_sec(double time_ms) {
372 _cur_collection_start_sec = time_ms;
373 }
374
375 void record_verify_before_time_ms(double time_ms) {
376 _cur_verify_before_time_ms = time_ms;
377 }
378
379 void record_verify_after_time_ms(double time_ms) {
380 _cur_verify_after_time_ms = time_ms;
381 }
382
383 void inc_external_accounted_time_ms(double time_ms) {
384 _external_accounted_time_ms += time_ms;
385 }
386
387 void record_prepare_heap_roots_time_ms(double recorded_prepare_heap_roots_time_ms) {
388 _recorded_prepare_heap_roots_time_ms = recorded_prepare_heap_roots_time_ms;
389 }
390
391 void record_clear_claimed_marks_time_ms(double recorded_clear_claimed_marks_time_ms) {
392 _recorded_clear_claimed_marks_time_ms = recorded_clear_claimed_marks_time_ms;
393 }
394
395 double cur_collection_start_sec() {
396 return _cur_collection_start_sec;
397 }
398
399 double cur_collection_par_time_ms() {
400 return _cur_collection_initial_evac_time_ms + _cur_optional_evac_time_ms;
401 }
402
403 double cur_clear_ct_time_ms() {
404 return _cur_clear_ct_time_ms;
405 }
406
407 double cur_expand_heap_time_ms() {
408 return _cur_expand_heap_time_ms;
409 }
410
411 double cur_adjust_heap_time_ms() {
412 return _cur_adjust_heap_time_ms;
413 }
414
415 double root_region_scan_wait_time_ms() {
416 return _root_region_scan_wait_time_ms;
417 }
418
419 double young_cset_choice_time_ms() {
420 return _recorded_young_cset_choice_time_ms;
421 }
422
423 double total_free_cset_time_ms() {
424 return _recorded_total_free_cset_time_ms;
425 }
426
427 double total_rebuild_freelist_time_ms() {
428 return _recorded_total_rebuild_freelist_time_ms;
429 }
430
431 double non_young_cset_choice_time_ms() {
432 return _recorded_non_young_cset_choice_time_ms;
433 }
434
435 double fast_reclaim_humongous_time_ms() {
436 return _cur_fast_reclaim_humongous_time_ms;
437 }
438
439 size_t fast_reclaim_humongous_candidates() const {
440 return _cur_fast_reclaim_humongous_candidates;
441 }
442
443 ReferenceProcessorPhaseTimes* ref_phase_times() { return &_ref_phase_times; }
444
445 WeakProcessorPhaseTimes* weak_phase_times() { return &_weak_phase_times; }
446 };
447
448 class G1EvacPhaseWithTrimTimeTracker : public StackObj {
449 G1ParScanThreadState* _pss;
450 Ticks _start;
451
452 Tickspan& _total_time;
453 Tickspan& _trim_time;
454
455 bool _stopped;
456 public:
457 G1EvacPhaseWithTrimTimeTracker(G1ParScanThreadState* pss, Tickspan& total_time, Tickspan& trim_time);
458 ~G1EvacPhaseWithTrimTimeTracker();
459
460 void stop();
461 };
462
463 class G1GCParPhaseTimesTracker : public CHeapObj<mtGC> {
464 protected:
465 Ticks _start_time;
466 G1GCPhaseTimes::GCParPhases _phase;
467 G1GCPhaseTimes* _phase_times;
468 uint _worker_id;
469 EventGCPhaseParallel _event;
470 bool _must_record;
471
472 public:
473 G1GCParPhaseTimesTracker(G1GCPhaseTimes* phase_times, G1GCPhaseTimes::GCParPhases phase, uint worker_id, bool must_record = true);
474 virtual ~G1GCParPhaseTimesTracker();
475 };
476
477 class G1EvacPhaseTimesTracker : public G1GCParPhaseTimesTracker {
478 Tickspan _total_time;
479 Tickspan _trim_time;
480
481 G1EvacPhaseWithTrimTimeTracker _trim_tracker;
482 public:
483 G1EvacPhaseTimesTracker(G1GCPhaseTimes* phase_times, G1ParScanThreadState* pss, G1GCPhaseTimes::GCParPhases phase, uint worker_id);
484 virtual ~G1EvacPhaseTimesTracker();
485 };
486
487 #endif // SHARE_GC_G1_G1GCPHASETIMES_HPP