21 * questions. |
21 * questions. |
22 * |
22 * |
23 */ |
23 */ |
24 |
24 |
25 #include "precompiled.hpp" |
25 #include "precompiled.hpp" |
26 #include "gc/shared/gcTimer.hpp" |
26 #include "gc/shared/gcTraceTime.inline.hpp" |
27 #include "gc/shared/gcTrace.hpp" |
27 #include "logging/log.hpp" |
28 #include "gc/shared/gcTraceTime.hpp" |
|
29 #include "runtime/globals.hpp" |
|
30 #include "runtime/os.hpp" |
28 #include "runtime/os.hpp" |
31 #include "runtime/safepoint.hpp" |
|
32 #include "runtime/thread.inline.hpp" |
|
33 #include "runtime/timer.hpp" |
|
34 #include "utilities/ostream.hpp" |
|
35 #include "utilities/ticks.inline.hpp" |
|
36 |
29 |
37 |
30 GCTraceCPUTime::GCTraceCPUTime() : |
38 GCTraceTimeImpl::GCTraceTimeImpl(const char* title, bool doit, bool print_cr, GCTimer* timer) : |
31 _active(log_is_enabled(Info, gc, cpu)), |
39 _title(title), _doit(doit), _print_cr(print_cr), _timer(timer), _start_counter() { |
32 _starting_user_time(0.0), |
40 if (_doit || _timer != NULL) { |
33 _starting_system_time(0.0), |
41 _start_counter.stamp(); |
34 _starting_real_time(0.0) |
42 } |
35 { |
43 |
36 if (_active) { |
44 if (_timer != NULL) { |
37 bool valid = os::getTimesSecs(&_starting_real_time, |
45 assert(SafepointSynchronize::is_at_safepoint(), "Tracing currently only supported at safepoints"); |
38 &_starting_user_time, |
46 assert(Thread::current()->is_VM_thread(), "Tracing currently only supported from the VM thread"); |
39 &_starting_system_time); |
47 |
40 if (!valid) { |
48 _timer->register_gc_phase_start(title, _start_counter); |
41 log_warning(gc, cpu)("TraceCPUTime: os::getTimesSecs() returned invalid result"); |
49 } |
42 _active = false; |
50 |
43 } |
51 if (_doit) { |
|
52 gclog_or_tty->gclog_stamp(); |
|
53 gclog_or_tty->print("[%s", title); |
|
54 gclog_or_tty->flush(); |
|
55 } |
44 } |
56 } |
45 } |
57 |
46 |
58 GCTraceTimeImpl::~GCTraceTimeImpl() { |
47 GCTraceCPUTime::~GCTraceCPUTime() { |
59 Ticks stop_counter; |
48 if (_active) { |
60 |
49 double real_time, user_time, system_time; |
61 if (_doit || _timer != NULL) { |
50 bool valid = os::getTimesSecs(&real_time, &user_time, &system_time); |
62 stop_counter.stamp(); |
51 if (valid) { |
63 } |
52 log_info(gc, cpu)("User=%3.2fs Sys=%3.2fs Real=%3.2fs", |
64 |
53 user_time - _starting_user_time, |
65 if (_timer != NULL) { |
54 system_time - _starting_system_time, |
66 _timer->register_gc_phase_end(stop_counter); |
55 real_time - _starting_real_time); |
67 } |
|
68 |
|
69 if (_doit) { |
|
70 const Tickspan duration = stop_counter - _start_counter; |
|
71 double duration_in_seconds = TicksToTimeHelper::seconds(duration); |
|
72 if (_print_cr) { |
|
73 gclog_or_tty->print_cr(", %3.7f secs]", duration_in_seconds); |
|
74 } else { |
56 } else { |
75 gclog_or_tty->print(", %3.7f secs]", duration_in_seconds); |
57 log_warning(gc, cpu)("TraceCPUTime: os::getTimesSecs() returned invalid result"); |
76 } |
58 } |
77 gclog_or_tty->flush(); |
|
78 } |
59 } |
79 } |
60 } |