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