1 /*
2 * Copyright (c) 2012, 2019, 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 #ifndef SHARE_GC_SHARED_GCTRACETIME_INLINE_HPP
26 #define SHARE_GC_SHARED_GCTRACETIME_INLINE_HPP
27
28 #include "gc/shared/collectedHeap.hpp"
29 #include "gc/shared/gcTimer.hpp"
30 #include "gc/shared/gcTrace.hpp"
31 #include "gc/shared/gcTraceTime.hpp"
32 #include "logging/log.hpp"
33 #include "logging/logStream.hpp"
34 #include "memory/universe.hpp"
35 #include "utilities/ticks.hpp"
36
37 #define LOG_STOP_HEAP_FORMAT SIZE_FORMAT "M->" SIZE_FORMAT "M(" SIZE_FORMAT "M)"
38
39 inline void GCTraceTimeImpl::log_start(jlong start_counter) {
40 if (_out_start.is_enabled()) {
41 LogStream out(_out_start);
42
43 out.print("%s", _title);
44 if (_gc_cause != GCCause::_no_gc) {
45 out.print(" (%s)", GCCause::to_string(_gc_cause));
46 }
47 out.cr();
48 }
49 }
50
51 inline void GCTraceTimeImpl::log_stop(jlong start_counter, jlong stop_counter) {
52 double duration_in_ms = TimeHelper::counter_to_millis(stop_counter - start_counter);
53 double start_time_in_secs = TimeHelper::counter_to_seconds(start_counter);
54 double stop_time_in_secs = TimeHelper::counter_to_seconds(stop_counter);
55
56 LogStream out(_out_stop);
57
58 out.print("%s", _title);
59
60 if (_gc_cause != GCCause::_no_gc) {
61 out.print(" (%s)", GCCause::to_string(_gc_cause));
62 }
63
64 if (_heap_usage_before != SIZE_MAX) {
65 CollectedHeap* heap = Universe::heap();
66 size_t used_before_m = _heap_usage_before / M;
67 size_t used_m = heap->used() / M;
68 size_t capacity_m = heap->capacity() / M;
69 out.print(" " LOG_STOP_HEAP_FORMAT, used_before_m, used_m, capacity_m);
70 }
71
72 out.print_cr(" %.3fms", duration_in_ms);
73 }
74
75 inline void GCTraceTimeImpl::time_stamp(Ticks& ticks) {
76 if (_enabled || _timer != NULL) {
77 ticks.stamp();
78 }
79 }
80
81 inline GCTraceTimeImpl::GCTraceTimeImpl(LogTargetHandle out_start, LogTargetHandle out_stop, const char* title, GCTimer* timer, GCCause::Cause gc_cause, bool log_heap_usage) :
82 _out_start(out_start),
83 _out_stop(out_stop),
84 _enabled(out_stop.is_enabled()),
85 _start_ticks(),
86 _title(title),
87 _gc_cause(gc_cause),
88 _timer(timer),
89 _heap_usage_before(SIZE_MAX) {
90
91 time_stamp(_start_ticks);
92 if (_enabled) {
93 if (log_heap_usage) {
94 _heap_usage_before = Universe::heap()->used();
95 }
96 log_start(_start_ticks.value());
97 }
98 if (_timer != NULL) {
99 _timer->register_gc_phase_start(_title, _start_ticks);
100 }
101 }
102
103 inline GCTraceTimeImpl::~GCTraceTimeImpl() {
104 Ticks stop_ticks;
105 time_stamp(stop_ticks);
106 if (_enabled) {
107 log_stop(_start_ticks.value(), stop_ticks.value());
108 }
109 if (_timer != NULL) {
110 _timer->register_gc_phase_end(stop_ticks);
111 }
112 }
113
114 template <LogLevelType Level, LogTagType T0, LogTagType T1, LogTagType T2, LogTagType T3, LogTagType T4, LogTagType GuardTag >
115 GCTraceConcTimeImpl<Level, T0, T1, T2, T3, T4, GuardTag>::GCTraceConcTimeImpl(const char* title) :
116 _enabled(LogImpl<T0, T1, T2, T3, T4, GuardTag>::is_level(Level)), _start_time(os::elapsed_counter()), _title(title) {
117 if (_enabled) {
118 LogImpl<T0, T1, T2, T3, T4>::template write<Level>("%s", _title);
119 }
120 }
121
122 template <LogLevelType Level, LogTagType T0, LogTagType T1, LogTagType T2, LogTagType T3, LogTagType T4, LogTagType GuardTag >
123 GCTraceConcTimeImpl<Level, T0, T1, T2, T3, T4, GuardTag>::~GCTraceConcTimeImpl() {
133 (( T1 == LogTag::__NO_TAG) ? PREFIX_LOG_TAG(start) : T1), \
134 ((T1 != LogTag::__NO_TAG && T2 == LogTag::__NO_TAG) ? PREFIX_LOG_TAG(start) : T2), \
135 ((T2 != LogTag::__NO_TAG && T3 == LogTag::__NO_TAG) ? PREFIX_LOG_TAG(start) : T3), \
136 ((T3 != LogTag::__NO_TAG && T4 == LogTag::__NO_TAG) ? PREFIX_LOG_TAG(start) : T4)
137
138 template <LogLevelType level, LogTagType T0, LogTagType T1, LogTagType T2, LogTagType T3, LogTagType T4, LogTagType GuardTag>
139 GCTraceTimeImplWrapper<level, T0, T1, T2, T3, T4, GuardTag>::GCTraceTimeImplWrapper(
140 const char* title, GCTimer* timer, GCCause::Cause gc_cause, bool log_heap_usage)
141 : _impl(
142 LogTargetHandle::create<level, T0, INJECT_START_TAG(T1, T2, T3, T4), GuardTag>(),
143 LogTargetHandle::create<level, T0, T1, T2, T3, T4, GuardTag>(),
144 title,
145 timer,
146 gc_cause,
147 log_heap_usage) {
148
149 STATIC_ASSERT(T0 != LogTag::__NO_TAG); // Need some tag to log on.
150 STATIC_ASSERT(T4 == LogTag::__NO_TAG); // Need to leave at least the last tag for the "start" tag in log_start()
151 }
152
153 #undef INJECT_START_TAG
154
155 template <LogLevelType Level, LogTagType T0, LogTagType T1, LogTagType T2, LogTagType T3, LogTagType T4, LogTagType GuardTag>
156 GCTraceTimeImplWrapper<Level, T0, T1, T2, T3, T4, GuardTag>::~GCTraceTimeImplWrapper() {}
157
158 #define GCTraceTime(Level, ...) GCTraceTimeImplWrapper<LogLevel::Level, LOG_TAGS(__VA_ARGS__)>
159 #define GCTraceConcTime(Level, ...) GCTraceConcTimeImpl<LogLevel::Level, LOG_TAGS(__VA_ARGS__)>
160
161 #endif // SHARE_GC_SHARED_GCTRACETIME_INLINE_HPP
|
1 /*
2 * Copyright (c) 2012, 2020, 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 #ifndef SHARE_GC_SHARED_GCTRACETIME_INLINE_HPP
26 #define SHARE_GC_SHARED_GCTRACETIME_INLINE_HPP
27
28 #include "gc/shared/collectedHeap.hpp"
29 #include "gc/shared/gcTimer.hpp"
30 #include "gc/shared/gcTrace.hpp"
31 #include "gc/shared/gcTraceTime.hpp"
32 #include "logging/log.hpp"
33 #include "logging/logStream.hpp"
34 #include "memory/universe.hpp"
35 #include "utilities/ticks.hpp"
36
37 #define LOG_STOP_HEAP_FORMAT SIZE_FORMAT "M->" SIZE_FORMAT "M(" SIZE_FORMAT "M)"
38
39 template <typename Handle1, typename Handle2>
40 inline void GCTraceTimeImpl<Handle1, Handle2>::log_start(jlong start_counter) {
41 if (_out_start.is_enabled()) {
42 LogStream out(_out_start);
43
44 out.print("%s", _title);
45 if (_gc_cause != GCCause::_no_gc) {
46 out.print(" (%s)", GCCause::to_string(_gc_cause));
47 }
48 out.cr();
49 }
50 }
51
52 template <typename Handle1, typename Handle2>
53 inline void GCTraceTimeImpl<Handle1, Handle2>::log_stop(jlong start_counter, jlong stop_counter) {
54 double duration_in_ms = TimeHelper::counter_to_millis(stop_counter - start_counter);
55 double start_time_in_secs = TimeHelper::counter_to_seconds(start_counter);
56 double stop_time_in_secs = TimeHelper::counter_to_seconds(stop_counter);
57
58 LogStream out(_out_stop);
59
60 out.print("%s", _title);
61
62 if (_gc_cause != GCCause::_no_gc) {
63 out.print(" (%s)", GCCause::to_string(_gc_cause));
64 }
65
66 if (_heap_usage_before != SIZE_MAX) {
67 CollectedHeap* heap = Universe::heap();
68 size_t used_before_m = _heap_usage_before / M;
69 size_t used_m = heap->used() / M;
70 size_t capacity_m = heap->capacity() / M;
71 out.print(" " LOG_STOP_HEAP_FORMAT, used_before_m, used_m, capacity_m);
72 }
73
74 out.print_cr(" %.3fms", duration_in_ms);
75 }
76
77 template <typename Handle1, typename Handle2>
78 inline void GCTraceTimeImpl<Handle1, Handle2>::time_stamp(Ticks& ticks) {
79 if (_enabled || _timer != NULL) {
80 ticks.stamp();
81 }
82 }
83
84 template <typename Handle1, typename Handle2>
85 inline GCTraceTimeImpl<Handle1, Handle2>::GCTraceTimeImpl(Handle1 out_start, Handle2 out_stop, const char* title, GCTimer* timer, GCCause::Cause gc_cause, bool log_heap_usage) :
86 _out_start(out_start),
87 _out_stop(out_stop),
88 _enabled(out_stop.is_enabled()),
89 _start_ticks(),
90 _title(title),
91 _gc_cause(gc_cause),
92 _timer(timer),
93 _heap_usage_before(SIZE_MAX) {
94
95 time_stamp(_start_ticks);
96 if (_enabled) {
97 if (log_heap_usage) {
98 _heap_usage_before = Universe::heap()->used();
99 }
100 log_start(_start_ticks.value());
101 }
102 if (_timer != NULL) {
103 _timer->register_gc_phase_start(_title, _start_ticks);
104 }
105 }
106 template <typename Handle1, typename Handle2>
107 inline GCTraceTimeImpl<Handle1, Handle2>::~GCTraceTimeImpl() {
108 Ticks stop_ticks;
109 time_stamp(stop_ticks);
110 if (_enabled) {
111 log_stop(_start_ticks.value(), stop_ticks.value());
112 }
113 if (_timer != NULL) {
114 _timer->register_gc_phase_end(stop_ticks);
115 }
116 }
117
118 template <LogLevelType Level, LogTagType T0, LogTagType T1, LogTagType T2, LogTagType T3, LogTagType T4, LogTagType GuardTag >
119 GCTraceConcTimeImpl<Level, T0, T1, T2, T3, T4, GuardTag>::GCTraceConcTimeImpl(const char* title) :
120 _enabled(LogImpl<T0, T1, T2, T3, T4, GuardTag>::is_level(Level)), _start_time(os::elapsed_counter()), _title(title) {
121 if (_enabled) {
122 LogImpl<T0, T1, T2, T3, T4>::template write<Level>("%s", _title);
123 }
124 }
125
126 template <LogLevelType Level, LogTagType T0, LogTagType T1, LogTagType T2, LogTagType T3, LogTagType T4, LogTagType GuardTag >
127 GCTraceConcTimeImpl<Level, T0, T1, T2, T3, T4, GuardTag>::~GCTraceConcTimeImpl() {
137 (( T1 == LogTag::__NO_TAG) ? PREFIX_LOG_TAG(start) : T1), \
138 ((T1 != LogTag::__NO_TAG && T2 == LogTag::__NO_TAG) ? PREFIX_LOG_TAG(start) : T2), \
139 ((T2 != LogTag::__NO_TAG && T3 == LogTag::__NO_TAG) ? PREFIX_LOG_TAG(start) : T3), \
140 ((T3 != LogTag::__NO_TAG && T4 == LogTag::__NO_TAG) ? PREFIX_LOG_TAG(start) : T4)
141
142 template <LogLevelType level, LogTagType T0, LogTagType T1, LogTagType T2, LogTagType T3, LogTagType T4, LogTagType GuardTag>
143 GCTraceTimeImplWrapper<level, T0, T1, T2, T3, T4, GuardTag>::GCTraceTimeImplWrapper(
144 const char* title, GCTimer* timer, GCCause::Cause gc_cause, bool log_heap_usage)
145 : _impl(
146 LogTargetHandle::create<level, T0, INJECT_START_TAG(T1, T2, T3, T4), GuardTag>(),
147 LogTargetHandle::create<level, T0, T1, T2, T3, T4, GuardTag>(),
148 title,
149 timer,
150 gc_cause,
151 log_heap_usage) {
152
153 STATIC_ASSERT(T0 != LogTag::__NO_TAG); // Need some tag to log on.
154 STATIC_ASSERT(T4 == LogTag::__NO_TAG); // Need to leave at least the last tag for the "start" tag in log_start()
155 }
156
157 template <LogLevelType level, LogTagType T0, LogTagType T1, LogTagType T2, LogTagType T3, LogTagType T4, LogTagType GuardTag>
158 GCAsyncTraceTimeImplWrapper<level, T0, T1, T2, T3, T4, GuardTag>::GCAsyncTraceTimeImplWrapper(
159 const char* title, GCTimer* timer, GCCause::Cause gc_cause, bool log_heap_usage)
160 : _impl(
161 AsyncLogTargetHandle::create<level, T0, INJECT_START_TAG(T1, T2, T3, T4), GuardTag>(),
162 AsyncLogTargetHandle::create<level, T0, T1, T2, T3, T4, GuardTag>(),
163 title,
164 timer,
165 gc_cause,
166 log_heap_usage) {
167
168 STATIC_ASSERT(T0 != LogTag::__NO_TAG); // Need some tag to log on.
169 STATIC_ASSERT(T4 == LogTag::__NO_TAG); // Need to leave at least the last tag for the "start" tag in log_start()
170 }
171
172 #undef INJECT_START_TAG
173
174
175 #define GCTraceTime(Level, ...) GCTraceTimeImplWrapper<LogLevel::Level, LOG_TAGS(__VA_ARGS__)>
176 #define GCTraceConcTime(Level, ...) GCTraceConcTimeImpl<LogLevel::Level, LOG_TAGS(__VA_ARGS__)>
177
178 #endif // SHARE_GC_SHARED_GCTRACETIME_INLINE_HPP
|