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/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"
 
 namespace scheduler {
 namespace {
 // The run time of loading tasks is strongly bimodal.  The vast majority are
 // very cheap, but there are usually a handful of very expensive tasks (e.g ~1
-// second on a mobile device) so we take a very pesimistic view when estimating
+// second on a mobile device) so we take a very pessimistic view when estimating
 // the cost of loading tasks.
 const int kLoadingTaskEstimationSampleCount = 1000;
 const double kLoadingTaskEstimationPercentile = 99;
 const int kTimerTaskEstimationSampleCount = 1000;
 const double kTimerTaskEstimationPercentile = 99;
 const int kShortIdlePeriodDurationSampleCount = 10;
 const double kShortIdlePeriodDurationPercentile = 50;
 // Amount of idle time left in a frame (as a ratio of the vsync interval) above
 // which main thread compositing can be considered fast.
 const double kFastCompositingIdleTimeThreshold = .2;
 }  // namespace
 
 RendererSchedulerImpl::RendererSchedulerImpl(
     scoped_refptr<SchedulerTqmDelegate> main_task_runner)
     : helper_(main_task_runner,
               "renderer.scheduler",
               TRACE_DISABLED_BY_DEFAULT("renderer.scheduler"),
               TRACE_DISABLED_BY_DEFAULT("renderer.scheduler.debug")),
       idle_helper_(&helper_,
                    this,
                    "renderer.scheduler",
                    TRACE_DISABLED_BY_DEFAULT("renderer.scheduler"),
                    "RendererSchedulerIdlePeriod",
                    base::TimeDelta()),
+      task_time_tracker_(this),
       render_widget_scheduler_signals_(this),
       control_task_runner_(helper_.ControlTaskRunner()),
-      compositor_task_runner_(
-          helper_.NewTaskQueue(TaskQueue::Spec("compositor_tq")
-                                   .SetShouldMonitorQuiescence(true))),
+      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()),
       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);
+  helper_.SetTaskTimeTracker(&task_time_tracker_);
 }
 
 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);
   }
 
   // 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),
+      queueing_time_estimator(renderer_scheduler_impl,
+                              base::TimeDelta::FromSeconds(1)),
       idle_time_estimator(compositor_task_runner,
                           time_source,
                           kShortIdlePeriodDurationSampleCount,
                           kShortIdlePeriodDurationPercentile),
       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),
@@ skipping 1254 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::ReportTaskTime(base::TimeTicks start_time,
+                                           base::TimeTicks end_time) {
+  MainThreadOnly().queueing_time_estimator.OnToplevelTaskCompleted(start_time,
+                                                                   end_time);
+}
+
+void RendererSchedulerImpl::OnQueueingTimeForWindowEstimated(
+    base::TimeDelta queueing_time) {
+  UMA_HISTOGRAM_TIMES("RendererScheduler.ExpectedTaskQueueingDuration",
+                      queueing_time);
+  TRACE_COUNTER1(TRACE_DISABLED_BY_DEFAULT("renderer.scheduler"),
+                 "estimated_queueing_time_for_window",
+                 queueing_time.InMillisecondsF());
+}
+
 // static
 const char* RendererSchedulerImpl::UseCaseToString(UseCase use_case) {
   switch (use_case) {
     case UseCase::NONE:
       return "none";
     case UseCase::COMPOSITOR_GESTURE:
       return "compositor_gesture";
     case UseCase::MAIN_THREAD_CUSTOM_INPUT_HANDLING:
       return "main_thread_custom_input_handling";
     case UseCase::SYNCHRONIZED_GESTURE:
@@ skipping 21 matching lines @@
       return "idle";
     case v8::PERFORMANCE_LOAD:
       return "load";
     default:
       NOTREACHED();
       return nullptr;
   }
 }
 
 }  // namespace scheduler