• Home
  • Line#
  • Scopes#
  • Navigate#
  • Raw
  • Download
1 // Copyright 2015 The Chromium Authors
2 // Use of this source code is governed by a BSD-style license that can be
3 // found in the LICENSE file.
4 
5 #ifndef BASE_TRACE_EVENT_COMMON_TRACE_EVENT_COMMON_H_
6 #define BASE_TRACE_EVENT_COMMON_TRACE_EVENT_COMMON_H_
7 
8 // Trace events are for tracking application performance and resource usage.
9 // Macros are provided to track:
10 //    Begin and end of function calls
11 //    Counters
12 //
13 // Events are issued against categories. Whereas LOG's
14 // categories are statically defined, TRACE categories are created
15 // implicitly with a string. For example:
16 //   TRACE_EVENT_INSTANT0("MY_SUBSYSTEM", "SomeImportantEvent",
17 //                        TRACE_EVENT_SCOPE_THREAD)
18 //
19 // It is often the case that one trace may belong in multiple categories at the
20 // same time. The first argument to the trace can be a comma-separated list of
21 // categories, forming a category group, like:
22 //
23 // TRACE_EVENT_INSTANT0("input,views", "OnMouseOver", TRACE_EVENT_SCOPE_THREAD)
24 //
25 // We can enable/disable tracing of OnMouseOver by enabling/disabling either
26 // category.
27 //
28 // Events can be INSTANT, or can be pairs of BEGIN and END in the same scope:
29 //   TRACE_EVENT_BEGIN0("MY_SUBSYSTEM", "SomethingCostly")
30 //   doSomethingCostly()
31 //   TRACE_EVENT_END0("MY_SUBSYSTEM", "SomethingCostly")
32 // Note: our tools can't always determine the correct BEGIN/END pairs unless
33 // these are used in the same scope. Use ASYNC_BEGIN/ASYNC_END macros if you
34 // need them to be in separate scopes.
35 //
36 // A common use case is to trace entire function scopes. This
37 // issues a trace BEGIN and END automatically:
38 //   void doSomethingCostly() {
39 //     TRACE_EVENT0("MY_SUBSYSTEM", "doSomethingCostly");
40 //     ...
41 //   }
42 //
43 // Additional parameters can be associated with an event:
44 //   void doSomethingCostly2(int howMuch) {
45 //     TRACE_EVENT1("MY_SUBSYSTEM", "doSomethingCostly",
46 //         "howMuch", howMuch);
47 //     ...
48 //   }
49 //
50 // The trace system will automatically add to this information the
51 // current process id, thread id, and a timestamp in microseconds.
52 //
53 // To trace an asynchronous procedure such as an IPC send/receive, use
54 // NESTABLE_ASYNC_BEGIN and NESTABLE_ASYNC_END:
55 //   [single threaded sender code]
56 //     static int send_count = 0;
57 //     ++send_count;
58 //     TRACE_EVENT_NESTABLE_ASYNC_BEGIN0(
59 //         "ipc", "message", TRACE_ID_WITH_SCOPE("message", send_count));
60 //     Send(new MyMessage(send_count));
61 //   [receive code]
62 //     void OnMyMessage(send_count) {
63 //       TRACE_NESTABLE_EVENT_ASYNC_END0(
64 //           "ipc", "message", TRACE_ID_WITH_SCOPE("message", send_count));
65 //     }
66 // The third parameter is a unique ID to match NESTABLE_ASYNC_BEGIN/ASYNC_END
67 // pairs. NESTABLE_ASYNC_BEGIN and ASYNC_END can occur on any thread of any
68 // traced process. // Pointers can be used for the ID parameter, and they will
69 // be annotated internally so that the same pointer on two different processes
70 // will not match. For example:
71 //   class MyTracedClass {
72 //    public:
73 //     MyTracedClass() {
74 //       TRACE_EVENT_NESTABLE_ASYNC_BEGIN0("category", "MyTracedClass",
75 //                                         TRACE_ID_LOCAL(this));
76 //     }
77 //     ~MyTracedClass() {
78 //       TRACE_EVENT_NESTABLE_ASYNC_END0("category", "MyTracedClass",
79 //                                       TRACE_ID_LOCAL(this));
80 //     }
81 //   }
82 //
83 // Trace event also supports counters, which is a way to track a quantity
84 // as it varies over time. Counters are created with the following macro:
85 //   TRACE_COUNTER1("MY_SUBSYSTEM", "myCounter", g_myCounterValue);
86 //
87 // Counters are process-specific. The macro itself can be issued from any
88 // thread, however.
89 //
90 // Sometimes, you want to track two counters at once. You can do this with two
91 // counter macros:
92 //   TRACE_COUNTER1("MY_SUBSYSTEM", "myCounter0", g_myCounterValue[0]);
93 //   TRACE_COUNTER1("MY_SUBSYSTEM", "myCounter1", g_myCounterValue[1]);
94 // Or you can do it with a combined macro:
95 //   TRACE_COUNTER2("MY_SUBSYSTEM", "myCounter",
96 //       "bytesPinned", g_myCounterValue[0],
97 //       "bytesAllocated", g_myCounterValue[1]);
98 // This indicates to the tracing UI that these counters should be displayed
99 // in a single graph, as a summed area chart.
100 //
101 // Since counters are in a global namespace, you may want to disambiguate with a
102 // unique ID, by using the TRACE_COUNTER_ID* variations.
103 //
104 // By default, trace collection is compiled in, but turned off at runtime.
105 // Collecting trace data is the responsibility of the embedding
106 // application. In Chrome's case, navigating to about:tracing will turn on
107 // tracing and display data collected across all active processes.
108 //
109 //
110 // Memory scoping note:
111 // Tracing copies the pointers, not the string content, of the strings passed
112 // in for category_group, name, and arg_names.  Thus, the following code will
113 // cause problems:
114 //     char* str = strdup("importantName");
115 //     TRACE_EVENT_INSTANT0("SUBSYSTEM", str);  // BAD!
116 //     free(str);                   // Trace system now has dangling pointer
117 //
118 // To avoid this issue with the |name| and |arg_name| parameters, use the
119 // TRACE_EVENT_COPY_XXX overloads of the macros at additional runtime overhead.
120 // Notes: The category must always be in a long-lived char* (i.e. static const).
121 //        The |arg_values|, when used, are always deep copied with the _COPY
122 //        macros.
123 //
124 // When are string argument values copied:
125 // const char* arg_values are only referenced by default:
126 //     TRACE_EVENT1("category", "name",
127 //                  "arg1", "literal string is only referenced");
128 // Use TRACE_STR_COPY to force copying of a const char*:
129 //     TRACE_EVENT1("category", "name",
130 //                  "arg1", TRACE_STR_COPY("string will be copied"));
131 // std::string arg_values are always copied:
132 //     TRACE_EVENT1("category", "name",
133 //                  "arg1", std::string("string will be copied"));
134 //
135 //
136 // Convertable notes:
137 // Converting a large data type to a string can be costly. To help with this,
138 // the trace framework provides an interface ConvertableToTraceFormat. If you
139 // inherit from it and implement the AppendAsTraceFormat method the trace
140 // framework will call back to your object to convert a trace output time. This
141 // means, if the category for the event is disabled, the conversion will not
142 // happen.
143 //
144 //   class MyData : public base::trace_event::ConvertableToTraceFormat {
145 //    public:
146 //     MyData() {}
147 //
148 //     MyData(const MyData&) = delete;
149 //     MyData& operator=(const MyData&) = delete;
150 //
151 //     void AppendAsTraceFormat(std::string* out) const override {
152 //       out->append("{\"foo\":1}");
153 //     }
154 //    private:
155 //     ~MyData() override {}
156 //   };
157 //
158 //   TRACE_EVENT1("foo", "bar", "data",
159 //                std::unique_ptr<ConvertableToTraceFormat>(new MyData()));
160 //
161 // The trace framework will take ownership if the passed pointer and it will
162 // be free'd when the trace buffer is flushed.
163 //
164 // Note, we only do the conversion when the buffer is flushed, so the provided
165 // data object should not be modified after it's passed to the trace framework.
166 //
167 //
168 // Thread Safety:
169 // A thread safe singleton and mutex are used for thread safety. Category
170 // enabled flags are used to limit the performance impact when the system
171 // is not enabled.
172 //
173 // TRACE_EVENT macros first cache a pointer to a category. The categories are
174 // statically allocated and safe at all times, even after exit. Fetching a
175 // category is protected by the TraceLog::lock_. Multiple threads initializing
176 // the static variable is safe, as they will be serialized by the lock and
177 // multiple calls will return the same pointer to the category.
178 //
179 // Then the category_group_enabled flag is checked. This is a unsigned char, and
180 // not intended to be multithread safe. It optimizes access to AddTraceEvent
181 // which is threadsafe internally via TraceLog::lock_. The enabled flag may
182 // cause some threads to incorrectly call or skip calling AddTraceEvent near
183 // the time of the system being enabled or disabled. This is acceptable as
184 // we tolerate some data loss while the system is being enabled/disabled and
185 // because AddTraceEvent is threadsafe internally and checks the enabled state
186 // again under lock.
187 //
188 // Without the use of these static category pointers and enabled flags all
189 // trace points would carry a significant performance cost of acquiring a lock
190 // and resolving the category.
191 
192 ////////////////////////////////////////////////////////////////////////////////
193 // Perfetto trace macros
194 
195 #include "base/threading/platform_thread.h"
196 #include "base/time/time.h"
197 #include "build/build_config.h"
198 
199 #if BUILDFLAG(ENABLE_BASE_TRACING)
200 
201 // Enable legacy trace event macros (e.g., TRACE_EVENT{0,1,2}).
202 #define PERFETTO_ENABLE_LEGACY_TRACE_EVENTS 1
203 
204 // Macros for reading the current trace time (bypassing any virtual time
205 // overrides).
206 #define TRACE_TIME_TICKS_NOW() ::base::subtle::TimeTicksNowIgnoringOverride()
207 #define TRACE_TIME_NOW() ::base::subtle::TimeNowIgnoringOverride()
208 
209 // Implementation detail: trace event macros create temporary variables
210 // to keep instrumentation overhead low. These macros give each temporary
211 // variable a unique name based on the line number to prevent name collisions.
212 #define INTERNAL_TRACE_EVENT_UID(name_prefix) PERFETTO_UID(name_prefix)
213 
214 // Declare debug annotation converters for base time types, so they can be
215 // passed as trace event arguments.
216 // TODO(skyostil): Serialize timestamps using perfetto::TracedValue instead.
217 namespace perfetto {
218 namespace protos {
219 namespace pbzero {
220 class DebugAnnotation;
221 }  // namespace pbzero
222 }  // namespace protos
223 namespace internal {
224 
225 void BASE_EXPORT
226 WriteDebugAnnotation(protos::pbzero::DebugAnnotation* annotation,
227                      ::base::TimeTicks);
228 void BASE_EXPORT
229 WriteDebugAnnotation(protos::pbzero::DebugAnnotation* annotation, ::base::Time);
230 
231 }  // namespace internal
232 }  // namespace perfetto
233 
234 // Pull in the tracing macro definitions from Perfetto.
235 #include "third_party/perfetto/include/perfetto/tracing/track_event.h"  // IWYU pragma: export
236 #include "third_party/perfetto/include/perfetto/tracing/track_event_legacy.h"  // IWYU pragma: export
237 
238 namespace perfetto {
239 namespace legacy {
240 
241 template <>
242 perfetto::ThreadTrack BASE_EXPORT
243 ConvertThreadId(const ::base::PlatformThreadId& thread);
244 
245 #if BUILDFLAG(IS_WIN)
246 template <>
247 perfetto::ThreadTrack BASE_EXPORT ConvertThreadId(const int& thread);
248 #endif  // BUILDFLAG(IS_WIN)
249 
250 }  // namespace legacy
251 
252 template <>
253 struct BASE_EXPORT TraceTimestampTraits<::base::TimeTicks> {
254   static TraceTimestamp ConvertTimestampToTraceTimeNs(
255       const ::base::TimeTicks& ticks);
256 };
257 
258 }  // namespace perfetto
259 
260 #else  // !BUILDFLAG(ENABLE_BASE_TRACING)
261 
262 // This macro is still used in some components even when base tracing is
263 // disabled.
264 // TODO(crbug/336718643): Make sure no code affected by
265 // enable_base_tracing=false includes this file directly, then move the define
266 // to trace_event_stub.h.
267 #define TRACE_DISABLED_BY_DEFAULT(name) "disabled-by-default-" name
268 
269 #endif  // !BUILDFLAG(ENABLE_BASE_TRACING)
270 
271 #endif  // BASE_TRACE_EVENT_COMMON_TRACE_EVENT_COMMON_H_
272