Adding flow traces for blink scheduler events

Source/platform/scheduler/Scheduler.cpp

Index: Source/platform/scheduler/Scheduler.cpp
diff --git a/Source/platform/scheduler/Scheduler.cpp b/Source/platform/scheduler/Scheduler.cpp
index 39cb5cac817693d04ac6c4480ff835f857059ffc..ce236ee2d8729ce0c7e66ff4c583830104d18c50 100644
--- a/Source/platform/scheduler/Scheduler.cpp
+++ b/Source/platform/scheduler/Scheduler.cpp
@@ -74,7 +74,7 @@ class Scheduler::MainThreadPendingTaskRunner : public WebThread::Task {
 public:
     MainThreadPendingTaskRunner(
         const Scheduler::Task& task, const TraceLocation& location)
-        : m_task(task, location)
+        : m_task(task, location, TracedTask::Type::MainThread)
     {
         ASSERT(Scheduler::shared());
     }
@@ -93,6 +93,7 @@ public:
     Scheduler::TracedTask m_task;
 };
 
+

[Sami, 2014/08/20 14:20:57]

nit: extra whitespace

[picksi1, 2014/08/29 14:11:28]

Done.

 Scheduler* Scheduler::s_sharedScheduler = nullptr;
 
 void Scheduler::initializeOnMainThread()
@@ -116,6 +117,11 @@ Scheduler::Scheduler()
     , m_mainThread(blink::Platform::current()->currentThread())
     , m_highPriorityTaskCount(0)
 {
+    // Set up static array with names used for tracing. Set up dynamically
+    // to avoid the need to ensure enums and strings remain in sync.
+    TracedTask::setTypeName(TracedTask::Type::Compositor, "Scheduler::CompositorTask");
+    TracedTask::setTypeName(TracedTask::Type::Input, "Scheduler::InputTask");
+    TracedTask::setTypeName(TracedTask::Type::MainThread, "Scheduler::MainThreadTask");
 }
 
 Scheduler::~Scheduler()
@@ -139,7 +145,8 @@ void Scheduler::postTask(const TraceLocation& location, const Task& task)
 void Scheduler::postInputTask(const TraceLocation& location, const Task& task)
 {
     Locker<Mutex> lock(m_pendingTasksMutex);
-    m_pendingInputTasks.append(TracedTask(task, location));
+    TracedTask tracedTask = TracedTask(task, location, TracedTask::Type::Input);
+    m_pendingInputTasks.append(tracedTask);
     atomicIncrement(&m_highPriorityTaskCount);
     m_mainThread->postTask(new MainThreadPendingHighPriorityTaskRunner());
 }
@@ -147,7 +154,8 @@ void Scheduler::postInputTask(const TraceLocation& location, const Task& task)
 void Scheduler::postCompositorTask(const TraceLocation& location, const Task& task)
 {
     Locker<Mutex> lock(m_pendingTasksMutex);
-    m_pendingCompositorTasks.append(TracedTask(task, location));
+    TracedTask tracedTask = TracedTask(task, location, TracedTask::Type::Compositor);
+    m_pendingCompositorTasks.append(tracedTask);
     atomicIncrement(&m_highPriorityTaskCount);
     m_mainThread->postTask(new MainThreadPendingHighPriorityTaskRunner());
 }
@@ -233,12 +241,38 @@ bool Scheduler::hasPendingHighPriorityWork() const
     return acquireLoad(&m_highPriorityTaskCount) != 0;
 }
 
+FlowTraceID Scheduler::TracedTask::s_NextFlowTraceID = 0;
+char const * Scheduler::TracedTask::s_typeNames[TracedTask::Type::TypeCount];
+
 void Scheduler::TracedTask::run()
 {
-    TRACE_EVENT2("blink", "TracedTask::run",
+    TRACE_EVENT_FLOW_END2("blink",  s_typeNames[m_type], TRACE_ID_MANGLE(m_FlowTraceID),
+        "src_file", m_location.fileName(),

[Sami, 2014/08/20 14:20:57]

No need to report the same src_file and src_func here since we do that below.

Chromium also reports the queuing duration here[1]. I wonder if we could do the
same?

[1]
https://code.google.com/p/chromium/codesearch#chromium/src/base/debug/task_an...

[picksi1, 2014/08/29 14:11:28]

file and func removed, will add queue duration as a separate patch to avoid
bloating.

+        "src_func", m_location.functionName());
+
+    TRACE_EVENT2("blink", s_typeNames[m_type],
         "src_file", m_location.fileName(),
         "src_func", m_location.functionName());
+
     m_task();
 }
 
+void Scheduler::TracedTask::setTypeName(TracedTask::Type type, char const * name)
+{
+    ASSERT((type >= 0) && (type < TracedTask::Type::TypeCount));
+    s_typeNames[type] = name;
+}
+
+Scheduler::TracedTask::TracedTask(const Task& task, const TraceLocation& location, TracedTask::Type type)
+    : m_FlowTraceID(s_NextFlowTraceID++)

[Sami, 2014/08/20 14:20:57]

Unfortunately TracedTasks can get constructed on arbitrary threads, so
incrementing the counter like this isn't thread safe. I think this needs to be
an atomic increment. Or better yet, we can make the counter a member of
Scheduler and increment it while m_pendingTaskMutex is held.

[picksi1, 2014/08/29 14:11:28]

Done.

+    , m_task(task)
+    , m_location(location)
+    , m_type(type)
+{
+    TRACE_EVENT_FLOW_BEGIN2("blink", s_typeNames[type], TRACE_ID_MANGLE(m_FlowTraceID),
+        "src_file", m_location.fileName(),
+        "src_func", m_location.functionName());
+}
+
+
 } // namespace blink