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     YoungFreeCSet,
  80     NonYoungFreeCSet,
  81     MergePSS,
  82     GCParPhasesSentinel
  83   };
  84 
  85   static const GCParPhases ExtRootScanSubPhasesFirst = ThreadRoots;
  86   static const GCParPhases ExtRootScanSubPhasesLast = CMRefRoots;
  87 
  88   enum GCMergeRSWorkTimes {
  89     MergeRSMergedSparse,
  90     MergeRSMergedFine,
  91     MergeRSMergedCoarse,
  92     MergeRSDirtyCards
  93   };
  94 
  95   enum GCScanHRWorkItems {
  96     ScanHRScannedCards,
  97     ScanHRScannedBlocks,
  98     ScanHRClaimedChunks,
  99     ScanHRScannedOptRefs,
 100     ScanHRUsedMemory
 101   };
 102 
 103   enum GCMergeHCCWorkItems {
 104     MergeHCCDirtyCards,
 105     MergeHCCSkippedCards
 106   };
 107 
 108   enum GCMergeLBWorkItems {
 109     MergeLBDirtyCards,
 110     MergeLBSkippedCards
 111   };
 112 
 113   enum GCMergePSSWorkItems {
 114     MergePSSCopiedBytes,
 115     MergePSSLABWasteBytes,
 116     MergePSSLABUndoWasteBytes
 117   };
 118 
 119  private:
 120   // Markers for grouping the phases in the GCPhases enum above
 121   static const int GCMainParPhasesLast = GCWorkerEnd;
 122 
 123   WorkerDataArray<double>* _gc_par_phases[GCParPhasesSentinel];
 124 
 125   WorkerDataArray<size_t>* _merge_rs_merged_sparse;
 126   WorkerDataArray<size_t>* _merge_rs_merged_fine;
 127   WorkerDataArray<size_t>* _merge_rs_merged_coarse;
 128   WorkerDataArray<size_t>* _merge_rs_dirty_cards;
 129 
 130   WorkerDataArray<size_t>* _merge_hcc_dirty_cards;
 131   WorkerDataArray<size_t>* _merge_hcc_skipped_cards;
 132 
 133   WorkerDataArray<size_t>* _merge_lb_dirty_cards;
 134   WorkerDataArray<size_t>* _merge_lb_skipped_cards;
 135 
 136   WorkerDataArray<size_t>* _scan_hr_scanned_cards;
 137   WorkerDataArray<size_t>* _scan_hr_scanned_blocks;
 138   WorkerDataArray<size_t>* _scan_hr_claimed_chunks;
 139 
 140   WorkerDataArray<size_t>* _opt_merge_rs_merged_sparse;
 141   WorkerDataArray<size_t>* _opt_merge_rs_merged_fine;
 142   WorkerDataArray<size_t>* _opt_merge_rs_merged_coarse;
 143   WorkerDataArray<size_t>* _opt_merge_rs_dirty_cards;
 144 
 145   WorkerDataArray<size_t>* _opt_scan_hr_scanned_cards;
 146   WorkerDataArray<size_t>* _opt_scan_hr_scanned_blocks;
 147   WorkerDataArray<size_t>* _opt_scan_hr_claimed_chunks;
 148   WorkerDataArray<size_t>* _opt_scan_hr_scanned_opt_refs;
 149   WorkerDataArray<size_t>* _opt_scan_hr_used_memory;
 150 
 151   WorkerDataArray<size_t>* _merge_pss_copied_bytes;
 152   WorkerDataArray<size_t>* _merge_pss_lab_waste_bytes;
 153   WorkerDataArray<size_t>* _merge_pss_lab_undo_waste_bytes;
 154 
 155   WorkerDataArray<size_t>* _termination_attempts;
 156 
 157   WorkerDataArray<size_t>* _opt_termination_attempts;
 158 
 159   WorkerDataArray<size_t>* _redirtied_cards;
 160 
 161   double _cur_collection_initial_evac_time_ms;
 162   double _cur_optional_evac_time_ms;
 163   double _cur_collection_code_root_fixup_time_ms;
 164   double _cur_strong_code_root_purge_time_ms;
 165 
 166   double _cur_evac_fail_recalc_used;
 167   double _cur_evac_fail_remove_self_forwards;
 168 
 169   double _cur_string_deduplication_time_ms;
 170 
 171   double _cur_merge_heap_roots_time_ms;
 172   double _cur_optional_merge_heap_roots_time_ms;
 173 
 174   double _cur_prepare_merge_heap_roots_time_ms;
 175   double _cur_optional_prepare_merge_heap_roots_time_ms;
 176 
 177   double _cur_prepare_tlab_time_ms;
 178   double _cur_resize_tlab_time_ms;
 179 
 180   double _cur_derived_pointer_table_update_time_ms;
 181 
 182   double _cur_clear_ct_time_ms;
 183   double _cur_expand_heap_time_ms;
 184   double _cur_ref_proc_time_ms;
 185 
 186   double _cur_collection_start_sec;
 187   double _root_region_scan_wait_time_ms;
 188 
 189   double _external_accounted_time_ms;
 190 
 191   double _recorded_prepare_heap_roots_time_ms;
 192 
 193   double _recorded_clear_claimed_marks_time_ms;
 194 
 195   double _recorded_young_cset_choice_time_ms;
 196   double _recorded_non_young_cset_choice_time_ms;
 197 
 198   double _recorded_redirty_logged_cards_time_ms;
 199 
 200   double _recorded_preserve_cm_referents_time_ms;
 201 
 202   double _recorded_merge_pss_time_ms;
 203 
 204   double _recorded_start_new_cset_time_ms;
 205 
 206   double _recorded_total_free_cset_time_ms;
 207 
 208   double _recorded_serial_free_cset_time_ms;
 209 
 210   double _cur_region_register_time;
 211 
 212   double _cur_fast_reclaim_humongous_time_ms;
 213   size_t _cur_fast_reclaim_humongous_total;
 214   size_t _cur_fast_reclaim_humongous_candidates;
 215   size_t _cur_fast_reclaim_humongous_reclaimed;
 216 
 217   double _cur_verify_before_time_ms;
 218   double _cur_verify_after_time_ms;
 219 
 220   ReferenceProcessorPhaseTimes _ref_phase_times;
 221   WeakProcessorPhaseTimes _weak_phase_times;
 222 
 223   double worker_time(GCParPhases phase, uint worker);
 224   void note_gc_end();
 225   void reset();
 226 
 227   template <class T>
 228   void details(T* phase, const char* indent) const;
 229 
 230   void log_work_items(WorkerDataArray<double>* phase, uint indent, outputStream* out) const;
 231   void log_phase(WorkerDataArray<double>* phase, uint indent, outputStream* out, bool print_sum) const;
 232   void debug_serial_phase(WorkerDataArray<double>* phase, uint extra_indent = 0) const;
 233   void debug_phase(WorkerDataArray<double>* phase, uint extra_indent = 0) const;
 234   void trace_phase(WorkerDataArray<double>* phase, bool print_sum = true) const;
 235 
 236   void info_time(const char* name, double value) const;
 237   void debug_time(const char* name, double value) const;
 238   // This will print logs for both 'gc+phases' and 'gc+phases+ref'.
 239   void debug_time_for_reference(const char* name, double value) const;
 240   void trace_time(const char* name, double value) const;
 241   void trace_count(const char* name, size_t value) const;
 242 
 243   double print_pre_evacuate_collection_set() const;
 244   double print_merge_heap_roots_time() const;
 245   double print_evacuate_initial_collection_set() const;
 246   double print_evacuate_optional_collection_set() const;
 247   double print_post_evacuate_collection_set() const;
 248   void print_other(double accounted_ms) const;
 249 
 250  public:
 251   G1GCPhaseTimes(STWGCTimer* gc_timer, uint max_gc_threads);
 252   void note_gc_start();
 253   void print();
 254   static const char* phase_name(GCParPhases phase);
 255 
 256   // record the time a phase took in seconds
 257   void record_time_secs(GCParPhases phase, uint worker_id, double secs);
 258 
 259   // add a number of seconds to a phase
 260   void add_time_secs(GCParPhases phase, uint worker_id, double secs);
 261 
 262   void record_or_add_time_secs(GCParPhases phase, uint worker_id, double secs);
 263 
 264   double get_time_secs(GCParPhases phase, uint worker_id);
 265 
 266   void record_thread_work_item(GCParPhases phase, uint worker_id, size_t count, uint index = 0);
 267 
 268   void record_or_add_thread_work_item(GCParPhases phase, uint worker_id, size_t count, uint index = 0);
 269 
 270   size_t get_thread_work_item(GCParPhases phase, uint worker_id, uint index = 0);
 271 
 272   // return the average time for a phase in milliseconds
 273   double average_time_ms(GCParPhases phase);
 274 
 275   size_t sum_thread_work_items(GCParPhases phase, uint index = 0);
 276 
 277   void record_prepare_tlab_time_ms(double ms) {
 278     _cur_prepare_tlab_time_ms = ms;
 279   }
 280 
 281   void record_resize_tlab_time_ms(double ms) {
 282     _cur_resize_tlab_time_ms = ms;
 283   }
 284 
 285   void record_derived_pointer_table_update_time(double ms) {
 286     _cur_derived_pointer_table_update_time_ms = ms;
 287   }
 288 
 289   void record_clear_ct_time(double ms) {
 290     _cur_clear_ct_time_ms = ms;
 291   }
 292 
 293   void record_expand_heap_time(double ms) {
 294     _cur_expand_heap_time_ms = ms;
 295   }
 296 
 297   void record_initial_evac_time(double ms) {
 298     _cur_collection_initial_evac_time_ms = ms;
 299   }
 300 
 301   void record_or_add_optional_evac_time(double ms) {
 302     _cur_optional_evac_time_ms += ms;
 303   }
 304 
 305   void record_or_add_code_root_fixup_time(double ms) {
 306     _cur_collection_code_root_fixup_time_ms += ms;
 307   }
 308 
 309   void record_strong_code_root_purge_time(double ms) {
 310     _cur_strong_code_root_purge_time_ms = ms;
 311   }
 312 
 313   void record_merge_heap_roots_time(double ms) {
 314     _cur_merge_heap_roots_time_ms += ms;
 315   }
 316 
 317   void record_or_add_optional_merge_heap_roots_time(double ms) {
 318     _cur_optional_merge_heap_roots_time_ms += ms;
 319   }
 320 
 321   void record_prepare_merge_heap_roots_time(double ms) {
 322     _cur_prepare_merge_heap_roots_time_ms += ms;
 323   }
 324 
 325   void record_or_add_optional_prepare_merge_heap_roots_time(double ms) {
 326     _cur_optional_prepare_merge_heap_roots_time_ms += ms;
 327   }
 328 
 329   void record_evac_fail_recalc_used_time(double ms) {
 330     _cur_evac_fail_recalc_used = ms;
 331   }
 332 
 333   void record_evac_fail_remove_self_forwards(double ms) {
 334     _cur_evac_fail_remove_self_forwards = ms;
 335   }
 336 
 337   void record_string_deduplication_time(double ms) {
 338     _cur_string_deduplication_time_ms = ms;
 339   }
 340 
 341   void record_ref_proc_time(double ms) {
 342     _cur_ref_proc_time_ms = ms;
 343   }
 344 
 345   void record_root_region_scan_wait_time(double time_ms) {
 346     _root_region_scan_wait_time_ms = time_ms;
 347   }
 348 
 349   void record_total_free_cset_time_ms(double time_ms) {
 350     _recorded_total_free_cset_time_ms = time_ms;
 351   }
 352 
 353   void record_serial_free_cset_time_ms(double time_ms) {
 354     _recorded_serial_free_cset_time_ms = time_ms;
 355   }
 356 
 357   void record_register_regions(double time_ms, size_t total, size_t candidates) {
 358     _cur_region_register_time = time_ms;
 359     _cur_fast_reclaim_humongous_total = total;
 360     _cur_fast_reclaim_humongous_candidates = candidates;
 361   }
 362 
 363   void record_fast_reclaim_humongous_time_ms(double value, size_t reclaimed) {
 364     _cur_fast_reclaim_humongous_time_ms = value;
 365     _cur_fast_reclaim_humongous_reclaimed = reclaimed;
 366   }
 367 
 368   void record_young_cset_choice_time_ms(double time_ms) {
 369     _recorded_young_cset_choice_time_ms = time_ms;
 370   }
 371 
 372   void record_non_young_cset_choice_time_ms(double time_ms) {
 373     _recorded_non_young_cset_choice_time_ms = time_ms;
 374   }
 375 
 376   void record_redirty_logged_cards_time_ms(double time_ms) {
 377     _recorded_redirty_logged_cards_time_ms = time_ms;
 378   }
 379 
 380   void record_preserve_cm_referents_time_ms(double time_ms) {
 381     _recorded_preserve_cm_referents_time_ms = time_ms;
 382   }
 383 
 384   void record_start_new_cset_time_ms(double time_ms) {
 385     _recorded_start_new_cset_time_ms = time_ms;
 386   }
 387 
 388   void record_cur_collection_start_sec(double time_ms) {
 389     _cur_collection_start_sec = time_ms;
 390   }
 391 
 392   void record_verify_before_time_ms(double time_ms) {
 393     _cur_verify_before_time_ms = time_ms;
 394   }
 395 
 396   void record_verify_after_time_ms(double time_ms) {
 397     _cur_verify_after_time_ms = time_ms;
 398   }
 399 
 400   void inc_external_accounted_time_ms(double time_ms) {
 401     _external_accounted_time_ms += time_ms;
 402   }
 403 
 404   void record_prepare_heap_roots_time_ms(double recorded_prepare_heap_roots_time_ms) {
 405     _recorded_prepare_heap_roots_time_ms = recorded_prepare_heap_roots_time_ms;
 406   }
 407 
 408   void record_clear_claimed_marks_time_ms(double recorded_clear_claimed_marks_time_ms) {
 409     _recorded_clear_claimed_marks_time_ms = recorded_clear_claimed_marks_time_ms;
 410   }
 411 
 412   double cur_collection_start_sec() {
 413     return _cur_collection_start_sec;
 414   }
 415 
 416   double cur_collection_par_time_ms() {
 417     return _cur_collection_initial_evac_time_ms + _cur_optional_evac_time_ms;
 418   }
 419 
 420   double cur_clear_ct_time_ms() {
 421     return _cur_clear_ct_time_ms;
 422   }
 423 
 424   double cur_expand_heap_time_ms() {
 425     return _cur_expand_heap_time_ms;
 426   }
 427 
 428   double root_region_scan_wait_time_ms() {
 429     return _root_region_scan_wait_time_ms;
 430   }
 431 
 432   double young_cset_choice_time_ms() {
 433     return _recorded_young_cset_choice_time_ms;
 434   }
 435 
 436   double total_free_cset_time_ms() {
 437     return _recorded_total_free_cset_time_ms;
 438   }
 439 
 440   double non_young_cset_choice_time_ms() {
 441     return _recorded_non_young_cset_choice_time_ms;
 442   }
 443 
 444   double fast_reclaim_humongous_time_ms() {
 445     return _cur_fast_reclaim_humongous_time_ms;
 446   }
 447 
 448   size_t fast_reclaim_humongous_candidates() const {
 449     return _cur_fast_reclaim_humongous_candidates;
 450   }
 451 
 452   ReferenceProcessorPhaseTimes* ref_phase_times() { return &_ref_phase_times; }
 453 
 454   WeakProcessorPhaseTimes* weak_phase_times() { return &_weak_phase_times; }
 455 };
 456 
 457 class G1EvacPhaseWithTrimTimeTracker : public StackObj {
 458   G1ParScanThreadState* _pss;
 459   Ticks _start;
 460 
 461   Tickspan& _total_time;
 462   Tickspan& _trim_time;
 463 
 464   bool _stopped;
 465 public:
 466   G1EvacPhaseWithTrimTimeTracker(G1ParScanThreadState* pss, Tickspan& total_time, Tickspan& trim_time);
 467   ~G1EvacPhaseWithTrimTimeTracker();
 468 
 469   void stop();
 470 };
 471 
 472 class G1GCParPhaseTimesTracker : public CHeapObj<mtGC> {
 473 protected:
 474   Ticks _start_time;
 475   G1GCPhaseTimes::GCParPhases _phase;
 476   G1GCPhaseTimes* _phase_times;
 477   uint _worker_id;
 478   EventGCPhaseParallel _event;
 479   bool _must_record;
 480 
 481 public:
 482   G1GCParPhaseTimesTracker(G1GCPhaseTimes* phase_times, G1GCPhaseTimes::GCParPhases phase, uint worker_id, bool must_record = true);
 483   virtual ~G1GCParPhaseTimesTracker();
 484 };
 485 
 486 class G1EvacPhaseTimesTracker : public G1GCParPhaseTimesTracker {
 487   Tickspan _total_time;
 488   Tickspan _trim_time;
 489 
 490   G1EvacPhaseWithTrimTimeTracker _trim_tracker;
 491 public:
 492   G1EvacPhaseTimesTracker(G1GCPhaseTimes* phase_times, G1ParScanThreadState* pss, G1GCPhaseTimes::GCParPhases phase, uint worker_id);
 493   virtual ~G1EvacPhaseTimesTracker();
 494 };
 495 
 496 #endif // SHARE_GC_G1_G1GCPHASETIMES_HPP