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