Define the task-tracking events

Based on initial patches by Mikolaj Konarski <mikolaj@well-typed.com>

These new eventlog events are to let profiling tools keep track of all
the OS threads that belong to an RTS capability at any moment in time.
In the RTS, OS threads correspond to the Task abstraction, so that is
what we track. There are events for tasks being created, migrated
between capabilities and deleted. In particular the task creation event
also records the kernel thread id which lets us match up the OS thread
with data collected by others tools (in the initial use case with
Linux's perf tool, but in principle also with DTrace).

6 files changed, 224 insertions, 12 deletions

diff --git a/includes/rts/EventLogFormat.h b/includes/rts/EventLogFormat.h
index b1933562da..82d3f683cc 100644
--- a/includes/rts/EventLogFormat.h
+++ b/includes/rts/EventLogFormat.h
@@ -158,21 +158,26 @@
                                          par_n_threads,
                                          par_max_copied, par_tot_copied) */
 #define EVENT_GC_GLOBAL_SYNC      54 /* ()                     */
+#define EVENT_TASK_CREATE         55 /* (taskID, cap, tid)       */
+#define EVENT_TASK_MIGRATE        56 /* (taskID, cap, new_cap)   */
+#define EVENT_TASK_DELETE         57 /* (taskID)                 */
 
-/* Range 55 - 59 is available for new GHC and common events */
+/* Range 58 - 59 is available for new GHC and common events. */
 
 /* Range 60 - 80 is used by eden for parallel tracing
  * see http://www.mathematik.uni-marburg.de/~eden/
  */
 
-/* Range 100 - 139 is reserved for Mercury */
+/* Range 100 - 139 is reserved for Mercury. */
+
+/* Range 140 - 159 is reserved for Perf events. */
 
 /*
  * The highest event code +1 that ghc itself emits. Note that some event
  * ranges higher than this are reserved but not currently emitted by ghc.
  * This must match the size of the EventDesc[] array in EventLog.c
  */
-#define NUM_GHC_EVENT_TAGS        55
+#define NUM_GHC_EVENT_TAGS        58
 
 #if 0  /* DEPRECATED EVENTS: */
 /* we don't actually need to record the thread, it's implicit */
@@ -229,6 +234,8 @@ typedef StgWord16 EventPayloadSize; /* variable-size events */
 typedef StgWord16 EventThreadStatus; /* status for EVENT_STOP_THREAD */
 typedef StgWord32 EventCapsetID;
 typedef StgWord16 EventCapsetType;   /* types for EVENT_CAPSET_CREATE */
+typedef StgWord64 EventTaskId;         /* for EVENT_TASK_* */
+typedef StgWord64 EventKernelThreadId; /* for EVENT_TASK_CREATE */
 
 #endif
 
diff --git a/rts/RtsProbes.d b/rts/RtsProbes.d
index 40665acc56..9be0e66a40 100644
--- a/rts/RtsProbes.d
+++ b/rts/RtsProbes.d
@@ -90,6 +90,11 @@ provider HaskellEvent {
   probe spark__fizzle   (EventCapNo);
   probe spark__gc       (EventCapNo);
 
+  /* task events */
+  probe task__create(EventTaskId, EventCapNo, EventKernelThreadId);
+  probe task__migrate(EventTaskId, EventCapNo, EventCapNo);
+  probe task__delete(EventTaskId);
+
   /* other events */
 /* This one doesn't seem to be used at all at the moment: */
 /*  probe log__msg (char *); */
diff --git a/rts/Trace.c b/rts/Trace.c
index 9fa8eb177b..a946f2c5d3 100644
--- a/rts/Trace.c
+++ b/rts/Trace.c
@@ -574,6 +574,52 @@ void traceSparkCounters_ (Capability *cap,
     }
 }
 
+void traceTaskCreate_ (Task       *task,
+                       Capability *cap)
+{
+#ifdef DEBUG
+    if (RtsFlags.TraceFlags.tracing == TRACE_STDERR) {
+        /* We currently don't do debug tracing of tasks but we must
+           test for TRACE_STDERR because of the !eventlog_enabled case. */
+    } else
+#endif
+    {
+        EventTaskId         taskid = serialisableTaskId(task);
+        EventKernelThreadId tid    = kernelThreadId();
+        postTaskCreateEvent(taskid, cap->no, tid);
+    }
+}
+
+void traceTaskMigrate_ (Task       *task,
+                        Capability *cap,
+                        Capability *new_cap)
+{
+#ifdef DEBUG
+    if (RtsFlags.TraceFlags.tracing == TRACE_STDERR) {
+        /* We currently don't do debug tracing of tasks but we must
+           test for TRACE_STDERR because of the !eventlog_enabled case. */
+    } else
+#endif
+    {
+        EventTaskId taskid = serialisableTaskId(task);
+        postTaskMigrateEvent(taskid, cap->no, new_cap->no);
+    }
+}
+
+void traceTaskDelete_ (Task *task)
+{
+#ifdef DEBUG
+    if (RtsFlags.TraceFlags.tracing == TRACE_STDERR) {
+        /* We currently don't do debug tracing of tasks but we must
+           test for TRACE_STDERR because of the !eventlog_enabled case. */
+    } else
+#endif
+    {
+        EventTaskId taskid = serialisableTaskId(task);
+        postTaskDeleteEvent(taskid);
+    }
+}
+
 #ifdef DEBUG
 static void traceCap_stderr(Capability *cap, char *msg, va_list ap)
 {
diff --git a/rts/Trace.h b/rts/Trace.h
index 58ce43df68..6141003026 100644
--- a/rts/Trace.h
+++ b/rts/Trace.h
@@ -262,6 +262,15 @@ void traceSparkCounters_ (Capability *cap,
                           SparkCounters counters,
                           StgWord remaining);
 
+void traceTaskCreate_ (Task       *task,
+                       Capability *cap);
+
+void traceTaskMigrate_ (Task       *task,
+                        Capability *cap,
+                        Capability *new_cap);
+
+void traceTaskDelete_ (Task       *task);
+
 #else /* !TRACING */
 
 #define traceSchedEvent(cap, tag, tso, other) /* nothing */
@@ -289,6 +298,9 @@ INLINE_HEADER void traceEventStartup_ (int n_caps STG_UNUSED) {};
 #define traceWallClockTime_() /* nothing */
 #define traceOSProcessInfo_() /* nothing */
 #define traceSparkCounters_(cap, counters, remaining) /* nothing */
+#define traceTaskCreate_(taskID, cap) /* nothing */
+#define traceTaskMigrate_(taskID, cap, new_cap) /* nothing */
+#define traceTaskDelete_(taskID) /* nothing */
 
 #endif /* TRACING */
 
@@ -415,6 +427,12 @@ INLINE_HEADER void dtraceStartup (int num_caps) {
     HASKELLEVENT_SPARK_FIZZLE(cap)
 #define dtraceSparkGc(cap)                              \
     HASKELLEVENT_SPARK_GC(cap)
+#define dtraceTaskCreate(taskID, cap)                   \
+    HASKELLEVENT_TASK_CREATE(taskID, cap)
+#define dtraceTaskMigrate(taskID, cap, new_cap)         \
+    HASKELLEVENT_TASK_MIGRATE(taskID, cap, new_cap)
+#define dtraceTaskDelete(taskID)                        \
+    HASKELLEVENT_TASK_DELETE(taskID)
 
 #else /* !defined(DTRACE) */
 
@@ -464,6 +482,9 @@ INLINE_HEADER void dtraceStartup (int num_caps STG_UNUSED) {};
 #define dtraceSparkSteal(cap, victim_cap)               /* nothing */
 #define dtraceSparkFizzle(cap)                          /* nothing */
 #define dtraceSparkGc(cap)                              /* nothing */
+#define dtraceTaskCreate(taskID, cap)                   /* nothing */
+#define dtraceTaskMigrate(taskID, cap, new_cap)         /* nothing */
+#define dtraceTaskDelete(taskID)                        /* nothing */
 
 #endif
 
@@ -822,6 +843,47 @@ INLINE_HEADER void traceEventSparkGC(Capability *cap STG_UNUSED)
     dtraceSparkGc((EventCapNo)cap->no);
 }
 
+INLINE_HEADER void traceTaskCreate(Task       *task STG_UNUSED,
+                                   Capability *cap  STG_UNUSED)
+{
+    ASSERT(task->cap == cap);
+    // TODO: asserting task->cap == NULL would be much stronger
+    // (the intention being that the task structure is just created and empty)
+    // but would require large changes of traceTaskCreate calls.
+    ASSERT(cap != NULL);
+    // A new task gets associated with a cap. We also record
+    // the kernel thread id of the task, which should never change.
+    if (RTS_UNLIKELY(TRACE_sched)) {
+        traceTaskCreate_(task, cap);
+    }
+    dtraceTaskCreate(serialisableTaskId(task), (EventCapNo)cap->no);
+}
+
+INLINE_HEADER void traceTaskMigrate(Task       *task    STG_UNUSED,
+                                    Capability *cap     STG_UNUSED,
+                                    Capability *new_cap STG_UNUSED)
+{
+    ASSERT(task->cap == cap);
+    ASSERT(cap != NULL);
+    ASSERT(cap != new_cap);
+    ASSERT(new_cap != NULL);
+    // A task migrates from a cap to another.
+    if (RTS_UNLIKELY(TRACE_sched)) {
+        traceTaskMigrate_(task, cap, new_cap);
+    }
+    dtraceTaskMigrate(serialisableTaskId(task), (EventCapNo)cap->no,
+                                                (EventCapNo)new_cap->no);
+}
+
+INLINE_HEADER void traceTaskDelete(Task *task STG_UNUSED)
+{
+    ASSERT(task->cap != NULL);
+    if (RTS_UNLIKELY(TRACE_sched)) {
+        traceTaskDelete_(task);
+    }
+    dtraceTaskDelete(serialisableTaskId(task));
+}
+
 #include "EndPrivate.h"
 
 #endif /* TRACE_H */
diff --git a/rts/eventlog/EventLog.c b/rts/eventlog/EventLog.c
index 66b589e282..b6614b940c 100644
--- a/rts/eventlog/EventLog.c
+++ b/rts/eventlog/EventLog.c
@@ -102,6 +102,9 @@ char *EventDesc[] = {
   [EVENT_SPARK_STEAL]         = "Spark steal",
   [EVENT_SPARK_FIZZLE]        = "Spark fizzle",
   [EVENT_SPARK_GC]            = "Spark GC",
+  [EVENT_TASK_CREATE]         = "Task create",
+  [EVENT_TASK_MIGRATE]        = "Task migrate",
+  [EVENT_TASK_DELETE]         = "Task delete",
 };
 
 // Event type. 
@@ -178,6 +181,15 @@ static inline void postCapsetID(EventsBuf *eb, EventCapsetID id)
 static inline void postCapsetType(EventsBuf *eb, EventCapsetType type)
 { postWord16(eb,type); }
 
+static inline void postOSProcessId(EventsBuf *eb, pid_t pid)
+{ postWord32(eb, pid); }
+
+static inline void postKernelThreadId(EventsBuf *eb, EventKernelThreadId tid)
+{ postWord64(eb, tid); }
+
+static inline void postTaskId(EventsBuf *eb, EventTaskId tUniq)
+{ postWord64(eb, tUniq); }
+
 static inline void postPayloadSize(EventsBuf *eb, EventPayloadSize size)
 { postWord16(eb,size); }
 
@@ -393,6 +405,20 @@ initEventLogging(void)
                                + sizeof(StgWord64) * 2;
             break;
 
+        case EVENT_TASK_CREATE:   // (taskId, cap, tid)
+            eventTypes[t].size =
+                sizeof(EventTaskId) + sizeof(EventCapNo) + sizeof(EventKernelThreadId);
+            break;
+
+        case EVENT_TASK_MIGRATE:   // (taskId, cap, new_cap)
+            eventTypes[t].size =
+                sizeof(EventTaskId) + sizeof(EventCapNo) + sizeof(EventCapNo);
+            break;
+
+        case EVENT_TASK_DELETE:   // (taskId)
+            eventTypes[t].size = sizeof(EventTaskId);
+            break;
+
         case EVENT_BLOCK_MARKER:
             eventTypes[t].size = sizeof(StgWord32) + sizeof(EventTimestamp) + 
                 sizeof(EventCapNo);
@@ -699,7 +725,7 @@ void postCapsetEvent (EventTypeNum tag,
     case EVENT_OSPROCESS_PID:   // (capset, pid)
     case EVENT_OSPROCESS_PPID:  // (capset, parent_pid)
     {
-        postWord32(&eventBuf, info);
+        postOSProcessId(&eventBuf, info);
         break;
     }
     default:
@@ -914,6 +940,62 @@ void postEventGcStats  (Capability    *cap,
     postWord64(eb, par_tot_copied);
 }
 
+void postTaskCreateEvent (EventTaskId taskId,
+                          EventCapNo capno,
+                          EventKernelThreadId tid)
+{
+    ACQUIRE_LOCK(&eventBufMutex);
+
+    if (!hasRoomForEvent(&eventBuf, EVENT_TASK_CREATE)) {
+        // Flush event buffer to make room for new event.
+        printAndClearEventBuf(&eventBuf);
+    }
+
+    postEventHeader(&eventBuf, EVENT_TASK_CREATE);
+    /* EVENT_TASK_CREATE (taskID, cap, tid) */
+    postTaskId(&eventBuf, taskId);
+    postCapNo(&eventBuf, capno);
+    postKernelThreadId(&eventBuf, tid);
+
+    RELEASE_LOCK(&eventBufMutex);
+}
+
+void postTaskMigrateEvent (EventTaskId taskId,
+                           EventCapNo capno,
+                           EventCapNo new_capno)
+{
+    ACQUIRE_LOCK(&eventBufMutex);
+
+    if (!hasRoomForEvent(&eventBuf, EVENT_TASK_MIGRATE)) {
+        // Flush event buffer to make room for new event.
+        printAndClearEventBuf(&eventBuf);
+    }
+
+    postEventHeader(&eventBuf, EVENT_TASK_MIGRATE);
+    /* EVENT_TASK_MIGRATE (taskID, cap, new_cap) */
+    postTaskId(&eventBuf, taskId);
+    postCapNo(&eventBuf, capno);
+    postCapNo(&eventBuf, new_capno);
+
+    RELEASE_LOCK(&eventBufMutex);
+}
+
+void postTaskDeleteEvent (EventTaskId taskId)
+{
+    ACQUIRE_LOCK(&eventBufMutex);
+
+    if (!hasRoomForEvent(&eventBuf, EVENT_TASK_DELETE)) {
+        // Flush event buffer to make room for new event.
+        printAndClearEventBuf(&eventBuf);
+    }
+
+    postEventHeader(&eventBuf, EVENT_TASK_DELETE);
+    /* EVENT_TASK_DELETE (taskID) */
+    postTaskId(&eventBuf, taskId);
+
+    RELEASE_LOCK(&eventBufMutex);
+}
+
 void
 postEvent (Capability *cap, EventTypeNum tag)
 {
diff --git a/rts/eventlog/EventLog.h b/rts/eventlog/EventLog.h
index b8ee56aa3b..93dd9a8144 100644
--- a/rts/eventlog/EventLog.h
+++ b/rts/eventlog/EventLog.h
@@ -28,11 +28,11 @@ void abortEventLogging(void); // #4512 - after fork child needs to abort
 void flushEventLog(void);     // event log inherited from parent
 void moreCapEventBufs (nat from, nat to);
 
-/* 
+/*
  * Post a scheduler event to the capability's event buffer (an event
  * that has an associated thread).
  */
-void postSchedEvent(Capability *cap, EventTypeNum tag, 
+void postSchedEvent(Capability *cap, EventTypeNum tag,
                     StgThreadID id, StgWord info1, StgWord info2);
 
 /*
@@ -40,7 +40,7 @@ void postSchedEvent(Capability *cap, EventTypeNum tag,
  */
 void postEvent(Capability *cap, EventTypeNum tag);
 
-void postEventAtTimestamp (Capability *cap, EventTimestamp ts, 
+void postEventAtTimestamp (Capability *cap, EventTimestamp ts,
                            EventTypeNum tag);
 
 void postMsg(char *msg, va_list ap);
@@ -81,7 +81,7 @@ void postCapsetVecEvent (EventTypeNum tag,
 
 void postWallClockTime (EventCapsetID capset);
 
-/* 
+/*
  * Post a `par` spark event
  */
 void postSparkEvent(Capability *cap, EventTypeNum tag, StgWord info1);
@@ -89,7 +89,7 @@ void postSparkEvent(Capability *cap, EventTypeNum tag, StgWord info1);
 /*
  * Post an event with several counters relating to `par` sparks.
  */
-void postSparkCountersEvent (Capability *cap, 
+void postSparkCountersEvent (Capability *cap,
                              SparkCounters counters,
                              StgWord remaining);
 
@@ -125,6 +125,16 @@ void postEventGcStats  (Capability    *cap,
                         lnat           par_max_copied,
                         lnat           par_tot_copied);
 
+void postTaskCreateEvent (EventTaskId taskId,
+                          EventCapNo cap,
+                          EventKernelThreadId tid);
+
+void postTaskMigrateEvent (EventTaskId taskId,
+                           EventCapNo capno,
+                           EventCapNo new_capno);
+
+void postTaskDeleteEvent (EventTaskId taskId);
+
 #else /* !TRACING */
 
 INLINE_HEADER void postSchedEvent (Capability *cap  STG_UNUSED,
@@ -138,12 +148,12 @@ INLINE_HEADER void postEvent (Capability *cap  STG_UNUSED,
                               EventTypeNum tag STG_UNUSED)
 { /* nothing */ }
 
-INLINE_HEADER void postMsg (char *msg STG_UNUSED, 
+INLINE_HEADER void postMsg (char *msg STG_UNUSED,
                             va_list ap STG_UNUSED)
 { /* nothing */ }
 
 INLINE_HEADER void postCapMsg (Capability *cap STG_UNUSED,
-                               char *msg STG_UNUSED, 
+                               char *msg STG_UNUSED,
                                va_list ap STG_UNUSED)
 { /* nothing */ }
 
@@ -152,7 +162,7 @@ INLINE_HEADER void postThreadLabel(Capability    *cap   STG_UNUSED,
                                    EventThreadID  id    STG_UNUSED,
                                    char          *label STG_UNUSED)
 { /* nothing */ }
-                                   
+
 #endif
 
 #include "EndPrivate.h"