implement SetWatchEvent and WaitForEvent for trace-based-tests.

Up until now, tracing-based tests have been required to either run a trace for some amount of time or use existing notification mechanisms to return control to the test.

This change adds a 'watch event' feature to trace_event_impl which can be used by tests to wait for an event to occur. This mechanism could replace the use of test-only notifications which is frowned upon as well as mock classes for catching events. Trace events also have the huge advantage of working on all chrome processes as opposed to the browser-only notification service.

BUG=139939

Review URL: https://chromiumcodereview.appspot.com/10837082

git-svn-id: svn://svn.chromium.org/chrome/trunk/src@154552 0039d316-1c4b-4281-b951-d872f2087c98

4 files changed, 285 insertions, 108 deletions

diff --git a/base/debug/trace_event_impl.cc b/base/debug/trace_event_impl.cc
index 9cf3341..13b6a97 100644
--- a/base/debug/trace_event_impl.cc
+++ b/base/debug/trace_event_impl.cc
@@ -7,21 +7,23 @@
 #include <algorithm>
 
 #include "base/bind.h"
+#include "base/debug/leak_annotations.h"
 #include "base/debug/trace_event.h"
 #include "base/file_util.h"
 #include "base/format_macros.h"
 #include "base/lazy_instance.h"
 #include "base/memory/singleton.h"
 #include "base/process_util.h"
+#include "base/stl_util.h"
 #include "base/stringprintf.h"
 #include "base/string_tokenizer.h"
-#include "base/threading/platform_thread.h"
-#include "base/threading/thread_local.h"
-#include "base/utf_string_conversions.h"
-#include "base/stl_util.h"
+#include "base/string_util.h"
 #include "base/sys_info.h"
 #include "base/third_party/dynamic_annotations/dynamic_annotations.h"
+#include "base/threading/platform_thread.h"
+#include "base/threading/thread_local.h"
 #include "base/time.h"
+#include "base/utf_string_conversions.h"
 
 #if defined(OS_WIN)
 #include "base/debug/trace_event_win.h"
@@ -316,14 +318,37 @@ void TraceResultBuffer::Finish() {
 //
 ////////////////////////////////////////////////////////////////////////////////
 
+TraceLog::NotificationHelper::NotificationHelper(TraceLog* trace_log)
+    : trace_log_(trace_log),
+      notification_(0) {
+}
+
+TraceLog::NotificationHelper::~NotificationHelper() {
+}
+
+void TraceLog::NotificationHelper::AddNotificationWhileLocked(
+    int notification) {
+  if (trace_log_->notification_callback_.is_null())
+    return;
+  if (notification_ == 0)
+    callback_copy_ = trace_log_->notification_callback_;
+  notification_ |= notification;
+}
+
+void TraceLog::NotificationHelper::SendNotificationIfAny() {
+  if (notification_)
+    callback_copy_.Run(notification_);
+}
+
 // static
 TraceLog* TraceLog::GetInstance() {
   return Singleton<TraceLog, StaticMemorySingletonTraits<TraceLog> >::get();
 }
 
 TraceLog::TraceLog()
-    : enabled_(false)
-    , dispatching_to_observer_list_(false) {
+    : enabled_(false),
+      dispatching_to_observer_list_(false),
+      watch_category_(NULL) {
   // Trace is enabled or disabled on one thread while other threads are
   // accessing the enabled flag. We don't care whether edge-case events are
   // traced or not, so we allow races on the enabled flag to keep the trace
@@ -406,7 +431,11 @@ const unsigned char* TraceLog::GetCategoryEnabledInternal(const char* name) {
       "must increase TRACE_EVENT_MAX_CATEGORIES";
   if (g_category_index < TRACE_EVENT_MAX_CATEGORIES) {
     int new_index = g_category_index++;
-    g_categories[new_index] = name;
+    // Don't hold on to the name pointer, so that we can create categories with
+    // strings not known at compile time (this is required by SetWatchEvent).
+    const char* new_name = base::strdup(name);
+    ANNOTATE_LEAKING_OBJECT_PTR(new_name);
+    g_categories[new_index] = new_name;
     DCHECK(!g_category_enabled[new_index]);
     if (enabled_) {
       // Note that if both included and excluded_categories are empty, the else
@@ -491,31 +520,30 @@ void TraceLog::GetEnabledTraceCategories(
 }
 
 void TraceLog::SetDisabled() {
-  {
-    AutoLock lock(lock_);
-    if (!enabled_)
-      return;
+  AutoLock lock(lock_);
+  if (!enabled_)
+    return;
 
-    if (dispatching_to_observer_list_) {
-      DLOG(ERROR)
-          << "Cannot manipulate TraceLog::Enabled state from an observer.";
-      return;
-    }
+  if (dispatching_to_observer_list_) {
+    DLOG(ERROR)
+        << "Cannot manipulate TraceLog::Enabled state from an observer.";
+    return;
+  }
 
-    dispatching_to_observer_list_ = true;
-    FOR_EACH_OBSERVER(EnabledStateChangedObserver, enabled_state_observer_list_,
-                      OnTraceLogWillDisable());
-    dispatching_to_observer_list_ = false;
-
-    enabled_ = false;
-    included_categories_.clear();
-    excluded_categories_.clear();
-    for (int i = 0; i < g_category_index; i++)
-      g_category_enabled[i] = 0;
-    AddThreadNameMetadataEvents();
-    AddClockSyncMetadataEvents();
-  }  // release lock
-  Flush();
+  dispatching_to_observer_list_ = true;
+  FOR_EACH_OBSERVER(EnabledStateChangedObserver, enabled_state_observer_list_,
+                    OnTraceLogWillDisable());
+  dispatching_to_observer_list_ = false;
+
+  enabled_ = false;
+  included_categories_.clear();
+  excluded_categories_.clear();
+  watch_category_ = NULL;
+  watch_event_name_ = "";
+  for (int i = 0; i < g_category_index; i++)
+    g_category_enabled[i] = 0;
+  AddThreadNameMetadataEvents();
+  AddClockSyncMetadataEvents();
 }
 
 void TraceLog::SetEnabled(bool enabled) {
@@ -538,28 +566,19 @@ float TraceLog::GetBufferPercentFull() const {
   return (float)((double)logged_events_.size()/(double)kTraceEventBufferSize);
 }
 
-void TraceLog::SetOutputCallback(const TraceLog::OutputCallback& cb) {
+void TraceLog::SetNotificationCallback(
+    const TraceLog::NotificationCallback& cb) {
   AutoLock lock(lock_);
-  output_callback_ = cb;
+  notification_callback_ = cb;
 }
 
-void TraceLog::SetBufferFullCallback(const TraceLog::BufferFullCallback& cb) {
-  AutoLock lock(lock_);
-  buffer_full_callback_ = cb;
-}
-
-void TraceLog::Flush() {
+void TraceLog::Flush(const TraceLog::OutputCallback& cb) {
   std::vector<TraceEvent> previous_logged_events;
-  OutputCallback output_callback_copy;
   {
     AutoLock lock(lock_);
     previous_logged_events.swap(logged_events_);
-    output_callback_copy = output_callback_;
   }  // release lock
 
-  if (output_callback_copy.is_null())
-    return;
-
   for (size_t i = 0;
        i < previous_logged_events.size();
        i += kTraceEventBatchSize) {
@@ -569,7 +588,7 @@ void TraceLog::Flush() {
                                    i,
                                    kTraceEventBatchSize,
                                    &(json_events_str_ptr->data()));
-    output_callback_copy.Run(json_events_str_ptr);
+    cb.Run(json_events_str_ptr);
   }
 }
 
@@ -586,7 +605,7 @@ int TraceLog::AddTraceEvent(char phase,
                             unsigned char flags) {
   DCHECK(name);
   TimeTicks now = TimeTicks::NowFromSystemTraceTime();
-  BufferFullCallback buffer_full_callback_copy;
+  NotificationHelper notifier(this);
   int ret_begin_id = -1;
   {
     AutoLock lock(lock_);
@@ -652,13 +671,14 @@ int TraceLog::AddTraceEvent(char phase,
                    num_args, arg_names, arg_types, arg_values,
                    flags));
 
-    if (logged_events_.size() == kTraceEventBufferSize) {
-      buffer_full_callback_copy = buffer_full_callback_;
-    }
+    if (logged_events_.size() == kTraceEventBufferSize)
+      notifier.AddNotificationWhileLocked(TRACE_BUFFER_FULL);
+
+    if (watch_category_ == category_enabled && watch_event_name_ == name)
+      notifier.AddNotificationWhileLocked(EVENT_WATCH_NOTIFICATION);
   }  // release lock
 
-  if (!buffer_full_callback_copy.is_null())
-    buffer_full_callback_copy.Run();
+  notifier.SendNotificationIfAny();
 
   return ret_begin_id;
 }
@@ -686,6 +706,41 @@ void TraceLog::AddTraceEventEtw(char phase,
                            TRACE_EVENT_FLAG_COPY, "id", id, "extra", extra);
 }
 
+void TraceLog::SetWatchEvent(const std::string& category_name,
+                             const std::string& event_name) {
+  const unsigned char* category = GetCategoryEnabled(category_name.c_str());
+  int notify_count = 0;
+  {
+    AutoLock lock(lock_);
+    watch_category_ = category;
+    watch_event_name_ = event_name;
+
+    // First, search existing events for watch event because we want to catch it
+    // even if it has already occurred.
+    for (size_t i = 0u; i < logged_events_.size(); ++i) {
+      if (category == logged_events_[i].category_enabled() &&
+          strcmp(event_name.c_str(), logged_events_[i].name()) == 0) {
+        ++notify_count;
+      }
+    }
+  }  // release lock
+
+  // Send notification for each event found.
+  for (int i = 0; i < notify_count; ++i) {
+    NotificationHelper notifier(this);
+    lock_.Acquire();
+    notifier.AddNotificationWhileLocked(EVENT_WATCH_NOTIFICATION);
+    lock_.Release();
+    notifier.SendNotificationIfAny();
+  }
+}
+
+void TraceLog::CancelWatchEvent() {
+  AutoLock lock(lock_);
+  watch_category_ = NULL;
+  watch_event_name_ = "";
+}
+
 void TraceLog::AddClockSyncMetadataEvents() {
 #if defined(OS_ANDROID)
   // Since Android does not support sched_setaffinity, we cannot establish clock
diff --git a/base/debug/trace_event_impl.h b/base/debug/trace_event_impl.h
index ca711db..62a81d8 100644
--- a/base/debug/trace_event_impl.h
+++ b/base/debug/trace_event_impl.h
@@ -16,6 +16,7 @@
 #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"
 
@@ -89,6 +90,7 @@ class BASE_EXPORT TraceEvent {
     return parameter_copy_storage_.get();
   }
 
+  const unsigned char* category_enabled() const { return category_enabled_; }
   const char* name() const { return name_; }
 
  private:
@@ -154,6 +156,16 @@ class BASE_EXPORT TraceResultBuffer {
 
 class BASE_EXPORT TraceLog {
  public:
+  // Notification is a mask of one or more of the following events.
+  enum 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.
@@ -213,23 +225,21 @@ class BASE_EXPORT TraceLog {
 
   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 and from any thread. WARNING: It is possible for the previously set
+  // callback to be called during OR AFTER a call to SetNotificationCallback.
+  // Therefore, the target of the callback must either be a global function,
+  // ref-counted object or a LazyInstance with Leaky traits (or equivalent).
+  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);
@@ -263,6 +273,16 @@ class BASE_EXPORT TraceLog {
                                const void* id,
                                const std::string& extra);
 
+  // For every matching event, a notification will be fired. NOTE: the
+  // notification will fire for each matching event that has already occurred
+  // since tracing was started (including before tracing if the process was
+  // started with tracing turned on).
+  void SetWatchEvent(const std::string& category_name,
+                     const std::string& event_name);
+  // 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:
@@ -287,6 +307,29 @@ class BASE_EXPORT TraceLog {
   // by the Singleton class.
   friend struct StaticMemorySingletonTraits<TraceLog>;
 
+  // Helper class for managing notification_thread_count_ and running
+  // notification callbacks. This is very similar to a reader-writer lock, but
+  // shares the lock with TraceLog and manages the notification flags.
+  class NotificationHelper {
+   public:
+    inline explicit NotificationHelper(TraceLog* trace_log);
+    inline ~NotificationHelper();
+
+    // Called only while TraceLog::lock_ is held. This ORs the given
+    // notification with any existing notifcations.
+    inline void AddNotificationWhileLocked(int notification);
+
+    // Called only while TraceLog::lock_ is NOT held. If there are any pending
+    // notifications from previous calls to AddNotificationWhileLocked, this
+    // will call the NotificationCallback.
+    inline void SendNotificationIfAny();
+
+   private:
+    TraceLog* trace_log_;
+    NotificationCallback callback_copy_;
+    int notification_;
+  };
+
   TraceLog();
   ~TraceLog();
   const unsigned char* GetCategoryEnabledInternal(const char* name);
@@ -295,10 +338,10 @@ class BASE_EXPORT TraceLog {
 
   // TODO(nduca): switch to per-thread trace buffers to reduce thread
   // synchronization.
+  // This lock protects TraceLog member accesses from arbitrary threads.
   Lock lock_;
   bool enabled_;
-  OutputCallback output_callback_;
-  BufferFullCallback buffer_full_callback_;
+  NotificationCallback notification_callback_;
   std::vector<TraceEvent> logged_events_;
   std::vector<std::string> included_categories_;
   std::vector<std::string> excluded_categories_;
@@ -312,6 +355,10 @@ class BASE_EXPORT TraceLog {
 
   int process_id_;
 
+  // Allow tests to wake up when certain events occur.
+  const unsigned char* watch_category_;
+  std::string watch_event_name_;
+
   DISALLOW_COPY_AND_ASSIGN(TraceLog);
 };
 
diff --git a/base/debug/trace_event_unittest.cc b/base/debug/trace_event_unittest.cc
index f806cf1..1f358fb 100644
--- a/base/debug/trace_event_unittest.cc
+++ b/base/debug/trace_event_unittest.cc
@@ -46,6 +46,10 @@ class TraceEventTestFixture : public testing::Test {
   void ManualTestSetUp();
   void OnTraceDataCollected(
       const scoped_refptr<base::RefCountedString>& events_str);
+  void OnTraceNotification(int notification) {
+    if (notification & TraceLog::EVENT_WATCH_NOTIFICATION)
+      ++event_watch_notification_;
+  }
   DictionaryValue* FindMatchingTraceEntry(const JsonKeyValue* key_values);
   DictionaryValue* FindNamePhase(const char* name, const char* phase);
   DictionaryValue* FindNamePhaseKeyValue(const char* name,
@@ -61,6 +65,18 @@ class TraceEventTestFixture : public testing::Test {
     json_output_.json_output.clear();
   }
 
+  void BeginTrace() {
+    event_watch_notification_ = 0;
+    TraceLog::GetInstance()->SetEnabled("*");
+  }
+
+  void EndTraceAndFlush() {
+    TraceLog::GetInstance()->SetDisabled();
+    TraceLog::GetInstance()->Flush(
+        base::Bind(&TraceEventTestFixture::OnTraceDataCollected,
+                   base::Unretained(this)));
+  }
+
   virtual void SetUp() OVERRIDE {
     old_thread_name_ = PlatformThread::GetName();
   }
@@ -74,6 +90,7 @@ class TraceEventTestFixture : public testing::Test {
   ListValue trace_parsed_;
   base::debug::TraceResultBuffer trace_buffer_;
   base::debug::TraceResultBuffer::SimpleOutput json_output_;
+  int event_watch_notification_;
 
  private:
   // We want our singleton torn down after each test.
@@ -87,8 +104,8 @@ void TraceEventTestFixture::ManualTestSetUp() {
   TraceLog* tracelog = TraceLog::GetInstance();
   ASSERT_TRUE(tracelog);
   ASSERT_FALSE(tracelog->IsEnabled());
-  tracelog->SetOutputCallback(
-      base::Bind(&TraceEventTestFixture::OnTraceDataCollected,
+  tracelog->SetNotificationCallback(
+      base::Bind(&TraceEventTestFixture::OnTraceNotification,
                  base::Unretained(this)));
   trace_buffer_.SetOutputCallback(json_output_.GetCallback());
 }
@@ -650,7 +667,7 @@ TEST_F(TraceEventTestFixture, DataCaptured) {
 
   TraceWithAllMacroVariants(NULL);
 
-  TraceLog::GetInstance()->SetEnabled(false);
+  EndTraceAndFlush();
 
   ValidateAllTraceMacrosCreatedData(trace_parsed_);
 }
@@ -741,10 +758,10 @@ TEST_F(TraceEventTestFixture, Categories) {
   // enabled or disabled when the trace event was encountered.
   TRACE_EVENT_INSTANT0("c1", "name");
   TRACE_EVENT_INSTANT0("c2", "name");
-  TraceLog::GetInstance()->SetEnabled(true);
+  BeginTrace();
   TRACE_EVENT_INSTANT0("c3", "name");
   TRACE_EVENT_INSTANT0("c4", "name");
-  TraceLog::GetInstance()->SetEnabled(false);
+  EndTraceAndFlush();
   std::vector<std::string> cats;
   TraceLog::GetInstance()->GetKnownCategories(&cats);
   EXPECT_TRUE(std::find(cats.begin(), cats.end(), "c1") != cats.end());
@@ -765,7 +782,7 @@ TEST_F(TraceEventTestFixture, Categories) {
   TraceLog::GetInstance()->SetEnabled(included_categories, empty_categories);
   TRACE_EVENT_INSTANT0("cat1", "name");
   TRACE_EVENT_INSTANT0("cat2", "name");
-  TraceLog::GetInstance()->SetDisabled();
+  EndTraceAndFlush();
   EXPECT_TRUE(trace_parsed_.empty());
 
   // Include existent category -> only events of that category
@@ -775,7 +792,7 @@ TEST_F(TraceEventTestFixture, Categories) {
   TraceLog::GetInstance()->SetEnabled(included_categories, empty_categories);
   TRACE_EVENT_INSTANT0("inc", "name");
   TRACE_EVENT_INSTANT0("inc2", "name");
-  TraceLog::GetInstance()->SetDisabled();
+  EndTraceAndFlush();
   EXPECT_TRUE(FindMatchingValue("cat", "inc"));
   EXPECT_FALSE(FindNonMatchingValue("cat", "inc"));
 
@@ -791,7 +808,7 @@ TEST_F(TraceEventTestFixture, Categories) {
   TRACE_EVENT_INSTANT0("inc_wildchar_bla_end", "not_inc");
   TRACE_EVENT_INSTANT0("cat1", "not_inc");
   TRACE_EVENT_INSTANT0("cat2", "not_inc");
-  TraceLog::GetInstance()->SetDisabled();
+  EndTraceAndFlush();
   EXPECT_TRUE(FindMatchingValue("cat", "inc_wildcard_abc"));
   EXPECT_TRUE(FindMatchingValue("cat", "inc_wildcard_"));
   EXPECT_TRUE(FindMatchingValue("cat", "inc_wildchar_x_end"));
@@ -806,7 +823,7 @@ TEST_F(TraceEventTestFixture, Categories) {
   TraceLog::GetInstance()->SetEnabled(empty_categories, excluded_categories);
   TRACE_EVENT_INSTANT0("cat1", "name");
   TRACE_EVENT_INSTANT0("cat2", "name");
-  TraceLog::GetInstance()->SetDisabled();
+  EndTraceAndFlush();
   EXPECT_TRUE(FindMatchingValue("cat", "cat1"));
   EXPECT_TRUE(FindMatchingValue("cat", "cat2"));
 
@@ -817,7 +834,7 @@ TEST_F(TraceEventTestFixture, Categories) {
   TraceLog::GetInstance()->SetEnabled(empty_categories, excluded_categories);
   TRACE_EVENT_INSTANT0("inc", "name");
   TRACE_EVENT_INSTANT0("inc2", "name");
-  TraceLog::GetInstance()->SetDisabled();
+  EndTraceAndFlush();
   EXPECT_TRUE(FindMatchingValue("cat", "inc2"));
   EXPECT_FALSE(FindMatchingValue("cat", "inc"));
 
@@ -833,7 +850,7 @@ TEST_F(TraceEventTestFixture, Categories) {
   TRACE_EVENT_INSTANT0("inc_wildchar_bla_end", "included");
   TRACE_EVENT_INSTANT0("cat1", "included");
   TRACE_EVENT_INSTANT0("cat2", "included");
-  TraceLog::GetInstance()->SetDisabled();
+  EndTraceAndFlush();
   EXPECT_TRUE(FindMatchingValue("cat", "inc_wildchar_bla_end"));
   EXPECT_TRUE(FindMatchingValue("cat", "cat1"));
   EXPECT_TRUE(FindMatchingValue("cat", "cat2"));
@@ -843,7 +860,7 @@ TEST_F(TraceEventTestFixture, Categories) {
 // Simple Test for time threshold events.
 TEST_F(TraceEventTestFixture, DataCapturedThreshold) {
   ManualTestSetUp();
-  TraceLog::GetInstance()->SetEnabled(true);
+  BeginTrace();
 
   // Test that events at the same level are properly filtered by threshold.
   {
@@ -910,7 +927,7 @@ TEST_F(TraceEventTestFixture, DataCapturedThreshold) {
     }
   }
 
-  TraceLog::GetInstance()->SetEnabled(false);
+  EndTraceAndFlush();
 
 #define EXPECT_FIND_BE_(str) \
   EXPECT_TRUE(FindNamePhase(str, "B")); \
@@ -943,10 +960,69 @@ TEST_F(TraceEventTestFixture, DataCapturedThreshold) {
   EXPECT_NOT_FIND_BE_("4thresholdlong2");
 }
 
+// Test EVENT_WATCH_NOTIFICATION
+TEST_F(TraceEventTestFixture, EventWatchNotification) {
+  ManualTestSetUp();
+
+  // Basic one occurrence.
+  BeginTrace();
+  TraceLog::GetInstance()->SetWatchEvent("cat", "event");
+  TRACE_EVENT_INSTANT0("cat", "event");
+  EndTraceAndFlush();
+  EXPECT_EQ(event_watch_notification_, 1);
+
+  // Basic one occurrence before Set.
+  BeginTrace();
+  TRACE_EVENT_INSTANT0("cat", "event");
+  TraceLog::GetInstance()->SetWatchEvent("cat", "event");
+  EndTraceAndFlush();
+  EXPECT_EQ(event_watch_notification_, 1);
+
+  // Auto-reset after end trace.
+  BeginTrace();
+  TraceLog::GetInstance()->SetWatchEvent("cat", "event");
+  EndTraceAndFlush();
+  BeginTrace();
+  TRACE_EVENT_INSTANT0("cat", "event");
+  EndTraceAndFlush();
+  EXPECT_EQ(event_watch_notification_, 0);
+
+  // Multiple occurrence.
+  BeginTrace();
+  int num_occurrences = 5;
+  TraceLog::GetInstance()->SetWatchEvent("cat", "event");
+  for (int i = 0; i < num_occurrences; ++i)
+    TRACE_EVENT_INSTANT0("cat", "event");
+  EndTraceAndFlush();
+  EXPECT_EQ(event_watch_notification_, num_occurrences);
+
+  // Wrong category.
+  BeginTrace();
+  TraceLog::GetInstance()->SetWatchEvent("cat", "event");
+  TRACE_EVENT_INSTANT0("wrong_cat", "event");
+  EndTraceAndFlush();
+  EXPECT_EQ(event_watch_notification_, 0);
+
+  // Wrong name.
+  BeginTrace();
+  TraceLog::GetInstance()->SetWatchEvent("cat", "event");
+  TRACE_EVENT_INSTANT0("cat", "wrong_event");
+  EndTraceAndFlush();
+  EXPECT_EQ(event_watch_notification_, 0);
+
+  // Canceled.
+  BeginTrace();
+  TraceLog::GetInstance()->SetWatchEvent("cat", "event");
+  TraceLog::GetInstance()->CancelWatchEvent();
+  TRACE_EVENT_INSTANT0("cat", "event");
+  EndTraceAndFlush();
+  EXPECT_EQ(event_watch_notification_, 0);
+}
+
 // Test ASYNC_BEGIN/END events
 TEST_F(TraceEventTestFixture, AsyncBeginEndEvents) {
   ManualTestSetUp();
-  TraceLog::GetInstance()->SetEnabled(true);
+  BeginTrace();
 
   unsigned long long id = 0xfeedbeeffeedbeefull;
   TRACE_EVENT_ASYNC_BEGIN0( "cat", "name1", id);
@@ -955,7 +1031,7 @@ TEST_F(TraceEventTestFixture, AsyncBeginEndEvents) {
   TRACE_EVENT_BEGIN0( "cat", "name2");
   TRACE_EVENT_ASYNC_BEGIN0( "cat", "name3", 0);
 
-  TraceLog::GetInstance()->SetEnabled(false);
+  EndTraceAndFlush();
 
   EXPECT_TRUE(FindNamePhase("name1", "S"));
   EXPECT_TRUE(FindNamePhase("name1", "T"));
@@ -980,15 +1056,15 @@ TEST_F(TraceEventTestFixture, AsyncBeginEndPointerMangling) {
   void* ptr = this;
 
   TraceLog::GetInstance()->SetProcessID(100);
-  TraceLog::GetInstance()->SetEnabled(true);
+  BeginTrace();
   TRACE_EVENT_ASYNC_BEGIN0( "cat", "name1", ptr);
   TRACE_EVENT_ASYNC_BEGIN0( "cat", "name2", ptr);
-  TraceLog::GetInstance()->SetEnabled(false);
+  EndTraceAndFlush();
 
   TraceLog::GetInstance()->SetProcessID(200);
-  TraceLog::GetInstance()->SetEnabled(true);
+  BeginTrace();
   TRACE_EVENT_ASYNC_END0( "cat", "name1", ptr);
-  TraceLog::GetInstance()->SetEnabled(false);
+  EndTraceAndFlush();
 
   DictionaryValue* async_begin = FindNamePhase("name1", "S");
   DictionaryValue* async_begin2 = FindNamePhase("name2", "S");
@@ -1017,11 +1093,11 @@ TEST_F(TraceEventTestFixture, StaticStringVsString) {
   ManualTestSetUp();
   TraceLog* tracer = TraceLog::GetInstance();
   // Make sure old events are flushed:
-  tracer->SetEnabled(false);
+  EndTraceAndFlush();
   EXPECT_EQ(0u, tracer->GetEventsSize());
 
   {
-    tracer->SetEnabled(true);
+    BeginTrace();
     // Test that string arguments are copied.
     TRACE_EVENT2("cat", "name1",
                  "arg1", std::string("argval"), "arg2", std::string("argval"));
@@ -1039,11 +1115,11 @@ TEST_F(TraceEventTestFixture, StaticStringVsString) {
     EXPECT_TRUE(event2.parameter_copy_storage() != NULL);
     EXPECT_GT(event1.parameter_copy_storage()->size(), 0u);
     EXPECT_GT(event2.parameter_copy_storage()->size(), 0u);
-    tracer->SetEnabled(false);
+    EndTraceAndFlush();
   }
 
   {
-    tracer->SetEnabled(true);
+    BeginTrace();
     // Test that static literal string arguments are not copied.
     TRACE_EVENT2("cat", "name1",
                  "arg1", "argval", "arg2", "argval");
@@ -1061,14 +1137,14 @@ TEST_F(TraceEventTestFixture, StaticStringVsString) {
     EXPECT_STREQ("name2", event2.name());
     EXPECT_TRUE(event1.parameter_copy_storage() == NULL);
     EXPECT_TRUE(event2.parameter_copy_storage() == NULL);
-    tracer->SetEnabled(false);
+    EndTraceAndFlush();
   }
 }
 
 // Test that data sent from other threads is gathered
 TEST_F(TraceEventTestFixture, DataCapturedOnThread) {
   ManualTestSetUp();
-  TraceLog::GetInstance()->SetEnabled(true);
+  BeginTrace();
 
   Thread thread("1");
   WaitableEvent task_complete_event(false, false);
@@ -1079,14 +1155,14 @@ TEST_F(TraceEventTestFixture, DataCapturedOnThread) {
   task_complete_event.Wait();
   thread.Stop();
 
-  TraceLog::GetInstance()->SetEnabled(false);
+  EndTraceAndFlush();
   ValidateAllTraceMacrosCreatedData(trace_parsed_);
 }
 
 // Test that data sent from multiple threads is gathered
 TEST_F(TraceEventTestFixture, DataCapturedManyThreads) {
   ManualTestSetUp();
-  TraceLog::GetInstance()->SetEnabled(true);
+  BeginTrace();
 
   const int num_threads = 4;
   const int num_events = 4000;
@@ -1111,7 +1187,7 @@ TEST_F(TraceEventTestFixture, DataCapturedManyThreads) {
     delete task_complete_events[i];
   }
 
-  TraceLog::GetInstance()->SetEnabled(false);
+  EndTraceAndFlush();
 
   ValidateInstantEventPresentOnEveryThread(trace_parsed_,
                                            num_threads, num_events);
@@ -1131,7 +1207,7 @@ TEST_F(TraceEventTestFixture, ThreadNames) {
     threads[i] = new Thread(StringPrintf("Thread %d", i).c_str());
 
   // Enable tracing.
-  TraceLog::GetInstance()->SetEnabled(true);
+  BeginTrace();
 
   // Now run some trace code on these threads.
   WaitableEvent* task_complete_events[num_threads];
@@ -1154,7 +1230,7 @@ TEST_F(TraceEventTestFixture, ThreadNames) {
     delete task_complete_events[i];
   }
 
-  TraceLog::GetInstance()->SetEnabled(false);
+  EndTraceAndFlush();
 
   std::string tmp;
   int tmp_int;
@@ -1190,7 +1266,7 @@ TEST_F(TraceEventTestFixture, ThreadNames) {
 TEST_F(TraceEventTestFixture, ThreadNameChanges) {
   ManualTestSetUp();
 
-  TraceLog::GetInstance()->SetEnabled(true);
+  BeginTrace();
 
   PlatformThread::SetName("");
   TRACE_EVENT_INSTANT0("drink", "water");
@@ -1208,7 +1284,7 @@ TEST_F(TraceEventTestFixture, ThreadNameChanges) {
   PlatformThread::SetName(" bar");
   TRACE_EVENT_INSTANT0("drink", "whisky");
 
-  TraceLog::GetInstance()->SetEnabled(false);
+  EndTraceAndFlush();
 
   std::vector<const DictionaryValue*> items =
       FindTraceEntries(trace_parsed_, "thread_name");
@@ -1247,14 +1323,14 @@ TEST_F(TraceEventTestFixture, AtExit) {
 
       TRACE_EVENT_INSTANT0("all", "not recorded; system not enabled");
 
-      TraceLog::GetInstance()->SetEnabled(true);
+      BeginTrace();
 
       TRACE_EVENT_INSTANT0("all", "is recorded 1; system has been enabled");
       // Trace calls that will cache pointers to categories; they're valid here
       TraceCallsWithCachedCategoryPointersPointers(
           "is recorded 2; system has been enabled");
 
-      TraceLog::GetInstance()->SetEnabled(false);
+      EndTraceAndFlush();
     } // scope to destroy singleton
     ASSERT_FALSE(TraceLog::GetInstance());
 
@@ -1295,14 +1371,14 @@ TEST_F(TraceEventTestFixture, NormallyNoDeepCopy) {
 
   std::string name_string("event name");
 
-  TraceLog::GetInstance()->SetEnabled(true);
+  BeginTrace();
   TRACE_EVENT_INSTANT0("category", name_string.c_str());
 
   // Modify the string in place (a wholesale reassignment may leave the old
   // string intact on the heap).
   name_string[0] = '@';
 
-  TraceLog::GetInstance()->SetEnabled(false);
+  EndTraceAndFlush();
 
   EXPECT_FALSE(FindTraceEntry(trace_parsed_, "event name"));
   EXPECT_TRUE(FindTraceEntry(trace_parsed_, name_string.c_str()));
@@ -1322,7 +1398,7 @@ TEST_F(TraceEventTestFixture, DeepCopy) {
   std::string val1("val1");
   std::string val2("val2");
 
-  TraceLog::GetInstance()->SetEnabled(true);
+  BeginTrace();
   TRACE_EVENT_COPY_INSTANT0("category", name1.c_str());
   TRACE_EVENT_COPY_BEGIN1("category", name2.c_str(),
                           arg1.c_str(), 5);
@@ -1333,7 +1409,7 @@ TEST_F(TraceEventTestFixture, DeepCopy) {
   // As per NormallyNoDeepCopy, modify the strings in place.
   name1[0] = name2[0] = name3[0] = arg1[0] = arg2[0] = val1[0] = val2[0] = '@';
 
-  TraceLog::GetInstance()->SetEnabled(false);
+  EndTraceAndFlush();
 
   EXPECT_FALSE(FindTraceEntry(trace_parsed_, name1.c_str()));
   EXPECT_FALSE(FindTraceEntry(trace_parsed_, name2.c_str()));
diff --git a/base/test/trace_event_analyzer_unittest.cc b/base/test/trace_event_analyzer_unittest.cc
index 63760a4..5d850e2 100644
--- a/base/test/trace_event_analyzer_unittest.cc
+++ b/base/test/trace_event_analyzer_unittest.cc
@@ -26,11 +26,7 @@ class TraceEventAnalyzerTest : public testing::Test {
 
 void TraceEventAnalyzerTest::ManualSetUp() {
   base::debug::TraceLog::Resurrect();
-  base::debug::TraceLog* tracelog = base::debug::TraceLog::GetInstance();
-  ASSERT_TRUE(tracelog);
-  tracelog->SetOutputCallback(
-    base::Bind(&TraceEventAnalyzerTest::OnTraceDataCollected,
-               base::Unretained(this)));
+  ASSERT_TRUE(base::debug::TraceLog::GetInstance());
   buffer_.SetOutputCallback(output_.GetCallback());
   output_.json_output.clear();
 }
@@ -48,6 +44,9 @@ void TraceEventAnalyzerTest::BeginTracing() {
 
 void TraceEventAnalyzerTest::EndTracing() {
   base::debug::TraceLog::GetInstance()->SetEnabled(false);
+  base::debug::TraceLog::GetInstance()->Flush(
+      base::Bind(&TraceEventAnalyzerTest::OnTraceDataCollected,
+                 base::Unretained(this)));
   buffer_.Finish();
 }