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