Microbenchmark for the cost of posting tasks to different pump types

base/threading/thread_perftest.cc

Index: base/threading/thread_perftest.cc
diff --git a/base/threading/thread_perftest.cc b/base/threading/thread_perftest.cc
index eaeddf9443507f4e73c8688f093628e797254bc9..260c1562313bf6c46746e191e53f2f4f623cf831 100644
--- a/base/threading/thread_perftest.cc
+++ b/base/threading/thread_perftest.cc
@@ -5,7 +5,9 @@
 #include "base/base_switches.h"
 #include "base/bind.h"
 #include "base/command_line.h"
+#include "base/format_macros.h"
 #include "base/memory/scoped_vector.h"
+#include "base/strings/stringprintf.h"
 #include "base/synchronization/condition_variable.h"
 #include "base/synchronization/lock.h"
 #include "base/synchronization/waitable_event.h"
@@ -260,6 +262,163 @@ TEST_F(ConditionVariablePerfTest, EventPingPong) {
   RunPingPongTest("4_ConditionVariable_Threads", 4);
 }
 
+class PostTaskTest : public testing::Test {
+ public:
+  PostTaskTest() : target_("target thread"), counter_(0) {
+    // Disable the task profiler as it adds significant cost!
+    CommandLine::Init(0, NULL);
+    CommandLine::ForCurrentProcess()->AppendSwitchASCII(
+        switches::kProfilerTiming, switches::kProfilerTimingDisabledValue);
+  }
+
+  void Increment() { counter_++; }
+
+  void PostTasks(int index) {
+    base::TimeTicks start = base::TimeTicks::HighResNow();
+    base::TimeTicks thread_start;
+    if (TimeTicks::IsThreadNowSupported())
+      thread_start = base::TimeTicks::ThreadNow();
+    base::TimeDelta minimum = base::TimeDelta::Max();
+    base::TimeDelta maximum = base::TimeDelta();
+    base::TimeTicks now, lastnow = start;
+    do {
+      for (size_t i = 0; i < kBatchSize; ++i) {
+        target_.message_loop()->PostTask(
+            FROM_HERE,
+            base::Bind(&PostTaskTest::Increment, base::Unretained(this)));
+      }
+      now = base::TimeTicks::HighResNow();
+      base::TimeDelta laptime = now - lastnow;
+      lastnow = now;
+      minimum = std::min(minimum, laptime);
+      maximum = std::max(maximum, laptime);
+    } while (now - start < base::TimeDelta::FromSeconds(kTargetTimeSec));
+    posting_times_[index] = now - start;
+    if (TimeTicks::IsThreadNowSupported())
+      posting_thread_times_[index] =
+          base::TimeTicks::ThreadNow() - thread_start;
+    min_batch_times_[index] = minimum;
+    max_batch_times_[index] = maximum;
+  }
+
+  void PostTasksToThread(MessageLoop::Type target_type, int numPostingThreads) {

[darin (slow to review), 2014/09/09 04:05:07]

nit: numPostingThreads -> num_posting_threads

+    counter_ = 0;
+    target_.StartWithOptions(Thread::Options(target_type, 0u));
+
+    ScopedVector<Thread> posting_threads;
+    posting_times_.reset(new base::TimeDelta[numPostingThreads]);
+    posting_thread_times_.reset(new base::TimeDelta[numPostingThreads]);
+    min_batch_times_.reset(new base::TimeDelta[numPostingThreads]);
+    max_batch_times_.reset(new base::TimeDelta[numPostingThreads]);
+
+    for (int i = 0; i < numPostingThreads; ++i) {
+      posting_threads.push_back(new Thread("posting thread"));
+      posting_threads[i]->Start();

[darin (slow to review), 2014/09/09 04:05:06]

Start() blocks the calling thread until the target thread starts. Would it be
worth starting all of the threads first, and then calling PostTask on each?
Maybe that would help increase contention in the numPostingThreads > 1 case?

+      posting_threads[i]->message_loop()->PostTask(
+          FROM_HERE,
+          base::Bind(&PostTaskTest::PostTasks, base::Unretained(this), i));
+    }
+
+    for (int i = 0; i < numPostingThreads; ++i) {
+      posting_threads[i]->Stop();
+    }
+    target_.Stop();
+    base::TimeDelta total_time;
+    base::TimeDelta total_thread_time;
+    base::TimeDelta min_batch_time = base::TimeDelta::Max();
+    base::TimeDelta max_batch_time = base::TimeDelta();
+    for (int i = 0; i < numPostingThreads; ++i) {
+      total_time += posting_times_[i];
+      total_thread_time += posting_thread_times_[i];
+      min_batch_time = std::min(min_batch_time, min_batch_times_[i]);
+      max_batch_time = std::max(max_batch_time, max_batch_times_[i]);
+    }
+    std::string trace = StringPrintf(
+        "%d_threads_posting_to_%s_pump",
+        numPostingThreads,
+        target_type == MessageLoop::TYPE_IO
+            ? "io"
+            : (target_type == MessageLoop::TYPE_UI ? "ui" : "default"));
+    perf_test::PrintResult(
+        "task",
+        "",
+        trace,
+        total_time.InMicroseconds() / static_cast<double>(counter_),
+        "us/task",
+        true);
+    perf_test::PrintResult(
+        "task",
+        "_min_batch_time",
+        trace,
+        min_batch_time.InMicroseconds() / static_cast<double>(kBatchSize),
+        "us/task",
+        false);
+    perf_test::PrintResult(
+        "task",
+        "_max_batch_time",
+        trace,
+        max_batch_time.InMicroseconds() / static_cast<double>(kBatchSize),
+        "us/task",
+        false);
+    if (TimeTicks::IsThreadNowSupported()) {
+      perf_test::PrintResult(
+          "task",
+          "_thread_time",
+          trace,
+          total_thread_time.InMicroseconds() / static_cast<double>(counter_),
+          "us/task",
+          true);
+    }
+  }
+
+ private:
+  base::Thread target_;
+  scoped_ptr<base::TimeDelta[]> posting_times_;
+  scoped_ptr<base::TimeDelta[]> posting_thread_times_;
+  scoped_ptr<base::TimeDelta[]> min_batch_times_;
+  scoped_ptr<base::TimeDelta[]> max_batch_times_;
+  int counter_;
+
+  static const size_t kTargetTimeSec = 5;
+  static const size_t kBatchSize = 100000;
+};
+
+TEST_F(PostTaskTest, ThreadTimeToIOFromOneThread) {
+  PostTasksToThread(MessageLoop::TYPE_IO, 1);
+}
+
+TEST_F(PostTaskTest, ThreadTimeToIOFromTwoThreads) {
+  PostTasksToThread(MessageLoop::TYPE_IO, 2);
+}
+
+TEST_F(PostTaskTest, ThreadTimeToIOFromFourThreads) {
+  PostTasksToThread(MessageLoop::TYPE_IO, 4);
+}
+
+TEST_F(PostTaskTest, ThreadTimeToUIFromOneThread) {
+  PostTasksToThread(MessageLoop::TYPE_UI, 1);
+}
+
+TEST_F(PostTaskTest, ThreadTimeToUIFromTwoThreads) {
+  PostTasksToThread(MessageLoop::TYPE_UI, 2);
+}
+
+TEST_F(PostTaskTest, ThreadTimeToUIFromFourThreads) {
+  PostTasksToThread(MessageLoop::TYPE_UI, 4);
+}
+
+TEST_F(PostTaskTest, ThreadTimeToDefaultFromOneThread) {
+  PostTasksToThread(MessageLoop::TYPE_DEFAULT, 1);
+}
+
+TEST_F(PostTaskTest, ThreadTimeToDefaultFromTwoThreads) {
+  PostTasksToThread(MessageLoop::TYPE_DEFAULT, 2);
+}
+
+TEST_F(PostTaskTest, ThreadTimeToDefaultFromFourThreads) {
+  PostTasksToThread(MessageLoop::TYPE_DEFAULT, 4);
+}
+
 #if defined(OS_POSIX)
 
 // Absolutely 100% minimal posix waitable event. If there is a better/faster