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 #ifndef BASE_TRACE_EVENT_TRACE_LOG_H_ 6 #define BASE_TRACE_EVENT_TRACE_LOG_H_ 7 8 #include <stddef.h> 9 #include <stdint.h> 10 11 #include <memory> 12 #include <string> 13 #include <unordered_map> 14 #include <vector> 15 16 #include "base/atomicops.h" 17 #include "base/containers/stack.h" 18 #include "base/gtest_prod_util.h" 19 #include "base/macros.h" 20 #include "base/time/time_override.h" 21 #include "base/trace_event/memory_dump_provider.h" 22 #include "base/trace_event/trace_config.h" 23 #include "base/trace_event/trace_event_impl.h" 24 #include "build/build_config.h" 25 26 namespace base { 27 28 class MessageLoop; 29 class RefCountedString; 30 31 template <typename T> 32 class NoDestructor; 33 34 namespace trace_event { 35 36 struct TraceCategory; 37 class TraceBuffer; 38 class TraceBufferChunk; 39 class TraceEvent; 40 class TraceEventFilter; 41 class TraceEventMemoryOverhead; 42 43 struct BASE_EXPORT TraceLogStatus { 44 TraceLogStatus(); 45 ~TraceLogStatus(); 46 uint32_t event_capacity; 47 uint32_t event_count; 48 }; 49 50 class BASE_EXPORT TraceLog : public MemoryDumpProvider { 51 public: 52 // Argument passed to TraceLog::SetEnabled. 53 enum Mode : uint8_t { 54 // Enables normal tracing (recording trace events in the trace buffer). 55 RECORDING_MODE = 1 << 0, 56 57 // Trace events are enabled just for filtering but not for recording. Only 58 // event filters config of |trace_config| argument is used. 59 FILTERING_MODE = 1 << 1 60 }; 61 62 static TraceLog* GetInstance(); 63 64 // Get set of known category groups. This can change as new code paths are 65 // reached. The known category groups are inserted into |category_groups|. 66 void GetKnownCategoryGroups(std::vector<std::string>* category_groups); 67 68 // Retrieves a copy (for thread-safety) of the current TraceConfig. 69 TraceConfig GetCurrentTraceConfig() const; 70 71 // Initializes the thread-local event buffer, if not already initialized and 72 // if the current thread supports that (has a message loop). 73 void InitializeThreadLocalEventBufferIfSupported(); 74 75 // See TraceConfig comments for details on how to control which categories 76 // will be traced. SetDisabled must be called distinctly for each mode that is 77 // enabled. If tracing has already been enabled for recording, category filter 78 // (enabled and disabled categories) will be merged into the current category 79 // filter. Enabling RECORDING_MODE does not enable filters. Trace event 80 // filters will be used only if FILTERING_MODE is set on |modes_to_enable|. 81 // Conversely to RECORDING_MODE, FILTERING_MODE doesn't support upgrading, 82 // i.e. filters can only be enabled if not previously enabled. 83 void SetEnabled(const TraceConfig& trace_config, uint8_t modes_to_enable); 84 85 // TODO(ssid): Remove the default SetEnabled and IsEnabled. They should take 86 // Mode as argument. 87 88 // Disables tracing for all categories for the specified |modes_to_disable| 89 // only. Only RECORDING_MODE is taken as default |modes_to_disable|. 90 void SetDisabled(); 91 void SetDisabled(uint8_t modes_to_disable); 92 93 // Returns true if TraceLog is enabled on recording mode. 94 // Note: Returns false even if FILTERING_MODE is enabled. IsEnabled()95 bool IsEnabled() { return enabled_modes_ & RECORDING_MODE; } 96 97 // Returns a bitmap of enabled modes from TraceLog::Mode. enabled_modes()98 uint8_t enabled_modes() { return enabled_modes_; } 99 100 // The number of times we have begun recording traces. If tracing is off, 101 // returns -1. If tracing is on, then it returns the number of times we have 102 // recorded a trace. By watching for this number to increment, you can 103 // passively discover when a new trace has begun. This is then used to 104 // implement the TRACE_EVENT_IS_NEW_TRACE() primitive. 105 int GetNumTracesRecorded(); 106 107 #if defined(OS_ANDROID) 108 void StartATrace(); 109 void StopATrace(); 110 void AddClockSyncMetadataEvent(); 111 #endif 112 113 // Enabled state listeners give a callback when tracing is enabled or 114 // disabled. This can be used to tie into other library's tracing systems 115 // on-demand. 116 class BASE_EXPORT EnabledStateObserver { 117 public: 118 virtual ~EnabledStateObserver() = default; 119 120 // Called just after the tracing system becomes enabled, outside of the 121 // |lock_|. TraceLog::IsEnabled() is true at this point. 122 virtual void OnTraceLogEnabled() = 0; 123 124 // Called just after the tracing system disables, outside of the |lock_|. 125 // TraceLog::IsEnabled() is false at this point. 126 virtual void OnTraceLogDisabled() = 0; 127 }; 128 void AddEnabledStateObserver(EnabledStateObserver* listener); 129 void RemoveEnabledStateObserver(EnabledStateObserver* listener); 130 bool HasEnabledStateObserver(EnabledStateObserver* listener) const; 131 132 // Asynchronous enabled state listeners. When tracing is enabled or disabled, 133 // for each observer, a task for invoking its appropriate callback is posted 134 // to the thread from which AddAsyncEnabledStateObserver() was called. This 135 // allows the observer to be safely destroyed, provided that it happens on the 136 // same thread that invoked AddAsyncEnabledStateObserver(). 137 class BASE_EXPORT AsyncEnabledStateObserver { 138 public: 139 virtual ~AsyncEnabledStateObserver() = default; 140 141 // Posted just after the tracing system becomes enabled, outside |lock_|. 142 // TraceLog::IsEnabled() is true at this point. 143 virtual void OnTraceLogEnabled() = 0; 144 145 // Posted just after the tracing system becomes disabled, outside |lock_|. 146 // TraceLog::IsEnabled() is false at this point. 147 virtual void OnTraceLogDisabled() = 0; 148 }; 149 void AddAsyncEnabledStateObserver( 150 WeakPtr<AsyncEnabledStateObserver> listener); 151 void RemoveAsyncEnabledStateObserver(AsyncEnabledStateObserver* listener); 152 bool HasAsyncEnabledStateObserver(AsyncEnabledStateObserver* listener) const; 153 154 TraceLogStatus GetStatus() const; 155 bool BufferIsFull() const; 156 157 // Computes an estimate of the size of the TraceLog including all the retained 158 // objects. 159 void EstimateTraceMemoryOverhead(TraceEventMemoryOverhead* overhead); 160 161 void SetArgumentFilterPredicate( 162 const ArgumentFilterPredicate& argument_filter_predicate); 163 164 // Flush all collected events to the given output callback. The callback will 165 // be called one or more times either synchronously or asynchronously from 166 // the current thread with IPC-bite-size chunks. The string format is 167 // undefined. Use TraceResultBuffer to convert one or more trace strings to 168 // JSON. The callback can be null if the caller doesn't want any data. 169 // Due to the implementation of thread-local buffers, flush can't be 170 // done when tracing is enabled. If called when tracing is enabled, the 171 // callback will be called directly with (empty_string, false) to indicate 172 // the end of this unsuccessful flush. Flush does the serialization 173 // on the same thread if the caller doesn't set use_worker_thread explicitly. 174 typedef base::Callback<void(const scoped_refptr<base::RefCountedString>&, 175 bool has_more_events)> OutputCallback; 176 void Flush(const OutputCallback& cb, bool use_worker_thread = false); 177 178 // Cancels tracing and discards collected data. 179 void CancelTracing(const OutputCallback& cb); 180 181 typedef void (*AddTraceEventOverrideCallback)(const TraceEvent&); 182 // The callback will be called up until the point where the flush is 183 // finished, i.e. must be callable until OutputCallback is called with 184 // has_more_events==false. 185 void SetAddTraceEventOverride(const AddTraceEventOverrideCallback& override); 186 187 // Called by TRACE_EVENT* macros, don't call this directly. 188 // The name parameter is a category group for example: 189 // TRACE_EVENT0("renderer,webkit", "WebViewImpl::HandleInputEvent") 190 static const unsigned char* GetCategoryGroupEnabled(const char* name); 191 static const char* GetCategoryGroupName( 192 const unsigned char* category_group_enabled); 193 194 // Called by TRACE_EVENT* macros, don't call this directly. 195 // If |copy| is set, |name|, |arg_name1| and |arg_name2| will be deep copied 196 // into the event; see "Memory scoping note" and TRACE_EVENT_COPY_XXX above. 197 TraceEventHandle AddTraceEvent( 198 char phase, 199 const unsigned char* category_group_enabled, 200 const char* name, 201 const char* scope, 202 unsigned long long id, 203 int num_args, 204 const char* const* arg_names, 205 const unsigned char* arg_types, 206 const unsigned long long* arg_values, 207 std::unique_ptr<ConvertableToTraceFormat>* convertable_values, 208 unsigned int flags); 209 TraceEventHandle AddTraceEventWithBindId( 210 char phase, 211 const unsigned char* category_group_enabled, 212 const char* name, 213 const char* scope, 214 unsigned long long id, 215 unsigned long long bind_id, 216 int num_args, 217 const char* const* arg_names, 218 const unsigned char* arg_types, 219 const unsigned long long* arg_values, 220 std::unique_ptr<ConvertableToTraceFormat>* convertable_values, 221 unsigned int flags); 222 TraceEventHandle AddTraceEventWithProcessId( 223 char phase, 224 const unsigned char* category_group_enabled, 225 const char* name, 226 const char* scope, 227 unsigned long long id, 228 int process_id, 229 int num_args, 230 const char* const* arg_names, 231 const unsigned char* arg_types, 232 const unsigned long long* arg_values, 233 std::unique_ptr<ConvertableToTraceFormat>* convertable_values, 234 unsigned int flags); 235 TraceEventHandle AddTraceEventWithThreadIdAndTimestamp( 236 char phase, 237 const unsigned char* category_group_enabled, 238 const char* name, 239 const char* scope, 240 unsigned long long id, 241 int thread_id, 242 const TimeTicks& timestamp, 243 int num_args, 244 const char* const* arg_names, 245 const unsigned char* arg_types, 246 const unsigned long long* arg_values, 247 std::unique_ptr<ConvertableToTraceFormat>* convertable_values, 248 unsigned int flags); 249 TraceEventHandle AddTraceEventWithThreadIdAndTimestamp( 250 char phase, 251 const unsigned char* category_group_enabled, 252 const char* name, 253 const char* scope, 254 unsigned long long id, 255 unsigned long long bind_id, 256 int thread_id, 257 const TimeTicks& timestamp, 258 int num_args, 259 const char* const* arg_names, 260 const unsigned char* arg_types, 261 const unsigned long long* arg_values, 262 std::unique_ptr<ConvertableToTraceFormat>* convertable_values, 263 unsigned int flags); 264 265 // Adds a metadata event that will be written when the trace log is flushed. 266 void AddMetadataEvent( 267 const unsigned char* category_group_enabled, 268 const char* name, 269 int num_args, 270 const char* const* arg_names, 271 const unsigned char* arg_types, 272 const unsigned long long* arg_values, 273 std::unique_ptr<ConvertableToTraceFormat>* convertable_values, 274 unsigned int flags); 275 276 void UpdateTraceEventDuration(const unsigned char* category_group_enabled, 277 const char* name, 278 TraceEventHandle handle); 279 280 void UpdateTraceEventDurationExplicit( 281 const unsigned char* category_group_enabled, 282 const char* name, 283 TraceEventHandle handle, 284 const TimeTicks& now, 285 const ThreadTicks& thread_now); 286 287 void EndFilteredEvent(const unsigned char* category_group_enabled, 288 const char* name, 289 TraceEventHandle handle); 290 process_id()291 int process_id() const { return process_id_; } 292 293 uint64_t MangleEventId(uint64_t id); 294 295 // Exposed for unittesting: 296 297 // Testing factory for TraceEventFilter. 298 typedef std::unique_ptr<TraceEventFilter> (*FilterFactoryForTesting)( 299 const std::string& /* predicate_name */); SetFilterFactoryForTesting(FilterFactoryForTesting factory)300 void SetFilterFactoryForTesting(FilterFactoryForTesting factory) { 301 filter_factory_for_testing_ = factory; 302 } 303 304 // Allows clearing up our singleton instance. 305 static void ResetForTesting(); 306 307 // Allow tests to inspect TraceEvents. 308 TraceEvent* GetEventByHandle(TraceEventHandle handle); 309 310 void SetProcessID(int process_id); 311 312 // Process sort indices, if set, override the order of a process will appear 313 // relative to other processes in the trace viewer. Processes are sorted first 314 // on their sort index, ascending, then by their name, and then tid. 315 void SetProcessSortIndex(int sort_index); 316 317 // Sets the name of the process. set_process_name(const std::string & process_name)318 void set_process_name(const std::string& process_name) { 319 AutoLock lock(lock_); 320 process_name_ = process_name; 321 } 322 IsProcessNameEmpty()323 bool IsProcessNameEmpty() const { return process_name_.empty(); } 324 325 // Processes can have labels in addition to their names. Use labels, for 326 // instance, to list out the web page titles that a process is handling. 327 void UpdateProcessLabel(int label_id, const std::string& current_label); 328 void RemoveProcessLabel(int label_id); 329 330 // Thread sort indices, if set, override the order of a thread will appear 331 // within its process in the trace viewer. Threads are sorted first on their 332 // sort index, ascending, then by their name, and then tid. 333 void SetThreadSortIndex(PlatformThreadId thread_id, int sort_index); 334 335 // Allow setting an offset between the current TimeTicks time and the time 336 // that should be reported. 337 void SetTimeOffset(TimeDelta offset); 338 339 size_t GetObserverCountForTest() const; 340 341 // Call this method if the current thread may block the message loop to 342 // prevent the thread from using the thread-local buffer because the thread 343 // may not handle the flush request in time causing lost of unflushed events. 344 void SetCurrentThreadBlocksMessageLoop(); 345 346 #if defined(OS_WIN) 347 // This function is called by the ETW exporting module whenever the ETW 348 // keyword (flags) changes. This keyword indicates which categories should be 349 // exported, so whenever it changes, we adjust accordingly. 350 void UpdateETWCategoryGroupEnabledFlags(); 351 #endif 352 353 // Replaces |logged_events_| with a new TraceBuffer for testing. 354 void SetTraceBufferForTesting(std::unique_ptr<TraceBuffer> trace_buffer); 355 356 private: 357 typedef unsigned int InternalTraceOptions; 358 359 FRIEND_TEST_ALL_PREFIXES(TraceEventTestFixture, 360 TraceBufferRingBufferGetReturnChunk); 361 FRIEND_TEST_ALL_PREFIXES(TraceEventTestFixture, 362 TraceBufferRingBufferHalfIteration); 363 FRIEND_TEST_ALL_PREFIXES(TraceEventTestFixture, 364 TraceBufferRingBufferFullIteration); 365 FRIEND_TEST_ALL_PREFIXES(TraceEventTestFixture, TraceBufferVectorReportFull); 366 FRIEND_TEST_ALL_PREFIXES(TraceEventTestFixture, 367 ConvertTraceConfigToInternalOptions); 368 FRIEND_TEST_ALL_PREFIXES(TraceEventTestFixture, 369 TraceRecordAsMuchAsPossibleMode); 370 371 friend class base::NoDestructor<TraceLog>; 372 373 // MemoryDumpProvider implementation. 374 bool OnMemoryDump(const MemoryDumpArgs& args, 375 ProcessMemoryDump* pmd) override; 376 377 // Enable/disable each category group based on the current mode_, 378 // category_filter_ and event_filters_enabled_. 379 // Enable the category group in the recording mode if category_filter_ matches 380 // the category group, is not null. Enable category for filtering if any 381 // filter in event_filters_enabled_ enables it. 382 void UpdateCategoryRegistry(); 383 void UpdateCategoryState(TraceCategory* category); 384 385 void CreateFiltersForTraceConfig(); 386 387 InternalTraceOptions GetInternalOptionsFromTraceConfig( 388 const TraceConfig& config); 389 390 class ThreadLocalEventBuffer; 391 class OptionalAutoLock; 392 struct RegisteredAsyncObserver; 393 394 TraceLog(); 395 ~TraceLog() override; 396 void AddMetadataEventsWhileLocked(); 397 trace_options()398 InternalTraceOptions trace_options() const { 399 return static_cast<InternalTraceOptions>( 400 subtle::NoBarrier_Load(&trace_options_)); 401 } 402 trace_buffer()403 TraceBuffer* trace_buffer() const { return logged_events_.get(); } 404 TraceBuffer* CreateTraceBuffer(); 405 406 std::string EventToConsoleMessage(unsigned char phase, 407 const TimeTicks& timestamp, 408 TraceEvent* trace_event); 409 410 TraceEvent* AddEventToThreadSharedChunkWhileLocked(TraceEventHandle* handle, 411 bool check_buffer_is_full); 412 void CheckIfBufferIsFullWhileLocked(); 413 void SetDisabledWhileLocked(uint8_t modes); 414 415 TraceEvent* GetEventByHandleInternal(TraceEventHandle handle, 416 OptionalAutoLock* lock); 417 418 void FlushInternal(const OutputCallback& cb, 419 bool use_worker_thread, 420 bool discard_events); 421 422 // |generation| is used in the following callbacks to check if the callback 423 // is called for the flush of the current |logged_events_|. 424 void FlushCurrentThread(int generation, bool discard_events); 425 // Usually it runs on a different thread. 426 static void ConvertTraceEventsToTraceFormat( 427 std::unique_ptr<TraceBuffer> logged_events, 428 const TraceLog::OutputCallback& flush_output_callback, 429 const ArgumentFilterPredicate& argument_filter_predicate); 430 void FinishFlush(int generation, bool discard_events); 431 void OnFlushTimeout(int generation, bool discard_events); 432 generation()433 int generation() const { 434 return static_cast<int>(subtle::NoBarrier_Load(&generation_)); 435 } CheckGeneration(int generation)436 bool CheckGeneration(int generation) const { 437 return generation == this->generation(); 438 } 439 void UseNextTraceBuffer(); 440 OffsetNow()441 TimeTicks OffsetNow() const { 442 // This should be TRACE_TIME_TICKS_NOW but include order makes that hard. 443 return OffsetTimestamp(base::subtle::TimeTicksNowIgnoringOverride()); 444 } OffsetTimestamp(const TimeTicks & timestamp)445 TimeTicks OffsetTimestamp(const TimeTicks& timestamp) const { 446 return timestamp - time_offset_; 447 } 448 449 // Internal representation of trace options since we store the currently used 450 // trace option as an AtomicWord. 451 static const InternalTraceOptions kInternalNone; 452 static const InternalTraceOptions kInternalRecordUntilFull; 453 static const InternalTraceOptions kInternalRecordContinuously; 454 static const InternalTraceOptions kInternalEchoToConsole; 455 static const InternalTraceOptions kInternalRecordAsMuchAsPossible; 456 static const InternalTraceOptions kInternalEnableArgumentFilter; 457 458 // This lock protects TraceLog member accesses (except for members protected 459 // by thread_info_lock_) from arbitrary threads. 460 mutable Lock lock_; 461 // This lock protects accesses to thread_names_, thread_event_start_times_ 462 // and thread_colors_. 463 Lock thread_info_lock_; 464 uint8_t enabled_modes_; // See TraceLog::Mode. 465 int num_traces_recorded_; 466 std::unique_ptr<TraceBuffer> logged_events_; 467 std::vector<std::unique_ptr<TraceEvent>> metadata_events_; 468 bool dispatching_to_observer_list_; 469 std::vector<EnabledStateObserver*> enabled_state_observer_list_; 470 std::map<AsyncEnabledStateObserver*, RegisteredAsyncObserver> 471 async_observers_; 472 473 std::string process_name_; 474 std::unordered_map<int, std::string> process_labels_; 475 int process_sort_index_; 476 std::unordered_map<int, int> thread_sort_indices_; 477 std::unordered_map<int, std::string> thread_names_; 478 base::Time process_creation_time_; 479 480 // The following two maps are used only when ECHO_TO_CONSOLE. 481 std::unordered_map<int, base::stack<TimeTicks>> thread_event_start_times_; 482 std::unordered_map<std::string, int> thread_colors_; 483 484 TimeTicks buffer_limit_reached_timestamp_; 485 486 // XORed with TraceID to make it unlikely to collide with other processes. 487 unsigned long long process_id_hash_; 488 489 int process_id_; 490 491 TimeDelta time_offset_; 492 493 subtle::AtomicWord /* Options */ trace_options_; 494 495 TraceConfig trace_config_; 496 TraceConfig::EventFilters enabled_event_filters_; 497 498 ThreadLocalPointer<ThreadLocalEventBuffer> thread_local_event_buffer_; 499 ThreadLocalBoolean thread_blocks_message_loop_; 500 ThreadLocalBoolean thread_is_in_trace_event_; 501 502 // Contains the message loops of threads that have had at least one event 503 // added into the local event buffer. Not using SingleThreadTaskRunner 504 // because we need to know the life time of the message loops. 505 hash_set<MessageLoop*> thread_message_loops_; 506 507 // For events which can't be added into the thread local buffer, e.g. events 508 // from threads without a message loop. 509 std::unique_ptr<TraceBufferChunk> thread_shared_chunk_; 510 size_t thread_shared_chunk_index_; 511 512 // Set when asynchronous Flush is in progress. 513 OutputCallback flush_output_callback_; 514 scoped_refptr<SequencedTaskRunner> flush_task_runner_; 515 ArgumentFilterPredicate argument_filter_predicate_; 516 subtle::AtomicWord generation_; 517 bool use_worker_thread_; 518 subtle::AtomicWord trace_event_override_; 519 520 FilterFactoryForTesting filter_factory_for_testing_; 521 522 DISALLOW_COPY_AND_ASSIGN(TraceLog); 523 }; 524 525 } // namespace trace_event 526 } // namespace base 527 528 #endif // BASE_TRACE_EVENT_TRACE_LOG_H_ 529