Fixing and enhancing OrderedSimpleTaskRunner to allow 100% deterministic tests.

cc/scheduler/scheduler.cc

 // Copyright 2011 The Chromium Authors. All rights reserved.
 // Use of this source code is governed by a BSD-style license that can be
 // found in the LICENSE file.
 
 #include "cc/scheduler/scheduler.h"
 
 #include <algorithm>
 #include "base/auto_reset.h"
 #include "base/debug/trace_event.h"
 #include "base/debug/trace_event_argument.h"
 #include "base/logging.h"
 #include "base/single_thread_task_runner.h"
 #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);
 }
 
 Scheduler::SyntheticBeginFrameSource::~SyntheticBeginFrameSource() {
 }
 
 void Scheduler::SyntheticBeginFrameSource::CommitVSyncParameters(
     base::TimeTicks timebase,
     base::TimeDelta interval) {
   time_source_->SetTimebaseAndInterval(timebase, interval);
@@ skipping 78 matching lines @@
 }
 
 Scheduler::~Scheduler() {
   if (synthetic_begin_frame_source_) {
     synthetic_begin_frame_source_->SetNeedsBeginFrame(false,
                                                       &begin_retro_frame_args_);
   }
 }
 
 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,
                                       base::TimeDelta interval) {
   // TODO(brianderson): We should not be receiving 0 intervals.
   if (interval == base::TimeDelta())
     interval = BeginFrameArgs::DefaultInterval();
   vsync_interval_ = interval;
   if (!settings_.begin_frame_scheduling_enabled)
     synthetic_begin_frame_source_->CommitVSyncParameters(timebase, interval);
@@ skipping 113 matching lines @@
 void Scheduler::NotifyBeginMainFrameStarted() {
   TRACE_EVENT0("cc", "Scheduler::NotifyBeginMainFrameStarted");
   state_machine_.NotifyBeginMainFrameStarted();
 }
 
 base::TimeTicks Scheduler::AnticipatedDrawTime() const {
   if (!last_set_needs_begin_frame_ ||
       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);
   return timebase + (begin_impl_frame_args_.interval * intervals);
 }
 
 base::TimeTicks Scheduler::LastBeginImplFrameTime() {
   return begin_impl_frame_args_.frame_time;
 }
 
@@ skipping 54 matching lines @@
   begin_unthrottled_frame_posted_ = true;
   impl_task_runner_->PostTask(FROM_HERE, begin_unthrottled_frame_closure_);
 }
 
 // BeginUnthrottledFrame is used when we aren't throttling frame production.
 // This will usually be because VSync is disabled.
 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 =
       BeginFrameArgs::Create(now, deadline, vsync_interval_);
   BeginImplFrame(begin_frame_args);
 
   begin_unthrottled_frame_posted_ = false;
 }
 
 // We may need to poll when we can't rely on BeginFrame to advance certain
@@ skipping 90 matching lines @@
   if (begin_retro_frame_args_.empty())
     return;
 
   // Discard expired BeginRetroFrames
   // Today, we should always end up with at most one un-expired BeginRetroFrame
   // because deadlines will not be greater than the next frame time. We don't
   // DCHECK though because some systems don't always have monotonic timestamps.
   // 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(),
                                               draw_duration_estimate)) {
     TRACE_EVENT1("cc",
                  "Scheduler::BeginRetroFrame discarding",
                  "frame_time",
                  begin_retro_frame_args_.front().frame_time);
     begin_retro_frame_args_.pop_front();
   }
 
   if (begin_retro_frame_args_.empty()) {
     DCHECK(settings_.throttle_frame_production);
     TRACE_EVENT_INSTANT0("cc",
                          "Scheduler::BeginRetroFrames all expired",
                          TRACE_EVENT_SCOPE_THREAD);
   } else {
     BeginImplFrame(begin_retro_frame_args_.front());
     begin_retro_frame_args_.pop_front();
   }
 }
 
 // There could be a race between the posted BeginRetroFrame and a new
 // BeginFrame arriving via the normal mechanism. Scheduler::BeginFrame
 // 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;
 
   if (begin_retro_frame_args_.empty() || begin_retro_frame_posted_)
     return;
 
   // begin_retro_frame_args_ should always be empty for the
   // synchronous compositor.
   DCHECK(!settings_.using_synchronous_renderer_compositor);
 
@@ skipping 56 matching lines @@
     // expected BeginImplFrame start. This allows us to draw immediately when
     // there is a new active tree, instead of waiting for the next
     // BeginImplFrame.
     // TODO(brianderson): Handle long deadlines (that are past the next frame's
     // frame time) properly instead of using this hack.
     return args.frame_time + args.interval;
   }
 }
 
 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.
     // TODO(brianderson): Have the OutputSurface initiate the deadline tasks
     // so the sychronous renderer compositor can take advantage of splitting
     // up the BeginImplFrame and deadline as well.
     OnBeginImplFrameDeadline();
     return;
   }
   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(
       FROM_HERE, begin_impl_frame_deadline_task_.callback(), delta);
 }
 
 void Scheduler::OnBeginImplFrameDeadline() {
   TRACE_EVENT0("cc", "Scheduler::OnBeginImplFrameDeadline");
   begin_impl_frame_deadline_task_.Cancel();
 
@@ skipping 111 matching lines @@
   state->BeginDictionary("state_machine");
   state_machine_.AsValueInto(state);
   state->EndDictionary();
   if (synthetic_begin_frame_source_) {
     state->BeginDictionary("synthetic_begin_frame_source_");
     synthetic_begin_frame_source_->AsValueInto(state);
     state->EndDictionary();
   }
 
   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());
   state->SetBoolean("last_set_needs_begin_frame_", last_set_needs_begin_frame_);
   state->SetBoolean("begin_unthrottled_frame_posted_",
                     begin_unthrottled_frame_posted_);
   state->SetBoolean("begin_retro_frame_posted_", begin_retro_frame_posted_);
   state->SetInteger("begin_retro_frame_args_", begin_retro_frame_args_.size());
   state->SetBoolean("begin_impl_frame_deadline_task_",
                     !begin_impl_frame_deadline_task_.IsCancelled());
@@ skipping 40 matching lines @@
 }
 
 bool Scheduler::IsBeginMainFrameSentOrStarted() const {
   return (state_machine_.commit_state() ==
               SchedulerStateMachine::COMMIT_STATE_BEGIN_MAIN_FRAME_SENT ||
           state_machine_.commit_state() ==
               SchedulerStateMachine::COMMIT_STATE_BEGIN_MAIN_FRAME_STARTED);
 }
 
 }  // namespace cc