51546
|
1 |
/*
|
|
2 |
* Copyright (c) 2018, 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/shared/weakProcessorPhases.hpp"
|
|
27 |
#include "gc/shared/weakProcessorPhaseTimes.hpp"
|
|
28 |
#include "gc/shared/workerDataArray.inline.hpp"
|
|
29 |
#include "logging/log.hpp"
|
|
30 |
#include "logging/logStream.hpp"
|
|
31 |
#include "utilities/debug.hpp"
|
|
32 |
#include "utilities/globalDefinitions.hpp"
|
|
33 |
#include "utilities/ticks.hpp"
|
|
34 |
|
|
35 |
static uint phase_index(WeakProcessorPhase phase) {
|
|
36 |
return WeakProcessorPhases::index(phase);
|
|
37 |
}
|
|
38 |
|
|
39 |
static bool is_serial_phase(WeakProcessorPhase phase) {
|
|
40 |
return WeakProcessorPhases::is_serial(phase);
|
|
41 |
}
|
|
42 |
|
|
43 |
static void assert_oop_storage_phase(WeakProcessorPhase phase) {
|
|
44 |
assert(WeakProcessorPhases::is_oop_storage(phase),
|
|
45 |
"Not an oop_storage phase %u", phase_index(phase));
|
|
46 |
}
|
|
47 |
|
|
48 |
const double uninitialized_time = -1.0;
|
|
49 |
|
|
50 |
#ifdef ASSERT
|
|
51 |
static bool is_initialized_time(double t) { return t >= 0.0; }
|
|
52 |
#endif // ASSERT
|
|
53 |
|
|
54 |
static void reset_times(double* times, size_t ntimes) {
|
|
55 |
for (size_t i = 0; i < ntimes; ++i) {
|
|
56 |
times[i] = uninitialized_time;
|
|
57 |
}
|
|
58 |
}
|
|
59 |
|
|
60 |
WeakProcessorPhaseTimes::WeakProcessorPhaseTimes(uint max_threads) :
|
|
61 |
_max_threads(max_threads),
|
|
62 |
_active_workers(0),
|
|
63 |
_total_time_sec(uninitialized_time),
|
|
64 |
_worker_phase_times_sec()
|
|
65 |
{
|
|
66 |
assert(_max_threads > 0, "max_threads must not be zero");
|
|
67 |
|
|
68 |
reset_times(_phase_times_sec, ARRAY_SIZE(_phase_times_sec));
|
|
69 |
|
|
70 |
if (_max_threads > 1) {
|
|
71 |
WorkerDataArray<double>** wpt = _worker_phase_times_sec;
|
|
72 |
FOR_EACH_WEAK_PROCESSOR_OOP_STORAGE_PHASE(phase) {
|
|
73 |
const char* description = WeakProcessorPhases::description(phase);
|
|
74 |
*wpt++ = new WorkerDataArray<double>(_max_threads, description);
|
|
75 |
}
|
|
76 |
}
|
|
77 |
}
|
|
78 |
|
|
79 |
WeakProcessorPhaseTimes::~WeakProcessorPhaseTimes() {
|
|
80 |
for (size_t i = 0; i < ARRAY_SIZE(_worker_phase_times_sec); ++i) {
|
|
81 |
delete _worker_phase_times_sec[i];
|
|
82 |
}
|
|
83 |
}
|
|
84 |
|
|
85 |
uint WeakProcessorPhaseTimes::max_threads() const { return _max_threads; }
|
|
86 |
|
|
87 |
uint WeakProcessorPhaseTimes::active_workers() const {
|
|
88 |
assert(_active_workers != 0, "active workers not set");
|
|
89 |
return _active_workers;
|
|
90 |
}
|
|
91 |
|
|
92 |
void WeakProcessorPhaseTimes::set_active_workers(uint n) {
|
|
93 |
assert(_active_workers == 0, "active workers already set");
|
|
94 |
assert(n > 0, "active workers must be non-zero");
|
|
95 |
assert(n <= _max_threads, "active workers must not exceed max threads");
|
|
96 |
_active_workers = n;
|
|
97 |
}
|
|
98 |
|
|
99 |
void WeakProcessorPhaseTimes::reset() {
|
|
100 |
_active_workers = 0;
|
|
101 |
_total_time_sec = uninitialized_time;
|
|
102 |
reset_times(_phase_times_sec, ARRAY_SIZE(_phase_times_sec));
|
|
103 |
if (_max_threads > 1) {
|
|
104 |
for (size_t i = 0; i < ARRAY_SIZE(_worker_phase_times_sec); ++i) {
|
|
105 |
_worker_phase_times_sec[i]->reset();
|
|
106 |
}
|
|
107 |
}
|
|
108 |
}
|
|
109 |
|
|
110 |
double WeakProcessorPhaseTimes::total_time_sec() const {
|
|
111 |
assert(is_initialized_time(_total_time_sec), "Total time not set");
|
|
112 |
return _total_time_sec;
|
|
113 |
}
|
|
114 |
|
|
115 |
void WeakProcessorPhaseTimes::record_total_time_sec(double time_sec) {
|
|
116 |
assert(!is_initialized_time(_total_time_sec), "Already set total time");
|
|
117 |
_total_time_sec = time_sec;
|
|
118 |
}
|
|
119 |
|
|
120 |
double WeakProcessorPhaseTimes::phase_time_sec(WeakProcessorPhase phase) const {
|
|
121 |
assert(is_initialized_time(_phase_times_sec[phase_index(phase)]),
|
|
122 |
"phase time not set %u", phase_index(phase));
|
|
123 |
return _phase_times_sec[phase_index(phase)];
|
|
124 |
}
|
|
125 |
|
|
126 |
void WeakProcessorPhaseTimes::record_phase_time_sec(WeakProcessorPhase phase, double time_sec) {
|
|
127 |
assert(!is_initialized_time(_phase_times_sec[phase_index(phase)]),
|
|
128 |
"Already set time for phase %u", phase_index(phase));
|
|
129 |
_phase_times_sec[phase_index(phase)] = time_sec;
|
|
130 |
}
|
|
131 |
|
|
132 |
WorkerDataArray<double>* WeakProcessorPhaseTimes::worker_data(WeakProcessorPhase phase) const {
|
|
133 |
assert_oop_storage_phase(phase);
|
|
134 |
assert(active_workers() > 1, "No worker data when single-threaded");
|
|
135 |
return _worker_phase_times_sec[WeakProcessorPhases::oop_storage_index(phase)];
|
|
136 |
}
|
|
137 |
|
|
138 |
double WeakProcessorPhaseTimes::worker_time_sec(uint worker_id, WeakProcessorPhase phase) const {
|
|
139 |
assert(worker_id < active_workers(),
|
|
140 |
"invalid worker id %u for %u", worker_id, active_workers());
|
|
141 |
if (active_workers() == 1) {
|
|
142 |
return phase_time_sec(phase);
|
|
143 |
} else {
|
|
144 |
return worker_data(phase)->get(worker_id);
|
|
145 |
}
|
|
146 |
}
|
|
147 |
|
|
148 |
void WeakProcessorPhaseTimes::record_worker_time_sec(uint worker_id,
|
|
149 |
WeakProcessorPhase phase,
|
|
150 |
double time_sec) {
|
|
151 |
if (active_workers() == 1) {
|
|
152 |
record_phase_time_sec(phase, time_sec);
|
|
153 |
} else {
|
|
154 |
worker_data(phase)->set(worker_id, time_sec);
|
|
155 |
}
|
|
156 |
}
|
|
157 |
|
|
158 |
static double elapsed_time_sec(Ticks start_time, Ticks end_time) {
|
|
159 |
return (end_time - start_time).seconds();
|
|
160 |
}
|
|
161 |
|
|
162 |
WeakProcessorTimeTracker::WeakProcessorTimeTracker(WeakProcessorPhaseTimes* times) :
|
|
163 |
_times(times),
|
|
164 |
_start_time(Ticks::now())
|
|
165 |
{}
|
|
166 |
|
|
167 |
WeakProcessorTimeTracker::~WeakProcessorTimeTracker() {
|
|
168 |
if (_times != NULL) {
|
|
169 |
Ticks end_time = Ticks::now();
|
|
170 |
_times->record_total_time_sec(elapsed_time_sec(_start_time, end_time));
|
|
171 |
}
|
|
172 |
}
|
|
173 |
|
|
174 |
WeakProcessorPhaseTimeTracker::WeakProcessorPhaseTimeTracker(WeakProcessorPhaseTimes* times,
|
|
175 |
WeakProcessorPhase phase,
|
|
176 |
uint worker_id) :
|
|
177 |
_times(times),
|
|
178 |
_phase(phase),
|
|
179 |
_worker_id(worker_id),
|
|
180 |
_start_time(Ticks::now())
|
|
181 |
{
|
|
182 |
assert_oop_storage_phase(_phase);
|
|
183 |
assert(_times == NULL || worker_id < _times->active_workers(),
|
|
184 |
"Invalid worker_id %u", worker_id);
|
|
185 |
}
|
|
186 |
|
|
187 |
WeakProcessorPhaseTimeTracker::WeakProcessorPhaseTimeTracker(WeakProcessorPhaseTimes* times,
|
|
188 |
WeakProcessorPhase phase) :
|
|
189 |
_times(times),
|
|
190 |
_phase(phase),
|
|
191 |
_worker_id(0),
|
|
192 |
_start_time(Ticks::now())
|
|
193 |
{
|
|
194 |
assert(is_serial_phase(phase), "Not a serial phase %u", phase_index(phase));
|
|
195 |
}
|
|
196 |
|
|
197 |
WeakProcessorPhaseTimeTracker::~WeakProcessorPhaseTimeTracker() {
|
|
198 |
if (_times != NULL) {
|
|
199 |
double time_sec = elapsed_time_sec(_start_time, Ticks::now());
|
|
200 |
if (is_serial_phase(_phase)) {
|
|
201 |
_times->record_phase_time_sec(_phase, time_sec);
|
|
202 |
} else {
|
|
203 |
_times->record_worker_time_sec(_worker_id, _phase, time_sec);
|
|
204 |
}
|
|
205 |
}
|
|
206 |
}
|
|
207 |
|
|
208 |
//////////////////////////////////////////////////////////////////////////////
|
|
209 |
// Printing times
|
|
210 |
|
|
211 |
const char* const indents[] = {"", " ", " ", " ", " "};
|
|
212 |
const size_t max_indents_index = ARRAY_SIZE(indents) - 1;
|
|
213 |
|
|
214 |
static const char* indent_str(size_t i) {
|
|
215 |
return indents[MIN2(i, max_indents_index)];
|
|
216 |
}
|
|
217 |
|
|
218 |
#define TIME_FORMAT "%.1lfms"
|
|
219 |
|
|
220 |
void WeakProcessorPhaseTimes::log_st_phase(WeakProcessorPhase phase,
|
|
221 |
uint indent) const {
|
|
222 |
log_debug(gc, phases)("%s%s: " TIME_FORMAT,
|
|
223 |
indent_str(indent),
|
|
224 |
WeakProcessorPhases::description(phase),
|
|
225 |
phase_time_sec(phase) * MILLIUNITS);
|
|
226 |
}
|
|
227 |
|
|
228 |
void WeakProcessorPhaseTimes::log_mt_phase_summary(WeakProcessorPhase phase,
|
|
229 |
uint indent) const {
|
|
230 |
LogTarget(Debug, gc, phases) lt;
|
|
231 |
LogStream ls(lt);
|
|
232 |
ls.print("%s", indents[indent]);
|
|
233 |
worker_data(phase)->print_summary_on(&ls, true);
|
|
234 |
}
|
|
235 |
|
|
236 |
void WeakProcessorPhaseTimes::log_mt_phase_details(WeakProcessorPhase phase,
|
|
237 |
uint indent) const {
|
|
238 |
LogTarget(Trace, gc, phases) lt;
|
|
239 |
LogStream ls(lt);
|
|
240 |
ls.print("%s", indents[indent]);
|
|
241 |
worker_data(phase)->print_details_on(&ls);
|
|
242 |
}
|
|
243 |
|
|
244 |
void WeakProcessorPhaseTimes::log_print_phases(uint indent) const {
|
|
245 |
if (log_is_enabled(Debug, gc, phases)) {
|
|
246 |
bool details_enabled = log_is_enabled(Trace, gc, phases);
|
|
247 |
FOR_EACH_WEAK_PROCESSOR_PHASE(phase) {
|
|
248 |
if (is_serial_phase(phase) || (active_workers() == 1)) {
|
|
249 |
log_st_phase(phase, indent);
|
|
250 |
} else {
|
|
251 |
log_mt_phase_summary(phase, indent);
|
|
252 |
if (details_enabled) {
|
|
253 |
log_mt_phase_details(phase, indent + 1);
|
|
254 |
}
|
|
255 |
}
|
|
256 |
}
|
|
257 |
}
|
|
258 |
}
|
|
259 |
|
|
260 |
void WeakProcessorPhaseTimes::log_print(uint indent) const {
|
|
261 |
if (log_is_enabled(Debug, gc, phases)) {
|
|
262 |
log_debug(gc, phases)("%s%s: " TIME_FORMAT,
|
|
263 |
indent_str(indent),
|
|
264 |
"Weak Processing",
|
|
265 |
total_time_sec() * MILLIUNITS);
|
|
266 |
log_print_phases(indent + 1);
|
|
267 |
}
|
|
268 |
}
|