1 // Copyright 2015 The Chromium Authors. All rights reserved.
2 // Use of this source code is governed by a BSD-style license that can be
3 // found in the LICENSE file.
4
5 #include "base/trace_event/trace_event_etw_export_win.h"
6
7 #include <stddef.h>
8
9 #include "base/at_exit.h"
10 #include "base/command_line.h"
11 #include "base/logging.h"
12 #include "base/memory/singleton.h"
13 #include "base/strings/string_tokenizer.h"
14 #include "base/strings/utf_string_conversions.h"
15 #include "base/threading/platform_thread.h"
16 #include "base/trace_event/trace_event.h"
17 #include "base/trace_event/trace_event_impl.h"
18
19 #include <windows.h>
20
21 // The GetProcAddress technique is borrowed from
22 // https://github.com/google/UIforETW/tree/master/ETWProviders
23 //
24 // EVNTAPI is used in evntprov.h which is included by chrome_events_win.h.
25 // We define EVNTAPI without the DECLSPEC_IMPORT specifier so that we can
26 // implement these functions locally instead of using the import library, and
27 // can therefore still run on Windows XP.
28 #define EVNTAPI __stdcall
29 // Include the event register/write/unregister macros compiled from the manifest
30 // file. Note that this includes evntprov.h which requires a Vista+ Windows SDK.
31 //
32 // In SHARED_INTERMEDIATE_DIR.
33
34 // Headers generated by mc.exe have a ';' at the end of extern "C" {} blocks.
35 #if defined(__clang__)
36 #pragma clang diagnostic push
37 #pragma clang diagnostic ignored "-Wextra-semi"
38 #endif
39
40 #include "base/trace_event/etw_manifest/chrome_events_win.h" // NOLINT
41
42 #if defined(__clang__)
43 #pragma clang diagnostic pop
44 #endif
45
46 namespace {
47
48 // |kFilteredEventGroupNames| contains the event categories that can be
49 // exported individually. These categories can be enabled by passing the correct
50 // keyword when starting the trace. A keyword is a 64-bit flag and we attribute
51 // one bit per category. We can therefore enable a particular category by
52 // setting its corresponding bit in the keyword. For events that are not present
53 // in |kFilteredEventGroupNames|, we have two bits that control their
54 // behaviour. When bit 61 is enabled, any event that is not disabled by default
55 // (ie. doesn't start with disabled-by-default-) will be exported. Likewise,
56 // when bit 62 is enabled, any event that is disabled by default will be
57 // exported.
58 //
59 // Note that bit 63 (MSB) must always be set, otherwise tracing will be disabled
60 // by ETW. Therefore, the keyword will always be greater than
61 // 0x8000000000000000.
62 //
63 // Examples of passing keywords to the provider using xperf:
64 // # This exports "benchmark" and "cc" events
65 // xperf -start chrome -on Chrome:0x8000000000000009
66 //
67 // # This exports "gpu", "netlog" and all other events that are not disabled by
68 // # default
69 // xperf -start chrome -on Chrome:0xA0000000000000A0
70 //
71 // More info about starting a trace and keyword can be obtained by using the
72 // help section of xperf (xperf -help start). Note that xperf documentation
73 // refers to keywords as flags and there are two ways to enable them, using
74 // group names or the hex representation. We only support the latter. Also, we
75 // ignore the level.
76 const char* const kFilteredEventGroupNames[] = {
77 "benchmark", // 0x1
78 "blink", // 0x2
79 "browser", // 0x4
80 "cc", // 0x8
81 "evdev", // 0x10
82 "gpu", // 0x20
83 "input", // 0x40
84 "netlog", // 0x80
85 "sequence_manager", // 0x100
86 "toplevel", // 0x200
87 "v8", // 0x400
88 "disabled-by-default-cc.debug", // 0x800
89 "disabled-by-default-cc.debug.picture", // 0x1000
90 "disabled-by-default-toplevel.flow", // 0x2000
91 "startup", // 0x4000
92 "latency", // 0x8000
93 "blink.user_timing", // 0x10000
94 "media", // 0x20000
95 "loading", // 0x40000
96 };
97 const char kOtherEventsGroupName[] = "__OTHER_EVENTS"; // 0x2000000000000000
98 const char kDisabledOtherEventsGroupName[] =
99 "__DISABLED_OTHER_EVENTS"; // 0x4000000000000000
100 const uint64_t kOtherEventsKeywordBit = 1ULL << 61;
101 const uint64_t kDisabledOtherEventsKeywordBit = 1ULL << 62;
102 const size_t kNumberOfCategories = ARRAYSIZE(kFilteredEventGroupNames) + 2U;
103
EtwEnableCallback(LPCGUID SourceId,ULONG ControlCode,UCHAR Level,ULONGLONG MatchAnyKeyword,ULONGLONG MatchAllKeyword,PEVENT_FILTER_DESCRIPTOR FilterData,PVOID CallbackContext)104 static void __stdcall EtwEnableCallback(LPCGUID SourceId,
105 ULONG ControlCode,
106 UCHAR Level,
107 ULONGLONG MatchAnyKeyword,
108 ULONGLONG MatchAllKeyword,
109 PEVENT_FILTER_DESCRIPTOR FilterData,
110 PVOID CallbackContext) {
111 // Invoke the default callback, which updates the information inside
112 // CHROME_Context.
113 McGenControlCallbackV2(SourceId, ControlCode, Level, MatchAnyKeyword,
114 MatchAllKeyword, FilterData, CallbackContext);
115
116 base::trace_event::TraceEventETWExport::OnETWEnableUpdate();
117 }
118
119 } // namespace
120
121 namespace base {
122 namespace trace_event {
123
124 bool TraceEventETWExport::is_registration_complete_ = false;
125
TraceEventETWExport()126 TraceEventETWExport::TraceEventETWExport() : etw_match_any_keyword_(0ULL) {
127 // Register the ETW provider. If registration fails then the event logging
128 // calls will fail. We're essentially doing the same operation as
129 // EventRegisterChrome (which was auto generated for our provider by the
130 // ETW manifest compiler), but instead we're passing our own callback.
131 // This allows us to detect changes to enable/disable/keyword changes.
132 // ChromeHandle and the other parameters to EventRegister are all generated
133 // globals from chrome_events_win.h
134 DCHECK(!ChromeHandle);
135 EventRegister(&CHROME, &EtwEnableCallback, &CHROME_Context, &ChromeHandle);
136 TraceEventETWExport::is_registration_complete_ = true;
137
138 // Make sure to initialize the map with all the group names. Subsequent
139 // modifications will be made by the background thread and only affect the
140 // values of the keys (no key addition/deletion). Therefore, the map does not
141 // require a lock for access.
142 for (size_t i = 0; i < ARRAYSIZE(kFilteredEventGroupNames); i++)
143 categories_status_[kFilteredEventGroupNames[i]] = false;
144 categories_status_[kOtherEventsGroupName] = false;
145 categories_status_[kDisabledOtherEventsGroupName] = false;
146 DCHECK_EQ(kNumberOfCategories, categories_status_.size());
147 }
148
~TraceEventETWExport()149 TraceEventETWExport::~TraceEventETWExport() {
150 EventUnregisterChrome();
151 is_registration_complete_ = false;
152 }
153
154 // static
EnableETWExport()155 void TraceEventETWExport::EnableETWExport() {
156 auto* instance = GetInstance();
157 if (instance) {
158 // Sync the enabled categories with ETW by calling UpdateEnabledCategories()
159 // that checks the keyword. We'll stay in sync via the EtwEnableCallback
160 // we register in TraceEventETWExport's constructor.
161 instance->UpdateEnabledCategories();
162 }
163 }
164
165 // static
AddEvent(char phase,const unsigned char * category_group_enabled,const char * name,unsigned long long id,const TraceArguments * args)166 void TraceEventETWExport::AddEvent(char phase,
167 const unsigned char* category_group_enabled,
168 const char* name,
169 unsigned long long id,
170 const TraceArguments* args) {
171 // We bail early in case exporting is disabled or no consumer is listening.
172 auto* instance = GetInstance();
173 if (!instance || !EventEnabledChromeEvent())
174 return;
175
176 const char* phase_string = nullptr;
177 // Space to store the phase identifier and null-terminator, when needed.
178 char phase_buffer[2];
179 switch (phase) {
180 case TRACE_EVENT_PHASE_BEGIN:
181 phase_string = "Begin";
182 break;
183 case TRACE_EVENT_PHASE_END:
184 phase_string = "End";
185 break;
186 case TRACE_EVENT_PHASE_COMPLETE:
187 phase_string = "Complete";
188 break;
189 case TRACE_EVENT_PHASE_INSTANT:
190 phase_string = "Instant";
191 break;
192 case TRACE_EVENT_PHASE_ASYNC_BEGIN:
193 phase_string = "Async Begin";
194 break;
195 case TRACE_EVENT_PHASE_ASYNC_STEP_INTO:
196 phase_string = "Async Step Into";
197 break;
198 case TRACE_EVENT_PHASE_ASYNC_STEP_PAST:
199 phase_string = "Async Step Past";
200 break;
201 case TRACE_EVENT_PHASE_ASYNC_END:
202 phase_string = "Async End";
203 break;
204 case TRACE_EVENT_PHASE_NESTABLE_ASYNC_BEGIN:
205 phase_string = "Nestable Async Begin";
206 break;
207 case TRACE_EVENT_PHASE_NESTABLE_ASYNC_END:
208 phase_string = "Nestable Async End";
209 break;
210 case TRACE_EVENT_PHASE_NESTABLE_ASYNC_INSTANT:
211 phase_string = "Nestable Async Instant";
212 break;
213 case TRACE_EVENT_PHASE_FLOW_BEGIN:
214 phase_string = "Phase Flow Begin";
215 break;
216 case TRACE_EVENT_PHASE_FLOW_STEP:
217 phase_string = "Phase Flow Step";
218 break;
219 case TRACE_EVENT_PHASE_FLOW_END:
220 phase_string = "Phase Flow End";
221 break;
222 case TRACE_EVENT_PHASE_METADATA:
223 phase_string = "Phase Metadata";
224 break;
225 case TRACE_EVENT_PHASE_COUNTER:
226 phase_string = "Phase Counter";
227 break;
228 case TRACE_EVENT_PHASE_SAMPLE:
229 phase_string = "Phase Sample";
230 break;
231 case TRACE_EVENT_PHASE_CREATE_OBJECT:
232 phase_string = "Phase Create Object";
233 break;
234 case TRACE_EVENT_PHASE_SNAPSHOT_OBJECT:
235 phase_string = "Phase Snapshot Object";
236 break;
237 case TRACE_EVENT_PHASE_DELETE_OBJECT:
238 phase_string = "Phase Delete Object";
239 break;
240 default:
241 phase_buffer[0] = phase;
242 phase_buffer[1] = 0;
243 phase_string = phase_buffer;
244 break;
245 }
246
247 std::string arg_values_string[3];
248 size_t num_args = args ? args->size() : 0;
249 for (size_t i = 0; i < num_args; i++) {
250 if (args->types()[i] == TRACE_VALUE_TYPE_CONVERTABLE) {
251 // Temporarily do nothing here. This function consumes 1/3 to 1/2 of
252 // *total* process CPU time when ETW tracing, and many of the strings
253 // created exceed WPA's 4094 byte limit and are shown as:
254 // "Unable to parse data". See crbug.com/488257
255 } else {
256 args->values()[i].AppendAsString(args->types()[i], arg_values_string + i);
257 }
258 }
259
260 EventWriteChromeEvent(
261 name, phase_string, num_args > 0 ? args->names()[0] : "",
262 arg_values_string[0].c_str(), num_args > 1 ? args->names()[1] : "",
263 arg_values_string[1].c_str(), "", "");
264 }
265
266 // static
AddCompleteEndEvent(const char * name)267 void TraceEventETWExport::AddCompleteEndEvent(const char* name) {
268 auto* instance = GetInstance();
269 if (!instance || !EventEnabledChromeEvent())
270 return;
271
272 EventWriteChromeEvent(name, "Complete End", "", "", "", "", "", "");
273 }
274
275 // static
IsCategoryGroupEnabled(StringPiece category_group_name)276 bool TraceEventETWExport::IsCategoryGroupEnabled(
277 StringPiece category_group_name) {
278 DCHECK(!category_group_name.empty());
279 auto* instance = GetInstanceIfExists();
280 if (instance == nullptr)
281 return false;
282
283 if (!EventEnabledChromeEvent())
284 return false;
285
286 CStringTokenizer category_group_tokens(category_group_name.begin(),
287 category_group_name.end(), ",");
288 while (category_group_tokens.GetNext()) {
289 StringPiece category_group_token = category_group_tokens.token_piece();
290 if (instance->IsCategoryEnabled(category_group_token)) {
291 return true;
292 }
293 }
294 return false;
295 }
296
UpdateEnabledCategories()297 bool TraceEventETWExport::UpdateEnabledCategories() {
298 if (etw_match_any_keyword_ == CHROME_Context.MatchAnyKeyword)
299 return false;
300
301 // If the keyword has changed, update each category.
302 // Chrome_Context.MatchAnyKeyword is set by UIforETW (or other ETW trace
303 // recording tools) using the ETW infrastructure. This value will be set in
304 // all Chrome processes that have registered their ETW provider.
305 etw_match_any_keyword_ = CHROME_Context.MatchAnyKeyword;
306 for (size_t i = 0; i < ARRAYSIZE(kFilteredEventGroupNames); i++) {
307 if (etw_match_any_keyword_ & (1ULL << i)) {
308 categories_status_[kFilteredEventGroupNames[i]] = true;
309 } else {
310 categories_status_[kFilteredEventGroupNames[i]] = false;
311 }
312 }
313
314 // Also update the two default categories.
315 if (etw_match_any_keyword_ & kOtherEventsKeywordBit) {
316 categories_status_[kOtherEventsGroupName] = true;
317 } else {
318 categories_status_[kOtherEventsGroupName] = false;
319 }
320 if (etw_match_any_keyword_ & kDisabledOtherEventsKeywordBit) {
321 categories_status_[kDisabledOtherEventsGroupName] = true;
322 } else {
323 categories_status_[kDisabledOtherEventsGroupName] = false;
324 }
325
326 DCHECK_EQ(kNumberOfCategories, categories_status_.size());
327
328 // Update the categories in TraceLog.
329 TraceLog::GetInstance()->UpdateETWCategoryGroupEnabledFlags();
330
331 return true;
332 }
333
IsCategoryEnabled(StringPiece category_name) const334 bool TraceEventETWExport::IsCategoryEnabled(StringPiece category_name) const {
335 DCHECK_EQ(kNumberOfCategories, categories_status_.size());
336 // Try to find the category and return its status if found
337 auto it = categories_status_.find(category_name);
338 if (it != categories_status_.end())
339 return it->second;
340
341 // Otherwise return the corresponding default status by first checking if the
342 // category is disabled by default.
343 if (category_name.starts_with("disabled-by-default")) {
344 DCHECK(categories_status_.find(kDisabledOtherEventsGroupName) !=
345 categories_status_.end());
346 return categories_status_.find(kDisabledOtherEventsGroupName)->second;
347 } else {
348 DCHECK(categories_status_.find(kOtherEventsGroupName) !=
349 categories_status_.end());
350 return categories_status_.find(kOtherEventsGroupName)->second;
351 }
352 }
353
354 // static
OnETWEnableUpdate()355 void TraceEventETWExport::OnETWEnableUpdate() {
356 // During construction, if tracing is already enabled, we'll get
357 // a callback synchronously on the same thread. Calling GetInstance
358 // in that case will hang since we're in the process of creating the
359 // singleton.
360 if (is_registration_complete_) {
361 auto* instance = GetInstance();
362 if (instance)
363 instance->UpdateEnabledCategories();
364 }
365 }
366
367 // static
GetInstance()368 TraceEventETWExport* TraceEventETWExport::GetInstance() {
369 return Singleton<TraceEventETWExport,
370 StaticMemorySingletonTraits<TraceEventETWExport>>::get();
371 }
372
373 // static
GetInstanceIfExists()374 TraceEventETWExport* TraceEventETWExport::GetInstanceIfExists() {
375 return Singleton<
376 TraceEventETWExport,
377 StaticMemorySingletonTraits<TraceEventETWExport>>::GetIfExists();
378 }
379
380 } // namespace trace_event
381 } // namespace base
382