Report expected task queueing time via UMA

components/scheduler/renderer/queueing_time_estimator_unittest.cc

+// Copyright 2015 The Chromium Authors. All rights reserved.

[Sami, 2016/04/20 09:51:27]

++year

[tdresser, 2016/04/20 15:13:33]

Done.

+// Use of this source code is governed by a BSD-style license that can be
+// found in the LICENSE file.
+
+#include "base/memory/scoped_ptr.h"
+#include "base/test/simple_test_tick_clock.h"
+#include "components/scheduler/base/test_time_source.h"
+#include "components/scheduler/renderer/queueing_time_estimator.h"
+#include "testing/gmock/include/gmock/gmock.h"
+#include "testing/gtest/include/gtest/gtest.h"
+
+namespace scheduler {
+
+class QueueingTimeEstimatorTest : public testing::Test {
+ public:
+  QueueingTimeEstimatorTest() {}
+  ~QueueingTimeEstimatorTest() override {}
+
+  void SetUp() override {
+    test_time_source_.reset(new TestTimeSource(&clock_));
+  }
+
+  base::SimpleTestTickClock clock_;
+  scoped_ptr<TestTimeSource> test_time_source_;
+};
+
+class TestQueueingTimeEstimatorClient
+    : public QueueingTimeEstimator::QueueingTimeEstimatorClient {
+ public:
+  void OnQueueingTimeForWindowEstimated(
+      base::TimeDelta queueing_time) override {
+    expected_queueing_times_.push_back(queueing_time);
+  }
+  const std::vector<base::TimeDelta>& expected_queueing_times() {
+    return expected_queueing_times_;
+  }
+
+ private:
+  std::vector<base::TimeDelta> expected_queueing_times_;
+};
+
+class QueueingTimeEstimatorForTest : public QueueingTimeEstimator {
+ public:
+  QueueingTimeEstimatorForTest(TestQueueingTimeEstimatorClient* client,
+                               TestTimeSource* test_time_source,
+                               base::TimeDelta window_duration)
+      : QueueingTimeEstimator(client, test_time_source, window_duration) {}
+};
+
+// Three tasks of one second each, all within a 5 second window. Expected
+// queueing time is the probability of falling into one of these tasks (3/5),
+// multiplied by the expected queueing time within a task (0.5 seconds). Thus we
+// expect a queueing time of 0.3 seconds.
+TEST_F(QueueingTimeEstimatorTest, AllTasksWithinWindow) {
+  TestQueueingTimeEstimatorClient client;
+  QueueingTimeEstimatorForTest estimator(&client, test_time_source_.get(),
+                                         base::TimeDelta::FromSeconds(5));
+  base::PendingTask task(FROM_HERE, base::Closure());
+
+  for (int i = 0; i < 3; ++i) {
+    estimator.WillProcessTask(task);
+    clock_.Advance(base::TimeDelta::FromMilliseconds(1000));
+    estimator.DidProcessTask(task);
+
+    clock_.Advance(base::TimeDelta::FromMilliseconds(500));
+  }
+
+  // Flush the data by adding a task in the next window.
+  clock_.Advance(base::TimeDelta::FromMilliseconds(5000));
+  estimator.WillProcessTask(task);
+  clock_.Advance(base::TimeDelta::FromMilliseconds(500));
+  estimator.DidProcessTask(task);
+
+  EXPECT_THAT(client.expected_queueing_times(),
+              testing::ElementsAre(base::TimeDelta::FromMilliseconds(300)));
+}
+
+// One 20 second long task, starting 3 seconds into the first window.
+// Window 1: Probability of being within task = 2/5. Expected delay within task:
+// avg(20, 18). Total expected queueing time = 7.6s.
+// Window 2: Probability of being within task = 1. Expected delay within task:
+// avg(18, 13). Total expected queueing time = 15.5s.
+// Window 5: Probability of being within task = 3/5. Expected delay within task:
+// avg(3, 0). Total expected queueing time = 0.9s.
+TEST_F(QueueingTimeEstimatorTest, MultiWindowTask) {
+  TestQueueingTimeEstimatorClient client;
+  QueueingTimeEstimatorForTest estimator(&client, test_time_source_.get(),
+                                         base::TimeDelta::FromSeconds(5));
+  base::PendingTask task(FROM_HERE, base::Closure());
+
+  estimator.WillProcessTask(task);
+  clock_.Advance(base::TimeDelta::FromMilliseconds(0));
+  estimator.DidProcessTask(task);
+
+  clock_.Advance(base::TimeDelta::FromMilliseconds(3000));
+
+  estimator.WillProcessTask(task);
+  clock_.Advance(base::TimeDelta::FromMilliseconds(20000));
+  estimator.DidProcessTask(task);
+
+  // Flush the data by adding a task in the next window.
+  clock_.Advance(base::TimeDelta::FromMilliseconds(5000));
+  estimator.WillProcessTask(task);
+  clock_.Advance(base::TimeDelta::FromMilliseconds(500));
+  estimator.DidProcessTask(task);
+
+  EXPECT_THAT(client.expected_queueing_times(),
+              testing::ElementsAre(base::TimeDelta::FromMilliseconds(7600),
+                                   base::TimeDelta::FromMilliseconds(15500),
+                                   base::TimeDelta::FromMilliseconds(10500),
+                                   base::TimeDelta::FromMilliseconds(5500),
+                                   base::TimeDelta::FromMilliseconds(900)));
+}
+
+/*TEST_F(QueueingTimeEstimatorTest, Clear) {

[tdresser, 2016/04/19 17:23:46]

I don't think we should clear this estimator on navigation.
https://code.google.com/p/chromium/codesearch#chromium/src/components/schedul...

Does that seem correct to you?

[Sami, 2016/04/20 09:51:27]

Not clearing it should give more accurate results in cases where we have
multiple render views in the same renderer and only one of them navigates.

[tdresser, 2016/04/20 15:13:33]

Acknowledged.

+  QueueingTimeEstimatorForTest estimator(test_time_source_.get(), 1, 100);
+  base::PendingTask task(FROM_HERE, base::Closure());
+
+  estimator.WillProcessTask(task);
+  clock_.Advance(base::TimeDelta::FromMilliseconds(500));
+  estimator.DidProcessTask(task);
+
+  estimator.Clear();
+
+  EXPECT_EQ(base::TimeDelta(), estimator.expected_task_duration());
+  }*/
+
+// A single task with a nested message loop. The top level task lasts 4 seconds.
+// Probability of landing within this task = 4/5, expected queueing time within
+// this task = 2s. Total expected queueing time = 1.6.
+TEST_F(QueueingTimeEstimatorTest, NestedRunLoop) {
+  TestQueueingTimeEstimatorClient client;
+  QueueingTimeEstimatorForTest estimator(&client, test_time_source_.get(),
+                                         base::TimeDelta::FromSeconds(5));
+  base::PendingTask task(FROM_HERE, base::Closure());
+
+  // Make sure we ignore the tasks inside the nested run loop.
+  estimator.WillProcessTask(task);
+  estimator.WillProcessTask(task);
+  clock_.Advance(base::TimeDelta::FromMilliseconds(2000));
+  estimator.DidProcessTask(task);
+  clock_.Advance(base::TimeDelta::FromMilliseconds(2000));
+  estimator.DidProcessTask(task);
+
+  // Flush the data by adding a task in the next window.
+  clock_.Advance(base::TimeDelta::FromMilliseconds(5000));
+  estimator.WillProcessTask(task);
+  clock_.Advance(base::TimeDelta::FromMilliseconds(500));
+  estimator.DidProcessTask(task);
+
+  EXPECT_THAT(client.expected_queueing_times(),
+              testing::ElementsAre(base::TimeDelta::FromMilliseconds(1600)));
+}
+
+}  // namespace scheduler