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
42template <typename Type>
43struct DefaultSingletonTraits;
44
45namespace base {
46
47class WaitableEvent;
48
49namespace debug {
50
51// For any argument of type TRACE_VALUE_TYPE_CONVERTABLE the provided
52// class must implement this interface.
53class 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
64const 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.
70class 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.
142class 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.
158class 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
199class 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
268class TraceSamplingThread;
269
270class 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