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   double _cur_collection_initial_evac_time_ms;
 126   double _cur_optional_evac_time_ms;
 127   double _cur_collection_code_root_fixup_time_ms;
 128   double _cur_strong_code_root_purge_time_ms;
 129 
 130   double _cur_evac_fail_recalc_used;
 131   double _cur_evac_fail_remove_self_forwards;
 132 
 133   double _cur_string_deduplication_time_ms;
 134 
 135   double _cur_merge_heap_roots_time_ms;
 136   double _cur_optional_merge_heap_roots_time_ms;
 137 
 138   double _cur_prepare_merge_heap_roots_time_ms;
 139   double _cur_optional_prepare_merge_heap_roots_time_ms;
 140 
 141   double _cur_prepare_tlab_time_ms;
 142   double _cur_resize_tlab_time_ms;
 143 
 144   double _cur_derived_pointer_table_update_time_ms;
 145 
 146   double _cur_clear_ct_time_ms;
 147   double _cur_expand_heap_time_ms;
 148   double _cur_ref_proc_time_ms;
 149 
 150   double _cur_collection_start_sec;
 151   double _root_region_scan_wait_time_ms;
 152 
 153   double _external_accounted_time_ms;
 154 
 155   double _recorded_prepare_heap_roots_time_ms;
 156 
 157   double _recorded_clear_claimed_marks_time_ms;
 158 
 159   double _recorded_young_cset_choice_time_ms;
 160   double _recorded_non_young_cset_choice_time_ms;
 161 
 162   double _recorded_redirty_logged_cards_time_ms;
 163 
 164   double _recorded_preserve_cm_referents_time_ms;
 165 
 166   double _recorded_merge_pss_time_ms;
 167 
 168   double _recorded_start_new_cset_time_ms;
 169 
 170   double _recorded_total_free_cset_time_ms;
 171 
 172   double _recorded_serial_free_cset_time_ms;
 173 
 174   double _cur_region_register_time;
 175 
 176   double _cur_fast_reclaim_humongous_time_ms;
 177   size_t _cur_fast_reclaim_humongous_total;
 178   size_t _cur_fast_reclaim_humongous_candidates;
 179   size_t _cur_fast_reclaim_humongous_reclaimed;
 180 
 181   double _cur_verify_before_time_ms;
 182   double _cur_verify_after_time_ms;
 183 
 184   ReferenceProcessorPhaseTimes _ref_phase_times;
 185   WeakProcessorPhaseTimes _weak_phase_times;
 186 
 187   double worker_time(GCParPhases phase, uint worker);
 188   void note_gc_end();
 189   void reset();
 190 
 191   template <class T>
 192   void details(T* phase, const char* indent) const;
 193 
 194   void log_work_items(WorkerDataArray<double>* phase, uint indent, outputStream* out) const;
 195   void log_phase(WorkerDataArray<double>* phase, uint indent, outputStream* out, bool print_sum) const;
 196   void debug_serial_phase(WorkerDataArray<double>* phase, uint extra_indent = 0) const;
 197   void debug_phase(WorkerDataArray<double>* phase, uint extra_indent = 0) const;
 198   void trace_phase(WorkerDataArray<double>* phase, bool print_sum = true) const;
 199 
 200   void info_time(const char* name, double value) const;
 201   void debug_time(const char* name, double value) const;
 202   // This will print logs for both 'gc+phases' and 'gc+phases+ref'.
 203   void debug_time_for_reference(const char* name, double value) const;
 204   void trace_time(const char* name, double value) const;
 205   void trace_count(const char* name, size_t value) const;
 206 
 207   double print_pre_evacuate_collection_set() const;
 208   double print_merge_heap_roots_time() const;
 209   double print_evacuate_initial_collection_set() const;
 210   double print_evacuate_optional_collection_set() const;
 211   double print_post_evacuate_collection_set() const;
 212   void print_other(double accounted_ms) const;
 213 
 214  public:
 215   G1GCPhaseTimes(STWGCTimer* gc_timer, uint max_gc_threads);
 216   void note_gc_start();
 217   void print();
 218   static const char* phase_name(GCParPhases phase);
 219 
 220   // record the time a phase took in seconds
 221   void record_time_secs(GCParPhases phase, uint worker_id, double secs);
 222 
 223   // add a number of seconds to a phase
 224   void add_time_secs(GCParPhases phase, uint worker_id, double secs);
 225 
 226   void record_or_add_time_secs(GCParPhases phase, uint worker_id, double secs);
 227 
 228   double get_time_secs(GCParPhases phase, uint worker_id);
 229 
 230   void record_thread_work_item(GCParPhases phase, uint worker_id, size_t count, uint index = 0);
 231 
 232   void record_or_add_thread_work_item(GCParPhases phase, uint worker_id, size_t count, uint index = 0);
 233 
 234   size_t get_thread_work_item(GCParPhases phase, uint worker_id, uint index = 0);
 235 
 236   // return the average time for a phase in milliseconds
 237   double average_time_ms(GCParPhases phase);
 238 
 239   size_t sum_thread_work_items(GCParPhases phase, uint index = 0);
 240 
 241   void record_prepare_tlab_time_ms(double ms) {
 242     _cur_prepare_tlab_time_ms = ms;
 243   }
 244 
 245   void record_resize_tlab_time_ms(double ms) {
 246     _cur_resize_tlab_time_ms = ms;
 247   }
 248 
 249   void record_derived_pointer_table_update_time(double ms) {
 250     _cur_derived_pointer_table_update_time_ms = ms;
 251   }
 252 
 253   void record_clear_ct_time(double ms) {
 254     _cur_clear_ct_time_ms = ms;
 255   }
 256 
 257   void record_expand_heap_time(double ms) {
 258     _cur_expand_heap_time_ms = ms;
 259   }
 260 
 261   void record_initial_evac_time(double ms) {
 262     _cur_collection_initial_evac_time_ms = ms;
 263   }
 264 
 265   void record_or_add_optional_evac_time(double ms) {
 266     _cur_optional_evac_time_ms += ms;
 267   }
 268 
 269   void record_or_add_code_root_fixup_time(double ms) {
 270     _cur_collection_code_root_fixup_time_ms += ms;
 271   }
 272 
 273   void record_strong_code_root_purge_time(double ms) {
 274     _cur_strong_code_root_purge_time_ms = ms;
 275   }
 276 
 277   void record_merge_heap_roots_time(double ms) {
 278     _cur_merge_heap_roots_time_ms += ms;
 279   }
 280 
 281   void record_or_add_optional_merge_heap_roots_time(double ms) {
 282     _cur_optional_merge_heap_roots_time_ms += ms;
 283   }
 284 
 285   void record_prepare_merge_heap_roots_time(double ms) {
 286     _cur_prepare_merge_heap_roots_time_ms += ms;
 287   }
 288 
 289   void record_or_add_optional_prepare_merge_heap_roots_time(double ms) {
 290     _cur_optional_prepare_merge_heap_roots_time_ms += ms;
 291   }
 292 
 293   void record_evac_fail_recalc_used_time(double ms) {
 294     _cur_evac_fail_recalc_used = ms;
 295   }
 296 
 297   void record_evac_fail_remove_self_forwards(double ms) {
 298     _cur_evac_fail_remove_self_forwards = ms;
 299   }
 300 
 301   void record_string_deduplication_time(double ms) {
 302     _cur_string_deduplication_time_ms = ms;
 303   }
 304 
 305   void record_ref_proc_time(double ms) {
 306     _cur_ref_proc_time_ms = ms;
 307   }
 308 
 309   void record_root_region_scan_wait_time(double time_ms) {
 310     _root_region_scan_wait_time_ms = time_ms;
 311   }
 312 
 313   void record_total_free_cset_time_ms(double time_ms) {
 314     _recorded_total_free_cset_time_ms = time_ms;
 315   }
 316 
 317   void record_serial_free_cset_time_ms(double time_ms) {
 318     _recorded_serial_free_cset_time_ms = time_ms;
 319   }
 320 
 321   void record_register_regions(double time_ms, size_t total, size_t candidates) {
 322     _cur_region_register_time = time_ms;
 323     _cur_fast_reclaim_humongous_total = total;
 324     _cur_fast_reclaim_humongous_candidates = candidates;
 325   }
 326 
 327   void record_fast_reclaim_humongous_time_ms(double value, size_t reclaimed) {
 328     _cur_fast_reclaim_humongous_time_ms = value;
 329     _cur_fast_reclaim_humongous_reclaimed = reclaimed;
 330   }
 331 
 332   void record_young_cset_choice_time_ms(double time_ms) {
 333     _recorded_young_cset_choice_time_ms = time_ms;
 334   }
 335 
 336   void record_non_young_cset_choice_time_ms(double time_ms) {
 337     _recorded_non_young_cset_choice_time_ms = time_ms;
 338   }
 339 
 340   void record_redirty_logged_cards_time_ms(double time_ms) {
 341     _recorded_redirty_logged_cards_time_ms = time_ms;
 342   }
 343 
 344   void record_preserve_cm_referents_time_ms(double time_ms) {
 345     _recorded_preserve_cm_referents_time_ms = time_ms;
 346   }
 347 
 348   void record_start_new_cset_time_ms(double time_ms) {
 349     _recorded_start_new_cset_time_ms = time_ms;
 350   }
 351 
 352   void record_cur_collection_start_sec(double time_ms) {
 353     _cur_collection_start_sec = time_ms;
 354   }
 355 
 356   void record_verify_before_time_ms(double time_ms) {
 357     _cur_verify_before_time_ms = time_ms;
 358   }
 359 
 360   void record_verify_after_time_ms(double time_ms) {
 361     _cur_verify_after_time_ms = time_ms;
 362   }
 363 
 364   void inc_external_accounted_time_ms(double time_ms) {
 365     _external_accounted_time_ms += time_ms;
 366   }
 367 
 368   void record_prepare_heap_roots_time_ms(double recorded_prepare_heap_roots_time_ms) {
 369     _recorded_prepare_heap_roots_time_ms = recorded_prepare_heap_roots_time_ms;
 370   }
 371 
 372   void record_clear_claimed_marks_time_ms(double recorded_clear_claimed_marks_time_ms) {
 373     _recorded_clear_claimed_marks_time_ms = recorded_clear_claimed_marks_time_ms;
 374   }
 375 
 376   double cur_collection_start_sec() {
 377     return _cur_collection_start_sec;
 378   }
 379 
 380   double cur_collection_par_time_ms() {
 381     return _cur_collection_initial_evac_time_ms + _cur_optional_evac_time_ms;
 382   }
 383 
 384   double cur_clear_ct_time_ms() {
 385     return _cur_clear_ct_time_ms;
 386   }
 387 
 388   double cur_expand_heap_time_ms() {
 389     return _cur_expand_heap_time_ms;
 390   }
 391 
 392   double root_region_scan_wait_time_ms() {
 393     return _root_region_scan_wait_time_ms;
 394   }
 395 
 396   double young_cset_choice_time_ms() {
 397     return _recorded_young_cset_choice_time_ms;
 398   }
 399 
 400   double total_free_cset_time_ms() {
 401     return _recorded_total_free_cset_time_ms;
 402   }
 403 
 404   double non_young_cset_choice_time_ms() {
 405     return _recorded_non_young_cset_choice_time_ms;
 406   }
 407 
 408   double fast_reclaim_humongous_time_ms() {
 409     return _cur_fast_reclaim_humongous_time_ms;
 410   }
 411 
 412   size_t fast_reclaim_humongous_candidates() const {
 413     return _cur_fast_reclaim_humongous_candidates;
 414   }
 415 
 416   ReferenceProcessorPhaseTimes* ref_phase_times() { return &_ref_phase_times; }
 417 
 418   WeakProcessorPhaseTimes* weak_phase_times() { return &_weak_phase_times; }
 419 };
 420 
 421 class G1EvacPhaseWithTrimTimeTracker : public StackObj {
 422   G1ParScanThreadState* _pss;
 423   Ticks _start;
 424 
 425   Tickspan& _total_time;
 426   Tickspan& _trim_time;
 427 
 428   bool _stopped;
 429 public:
 430   G1EvacPhaseWithTrimTimeTracker(G1ParScanThreadState* pss, Tickspan& total_time, Tickspan& trim_time);
 431   ~G1EvacPhaseWithTrimTimeTracker();
 432 
 433   void stop();
 434 };
 435 
 436 class G1GCParPhaseTimesTracker : public CHeapObj<mtGC> {
 437 protected:
 438   Ticks _start_time;
 439   G1GCPhaseTimes::GCParPhases _phase;
 440   G1GCPhaseTimes* _phase_times;
 441   uint _worker_id;
 442   EventGCPhaseParallel _event;
 443   bool _must_record;
 444 
 445 public:
 446   G1GCParPhaseTimesTracker(G1GCPhaseTimes* phase_times, G1GCPhaseTimes::GCParPhases phase, uint worker_id, bool must_record = true);
 447   virtual ~G1GCParPhaseTimesTracker();
 448 };
 449 
 450 class G1EvacPhaseTimesTracker : public G1GCParPhaseTimesTracker {
 451   Tickspan _total_time;
 452   Tickspan _trim_time;
 453 
 454   G1EvacPhaseWithTrimTimeTracker _trim_tracker;
 455 public:
 456   G1EvacPhaseTimesTracker(G1GCPhaseTimes* phase_times, G1ParScanThreadState* pss, G1GCPhaseTimes::GCParPhases phase, uint worker_id);
 457   virtual ~G1EvacPhaseTimesTracker();
 458 };
 459 
 460 #endif // SHARE_GC_G1_G1GCPHASETIMES_HPP