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