1.1 --- /dev/null Thu Jan 01 00:00:00 1970 +0000
1.2 +++ b/src/share/vm/gc_implementation/shared/gcTimer.cpp Wed Apr 27 01:25:04 2016 +0800
1.3 @@ -0,0 +1,369 @@
1.4 +/*
1.5 + * Copyright (c) 2012, 2013, Oracle and/or its affiliates. All rights reserved.
1.6 + * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
1.7 + *
1.8 + * This code is free software; you can redistribute it and/or modify it
1.9 + * under the terms of the GNU General Public License version 2 only, as
1.10 + * published by the Free Software Foundation.
1.11 + *
1.12 + * This code is distributed in the hope that it will be useful, but WITHOUT
1.13 + * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or
1.14 + * FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License
1.15 + * version 2 for more details (a copy is included in the LICENSE file that
1.16 + * accompanied this code).
1.17 + *
1.18 + * You should have received a copy of the GNU General Public License version
1.19 + * 2 along with this work; if not, write to the Free Software Foundation,
1.20 + * Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA.
1.21 + *
1.22 + * Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA
1.23 + * or visit www.oracle.com if you need additional information or have any
1.24 + * questions.
1.25 + *
1.26 + */
1.27 +
1.28 +#include "precompiled.hpp"
1.29 +#include "gc_implementation/shared/gcTimer.hpp"
1.30 +#include "utilities/growableArray.hpp"
1.31 +#include "utilities/ticks.inline.hpp"
1.32 +
1.33 +// the "time" parameter for most functions
1.34 +// has a default value set by Ticks::now()
1.35 +
1.36 +void GCTimer::register_gc_start(const Ticks& time) {
1.37 + _time_partitions.clear();
1.38 + _gc_start = time;
1.39 +}
1.40 +
1.41 +void GCTimer::register_gc_end(const Ticks& time) {
1.42 + assert(!_time_partitions.has_active_phases(),
1.43 + "We should have ended all started phases, before ending the GC");
1.44 +
1.45 + _gc_end = time;
1.46 +}
1.47 +
1.48 +void GCTimer::register_gc_pause_start(const char* name, const Ticks& time) {
1.49 + _time_partitions.report_gc_phase_start(name, time);
1.50 +}
1.51 +
1.52 +void GCTimer::register_gc_pause_end(const Ticks& time) {
1.53 + _time_partitions.report_gc_phase_end(time);
1.54 +}
1.55 +
1.56 +void GCTimer::register_gc_phase_start(const char* name, const Ticks& time) {
1.57 + _time_partitions.report_gc_phase_start(name, time);
1.58 +}
1.59 +
1.60 +void GCTimer::register_gc_phase_end(const Ticks& time) {
1.61 + _time_partitions.report_gc_phase_end(time);
1.62 +}
1.63 +
1.64 +void STWGCTimer::register_gc_start(const Ticks& time) {
1.65 + GCTimer::register_gc_start(time);
1.66 + register_gc_pause_start("GC Pause", time);
1.67 +}
1.68 +
1.69 +void STWGCTimer::register_gc_end(const Ticks& time) {
1.70 + register_gc_pause_end(time);
1.71 + GCTimer::register_gc_end(time);
1.72 +}
1.73 +
1.74 +void ConcurrentGCTimer::register_gc_pause_start(const char* name) {
1.75 + GCTimer::register_gc_pause_start(name);
1.76 +}
1.77 +
1.78 +void ConcurrentGCTimer::register_gc_pause_end() {
1.79 + GCTimer::register_gc_pause_end();
1.80 +}
1.81 +
1.82 +void PhasesStack::clear() {
1.83 + _next_phase_level = 0;
1.84 +}
1.85 +
1.86 +void PhasesStack::push(int phase_index) {
1.87 + assert(_next_phase_level < PHASE_LEVELS, "Overflow");
1.88 +
1.89 + _phase_indices[_next_phase_level] = phase_index;
1.90 +
1.91 + _next_phase_level++;
1.92 +}
1.93 +
1.94 +int PhasesStack::pop() {
1.95 + assert(_next_phase_level > 0, "Underflow");
1.96 +
1.97 + _next_phase_level--;
1.98 +
1.99 + return _phase_indices[_next_phase_level];
1.100 +}
1.101 +
1.102 +int PhasesStack::count() const {
1.103 + return _next_phase_level;
1.104 +}
1.105 +
1.106 +
1.107 +TimePartitions::TimePartitions() {
1.108 + _phases = new (ResourceObj::C_HEAP, mtGC) GrowableArray<PausePhase>(INITIAL_CAPACITY, true, mtGC);
1.109 + clear();
1.110 +}
1.111 +
1.112 +TimePartitions::~TimePartitions() {
1.113 + delete _phases;
1.114 + _phases = NULL;
1.115 +}
1.116 +
1.117 +void TimePartitions::clear() {
1.118 + _phases->clear();
1.119 + _active_phases.clear();
1.120 + _sum_of_pauses = Tickspan();
1.121 + _longest_pause = Tickspan();
1.122 +}
1.123 +
1.124 +void TimePartitions::report_gc_phase_start(const char* name, const Ticks& time) {
1.125 + assert(_phases->length() <= 1000, "Too many recored phases?");
1.126 +
1.127 + int level = _active_phases.count();
1.128 +
1.129 + PausePhase phase;
1.130 + phase.set_level(level);
1.131 + phase.set_name(name);
1.132 + phase.set_start(time);
1.133 +
1.134 + int index = _phases->append(phase);
1.135 +
1.136 + _active_phases.push(index);
1.137 +}
1.138 +
1.139 +void TimePartitions::update_statistics(GCPhase* phase) {
1.140 + // FIXME: This should only be done for pause phases
1.141 + if (phase->level() == 0) {
1.142 + const Tickspan pause = phase->end() - phase->start();
1.143 + _sum_of_pauses += pause;
1.144 + _longest_pause = MAX2(pause, _longest_pause);
1.145 + }
1.146 +}
1.147 +
1.148 +void TimePartitions::report_gc_phase_end(const Ticks& time) {
1.149 + int phase_index = _active_phases.pop();
1.150 + GCPhase* phase = _phases->adr_at(phase_index);
1.151 + phase->set_end(time);
1.152 + update_statistics(phase);
1.153 +}
1.154 +
1.155 +int TimePartitions::num_phases() const {
1.156 + return _phases->length();
1.157 +}
1.158 +
1.159 +GCPhase* TimePartitions::phase_at(int index) const {
1.160 + assert(index >= 0, "Out of bounds");
1.161 + assert(index < _phases->length(), "Out of bounds");
1.162 +
1.163 + return _phases->adr_at(index);
1.164 +}
1.165 +
1.166 +bool TimePartitions::has_active_phases() {
1.167 + return _active_phases.count() > 0;
1.168 +}
1.169 +
1.170 +bool TimePartitionPhasesIterator::has_next() {
1.171 + return _next < _time_partitions->num_phases();
1.172 +}
1.173 +
1.174 +GCPhase* TimePartitionPhasesIterator::next() {
1.175 + assert(has_next(), "Must have phases left");
1.176 + return _time_partitions->phase_at(_next++);
1.177 +}
1.178 +
1.179 +
1.180 +/////////////// Unit tests ///////////////
1.181 +
1.182 +#ifndef PRODUCT
1.183 +
1.184 +class TimePartitionPhasesIteratorTest {
1.185 + public:
1.186 + static void all() {
1.187 + one_pause();
1.188 + two_pauses();
1.189 + one_sub_pause_phase();
1.190 + many_sub_pause_phases();
1.191 + many_sub_pause_phases2();
1.192 + max_nested_pause_phases();
1.193 + }
1.194 +
1.195 + static void validate_pause_phase(GCPhase* phase, int level, const char* name, const Ticks& start, const Ticks& end) {
1.196 + assert(phase->level() == level, "Incorrect level");
1.197 + assert(strcmp(phase->name(), name) == 0, "Incorrect name");
1.198 + assert(phase->start() == start, "Incorrect start");
1.199 + assert(phase->end() == end, "Incorrect end");
1.200 + }
1.201 +
1.202 + static void one_pause() {
1.203 + TimePartitions time_partitions;
1.204 + time_partitions.report_gc_phase_start("PausePhase", 2);
1.205 + time_partitions.report_gc_phase_end(8);
1.206 +
1.207 + TimePartitionPhasesIterator iter(&time_partitions);
1.208 +
1.209 + validate_pause_phase(iter.next(), 0, "PausePhase", 2, 8);
1.210 + assert(time_partitions.sum_of_pauses() == Ticks(8) - Ticks(2), "Incorrect");
1.211 + assert(time_partitions.longest_pause() == Ticks(8) - Ticks(2), "Incorrect");
1.212 +
1.213 + assert(!iter.has_next(), "Too many elements");
1.214 + }
1.215 +
1.216 + static void two_pauses() {
1.217 + TimePartitions time_partitions;
1.218 + time_partitions.report_gc_phase_start("PausePhase1", 2);
1.219 + time_partitions.report_gc_phase_end(3);
1.220 + time_partitions.report_gc_phase_start("PausePhase2", 4);
1.221 + time_partitions.report_gc_phase_end(6);
1.222 +
1.223 + TimePartitionPhasesIterator iter(&time_partitions);
1.224 +
1.225 + validate_pause_phase(iter.next(), 0, "PausePhase1", 2, 3);
1.226 + validate_pause_phase(iter.next(), 0, "PausePhase2", 4, 6);
1.227 +
1.228 + assert(time_partitions.sum_of_pauses() == Ticks(3) - Ticks(0), "Incorrect");
1.229 + assert(time_partitions.longest_pause() == Ticks(2) - Ticks(0), "Incorrect");
1.230 +
1.231 + assert(!iter.has_next(), "Too many elements");
1.232 + }
1.233 +
1.234 + static void one_sub_pause_phase() {
1.235 + TimePartitions time_partitions;
1.236 + time_partitions.report_gc_phase_start("PausePhase", 2);
1.237 + time_partitions.report_gc_phase_start("SubPhase", 3);
1.238 + time_partitions.report_gc_phase_end(4);
1.239 + time_partitions.report_gc_phase_end(5);
1.240 +
1.241 + TimePartitionPhasesIterator iter(&time_partitions);
1.242 +
1.243 + validate_pause_phase(iter.next(), 0, "PausePhase", 2, 5);
1.244 + validate_pause_phase(iter.next(), 1, "SubPhase", 3, 4);
1.245 +
1.246 + assert(time_partitions.sum_of_pauses() == Ticks(3) - Ticks(0), "Incorrect");
1.247 + assert(time_partitions.longest_pause() == Ticks(3) - Ticks(0), "Incorrect");
1.248 +
1.249 + assert(!iter.has_next(), "Too many elements");
1.250 + }
1.251 +
1.252 + static void max_nested_pause_phases() {
1.253 + TimePartitions time_partitions;
1.254 + time_partitions.report_gc_phase_start("PausePhase", 2);
1.255 + time_partitions.report_gc_phase_start("SubPhase1", 3);
1.256 + time_partitions.report_gc_phase_start("SubPhase2", 4);
1.257 + time_partitions.report_gc_phase_start("SubPhase3", 5);
1.258 + time_partitions.report_gc_phase_end(6);
1.259 + time_partitions.report_gc_phase_end(7);
1.260 + time_partitions.report_gc_phase_end(8);
1.261 + time_partitions.report_gc_phase_end(9);
1.262 +
1.263 + TimePartitionPhasesIterator iter(&time_partitions);
1.264 +
1.265 + validate_pause_phase(iter.next(), 0, "PausePhase", 2, 9);
1.266 + validate_pause_phase(iter.next(), 1, "SubPhase1", 3, 8);
1.267 + validate_pause_phase(iter.next(), 2, "SubPhase2", 4, 7);
1.268 + validate_pause_phase(iter.next(), 3, "SubPhase3", 5, 6);
1.269 +
1.270 + assert(time_partitions.sum_of_pauses() == Ticks(7) - Ticks(0), "Incorrect");
1.271 + assert(time_partitions.longest_pause() == Ticks(7) - Ticks(0), "Incorrect");
1.272 +
1.273 + assert(!iter.has_next(), "Too many elements");
1.274 + }
1.275 +
1.276 + static void many_sub_pause_phases() {
1.277 + TimePartitions time_partitions;
1.278 + time_partitions.report_gc_phase_start("PausePhase", 2);
1.279 +
1.280 + time_partitions.report_gc_phase_start("SubPhase1", 3);
1.281 + time_partitions.report_gc_phase_end(4);
1.282 + time_partitions.report_gc_phase_start("SubPhase2", 5);
1.283 + time_partitions.report_gc_phase_end(6);
1.284 + time_partitions.report_gc_phase_start("SubPhase3", 7);
1.285 + time_partitions.report_gc_phase_end(8);
1.286 + time_partitions.report_gc_phase_start("SubPhase4", 9);
1.287 + time_partitions.report_gc_phase_end(10);
1.288 +
1.289 + time_partitions.report_gc_phase_end(11);
1.290 +
1.291 + TimePartitionPhasesIterator iter(&time_partitions);
1.292 +
1.293 + validate_pause_phase(iter.next(), 0, "PausePhase", 2, 11);
1.294 + validate_pause_phase(iter.next(), 1, "SubPhase1", 3, 4);
1.295 + validate_pause_phase(iter.next(), 1, "SubPhase2", 5, 6);
1.296 + validate_pause_phase(iter.next(), 1, "SubPhase3", 7, 8);
1.297 + validate_pause_phase(iter.next(), 1, "SubPhase4", 9, 10);
1.298 +
1.299 + assert(time_partitions.sum_of_pauses() == Ticks(9) - Ticks(0), "Incorrect");
1.300 + assert(time_partitions.longest_pause() == Ticks(9) - Ticks(0), "Incorrect");
1.301 +
1.302 + assert(!iter.has_next(), "Too many elements");
1.303 + }
1.304 +
1.305 + static void many_sub_pause_phases2() {
1.306 + TimePartitions time_partitions;
1.307 + time_partitions.report_gc_phase_start("PausePhase", 2);
1.308 +
1.309 + time_partitions.report_gc_phase_start("SubPhase1", 3);
1.310 + time_partitions.report_gc_phase_start("SubPhase11", 4);
1.311 + time_partitions.report_gc_phase_end(5);
1.312 + time_partitions.report_gc_phase_start("SubPhase12", 6);
1.313 + time_partitions.report_gc_phase_end(7);
1.314 + time_partitions.report_gc_phase_end(8);
1.315 + time_partitions.report_gc_phase_start("SubPhase2", 9);
1.316 + time_partitions.report_gc_phase_start("SubPhase21", 10);
1.317 + time_partitions.report_gc_phase_end(11);
1.318 + time_partitions.report_gc_phase_start("SubPhase22", 12);
1.319 + time_partitions.report_gc_phase_end(13);
1.320 + time_partitions.report_gc_phase_end(14);
1.321 + time_partitions.report_gc_phase_start("SubPhase3", 15);
1.322 + time_partitions.report_gc_phase_end(16);
1.323 +
1.324 + time_partitions.report_gc_phase_end(17);
1.325 +
1.326 + TimePartitionPhasesIterator iter(&time_partitions);
1.327 +
1.328 + validate_pause_phase(iter.next(), 0, "PausePhase", 2, 17);
1.329 + validate_pause_phase(iter.next(), 1, "SubPhase1", 3, 8);
1.330 + validate_pause_phase(iter.next(), 2, "SubPhase11", 4, 5);
1.331 + validate_pause_phase(iter.next(), 2, "SubPhase12", 6, 7);
1.332 + validate_pause_phase(iter.next(), 1, "SubPhase2", 9, 14);
1.333 + validate_pause_phase(iter.next(), 2, "SubPhase21", 10, 11);
1.334 + validate_pause_phase(iter.next(), 2, "SubPhase22", 12, 13);
1.335 + validate_pause_phase(iter.next(), 1, "SubPhase3", 15, 16);
1.336 +
1.337 + assert(time_partitions.sum_of_pauses() == Ticks(15) - Ticks(0), "Incorrect");
1.338 + assert(time_partitions.longest_pause() == Ticks(15) - Ticks(0), "Incorrect");
1.339 +
1.340 + assert(!iter.has_next(), "Too many elements");
1.341 + }
1.342 +};
1.343 +
1.344 +class GCTimerTest {
1.345 +public:
1.346 + static void all() {
1.347 + gc_start();
1.348 + gc_end();
1.349 + }
1.350 +
1.351 + static void gc_start() {
1.352 + GCTimer gc_timer;
1.353 + gc_timer.register_gc_start(1);
1.354 +
1.355 + assert(gc_timer.gc_start() == 1, "Incorrect");
1.356 + }
1.357 +
1.358 + static void gc_end() {
1.359 + GCTimer gc_timer;
1.360 + gc_timer.register_gc_start(1);
1.361 + gc_timer.register_gc_end(2);
1.362 +
1.363 + assert(gc_timer.gc_end() == 2, "Incorrect");
1.364 + }
1.365 +};
1.366 +
1.367 +void GCTimerAllTest::all() {
1.368 + GCTimerTest::all();
1.369 + TimePartitionPhasesIteratorTest::all();
1.370 +}
1.371 +
1.372 +#endif
