1 // Copyright (c) 2012 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 6 #ifndef BASE_DEBUG_TRACE_EVENT_IMPL_H_ 7 #define BASE_DEBUG_TRACE_EVENT_IMPL_H_ 8 9 #include <stack> 10 #include <string> 11 #include <vector> 12 13 #include "base/callback.h" 14 #include "base/containers/hash_tables.h" 15 #include "base/gtest_prod_util.h" 16 #include "base/memory/ref_counted_memory.h" 17 #include "base/memory/scoped_vector.h" 18 #include "base/observer_list.h" 19 #include "base/strings/string_util.h" 20 #include "base/synchronization/condition_variable.h" 21 #include "base/synchronization/lock.h" 22 #include "base/threading/thread.h" 23 #include "base/timer/timer.h" 24 25 // Older style trace macros with explicit id and extra data 26 // Only these macros result in publishing data to ETW as currently implemented. 27 #define TRACE_EVENT_BEGIN_ETW(name, id, extra) \ 28 base::debug::TraceLog::AddTraceEventEtw( \ 29 TRACE_EVENT_PHASE_BEGIN, \ 30 name, reinterpret_cast<const void*>(id), extra) 31 32 #define TRACE_EVENT_END_ETW(name, id, extra) \ 33 base::debug::TraceLog::AddTraceEventEtw( \ 34 TRACE_EVENT_PHASE_END, \ 35 name, reinterpret_cast<const void*>(id), extra) 36 37 #define TRACE_EVENT_INSTANT_ETW(name, id, extra) \ 38 base::debug::TraceLog::AddTraceEventEtw( \ 39 TRACE_EVENT_PHASE_INSTANT, \ 40 name, reinterpret_cast<const void*>(id), extra) 41 42 template <typename Type> 43 struct DefaultSingletonTraits; 44 45 namespace base { 46 47 class WaitableEvent; 48 49 namespace debug { 50 51 // For any argument of type TRACE_VALUE_TYPE_CONVERTABLE the provided 52 // class must implement this interface. 53 class ConvertableToTraceFormat { 54 public: 55 virtual ~ConvertableToTraceFormat() {} 56 57 // Append the class info to the provided |out| string. The appended 58 // data must be a valid JSON object. Strings must be properly quoted, and 59 // escaped. There is no processing applied to the content after it is 60 // appended. 61 virtual void AppendAsTraceFormat(std::string* out) const = 0; 62 }; 63 64 const int kTraceMaxNumArgs = 2; 65 66 // Output records are "Events" and can be obtained via the 67 // OutputCallback whenever the tracing system decides to flush. This 68 // can happen at any time, on any thread, or you can programmatically 69 // force it to happen. 70 class BASE_EXPORT TraceEvent { 71 public: 72 union TraceValue { 73 bool as_bool; 74 unsigned long long as_uint; 75 long long as_int; 76 double as_double; 77 const void* as_pointer; 78 const char* as_string; 79 }; 80 81 TraceEvent(); 82 TraceEvent(int thread_id, 83 TimeTicks timestamp, 84 char phase, 85 const unsigned char* category_group_enabled, 86 const char* name, 87 unsigned long long id, 88 int num_args, 89 const char** arg_names, 90 const unsigned char* arg_types, 91 const unsigned long long* arg_values, 92 scoped_ptr<ConvertableToTraceFormat> convertable_values[], 93 unsigned char flags); 94 TraceEvent(const TraceEvent& other); 95 TraceEvent& operator=(const TraceEvent& other); 96 ~TraceEvent(); 97 98 // Serialize event data to JSON 99 static void AppendEventsAsJSON(const std::vector<TraceEvent>& events, 100 size_t start, 101 size_t count, 102 std::string* out); 103 void AppendAsJSON(std::string* out) const; 104 void AppendPrettyPrinted(std::ostringstream* out) const; 105 106 static void AppendValueAsJSON(unsigned char type, 107 TraceValue value, 108 std::string* out); 109 110 TimeTicks timestamp() const { return timestamp_; } 111 112 // Exposed for unittesting: 113 114 const base::RefCountedString* parameter_copy_storage() const { 115 return parameter_copy_storage_.get(); 116 } 117 118 const unsigned char* category_group_enabled() const { 119 return category_group_enabled_; 120 } 121 122 const char* name() const { return name_; } 123 124 private: 125 // Note: these are ordered by size (largest first) for optimal packing. 126 TimeTicks timestamp_; 127 // id_ can be used to store phase-specific data. 128 unsigned long long id_; 129 TraceValue arg_values_[kTraceMaxNumArgs]; 130 const char* arg_names_[kTraceMaxNumArgs]; 131 scoped_ptr<ConvertableToTraceFormat> convertable_values_[kTraceMaxNumArgs]; 132 const unsigned char* category_group_enabled_; 133 const char* name_; 134 scoped_refptr<base::RefCountedString> parameter_copy_storage_; 135 int thread_id_; 136 char phase_; 137 unsigned char flags_; 138 unsigned char arg_types_[kTraceMaxNumArgs]; 139 }; 140 141 // TraceBuffer holds the events as they are collected. 142 class BASE_EXPORT TraceBuffer { 143 public: 144 virtual ~TraceBuffer() {} 145 146 virtual void AddEvent(const TraceEvent& event) = 0; 147 virtual bool HasMoreEvents() const = 0; 148 virtual const TraceEvent& NextEvent() = 0; 149 virtual bool IsFull() const = 0; 150 virtual size_t CountEnabledByName(const unsigned char* category, 151 const std::string& event_name) const = 0; 152 virtual size_t Size() const = 0; 153 virtual const TraceEvent& GetEventAt(size_t index) const = 0; 154 }; 155 156 // TraceResultBuffer collects and converts trace fragments returned by TraceLog 157 // to JSON output. 158 class BASE_EXPORT TraceResultBuffer { 159 public: 160 typedef base::Callback<void(const std::string&)> OutputCallback; 161 162 // If you don't need to stream JSON chunks out efficiently, and just want to 163 // get a complete JSON string after calling Finish, use this struct to collect 164 // JSON trace output. 165 struct BASE_EXPORT SimpleOutput { 166 OutputCallback GetCallback(); 167 void Append(const std::string& json_string); 168 169 // Do what you want with the json_output_ string after calling 170 // TraceResultBuffer::Finish. 171 std::string json_output; 172 }; 173 174 TraceResultBuffer(); 175 ~TraceResultBuffer(); 176 177 // Set callback. The callback will be called during Start with the initial 178 // JSON output and during AddFragment and Finish with following JSON output 179 // chunks. The callback target must live past the last calls to 180 // TraceResultBuffer::Start/AddFragment/Finish. 181 void SetOutputCallback(const OutputCallback& json_chunk_callback); 182 183 // Start JSON output. This resets all internal state, so you can reuse 184 // the TraceResultBuffer by calling Start. 185 void Start(); 186 187 // Call AddFragment 0 or more times to add trace fragments from TraceLog. 188 void AddFragment(const std::string& trace_fragment); 189 190 // When all fragments have been added, call Finish to complete the JSON 191 // formatted output. 192 void Finish(); 193 194 private: 195 OutputCallback output_callback_; 196 bool append_comma_; 197 }; 198 199 class BASE_EXPORT CategoryFilter { 200 public: 201 // The default category filter, used when none is provided. 202 // Allows all categories through, except if they end in the suffix 'Debug' or 203 // 'Test'. 204 static const char* kDefaultCategoryFilterString; 205 206 // |filter_string| is a comma-delimited list of category wildcards. 207 // A category can have an optional '-' prefix to make it an excluded category. 208 // All the same rules apply above, so for example, having both included and 209 // excluded categories in the same list would not be supported. 210 // 211 // Example: CategoryFilter"test_MyTest*"); 212 // Example: CategoryFilter("test_MyTest*,test_OtherStuff"); 213 // Example: CategoryFilter("-excluded_category1,-excluded_category2"); 214 // Example: CategoryFilter("-*,webkit"); would disable everything but webkit. 215 // Example: CategoryFilter("-webkit"); would enable everything but webkit. 216 explicit CategoryFilter(const std::string& filter_string); 217 218 CategoryFilter(const CategoryFilter& cf); 219 220 ~CategoryFilter(); 221 222 CategoryFilter& operator=(const CategoryFilter& rhs); 223 224 // Writes the string representation of the CategoryFilter. This is a comma 225 // separated string, similar in nature to the one used to determine 226 // enabled/disabled category patterns, except here there is an arbitrary 227 // order, included categories go first, then excluded categories. Excluded 228 // categories are distinguished from included categories by the prefix '-'. 229 std::string ToString() const; 230 231 // Determines whether category group would be enabled or 232 // disabled by this category filter. 233 bool IsCategoryGroupEnabled(const char* category_group) const; 234 235 // Merges nested_filter with the current CategoryFilter 236 void Merge(const CategoryFilter& nested_filter); 237 238 // Clears both included/excluded pattern lists. This would be equivalent to 239 // creating a CategoryFilter with an empty string, through the constructor. 240 // i.e: CategoryFilter(""). 241 // 242 // When using an empty filter, all categories are considered included as we 243 // are not excluding anything. 244 void Clear(); 245 246 private: 247 FRIEND_TEST_ALL_PREFIXES(TraceEventTestFixture, CategoryFilter); 248 249 static bool IsEmptyOrContainsLeadingOrTrailingWhitespace( 250 const std::string& str); 251 252 typedef std::vector<std::string> StringList; 253 254 void Initialize(const std::string& filter_string); 255 void WriteString(const StringList& values, 256 std::string* out, 257 bool included) const; 258 bool HasIncludedPatterns() const; 259 260 bool DoesCategoryGroupContainCategory(const char* category_group, 261 const char* category) const; 262 263 StringList included_; 264 StringList disabled_; 265 StringList excluded_; 266 }; 267 268 class TraceSamplingThread; 269 270 class BASE_EXPORT TraceLog { 271 public: 272 // Notification is a mask of one or more of the following events. 273 enum Notification { 274 // The trace buffer does not flush dynamically, so when it fills up, 275 // subsequent trace events will be dropped. This callback is generated when 276 // the trace buffer is full. The callback must be thread safe. 277 TRACE_BUFFER_FULL = 1 << 0, 278 // A subscribed trace-event occurred. 279 EVENT_WATCH_NOTIFICATION = 1 << 1 280 }; 281 282 // Options determines how the trace buffer stores data. 283 enum Options { 284 // Record until the trace buffer is full. 285 RECORD_UNTIL_FULL = 1 << 0, 286 287 // Record until the user ends the trace. The trace buffer is a fixed size 288 // and we use it as a ring buffer during recording. 289 RECORD_CONTINUOUSLY = 1 << 1, 290 291 // Enable the sampling profiler. 292 ENABLE_SAMPLING = 1 << 2, 293 294 // Echo to console. Events are discarded. 295 ECHO_TO_CONSOLE = 1 << 3 296 }; 297 298 static TraceLog* GetInstance(); 299 300 // Convert the given string to trace options. Defaults to RECORD_UNTIL_FULL if 301 // the string does not provide valid options. 302 static Options TraceOptionsFromString(const std::string& str); 303 304 // Get set of known category groups. This can change as new code paths are 305 // reached. The known category groups are inserted into |category_groups|. 306 void GetKnownCategoryGroups(std::vector<std::string>* category_groups); 307 308 // Retrieves the current CategoryFilter. 309 const CategoryFilter& GetCurrentCategoryFilter(); 310 311 Options trace_options() const { return trace_options_; } 312 313 // Enables tracing. See CategoryFilter comments for details 314 // on how to control what categories will be traced. 315 void SetEnabled(const CategoryFilter& category_filter, Options options); 316 317 // Disable tracing for all categories. 318 void SetDisabled(); 319 bool IsEnabled() { return !!enable_count_; } 320 321 // The number of times we have begun recording traces. If tracing is off, 322 // returns -1. If tracing is on, then it returns the number of times we have 323 // recorded a trace. By watching for this number to increment, you can 324 // passively discover when a new trace has begun. This is then used to 325 // implement the TRACE_EVENT_IS_NEW_TRACE() primitive. 326 int GetNumTracesRecorded(); 327 328 #if defined(OS_ANDROID) 329 void StartATrace(); 330 void StopATrace(); 331 #endif 332 333 // Enabled state listeners give a callback when tracing is enabled or 334 // disabled. This can be used to tie into other library's tracing systems 335 // on-demand. 336 class EnabledStateObserver { 337 public: 338 // Called just after the tracing system becomes enabled, outside of the 339 // |lock_|. TraceLog::IsEnabled() is true at this point. 340 virtual void OnTraceLogEnabled() = 0; 341 342 // Called just after the tracing system disables, outside of the |lock_|. 343 // TraceLog::IsEnabled() is false at this point. 344 virtual void OnTraceLogDisabled() = 0; 345 }; 346 void AddEnabledStateObserver(EnabledStateObserver* listener); 347 void RemoveEnabledStateObserver(EnabledStateObserver* listener); 348 bool HasEnabledStateObserver(EnabledStateObserver* listener) const; 349 350 float GetBufferPercentFull() const; 351 352 // Set the thread-safe notification callback. The callback can occur at any 353 // time and from any thread. WARNING: It is possible for the previously set 354 // callback to be called during OR AFTER a call to SetNotificationCallback. 355 // Therefore, the target of the callback must either be a global function, 356 // ref-counted object or a LazyInstance with Leaky traits (or equivalent). 357 typedef base::Callback<void(int)> NotificationCallback; 358 void SetNotificationCallback(const NotificationCallback& cb); 359 360 // Not using base::Callback because of its limited by 7 parameters. 361 // Also, using primitive type allows directly passing callback from WebCore. 362 // WARNING: It is possible for the previously set callback to be called 363 // after a call to SetEventCallback() that replaces or clears the callback. 364 // This callback may be invoked on any thread. 365 typedef void (*EventCallback)(char phase, 366 const unsigned char* category_group_enabled, 367 const char* name, 368 unsigned long long id, 369 int num_args, 370 const char* const arg_names[], 371 const unsigned char arg_types[], 372 const unsigned long long arg_values[], 373 unsigned char flags); 374 void SetEventCallback(EventCallback cb); 375 376 // Flush all collected events to the given output callback. The callback will 377 // be called one or more times with IPC-bite-size chunks. The string format is 378 // undefined. Use TraceResultBuffer to convert one or more trace strings to 379 // JSON. 380 typedef base::Callback<void(const scoped_refptr<base::RefCountedString>&)> 381 OutputCallback; 382 void Flush(const OutputCallback& cb); 383 384 // Called by TRACE_EVENT* macros, don't call this directly. 385 // The name parameter is a category group for example: 386 // TRACE_EVENT0("renderer,webkit", "WebViewImpl::HandleInputEvent") 387 static const unsigned char* GetCategoryGroupEnabled(const char* name); 388 static const char* GetCategoryGroupName( 389 const unsigned char* category_group_enabled); 390 391 // Called by TRACE_EVENT* macros, don't call this directly. 392 // If |copy| is set, |name|, |arg_name1| and |arg_name2| will be deep copied 393 // into the event; see "Memory scoping note" and TRACE_EVENT_COPY_XXX above. 394 void AddTraceEvent(char phase, 395 const unsigned char* category_group_enabled, 396 const char* name, 397 unsigned long long id, 398 int num_args, 399 const char** arg_names, 400 const unsigned char* arg_types, 401 const unsigned long long* arg_values, 402 scoped_ptr<ConvertableToTraceFormat> convertable_values[], 403 unsigned char flags); 404 void AddTraceEventWithThreadIdAndTimestamp( 405 char phase, 406 const unsigned char* category_group_enabled, 407 const char* name, 408 unsigned long long id, 409 int thread_id, 410 const TimeTicks& timestamp, 411 int num_args, 412 const char** arg_names, 413 const unsigned char* arg_types, 414 const unsigned long long* arg_values, 415 scoped_ptr<ConvertableToTraceFormat> convertable_values[], 416 unsigned char flags); 417 static void AddTraceEventEtw(char phase, 418 const char* category_group, 419 const void* id, 420 const char* extra); 421 static void AddTraceEventEtw(char phase, 422 const char* category_group, 423 const void* id, 424 const std::string& extra); 425 426 // For every matching event, a notification will be fired. NOTE: the 427 // notification will fire for each matching event that has already occurred 428 // since tracing was started (including before tracing if the process was 429 // started with tracing turned on). 430 void SetWatchEvent(const std::string& category_name, 431 const std::string& event_name); 432 // Cancel the watch event. If tracing is enabled, this may race with the 433 // watch event notification firing. 434 void CancelWatchEvent(); 435 436 int process_id() const { return process_id_; } 437 438 // Exposed for unittesting: 439 440 void InstallWaitableEventForSamplingTesting(WaitableEvent* waitable_event); 441 442 // Allows deleting our singleton instance. 443 static void DeleteForTesting(); 444 445 // Allow tests to inspect TraceEvents. 446 size_t GetEventsSize() const { return logged_events_->Size(); } 447 const TraceEvent& GetEventAt(size_t index) const { 448 return logged_events_->GetEventAt(index); 449 } 450 451 void SetProcessID(int process_id); 452 453 // Process sort indices, if set, override the order of a process will appear 454 // relative to other processes in the trace viewer. Processes are sorted first 455 // on their sort index, ascending, then by their name, and then tid. 456 void SetProcessSortIndex(int sort_index); 457 458 // Sets the name of the process. 459 void SetProcessName(const std::string& process_name); 460 461 // Processes can have labels in addition to their names. Use labels, for 462 // instance, to list out the web page titles that a process is handling. 463 void UpdateProcessLabel(int label_id, const std::string& current_label); 464 void RemoveProcessLabel(int label_id); 465 466 // Thread sort indices, if set, override the order of a thread will appear 467 // within its process in the trace viewer. Threads are sorted first on their 468 // sort index, ascending, then by their name, and then tid. 469 void SetThreadSortIndex(PlatformThreadId , int sort_index); 470 471 // Allow setting an offset between the current TimeTicks time and the time 472 // that should be reported. 473 void SetTimeOffset(TimeDelta offset); 474 475 size_t GetObserverCountForTest() const; 476 477 private: 478 // This allows constructor and destructor to be private and usable only 479 // by the Singleton class. 480 friend struct DefaultSingletonTraits<TraceLog>; 481 482 // Enable/disable each category group based on the current enable_count_ 483 // and category_filter_. Disable the category group if enabled_count_ is 0, or 484 // if the category group contains a category that matches an included category 485 // pattern, that category group will be enabled. 486 // On Android, ATRACE_ENABLED flag will be applied if atrace is started. 487 void UpdateCategoryGroupEnabledFlags(); 488 void UpdateCategoryGroupEnabledFlag(int category_index); 489 490 static void SetCategoryGroupEnabled(int category_index, bool enabled); 491 static bool IsCategoryGroupEnabled( 492 const unsigned char* category_group_enabled); 493 494 // The pointer returned from GetCategoryGroupEnabledInternal() points to a 495 // value with zero or more of the following bits. Used in this class only. 496 // The TRACE_EVENT macros should only use the value as a bool. 497 enum CategoryGroupEnabledFlags { 498 // Normal enabled flag for category groups enabled with Enable(). 499 CATEGORY_GROUP_ENABLED = 1 << 0, 500 // On Android if ATrace is enabled, all categories will have this bit. 501 // Not used on other platforms. 502 ATRACE_ENABLED = 1 << 1 503 }; 504 505 // Helper class for managing notification_thread_count_ and running 506 // notification callbacks. This is very similar to a reader-writer lock, but 507 // shares the lock with TraceLog and manages the notification flags. 508 class NotificationHelper { 509 public: 510 inline explicit NotificationHelper(TraceLog* trace_log); 511 inline ~NotificationHelper(); 512 513 // Called only while TraceLog::lock_ is held. This ORs the given 514 // notification with any existing notifications. 515 inline void AddNotificationWhileLocked(int notification); 516 517 // Called only while TraceLog::lock_ is NOT held. If there are any pending 518 // notifications from previous calls to AddNotificationWhileLocked, this 519 // will call the NotificationCallback. 520 inline void SendNotificationIfAny(); 521 522 private: 523 TraceLog* trace_log_; 524 NotificationCallback callback_copy_; 525 int notification_; 526 }; 527 528 TraceLog(); 529 ~TraceLog(); 530 const unsigned char* GetCategoryGroupEnabledInternal(const char* name); 531 void AddMetadataEvents(); 532 533 #if defined(OS_ANDROID) 534 void SendToATrace(char phase, 535 const char* category_group, 536 const char* name, 537 unsigned long long id, 538 int num_args, 539 const char** arg_names, 540 const unsigned char* arg_types, 541 const unsigned long long* arg_values, 542 scoped_ptr<ConvertableToTraceFormat> convertable_values[], 543 unsigned char flags); 544 static void ApplyATraceEnabledFlag(unsigned char* category_group_enabled); 545 #endif 546 547 TraceBuffer* GetTraceBuffer(); 548 549 // TODO(nduca): switch to per-thread trace buffers to reduce thread 550 // synchronization. 551 // This lock protects TraceLog member accesses from arbitrary threads. 552 Lock lock_; 553 int enable_count_; 554 int num_traces_recorded_; 555 NotificationCallback notification_callback_; 556 scoped_ptr<TraceBuffer> logged_events_; 557 EventCallback event_callback_; 558 bool dispatching_to_observer_list_; 559 std::vector<EnabledStateObserver*> enabled_state_observer_list_; 560 561 std::string process_name_; 562 base::hash_map<int, std::string> process_labels_; 563 int process_sort_index_; 564 base::hash_map<int, int> thread_sort_indices_; 565 566 base::hash_map<int, std::string> thread_names_; 567 base::hash_map<int, std::stack<TimeTicks> > thread_event_start_times_; 568 base::hash_map<std::string, int> thread_colors_; 569 570 // XORed with TraceID to make it unlikely to collide with other processes. 571 unsigned long long process_id_hash_; 572 573 int process_id_; 574 575 TimeDelta time_offset_; 576 577 // Allow tests to wake up when certain events occur. 578 const unsigned char* watch_category_; 579 std::string watch_event_name_; 580 581 Options trace_options_; 582 583 // Sampling thread handles. 584 scoped_ptr<TraceSamplingThread> sampling_thread_; 585 PlatformThreadHandle sampling_thread_handle_; 586 587 CategoryFilter category_filter_; 588 589 DISALLOW_COPY_AND_ASSIGN(TraceLog); 590 }; 591 592 } // namespace debug 593 } // namespace base 594 595 #endif // BASE_DEBUG_TRACE_EVENT_IMPL_H_ 596