eventlog: Add biographical and retainer profiling traces

This patch adds a new eventlog event which indicates the start of
a biographical profiler sample. These are different to normal events as
they also include the timestamp of when the census took place. This is
because the LDV profiler only emits samples at the end of the run.

Now all the different profiling modes emit consumable events to the
eventlog.

7 files changed, 64 insertions, 4 deletions

diff --git a/rts/ProfHeap.c b/rts/ProfHeap.c
index cc99e37fdc..55541f70cc 100644
--- a/rts/ProfHeap.c
+++ b/rts/ProfHeap.c
@@ -81,6 +81,10 @@ initLDVCtr( counter *ctr )
 
 typedef struct {
     double      time;    // the time in MUT time when the census is made
+    StgWord64   rtime;   // The eventlog time the census was made. This is used
+                         // for the LDV profiling events because they are all
+                         // emitted at the end of compilation so we need to know
+                         // when the sample actually took place.
     HashTable * hash;
     counter   * ctrs;
     Arena     * arena;
@@ -769,9 +773,18 @@ dumpCensus( Census *census )
     ssize_t count;
 
     printSample(true, census->time);
-    traceHeapProfSampleBegin(era);
+
+
+    if (RtsFlags.ProfFlags.doHeapProfile == HEAP_BY_LDV) {
+      traceHeapBioProfSampleBegin(era, census->rtime);
+    } else {
+      traceHeapProfSampleBegin(era);
+    }
+
+
 
 #if defined(PROFILING)
+
     /* change typecast to uint64_t to remove
      * print formatting warning. See #12636 */
     if (RtsFlags.ProfFlags.doHeapProfile == HEAP_BY_LDV) {
@@ -788,6 +801,23 @@ dumpCensus( Census *census )
                 (uint64_t)(census->prim * sizeof(W_)));
         fprintf(hp_file, "DRAG\t%" FMT_Word64 "\n",
                 (uint64_t)(census->drag_total * sizeof(W_)));
+
+
+        // Eventlog
+        traceHeapProfSampleString(0, "VOID",
+                (census->void_total * sizeof(W_)));
+        traceHeapProfSampleString(0, "LAG",
+                ((census->not_used - census->void_total) *
+                                     sizeof(W_)));
+        traceHeapProfSampleString(0, "USE",
+                ((census->used - census->drag_total) *
+                                     sizeof(W_)));
+        traceHeapProfSampleString(0, "INHERENT_USE",
+                (census->prim * sizeof(W_)));
+        traceHeapProfSampleString(0, "DRAG",
+                (census->drag_total * sizeof(W_)));
+
+        traceHeapProfSampleEnd(era);
         printSample(false, census->time);
         return;
     }
@@ -856,7 +886,8 @@ dumpCensus( Census *census )
                 rs->id = -(rs->id);
 
             // report in the unit of bytes: * sizeof(StgWord)
-            printRetainerSetShort(hp_file, rs, RtsFlags.ProfFlags.ccsLength);
+            printRetainerSetShort(hp_file, rs, (W_)count * sizeof(W_)
+                                             , RtsFlags.ProfFlags.ccsLength);
             break;
         }
 #endif
@@ -1156,6 +1187,8 @@ void heapCensus (Time t)
 
   census = &censuses[era];
   census->time  = mut_user_time_until(t);
+  census->rtime = TimeToNS(stat_getElapsedTime());
+
 
   // calculate retainer sets if necessary
 #if defined(PROFILING)
diff --git a/rts/RetainerSet.c b/rts/RetainerSet.c
index 59103ddf61..634035b0d0 100644
--- a/rts/RetainerSet.c
+++ b/rts/RetainerSet.c
@@ -17,6 +17,7 @@
 #include "RetainerSet.h"
 #include "Arena.h"
 #include "Profiling.h"
+#include "Trace.h"
 
 #include <string.h>
 
@@ -230,7 +231,7 @@ printRetainer(FILE *f, retainer ccs)
  * -------------------------------------------------------------------------- */
 #if defined(SECOND_APPROACH)
 void
-printRetainerSetShort(FILE *f, RetainerSet *rs, uint32_t max_length)
+printRetainerSetShort(FILE *f, RetainerSet *rs, W_ total_size, uint32_t max_length)
 {
     char tmp[max_length + 1];
     uint32_t size;
@@ -262,6 +263,7 @@ printRetainerSetShort(FILE *f, RetainerSet *rs, uint32_t max_length)
         }
     }
     fputs(tmp, f);
+    traceHeapProfSampleString(0, tmp, total_size);
 }
 #endif /* SECOND_APPROACH */
 
diff --git a/rts/RetainerSet.h b/rts/RetainerSet.h
index 2f9aeea644..44ec519c68 100644
--- a/rts/RetainerSet.h
+++ b/rts/RetainerSet.h
@@ -140,7 +140,7 @@ RetainerSet *addElement(retainer, RetainerSet *);
 
 #if defined(SECOND_APPROACH)
 // Prints a single retainer set.
-void printRetainerSetShort(FILE *, RetainerSet *, uint32_t);
+void printRetainerSetShort(FILE *, RetainerSet *, W_, uint32_t);
 #endif
 
 // Print the statistics on all the retainer sets.
diff --git a/rts/Trace.c b/rts/Trace.c
index d5c4319076..de647f762b 100644
--- a/rts/Trace.c
+++ b/rts/Trace.c
@@ -615,6 +615,12 @@ void traceHeapProfBegin(StgWord8 profile_id)
         postHeapProfBegin(profile_id);
     }
 }
+void traceHeapBioProfSampleBegin(StgInt era, StgWord64 time)
+{
+    if (eventlog_enabled) {
+        postHeapBioProfSampleBegin(era, time);
+    }
+}
 
 void traceHeapProfSampleBegin(StgInt era)
 {
diff --git a/rts/Trace.h b/rts/Trace.h
index 17e3dc7040..9985adc52f 100644
--- a/rts/Trace.h
+++ b/rts/Trace.h
@@ -288,6 +288,7 @@ void traceTaskDelete_ (Task       *task);
 
 void traceHeapProfBegin(StgWord8 profile_id);
 void traceHeapProfSampleBegin(StgInt era);
+void traceHeapBioProfSampleBegin(StgInt era, StgWord64 time);
 void traceHeapProfSampleEnd(StgInt era);
 void traceHeapProfSampleString(StgWord8 profile_id,
                                const char *label, StgWord residency);
@@ -336,6 +337,7 @@ void flushTrace(void);
 #define traceHeapProfBegin(profile_id) /* nothing */
 #define traceHeapProfCostCentre(ccID, label, module, srcloc, is_caf) /* nothing */
 #define traceHeapProfSampleBegin(era) /* nothing */
+#define traceHeapBioProfSampleBegin(era, time) /* nothing */
 #define traceHeapProfSampleEnd(era) /* nothing */
 #define traceHeapProfSampleCostCentre(profile_id, stack, residency) /* nothing */
 #define traceHeapProfSampleString(profile_id, label, residency) /* nothing */
diff --git a/rts/eventlog/EventLog.c b/rts/eventlog/EventLog.c
index 0651de268c..5c6a1ca48a 100644
--- a/rts/eventlog/EventLog.c
+++ b/rts/eventlog/EventLog.c
@@ -103,6 +103,7 @@ char *EventDesc[] = {
   [EVENT_HEAP_PROF_BEGIN]     = "Start of heap profile",
   [EVENT_HEAP_PROF_COST_CENTRE]   = "Cost center definition",
   [EVENT_HEAP_PROF_SAMPLE_BEGIN]  = "Start of heap profile sample",
+  [EVENT_HEAP_BIO_PROF_SAMPLE_BEGIN]  = "Start of heap profile (biographical) sample",
   [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",
@@ -425,6 +426,10 @@ init_event_types(void)
             eventTypes[t].size = 8;
             break;
 
+        case EVENT_HEAP_BIO_PROF_SAMPLE_BEGIN:
+            eventTypes[t].size = 16;
+            break;
+
         case EVENT_HEAP_PROF_SAMPLE_END:
             eventTypes[t].size = 8;
             break;
@@ -1224,6 +1229,17 @@ void postHeapProfSampleBegin(StgInt era)
     RELEASE_LOCK(&eventBufMutex);
 }
 
+
+void postHeapBioProfSampleBegin(StgInt era, StgWord64 time)
+{
+    ACQUIRE_LOCK(&eventBufMutex);
+    ensureRoomForEvent(&eventBuf, EVENT_HEAP_BIO_PROF_SAMPLE_BEGIN);
+    postEventHeader(&eventBuf, EVENT_HEAP_BIO_PROF_SAMPLE_BEGIN);
+    postWord64(&eventBuf, era);
+    postWord64(&eventBuf, time);
+    RELEASE_LOCK(&eventBufMutex);
+}
+
 void postHeapProfSampleEnd(StgInt era)
 {
     ACQUIRE_LOCK(&eventBufMutex);
diff --git a/rts/eventlog/EventLog.h b/rts/eventlog/EventLog.h
index 8935e61985..d8a614b45c 100644
--- a/rts/eventlog/EventLog.h
+++ b/rts/eventlog/EventLog.h
@@ -140,6 +140,7 @@ void postTaskDeleteEvent (EventTaskId taskId);
 void postHeapProfBegin(StgWord8 profile_id);
 
 void postHeapProfSampleBegin(StgInt era);
+void postHeapBioProfSampleBegin(StgInt era, StgWord64 time_ns);
 void postHeapProfSampleEnd(StgInt era);
 
 void postHeapProfSampleString(StgWord8 profile_id,