1 /*
  2  * Copyright (c) 2013, 2018, 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_VM_GC_G1_G1GCPHASETIMES_HPP
 26 #define SHARE_VM_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     StringTableRoots,
 52     UniverseRoots,
 53     JNIRoots,
 54     ObjectSynchronizerRoots,
 55     ManagementRoots,
 56     SystemDictionaryRoots,
 57     CLDGRoots,
 58     JVMTIRoots,
 59     CMRefRoots,
 60     WaitForStrongCLD,
 61     WeakCLDRoots,
 62     SATBFiltering,
 63     UpdateRS,
 64     ScanHCC,
 65     ScanRS,
 66     CodeRoots,
 67 #if INCLUDE_AOT
 68     AOTCodeRoots,
 69 #endif
 70     ObjCopy,
 71     Termination,
 72     Other,
 73     GCWorkerTotal,
 74     GCWorkerEnd,
 75     StringDedupQueueFixup,
 76     StringDedupTableFixup,
 77     RedirtyCards,
 78     YoungFreeCSet,
 79     NonYoungFreeCSet,
 80     GCParPhasesSentinel
 81   };
 82 
 83   enum GCScanRSWorkItems {
 84     ScanRSScannedCards,
 85     ScanRSClaimedCards,
 86     ScanRSSkippedCards
 87   };
 88 
 89   enum GCUpdateRSWorkItems {
 90     UpdateRSProcessedBuffers,
 91     UpdateRSScannedCards,
 92     UpdateRSSkippedCards
 93   };
 94 
 95  private:
 96   // Markers for grouping the phases in the GCPhases enum above
 97   static const int GCMainParPhasesLast = GCWorkerEnd;
 98   static const int StringDedupPhasesFirst = StringDedupQueueFixup;
 99   static const int StringDedupPhasesLast = StringDedupTableFixup;
100 
101   WorkerDataArray<double>* _gc_par_phases[GCParPhasesSentinel];
102 
103   WorkerDataArray<size_t>* _update_rs_processed_buffers;
104   WorkerDataArray<size_t>* _update_rs_scanned_cards;
105   WorkerDataArray<size_t>* _update_rs_skipped_cards;
106 
107   WorkerDataArray<size_t>* _scan_rs_scanned_cards;
108   WorkerDataArray<size_t>* _scan_rs_claimed_cards;
109   WorkerDataArray<size_t>* _scan_rs_skipped_cards;
110 
111   WorkerDataArray<size_t>* _termination_attempts;
112 
113   WorkerDataArray<size_t>* _redirtied_cards;
114 
115   double _cur_collection_par_time_ms;
116   double _cur_collection_code_root_fixup_time_ms;
117   double _cur_strong_code_root_purge_time_ms;
118 
119   double _cur_evac_fail_recalc_used;
120   double _cur_evac_fail_remove_self_forwards;
121 
122   double _cur_string_dedup_fixup_time_ms;
123 
124   double _cur_prepare_tlab_time_ms;
125   double _cur_resize_tlab_time_ms;
126 
127   double _cur_derived_pointer_table_update_time_ms;
128 
129   double _cur_clear_ct_time_ms;
130   double _cur_expand_heap_time_ms;
131   double _cur_ref_proc_time_ms;
132 
133   double _cur_collection_start_sec;
134   double _root_region_scan_wait_time_ms;
135 
136   double _external_accounted_time_ms;
137 
138   double _recorded_clear_claimed_marks_time_ms;
139 
140   double _recorded_young_cset_choice_time_ms;
141   double _recorded_non_young_cset_choice_time_ms;
142 
143   double _recorded_redirty_logged_cards_time_ms;
144 
145   double _recorded_preserve_cm_referents_time_ms;
146 
147   double _recorded_merge_pss_time_ms;
148 
149   double _recorded_start_new_cset_time_ms;
150 
151   double _recorded_total_free_cset_time_ms;
152 
153   double _recorded_serial_free_cset_time_ms;
154 
155   double _cur_fast_reclaim_humongous_time_ms;
156   double _cur_fast_reclaim_humongous_register_time_ms;
157   size_t _cur_fast_reclaim_humongous_total;
158   size_t _cur_fast_reclaim_humongous_candidates;
159   size_t _cur_fast_reclaim_humongous_reclaimed;
160 
161   double _cur_verify_before_time_ms;
162   double _cur_verify_after_time_ms;
163 
164   ReferenceProcessorPhaseTimes _ref_phase_times;
165   WeakProcessorPhaseTimes _weak_phase_times;
166 
167   double worker_time(GCParPhases phase, uint worker);
168   void note_gc_end();
169   void reset();
170 
171   template <class T>
172   void details(T* phase, const char* indent) const;
173 
174   void log_phase(WorkerDataArray<double>* phase, uint indent, outputStream* out, bool print_sum) const;
175   void debug_phase(WorkerDataArray<double>* phase) const;
176   void trace_phase(WorkerDataArray<double>* phase, bool print_sum = true) const;
177 
178   void info_time(const char* name, double value) const;
179   void debug_time(const char* name, double value) const;
180   // This will print logs for both 'gc+phases' and 'gc+phases+ref'.
181   void debug_time_for_reference(const char* name, double value) const;
182   void trace_time(const char* name, double value) const;
183   void trace_count(const char* name, size_t value) const;
184 
185   double print_pre_evacuate_collection_set() const;
186   double print_evacuate_collection_set() const;
187   double print_post_evacuate_collection_set() const;
188   void print_other(double accounted_ms) const;
189 
190  public:
191   G1GCPhaseTimes(STWGCTimer* gc_timer, uint max_gc_threads);
192   void note_gc_start();
193   void print();
194   static const char* phase_name(GCParPhases phase);
195 
196   // record the time a phase took in seconds
197   void record_time_secs(GCParPhases phase, uint worker_i, double secs);
198 
199   // add a number of seconds to a phase
200   void add_time_secs(GCParPhases phase, uint worker_i, double secs);
201 
202   void record_or_add_objcopy_time_secs(uint worker_i, double secs);
203 
204   void record_thread_work_item(GCParPhases phase, uint worker_i, size_t count, uint index = 0);
205 
206   // return the average time for a phase in milliseconds
207   double average_time_ms(GCParPhases phase);
208 
209   size_t sum_thread_work_items(GCParPhases phase, uint index = 0);
210 
211  public:
212 
213   void record_prepare_tlab_time_ms(double ms) {
214     _cur_prepare_tlab_time_ms = ms;
215   }
216 
217   void record_resize_tlab_time_ms(double ms) {
218     _cur_resize_tlab_time_ms = ms;
219   }
220 
221   void record_derived_pointer_table_update_time(double ms) {
222     _cur_derived_pointer_table_update_time_ms = ms;
223   }
224 
225   void record_clear_ct_time(double ms) {
226     _cur_clear_ct_time_ms = ms;
227   }
228 
229   void record_expand_heap_time(double ms) {
230     _cur_expand_heap_time_ms = ms;
231   }
232 
233   void record_par_time(double ms) {
234     _cur_collection_par_time_ms = ms;
235   }
236 
237   void record_code_root_fixup_time(double ms) {
238     _cur_collection_code_root_fixup_time_ms = ms;
239   }
240 
241   void record_strong_code_root_purge_time(double ms) {
242     _cur_strong_code_root_purge_time_ms = ms;
243   }
244 
245   void record_evac_fail_recalc_used_time(double ms) {
246     _cur_evac_fail_recalc_used = ms;
247   }
248 
249   void record_evac_fail_remove_self_forwards(double ms) {
250     _cur_evac_fail_remove_self_forwards = ms;
251   }
252 
253   void record_string_dedup_fixup_time(double ms) {
254     _cur_string_dedup_fixup_time_ms = ms;
255   }
256 
257   void record_ref_proc_time(double ms) {
258     _cur_ref_proc_time_ms = ms;
259   }
260 
261   void record_root_region_scan_wait_time(double time_ms) {
262     _root_region_scan_wait_time_ms = time_ms;
263   }
264 
265   void record_total_free_cset_time_ms(double time_ms) {
266     _recorded_total_free_cset_time_ms = time_ms;
267   }
268 
269   void record_serial_free_cset_time_ms(double time_ms) {
270     _recorded_serial_free_cset_time_ms = time_ms;
271   }
272 
273   void record_fast_reclaim_humongous_stats(double time_ms, size_t total, size_t candidates) {
274     _cur_fast_reclaim_humongous_register_time_ms = time_ms;
275     _cur_fast_reclaim_humongous_total = total;
276     _cur_fast_reclaim_humongous_candidates = candidates;
277   }
278 
279   void record_fast_reclaim_humongous_time_ms(double value, size_t reclaimed) {
280     _cur_fast_reclaim_humongous_time_ms = value;
281     _cur_fast_reclaim_humongous_reclaimed = reclaimed;
282   }
283 
284   void record_young_cset_choice_time_ms(double time_ms) {
285     _recorded_young_cset_choice_time_ms = time_ms;
286   }
287 
288   void record_non_young_cset_choice_time_ms(double time_ms) {
289     _recorded_non_young_cset_choice_time_ms = time_ms;
290   }
291 
292   void record_redirty_logged_cards_time_ms(double time_ms) {
293     _recorded_redirty_logged_cards_time_ms = time_ms;
294   }
295 
296   void record_preserve_cm_referents_time_ms(double time_ms) {
297     _recorded_preserve_cm_referents_time_ms = time_ms;
298   }
299 
300   void record_merge_pss_time_ms(double time_ms) {
301     _recorded_merge_pss_time_ms = time_ms;
302   }
303 
304   void record_start_new_cset_time_ms(double time_ms) {
305     _recorded_start_new_cset_time_ms = time_ms;
306   }
307 
308   void record_cur_collection_start_sec(double time_ms) {
309     _cur_collection_start_sec = time_ms;
310   }
311 
312   void record_verify_before_time_ms(double time_ms) {
313     _cur_verify_before_time_ms = time_ms;
314   }
315 
316   void record_verify_after_time_ms(double time_ms) {
317     _cur_verify_after_time_ms = time_ms;
318   }
319 
320   void inc_external_accounted_time_ms(double time_ms) {
321     _external_accounted_time_ms += time_ms;
322   }
323 
324   void record_clear_claimed_marks_time_ms(double recorded_clear_claimed_marks_time_ms) {
325     _recorded_clear_claimed_marks_time_ms = recorded_clear_claimed_marks_time_ms;
326   }
327 
328   double cur_collection_start_sec() {
329     return _cur_collection_start_sec;
330   }
331 
332   double cur_collection_par_time_ms() {
333     return _cur_collection_par_time_ms;
334   }
335 
336   double cur_clear_ct_time_ms() {
337     return _cur_clear_ct_time_ms;
338   }
339 
340   double cur_expand_heap_time_ms() {
341     return _cur_expand_heap_time_ms;
342   }
343 
344   double root_region_scan_wait_time_ms() {
345     return _root_region_scan_wait_time_ms;
346   }
347 
348   double young_cset_choice_time_ms() {
349     return _recorded_young_cset_choice_time_ms;
350   }
351 
352   double total_free_cset_time_ms() {
353     return _recorded_total_free_cset_time_ms;
354   }
355 
356   double non_young_cset_choice_time_ms() {
357     return _recorded_non_young_cset_choice_time_ms;
358   }
359 
360   double fast_reclaim_humongous_time_ms() {
361     return _cur_fast_reclaim_humongous_time_ms;
362   }
363 
364   ReferenceProcessorPhaseTimes* ref_phase_times() { return &_ref_phase_times; }
365 
366   WeakProcessorPhaseTimes* weak_phase_times() { return &_weak_phase_times; }
367 };
368 
369 class G1EvacPhaseWithTrimTimeTracker : public StackObj {
370   G1ParScanThreadState* _pss;
371   Ticks _start;
372 
373   Tickspan& _total_time;
374   Tickspan& _trim_time;
375 
376   bool _stopped;
377 public:
378   G1EvacPhaseWithTrimTimeTracker(G1ParScanThreadState* pss, Tickspan& total_time, Tickspan& trim_time);
379   ~G1EvacPhaseWithTrimTimeTracker();
380 
381   void stop();
382 };
383 
384 class G1GCParPhaseTimesTracker : public CHeapObj<mtGC> {
385 protected:
386   Ticks _start_time;
387   G1GCPhaseTimes::GCParPhases _phase;
388   G1GCPhaseTimes* _phase_times;
389   uint _worker_id;
390   EventGCPhaseParallel _event;
391 public:
392   G1GCParPhaseTimesTracker(G1GCPhaseTimes* phase_times, G1GCPhaseTimes::GCParPhases phase, uint worker_id);
393   virtual ~G1GCParPhaseTimesTracker();
394 };
395 
396 class G1EvacPhaseTimesTracker : public G1GCParPhaseTimesTracker {
397   Tickspan _total_time;
398   Tickspan _trim_time;
399 
400   G1EvacPhaseWithTrimTimeTracker _trim_tracker;
401 public:
402   G1EvacPhaseTimesTracker(G1GCPhaseTimes* phase_times, G1ParScanThreadState* pss, G1GCPhaseTimes::GCParPhases phase, uint worker_id);
403   virtual ~G1EvacPhaseTimesTracker();
404 };
405 
406 #endif // SHARE_VM_GC_G1_G1GCPHASETIMES_HPP