1 /* 2 * Copyright (c) 2017, 2018, Red Hat, Inc. All rights reserved. 3 * 4 * This code is free software; you can redistribute it and/or modify it 5 * under the terms of the GNU General Public License version 2 only, as 6 * published by the Free Software Foundation. 7 * 8 * This code is distributed in the hope that it will be useful, but WITHOUT 9 * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or 10 * FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License 11 * version 2 for more details (a copy is included in the LICENSE file that 12 * accompanied this code). 13 * 14 * You should have received a copy of the GNU General Public License version 15 * 2 along with this work; if not, write to the Free Software Foundation, 16 * Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA. 17 * 18 * Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA 19 * or visit www.oracle.com if you need additional information or have any 20 * questions. 21 * 22 */ 23 24 #include "precompiled.hpp" 25 26 #include "gc/shared/workerDataArray.inline.hpp" 27 #include "gc/shenandoah/shenandoahCollectorPolicy.hpp" 28 #include "gc/shenandoah/shenandoahPhaseTimings.hpp" 29 #include "gc/shenandoah/shenandoahHeap.inline.hpp" 30 #include "gc/shenandoah/shenandoahUtils.hpp" 31 #include "gc/shenandoah/heuristics/shenandoahHeuristics.hpp" 32 #include "runtime/orderAccess.hpp" 33 #include "utilities/ostream.hpp" 34 35 #define SHENANDOAH_PHASE_NAME_FORMAT "%-30s" 36 #define SHENANDOAH_S_TIME_FORMAT "%8.3lf" 37 #define SHENANDOAH_US_TIME_FORMAT "%8.0lf" 38 #define SHENANDOAH_US_WORKER_TIME_FORMAT "%3.0lf" 39 #define SHENANDOAH_US_WORKER_NOTIME_FORMAT "%3s" 40 #define SHENANDOAH_PARALLELISM_FORMAT "%4.2lf" 41 42 #define SHENANDOAH_PHASE_DECLARE_NAME(type, title) \ 43 title, 44 45 const char* ShenandoahPhaseTimings::_phase_names[] = { 46 SHENANDOAH_PHASE_DO(SHENANDOAH_PHASE_DECLARE_NAME) 47 }; 48 49 #undef SHENANDOAH_PHASE_DECLARE_NAME 50 51 ShenandoahPhaseTimings::ShenandoahPhaseTimings(uint max_workers) : 52 _max_workers(max_workers) { 53 assert(_max_workers > 0, "Must have some GC threads"); 54 55 // Initialize everything to sane defaults 56 for (uint i = 0; i < _num_phases; i++) { 57 #define SHENANDOAH_WORKER_DATA_NULL(type, title) \ 58 _worker_data[i] = NULL; 59 SHENANDOAH_PAR_PHASE_DO(,, SHENANDOAH_WORKER_DATA_NULL) 60 #undef SHENANDOAH_WORKER_DATA_NULL 61 _cycle_data[i] = uninitialized(); 62 } 63 64 // Then punch in the worker-related data. 65 // Every worker phase get a bunch of internal objects, except 66 // the very first slot, which is "<total>" and is not populated. 67 for (uint i = 0; i < _num_phases; i++) { 68 if (is_worker_phase(Phase(i))) { 69 int c = 0; 70 #define SHENANDOAH_WORKER_DATA_INIT(type, title) \ 71 if (c++ != 0) _worker_data[i + c] = new ShenandoahWorkerData(_max_workers, title); 72 SHENANDOAH_PAR_PHASE_DO(,, SHENANDOAH_WORKER_DATA_INIT) 73 #undef SHENANDOAH_WORKER_DATA_INIT 74 } 75 } 76 77 _policy = ShenandoahHeap::heap()->shenandoah_policy(); 78 assert(_policy != NULL, "Can not be NULL"); 79 } 80 81 ShenandoahPhaseTimings::Phase ShenandoahPhaseTimings::worker_par_phase(Phase phase, ParPhase par_phase) { 82 assert(is_worker_phase(phase), "Phase should accept worker phase times: %s", phase_name(phase)); 83 Phase p = Phase(phase + 1 + par_phase); 84 assert(p >= 0 && p < _num_phases, "Out of bound for: %s", phase_name(phase)); 85 return p; 86 } 87 88 ShenandoahWorkerData* ShenandoahPhaseTimings::worker_data(Phase phase, ParPhase par_phase) { 89 Phase p = worker_par_phase(phase, par_phase); 90 ShenandoahWorkerData* wd = _worker_data[p]; 91 assert(wd != NULL, "Counter initialized: %s", phase_name(p)); 92 return wd; 93 } 94 95 bool ShenandoahPhaseTimings::is_worker_phase(Phase phase) { 96 assert(phase >= 0 && phase < _num_phases, "Out of bounds"); 97 switch (phase) { 98 case init_evac: 99 case scan_roots: 100 case update_roots: 101 case final_update_refs_roots: 102 case full_gc_scan_roots: 103 case full_gc_update_roots: 104 case full_gc_adjust_roots: 105 case degen_gc_update_roots: 106 case full_gc_purge_class_unload: 107 case full_gc_purge_weak_par: 108 case purge_class_unload: 109 case purge_weak_par: 110 case heap_iteration_roots: 111 return true; 112 default: 113 return false; 114 } 115 } 116 117 bool ShenandoahPhaseTimings::is_root_work_phase(Phase phase) { 118 switch (phase) { 119 case scan_roots: 120 case update_roots: 121 case init_evac: 122 case final_update_refs_roots: 123 case degen_gc_update_roots: 124 case full_gc_scan_roots: 125 case full_gc_update_roots: 126 case full_gc_adjust_roots: 127 return true; 128 default: 129 return false; 130 } 131 } 132 133 void ShenandoahPhaseTimings::set_cycle_data(Phase phase, double time) { 134 #ifdef ASSERT 135 double d = _cycle_data[phase]; 136 assert(d == uninitialized(), "Should not be set yet: %s, current value: %lf", phase_name(phase), d); 137 #endif 138 _cycle_data[phase] = time; 139 } 140 141 void ShenandoahPhaseTimings::record_phase_time(Phase phase, double time) { 142 if (!_policy->is_at_shutdown()) { 143 set_cycle_data(phase, time); 144 } 145 } 146 147 void ShenandoahPhaseTimings::record_workers_start(Phase phase) { 148 assert(is_worker_phase(phase), "Phase should accept worker phase times: %s", phase_name(phase)); 149 150 // Special case: these phases can enter multiple times, need to reset 151 // their worker data every time. 152 if (phase == heap_iteration_roots) { 153 for (uint i = 1; i < _num_par_phases; i++) { 154 worker_data(phase, ParPhase(i))->reset(); 155 } 156 } 157 158 #ifdef ASSERT 159 for (uint i = 1; i < _num_par_phases; i++) { 160 ShenandoahWorkerData* wd = worker_data(phase, ParPhase(i)); 161 for (uint c = 0; c < _max_workers; c++) { 162 assert(wd->get(c) == ShenandoahWorkerData::uninitialized(), 163 "Should not be set: %s", phase_name(worker_par_phase(phase, ParPhase(i)))); 164 } 165 } 166 #endif 167 } 168 169 void ShenandoahPhaseTimings::record_workers_end(Phase phase) { 170 assert(is_worker_phase(phase), "Phase should accept worker phase times: %s", phase_name(phase)); 171 } 172 173 void ShenandoahPhaseTimings::flush_par_workers_to_cycle() { 174 for (uint pi = 0; pi < _num_phases; pi++) { 175 Phase phase = Phase(pi); 176 if (is_worker_phase(phase)) { 177 double s = uninitialized(); 178 for (uint i = 1; i < _num_par_phases; i++) { 179 ShenandoahWorkerData* wd = worker_data(phase, ParPhase(i)); 180 double ws = uninitialized(); 181 for (uint c = 0; c < _max_workers; c++) { 182 double v = wd->get(c); 183 if (v != ShenandoahWorkerData::uninitialized()) { 184 if (ws == uninitialized()) { 185 ws = v; 186 } else { 187 ws += v; 188 } 189 } 190 } 191 if (ws != uninitialized()) { 192 // add to each line in phase 193 set_cycle_data(Phase(phase + i + 1), ws); 194 if (s == uninitialized()) { 195 s = ws; 196 } else { 197 s += ws; 198 } 199 } 200 } 201 if (s != uninitialized()) { 202 // add to total for phase 203 set_cycle_data(Phase(phase + 1), s); 204 } 205 } 206 } 207 } 208 209 void ShenandoahPhaseTimings::flush_cycle_to_global() { 210 for (uint i = 0; i < _num_phases; i++) { 211 if (_cycle_data[i] != uninitialized()) { 212 _global_data[i].add(_cycle_data[i]); 213 _cycle_data[i] = uninitialized(); 214 } 215 if (_worker_data[i] != NULL) { 216 _worker_data[i]->reset(); 217 } 218 } 219 OrderAccess::fence(); 220 } 221 222 void ShenandoahPhaseTimings::print_cycle_on(outputStream* out) const { 223 out->cr(); 224 out->print_cr("All times are wall-clock times, except per-root-class counters, that are sum over"); 225 out->print_cr("all workers. Dividing the <total> over the root stage time estimates parallelism."); 226 out->cr(); 227 for (uint i = 0; i < _num_phases; i++) { 228 double v = _cycle_data[i] * 1000000.0; 229 if (v > 0) { 230 out->print(SHENANDOAH_PHASE_NAME_FORMAT " " SHENANDOAH_US_TIME_FORMAT " us", _phase_names[i], v); 231 232 if (is_worker_phase(Phase(i))) { 233 double total = _cycle_data[i + 1] * 1000000.0; 234 if (total > 0) { 235 out->print(", parallelism: " SHENANDOAH_PARALLELISM_FORMAT "x", total / v); 236 } 237 } 238 239 if (_worker_data[i] != NULL) { 240 out->print(", workers (us): "); 241 for (uint c = 0; c < _max_workers; c++) { 242 double tv = _worker_data[i]->get(c); 243 if (tv != ShenandoahWorkerData::uninitialized()) { 244 out->print(SHENANDOAH_US_WORKER_TIME_FORMAT ", ", tv * 1000000.0); 245 } else { 246 out->print(SHENANDOAH_US_WORKER_NOTIME_FORMAT ", ", "---"); 247 } 248 } 249 } 250 out->cr(); 251 } 252 } 253 } 254 255 void ShenandoahPhaseTimings::print_global_on(outputStream* out) const { 256 out->cr(); 257 out->print_cr("GC STATISTICS:"); 258 out->print_cr(" \"(G)\" (gross) pauses include VM time: time to notify and block threads, do the pre-"); 259 out->print_cr(" and post-safepoint housekeeping. Use -XX:+PrintSafepointStatistics to dissect."); 260 out->print_cr(" \"(N)\" (net) pauses are the times spent in the actual GC code."); 261 out->print_cr(" \"a\" is average time for each phase, look at levels to see if average makes sense."); 262 out->print_cr(" \"lvls\" are quantiles: 0%% (minimum), 25%%, 50%% (median), 75%%, 100%% (maximum)."); 263 out->cr(); 264 out->print_cr(" All times are wall-clock times, except per-root-class counters, that are sum over"); 265 out->print_cr(" all workers. Dividing the <total> over the root stage time estimates parallelism."); 266 out->cr(); 267 268 for (uint i = 0; i < _num_phases; i++) { 269 if (_global_data[i].maximum() != 0) { 270 out->print_cr(SHENANDOAH_PHASE_NAME_FORMAT " = " SHENANDOAH_S_TIME_FORMAT " s " 271 "(a = " SHENANDOAH_US_TIME_FORMAT " us) " 272 "(n = " INT32_FORMAT_W(5) ") (lvls, us = " 273 SHENANDOAH_US_TIME_FORMAT ", " 274 SHENANDOAH_US_TIME_FORMAT ", " 275 SHENANDOAH_US_TIME_FORMAT ", " 276 SHENANDOAH_US_TIME_FORMAT ", " 277 SHENANDOAH_US_TIME_FORMAT ")", 278 _phase_names[i], 279 _global_data[i].sum(), 280 _global_data[i].avg() * 1000000.0, 281 _global_data[i].num(), 282 _global_data[i].percentile(0) * 1000000.0, 283 _global_data[i].percentile(25) * 1000000.0, 284 _global_data[i].percentile(50) * 1000000.0, 285 _global_data[i].percentile(75) * 1000000.0, 286 _global_data[i].maximum() * 1000000.0 287 ); 288 } 289 } 290 } 291 292 ShenandoahWorkerTimingsTracker::ShenandoahWorkerTimingsTracker(ShenandoahPhaseTimings::Phase phase, 293 ShenandoahPhaseTimings::ParPhase par_phase, uint worker_id) : 294 _timings(ShenandoahHeap::heap()->phase_timings()), 295 _phase(phase), _par_phase(par_phase), _worker_id(worker_id) { 296 297 assert(_timings->worker_data(_phase, _par_phase)->get(_worker_id) == ShenandoahWorkerData::uninitialized(), 298 "Should not be set yet: %s", ShenandoahPhaseTimings::phase_name(_timings->worker_par_phase(_phase, _par_phase))); 299 _start_time = os::elapsedTime(); 300 } 301 302 ShenandoahWorkerTimingsTracker::~ShenandoahWorkerTimingsTracker() { 303 _timings->worker_data(_phase, _par_phase)->set(_worker_id, os::elapsedTime() - _start_time); 304 }