rev 59534 : 8245961: Shenandoah: move some root marking to concurrent phase

   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.inline.hpp"
  31 #include "gc/shenandoah/shenandoahUtils.hpp"
  32 #include "gc/shenandoah/heuristics/shenandoahHeuristics.hpp"
  33 #include "runtime/orderAccess.hpp"
  34 #include "utilities/ostream.hpp"
  35 
  36 #define SHENANDOAH_PHASE_NAME_FORMAT "%-30s"
  37 #define SHENANDOAH_S_TIME_FORMAT "%8.3lf"
  38 #define SHENANDOAH_US_TIME_FORMAT "%8.0lf"
  39 #define SHENANDOAH_US_WORKER_TIME_FORMAT "%3.0lf"
  40 #define SHENANDOAH_US_WORKER_NOTIME_FORMAT "%3s"
  41 #define SHENANDOAH_PARALLELISM_FORMAT "%4.2lf"
  42 
  43 #define SHENANDOAH_PHASE_DECLARE_NAME(type, title) \
  44   title,
  45 
  46 const char* ShenandoahPhaseTimings::_phase_names[] = {
  47   SHENANDOAH_PHASE_DO(SHENANDOAH_PHASE_DECLARE_NAME)
  48 };
  49 
  50 #undef SHENANDOAH_PHASE_DECLARE_NAME
  51 
  52 ShenandoahPhaseTimings::ShenandoahPhaseTimings(uint max_workers) :
  53   _max_workers(max_workers) {
  54   assert(_max_workers > 0, "Must have some GC threads");
  55 
  56   // Initialize everything to sane defaults
  57   for (uint i = 0; i < _num_phases; i++) {
  58 #define SHENANDOAH_WORKER_DATA_NULL(type, title) \
  59     _worker_data[i] = NULL;
  60     SHENANDOAH_PAR_PHASE_DO(,, SHENANDOAH_WORKER_DATA_NULL)
  61 #undef SHENANDOAH_WORKER_DATA_NULL
  62     _cycle_data[i] = uninitialized();
  63   }
  64 
  65   // Then punch in the worker-related data.
  66   // Every worker phase get a bunch of internal objects, except
  67   // the very first slot, which is "<total>" and is not populated.
  68   for (uint i = 0; i < _num_phases; i++) {
  69     if (is_worker_phase(Phase(i))) {
  70       int c = 0;
  71 #define SHENANDOAH_WORKER_DATA_INIT(type, title) \
  72       if (c++ != 0) _worker_data[i + c] = new ShenandoahWorkerData(title, _max_workers);
  73       SHENANDOAH_PAR_PHASE_DO(,, SHENANDOAH_WORKER_DATA_INIT)
  74 #undef SHENANDOAH_WORKER_DATA_INIT
  75     }
  76   }
  77 
  78   _policy = ShenandoahHeap::heap()->shenandoah_policy();
  79   assert(_policy != NULL, "Can not be NULL");
  80 }
  81 
  82 ShenandoahPhaseTimings::Phase ShenandoahPhaseTimings::worker_par_phase(Phase phase, ParPhase par_phase) {
  83   assert(is_worker_phase(phase), "Phase should accept worker phase times: %s", phase_name(phase));
  84   Phase p = Phase(phase + 1 + par_phase);
  85   assert(p >= 0 && p < _num_phases, "Out of bound for: %s", phase_name(phase));
  86   return p;
  87 }
  88 
  89 ShenandoahWorkerData* ShenandoahPhaseTimings::worker_data(Phase phase, ParPhase par_phase) {
  90   Phase p = worker_par_phase(phase, par_phase);
  91   ShenandoahWorkerData* wd = _worker_data[p];
  92   assert(wd != NULL, "Counter initialized: %s", phase_name(p));
  93   return wd;
  94 }
  95 
  96 bool ShenandoahPhaseTimings::is_worker_phase(Phase phase) {
  97   assert(phase >= 0 && phase < _num_phases, "Out of bounds");
  98   switch (phase) {
  99     case init_evac:
 100     case scan_roots:
 101     case update_roots:
 102     case final_update_refs_roots:
 103     case full_gc_scan_roots:
 104     case full_gc_update_roots:
 105     case full_gc_adjust_roots:
 106     case degen_gc_scan_conc_roots:
 107     case degen_gc_update_roots:
 108     case full_gc_scan_conc_roots:
 109     case full_gc_purge_class_unload:
 110     case full_gc_purge_weak_par:
 111     case purge_class_unload:
 112     case purge_weak_par:
 113     case heap_iteration_roots:
 114     case conc_mark_roots:
 115     case conc_weak_roots_work:
 116     case conc_strong_roots:
 117       return true;
 118     default:
 119       return false;
 120   }
 121 }
 122 
 123 bool ShenandoahPhaseTimings::is_root_work_phase(Phase phase) {
 124   switch (phase) {
 125     case scan_roots:
 126     case update_roots:
 127     case init_evac:
 128     case final_update_refs_roots:
 129     case degen_gc_update_roots:
 130     case full_gc_scan_roots:
 131     case full_gc_update_roots:
 132     case full_gc_adjust_roots:
 133       return true;
 134     default:
 135       return false;
 136   }
 137 }
 138 
 139 void ShenandoahPhaseTimings::set_cycle_data(Phase phase, double time) {
 140 #ifdef ASSERT
 141   double d = _cycle_data[phase];
 142   assert(d == uninitialized(), "Should not be set yet: %s, current value: %lf", phase_name(phase), d);
 143 #endif
 144   _cycle_data[phase] = time;
 145 }
 146 
 147 void ShenandoahPhaseTimings::record_phase_time(Phase phase, double time) {
 148   if (!_policy->is_at_shutdown()) {
 149     set_cycle_data(phase, time);
 150   }
 151 }
 152 
 153 void ShenandoahPhaseTimings::record_workers_start(Phase phase) {
 154   assert(is_worker_phase(phase), "Phase should accept worker phase times: %s", phase_name(phase));
 155 
 156   // Special case: these phases can enter multiple times, need to reset
 157   // their worker data every time.
 158   if (phase == heap_iteration_roots) {
 159     for (uint i = 1; i < _num_par_phases; i++) {
 160       worker_data(phase, ParPhase(i))->reset();
 161     }
 162   }
 163 
 164 #ifdef ASSERT
 165   for (uint i = 1; i < _num_par_phases; i++) {
 166     ShenandoahWorkerData* wd = worker_data(phase, ParPhase(i));
 167     for (uint c = 0; c < _max_workers; c++) {
 168       assert(wd->get(c) == ShenandoahWorkerData::uninitialized(),
 169              "Should not be set: %s", phase_name(worker_par_phase(phase, ParPhase(i))));
 170     }
 171   }
 172 #endif
 173 }
 174 
 175 void ShenandoahPhaseTimings::record_workers_end(Phase phase) {
 176   assert(is_worker_phase(phase), "Phase should accept worker phase times: %s", phase_name(phase));
 177 }
 178 
 179 void ShenandoahPhaseTimings::flush_par_workers_to_cycle() {
 180   for (uint pi = 0; pi < _num_phases; pi++) {
 181     Phase phase = Phase(pi);
 182     if (is_worker_phase(phase)) {
 183       double s = uninitialized();
 184       for (uint i = 1; i < _num_par_phases; i++) {
 185         ShenandoahWorkerData* wd = worker_data(phase, ParPhase(i));
 186         double ws = uninitialized();
 187         for (uint c = 0; c < _max_workers; c++) {
 188           double v = wd->get(c);
 189           if (v != ShenandoahWorkerData::uninitialized()) {
 190             if (ws == uninitialized()) {
 191               ws = v;
 192             } else {
 193               ws += v;
 194             }
 195           }
 196         }
 197         if (ws != uninitialized()) {
 198           // add to each line in phase
 199           set_cycle_data(Phase(phase + i + 1), ws);
 200           if (s == uninitialized()) {
 201             s = ws;
 202           } else {
 203             s += ws;
 204           }
 205         }
 206       }
 207       if (s != uninitialized()) {
 208         // add to total for phase
 209         set_cycle_data(Phase(phase + 1), s);
 210       }
 211     }
 212   }
 213 }
 214 
 215 void ShenandoahPhaseTimings::flush_cycle_to_global() {
 216   for (uint i = 0; i < _num_phases; i++) {
 217     if (_cycle_data[i] != uninitialized()) {
 218       _global_data[i].add(_cycle_data[i]);
 219       _cycle_data[i] = uninitialized();
 220     }
 221     if (_worker_data[i] != NULL) {
 222       _worker_data[i]->reset();
 223     }
 224   }
 225   OrderAccess::fence();
 226 }
 227 
 228 void ShenandoahPhaseTimings::print_cycle_on(outputStream* out) const {
 229   out->cr();
 230   out->print_cr("All times are wall-clock times, except per-root-class counters, that are sum over");
 231   out->print_cr("all workers. Dividing the <total> over the root stage time estimates parallelism.");
 232   out->cr();
 233   for (uint i = 0; i < _num_phases; i++) {
 234     double v = _cycle_data[i] * 1000000.0;
 235     if (v > 0) {
 236       out->print(SHENANDOAH_PHASE_NAME_FORMAT " " SHENANDOAH_US_TIME_FORMAT " us", _phase_names[i], v);
 237 
 238       if (is_worker_phase(Phase(i))) {
 239         double total = _cycle_data[i + 1] * 1000000.0;
 240         if (total > 0) {
 241           out->print(", parallelism: " SHENANDOAH_PARALLELISM_FORMAT "x", total / v);
 242         }
 243       }
 244 
 245       if (_worker_data[i] != NULL) {
 246         out->print(", workers (us): ");
 247         for (uint c = 0; c < _max_workers; c++) {
 248           double tv = _worker_data[i]->get(c);
 249           if (tv != ShenandoahWorkerData::uninitialized()) {
 250             out->print(SHENANDOAH_US_WORKER_TIME_FORMAT ", ", tv * 1000000.0);
 251           } else {
 252             out->print(SHENANDOAH_US_WORKER_NOTIME_FORMAT ", ", "---");
 253           }
 254         }
 255       }
 256       out->cr();
 257     }
 258   }
 259 }
 260 
 261 void ShenandoahPhaseTimings::print_global_on(outputStream* out) const {
 262   out->cr();
 263   out->print_cr("GC STATISTICS:");
 264   out->print_cr("  \"(G)\" (gross) pauses include VM time: time to notify and block threads, do the pre-");
 265   out->print_cr("        and post-safepoint housekeeping. Use -Xlog:safepoint+stats to dissect.");
 266   out->print_cr("  \"(N)\" (net) pauses are the times spent in the actual GC code.");
 267   out->print_cr("  \"a\" is average time for each phase, look at levels to see if average makes sense.");
 268   out->print_cr("  \"lvls\" are quantiles: 0%% (minimum), 25%%, 50%% (median), 75%%, 100%% (maximum).");
 269   out->cr();
 270   out->print_cr("  All times are wall-clock times, except per-root-class counters, that are sum over");
 271   out->print_cr("  all workers. Dividing the <total> over the root stage time estimates parallelism.");
 272   out->cr();
 273 
 274   for (uint i = 0; i < _num_phases; i++) {
 275     if (_global_data[i].maximum() != 0) {
 276       out->print_cr(SHENANDOAH_PHASE_NAME_FORMAT " = " SHENANDOAH_S_TIME_FORMAT " s "
 277                     "(a = " SHENANDOAH_US_TIME_FORMAT " us) "
 278                     "(n = " INT32_FORMAT_W(5) ") (lvls, us = "
 279                     SHENANDOAH_US_TIME_FORMAT ", "
 280                     SHENANDOAH_US_TIME_FORMAT ", "
 281                     SHENANDOAH_US_TIME_FORMAT ", "
 282                     SHENANDOAH_US_TIME_FORMAT ", "
 283                     SHENANDOAH_US_TIME_FORMAT ")",
 284                     _phase_names[i],
 285                     _global_data[i].sum(),
 286                     _global_data[i].avg() * 1000000.0,
 287                     _global_data[i].num(),
 288                     _global_data[i].percentile(0) * 1000000.0,
 289                     _global_data[i].percentile(25) * 1000000.0,
 290                     _global_data[i].percentile(50) * 1000000.0,
 291                     _global_data[i].percentile(75) * 1000000.0,
 292                     _global_data[i].maximum() * 1000000.0
 293       );
 294     }
 295   }
 296 }
 297 
 298 ShenandoahWorkerTimingsTracker::ShenandoahWorkerTimingsTracker(ShenandoahPhaseTimings::Phase phase,
 299         ShenandoahPhaseTimings::ParPhase par_phase, uint worker_id) :
 300         _timings(ShenandoahHeap::heap()->phase_timings()),
 301         _phase(phase), _par_phase(par_phase), _worker_id(worker_id) {
 302 
 303   assert(_timings->worker_data(_phase, _par_phase)->get(_worker_id) == ShenandoahWorkerData::uninitialized(),
 304          "Should not be set yet: %s", ShenandoahPhaseTimings::phase_name(_timings->worker_par_phase(_phase, _par_phase)));
 305   _start_time = os::elapsedTime();
 306 }
 307 
 308 ShenandoahWorkerTimingsTracker::~ShenandoahWorkerTimingsTracker() {
 309   _timings->worker_data(_phase, _par_phase)->set(_worker_id, os::elapsedTime() - _start_time);
 310 
 311   if (ShenandoahPhaseTimings::is_root_work_phase(_phase)) {
 312     ShenandoahPhaseTimings::Phase root_phase = _phase;
 313     ShenandoahPhaseTimings::Phase cur_phase = _timings->worker_par_phase(root_phase, _par_phase);
 314     _event.commit(GCId::current(), _worker_id, ShenandoahPhaseTimings::phase_name(cur_phase));
 315   }
 316 }
 317 
--- EOF ---