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