Mon, 12 Aug 2019 18:30:40 +0300
8223147: JFR Backport
8199712: Flight Recorder
8203346: JFR: Inconsistent signature of jfr_add_string_constant
8195817: JFR.stop should require name of recording
8195818: JFR.start should increase autogenerated name by one
8195819: Remove recording=x from jcmd JFR.check output
8203921: JFR thread sampling is missing fixes from JDK-8194552
8203929: Limit amount of data for JFR.dump
8203664: JFR start failure after AppCDS archive created with JFR StartFlightRecording
8003209: JFR events for network utilization
8207392: [PPC64] Implement JFR profiling
8202835: jfr/event/os/TestSystemProcess.java fails on missing events
Summary: Backport JFR from JDK11. Initial integration
Reviewed-by: neugens
sla@5237 | 1 | /* |
sla@5237 | 2 | * Copyright (c) 2012, 2013, Oracle and/or its affiliates. All rights reserved. |
sla@5237 | 3 | * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER. |
sla@5237 | 4 | * |
sla@5237 | 5 | * This code is free software; you can redistribute it and/or modify it |
sla@5237 | 6 | * under the terms of the GNU General Public License version 2 only, as |
sla@5237 | 7 | * published by the Free Software Foundation. |
sla@5237 | 8 | * |
sla@5237 | 9 | * This code is distributed in the hope that it will be useful, but WITHOUT |
sla@5237 | 10 | * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or |
sla@5237 | 11 | * FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License |
sla@5237 | 12 | * version 2 for more details (a copy is included in the LICENSE file that |
sla@5237 | 13 | * accompanied this code). |
sla@5237 | 14 | * |
sla@5237 | 15 | * You should have received a copy of the GNU General Public License version |
sla@5237 | 16 | * 2 along with this work; if not, write to the Free Software Foundation, |
sla@5237 | 17 | * Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA. |
sla@5237 | 18 | * |
sla@5237 | 19 | * Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA |
sla@5237 | 20 | * or visit www.oracle.com if you need additional information or have any |
sla@5237 | 21 | * questions. |
sla@5237 | 22 | * |
sla@5237 | 23 | */ |
sla@5237 | 24 | |
sla@5237 | 25 | #include "precompiled.hpp" |
sla@5237 | 26 | #include "gc_implementation/shared/gcTimer.hpp" |
sla@5237 | 27 | #include "utilities/growableArray.hpp" |
apetushkov@9858 | 28 | #include "utilities/ticks.hpp" |
sla@5237 | 29 | |
mgronlun@6131 | 30 | // the "time" parameter for most functions |
mgronlun@6131 | 31 | // has a default value set by Ticks::now() |
mgronlun@6131 | 32 | |
mgronlun@6131 | 33 | void GCTimer::register_gc_start(const Ticks& time) { |
sla@5237 | 34 | _time_partitions.clear(); |
sla@5237 | 35 | _gc_start = time; |
sla@5237 | 36 | } |
sla@5237 | 37 | |
mgronlun@6131 | 38 | void GCTimer::register_gc_end(const Ticks& time) { |
sla@5237 | 39 | assert(!_time_partitions.has_active_phases(), |
sla@5237 | 40 | "We should have ended all started phases, before ending the GC"); |
sla@5237 | 41 | |
sla@5237 | 42 | _gc_end = time; |
sla@5237 | 43 | } |
sla@5237 | 44 | |
mgronlun@6131 | 45 | void GCTimer::register_gc_pause_start(const char* name, const Ticks& time) { |
sla@5237 | 46 | _time_partitions.report_gc_phase_start(name, time); |
sla@5237 | 47 | } |
sla@5237 | 48 | |
mgronlun@6131 | 49 | void GCTimer::register_gc_pause_end(const Ticks& time) { |
sla@5237 | 50 | _time_partitions.report_gc_phase_end(time); |
sla@5237 | 51 | } |
sla@5237 | 52 | |
mgronlun@6131 | 53 | void GCTimer::register_gc_phase_start(const char* name, const Ticks& time) { |
sla@5237 | 54 | _time_partitions.report_gc_phase_start(name, time); |
sla@5237 | 55 | } |
sla@5237 | 56 | |
mgronlun@6131 | 57 | void GCTimer::register_gc_phase_end(const Ticks& time) { |
sla@5237 | 58 | _time_partitions.report_gc_phase_end(time); |
sla@5237 | 59 | } |
sla@5237 | 60 | |
mgronlun@6131 | 61 | void STWGCTimer::register_gc_start(const Ticks& time) { |
sla@5237 | 62 | GCTimer::register_gc_start(time); |
sla@5237 | 63 | register_gc_pause_start("GC Pause", time); |
sla@5237 | 64 | } |
sla@5237 | 65 | |
mgronlun@6131 | 66 | void STWGCTimer::register_gc_end(const Ticks& time) { |
sla@5237 | 67 | register_gc_pause_end(time); |
sla@5237 | 68 | GCTimer::register_gc_end(time); |
sla@5237 | 69 | } |
sla@5237 | 70 | |
mgronlun@6131 | 71 | void ConcurrentGCTimer::register_gc_pause_start(const char* name) { |
mgronlun@6131 | 72 | GCTimer::register_gc_pause_start(name); |
sla@5237 | 73 | } |
sla@5237 | 74 | |
mgronlun@6131 | 75 | void ConcurrentGCTimer::register_gc_pause_end() { |
mgronlun@6131 | 76 | GCTimer::register_gc_pause_end(); |
sla@5237 | 77 | } |
sla@5237 | 78 | |
sla@5237 | 79 | void PhasesStack::clear() { |
sla@5237 | 80 | _next_phase_level = 0; |
sla@5237 | 81 | } |
sla@5237 | 82 | |
sla@5237 | 83 | void PhasesStack::push(int phase_index) { |
sla@5237 | 84 | assert(_next_phase_level < PHASE_LEVELS, "Overflow"); |
sla@5237 | 85 | |
sla@5237 | 86 | _phase_indices[_next_phase_level] = phase_index; |
sla@5237 | 87 | |
sla@5237 | 88 | _next_phase_level++; |
sla@5237 | 89 | } |
sla@5237 | 90 | |
sla@5237 | 91 | int PhasesStack::pop() { |
sla@5237 | 92 | assert(_next_phase_level > 0, "Underflow"); |
sla@5237 | 93 | |
sla@5237 | 94 | _next_phase_level--; |
sla@5237 | 95 | |
sla@5237 | 96 | return _phase_indices[_next_phase_level]; |
sla@5237 | 97 | } |
sla@5237 | 98 | |
sla@5237 | 99 | int PhasesStack::count() const { |
sla@5237 | 100 | return _next_phase_level; |
sla@5237 | 101 | } |
sla@5237 | 102 | |
sla@5237 | 103 | |
sla@5237 | 104 | TimePartitions::TimePartitions() { |
sla@5237 | 105 | _phases = new (ResourceObj::C_HEAP, mtGC) GrowableArray<PausePhase>(INITIAL_CAPACITY, true, mtGC); |
sla@5237 | 106 | clear(); |
sla@5237 | 107 | } |
sla@5237 | 108 | |
sla@5237 | 109 | TimePartitions::~TimePartitions() { |
sla@5237 | 110 | delete _phases; |
sla@5237 | 111 | _phases = NULL; |
sla@5237 | 112 | } |
sla@5237 | 113 | |
sla@5237 | 114 | void TimePartitions::clear() { |
sla@5237 | 115 | _phases->clear(); |
sla@5237 | 116 | _active_phases.clear(); |
mgronlun@6131 | 117 | _sum_of_pauses = Tickspan(); |
mgronlun@6131 | 118 | _longest_pause = Tickspan(); |
sla@5237 | 119 | } |
sla@5237 | 120 | |
mgronlun@6131 | 121 | void TimePartitions::report_gc_phase_start(const char* name, const Ticks& time) { |
sla@5237 | 122 | assert(_phases->length() <= 1000, "Too many recored phases?"); |
sla@5237 | 123 | |
sla@5237 | 124 | int level = _active_phases.count(); |
sla@5237 | 125 | |
sla@5237 | 126 | PausePhase phase; |
sla@5237 | 127 | phase.set_level(level); |
sla@5237 | 128 | phase.set_name(name); |
sla@5237 | 129 | phase.set_start(time); |
sla@5237 | 130 | |
sla@5237 | 131 | int index = _phases->append(phase); |
sla@5237 | 132 | |
sla@5237 | 133 | _active_phases.push(index); |
sla@5237 | 134 | } |
sla@5237 | 135 | |
sla@5237 | 136 | void TimePartitions::update_statistics(GCPhase* phase) { |
sla@5237 | 137 | // FIXME: This should only be done for pause phases |
sla@5237 | 138 | if (phase->level() == 0) { |
mgronlun@6131 | 139 | const Tickspan pause = phase->end() - phase->start(); |
sla@5237 | 140 | _sum_of_pauses += pause; |
sla@5237 | 141 | _longest_pause = MAX2(pause, _longest_pause); |
sla@5237 | 142 | } |
sla@5237 | 143 | } |
sla@5237 | 144 | |
mgronlun@6131 | 145 | void TimePartitions::report_gc_phase_end(const Ticks& time) { |
sla@5237 | 146 | int phase_index = _active_phases.pop(); |
sla@5237 | 147 | GCPhase* phase = _phases->adr_at(phase_index); |
sla@5237 | 148 | phase->set_end(time); |
sla@5237 | 149 | update_statistics(phase); |
sla@5237 | 150 | } |
sla@5237 | 151 | |
sla@5237 | 152 | int TimePartitions::num_phases() const { |
sla@5237 | 153 | return _phases->length(); |
sla@5237 | 154 | } |
sla@5237 | 155 | |
sla@5237 | 156 | GCPhase* TimePartitions::phase_at(int index) const { |
sla@5237 | 157 | assert(index >= 0, "Out of bounds"); |
sla@5237 | 158 | assert(index < _phases->length(), "Out of bounds"); |
sla@5237 | 159 | |
sla@5237 | 160 | return _phases->adr_at(index); |
sla@5237 | 161 | } |
sla@5237 | 162 | |
sla@5237 | 163 | bool TimePartitions::has_active_phases() { |
sla@5237 | 164 | return _active_phases.count() > 0; |
sla@5237 | 165 | } |
sla@5237 | 166 | |
sla@5237 | 167 | bool TimePartitionPhasesIterator::has_next() { |
sla@5237 | 168 | return _next < _time_partitions->num_phases(); |
sla@5237 | 169 | } |
sla@5237 | 170 | |
sla@5237 | 171 | GCPhase* TimePartitionPhasesIterator::next() { |
sla@5237 | 172 | assert(has_next(), "Must have phases left"); |
sla@5237 | 173 | return _time_partitions->phase_at(_next++); |
sla@5237 | 174 | } |
sla@5237 | 175 | |
sla@5237 | 176 | |
sla@5237 | 177 | /////////////// Unit tests /////////////// |
sla@5237 | 178 | |
sla@5237 | 179 | #ifndef PRODUCT |
sla@5237 | 180 | |
sla@5237 | 181 | class TimePartitionPhasesIteratorTest { |
sla@5237 | 182 | public: |
sla@5237 | 183 | static void all() { |
sla@5237 | 184 | one_pause(); |
sla@5237 | 185 | two_pauses(); |
sla@5237 | 186 | one_sub_pause_phase(); |
sla@5237 | 187 | many_sub_pause_phases(); |
sla@5237 | 188 | many_sub_pause_phases2(); |
sla@5237 | 189 | max_nested_pause_phases(); |
sla@5237 | 190 | } |
sla@5237 | 191 | |
mgronlun@6131 | 192 | static void validate_pause_phase(GCPhase* phase, int level, const char* name, const Ticks& start, const Ticks& end) { |
sla@5237 | 193 | assert(phase->level() == level, "Incorrect level"); |
sla@5237 | 194 | assert(strcmp(phase->name(), name) == 0, "Incorrect name"); |
sla@5237 | 195 | assert(phase->start() == start, "Incorrect start"); |
sla@5237 | 196 | assert(phase->end() == end, "Incorrect end"); |
sla@5237 | 197 | } |
sla@5237 | 198 | |
sla@5237 | 199 | static void one_pause() { |
sla@5237 | 200 | TimePartitions time_partitions; |
sla@5237 | 201 | time_partitions.report_gc_phase_start("PausePhase", 2); |
sla@5237 | 202 | time_partitions.report_gc_phase_end(8); |
sla@5237 | 203 | |
sla@5237 | 204 | TimePartitionPhasesIterator iter(&time_partitions); |
sla@5237 | 205 | |
sla@5237 | 206 | validate_pause_phase(iter.next(), 0, "PausePhase", 2, 8); |
mgronlun@6131 | 207 | assert(time_partitions.sum_of_pauses() == Ticks(8) - Ticks(2), "Incorrect"); |
mgronlun@6131 | 208 | assert(time_partitions.longest_pause() == Ticks(8) - Ticks(2), "Incorrect"); |
sla@5237 | 209 | |
sla@5237 | 210 | assert(!iter.has_next(), "Too many elements"); |
sla@5237 | 211 | } |
sla@5237 | 212 | |
sla@5237 | 213 | static void two_pauses() { |
sla@5237 | 214 | TimePartitions time_partitions; |
sla@5237 | 215 | time_partitions.report_gc_phase_start("PausePhase1", 2); |
sla@5237 | 216 | time_partitions.report_gc_phase_end(3); |
sla@5237 | 217 | time_partitions.report_gc_phase_start("PausePhase2", 4); |
sla@5237 | 218 | time_partitions.report_gc_phase_end(6); |
sla@5237 | 219 | |
sla@5237 | 220 | TimePartitionPhasesIterator iter(&time_partitions); |
sla@5237 | 221 | |
sla@5237 | 222 | validate_pause_phase(iter.next(), 0, "PausePhase1", 2, 3); |
sla@5237 | 223 | validate_pause_phase(iter.next(), 0, "PausePhase2", 4, 6); |
sla@5237 | 224 | |
mgronlun@6131 | 225 | assert(time_partitions.sum_of_pauses() == Ticks(3) - Ticks(0), "Incorrect"); |
mgronlun@6131 | 226 | assert(time_partitions.longest_pause() == Ticks(2) - Ticks(0), "Incorrect"); |
sla@5237 | 227 | |
sla@5237 | 228 | assert(!iter.has_next(), "Too many elements"); |
sla@5237 | 229 | } |
sla@5237 | 230 | |
sla@5237 | 231 | static void one_sub_pause_phase() { |
sla@5237 | 232 | TimePartitions time_partitions; |
sla@5237 | 233 | time_partitions.report_gc_phase_start("PausePhase", 2); |
sla@5237 | 234 | time_partitions.report_gc_phase_start("SubPhase", 3); |
sla@5237 | 235 | time_partitions.report_gc_phase_end(4); |
sla@5237 | 236 | time_partitions.report_gc_phase_end(5); |
sla@5237 | 237 | |
sla@5237 | 238 | TimePartitionPhasesIterator iter(&time_partitions); |
sla@5237 | 239 | |
sla@5237 | 240 | validate_pause_phase(iter.next(), 0, "PausePhase", 2, 5); |
sla@5237 | 241 | validate_pause_phase(iter.next(), 1, "SubPhase", 3, 4); |
sla@5237 | 242 | |
mgronlun@6131 | 243 | assert(time_partitions.sum_of_pauses() == Ticks(3) - Ticks(0), "Incorrect"); |
mgronlun@6131 | 244 | assert(time_partitions.longest_pause() == Ticks(3) - Ticks(0), "Incorrect"); |
sla@5237 | 245 | |
sla@5237 | 246 | assert(!iter.has_next(), "Too many elements"); |
sla@5237 | 247 | } |
sla@5237 | 248 | |
sla@5237 | 249 | static void max_nested_pause_phases() { |
sla@5237 | 250 | TimePartitions time_partitions; |
sla@5237 | 251 | time_partitions.report_gc_phase_start("PausePhase", 2); |
sla@5237 | 252 | time_partitions.report_gc_phase_start("SubPhase1", 3); |
sla@5237 | 253 | time_partitions.report_gc_phase_start("SubPhase2", 4); |
sla@5237 | 254 | time_partitions.report_gc_phase_start("SubPhase3", 5); |
sla@5237 | 255 | time_partitions.report_gc_phase_end(6); |
sla@5237 | 256 | time_partitions.report_gc_phase_end(7); |
sla@5237 | 257 | time_partitions.report_gc_phase_end(8); |
sla@5237 | 258 | time_partitions.report_gc_phase_end(9); |
sla@5237 | 259 | |
sla@5237 | 260 | TimePartitionPhasesIterator iter(&time_partitions); |
sla@5237 | 261 | |
sla@5237 | 262 | validate_pause_phase(iter.next(), 0, "PausePhase", 2, 9); |
sla@5237 | 263 | validate_pause_phase(iter.next(), 1, "SubPhase1", 3, 8); |
sla@5237 | 264 | validate_pause_phase(iter.next(), 2, "SubPhase2", 4, 7); |
sla@5237 | 265 | validate_pause_phase(iter.next(), 3, "SubPhase3", 5, 6); |
sla@5237 | 266 | |
mgronlun@6131 | 267 | assert(time_partitions.sum_of_pauses() == Ticks(7) - Ticks(0), "Incorrect"); |
mgronlun@6131 | 268 | assert(time_partitions.longest_pause() == Ticks(7) - Ticks(0), "Incorrect"); |
sla@5237 | 269 | |
sla@5237 | 270 | assert(!iter.has_next(), "Too many elements"); |
sla@5237 | 271 | } |
sla@5237 | 272 | |
sla@5237 | 273 | static void many_sub_pause_phases() { |
sla@5237 | 274 | TimePartitions time_partitions; |
sla@5237 | 275 | time_partitions.report_gc_phase_start("PausePhase", 2); |
sla@5237 | 276 | |
sla@5237 | 277 | time_partitions.report_gc_phase_start("SubPhase1", 3); |
sla@5237 | 278 | time_partitions.report_gc_phase_end(4); |
sla@5237 | 279 | time_partitions.report_gc_phase_start("SubPhase2", 5); |
sla@5237 | 280 | time_partitions.report_gc_phase_end(6); |
sla@5237 | 281 | time_partitions.report_gc_phase_start("SubPhase3", 7); |
sla@5237 | 282 | time_partitions.report_gc_phase_end(8); |
sla@5237 | 283 | time_partitions.report_gc_phase_start("SubPhase4", 9); |
sla@5237 | 284 | time_partitions.report_gc_phase_end(10); |
sla@5237 | 285 | |
sla@5237 | 286 | time_partitions.report_gc_phase_end(11); |
sla@5237 | 287 | |
sla@5237 | 288 | TimePartitionPhasesIterator iter(&time_partitions); |
sla@5237 | 289 | |
sla@5237 | 290 | validate_pause_phase(iter.next(), 0, "PausePhase", 2, 11); |
sla@5237 | 291 | validate_pause_phase(iter.next(), 1, "SubPhase1", 3, 4); |
sla@5237 | 292 | validate_pause_phase(iter.next(), 1, "SubPhase2", 5, 6); |
sla@5237 | 293 | validate_pause_phase(iter.next(), 1, "SubPhase3", 7, 8); |
sla@5237 | 294 | validate_pause_phase(iter.next(), 1, "SubPhase4", 9, 10); |
sla@5237 | 295 | |
mgronlun@6131 | 296 | assert(time_partitions.sum_of_pauses() == Ticks(9) - Ticks(0), "Incorrect"); |
mgronlun@6131 | 297 | assert(time_partitions.longest_pause() == Ticks(9) - Ticks(0), "Incorrect"); |
sla@5237 | 298 | |
sla@5237 | 299 | assert(!iter.has_next(), "Too many elements"); |
sla@5237 | 300 | } |
sla@5237 | 301 | |
sla@5237 | 302 | static void many_sub_pause_phases2() { |
sla@5237 | 303 | TimePartitions time_partitions; |
sla@5237 | 304 | time_partitions.report_gc_phase_start("PausePhase", 2); |
sla@5237 | 305 | |
sla@5237 | 306 | time_partitions.report_gc_phase_start("SubPhase1", 3); |
sla@5237 | 307 | time_partitions.report_gc_phase_start("SubPhase11", 4); |
sla@5237 | 308 | time_partitions.report_gc_phase_end(5); |
sla@5237 | 309 | time_partitions.report_gc_phase_start("SubPhase12", 6); |
sla@5237 | 310 | time_partitions.report_gc_phase_end(7); |
sla@5237 | 311 | time_partitions.report_gc_phase_end(8); |
sla@5237 | 312 | time_partitions.report_gc_phase_start("SubPhase2", 9); |
sla@5237 | 313 | time_partitions.report_gc_phase_start("SubPhase21", 10); |
sla@5237 | 314 | time_partitions.report_gc_phase_end(11); |
sla@5237 | 315 | time_partitions.report_gc_phase_start("SubPhase22", 12); |
sla@5237 | 316 | time_partitions.report_gc_phase_end(13); |
sla@5237 | 317 | time_partitions.report_gc_phase_end(14); |
sla@5237 | 318 | time_partitions.report_gc_phase_start("SubPhase3", 15); |
sla@5237 | 319 | time_partitions.report_gc_phase_end(16); |
sla@5237 | 320 | |
sla@5237 | 321 | time_partitions.report_gc_phase_end(17); |
sla@5237 | 322 | |
sla@5237 | 323 | TimePartitionPhasesIterator iter(&time_partitions); |
sla@5237 | 324 | |
sla@5237 | 325 | validate_pause_phase(iter.next(), 0, "PausePhase", 2, 17); |
sla@5237 | 326 | validate_pause_phase(iter.next(), 1, "SubPhase1", 3, 8); |
sla@5237 | 327 | validate_pause_phase(iter.next(), 2, "SubPhase11", 4, 5); |
sla@5237 | 328 | validate_pause_phase(iter.next(), 2, "SubPhase12", 6, 7); |
sla@5237 | 329 | validate_pause_phase(iter.next(), 1, "SubPhase2", 9, 14); |
sla@5237 | 330 | validate_pause_phase(iter.next(), 2, "SubPhase21", 10, 11); |
sla@5237 | 331 | validate_pause_phase(iter.next(), 2, "SubPhase22", 12, 13); |
sla@5237 | 332 | validate_pause_phase(iter.next(), 1, "SubPhase3", 15, 16); |
sla@5237 | 333 | |
mgronlun@6131 | 334 | assert(time_partitions.sum_of_pauses() == Ticks(15) - Ticks(0), "Incorrect"); |
mgronlun@6131 | 335 | assert(time_partitions.longest_pause() == Ticks(15) - Ticks(0), "Incorrect"); |
sla@5237 | 336 | |
sla@5237 | 337 | assert(!iter.has_next(), "Too many elements"); |
sla@5237 | 338 | } |
sla@5237 | 339 | }; |
sla@5237 | 340 | |
sla@5237 | 341 | class GCTimerTest { |
sla@5237 | 342 | public: |
sla@5237 | 343 | static void all() { |
sla@5237 | 344 | gc_start(); |
sla@5237 | 345 | gc_end(); |
sla@5237 | 346 | } |
sla@5237 | 347 | |
sla@5237 | 348 | static void gc_start() { |
sla@5237 | 349 | GCTimer gc_timer; |
sla@5237 | 350 | gc_timer.register_gc_start(1); |
sla@5237 | 351 | |
apetushkov@9858 | 352 | assert(gc_timer.gc_start() == Ticks(1), "Incorrect"); |
sla@5237 | 353 | } |
sla@5237 | 354 | |
sla@5237 | 355 | static void gc_end() { |
sla@5237 | 356 | GCTimer gc_timer; |
sla@5237 | 357 | gc_timer.register_gc_start(1); |
sla@5237 | 358 | gc_timer.register_gc_end(2); |
sla@5237 | 359 | |
apetushkov@9858 | 360 | assert(gc_timer.gc_end() == Ticks(2), "Incorrect"); |
sla@5237 | 361 | } |
sla@5237 | 362 | }; |
sla@5237 | 363 | |
sla@5237 | 364 | void GCTimerAllTest::all() { |
sla@5237 | 365 | GCTimerTest::all(); |
sla@5237 | 366 | TimePartitionPhasesIteratorTest::all(); |
sla@5237 | 367 | } |
sla@5237 | 368 | |
sla@5237 | 369 | #endif |