Tracing macros perftests.

components/tracing/test/trace_event_perftest.cc

Index: components/tracing/test/trace_event_perftest.cc
diff --git a/components/tracing/test/trace_event_perftest.cc b/components/tracing/test/trace_event_perftest.cc
index 4c93e2fb0cfefbc34bf495d40036bebe2543f0f2..c2bfaeb35a74292df023df346ee6d0cb9ad29168 100644
--- a/components/tracing/test/trace_event_perftest.cc
+++ b/components/tracing/test/trace_event_perftest.cc
@@ -3,20 +3,28 @@
 // found in the LICENSE file.
 
 #include "base/bind.h"
+#include "base/memory/ptr_util.h"
 #include "base/memory/ref_counted_memory.h"
 #include "base/run_loop.h"
+#include "base/threading/thread.h"
 #include "base/trace_event/trace_event.h"
+#include "base/trace_event/trace_event_argument.h"
 #include "perf_test_helpers.h"
 #include "testing/gtest/include/gtest/gtest.h"
 
 namespace tracing {
 namespace {
 
+using base::Bind;
+using base::Thread;
+using base::Unretained;
+using base::WaitableEvent;
 using base::trace_event::TraceConfig;
 using base::trace_event::TraceLog;
 using base::trace_event::TraceRecordMode;
+using base::trace_event::TracedValue;
 
-const int kNumRuns = 100;
+const int kNumRuns = 10;
 
 class TraceEventPerfTest : public ::testing::Test {
  public:
@@ -43,6 +51,34 @@ class TraceEventPerfTest : public ::testing::Test {
     if (!has_more_events)
       quit_closure.Run();
   }
+
+  std::unique_ptr<TracedValue> MakeTracedValue(int counter) {
+    auto value = base::MakeUnique<TracedValue>();
+    value->SetInteger("counter", counter);
+    value->BeginDictionary("test_dict");
+    value->BeginArray("nodes");
+    for (int i = 0; i < 10; i++) {
+      value->BeginDictionary();
+      value->SetInteger("id", i);
+      value->SetBoolean("valid", true);
+      value->SetString("value", "foo");
+      value->EndDictionary();
+    }
+    value->EndArray();
+    value->SetInteger("count", 10);
+    value->EndDictionary();
+    return value;
+  }
+
+  static void SubmitTraceEventsAndSignal(WaitableEvent* complete_event) {
+    for (int i = 0; i < 10000; i++) {
+      TRACE_EVENT0("test_category", "some call");
+    }
+    complete_event->Signal();
+  }
+
+ private:
+  base::MessageLoop _message_loop;
 };
 
 TEST_F(TraceEventPerfTest, Submit_10000_TRACE_EVENT0) {
@@ -57,5 +93,77 @@ TEST_F(TraceEventPerfTest, Submit_10000_TRACE_EVENT0) {
   EndTraceAndFlush();
 }
 
+TEST_F(TraceEventPerfTest, Long_TRACE_EVENT0) {
+  BeginTrace();
+  IterableStopwatch stopwatch("long_event");
+  for (int lap = 0; lap < kNumRuns; lap++) {
+    TRACE_EVENT0("test_category", "Outer event");
+    for (int i = 0; i < 10000; i++) {
+      TRACE_EVENT0("test_category", "TRACE_EVENT0 call");
+    }
+    stopwatch.NextLap();
+  }
+  EndTraceAndFlush();
+}
+
+TEST_F(TraceEventPerfTest, Create_10000_TracedValue) {
+  std::unique_ptr<TracedValue> value;
+  {
+    ScopedStopwatch value_sw("create_traced_values");
+    for (int i = 0; i < 10000; i++) {
+      value = MakeTracedValue(i);
+    }
+  }
+}
+
+TEST_F(TraceEventPerfTest, Submit_10000_TRACE_EVENT_with_TracedValue) {
+  BeginTrace();
+  // Time reported by this timer includes TracedValue creation as well.
+  IterableStopwatch trace_sw("events_with_value");
+  for (int lap = 0; lap < kNumRuns; lap++) {
+    for (int i = 0; i < 10000; i++) {
+      TRACE_EVENT_INSTANT1("test_category", "event_with_value",
+          TRACE_EVENT_SCOPE_THREAD, "value", MakeTracedValue(i));
+    }
+    trace_sw.NextLap();
+  }
+  EndTraceAndFlush();
+}
+
+TEST_F(TraceEventPerfTest, Concurrent_10000_TRACE_EVENT0) {

[Primiano Tucci (use gerrit), 2016/11/14 23:59:11]

Oh just one thing here: can you cal lthis Submit_10000_TRACE_EVENT_multithread
for consistency with the pattern above?

+  BeginTrace();
+  const int kNumThreads = 4;
+
+  std::vector<std::unique_ptr<Thread>> threads;
+  std::vector<std::unique_ptr<WaitableEvent>> complete_events;
+
+  for (int i = 0; i < kNumThreads; i++) {
+    Thread* thread = new Thread(std::string("thread_%d") + std::to_string(i));
+    WaitableEvent* complete_event =
+        new WaitableEvent(WaitableEvent::ResetPolicy::AUTOMATIC,
+                          WaitableEvent::InitialState::NOT_SIGNALED);
+    threads.push_back(base::WrapUnique(thread));
+    complete_events.push_back(base::WrapUnique(complete_event));
+    thread->Start();
+  }
+
+  {
+    ScopedStopwatch stopwatch("events_over_multiple_threads");
+    for (int i = 0; i < kNumThreads; i++) {
+      threads[i]->task_runner()->PostTask(
+          FROM_HERE,
+          base::Bind(&SubmitTraceEventsAndSignal, complete_events[i].get()));
+    }
+    for (int i = 0; i < kNumThreads; i++) {
+      complete_events[i]->Wait();
+    }
+  }
+
+  EndTraceAndFlush();
+  for (int i = 0; i < kNumThreads; i++) {
+    threads[i]->Stop();
+  }
+}
+
 }  // namespace
 }  // namespace tracing