Adding flow traces for blink scheduler events

Source/platform/scheduler/Scheduler.cpp

 // Copyright 2014 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 "config.h"
 #include "platform/scheduler/Scheduler.h"
 
 #include "platform/PlatformThreadData.h"
 #include "platform/Task.h"
 #include "platform/ThreadTimers.h"
@@ skipping 56 matching lines @@
     }
 };
 
 
 // Can be created from any thread.
 // Note if the scheduler gets shutdown, this may be run after.
 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());
     }
 
     // WebThread::Task implementation.
     virtual void run() OVERRIDE
     {
         Scheduler* scheduler = Scheduler::shared();
         // FIXME: This check should't be necessary, tasks should not outlive blink.
         ASSERT(scheduler);
         if (scheduler)
             Scheduler::shared()->runHighPriorityTasks();
         m_task.run();
     }
 
     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()
 {
     s_sharedScheduler = new Scheduler();
 }
 
 void Scheduler::shutdown()
 {
     delete s_sharedScheduler;
     s_sharedScheduler = nullptr;
 }
 
 Scheduler* Scheduler::shared()
 {
     return s_sharedScheduler;
 }
 
 Scheduler::Scheduler()
     : m_sharedTimerFunction(nullptr)
     , 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()
 {
     while (hasPendingHighPriorityWork()) {
         runHighPriorityTasks();
     }
 }
 
 void Scheduler::scheduleIdleTask(const TraceLocation& location, const IdleTask& idleTask)
 {
     // TODO: send a real allottedTime here.
     m_mainThread->postTask(new MainThreadIdleTaskAdapter(idleTask, 0, location));
 }
 
 void Scheduler::postTask(const TraceLocation& location, const Task& task)
 {
     m_mainThread->postTask(new MainThreadPendingTaskRunner(task, location));
 }
 
 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());
 }
 
 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());
 }
 
 void Scheduler::postIdleTask(const TraceLocation& location, const IdleTask& idleTask)
 {
     scheduleIdleTask(location, idleTask);
 }
 
 void Scheduler::tickSharedTimer()
@@ skipping 65 matching lines @@
 bool Scheduler::hasPendingHighPriorityWork() const
 {
     // This method is expected to be run on the main thread, but the high priority tasks will be posted by
     // other threads. We could use locks here, but this function is (sometimes) called a lot by
     // ThreadTimers::sharedTimerFiredInternal so we decided to use atomics + barrier loads here which
     // should be cheaper.
     // NOTE it's possible the barrier read is overkill here, since delayed yielding isn't a big deal.
     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