Mozart: Reduce pipeline depth and unify frame queue.

services/gfx/compositor/backend/gpu_output.cc

 // Copyright 2015 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 "services/gfx/compositor/backend/gpu_output.h"
 
 #include <utility>
 
 #include "base/bind.h"
 #include "base/command_line.h"
 #include "base/location.h"
 #include "base/logging.h"
 #include "base/message_loop/message_loop.h"
 #include "base/strings/string_number_conversions.h"
 #include "base/trace_event/trace_event.h"
 #include "services/gfx/compositor/render/render_frame.h"
 
 namespace compositor {
 namespace {
 constexpr const char* kPipelineDepthSwitch = "pipeline-depth";
-constexpr uint32_t kDefaultPipelineDepth = 2u;  // ideally should be 1
+constexpr uint32_t kDefaultPipelineDepth = 1u;
 constexpr uint32_t kMinPipelineDepth = 1u;
-constexpr uint32_t kMaxPipelineDepth = 10u;
+constexpr uint32_t kMaxPipelineDepth = 10u;  // for experimentation
 
 scoped_ptr<base::MessagePump> CreateMessagePumpMojo() {
   return base::MessageLoop::CreateMessagePumpForType(
       base::MessageLoop::TYPE_DEFAULT);
 }
 }  // namespace
 
 GpuOutput::GpuOutput(
     mojo::InterfaceHandle<mojo::ContextProvider> context_provider,
     const SchedulerCallbacks& scheduler_callbacks,
@@ skipping 45 matching lines @@
 
 Scheduler* GpuOutput::GetScheduler() {
   return vsync_scheduler_.get();
 }
 
 void GpuOutput::SubmitFrame(const scoped_refptr<RenderFrame>& frame) {
   DCHECK(frame);
   TRACE_EVENT0("gfx", "GpuOutput::SubmitFrame");
 
   const int64_t submit_time = MojoGetTimeTicksNow();
-  scoped_refptr<FrameData> frame_data(
+  std::unique_ptr<FrameData> frame_data(
       new FrameData(frame, submit_time));  // drop outside lock
   {
     std::lock_guard<std::mutex> lock(shared_state_.mutex);
 
-    TRACE_EVENT_FLOW_BEGIN0("gfx", "Frame Queued", frame_data.get());
-    shared_state_.current_frame_data.swap(frame_data);
-    if (frame_data && !frame_data->drawn) {
-      // Dropped an undrawn frame.
-      DVLOG(2) << "Rasterizer stalled, dropping frame to catch up.";
+    // Enqueue the frame, ensuring that the queue only contains at most
+    // one undrawn frame.  If the last frame hasn't been drawn by now then
+    // the rasterizer must be falling behind.
+    if (!shared_state_.frames.empty() && shared_state_.frames.front()->finished)

[mikejurka, 2016/05/25 21:11:46]

if you introduce a pinned_for_draw variable, i would do a DCHECK here to make
sure its false.

[jeffbrown, 2016/05/25 23:45:43]

Maybe add a DCHECK here that the queue size is exactly 1.

+      shared_state_.frames.pop();

[mikejurka, 2016/05/25 21:11:46]

should we have a DCHECK after this pop that the front() frame is not finished?

ie 

// Make sure all finished frames have been removed
DCHECK(shared_state_.frames.empty() || !shared_state_.frames.front()->finished)

[mikejurka, 2016/05/25 23:54:06]

actually, on second thought, shouldn't the above "if" clause be completely
unnecessary? doesn't OnRasterizerFinishedDraw set "finished" to true and then
remove from the queue in one swoop?

+    if (shared_state_.frames.empty() || shared_state_.frames.back()->drawn) {
+      shared_state_.frames.emplace(std::move(frame_data));
+    } else {

[jeffbrown, 2016/05/25 23:45:43]

Add a comment here explaining why it's safe to replace the last frame.

+      shared_state_.frames.back().swap(frame_data);

[mikejurka, 2016/05/25 21:11:46]

if you introduce a pinned_for_draw variable, i would do a DCHECK here to make
sure its false.


ie

 DCHECK(!shared_state_.frames.back().pinned_for_draw)

       TRACE_EVENT_FLOW_END1("gfx", "Frame Queued", frame_data.get(), "drawn",
                             false);
+      DVLOG(2) << "Rasterizer stalled, dropped a frame to catch up.";
     }
 
-    // TODO(jeffbrown): If the draw queue is full, we should pause
+    TRACE_EVENT_FLOW_BEGIN0("gfx", "Frame Queued",
+                            shared_state_.frames.back().get());
+
+    if (!shared_state_.rasterizer_ready)
+      return;
+
+    // TODO(jeffbrown): If the draw queue is overfull, we should pause
     // scheduling until the queue drains.
-    if (shared_state_.rasterizer_ready &&
-        shared_state_.drawn_frames_awaiting_finish.size() < pipeline_depth_)
+    if (shared_state_.frames.size() <= pipeline_depth_)
       ScheduleDrawLocked();

[mikejurka, 2016/05/25 21:11:46]

might be useful to track another time here ie draw_scheduled_time

[jeffbrown, 2016/05/25 23:45:43]

I'm going to leave this out.  The other two timestamps are useful for estimating
overall CPU and GPU latency on their own whereas specifically observing
scheduling latency is something we could accomplish through tracing.

   }
 }
 
 void GpuOutput::OnRasterizerReady(int64_t vsync_timebase,
                                   int64_t vsync_interval) {
   DCHECK(rasterizer_task_runner_->RunsTasksOnCurrentThread());
 
   // TODO(jeffbrown): This shouldn't be hardcoded.
   // Need to do some real tuning and possibly determine values adaptively.
   // We should probably split the Start() method in two to separate the
   // process of setting parameters from starting / stopping scheduling.
   const int64_t update_phase = -vsync_interval;
   const int64_t snapshot_phase = -vsync_interval / 6;
   // TODO(jeffbrown): Determine the presentation phase based on queue depth.
   const int64_t presentation_phase = vsync_interval * pipeline_depth_;
   if (!vsync_scheduler_->Start(vsync_timebase, vsync_interval, update_phase,
                                snapshot_phase, presentation_phase)) {
     LOG(ERROR) << "Received invalid vsync parameters: timebase="
                << vsync_timebase << ", interval=" << vsync_interval;
     PostErrorCallback();
     return;
   }
 
   {
     std::lock_guard<std::mutex> lock(shared_state_.mutex);
 
     if (shared_state_.rasterizer_ready)
       return;
 
-    DCHECK(shared_state_.drawn_frames_awaiting_finish.empty());
     shared_state_.rasterizer_ready = true;
 
-    if (!shared_state_.current_frame_data)
+    if (shared_state_.frames.empty())
       return;
 
-    shared_state_.current_frame_data->Recycle();
+    shared_state_.frames.back()->ClearDrawState();
     TRACE_EVENT_FLOW_BEGIN0("gfx", "Frame Queued",
-                            shared_state_.current_frame_data.get());
+                            shared_state_.frames.back().get());
     ScheduleDrawLocked();
   }
 }
 
 void GpuOutput::OnRasterizerSuspended() {
   DCHECK(rasterizer_task_runner_->RunsTasksOnCurrentThread());
 
   vsync_scheduler_->Stop();
 
   {
     std::lock_guard<std::mutex> lock(shared_state_.mutex);
 
     if (!shared_state_.rasterizer_ready)
       return;
 
     shared_state_.rasterizer_ready = false;
   }
 }
 
 void GpuOutput::OnRasterizerError() {
   DCHECK(rasterizer_task_runner_->RunsTasksOnCurrentThread());
 
   PostErrorCallback();
 }
 
 void GpuOutput::ScheduleDrawLocked() {
-  DCHECK(shared_state_.current_frame_data);
-  DCHECK(!shared_state_.current_frame_data->drawn);
+  DCHECK(!shared_state_.frames.empty());
+  DCHECK(!shared_state_.frames.back()->drawn);
+  DCHECK(shared_state_.frames.size() <= pipeline_depth_);
 
   if (shared_state_.draw_scheduled)
     return;
 
   shared_state_.draw_scheduled = true;
   rasterizer_task_runner_->PostTask(
       FROM_HERE, base::Bind(&GpuOutput::OnDraw, base::Unretained(this)));
 }
 
 void GpuOutput::OnDraw() {
   DCHECK(rasterizer_task_runner_->RunsTasksOnCurrentThread());
   TRACE_EVENT0("gfx", "GpuOutput::OnDraw");
 
-  scoped_refptr<FrameData> frame_data;  // used outside lock
+  FrameData* frame_data;

[mikejurka, 2016/05/25 21:11:46]

probably a good idea to initialize to null (just for a safeguard for future code
changes)

[jeffbrown, 2016/05/25 23:45:43]

The compiler will yell at me if I try to use an uninitialized variable so I find
it better leaving it that way rather than making the reader wonder whether a
null can ever happen.

   {
     std::lock_guard<std::mutex> lock(shared_state_.mutex);
 
     DCHECK(shared_state_.draw_scheduled);
-    DCHECK(shared_state_.current_frame_data);
-    DCHECK(!shared_state_.current_frame_data->drawn);
+    DCHECK(!shared_state_.frames.empty());
+    DCHECK(!shared_state_.frames.back()->drawn);
 
     shared_state_.draw_scheduled = false;
-
-    if (!shared_state_.rasterizer_ready ||
-        shared_state_.drawn_frames_awaiting_finish.size() >= pipeline_depth_)
+    if (!shared_state_.rasterizer_ready)
       return;
 
-    frame_data = shared_state_.current_frame_data;
+    frame_data = shared_state_.frames.back().get();

[mikejurka, 2016/05/25 21:11:46]

maybe move DCHECK(!frame_data->drawn) to here instead.

[jeffbrown, 2016/05/25 23:45:43]

I'd rather leave it where it is since the invariant must hold true independent
of whether the rasterizer is ready.

     frame_data->drawn = true;
     frame_data->draw_time = MojoGetTimeTicksNow();
-    TRACE_EVENT_FLOW_END1("gfx", "Frame Queued", frame_data.get(), "drawn",
-                          true);
-
-    TRACE_EVENT_ASYNC_BEGIN0("gfx", "Rasterize", frame_data.get());
-    shared_state_.drawn_frames_awaiting_finish.emplace(frame_data);
+    TRACE_EVENT_FLOW_END1("gfx", "Frame Queued", frame_data, "drawn", true);
   }
 

[mikejurka, 2016/05/25 21:11:46]

Do a DCHECK to ensure frame_data is not null here (just for a safeguard for
future code changes)

[jeffbrown, 2016/05/25 23:45:43]

I don't think that's really necessary.  It must obviously be non-null since we
dereferenced it.

+  // It is safe to access |frame_data| outside of the lock here because
+  // it will not be dequeued until |OnRasterizerFinishedDraw| gets posted
+  // to this thread's message loop.  Moreover |SubmitFrame| will not replace
+  // the frame because the |drawn| flag has been set.

[mikejurka, 2016/05/25 21:11:46]

I would put a note in the header file next to the drawn flag that you can never
remove or swap an item where (drawn && !isFinished) is true.

actually, i would consider making another variable called "pinned_for_draw" that
is true during this critical section (ie after "drawn" is set but before
"isFinished" is set"), and check for that in the other methods. and sprinkle
DCHECKs to make sure you are never popping or swapping an item with
"pinned_for_draw" set to true.

[jeffbrown, 2016/05/25 23:45:43]

I don't actually need extra state here.  I could add an inline function but I
think the indirection may make the code even harder to understand.  Note that
this invariant follows from the comments already in the header file.

+  TRACE_EVENT_ASYNC_BEGIN0("gfx", "Rasterize", frame_data);
   rasterizer_->DrawFrame(frame_data->frame);
   frame_data->wait_time = MojoGetTimeTicksNow();
 }
 
 void GpuOutput::OnRasterizerFinishedDraw(bool presented) {
   DCHECK(rasterizer_task_runner_->RunsTasksOnCurrentThread());
   TRACE_EVENT0("gfx", "GpuOutput::OnRasterizerFinishedDraw");
 
   const int64_t finish_time = MojoGetTimeTicksNow();
-  scoped_refptr<FrameData> frame_data;  // drop outside lock
+  std::unique_ptr<FrameData> old_frame_data;  // drop outside lock

[mikejurka, 2016/05/25 21:11:46]

change comment for "drop outside lock" to "keep old frame data alive until after
locked section"

[jeffbrown, 2016/05/25 23:45:43]

Done.

   {
     std::lock_guard<std::mutex> lock(shared_state_.mutex);
 
     DCHECK(shared_state_.rasterizer_ready);
-    DCHECK(!shared_state_.drawn_frames_awaiting_finish.empty());
-    size_t draw_queue_depth = shared_state_.drawn_frames_awaiting_finish.size();
-    shared_state_.drawn_frames_awaiting_finish.front().swap(frame_data);
-    shared_state_.drawn_frames_awaiting_finish.pop();
+    DCHECK(!shared_state_.frames.empty());
+
+    FrameData* frame_data = shared_state_.frames.front().get();
     DCHECK(frame_data);
     DCHECK(frame_data->drawn);
-    TRACE_EVENT_ASYNC_END1("gfx", "Rasterize", frame_data.get(), "presented",
+    TRACE_EVENT_ASYNC_END1("gfx", "Rasterize", frame_data, "presented",
                            presented);
+    frame_data->finished = true;

[mikejurka, 2016/05/25 21:11:46]

if you decide to use a "pinned_for_draw" var, i guess you'd set it to false here
as well.

 
     // TODO(jeffbrown): Adjust scheduler behavior based on observed timing.
     // Note: These measurements don't account for systematic downstream delay
     // in the display pipeline (how long it takes pixels to actually light up).
     if (presented) {
       const RenderFrame::Metadata& frame_metadata =
           frame_data->frame->metadata();
       const mojo::gfx::composition::FrameInfo& frame_info =
           frame_metadata.frame_info();
       const int64_t frame_time = frame_info.frame_time;
       const int64_t presentation_time = frame_info.presentation_time;
       const int64_t composition_time = frame_metadata.composition_time();
       const int64_t draw_time = frame_data->draw_time;
       const int64_t wait_time = frame_data->wait_time;
       const int64_t submit_time = frame_data->submit_time;
+      const size_t draw_queue_depth = shared_state_.frames.size();
 
       DVLOG(2) << "Presented frame: composition latency "
                << (composition_time - frame_time) << " us, submission latency "
                << (submit_time - composition_time) << " us, queue latency "
                << (draw_time - submit_time) << " us, draw latency "
                << (wait_time - draw_time) << " us, GPU latency "
                << (finish_time - wait_time) << " us, total latency "
                << (finish_time - frame_time) << " us, presentation time error "
                << (finish_time - presentation_time) << " us"
                << ", draw queue depth " << draw_queue_depth;
     } else {
       DVLOG(2) << "Rasterizer dropped frame.";
     }
 
-    DCHECK(shared_state_.current_frame_data);
-    if (!shared_state_.current_frame_data->drawn)
-      ScheduleDrawLocked();
+    if (shared_state_.frames.size() > 1u) {
+      shared_state_.frames.front().swap(old_frame_data);

[mikejurka, 2016/05/25 21:11:46]

I would add the earlier comment here again to clarify ie

"// keep old frame data alive until after locked section"

[jeffbrown, 2016/05/25 23:45:43]

Done.

+      shared_state_.frames.pop();
+      if (!shared_state_.frames.back()->drawn)
+        ScheduleDrawLocked();
+    }
   }
 }
 
 void GpuOutput::InitializeRasterizer(
     mojo::InterfaceHandle<mojo::ContextProvider> context_provider) {
   DCHECK(rasterizer_task_runner_->RunsTasksOnCurrentThread());
   DCHECK(!rasterizer_);
   TRACE_EVENT0("gfx", "GpuOutput::InitializeRasterizer");
 
   rasterizer_.reset(new GpuRasterizer(
@@ skipping 13 matching lines @@
 void GpuOutput::PostErrorCallback() {
   compositor_task_runner_->PostTask(FROM_HERE, error_callback_);
 }
 
 GpuOutput::FrameData::FrameData(const scoped_refptr<RenderFrame>& frame,
                                 int64_t submit_time)
     : frame(frame), submit_time(submit_time) {}
 
 GpuOutput::FrameData::~FrameData() {}
 
-void GpuOutput::FrameData::Recycle() {
+void GpuOutput::FrameData::ClearDrawState() {
   drawn = false;
+  finished = false;
   draw_time = 0;
   wait_time = 0;
 }
 
 }  // namespace compositor