Report expected task queueing time via UMA

components/scheduler/renderer/renderer_scheduler_impl.cc

 // Copyright 2014 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 "components/scheduler/renderer/renderer_scheduler_impl.h"
 
 #include "base/bind.h"
 #include "base/debug/stack_trace.h"
 #include "base/logging.h"
 #include "base/memory/ptr_util.h"
+#include "base/message_loop/message_loop.h"
+#include "base/metrics/histogram_macros.h"
 #include "base/trace_event/trace_event.h"
 #include "base/trace_event/trace_event_argument.h"
 #include "cc/output/begin_frame_args.h"
 #include "components/scheduler/base/task_queue_impl.h"
 #include "components/scheduler/base/task_queue_selector.h"
 #include "components/scheduler/base/virtual_time_domain.h"
 #include "components/scheduler/child/scheduler_tqm_delegate.h"
 #include "components/scheduler/renderer/web_view_scheduler_impl.h"
 #include "components/scheduler/renderer/webthread_impl_for_renderer_scheduler.h"
 
@@ skipping 28 matching lines @@
                    base::TimeDelta()),
       render_widget_scheduler_signals_(this),
       control_task_runner_(helper_.ControlTaskRunner()),
       compositor_task_runner_(
           helper_.NewTaskQueue(TaskQueue::Spec("compositor_tq")
                                    .SetShouldMonitorQuiescence(true))),
       delayed_update_policy_runner_(
           base::Bind(&RendererSchedulerImpl::UpdatePolicy,
                      base::Unretained(this)),
           helper_.ControlTaskRunner()),
-      main_thread_only_(compositor_task_runner_,
+      main_thread_only_(this,
+                        compositor_task_runner_,
                         helper_.scheduler_tqm_delegate().get()),
+      coarse_duration_timer_observing_(false),
       policy_may_need_update_(&any_thread_lock_),
       weak_factory_(this) {
   throttling_helper_.reset(new ThrottlingHelper(this, "renderer.scheduler"));
   update_policy_closure_ = base::Bind(&RendererSchedulerImpl::UpdatePolicy,
                                       weak_factory_.GetWeakPtr());
   end_renderer_hidden_idle_period_closure_.Reset(base::Bind(
       &RendererSchedulerImpl::EndIdlePeriod, weak_factory_.GetWeakPtr()));
 
   suspend_timers_when_backgrounded_closure_.Reset(
       base::Bind(&RendererSchedulerImpl::SuspendTimerQueueWhenBackgrounded,
                  weak_factory_.GetWeakPtr()));
 
   default_loading_task_runner_ = NewLoadingTaskRunner("default_loading_tq");
   default_timer_task_runner_ = NewTimerTaskRunner("default_timer_tq");
 
   TRACE_EVENT_OBJECT_CREATED_WITH_ID(
       TRACE_DISABLED_BY_DEFAULT("renderer.scheduler"), "RendererScheduler",
       this);
 
   helper_.SetObserver(this);
+  AddTaskObserver(&MainThreadOnly().queueing_time_estimator);
 }
 
 RendererSchedulerImpl::~RendererSchedulerImpl() {
   TRACE_EVENT_OBJECT_DELETED_WITH_ID(
       TRACE_DISABLED_BY_DEFAULT("renderer.scheduler"), "RendererScheduler",
       this);
 
   for (const scoped_refptr<TaskQueue>& loading_queue : loading_task_runners_) {
     loading_queue->RemoveTaskObserver(
         &MainThreadOnly().loading_task_cost_estimator);
   }
   for (const scoped_refptr<TaskQueue>& timer_queue : timer_task_runners_) {
     timer_queue->RemoveTaskObserver(
         &MainThreadOnly().timer_task_cost_estimator);
   }
+  RemoveTaskObserver(&MainThreadOnly().queueing_time_estimator);
 
   // Ensure the renderer scheduler was shut down explicitly, because otherwise
   // we could end up having stale pointers to the Blink heap which has been
   // terminated by this point.
   DCHECK(MainThreadOnly().was_shutdown);
 }
 
 RendererSchedulerImpl::MainThreadOnly::MainThreadOnly(
+    RendererSchedulerImpl* renderer_scheduler_impl,
     const scoped_refptr<TaskQueue>& compositor_task_runner,
     base::TickClock* time_source)
     : loading_task_cost_estimator(time_source,
                                   kLoadingTaskEstimationSampleCount,
                                   kLoadingTaskEstimationPercentile),
       timer_task_cost_estimator(time_source,
                                 kTimerTaskEstimationSampleCount,
                                 kTimerTaskEstimationPercentile),
       idle_time_estimator(compositor_task_runner,
                           time_source,
                           kShortIdlePeriodDurationSampleCount,
                           kShortIdlePeriodDurationPercentile),
+      queueing_time_estimator(renderer_scheduler_impl,
+                              renderer_scheduler_impl->coarse_duration_timer(),
+                              base::TimeDelta::FromSeconds(5)),
       current_use_case(UseCase::NONE),
       timer_queue_suspend_count(0),
       navigation_task_expected_count(0),
       expensive_task_policy(ExpensiveTaskPolicy::RUN),
       renderer_hidden(false),
       renderer_backgrounded(false),
       timer_queue_suspension_when_backgrounded_enabled(false),
       timer_queue_suspended_when_backgrounded(false),
       was_shutdown(false),
       loading_tasks_seem_expensive(false),
@@ skipping 311 matching lines @@
   if (blink::WebInputEvent::isMouseEventType(web_input_event.type) ||
       blink::WebInputEvent::isKeyboardEventType(web_input_event.type)) {
     return false;
   }
   return true;
 }
 
 void RendererSchedulerImpl::DidHandleInputEventOnCompositorThread(
     const blink::WebInputEvent& web_input_event,
     InputEventState event_state) {
+
+  // TODO - move this.
+  if (coarse_duration_timer_observing_ == false) {
+    coarse_duration_timer_observing_ = true;
+    base::MessageLoop::current()->AddRecentTimeObserver(
+        &coarse_duration_timer_);
+  }

[tdresser, 2016/05/30 19:07:46]

^

+
   TRACE_EVENT0(TRACE_DISABLED_BY_DEFAULT("renderer.scheduler"),
                "RendererSchedulerImpl::DidHandleInputEventOnCompositorThread");
   if (!ShouldPrioritizeInputEvent(web_input_event))
     return;
 
   UpdateForInputEventOnCompositorThread(web_input_event.type, event_state);
 }
 
 void RendererSchedulerImpl::DidAnimateForInputOnCompositorThread() {
   TRACE_EVENT0(TRACE_DISABLED_BY_DEFAULT("renderer.scheduler"),
@@ skipping 866 matching lines @@
         true;
     BroadcastConsoleWarning(
         "Blink deferred a task in order to make scrolling smoother. "
         "Your timer and network tasks should take less than 50ms to run "
         "to avoid this. Please see "
         "https://developers.google.com/web/tools/chrome-devtools/profile/evaluate-performance/rail"
         " and https://crbug.com/574343#c40 for more information.");
   }
 }
 
+void RendererSchedulerImpl::OnQueueingTimeForWindowEstimated(
+    base::TimeDelta queueing_time) {
+  // TODO - UMA_HISTOGRAM_TIMES is probably wrong.
+  UMA_HISTOGRAM_TIMES("RendererScheduler.ExpectedTaskQueueingDuration",
+                      queueing_time);
+  TRACE_COUNTER1(TRACE_DISABLED_BY_DEFAULT("renderer.scheduler"),
+                 "estimated_queueing_time_for_window",
+                 queueing_time.InMillisecondsF());
+}
+
 }  // namespace scheduler