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_implementation/shenandoah/shenandoahCollectorPolicy.hpp"
27 #include "gc_implementation/shenandoah/shenandoahPhaseTimings.hpp"
28 #include "gc_implementation/shenandoah/shenandoahHeap.hpp"
29 #include "gc_implementation/shenandoah/shenandoahWorkerDataArray.hpp"
30 #include "gc_implementation/shenandoah/shenandoahHeuristics.hpp"
31 #include "gc_implementation/shenandoah/shenandoahUtils.hpp"
32 #include "utilities/ostream.hpp"
33
34 #define GC_PHASE_DECLARE_NAME(type, title) \
35 title,
36
37 const char* ShenandoahPhaseTimings::_phase_names[] = {
38 SHENANDOAH_GC_PHASE_DO(GC_PHASE_DECLARE_NAME)
39 };
40
41 #undef GC_PHASE_DECLARE_NAME
42
43 ShenandoahPhaseTimings::ShenandoahPhaseTimings() : _policy(NULL) {
44 uint max_workers = (uint)MAX2(ConcGCThreads, ParallelGCThreads);
45 _worker_times = new ShenandoahWorkerTimings(max_workers);
46 _termination_times = new ShenandoahTerminationTimings(max_workers);
47 _policy = ShenandoahHeap::heap()->shenandoah_policy();
48 assert(_policy != NULL, "Can not be NULL");
49 }
50
51 void ShenandoahPhaseTimings::record_phase_start(Phase phase) {
52 _timing_data[phase]._start = os::elapsedTime();
53 }
54
55 void ShenandoahPhaseTimings::record_phase_end(Phase phase) {
56 assert(_policy != NULL, "Not yet initialized");
57 double end = os::elapsedTime();
58 double elapsed = end - _timing_data[phase]._start;
59 if (!_policy->is_at_shutdown()) {
60 _timing_data[phase]._secs.add(elapsed);
61 }
62 ShenandoahHeap::heap()->heuristics()->record_phase_time(phase, elapsed);
63 }
64
65 void ShenandoahPhaseTimings::record_phase_time(Phase phase, double time) {
66 assert(_policy != NULL, "Not yet initialized");
67 if (!_policy->is_at_shutdown()) {
68 _timing_data[phase]._secs.add(time);
69 }
70 }
71
72 void ShenandoahPhaseTimings::record_workers_start(Phase phase) {
73 for (uint i = 0; i < GCParPhasesSentinel; i++) {
74 _worker_times->reset(i);
75 }
76 }
77
78 void ShenandoahPhaseTimings::record_workers_end(Phase phase) {
79 if (_policy->is_at_shutdown()) {
80 // Do not record the past-shutdown events
81 return;
82 }
83
84 guarantee(phase == init_evac ||
85 phase == scan_roots ||
86 phase == update_roots ||
87 phase == final_update_refs_roots ||
88 phase == full_gc_roots ||
89 phase == degen_gc_update_roots ||
90 phase == _num_phases,
91 "only in these phases we can add per-thread phase times");
92 if (phase != _num_phases) {
93 // Merge _phase_time to counters below the given phase.
94 for (uint i = 0; i < GCParPhasesSentinel; i++) {
95 double t = _worker_times->average(i);
96 _timing_data[phase + i + 1]._secs.add(t);
97 }
98 }
99 }
100
101 void ShenandoahPhaseTimings::print_on(outputStream* out) const {
102 out->cr();
103 out->print_cr("GC STATISTICS:");
104 out->print_cr(" \"(G)\" (gross) pauses include VM time: time to notify and block threads, do the pre-");
105 out->print_cr(" and post-safepoint housekeeping. Use -XX:+PrintSafepointStatistics to dissect.");
106 out->print_cr(" \"(N)\" (net) pauses are the times spent in the actual GC code.");
107 out->print_cr(" \"a\" is average time for each phase, look at levels to see if average makes sense.");
108 out->print_cr(" \"lvls\" are quantiles: 0%% (minimum), 25%%, 50%% (median), 75%%, 100%% (maximum).");
109 out->cr();
110
111 for (uint i = 0; i < _num_phases; i++) {
112 if (_timing_data[i]._secs.maximum() != 0) {
113 print_summary_sd(out, _phase_names[i], &(_timing_data[i]._secs));
114 }
115 }
116 }
117
118 void ShenandoahPhaseTimings::print_summary_sd(outputStream* out, const char* str, const HdrSeq* seq) const {
119 out->print_cr("%-27s = %8.2lf s (a = %8.0lf us) (n = " INT32_FORMAT_W(5) ") (lvls, us = %8.0lf, %8.0lf, %8.0lf, %8.0lf, %8.0lf)",
120 str,
121 seq->sum(),
122 seq->avg() * 1000000.0,
123 seq->num(),
124 seq->percentile(0) * 1000000.0,
125 seq->percentile(25) * 1000000.0,
126 seq->percentile(50) * 1000000.0,
127 seq->percentile(75) * 1000000.0,
128 seq->maximum() * 1000000.0
129 );
130 }
131
132 ShenandoahWorkerTimings::ShenandoahWorkerTimings(uint max_gc_threads) :
133 _max_gc_threads(max_gc_threads)
134 {
135 assert(max_gc_threads > 0, "Must have some GC threads");
136
137 #define GC_PAR_PHASE_DECLARE_WORKER_DATA(type, title) \
138 _gc_par_phases[ShenandoahPhaseTimings::type] = new ShenandoahWorkerDataArray<double>(max_gc_threads, title);
139 // Root scanning phases
140 SHENANDOAH_GC_PAR_PHASE_DO(GC_PAR_PHASE_DECLARE_WORKER_DATA)
141 #undef GC_PAR_PHASE_DECLARE_WORKER_DATA
142 }
143
144 // record the time a phase took in seconds
145 void ShenandoahWorkerTimings::record_time_secs(ShenandoahPhaseTimings::GCParPhases phase, uint worker_i, double secs) {
146 _gc_par_phases[phase]->set(worker_i, secs);
147 }
148
149 double ShenandoahWorkerTimings::average(uint i) {
150 return _gc_par_phases[i]->average();
151 }
152 void ShenandoahWorkerTimings::reset(uint i) {
153 _gc_par_phases[i]->reset();
154 }
155
156 void ShenandoahWorkerTimings::print() {
157 for (uint i = 0; i < ShenandoahPhaseTimings::GCParPhasesSentinel; i++) {
158 _gc_par_phases[i]->print_summary_on(tty);
159 }
160 }
161
162
163 ShenandoahTerminationTimings::ShenandoahTerminationTimings(uint max_gc_threads) {
164 _gc_termination_phase = new ShenandoahWorkerDataArray<double>(max_gc_threads, "Task Termination (ms):");
165 }
166
167 void ShenandoahTerminationTimings::record_time_secs(uint worker_id, double secs) {
168 if (_gc_termination_phase->get(worker_id) == ShenandoahWorkerDataArray<double>::uninitialized()) {
169 _gc_termination_phase->set(worker_id, secs);
170 } else {
171 // worker may re-enter termination phase
172 _gc_termination_phase->add(worker_id, secs);
173 }
174 }
175
176 void ShenandoahTerminationTimings::print() const {
177 _gc_termination_phase->print_summary_on(tty);
178 }
179
180 double ShenandoahTerminationTimings::average() const {
181 return _gc_termination_phase->average();
182 }
183
184 void ShenandoahTerminationTimings::reset() {
185 _gc_termination_phase->reset();
186 }
187