Report expected task queueing time via UMA

components/scheduler/renderer/renderer_scheduler_impl.cc

Index: components/scheduler/renderer/renderer_scheduler_impl.cc
diff --git a/components/scheduler/renderer/renderer_scheduler_impl.cc b/components/scheduler/renderer/renderer_scheduler_impl.cc
index 9f3d9b6ef21a16711e52ff193531d3459aed5064..a584cfa2b499f858d4f5f90c3d320e32502697c0 100644
--- a/components/scheduler/renderer/renderer_scheduler_impl.cc
+++ b/components/scheduler/renderer/renderer_scheduler_impl.cc
@@ -7,6 +7,7 @@
 #include "base/bind.h"
 #include "base/debug/stack_trace.h"
 #include "base/logging.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"
@@ -45,14 +46,14 @@ RendererSchedulerImpl::RendererSchedulerImpl(
                    base::TimeDelta()),
       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) {
@@ -74,6 +75,7 @@ RendererSchedulerImpl::RendererSchedulerImpl(
       this);
 
   helper_.SetObserver(this);
+  AddTaskObserver(&MainThreadOnly().queueing_time_estimator);
 }
 
 RendererSchedulerImpl::~RendererSchedulerImpl() {
@@ -89,6 +91,7 @@ RendererSchedulerImpl::~RendererSchedulerImpl() {
     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
@@ -97,6 +100,7 @@ RendererSchedulerImpl::~RendererSchedulerImpl() {
 }
 
 RendererSchedulerImpl::MainThreadOnly::MainThreadOnly(
+    RendererSchedulerImpl* renderer_scheduler_impl,
     const scoped_refptr<TaskQueue>& compositor_task_runner,
     base::TickClock* time_source)
     : loading_task_cost_estimator(time_source,
@@ -109,6 +113,9 @@ RendererSchedulerImpl::MainThreadOnly::MainThreadOnly(
                           time_source,
                           kShortIdlePeriodDurationSampleCount,
                           kShortIdlePeriodDurationPercentile),
+      queueing_time_estimator(renderer_scheduler_impl,
+                              time_source,
+                              base::TimeDelta::FromSeconds(5)),
       current_use_case(UseCase::NONE),
       timer_queue_suspend_count(0),
       navigation_task_expected_count(0),
@@ -1250,4 +1257,13 @@ void RendererSchedulerImpl::OnTriedToExecuteBlockedTask(
   }
 }
 
+void RendererSchedulerImpl::OnQueueingTimeForWindowEstimated(
+    base::TimeDelta queueing_time) {
+  UMA_HISTOGRAM_TIMES("RendererScheduler.ExpectedTaskQueueingDuration",
+                      queueing_time);
+  TRACE_COUNTER1(TRACE_DISABLED_BY_DEFAULT("renderer.scheduler"),

[tdresser, 2016/04/20 15:13:33]

Is this correct? Where in the trace should I see this?

[Sami, 2016/04/21 10:04:01]

Looks good to me. You should see it as one of the counter tracks above the
renderer main thread thread slices. I think the counters show up in random order
every time you load a trace so you might have to scan everything to find it.
Make sure you also enable the disabled-by-default renderer.scheduler category.

One minor drawback is that the counter values won't show up where the window is
on the time axis if the tasks are much longer than a window (should be rare).

[tdresser, 2016/04/21 12:37:28]

Ah, thanks I was thinking it was on the same track as the snapshots, which it
wasn't.

It's working fine.

+                 "estimated_queueing_time_for_window",
+                 queueing_time.InMillisecondsF());
+}
+
 }  // namespace scheduler