Writing events into separate buffers by kind.

Always recording events into buffers, but only writing them to the telemetry stream if they're enabled.

Copied from Perforce
 Change: 179136
 ServerID: perforce.ravenbrook.com

5 files changed, 83 insertions, 53 deletions

diff --git a/mps/code/arena.c b/mps/code/arena.c
index 8a83b26fe5a..d01329dd57d 100644
--- a/mps/code/arena.c
+++ b/mps/code/arena.c
@@ -219,6 +219,11 @@ Res ArenaCreateV(Arena *arenaReturn, ArenaClass class, va_list args)
   AVER(arenaReturn != NULL);
   AVERT(ArenaClass, class);
 
+  /* We must initialise the event subsystem very early, because event logging
+     will start as soon as anything interesting happens and expect to write
+     to the EventLast pointers. */
+  EventInit();
+
   /* Do initialization.  This will call ArenaInit (see .init.caller). */
   res = (*class->init)(&arena, class, args);
   if (res != ResOK)
diff --git a/mps/code/event.c b/mps/code/event.c
index 7657e71cc37..9018e8e9b33 100644
--- a/mps/code/event.c
+++ b/mps/code/event.c
@@ -37,46 +37,66 @@ static mps_io_t eventIO;
 static Count eventUserCount;
 static Serial EventInternSerial;
 
-char EventBuffer[EventBufferSIZE];      /* in which events are recorded */
-char *EventLast;                        /* points to last written event */
+/* Buffers in which events are recorded, from the top down. */
+char EventBuffer[EventKindLIMIT][EventBufferSIZE];
+
+/* Pointers to last written event in each buffer. */
+char *EventLast[EventKindLIMIT];
+
 EventControlSet EventKindControl;       /* Bit set used to control output. */
 
 
 /* EventFlush -- flush event buffer to the event stream */
 
-Res EventFlush(void)
+Res EventFlush(EventKind kind)
 {
   Res res;
   size_t size;
 
   AVER(eventInited);
+  AVER(0 <= kind && kind < EventKindLIMIT);
 
-  AVER(EventBuffer <= EventLast);
-  AVER(EventLast <= EventBuffer + EventBufferSIZE);
-  size = (size_t)(EventBuffer + EventBufferSIZE - EventLast);
-
-  /* Checking the size avoids creating the event stream when the arena is
-     destroyed and no events have been logged. */
-  if (size == 0)
-    return ResOK;
-
-  /* Ensure the IO stream is open.  We do this late so that no stream is
-     created if no events are enabled by telemetry control. */
-  if (!eventIOInited) {
-    res = (Res)mps_io_create(&eventIO);
-    if(res != ResOK) return res;
-    eventIOInited = TRUE;
-  }
+  AVER(EventBuffer[kind] <= EventLast[kind]);
+  AVER(EventLast[kind] <= EventBuffer[kind] + EventBufferSIZE);
 
-  /* Writing might be faster if the size is aligned to a multiple of the
-     C library or kernel's buffer size.  We could pad out the buffer with
-     a marker for this purpose. */
+  /* Is event logging enabled for this kind of event, or are or are we just
+     writing to the buffer for backtraces, cores, and other debugging? */
+  if (BS_IS_MEMBER(EventKindControl, kind)) {
+    
+    size = (size_t)(EventBuffer[kind] + EventBufferSIZE - EventLast[kind]);
+  
+    /* Checking the size avoids creating the event stream when the arena is
+       destroyed and no events have been logged. */
+    if (size == 0)
+      return ResOK;
+  
+    /* Ensure the IO stream is open.  We do this late so that no stream is
+       created if no events are enabled by telemetry control. */
+    if (!eventIOInited) {
+      res = (Res)mps_io_create(&eventIO);
+      if(res != ResOK)
+        goto failCreate;
+      eventIOInited = TRUE;
+    }
+  
+    /* Writing might be faster if the size is aligned to a multiple of the
+       C library or kernel's buffer size.  We could pad out the buffer with
+       a marker for this purpose. */
+  
+    res = (Res)mps_io_write(eventIO, (void *)EventLast[kind], size);
+    if (res != ResOK)
+      goto failWrite;
 
-  res = (Res)mps_io_write(eventIO, (void *)EventLast, size);
+  }
+  
+  res = ResOK;
+
+failWrite:
+failCreate:
 
   /* Flush the in-memory buffer whether or not we succeeded, so that we can
      record recent events there. */
-  EventLast = EventBuffer + EventBufferSIZE;
+  EventLast[kind] = EventBuffer[kind] + EventBufferSIZE;
 
   return res;
 }
@@ -84,13 +104,12 @@ Res EventFlush(void)
 
 /* EventSync -- synchronize the event stream with the buffers */
 
-Res EventSync(void)
+void EventSync(void)
 {
-  Res resEv, resIO;
-
-  resEv = EventFlush();
-  resIO = mps_io_flush(eventIO);
-  return (resEv != ResOK) ? resEv : resIO;
+  EventKind kind;
+  for (kind = 0; kind < EventKindLIMIT; ++kind)
+    (void)EventFlush(kind);
+  (void)mps_io_flush(eventIO);
 }
 
 
@@ -152,8 +171,11 @@ Res EventInit(void)
 
   /* Only if this is the first call. */
   if(!eventInited) { /* See .trans.log */
-    AVER(EventLast == NULL);
-    EventLast = EventBuffer + EventBufferSIZE;
+    EventKind kind;
+    for (kind = 0; kind < EventKindLIMIT; ++kind) {
+      AVER(EventLast[kind] == NULL);
+      EventLast[kind] = EventBuffer[kind] + EventBufferSIZE;
+    }
     eventUserCount = (Count)1;
     eventInited = TRUE;
     EventKindControl = (Word)mps_lib_telemetry_control();
@@ -174,7 +196,7 @@ void EventFinish(void)
   AVER(eventInited);
   AVER(eventUserCount > 0);
 
-  (void)EventSync();
+  EventSync();
 
   --eventUserCount;
 }
@@ -341,16 +363,19 @@ Res EventWrite(Event event, mps_lib_FILE *stream)
 void EventDump(mps_lib_FILE *stream)
 {
   Event event;
+  EventKind kind;
 
   AVER(stream != NULL);
 
-  for (event = (Event)EventLast;
-       event < (Event)(EventBuffer + EventBufferSIZE);
-       event = (Event)((char *)event + event->any.size)) {
-    /* Try to keep going even if there's an error, because this is used as a
-       backtrace and we'll take what we can get. */
-    (void)EventWrite(event, stream);
-    (void)WriteF(stream, "\n", NULL);
+  for (kind = 0; kind < EventKindLIMIT; ++kind) {
+    for (event = (Event)EventLast[kind];
+         event < (Event)(EventBuffer[kind] + EventBufferSIZE);
+         event = (Event)((char *)event + event->any.size)) {
+      /* Try to keep going even if there's an error, because this is used as a
+         backtrace and we'll take what we can get. */
+      (void)EventWrite(event, stream);
+      (void)WriteF(stream, "\n", NULL);
+    }
   }
 }
 
diff --git a/mps/code/event.h b/mps/code/event.h
index 7d02b947d3e..4694dc820c0 100644
--- a/mps/code/event.h
+++ b/mps/code/event.h
@@ -24,7 +24,7 @@
 typedef Word EventStringId;
 typedef Word EventControlSet;
 
-extern Res EventSync(void);
+extern void EventSync(void);
 extern Res EventInit(void);
 extern void EventFinish(void);
 extern EventControlSet EventControl(EventControlSet resetMask,
@@ -32,7 +32,7 @@ extern EventControlSet EventControl(EventControlSet resetMask,
 extern EventStringId EventInternString(const char *label);
 extern EventStringId EventInternGenString(size_t, const char *label);
 extern void EventLabelAddr(Addr addr, Word id);
-extern Res EventFlush(void);
+extern Res EventFlush(EventKind kind);
 extern Res EventDescribe(Event event, mps_lib_FILE *stream);
 extern Res EventWrite(Event event, mps_lib_FILE *stream);
 extern void EventDump(mps_lib_FILE *stream);
@@ -42,8 +42,8 @@ extern void EventDump(mps_lib_FILE *stream);
 
 /* Event writing support */
 
-extern char EventBuffer[EventBufferSIZE];  /* in which events are recorded */
-extern char *EventLast;                    /* points to last written event */
+extern char EventBuffer[EventKindLIMIT][EventBufferSIZE];
+extern char *EventLast[EventKindLIMIT];
 extern Word EventKindControl;
 
 
@@ -52,20 +52,21 @@ extern Word EventKindControl;
 
 #define EVENT_BEGIN(name, structSize) \
   BEGIN \
-    if(/* Event##name##Always && FIXME: depend on variety */ \
-       BS_IS_MEMBER(EventKindControl, (Index)Event##name##Kind)) { \
+    if(Event##name##Always) { /* FIXME: depend on variety */ \
       Event##name##Struct *_event; \
       size_t _size = size_tAlignUp(structSize, MPS_PF_ALIGN); \
-      if (_size > (size_t)(EventLast - EventBuffer)) \
-        EventFlush(); \
-      AVER(_size <= (size_t)(EventLast - EventBuffer)); \
-      _event = (void *)(EventLast - _size); \
+      if (_size > (size_t)(EventLast[Event##name##Kind] \
+                           - EventBuffer[Event##name##Kind])) \
+        EventFlush(Event##name##Kind); \
+      AVER(_size <= (size_t)(EventLast[Event##name##Kind] \
+                             - EventBuffer[Event##name##Kind])); \
+      _event = (void *)(EventLast[Event##name##Kind] - _size); \
       _event->code = Event##name##Code; \
       _event->size = (EventSize)_size; \
       EVENT_CLOCK(_event->clock);
 
 #define EVENT_END(name, size) \
-      EventLast -= _size; \
+      EventLast[Event##name##Kind] -= _size; \
     } \
   END
 
diff --git a/mps/code/global.c b/mps/code/global.c
index 9f06af73cca..bb666f4e44b 100644
--- a/mps/code/global.c
+++ b/mps/code/global.c
@@ -239,7 +239,6 @@ Res GlobalsInit(Globals arenaGlobals)
     RingInit(&arenaRing);
     ProtSetup();
   }
-  EventInit();
   arenaReleaseRingLock();
 
   arena = GlobalsArena(arenaGlobals);
diff --git a/mps/code/mpsi.c b/mps/code/mpsi.c
index 3a356f5d50a..8bf0aee3af2 100644
--- a/mps/code/mpsi.c
+++ b/mps/code/mpsi.c
@@ -1908,7 +1908,7 @@ void mps_telemetry_label(mps_addr_t addr, mps_word_t intern_id)
 void mps_telemetry_flush(void)
 {
   /* Telemetry does its own concurrency control, so none here. */
-  (void)EventSync();
+  EventSync();
 }