implement SetWatchEvent and WaitForEvent for trace-based-tests

base/debug/trace_event_impl.h

 // Copyright (c) 2012 The Chromium Authors. All rights reserved.
 // Use of this source code is governed by a BSD-style license that can be
 // found in the LICENSE file.
 
 
 #ifndef BASE_DEBUG_TRACE_EVENT_IMPL_H_
 #define BASE_DEBUG_TRACE_EVENT_IMPL_H_
 
 #include "build/build_config.h"
 
 #include <string>
 #include <vector>
 
 #include "base/callback.h"
 #include "base/hash_tables.h"
 #include "base/memory/ref_counted_memory.h"
 #include "base/observer_list.h"
 #include "base/string_util.h"
+#include "base/synchronization/condition_variable.h"
 #include "base/synchronization/lock.h"
 #include "base/timer.h"
 
 // Older style trace macros with explicit id and extra data
 // Only these macros result in publishing data to ETW as currently implemented.
 #define TRACE_EVENT_BEGIN_ETW(name, id, extra) \
     base::debug::TraceLog::AddTraceEventEtw( \
         TRACE_EVENT_PHASE_BEGIN, \
         name, reinterpret_cast<const void*>(id), extra)
 
@@ skipping 53 matching lines @@
   void AppendAsJSON(std::string* out) const;
 
   TimeTicks timestamp() const { return timestamp_; }
 
   // Exposed for unittesting:
 
   const base::RefCountedString* parameter_copy_storage() const {
     return parameter_copy_storage_.get();
   }
 
+  const unsigned char* category_enabled() const { return category_enabled_; }
   const char* name() const { return name_; }
 
  private:
   // Note: these are ordered by size (largest first) for optimal packing.
   TimeTicks timestamp_;
   // id_ can be used to store phase-specific data.
   unsigned long long id_;
   TraceValue arg_values_[kTraceMaxNumArgs];
   const char* arg_names_[kTraceMaxNumArgs];
   const unsigned char* category_enabled_;
@@ skipping 45 matching lines @@
   void Finish();
 
  private:
   OutputCallback output_callback_;
   bool append_comma_;
 };
 
 
 class BASE_EXPORT TraceLog {
  public:
+  // Notification is a mask of one or more of the following events.
+  enum Notification {

[ccameron, 2012/08/21 01:06:34]

This isn't treated as a bit mask (but rather as a standard enum) in
TraceControllerImpl::OnTraceNotification.  Probably easier to not use as a mask
with multiple events.

[jbates, 2012/08/23 22:45:28]

Good catch, TraceControllerImpl::OnTraceNotification was wrong -- I updated it
to check for both flags because it's possible for them both to happen in one
notification.

+    // The trace buffer does not flush dynamically, so when it fills up,
+    // subsequent trace events will be dropped. This callback is generated when
+    // the trace buffer is full. The callback must be thread safe.
+    TRACE_BUFFER_FULL = 1 << 0,
+    // A subscribed trace-event occurred.
+    EVENT_WATCH_NOTIFICATION = 1 << 1
+  };
+
   static TraceLog* GetInstance();
 
   // Get set of known categories. This can change as new code paths are reached.
   // The known categories are inserted into |categories|.
   void GetKnownCategories(std::vector<std::string>* categories);
 
   // Enable tracing for provided list of categories. If tracing is already
   // enabled, this method does nothing -- changing categories during trace is
   // not supported.
   // If both included_categories and excluded_categories are empty,
@@ skipping 39 matching lines @@
     // still false at this point TRACE macros will still be capturing
     // data. However, trace macros and methods called within the observer will
     // deadlock.
     virtual void OnTraceLogWillDisable() { }
   };
   void AddEnabledStateObserver(EnabledStateChangedObserver* listener);
   void RemoveEnabledStateObserver(EnabledStateChangedObserver* listener);
 
   float GetBufferPercentFull() const;
 
-  // When enough events are collected, they are handed (in bulk) to
-  // the output callback. If no callback is set, the output will be
-  // silently dropped. The callback must be thread safe. The string format is
+  // Set the thread-safe notification callback. The callback can occur at any
+  // time. After calling SetNotificationCallback(NotificationCallback()) to
+  // clear the callback, it is guaranteed that the old callback will no longer
+  // be called. Warning: it is possible for the old callback to be called during
+  // a call to SetNotificationCallback.
+  typedef base::Callback<void(int)> NotificationCallback;
+  void SetNotificationCallback(const NotificationCallback& cb);
+
+  // Flush all collected events to the given output callback. The callback will
+  // be called one or more times with IPC-bite-size chunks. The string format is
   // undefined. Use TraceResultBuffer to convert one or more trace strings to
   // JSON.
   typedef base::Callback<void(const scoped_refptr<base::RefCountedString>&)>
       OutputCallback;
-  void SetOutputCallback(const OutputCallback& cb);
-
-  // The trace buffer does not flush dynamically, so when it fills up,
-  // subsequent trace events will be dropped. This callback is generated when
-  // the trace buffer is full. The callback must be thread safe.
-  typedef base::Callback<void(void)> BufferFullCallback;
-  void SetBufferFullCallback(const BufferFullCallback& cb);
-
-  // Flushes all logged data to the callback.
-  void Flush();
+  void Flush(const OutputCallback& cb);
 
   // Called by TRACE_EVENT* macros, don't call this directly.
   static const unsigned char* GetCategoryEnabled(const char* name);
   static const char* GetCategoryName(const unsigned char* category_enabled);
 
   // Called by TRACE_EVENT* macros, don't call this directly.
   // Returns the index in the internal vector of the event if it was added, or
   //         -1 if the event was not added.
   // On end events, the return value of the begin event can be specified along
   // with a threshold in microseconds. If the elapsed time between begin and end
@@ skipping 13 matching lines @@
                     unsigned char flags);
   static void AddTraceEventEtw(char phase,
                                const char* name,
                                const void* id,
                                const char* extra);
   static void AddTraceEventEtw(char phase,
                                const char* name,
                                const void* id,
                                const std::string& extra);
 
+  // After |num_occurrences| of given event have been seen on a particular
+  // process since tracing was enabled, a notification will be fired. The event
+  // count is not distributed across processes, so |num_occurrences| must occur
+  // on one process. The watch event is automatically cleared after the
+  // notification. |num_occurrences| must be greater than 0.
+  // NOTE: If |num_occurrences| events have already occurred, the notification

[ccameron, 2012/08/21 01:06:34]

I have a preference for not supporting this semantic (fire if these events
happened in the past), but it's mostly gut-based.  We should discuss how this
impacts use-cases offline.

[jbates, 2012/08/23 22:45:28]

This is important to catch the events that occur at process start before the
process hooks up to IPC and is told to start tracing (such as GPU process start
during the trace). It could be a bool option here, but with the current
requirement that there is one watch per Begin/End tracing, it seems good to keep
it simple until we have a feature request for more advanced use cases.

+  // will fire during the call to SetWatchEvent.
+  void SetWatchEvent(const char* category_name,
+                     const char* event_name,
+                     int num_occurrences);
+  // Cancel the watch event. If tracing is enabled, this may race with the
+  // watch event notification firing.
+  void CancelWatchEvent();
+
   int process_id() const { return process_id_; }
 
   // Exposed for unittesting:
 
   // Allows deleting our singleton instance.
   static void DeleteForTesting();
 
   // Allows resurrecting our singleton instance post-AtExit processing.
   static void Resurrect();
 
   // Allow tests to inspect TraceEvents.
   size_t GetEventsSize() const { return logged_events_.size(); }
   const TraceEvent& GetEventAt(size_t index) const {
     DCHECK(index < logged_events_.size());
     return logged_events_[index];
   }
 
   void SetProcessID(int process_id);
 
  private:
   // This allows constructor and destructor to be private and usable only
   // by the Singleton class.
   friend struct StaticMemorySingletonTraits<TraceLog>;
 
+  // Helper class for managing notification_thread_count_ and running
+  // notification callbacks.
+  class NotificationHelper {
+   public:
+    inline NotificationHelper(TraceLog* trace_log);
+    inline ~NotificationHelper();
+
+    // Called only while TraceLog::lock_ is held.
+    inline void AddNotificationWhileLocked(int notification);
+
+    // Called only while TraceLog::lock_ is NOT held.
+    inline void SendNotificationIfAny();
+
+   private:
+    TraceLog* trace_log_;
+    NotificationCallback callback_copy_;
+    int notification_;
+  };
+
   TraceLog();
   ~TraceLog();
   const unsigned char* GetCategoryEnabledInternal(const char* name);
   void AddThreadNameMetadataEvents();
   void AddClockSyncMetadataEvents();
 
   // TODO(nduca): switch to per-thread trace buffers to reduce thread
   // synchronization.
   Lock lock_;
   bool enabled_;
-  OutputCallback output_callback_;
-  BufferFullCallback buffer_full_callback_;
+  base::ConditionVariable notification_condition_;
+  NotificationCallback notification_callback_;

[ccameron, 2012/08/21 01:06:34]

I see no concurrency issues with this implementation.

That said, this seems to be a hand-rolled read-writer lock.  Perhaps we should
add that sort of structure to base (with LockForRead in SendNotificationIfAny,
and LockForWrite in SetNotificationCallback)?

That way, maintainers will be less likely to break this -- the mental load over
verifying there were no issues was high, and my certainty-of-correctness has a
half-life of ~2 minutes.  In fact, it may be worth considering just creating a
separate ordinary lock (and not exposing concurrent callbacks from multiple
threads) just to simplify the code.

[jbates, 2012/08/23 22:45:28]

As discussed, added comments around the NotificationHelper to explain that it's
like a reader-writer lock.

+  // Number of threads that are have a copy of the notification callback.
+  int notification_thread_count_;
   std::vector<TraceEvent> logged_events_;
   std::vector<std::string> included_categories_;
   std::vector<std::string> excluded_categories_;
   bool dispatching_to_observer_list_;
   ObserverList<EnabledStateChangedObserver> enabled_state_observer_list_;
 
   base::hash_map<int, std::string> thread_names_;
 
   // XORed with TraceID to make it unlikely to collide with other processes.
   unsigned long long process_id_hash_;
 
   int process_id_;
 
+  // Allow tests to wake up when certain events occur.
+  const unsigned char* watch_category_;
+  std::string watch_event_name_;
+  int watch_count_;
+
   DISALLOW_COPY_AND_ASSIGN(TraceLog);
 };
 
 }  // namespace debug
 }  // namespace base
 
 #endif  // BASE_DEBUG_TRACE_EVENT_IMPL_H_