Add queued_time_ms trace for events in message loop
These trace can be useful for examining the status of message loop
queues when debugging some performance issues.
BUG=none
Review URL: https://chromiumcodereview.appspot.com/18083015
git-svn-id: svn://svn.chromium.org/chrome/trunk/src@210880 0039d316-1c4b-4281-b951-d872f2087c98
CrOS-Libchrome-Original-Commit: e1a38d600ac88e2b70a50f1a95416ccfcb2de858
diff --git a/base/message_loop/message_loop.cc b/base/message_loop/message_loop.cc
index 9e33a42..96192a7 100644
--- a/base/message_loop/message_loop.cc
+++ b/base/message_loop/message_loop.cc
@@ -456,11 +456,17 @@
}
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;
@@ -476,9 +482,6 @@
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();