Bug 908995 - Part 2: Track runnables, tasks and timer events with TaskTracer. r=khuey.

ipc/chromium/src/base/message_loop.cc

@@ -31,6 +31,9 @@
 #ifdef ANDROID
 #include "base/message_pump_android.h"
 #endif
+#ifdef MOZ_TASK_TRACER
+#include "GeckoTaskTracer.h"
+#endif
 
 #include "MessagePump.h"
 
@@ -277,6 +280,11 @@ void MessageLoop::PostNonNestableDelayedTask(
 void MessageLoop::PostIdleTask(
     const tracked_objects::Location& from_here, Task* task) {
   DCHECK(current() == this);
+
+#ifdef MOZ_TASK_TRACER
+  task = mozilla::tasktracer::CreateTracedTask(task);
+#endif
+
   task->SetBirthPlace(from_here);
   PendingTask pending_task(task, false);
   deferred_non_nestable_work_queue_.push(pending_task);
@@ -286,6 +294,11 @@ void MessageLoop::PostIdleTask(
 void MessageLoop::PostTask_Helper(
     const tracked_objects::Location& from_here, Task* task, int delay_ms,
     bool nestable) {
+
+#ifdef MOZ_TASK_TRACER
+  task = mozilla::tasktracer::CreateTracedTask(task);
+#endif
+
   task->SetBirthPlace(from_here);
 
   PendingTask pending_task(task, nestable);

ipc/chromium/src/base/thread.cc

@@ -11,6 +11,10 @@
 #include "GeckoProfiler.h"
 #include "mozilla/IOInterposer.h"
 
+#ifdef MOZ_TASK_TRACER
+#include "GeckoTaskTracer.h"
+#endif
+
 namespace base {
 
 // This task is used to trigger the message loop to exit.
@@ -172,6 +176,10 @@ void Thread::ThreadMain() {
   mozilla::IOInterposer::UnregisterCurrentThread();
   profiler_unregister_thread();
 
+#ifdef MOZ_TASK_TRACER
+  mozilla::tasktracer::FreeTraceInfo();
+#endif
+
   // We can't receive messages anymore.
   message_loop_ = NULL;
   thread_id_ = 0;

ipc/chromium/src/chrome/common/ipc_channel_posix.cc

@@ -32,6 +32,11 @@
 #include "chrome/common/ipc_message_utils.h"
 #include "mozilla/ipc/ProtocolUtils.h"
 
+#ifdef MOZ_TASK_TRACER
+#include "GeckoTaskTracerImpl.h"
+using namespace mozilla::tasktracer;
+#endif
+
 namespace IPC {
 
 // IPC channels on Windows use named pipes (CreateNamedPipe()) with
@@ -594,6 +599,14 @@ bool Channel::ChannelImpl::ProcessIncomingMessages() {
         DLOG(INFO) << "received message on channel @" << this <<
                       " with type " << m.type();
 #endif
+
+#ifdef MOZ_TASK_TRACER
+        AutoSaveCurTraceInfo saveCurTraceInfo;
+        SetCurTraceInfo(m.header()->source_event_id,
+                        m.header()->parent_task_id,
+                        m.header()->source_event_type);
+#endif
+
         if (m.routing_id() == MSG_ROUTING_NONE &&
             m.type() == HELLO_MESSAGE_TYPE) {
           // The Hello message contains only the process id.
@@ -687,6 +700,11 @@ bool Channel::ChannelImpl::ProcessOutgoingMessages() {
       msg->set_fd_cookie(++last_pending_fd_id_);
 #endif
     }
+#ifdef MOZ_TASK_TRACER
+    GetCurTraceInfo(&msg->header()->source_event_id,
+                    &msg->header()->parent_task_id,
+                    &msg->header()->source_event_type);
+#endif
 
     size_t amt_to_write = msg->size() - message_send_bytes_written_;
     DCHECK(amt_to_write != 0);

ipc/chromium/src/chrome/common/ipc_message.cc

@@ -10,6 +10,13 @@
 #if defined(OS_POSIX)
 #include "chrome/common/file_descriptor_set_posix.h"
 #endif
+#ifdef MOZ_TASK_TRACER
+#include "GeckoTaskTracer.h"
+#endif
+
+#ifdef MOZ_TASK_TRACER
+using namespace mozilla::tasktracer;
+#endif
 
 namespace IPC {
 
@@ -23,6 +30,11 @@ Message::Message()
   header()->routing = header()->type = header()->flags = 0;
 #if defined(OS_POSIX)
   header()->num_fds = 0;
+#endif
+#ifdef MOZ_TASK_TRACER
+  header()->source_event_id = 0;
+  header()->parent_task_id = 0;
+  header()->source_event_type = SourceEventType::UNKNOWN;
 #endif
   InitLoggingVariables();
 }
@@ -43,6 +55,11 @@ Message::Message(int32_t routing_id, msgid_t type, PriorityValue priority,
   header()->seqno = 0;
 #if defined(OS_MACOSX)
   header()->cookie = 0;
+#endif
+#ifdef MOZ_TASK_TRACER
+  header()->source_event_id = 0;
+  header()->parent_task_id = 0;
+  header()->source_event_type = SourceEventType::UNKNOWN;
 #endif
   InitLoggingVariables(name);
 }
@@ -56,6 +73,11 @@ Message::Message(const Message& other) : Pickle(other) {
 #if defined(OS_POSIX)
   file_descriptor_set_ = other.file_descriptor_set_;
 #endif
+#ifdef MOZ_TASK_TRACER
+  header()->source_event_id = other.header()->source_event_id;
+  header()->parent_task_id = other.header()->parent_task_id;
+  header()->source_event_type = other.header()->source_event_type;
+#endif
 }
 
 void Message::InitLoggingVariables(const char* const name) {
@@ -72,6 +94,11 @@ Message& Message::operator=(const Message& other) {
   InitLoggingVariables(other.name_);
 #if defined(OS_POSIX)
   file_descriptor_set_ = other.file_descriptor_set_;
+#endif
+#ifdef MOZ_TASK_TRACER
+  header()->source_event_id = other.header()->source_event_id;
+  header()->parent_task_id = other.header()->parent_task_id;
+  header()->source_event_type = other.header()->source_event_type;
 #endif
   return *this;
 }

ipc/chromium/src/chrome/common/ipc_message.h

@@ -10,6 +10,10 @@
 #include "base/basictypes.h"
 #include "base/pickle.h"
 
+#ifdef MOZ_TASK_TRACER
+#include "GeckoTaskTracer.h"
+#endif
+
 #ifndef NDEBUG
 #define IPC_MESSAGE_LOG_ENABLED
 #endif
@@ -336,6 +340,11 @@ class Message : public Pickle {
     uint32_t interrupt_local_stack_depth;
     // Sequence number
     int32_t seqno;
+#ifdef MOZ_TASK_TRACER
+    uint64_t source_event_id;
+    uint64_t parent_task_id;
+    mozilla::tasktracer::SourceEventType source_event_type;
+#endif
   };
 
   Header* header() {

tools/profiler/GeckoProfilerImpl.h

@@ -17,6 +17,10 @@
 #include "PseudoStack.h"
 #include "nsISupports.h"
 
+#ifdef MOZ_TASK_TRACER
+#include "GeckoTaskTracerImpl.h"
+#endif
+
 /* QT has a #define for the word "slots" and jsfriendapi.h has a struct with
  * this variable name, causing compilation problems. Alleviate this for now by
  * removing this #define */
@@ -54,12 +58,18 @@ extern bool stack_key_initialized;
 static inline
 void profiler_init(void* stackTop)
 {
+#ifdef MOZ_TASK_TRACER
+  mozilla::tasktracer::InitTaskTracer();
+#endif
   mozilla_sampler_init(stackTop);
 }
 
 static inline
 void profiler_shutdown()
 {
+#ifdef MOZ_TASK_TRACER
+  mozilla::tasktracer::ShutdownTaskTracer();
+#endif
   mozilla_sampler_shutdown();
 }
 

xpcom/threads/TimerThread.cpp

@@ -418,6 +418,11 @@ int32_t TimerThread::AddTimerInternal(nsTimerImpl *aTimer)
 
   aTimer->mArmed = true;
   NS_ADDREF(aTimer);
+
+#ifdef MOZ_TASK_TRACER
+  aTimer->DispatchTracedTask();
+#endif
+
   return insertSlot - mTimers.Elements();
 }
 

xpcom/threads/nsThread.cpp

@@ -59,6 +59,11 @@
 #include "nsCRT.h"
 #endif
 
+#ifdef MOZ_TASK_TRACER
+#include "GeckoTaskTracer.h"
+using namespace mozilla::tasktracer;
+#endif
+
 using namespace mozilla;
 
 #ifdef PR_LOGGING
@@ -343,6 +348,10 @@ nsThread::ThreadFunc(void *arg)
   // Release any observer of the thread here.
   self->SetObserver(nullptr);
 
+#ifdef MOZ_TASK_TRACER
+  FreeTraceInfo();
+#endif
+
   NS_RELEASE(self);
 }
 
@@ -445,6 +454,11 @@ nsThread::DispatchInternal(nsIRunnable *event, uint32_t flags,
     return NS_ERROR_ILLEGAL_DURING_SHUTDOWN;
   }
 
+#ifdef MOZ_TASK_TRACER
+  nsRefPtr<nsIRunnable> tracedRunnable = CreateTracedRunnable(event);
+  event = tracedRunnable;
+#endif
+
   if (flags & DISPATCH_SYNC) {
     nsThread *thread = nsThreadManager::get()->GetCurrentThread();
     if (NS_WARN_IF(!thread))
@@ -453,7 +467,7 @@ nsThread::DispatchInternal(nsIRunnable *event, uint32_t flags,
     // XXX we should be able to do something better here... we should
     //     be able to monitor the slot occupied by this event and use
     //     that to tell us when the event has been processed.
- 
+
     nsRefPtr<nsThreadSyncDispatch> wrapper =
         new nsThreadSyncDispatch(thread, event);
     if (!wrapper)

xpcom/threads/nsTimerImpl.cpp

@@ -504,6 +504,10 @@ void nsTimerImpl::Fire()
 
   PROFILER_LABEL("Timer", "Fire");
 
+#ifdef MOZ_TASK_TRACER
+  mozilla::tasktracer::AutoRunFakeTracedTask runTracedTask(mTracedTask);
+#endif
+
 #ifdef DEBUG_TIMERS
   TimeStamp now = TimeStamp::Now();
   if (PR_LOG_TEST(GetTimerLog(), PR_LOG_DEBUG)) {
@@ -535,7 +539,7 @@ void nsTimerImpl::Fire()
   if (mCallbackType == CALLBACK_TYPE_INTERFACE)
     mTimerCallbackWhileFiring = mCallback.i;
   mFiring = true;
-  
+
   // Handle callbacks that re-init the timer, but avoid leaking.
   // See bug 330128.
   CallbackUnion callback = mCallback;

xpcom/threads/nsTimerImpl.h

@@ -18,6 +18,10 @@
 #include "mozilla/TimeStamp.h"
 #include "mozilla/Attributes.h"
 
+#ifdef MOZ_TASK_TRACER
+#include "TracedTaskCommon.h"
+#endif
+
 #if defined(PR_LOGGING)
 extern PRLogModuleInfo *GetTimerLog();
 #define DEBUG_TIMERS 1
@@ -62,6 +66,13 @@ public:
 
   int32_t GetGeneration() { return mGeneration; }
 
+#ifdef MOZ_TASK_TRACER
+  void DispatchTracedTask()
+  {
+    mTracedTask = mozilla::tasktracer::CreateFakeTracedTask(*(int**)(this));
+  }
+#endif
+
 private:
   ~nsTimerImpl();
   nsresult InitCommon(uint32_t aType, uint32_t aDelay);
@@ -129,6 +140,10 @@ private:
   uint32_t              mDelay;
   TimeStamp             mTimeout;
 
+#ifdef MOZ_TASK_TRACER
+  nsAutoPtr<mozilla::tasktracer::FakeTracedTask> mTracedTask;
+#endif
+
 #ifdef DEBUG_TIMERS
   TimeStamp             mStart, mStart2;
   static double         sDeltaSum;