Report expected task queueing time via UMA

components/scheduler/base/task_queue_manager.cc

Index: components/scheduler/base/task_queue_manager.cc
diff --git a/components/scheduler/base/task_queue_manager.cc b/components/scheduler/base/task_queue_manager.cc
index 36f08de540fe8529ab593f6248504b0d23561795..b67667fe039e5de5db1fedb9914eb6c299ba224b 100644
--- a/components/scheduler/base/task_queue_manager.cc
+++ b/components/scheduler/base/task_queue_manager.cc
@@ -14,6 +14,7 @@
 #include "components/scheduler/base/task_queue_impl.h"
 #include "components/scheduler/base/task_queue_manager_delegate.h"
 #include "components/scheduler/base/task_queue_selector.h"
+#include "components/scheduler/base/task_time_tracker.h"
 #include "components/scheduler/base/work_queue.h"
 #include "components/scheduler/base/work_queue_sets.h"
 
@@ -38,12 +39,15 @@ TaskQueueManager::TaskQueueManager(
     scoped_refptr<TaskQueueManagerDelegate> delegate,
     const char* tracing_category,
     const char* disabled_by_default_tracing_category,
-    const char* disabled_by_default_verbose_tracing_category)
+    const char* disabled_by_default_verbose_tracing_category,
+    TaskTimeTracker* task_time_tracker)
     : real_time_domain_(new RealTimeDomain(tracing_category)),
       delegate_(delegate),
       task_was_run_on_quiescence_monitored_queue_(false),
       work_batch_size_(1),
       task_count_(0),
+      task_time_tracker_(task_time_tracker),
+      do_work_depth_(0),
       tracing_category_(tracing_category),
       disabled_by_default_tracing_category_(
           disabled_by_default_tracing_category),
@@ -174,6 +178,7 @@ void TaskQueueManager::MaybeScheduleDelayedWork(
 }
 
 void TaskQueueManager::DoWork(base::TimeTicks run_time, bool from_main_thread) {
+  do_work_depth_++;

[Sami, 2016/07/05 14:40:38]

Could we use a base::AutoReset for this? (might not work in the case where the
TQM is deleted by a task.)

[tdresser, 2016/07/05 15:52:20]

Alex pointed out this isn't needed.

   DCHECK(main_thread_checker_.CalledOnValidThread());
   TRACE_EVENT1(tracing_category_, "TaskQueueManager::DoWork",
                "from_main_thread", from_main_thread);
@@ -192,6 +197,10 @@ void TaskQueueManager::DoWork(base::TimeTicks run_time, bool from_main_thread) {
   UpdateWorkQueues(false, nullptr);
 
   internal::TaskQueueImpl::Task previous_task;
+  base::TimeTicks task_start_time;
+  if (do_work_depth_ == 1 && from_main_thread)

[Sami, 2016/07/05 14:40:38]

Why the check for |from_main_thread|? That flag says which thread this task was
posted from -- all tasks run on the main thread.

[tdresser, 2016/07/05 20:09:38]

Done.

+    task_start_time = real_time_domain()->Now();
+
   for (int i = 0; i < work_batch_size_; i++) {
     internal::WorkQueue* work_queue;
     if (!SelectWorkQueueToService(&work_queue)) {
@@ -200,6 +209,7 @@ void TaskQueueManager::DoWork(base::TimeTicks run_time, bool from_main_thread) {
 
     bool should_trigger_wakeup = work_queue->task_queue()->wakeup_policy() ==
                                  TaskQueue::WakeupPolicy::CAN_WAKE_OTHER_QUEUES;
+
     switch (ProcessTaskFromWorkQueue(work_queue, &previous_task)) {
       case ProcessTaskResult::DEFERRED:
         // If a task was deferred, try again with another task. Note that this
@@ -211,6 +221,13 @@ void TaskQueueManager::DoWork(base::TimeTicks run_time, bool from_main_thread) {
       case ProcessTaskResult::TASK_QUEUE_MANAGER_DELETED:
         return;  // The TaskQueueManager got deleted, we must bail out.
     }
+    if (do_work_depth_ == 1 && from_main_thread) {

[alex clarke (OOO till 29th), 2016/07/05 13:47:45]

Isn't do_work_depth_ == 1  equivalent to !delegate_->IsNested() ?

[tdresser, 2016/07/05 14:30:13]

Awesome, thanks.

+      // Only report top level task durations.
+      base::TimeTicks task_end_time = real_time_domain()->Now();
+      task_time_tracker_->ReportTaskTime(task_start_time, task_end_time);
+      task_start_time = task_end_time;
+    }
+
     work_queue = nullptr; // The queue may have been unregistered.
 
     UpdateWorkQueues(should_trigger_wakeup, &previous_task);
@@ -226,6 +243,7 @@ void TaskQueueManager::DoWork(base::TimeTicks run_time, bool from_main_thread) {
   // continuation task.
   if (!selector_.EnabledWorkQueuesEmpty() || TryAdvanceTimeDomains())
     MaybeScheduleImmediateWork(FROM_HERE);
+  do_work_depth_--;
 }
 
 bool TaskQueueManager::TryAdvanceTimeDomains() {