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/g1/g1CollectedHeap.inline.hpp"
27 #include "gc/g1/g1GCPhaseTimes.hpp"
28 #include "gc/g1/g1HotCardCache.hpp"
29 #include "gc/g1/g1StringDedup.hpp"
30 #include "gc/g1/workerDataArray.inline.hpp"
31 #include "memory/resourceArea.hpp"
32 #include "logging/log.hpp"
33 #include "runtime/timer.hpp"
34 #include "runtime/os.hpp"
35
36 static const char* Indents[5] = {"", " ", " ", " ", " "};
37
38 G1GCPhaseTimes::G1GCPhaseTimes(uint max_gc_threads) :
39 _max_gc_threads(max_gc_threads),
40 _gc_start_counter(0),
41 _gc_pause_time_ms(0.0)
42 {
43 assert(max_gc_threads > 0, "Must have some GC threads");
44
45 _gc_par_phases[GCWorkerStart] = new WorkerDataArray<double>(max_gc_threads, "GC Worker Start (ms):");
46 _gc_par_phases[ExtRootScan] = new WorkerDataArray<double>(max_gc_threads, "Ext Root Scanning (ms):");
47
48 // Root scanning phases
49 _gc_par_phases[ThreadRoots] = new WorkerDataArray<double>(max_gc_threads, "Thread Roots (ms):");
50 _gc_par_phases[StringTableRoots] = new WorkerDataArray<double>(max_gc_threads, "StringTable Roots (ms):");
51 _gc_par_phases[UniverseRoots] = new WorkerDataArray<double>(max_gc_threads, "Universe Roots (ms):");
52 _gc_par_phases[JNIRoots] = new WorkerDataArray<double>(max_gc_threads, "JNI Handles Roots (ms):");
216 void G1GCPhaseTimes::add_time_secs(GCParPhases phase, uint worker_i, double secs) {
217 _gc_par_phases[phase]->add(worker_i, secs);
218 }
219
220 void G1GCPhaseTimes::record_thread_work_item(GCParPhases phase, uint worker_i, size_t count, uint index) {
221 _gc_par_phases[phase]->set_thread_work_item(worker_i, count, index);
222 }
223
224 // return the average time for a phase in milliseconds
225 double G1GCPhaseTimes::average_time_ms(GCParPhases phase) {
226 return _gc_par_phases[phase]->average() * 1000.0;
227 }
228
229 size_t G1GCPhaseTimes::sum_thread_work_items(GCParPhases phase, uint index) {
230 assert(_gc_par_phases[phase]->thread_work_items(index) != NULL, "No sub count");
231 return _gc_par_phases[phase]->thread_work_items(index)->sum();
232 }
233
234 template <class T>
235 void G1GCPhaseTimes::details(T* phase, const char* indent) const {
236 Log(gc, phases, task) log;
237 if (log.is_level(LogLevel::Trace)) {
238 outputStream* trace_out = log.trace_stream();
239 trace_out->print("%s", indent);
240 phase->print_details_on(trace_out);
241 }
242 }
243
244 void G1GCPhaseTimes::log_phase(WorkerDataArray<double>* phase, uint indent, outputStream* out, bool print_sum) const {
245 out->print("%s", Indents[indent]);
246 phase->print_summary_on(out, print_sum);
247 details(phase, Indents[indent]);
248
249 for (uint i = 0; i < phase->MaxThreadWorkItems; i++) {
250 WorkerDataArray<size_t>* work_items = phase->thread_work_items(i);
251 if (work_items != NULL) {
252 out->print("%s", Indents[indent + 1]);
253 work_items->print_summary_on(out, true);
254 details(work_items, Indents[indent + 1]);
255 }
256 }
257 }
258
259 void G1GCPhaseTimes::debug_phase(WorkerDataArray<double>* phase) const {
260 Log(gc, phases) log;
261 if (log.is_level(LogLevel::Debug)) {
262 ResourceMark rm;
263 log_phase(phase, 2, log.debug_stream(), true);
264 }
265 }
266
267 void G1GCPhaseTimes::trace_phase(WorkerDataArray<double>* phase, bool print_sum) const {
268 Log(gc, phases) log;
269 if (log.is_level(LogLevel::Trace)) {
270 ResourceMark rm;
271 log_phase(phase, 3, log.trace_stream(), print_sum);
272 }
273 }
274
275 #define TIME_FORMAT "%.1lfms"
276
277 void G1GCPhaseTimes::info_time(const char* name, double value) const {
278 log_info(gc, phases)("%s%s: " TIME_FORMAT, Indents[1], name, value);
279 }
280
281 void G1GCPhaseTimes::debug_time(const char* name, double value) const {
282 log_debug(gc, phases)("%s%s: " TIME_FORMAT, Indents[2], name, value);
283 }
284
285 void G1GCPhaseTimes::trace_time(const char* name, double value) const {
286 log_trace(gc, phases)("%s%s: " TIME_FORMAT, Indents[3], name, value);
287 }
288
289 void G1GCPhaseTimes::trace_count(const char* name, size_t value) const {
290 log_trace(gc, phases)("%s%s: " SIZE_FORMAT, Indents[3], name, value);
291 }
|
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/g1/g1CollectedHeap.inline.hpp"
27 #include "gc/g1/g1GCPhaseTimes.hpp"
28 #include "gc/g1/g1HotCardCache.hpp"
29 #include "gc/g1/g1StringDedup.hpp"
30 #include "gc/g1/workerDataArray.inline.hpp"
31 #include "memory/resourceArea.hpp"
32 #include "logging/log.hpp"
33 #include "logging/logStream.hpp"
34 #include "runtime/timer.hpp"
35 #include "runtime/os.hpp"
36
37 static const char* Indents[5] = {"", " ", " ", " ", " "};
38
39 G1GCPhaseTimes::G1GCPhaseTimes(uint max_gc_threads) :
40 _max_gc_threads(max_gc_threads),
41 _gc_start_counter(0),
42 _gc_pause_time_ms(0.0)
43 {
44 assert(max_gc_threads > 0, "Must have some GC threads");
45
46 _gc_par_phases[GCWorkerStart] = new WorkerDataArray<double>(max_gc_threads, "GC Worker Start (ms):");
47 _gc_par_phases[ExtRootScan] = new WorkerDataArray<double>(max_gc_threads, "Ext Root Scanning (ms):");
48
49 // Root scanning phases
50 _gc_par_phases[ThreadRoots] = new WorkerDataArray<double>(max_gc_threads, "Thread Roots (ms):");
51 _gc_par_phases[StringTableRoots] = new WorkerDataArray<double>(max_gc_threads, "StringTable Roots (ms):");
52 _gc_par_phases[UniverseRoots] = new WorkerDataArray<double>(max_gc_threads, "Universe Roots (ms):");
53 _gc_par_phases[JNIRoots] = new WorkerDataArray<double>(max_gc_threads, "JNI Handles Roots (ms):");
217 void G1GCPhaseTimes::add_time_secs(GCParPhases phase, uint worker_i, double secs) {
218 _gc_par_phases[phase]->add(worker_i, secs);
219 }
220
221 void G1GCPhaseTimes::record_thread_work_item(GCParPhases phase, uint worker_i, size_t count, uint index) {
222 _gc_par_phases[phase]->set_thread_work_item(worker_i, count, index);
223 }
224
225 // return the average time for a phase in milliseconds
226 double G1GCPhaseTimes::average_time_ms(GCParPhases phase) {
227 return _gc_par_phases[phase]->average() * 1000.0;
228 }
229
230 size_t G1GCPhaseTimes::sum_thread_work_items(GCParPhases phase, uint index) {
231 assert(_gc_par_phases[phase]->thread_work_items(index) != NULL, "No sub count");
232 return _gc_par_phases[phase]->thread_work_items(index)->sum();
233 }
234
235 template <class T>
236 void G1GCPhaseTimes::details(T* phase, const char* indent) const {
237 LogTarget(Trace, gc, phases, task) lt;
238 if (lt.is_enabled()) {
239 LogStream ls(lt);
240 ls.print("%s", indent);
241 phase->print_details_on(&ls);
242 }
243 }
244
245 void G1GCPhaseTimes::log_phase(WorkerDataArray<double>* phase, uint indent, outputStream* out, bool print_sum) const {
246 out->print("%s", Indents[indent]);
247 phase->print_summary_on(out, print_sum);
248 details(phase, Indents[indent]);
249
250 for (uint i = 0; i < phase->MaxThreadWorkItems; i++) {
251 WorkerDataArray<size_t>* work_items = phase->thread_work_items(i);
252 if (work_items != NULL) {
253 out->print("%s", Indents[indent + 1]);
254 work_items->print_summary_on(out, true);
255 details(work_items, Indents[indent + 1]);
256 }
257 }
258 }
259
260 void G1GCPhaseTimes::debug_phase(WorkerDataArray<double>* phase) const {
261 Log(gc, phases) log;
262 if (log.is_level(LogLevel::Debug)) {
263 ResourceMark rm;
264 LogStream ls(log.debug());
265 log_phase(phase, 2, &ls, true);
266 }
267 }
268
269 void G1GCPhaseTimes::trace_phase(WorkerDataArray<double>* phase, bool print_sum) const {
270 LogTarget(Trace, gc, phases) lt;
271 if (lt.is_enabled()) {
272 LogStream ls(lt);
273 log_phase(phase, 3, &ls, print_sum);
274 }
275 }
276
277 #define TIME_FORMAT "%.1lfms"
278
279 void G1GCPhaseTimes::info_time(const char* name, double value) const {
280 log_info(gc, phases)("%s%s: " TIME_FORMAT, Indents[1], name, value);
281 }
282
283 void G1GCPhaseTimes::debug_time(const char* name, double value) const {
284 log_debug(gc, phases)("%s%s: " TIME_FORMAT, Indents[2], name, value);
285 }
286
287 void G1GCPhaseTimes::trace_time(const char* name, double value) const {
288 log_trace(gc, phases)("%s%s: " TIME_FORMAT, Indents[3], name, value);
289 }
290
291 void G1GCPhaseTimes::trace_count(const char* name, size_t value) const {
292 log_trace(gc, phases)("%s%s: " SIZE_FORMAT, Indents[3], name, value);
293 }
|