eventlog: Dump cost centre stack on each sample

With this change it is possible to reconstruct the timing portion of a
`.prof` file after the fact. By logging the stacks at each time point
a more precise executation trace of the program can be observed rather
than all identical cost centres being identified in the report.

There are two new events:

1. `EVENT_PROF_BEGIN` - emitted at the start of profiling to communicate
the tick interval
2. `EVENT_PROF_SAMPLE_COST_CENTRE` - emitted on each tick to communicate the
current call stack.

Fixes #17322

2 files changed, 53 insertions, 0 deletions

diff --git a/rts/eventlog/EventLog.c b/rts/eventlog/EventLog.c
index 5c6a1ca48a..6d7b487152 100644
--- a/rts/eventlog/EventLog.c
+++ b/rts/eventlog/EventLog.c
@@ -107,6 +107,8 @@ char *EventDesc[] = {
   [EVENT_HEAP_PROF_SAMPLE_END]    = "End of heap profile sample",
   [EVENT_HEAP_PROF_SAMPLE_STRING] = "Heap profile string sample",
   [EVENT_HEAP_PROF_SAMPLE_COST_CENTRE] = "Heap profile cost-centre sample",
+  [EVENT_PROF_SAMPLE_COST_CENTRE] = "Time profile cost-centre stack",
+  [EVENT_PROF_BEGIN] = "Start of a time profile",
   [EVENT_USER_BINARY_MSG]     = "User binary message"
 };
 
@@ -442,6 +444,14 @@ init_event_types(void)
             eventTypes[t].size = EVENT_SIZE_DYNAMIC;
             break;
 
+        case EVENT_PROF_SAMPLE_COST_CENTRE:
+            eventTypes[t].size = EVENT_SIZE_DYNAMIC;
+            break;
+
+        case EVENT_PROF_BEGIN:
+            eventTypes[t].size = 8;
+            break;
+
         case EVENT_USER_BINARY_MSG:
             eventTypes[t].size = EVENT_SIZE_DYNAMIC;
             break;
@@ -1312,6 +1322,44 @@ void postHeapProfSampleCostCentre(StgWord8 profile_id,
         postWord32(&eventBuf, ccs->cc->ccID);
     RELEASE_LOCK(&eventBufMutex);
 }
+
+
+void postProfSampleCostCentre(Capability *cap,
+                              CostCentreStack *stack,
+                              StgWord64 tick)
+{
+    ACQUIRE_LOCK(&eventBufMutex);
+    StgWord depth = 0;
+    CostCentreStack *ccs;
+    for (ccs = stack; ccs != NULL && ccs != CCS_MAIN; ccs = ccs->prevStack)
+        depth++;
+    if (depth > 0xff) depth = 0xff;
+
+    StgWord len = 4+8+1+depth*4;
+    ensureRoomForVariableEvent(&eventBuf, len);
+    postEventHeader(&eventBuf, EVENT_PROF_SAMPLE_COST_CENTRE);
+    postPayloadSize(&eventBuf, len);
+    postWord32(&eventBuf, cap->no);
+    postWord64(&eventBuf, tick);
+    postWord8(&eventBuf, depth);
+    for (ccs = stack;
+         depth>0 && ccs != NULL && ccs != CCS_MAIN;
+         ccs = ccs->prevStack, depth--)
+        postWord32(&eventBuf, ccs->cc->ccID);
+    RELEASE_LOCK(&eventBufMutex);
+}
+
+// This event is output at the start of profiling so the tick interval can
+// be reported. Once the tick interval is reported the total executation time
+// can be calculuated from how many samples there are.
+void postProfBegin(void)
+{
+    ACQUIRE_LOCK(&eventBufMutex);
+    postEventHeader(&eventBuf, EVENT_PROF_BEGIN);
+    // The interval that each tick was sampled, in nanoseconds
+    postWord64(&eventBuf, TimeToNS(RtsFlags.MiscFlags.tickInterval));
+    RELEASE_LOCK(&eventBufMutex);
+}
 #endif /* PROFILING */
 
 void printAndClearEventBuf (EventsBuf *ebuf)
diff --git a/rts/eventlog/EventLog.h b/rts/eventlog/EventLog.h
index d8a614b45c..ec9a5f34e3 100644
--- a/rts/eventlog/EventLog.h
+++ b/rts/eventlog/EventLog.h
@@ -157,6 +157,11 @@ void postHeapProfCostCentre(StgWord32 ccID,
 void postHeapProfSampleCostCentre(StgWord8 profile_id,
                                   CostCentreStack *stack,
                                   StgWord64 residency);
+
+void postProfSampleCostCentre(Capability *cap,
+                              CostCentreStack *stack,
+                              StgWord64 ticks);
+void postProfBegin(void);
 #endif /* PROFILING */
 
 #else /* !TRACING */