Fixing and enhancing OrderedSimpleTaskRunner to allow 100% deterministic tests.

cc/scheduler/scheduler.cc

Index: cc/scheduler/scheduler.cc
diff --git a/cc/scheduler/scheduler.cc b/cc/scheduler/scheduler.cc
index 1451237cd9ff0cbd94a91a038a88c50585ed291b..7632dbf3571795bb2dbff15d0f0d7c3d3ddcfe82 100644
--- a/cc/scheduler/scheduler.cc
+++ b/cc/scheduler/scheduler.cc
@@ -13,21 +13,13 @@
 #include "cc/debug/devtools_instrumentation.h"
 #include "cc/debug/traced_value.h"
 #include "cc/scheduler/delay_based_time_source.h"
-#include "ui/gfx/frame_time.h"
 
 namespace cc {
 
 Scheduler::SyntheticBeginFrameSource::SyntheticBeginFrameSource(
     Scheduler* scheduler,
-    base::SingleThreadTaskRunner* task_runner)
-    : scheduler_(scheduler) {
-  if (gfx::FrameTime::TimestampsAreHighRes()) {
-    time_source_ = DelayBasedTimeSourceHighRes::Create(
-        scheduler_->VSyncInterval(), task_runner);
-  } else {
-    time_source_ = DelayBasedTimeSource::Create(scheduler_->VSyncInterval(),
-                                                task_runner);
-  }
+    scoped_refptr<DelayBasedTimeSource> time_source)
+    : scheduler_(scheduler), time_source_(time_source) {
   time_source_->SetClient(this);
 }
 
@@ -126,9 +118,21 @@ Scheduler::~Scheduler() {
 }
 
 void Scheduler::SetupSyntheticBeginFrames() {
+  scoped_refptr<DelayBasedTimeSource> time_source;
+  if (gfx::FrameTime::TimestampsAreHighRes()) {
+    time_source = DelayBasedTimeSourceHighRes::Create(VSyncInterval(),
+                                                      impl_task_runner_.get());
+  } else {
+    time_source =
+        DelayBasedTimeSource::Create(VSyncInterval(), impl_task_runner_.get());
+  }
   DCHECK(!synthetic_begin_frame_source_);
   synthetic_begin_frame_source_.reset(
-      new SyntheticBeginFrameSource(this, impl_task_runner_.get()));
+      new SyntheticBeginFrameSource(this, time_source));
+}
+
+base::TimeTicks Scheduler::Now() const {
+  return gfx::FrameTime::Now();
 }
 
 void Scheduler::CommitVSyncParameters(base::TimeTicks timebase,
@@ -262,7 +266,7 @@ base::TimeTicks Scheduler::AnticipatedDrawTime() const {
       begin_impl_frame_args_.interval <= base::TimeDelta())
     return base::TimeTicks();
 
-  base::TimeTicks now = gfx::FrameTime::Now();
+  base::TimeTicks now = Now();
   base::TimeTicks timebase = std::max(begin_impl_frame_args_.frame_time,
                                       begin_impl_frame_args_.deadline);
   int64 intervals = 1 + ((now - timebase) / begin_impl_frame_args_.interval);
@@ -337,7 +341,7 @@ void Scheduler::BeginUnthrottledFrame() {
   DCHECK(!settings_.throttle_frame_production);
   DCHECK(begin_retro_frame_args_.empty());
 
-  base::TimeTicks now = gfx::FrameTime::Now();
+  base::TimeTicks now = Now();
   base::TimeTicks deadline = now + vsync_interval_;
 
   BeginFrameArgs begin_frame_args =
@@ -448,7 +452,7 @@ void Scheduler::BeginRetroFrame() {
   // TODO(brianderson): In the future, long deadlines could result in us not
   // draining the queue if we don't catch up. If we consistently can't catch
   // up, our fallback should be to lower our frame rate.
-  base::TimeTicks now = gfx::FrameTime::Now();
+  base::TimeTicks now = Now();
   base::TimeDelta draw_duration_estimate = client_->DrawDurationEstimate();
   while (!begin_retro_frame_args_.empty() &&
          now > AdjustedBeginImplFrameDeadline(begin_retro_frame_args_.front(),
@@ -476,6 +480,10 @@ void Scheduler::BeginRetroFrame() {
 // will check if there is a pending BeginRetroFrame to ensure we handle
 // BeginFrames in FIFO order.
 void Scheduler::PostBeginRetroFrameIfNeeded() {
+  TRACE_EVENT1(TRACE_DISABLED_BY_DEFAULT("cc.debug.scheduler"),
+               "Scheduler::PostBeginRetroFrameIfNeeded",
+               "state",
+               AsValue());
   if (!last_set_needs_begin_frame_)
     return;
 
@@ -552,6 +560,8 @@ base::TimeTicks Scheduler::AdjustedBeginImplFrameDeadline(
 }
 
 void Scheduler::ScheduleBeginImplFrameDeadline(base::TimeTicks deadline) {
+  TRACE_EVENT1(
+      "cc", "Scheduler::ScheduleBeginImplFrameDeadline", "deadline", deadline);
   if (settings_.using_synchronous_renderer_compositor) {
     // The synchronous renderer compositor has to make its GL calls
     // within this call.
@@ -564,7 +574,7 @@ void Scheduler::ScheduleBeginImplFrameDeadline(base::TimeTicks deadline) {
   begin_impl_frame_deadline_task_.Cancel();
   begin_impl_frame_deadline_task_.Reset(begin_impl_frame_deadline_closure_);
 
-  base::TimeDelta delta = deadline - gfx::FrameTime::Now();
+  base::TimeDelta delta = deadline - Now();
   if (delta <= base::TimeDelta())
     delta = base::TimeDelta();
   impl_task_runner_->PostDelayedTask(
@@ -696,9 +706,8 @@ scoped_refptr<base::debug::ConvertableToTraceFormat> Scheduler::AsValue()
   }
 
   state->BeginDictionary("scheduler_state");
-  state->SetDouble(
-      "time_until_anticipated_draw_time_ms",
-      (AnticipatedDrawTime() - base::TimeTicks::Now()).InMillisecondsF());

[brianderson, 2014/08/20 20:04:30]

It was a bug to call base::TimeTicks::Now() rather than the gfx version. This
patch fixes it - thanks.

[mithro-old, 2014/08/21 17:39:18]

Acknowledged.

+  state->SetDouble("time_until_anticipated_draw_time_ms",
+                   (AnticipatedDrawTime() - Now()).InMillisecondsF());
   state->SetDouble("vsync_interval_ms", vsync_interval_.InMillisecondsF());
   state->SetDouble("estimated_parent_draw_time_ms",
                    estimated_parent_draw_time_.InMillisecondsF());