eventlog: Repost initialisation events when eventlog restartswip/ghc-eventlog-repost

If startEventlog is called after the program has already started running
then quite a few useful events are missing from the eventlog because
they are only posted when the program starts. This patch adds a
mechanism to declare that an event should be reposted everytime the
startEventlog function is called.

Now in EventLog.c there is a global list of functions called
`eventlog_header_funcs` which stores a list of functions which should be
called everytime the eventlog starts.

When calling `postInitEvent`, the event will not only be immediately
posted to the eventlog but also added to the global list.

When startEventLog is called, the list is traversed and the events
reposted.

5 files changed, 93 insertions, 9 deletions

diff --git a/rts/Profiling.c b/rts/Profiling.c
index c84296cd5d..e96f6b2b93 100644
--- a/rts/Profiling.c
+++ b/rts/Profiling.c
@@ -201,7 +201,7 @@ void initProfiling (void)
         initTimeProfiling();
     }
 
-    dumpCostCentresToEventLog();
+    traceInitEvent(dumpCostCentresToEventLog);
 }
 
 
diff --git a/rts/RtsStartup.c b/rts/RtsStartup.c
index 5cad851b80..371c96d08c 100644
--- a/rts/RtsStartup.c
+++ b/rts/RtsStartup.c
@@ -300,8 +300,8 @@ hs_init_ghc(int *argc, char **argv[], RtsConfig rts_config)
     initScheduler();
 
     /* Trace some basic information about the process */
-    traceWallClockTime();
-    traceOSProcessInfo();
+    traceInitEvent(traceWallClockTime);
+    traceInitEvent(traceOSProcessInfo);
     flushTrace();
 
     /* initialize the storage manager */
@@ -370,7 +370,7 @@ hs_init_ghc(int *argc, char **argv[], RtsConfig rts_config)
 #if defined(PROFILING)
     initProfiling();
 #endif
-    dumpIPEToEventLog();
+    traceInitEvent(dumpIPEToEventLog);
     initHeapProfiling();
 
     /* start the virtual timer 'subsystem'. */
diff --git a/rts/Trace.h b/rts/Trace.h
index f9d677d063..26fa89c693 100644
--- a/rts/Trace.h
+++ b/rts/Trace.h
@@ -108,6 +108,8 @@ void traceEnd (void);
 void traceSchedEvent_ (Capability *cap, EventTypeNum tag,
                        StgTSO *tso, StgWord info1, StgWord info2);
 
+#define traceInitEvent(event) postInitEvent(event)
+
 /*
  * Record a GC event
  */
@@ -332,6 +334,7 @@ void flushTrace(void);
 #else /* !TRACING */
 
 #define traceSchedEvent(cap, tag, tso, other) /* nothing */
+#define traceInitEvent(event) /* nothing */
 #define traceSchedEvent2(cap, tag, tso, other, info) /* nothing */
 #define traceGcEvent(cap, tag) /* nothing */
 #define traceGcEventAtT(cap, ts, tag) /* nothing */
@@ -354,7 +357,7 @@ void flushTrace(void);
 #define traceCapEvent(cap, tag) /* nothing */
 #define traceCapsetEvent(tag, capset, info) /* nothing */
 #define traceWallClockTime_() /* nothing */
-#define traceOSProcessInfo_() /* nothing */
+#define traceOSProcessInfo_()  /* nothing */
 #define traceSparkCounters_(cap, counters, remaining) /* nothing */
 #define traceTaskCreate_(taskID, cap) /* nothing */
 #define traceTaskMigrate_(taskID, cap, new_cap) /* nothing */
diff --git a/rts/eventlog/EventLog.c b/rts/eventlog/EventLog.c
index 0a1ed09f6f..80ed91960d 100644
--- a/rts/eventlog/EventLog.c
+++ b/rts/eventlog/EventLog.c
@@ -89,6 +89,10 @@ bool eventlog_enabled; // protected by state_change_mutex to ensure
 
 static const EventLogWriter *event_log_writer = NULL;
 
+// List of initialisation functions which are called each time the
+// eventlog is restarted
+static eventlog_init_func_t *eventlog_header_funcs = NULL;
+
 #define EVENT_LOG_SIZE 2 * (1024 * 1024) // 2MB
 
 static int flushCount;
@@ -211,6 +215,8 @@ static void closeBlockMarker(EventsBuf *ebuf);
 static StgBool hasRoomForEvent(EventsBuf *eb, EventTypeNum eNum);
 static StgBool hasRoomForVariableEvent(EventsBuf *eb, uint32_t payload_bytes);
 
+static void freeEventLoggingBuffer(void);
+
 static void ensureRoomForEvent(EventsBuf *eb, EventTypeNum tag);
 static int ensureRoomForVariableEvent(EventsBuf *eb, StgWord16 size);
 
@@ -602,6 +608,50 @@ postHeaderEvents(void)
     postInt32(&eventBuf, EVENT_DATA_BEGIN);
 }
 
+// These events will be reposted everytime we restart the eventlog
+void
+postInitEvent(EventlogInitPost post_init){
+    ACQUIRE_LOCK(&state_change_mutex);
+
+    // Add the event to the global list of events that will be rerun when
+    // the eventlog is restarted.
+    eventlog_init_func_t * new_func;
+    new_func = stgMallocBytes(sizeof(eventlog_init_func_t),"eventlog_init_func");
+    new_func->init_func = post_init;
+    new_func->next = eventlog_header_funcs;
+    eventlog_header_funcs = new_func;
+
+    RELEASE_LOCK(&state_change_mutex);
+    // Actually post it
+    (*post_init)();
+    return;
+}
+
+// Post events again which happened at the start of the eventlog, added by
+// postInitEvent.
+static void repostInitEvents(void){
+    eventlog_init_func_t * current_event = eventlog_header_funcs;
+    for (; current_event != NULL; current_event = current_event->next) {
+      (*(current_event->init_func))();
+    }
+    return;
+}
+
+// Clear the eventlog_header_funcs list and free the memory
+void resetInitEvents(void){
+    eventlog_init_func_t * tmp;
+    eventlog_init_func_t * current_event = eventlog_header_funcs;
+    for (; current_event != NULL; ) {
+      tmp = current_event;
+      current_event = current_event->next;
+      stgFree(tmp);
+    }
+    eventlog_header_funcs = NULL;
+    return;
+
+}
+
+
 static uint32_t
 get_n_capabilities(void)
 {
@@ -689,6 +739,7 @@ startEventLogging(const EventLogWriter *ev_writer)
     event_log_writer = ev_writer;
     bool ret = startEventLogging_();
     eventlog_enabled = true;
+    repostInitEvents();
     RELEASE_LOCK(&state_change_mutex);
     return ret;
 }
@@ -697,11 +748,12 @@ startEventLogging(const EventLogWriter *ev_writer)
 void
 restartEventLogging(void)
 {
-    freeEventLogging();
+    freeEventLoggingBuffer();
     stopEventLogWriter();
     initEventLogging();  // allocate new per-capability buffers
     if (event_log_writer != NULL) {
         startEventLogging_(); // child starts its own eventlog
+        repostInitEvents();   // Repost the initialisation events
     }
 }
 
@@ -782,15 +834,21 @@ moreCapEventBufs (uint32_t from, uint32_t to)
     }
 }
 
-
-void
-freeEventLogging(void)
+static void
+freeEventLoggingBuffer(void)
 {
     if (capEventBuf != NULL)  {
         stgFree(capEventBuf);
     }
 }
 
+void
+freeEventLogging(void)
+{
+    freeEventLoggingBuffer();
+    resetInitEvents();
+}
+
 /*
  * Post an event message to the capability's eventlog buffer.
  * If the buffer is full, prints out the buffer and clears it.
diff --git a/rts/eventlog/EventLog.h b/rts/eventlog/EventLog.h
index b0675db14d..665e0381f0 100644
--- a/rts/eventlog/EventLog.h
+++ b/rts/eventlog/EventLog.h
@@ -34,6 +34,22 @@ void flushLocalEventsBuf(Capability *cap);
 void flushAllCapsEventsBufs(void);
 void flushAllEventsBufs(Capability *cap);
 
+typedef void (*EventlogInitPost)(void);
+
+// Events which are emitted during program start-up should be wrapped with
+// postInitEvent so that when the eventlog is restarted (possibly by an external
+// writer) then these events appear again at the start of the log.
+void postInitEvent(EventlogInitPost post_init);
+
+// Clear the init events buffer on program exit
+void resetInitEvents(void);
+
+typedef struct eventlog_init_func {
+    EventlogInitPost init_func;
+    struct eventlog_init_func * next;
+} eventlog_init_func_t;
+
+
 /*
  * Post a scheduler event to the capability's event buffer (an event
  * that has an associated thread).
@@ -207,6 +223,13 @@ INLINE_HEADER void postEvent (Capability *cap  STG_UNUSED,
                               EventTypeNum tag STG_UNUSED)
 { /* nothing */ }
 
+typedef void (*EventlogInitPost)(void);
+
+INLINE_HEADER void postInitEvent(EventlogInitPost f STG_UNUSED)
+{ /* nothing */ } ;
+
+
+
 INLINE_HEADER void postEventNoCap (EventTypeNum tag STG_UNUSED)
 { /* nothing */ }