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