1 /* 2 * Copyright (c) 2012, 2013, 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 #include "precompiled.hpp" 26 #include "gc_implementation/shared/gcTimer.hpp" 27 #include "utilities/growableArray.hpp" 28 #include "utilities/ticks.inline.hpp" 29 30 // the "time" parameter for most functions 31 // has a default value set by Ticks::now() 32 33 void GCTimer::register_gc_start(const Ticks& time) { 34 _time_partitions.clear(); 35 _gc_start = time; 36 } 37 38 void GCTimer::register_gc_end(const Ticks& time) { 39 assert(!_time_partitions.has_active_phases(), 40 "We should have ended all started phases, before ending the GC"); 41 42 _gc_end = time; 43 } 44 45 void GCTimer::register_gc_pause_start(const char* name, const Ticks& time) { 46 _time_partitions.report_gc_phase_start(name, time); 47 } 48 49 void GCTimer::register_gc_pause_end(const Ticks& time) { 50 _time_partitions.report_gc_phase_end(time); 51 } 52 53 void GCTimer::register_gc_phase_start(const char* name, const Ticks& time) { 54 _time_partitions.report_gc_phase_start(name, time); 55 } 56 57 void GCTimer::register_gc_phase_end(const Ticks& time) { 58 _time_partitions.report_gc_phase_end(time); 59 } 60 61 void STWGCTimer::register_gc_start(const Ticks& time) { 62 GCTimer::register_gc_start(time); 63 register_gc_pause_start("GC Pause", time); 64 } 65 66 void STWGCTimer::register_gc_end(const Ticks& time) { 67 register_gc_pause_end(time); 68 GCTimer::register_gc_end(time); 69 } 70 71 void ConcurrentGCTimer::register_gc_pause_start(const char* name) { 72 GCTimer::register_gc_pause_start(name); 73 } 74 75 void ConcurrentGCTimer::register_gc_pause_end() { 76 GCTimer::register_gc_pause_end(); 77 } 78 79 void PhasesStack::clear() { 80 _next_phase_level = 0; 81 } 82 83 void PhasesStack::push(int phase_index) { 84 assert(_next_phase_level < PHASE_LEVELS, "Overflow"); 85 86 _phase_indices[_next_phase_level] = phase_index; 87 88 _next_phase_level++; 89 } 90 91 int PhasesStack::pop() { 92 assert(_next_phase_level > 0, "Underflow"); 93 94 _next_phase_level--; 95 96 return _phase_indices[_next_phase_level]; 97 } 98 99 int PhasesStack::count() const { 100 return _next_phase_level; 101 } 102 103 104 TimePartitions::TimePartitions() { 105 _phases = new (ResourceObj::C_HEAP, mtGC) GrowableArray<PausePhase>(INITIAL_CAPACITY, true, mtGC); 106 clear(); 107 } 108 109 TimePartitions::~TimePartitions() { 110 delete _phases; 111 _phases = NULL; 112 } 113 114 void TimePartitions::clear() { 115 _phases->clear(); 116 _active_phases.clear(); 117 _sum_of_pauses = Tickspan(); 118 _longest_pause = Tickspan(); 119 } 120 121 void TimePartitions::report_gc_phase_start(const char* name, const Ticks& time) { 122 assert(_phases->length() <= 1000, "Too many recored phases?"); 123 124 int level = _active_phases.count(); 125 126 PausePhase phase; 127 phase.set_level(level); 128 phase.set_name(name); 129 phase.set_start(time); 130 131 int index = _phases->append(phase); 132 133 _active_phases.push(index); 134 } 135 136 void TimePartitions::update_statistics(GCPhase* phase) { 137 // FIXME: This should only be done for pause phases 138 if (phase->level() == 0) { 139 const Tickspan pause = phase->end() - phase->start(); 140 _sum_of_pauses += pause; 141 _longest_pause = MAX2(pause, _longest_pause); 142 } 143 } 144 145 void TimePartitions::report_gc_phase_end(const Ticks& time) { 146 int phase_index = _active_phases.pop(); 147 GCPhase* phase = _phases->adr_at(phase_index); 148 phase->set_end(time); 149 update_statistics(phase); 150 } 151 152 int TimePartitions::num_phases() const { 153 return _phases->length(); 154 } 155 156 GCPhase* TimePartitions::phase_at(int index) const { 157 assert(index >= 0, "Out of bounds"); 158 assert(index < _phases->length(), "Out of bounds"); 159 160 return _phases->adr_at(index); 161 } 162 163 bool TimePartitions::has_active_phases() { 164 return _active_phases.count() > 0; 165 } 166 167 bool TimePartitionPhasesIterator::has_next() { 168 return _next < _time_partitions->num_phases(); 169 } 170 171 GCPhase* TimePartitionPhasesIterator::next() { 172 assert(has_next(), "Must have phases left"); 173 return _time_partitions->phase_at(_next++); 174 } 175 176 177 /////////////// Unit tests /////////////// 178 179 #ifndef PRODUCT 180 181 class TimePartitionPhasesIteratorTest { 182 public: 183 static void all() { 184 one_pause(); 185 two_pauses(); 186 one_sub_pause_phase(); 187 many_sub_pause_phases(); 188 many_sub_pause_phases2(); 189 max_nested_pause_phases(); 190 } 191 192 static void validate_pause_phase(GCPhase* phase, int level, const char* name, const Ticks& start, const Ticks& end) { 193 assert(phase->level() == level, "Incorrect level"); 194 assert(strcmp(phase->name(), name) == 0, "Incorrect name"); 195 assert(phase->start() == start, "Incorrect start"); 196 assert(phase->end() == end, "Incorrect end"); 197 } 198 199 static void one_pause() { 200 TimePartitions time_partitions; 201 time_partitions.report_gc_phase_start("PausePhase", 2); 202 time_partitions.report_gc_phase_end(8); 203 204 TimePartitionPhasesIterator iter(&time_partitions); 205 206 validate_pause_phase(iter.next(), 0, "PausePhase", 2, 8); 207 assert(time_partitions.sum_of_pauses() == Ticks(8) - Ticks(2), "Incorrect"); 208 assert(time_partitions.longest_pause() == Ticks(8) - Ticks(2), "Incorrect"); 209 210 assert(!iter.has_next(), "Too many elements"); 211 } 212 213 static void two_pauses() { 214 TimePartitions time_partitions; 215 time_partitions.report_gc_phase_start("PausePhase1", 2); 216 time_partitions.report_gc_phase_end(3); 217 time_partitions.report_gc_phase_start("PausePhase2", 4); 218 time_partitions.report_gc_phase_end(6); 219 220 TimePartitionPhasesIterator iter(&time_partitions); 221 222 validate_pause_phase(iter.next(), 0, "PausePhase1", 2, 3); 223 validate_pause_phase(iter.next(), 0, "PausePhase2", 4, 6); 224 225 assert(time_partitions.sum_of_pauses() == Ticks(3) - Ticks(0), "Incorrect"); 226 assert(time_partitions.longest_pause() == Ticks(2) - Ticks(0), "Incorrect"); 227 228 assert(!iter.has_next(), "Too many elements"); 229 } 230 231 static void one_sub_pause_phase() { 232 TimePartitions time_partitions; 233 time_partitions.report_gc_phase_start("PausePhase", 2); 234 time_partitions.report_gc_phase_start("SubPhase", 3); 235 time_partitions.report_gc_phase_end(4); 236 time_partitions.report_gc_phase_end(5); 237 238 TimePartitionPhasesIterator iter(&time_partitions); 239 240 validate_pause_phase(iter.next(), 0, "PausePhase", 2, 5); 241 validate_pause_phase(iter.next(), 1, "SubPhase", 3, 4); 242 243 assert(time_partitions.sum_of_pauses() == Ticks(3) - Ticks(0), "Incorrect"); 244 assert(time_partitions.longest_pause() == Ticks(3) - Ticks(0), "Incorrect"); 245 246 assert(!iter.has_next(), "Too many elements"); 247 } 248 249 static void max_nested_pause_phases() { 250 TimePartitions time_partitions; 251 time_partitions.report_gc_phase_start("PausePhase", 2); 252 time_partitions.report_gc_phase_start("SubPhase1", 3); 253 time_partitions.report_gc_phase_start("SubPhase2", 4); 254 time_partitions.report_gc_phase_start("SubPhase3", 5); 255 time_partitions.report_gc_phase_end(6); 256 time_partitions.report_gc_phase_end(7); 257 time_partitions.report_gc_phase_end(8); 258 time_partitions.report_gc_phase_end(9); 259 260 TimePartitionPhasesIterator iter(&time_partitions); 261 262 validate_pause_phase(iter.next(), 0, "PausePhase", 2, 9); 263 validate_pause_phase(iter.next(), 1, "SubPhase1", 3, 8); 264 validate_pause_phase(iter.next(), 2, "SubPhase2", 4, 7); 265 validate_pause_phase(iter.next(), 3, "SubPhase3", 5, 6); 266 267 assert(time_partitions.sum_of_pauses() == Ticks(7) - Ticks(0), "Incorrect"); 268 assert(time_partitions.longest_pause() == Ticks(7) - Ticks(0), "Incorrect"); 269 270 assert(!iter.has_next(), "Too many elements"); 271 } 272 273 static void many_sub_pause_phases() { 274 TimePartitions time_partitions; 275 time_partitions.report_gc_phase_start("PausePhase", 2); 276 277 time_partitions.report_gc_phase_start("SubPhase1", 3); 278 time_partitions.report_gc_phase_end(4); 279 time_partitions.report_gc_phase_start("SubPhase2", 5); 280 time_partitions.report_gc_phase_end(6); 281 time_partitions.report_gc_phase_start("SubPhase3", 7); 282 time_partitions.report_gc_phase_end(8); 283 time_partitions.report_gc_phase_start("SubPhase4", 9); 284 time_partitions.report_gc_phase_end(10); 285 286 time_partitions.report_gc_phase_end(11); 287 288 TimePartitionPhasesIterator iter(&time_partitions); 289 290 validate_pause_phase(iter.next(), 0, "PausePhase", 2, 11); 291 validate_pause_phase(iter.next(), 1, "SubPhase1", 3, 4); 292 validate_pause_phase(iter.next(), 1, "SubPhase2", 5, 6); 293 validate_pause_phase(iter.next(), 1, "SubPhase3", 7, 8); 294 validate_pause_phase(iter.next(), 1, "SubPhase4", 9, 10); 295 296 assert(time_partitions.sum_of_pauses() == Ticks(9) - Ticks(0), "Incorrect"); 297 assert(time_partitions.longest_pause() == Ticks(9) - Ticks(0), "Incorrect"); 298 299 assert(!iter.has_next(), "Too many elements"); 300 } 301 302 static void many_sub_pause_phases2() { 303 TimePartitions time_partitions; 304 time_partitions.report_gc_phase_start("PausePhase", 2); 305 306 time_partitions.report_gc_phase_start("SubPhase1", 3); 307 time_partitions.report_gc_phase_start("SubPhase11", 4); 308 time_partitions.report_gc_phase_end(5); 309 time_partitions.report_gc_phase_start("SubPhase12", 6); 310 time_partitions.report_gc_phase_end(7); 311 time_partitions.report_gc_phase_end(8); 312 time_partitions.report_gc_phase_start("SubPhase2", 9); 313 time_partitions.report_gc_phase_start("SubPhase21", 10); 314 time_partitions.report_gc_phase_end(11); 315 time_partitions.report_gc_phase_start("SubPhase22", 12); 316 time_partitions.report_gc_phase_end(13); 317 time_partitions.report_gc_phase_end(14); 318 time_partitions.report_gc_phase_start("SubPhase3", 15); 319 time_partitions.report_gc_phase_end(16); 320 321 time_partitions.report_gc_phase_end(17); 322 323 TimePartitionPhasesIterator iter(&time_partitions); 324 325 validate_pause_phase(iter.next(), 0, "PausePhase", 2, 17); 326 validate_pause_phase(iter.next(), 1, "SubPhase1", 3, 8); 327 validate_pause_phase(iter.next(), 2, "SubPhase11", 4, 5); 328 validate_pause_phase(iter.next(), 2, "SubPhase12", 6, 7); 329 validate_pause_phase(iter.next(), 1, "SubPhase2", 9, 14); 330 validate_pause_phase(iter.next(), 2, "SubPhase21", 10, 11); 331 validate_pause_phase(iter.next(), 2, "SubPhase22", 12, 13); 332 validate_pause_phase(iter.next(), 1, "SubPhase3", 15, 16); 333 334 assert(time_partitions.sum_of_pauses() == Ticks(15) - Ticks(0), "Incorrect"); 335 assert(time_partitions.longest_pause() == Ticks(15) - Ticks(0), "Incorrect"); 336 337 assert(!iter.has_next(), "Too many elements"); 338 } 339 }; 340 341 class GCTimerTest { 342 public: 343 static void all() { 344 gc_start(); 345 gc_end(); 346 } 347 348 static void gc_start() { 349 GCTimer gc_timer; 350 gc_timer.register_gc_start(1); 351 352 assert(gc_timer.gc_start() == 1, "Incorrect"); 353 } 354 355 static void gc_end() { 356 GCTimer gc_timer; 357 gc_timer.register_gc_start(1); 358 gc_timer.register_gc_end(2); 359 360 assert(gc_timer.gc_end() == 2, "Incorrect"); 361 } 362 }; 363 364 void GCTimerAllTest::all() { 365 GCTimerTest::all(); 366 TimePartitionPhasesIteratorTest::all(); 367 } 368 369 #endif