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