rev 58201 : 8240216: Shenandoah: remove ShenandoahTerminationTrace
Reviewed-by: XXX

   1 /*
   2  * Copyright (c) 2017, 2020, Red Hat, Inc. 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 #include "precompiled.hpp"
  26 
  27 #include "gc/shared/workerDataArray.inline.hpp"
  28 #include "gc/shenandoah/shenandoahCollectorPolicy.hpp"
  29 #include "gc/shenandoah/shenandoahPhaseTimings.hpp"
  30 #include "gc/shenandoah/shenandoahHeap.hpp"
  31 #include "gc/shenandoah/shenandoahHeuristics.hpp"
  32 #include "gc/shenandoah/shenandoahUtils.hpp"
  33 #include "utilities/ostream.hpp"
  34 
  35 #define GC_PHASE_DECLARE_NAME(type, title) \
  36   title,
  37 
  38 const char* ShenandoahPhaseTimings::_phase_names[] = {
  39   SHENANDOAH_GC_PHASE_DO(GC_PHASE_DECLARE_NAME)
  40 };
  41 
  42 #undef GC_PHASE_DECLARE_NAME
  43 
  44 ShenandoahPhaseTimings::ShenandoahPhaseTimings() : _policy(NULL) {
  45   uint max_workers = MAX2(ConcGCThreads, ParallelGCThreads);
  46   _worker_times = new ShenandoahWorkerTimings(max_workers);
  47   _termination_times = new ShenandoahTerminationTimings(max_workers);
  48   _policy = ShenandoahHeap::heap()->shenandoah_policy();
  49   assert(_policy != NULL, "Can not be NULL");
  50 }
  51 
  52 void ShenandoahPhaseTimings::record_phase_start(Phase phase) {
  53   _timing_data[phase]._start = os::elapsedTime();
  54 }
  55 
  56 void ShenandoahPhaseTimings::record_phase_end(Phase phase) {
  57   assert(_policy != NULL, "Not yet initialized");
  58   double end = os::elapsedTime();
  59   double elapsed = end - _timing_data[phase]._start;
  60   if (!_policy->is_at_shutdown()) {
  61     _timing_data[phase]._secs.add(elapsed);
  62   }
  63   ShenandoahHeap::heap()->heuristics()->record_phase_time(phase, elapsed);
  64 }
  65 
  66 void ShenandoahPhaseTimings::record_phase_time(Phase phase, double time) {
  67   assert(_policy != NULL, "Not yet initialized");
  68   if (!_policy->is_at_shutdown()) {
  69     _timing_data[phase]._secs.add(time);
  70   }
  71 }
  72 
  73 void ShenandoahPhaseTimings::record_workers_start(Phase phase) {
  74   for (uint i = 0; i < GCParPhasesSentinel; i++) {
  75     _worker_times->reset(i);
  76   }
  77 }
  78 
  79 void ShenandoahPhaseTimings::record_workers_end(Phase phase) {
  80   if (_policy->is_at_shutdown()) {
  81     // Do not record the past-shutdown events
  82     return;
  83   }
  84 
  85   guarantee(phase == init_evac ||
  86             phase == scan_roots ||
  87             phase == update_roots ||
  88             phase == init_traversal_gc_work ||
  89             phase == final_traversal_gc_work ||
  90             phase == final_traversal_update_roots ||
  91             phase == final_update_refs_roots ||
  92             phase == full_gc_roots ||
  93             phase == degen_gc_update_roots ||
  94             phase == full_gc_purge_par ||
  95             phase == purge_par ||
  96             phase == _num_phases,
  97             "only in these phases we can add per-thread phase times");
  98   if (phase != _num_phases) {
  99     // Merge _phase_time to counters below the given phase.
 100     for (uint i = 0; i < GCParPhasesSentinel; i++) {
 101       double t = _worker_times->average(i);
 102       _timing_data[phase + i + 1]._secs.add(t);
 103     }
 104   }
 105 }
 106 
 107 void ShenandoahPhaseTimings::print_on(outputStream* out) const {
 108   out->cr();
 109   out->print_cr("GC STATISTICS:");
 110   out->print_cr("  \"(G)\" (gross) pauses include VM time: time to notify and block threads, do the pre-");
 111   out->print_cr("        and post-safepoint housekeeping. Use -Xlog:safepoint+stats to dissect.");
 112   out->print_cr("  \"(N)\" (net) pauses are the times spent in the actual GC code.");
 113   out->print_cr("  \"a\" is average time for each phase, look at levels to see if average makes sense.");
 114   out->print_cr("  \"lvls\" are quantiles: 0%% (minimum), 25%%, 50%% (median), 75%%, 100%% (maximum).");
 115   out->cr();
 116 
 117   for (uint i = 0; i < _num_phases; i++) {
 118     if (_timing_data[i]._secs.maximum() != 0) {
 119       print_summary_sd(out, _phase_names[i], &(_timing_data[i]._secs));
 120     }
 121   }
 122 }
 123 
 124 void ShenandoahPhaseTimings::print_summary_sd(outputStream* out, const char* str, const HdrSeq* seq) const {
 125   out->print_cr("%-27s = %8.2lf s (a = %8.0lf us) (n = " INT32_FORMAT_W(5) ") (lvls, us = %8.0lf, %8.0lf, %8.0lf, %8.0lf, %8.0lf)",
 126           str,
 127           seq->sum(),
 128           seq->avg() * 1000000.0,
 129           seq->num(),
 130           seq->percentile(0)  * 1000000.0,
 131           seq->percentile(25) * 1000000.0,
 132           seq->percentile(50) * 1000000.0,
 133           seq->percentile(75) * 1000000.0,
 134           seq->maximum() * 1000000.0
 135   );
 136 }
 137 
 138 ShenandoahWorkerTimings::ShenandoahWorkerTimings(uint max_gc_threads) :
 139         _max_gc_threads(max_gc_threads)
 140 {
 141   assert(max_gc_threads > 0, "Must have some GC threads");
 142 
 143 #define GC_PAR_PHASE_DECLARE_WORKER_DATA(type, title) \
 144   _gc_par_phases[ShenandoahPhaseTimings::type] = new WorkerDataArray<double>(title, max_gc_threads);
 145   // Root scanning phases
 146   SHENANDOAH_GC_PAR_PHASE_DO(GC_PAR_PHASE_DECLARE_WORKER_DATA)
 147 #undef GC_PAR_PHASE_DECLARE_WORKER_DATA
 148 }
 149 
 150 // record the time a phase took in seconds
 151 void ShenandoahWorkerTimings::record_time_secs(ShenandoahPhaseTimings::GCParPhases phase, uint worker_i, double secs) {
 152   _gc_par_phases[phase]->set(worker_i, secs);
 153 }
 154 
 155 double ShenandoahWorkerTimings::average(uint i) const {
 156   return _gc_par_phases[i]->average();
 157 }
 158 
 159 void ShenandoahWorkerTimings::reset(uint i) {
 160   _gc_par_phases[i]->reset();
 161 }
 162 
 163 void ShenandoahWorkerTimings::print() const {
 164   for (uint i = 0; i < ShenandoahPhaseTimings::GCParPhasesSentinel; i++) {
 165     _gc_par_phases[i]->print_summary_on(tty);
 166   }
 167 }
 168 
 169 
 170 ShenandoahTerminationTimings::ShenandoahTerminationTimings(uint max_gc_threads) {
 171   _gc_termination_phase = new WorkerDataArray<double>("Task Termination (ms):", max_gc_threads);
 172 }
 173 
 174 void ShenandoahTerminationTimings::record_time_secs(uint worker_id, double secs) {
 175   if (_gc_termination_phase->get(worker_id) == WorkerDataArray<double>::uninitialized()) {
 176     _gc_termination_phase->set(worker_id, secs);
 177   } else {
 178     // worker may re-enter termination phase
 179     _gc_termination_phase->add(worker_id, secs);
 180   }
 181 }
 182 
 183 void ShenandoahTerminationTimings::print() const {
 184   _gc_termination_phase->print_summary_on(tty);
 185 }
 186 
 187 double ShenandoahTerminationTimings::average() const {
 188   return _gc_termination_phase->average();
 189 }
 190 
 191 void ShenandoahTerminationTimings::reset() {
 192   _gc_termination_phase->reset();
 193 }
 194 
--- EOF ---