1 //
2 // Copyright 2018 Pixar
3 //
4 // Licensed under the Apache License, Version 2.0 (the "Apache License")
5 // with the following modification; you may not use this file except in
6 // compliance with the Apache License and the following modification to it:
7 // Section 6. Trademarks. is deleted and replaced with:
8 //
9 // 6. Trademarks. This License does not grant permission to use the trade
10 //    names, trademarks, service marks, or product names of the Licensor
11 //    and its affiliates, except as required to comply with Section 4(c) of
12 //    the License and to reproduce the content of the NOTICE file.
13 //
14 // You may obtain a copy of the Apache License at
15 //
16 //     http://www.apache.org/licenses/LICENSE-2.0
17 //
18 // Unless required by applicable law or agreed to in writing, software
19 // distributed under the Apache License with the above modification is
20 // distributed on an "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
21 // KIND, either express or implied. See the Apache License for the specific
22 // language governing permissions and limitations under the Apache License.
23 //
24 
25 #ifndef PXR_BASE_TRACE_TRACE_H
26 #define PXR_BASE_TRACE_TRACE_H
27 
28 /// \file trace/trace.h
29 
30 #include "pxr/pxr.h"
31 
32 #include "pxr/base/trace/api.h"
33 #include "pxr/base/trace/collector.h"
34 
35 #include "pxr/base/tf/preprocessorUtilsLite.h"
36 
37 #include <atomic>
38 
39 #if !defined(TRACE_DISABLE)
40 
41 /// Records a timestamp when constructed and a timespan event when destructed,
42 /// using the name of the function or method as the key.
43 #define TRACE_FUNCTION() \
44         _TRACE_FUNCTION_INSTANCE(__LINE__, __ARCH_FUNCTION__, __ARCH_PRETTY_FUNCTION__)
45 
46 /// Records a timestamp when constructed and a timespan event when destructed,
47 /// using \a name as the key.
48 #define TRACE_SCOPE(name) \
49         _TRACE_SCOPE_INSTANCE(__LINE__, name)
50 
51 /// Records a timestamp when constructed and a timespan event when destructed,
52 /// using the name of the function concatenated with \a name as the key.
53 #define TRACE_FUNCTION_SCOPE(name) \
54         _TRACE_FUNCTION_SCOPE_INSTANCE( \
55             __LINE__, __ARCH_FUNCTION__, __ARCH_PRETTY_FUNCTION__, name)
56 
57 /// Records a timestamp when constructed, using \a name as the key.
58 #define TRACE_MARKER(name) \
59         _TRACE_MARKER_INSTANCE(__LINE__, name)
60 
61 /// Records a timestamp when constructed, using \a name as the key.
62 #define TRACE_MARKER_DYNAMIC(name) \
63         _TRACE_MARKER_DYNAMIC_INSTANCE(__LINE__, name)
64 
65 /// Records a counter \a delta using the \a name as the counter key. The delta can
66 /// be positive or negative. A positive delta will increment the total counter
67 /// value, whereas a negative delta will decrement it. The recorded value will
68 /// be stored at the currently traced scope, and will propagate up to the
69 /// parent scopes.
70 #define TRACE_COUNTER_DELTA(name, delta) \
71         _TRACE_COUNTER_INSTANCE(__LINE__, name, delta, /* isDelta */ true)
72 
73 /// Records a counter delta using the name as the counter key. Similar to
74 /// TRACE_COUNTER_DELTA except that \p name does not need to be a compile time
75 /// string.
76 /// \sa TRACE_COUNTER_DELTA
77 #define TRACE_COUNTER_DELTA_DYNAMIC(name, delta) \
78         TraceCollector::GetInstance().RecordCounterDelta(name, delta);
79 
80 /// Records a counter value using the name as the counter key. The recorded
81 /// value will be stored at the currently traced scope, and will propagate up to
82 /// the parent scopes.
83 #define TRACE_COUNTER_VALUE(name, value) \
84         _TRACE_COUNTER_INSTANCE(__LINE__, name, value, /* isDelta */ false)
85 
86 /// Records a counter value using the name as the counter key. Similar to
87 /// TRACE_COUNTER_VALUE except that \p name does not need to be a compile time
88 /// string.
89 /// \sa TRACE_COUNTER_VALUE
90 #define TRACE_COUNTER_VALUE_DYNAMIC(name, value) \
91         TraceCollector::GetInstance().RecordCounterValue(name, value);
92 
93 /// Records a counter value using the name as the counter key. The value can
94 /// be positive or negative. A positive value will increment the total counter
95 /// value, whereas a negative value will decrement it. The recorded value will
96 /// be stored at the currently traced scope, and will propagate up to the
97 /// parent scopes.
98 ///
99 /// This macro provides the same functionality as TRACE_COUNTER_DELTA, but takes
100 /// a section of code in brackets, which assumes that a value will be
101 /// assigned to 'value'. The section of code will not be executed, when
102 /// tracing is turned off, which makes it possible to gather counter values
103 /// from potentially expensive logic, without incurring an overhead with
104 /// tracing turned off.
105 ///
106 /// Usage:
107 ///
108 /// TRACE_COUNTER_DELTA_CODE("My counter", {
109 ///     value = _ComputeExpensiveCounterValue();
110 /// })
111 #define TRACE_COUNTER_DELTA_CODE(name, code) \
112         _TRACE_COUNTER_CODE_INSTANCE(__LINE__, name, code, true)
113 
114 /// Records a begin event when constructed and an end event when destructed,
115 /// using name of the function or method and the supplied name as the key.
116 /// Unlike TRACE_FUNCTION, the name argument will be evaluated each time this
117 /// macro is invoked. This allows for a single TRACE_FUNCTION to track time
118 /// under different keys, but incurs greater overhead.
119 #define TRACE_FUNCTION_DYNAMIC(name) \
120         _TRACE_FUNCTION_DYNAMIC_INSTANCE(__LINE__, __ARCH_FUNCTION__, __ARCH_PRETTY_FUNCTION__, name)
121 
122 /// Records a begin event when constructed and an end event when destructed,
123 /// using \a name as the key. Unlike TRACE_SCOPE, the name argument will
124 /// be evaluated each time this macro is invoked. This allows for a single
125 /// TRACE_SCOPE to track time under different keys, but incurs greater
126 /// overhead.
127 #define TRACE_SCOPE_DYNAMIC(name) \
128         _TRACE_SCOPE_DYNAMIC_INSTANCE(__LINE__, name)
129 
130 
131 /// These pair a uniquely named TraceScopeHolder with a TraceScopeAuto.
132 /// Together these will register a TraceScope only the first time the
133 /// code is executed or if the TraceScope expires.  Otherwise, the held
134 /// TraceScope will be used to record begin and end events.
135 
136 
137 #define _TRACE_FUNCTION_INSTANCE(instance, name, prettyName) \
138 constexpr static PXR_NS::TraceStaticKeyData \
139     TF_PP_CAT(TraceKeyData_, instance)(name, prettyName); \
140 PXR_NS::TraceScopeAuto TF_PP_CAT(TraceScopeAuto_, instance)(\
141     TF_PP_CAT(TraceKeyData_, instance));
142 
143 #define _TRACE_SCOPE_INSTANCE(instance, name) \
144 constexpr static PXR_NS::TraceStaticKeyData \
145     TF_PP_CAT(TraceKeyData_, instance)(name); \
146 PXR_NS::TraceScopeAuto TF_PP_CAT(TraceScopeAuto_, instance)(\
147     TF_PP_CAT(TraceKeyData_, instance));
148 
149 #define _TRACE_FUNCTION_SCOPE_INSTANCE(instance, name, prettyName, scopeName) \
150 constexpr static PXR_NS::TraceStaticKeyData \
151     TF_PP_CAT(TraceKeyData_, instance)(name, prettyName, scopeName); \
152 PXR_NS::TraceScopeAuto TF_PP_CAT(TraceScopeAuto_, instance)(\
153     TF_PP_CAT(TraceKeyData_, instance));
154 
155 #define _TRACE_MARKER_INSTANCE(instance, name) \
156 constexpr static PXR_NS::TraceStaticKeyData \
157     TF_PP_CAT(TraceKeyData_, instance)(name); \
158     TraceCollector::GetInstance().MarkerEventStatic(TF_PP_CAT(TraceKeyData_, instance));
159 
160 #define _TRACE_COUNTER_INSTANCE(instance, name, value, isDelta) \
161 constexpr static PXR_NS::TraceStaticKeyData \
162     TF_PP_CAT(TraceKeyData_, instance)(name); \
163 static PXR_NS::TraceCounterHolder \
164     TF_PP_CAT(TraceCounterHolder_, instance) \
165     (TF_PP_CAT(TraceKeyData_, instance)); \
166 TF_PP_CAT(TraceCounterHolder_, instance).Record(value, isDelta);
167 
168 #define _TRACE_COUNTER_CODE_INSTANCE(instance, name, code, isDelta) \
169 static PXR_NS::TraceCounterHolder \
170     TF_PP_CAT(TraceCounterHolder_, instance)(name); \
171 if (TF_PP_CAT(TraceCounterHolder_, instance).IsEnabled()) { \
172     double value = 0.0; \
173     code \
174     TF_PP_CAT(TraceCounterHolder_, instance).RecordDelta(value, isDelta); \
175 }
176 
177 #define _TRACE_FUNCTION_DYNAMIC_INSTANCE(instance, fnName, fnPrettyName, name) \
178 PXR_NS::TraceAuto TF_PP_CAT(TraceAuto_, instance)(fnName, fnPrettyName, name)
179 
180 #define _TRACE_SCOPE_DYNAMIC_INSTANCE(instance, str) \
181 PXR_NS::TraceAuto TF_PP_CAT(TraceAuto_, instance)(str)
182 
183 #define _TRACE_MARKER_DYNAMIC_INSTANCE(instance, name) \
184     TraceCollector::GetInstance().MarkerEvent(name);
185 
186 #else // TRACE_DISABLE
187 
188 #define TRACE_FUNCTION()
189 #define TRACE_FUNCTION_DYNAMIC(name)
190 #define TRACE_SCOPE(name)
191 #define TRACE_SCOPE_DYNAMIC(name)
192 #define TRACE_FUNCTION_SCOPE(name)
193 #define TRACE_MARKER(name)
194 #define TRACE_MARKER_DYNAMIC(name)
195 
196 #endif // TRACE_DISABLE
197 
198 PXR_NAMESPACE_OPEN_SCOPE
199 
200 ////////////////////////////////////////////////////////////////////////////////
201 /// \class TraceScopeAuto
202 ///
203 /// A class which records a timestamp when it is created and a
204 /// scope event when it is destructed.
205 ///
206 class TraceScopeAuto {
207 public:
208     /// Constructor for TRACE_FUNCTION macro.
209     ///
TraceScopeAuto(const TraceStaticKeyData & key)210     explicit TraceScopeAuto(const TraceStaticKeyData& key)
211         : _key(nullptr)
212         , _start(0) {
213 
214         if (ARCH_UNLIKELY(TraceCollector::IsEnabled())) {
215             // Init the key if needed.
216             _key = &key;
217             _start = ArchGetTickTime();
218         }
219 
220     }
221 
222     /// Constructor that also records scope arguments.
223     ///
224     template < typename... Args>
TraceScopeAuto(const TraceStaticKeyData & key,Args &&...args)225     TraceScopeAuto(const TraceStaticKeyData& key, Args&&... args)
226         : TraceScopeAuto(key) {
227         if (ARCH_UNLIKELY(_key)) {
228             TraceCollector::GetInstance().ScopeArgs(std::forward<Args>(args)...);
229         }
230     }
231 
232     /// Destructor.
233     ///
~TraceScopeAuto()234     ~TraceScopeAuto() {
235         if (ARCH_UNLIKELY(_key)) {
236             TraceCollector::GetInstance().Scope(*_key, _start);
237         }
238     }
239 
240 private:
241     const TraceStaticKeyData* _key;
242     TraceEvent::TimeStamp _start;
243 };
244 
245 ////////////////////////////////////////////////////////////////////////////////
246 /// \class TraceAuto
247 ///
248 /// A class which records a begin event when it is constructed, and a matching
249 /// end event when it is destructed.  It is intended to help ensure begin-end
250 /// pairing correctness when the begin-end pairing can be expressed by automatic
251 /// variable lifetime.
252 ///
253 /// The TRACE_FUNCTION() macro may be even more convenient in some
254 /// circumstances.
255 ///
256 struct TraceAuto {
257     /// Constructor taking function name, pretty function name and a scope name.
258     ///
TraceAutoTraceAuto259     TraceAuto(const char *funcName, const char *prettyFuncName,
260               const std::string &name)
261         : _key(_CreateKeyString(funcName, prettyFuncName, name)) {
262         std::atomic_thread_fence(std::memory_order_seq_cst);
263         _collector = &TraceCollector::GetInstance();
264         _collector->BeginEvent(_key);
265         std::atomic_thread_fence(std::memory_order_seq_cst);
266     }
267 
268     /// Constructor taking a TfToken key.
269     ///
TraceAutoTraceAuto270     explicit TraceAuto(const TfToken& key)
271         : _key(key) {
272         std::atomic_thread_fence(std::memory_order_seq_cst);
273         _collector = &TraceCollector::GetInstance();
274         _collector->BeginEvent(_key);
275         std::atomic_thread_fence(std::memory_order_seq_cst);
276     }
277 
278     /// Constructor taking a string key.
279     ///
TraceAutoTraceAuto280     explicit TraceAuto(const std::string& key)
281         : TraceAuto(TfToken(key)) {}
282 
283     // Non-copyable
284     //
285     TraceAuto(const TraceAuto &) = delete;
286     TraceAuto& operator=(const TraceAuto &) = delete;
287 
288     // Non-movable
289     //
290     TraceAuto(TraceAuto &&) = delete;
291     TraceAuto& operator=(TraceAuto &&) = delete;
292 
293     /// Destructor.
294     ///
~TraceAutoTraceAuto295     ~TraceAuto() {
296         std::atomic_thread_fence(std::memory_order_seq_cst);
297         _collector->EndEvent(_key);
298         std::atomic_thread_fence(std::memory_order_seq_cst);
299     }
300 
301 private:
_CreateKeyStringTraceAuto302     static std::string _CreateKeyString(
303         const char *funcName,
304         const char *prettyFuncName,
305         const std::string &name) {
306         std::string key = ArchGetPrettierFunctionName(funcName, prettyFuncName);
307         key += " [";
308         key += name;
309         key += "]";
310         return key;
311     }
312 
313     TraceCollector* _collector;
314     TraceDynamicKey _key;
315 };
316 
317 ////////////////////////////////////////////////////////////////////////////////
318 /// \class TraceCounterHolder
319 ///
320 /// Holds on to a counter key, as well as the global
321 /// collector for fast lookup.
322 ///
323 class TraceCounterHolder {
324 public:
325     /// Constructor used by TRACE_COUNTER_* macro.
326     ///
TraceCounterHolder(const TraceKey & key)327     explicit TraceCounterHolder(const TraceKey& key)
328         : _key(key) {}
329 
330     /// Returns whether the TraceCollector is enabled or not.
331     ///
IsEnabled()332     bool IsEnabled() const {
333         return TraceCollector::IsEnabled();
334     }
335 
336     /// Records a counter delta \p value if the TraceCollector is enabled.
337     ///
Record(double value,bool delta)338     void Record(double value, bool delta) {
339         if (delta) {
340             TraceCollector::GetInstance().RecordCounterDelta(_key, value);
341         } else {
342             TraceCollector::GetInstance().RecordCounterValue(_key, value);
343         }
344     }
345 
346 private:
347     TraceKey _key;
348 };
349 
350 PXR_NAMESPACE_CLOSE_SCOPE
351 
352 #endif // PXR_BASE_TRACE_TRACE_H
353