Add queued_time_ms trace for events in message loop

base/message_loop/message_loop.cc

 // Copyright 2013 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 "base/message_loop/message_loop.h"
 
 #include <algorithm>
 
 #include "base/bind.h"
 #include "base/compiler_specific.h"
@@ skipping 438 matching lines @@
     return false;
 
   PendingTask pending_task = deferred_non_nestable_work_queue_.front();
   deferred_non_nestable_work_queue_.pop();
 
   RunTask(pending_task);
   return true;
 }
 
 void MessageLoop::RunTask(const PendingTask& pending_task) {
-  TRACE_EVENT_FLOW_END0("task", "MessageLoop::PostTask",
-      TRACE_ID_MANGLE(GetTaskTraceID(pending_task, this)));
+  tracked_objects::TrackedTime start_time =
+      tracked_objects::ThreadData::NowForStartOfRun(pending_task.birth_tally);
+
+  TRACE_EVENT_FLOW_END1("task", "MessageLoop::PostTask",
+      TRACE_ID_MANGLE(GetTaskTraceID(pending_task, this)),
+      "queue_duration",
+      (start_time - pending_task.EffectiveTimePosted()).InMilliseconds());
   TRACE_EVENT2("task", "MessageLoop::RunTask",
                "src_file", pending_task.posted_from.file_name(),
                "src_func", pending_task.posted_from.function_name());
+
   DCHECK(nestable_tasks_allowed_);
   // Execute the task and assume the worst: It is probably not reentrant.
   nestable_tasks_allowed_ = false;
 
   // Before running the task, store the program counter where it was posted
   // and deliberately alias it to ensure it is on the stack if the task
   // crashes. Be careful not to assume that the variable itself will have the
   // expected value when displayed by the optimizer in an optimized build.
   // Look at a memory dump of the stack.
   const void* program_counter =
       pending_task.posted_from.program_counter();
   debug::Alias(&program_counter);
 
   HistogramEvent(kTaskRunEvent);
 
-  tracked_objects::TrackedTime start_time =
-      tracked_objects::ThreadData::NowForStartOfRun(pending_task.birth_tally);
-
   FOR_EACH_OBSERVER(TaskObserver, task_observers_,
                     WillProcessTask(pending_task));
   pending_task.task.Run();
   FOR_EACH_OBSERVER(TaskObserver, task_observers_,
                     DidProcessTask(pending_task));
 
   tracked_objects::ThreadData::TallyRunOnNamedThreadIfTracking(pending_task,
       start_time, tracked_objects::ThreadData::NowForEndOfRun());
 
   nestable_tasks_allowed_ = true;
@@ skipping 333 matching lines @@
       fd,
       persistent,
       mode,
       controller,
       delegate);
 }
 
 #endif
 
 }  // namespace base