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