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