Writing event dumper to print recent events, and adding it to the default assertion handler.

NUL-terminating event strings to make them easier to print.

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

5 files changed, 74 insertions, 4 deletions

diff --git a/mps/code/event.c b/mps/code/event.c
index d3ea72277fc..4a3c7b1a457 100644
--- a/mps/code/event.c
+++ b/mps/code/event.c
@@ -48,6 +48,8 @@ Res EventFlush(void)
   Res res;
   size_t size;
 
+EventDump(mps_lib_get_stdout());
+
   AVER(eventInited);
 
   AVER(EventBuffer <= EventLast);
@@ -112,7 +114,9 @@ Res EventInit(void)
 #define EVENT_PARAM_CHECK_B(name, index, ident)
 #define EVENT_PARAM_CHECK_S(name, index, ident) \
   AVER(index + 1 == Event##name##ParamLIMIT); /* strings must come last */ \
-  AVER(offsetof(Event##name##Struct, f##index.str) + EventStringLengthMAX \
+  AVER(offsetof(Event##name##Struct, f##index.str) \
+       + EventStringLengthMAX \
+       + sizeof('\0') \
        <= EventSizeMAX);
 
 #define EVENT_PARAM_CHECK(name, index, sort, ident) \
@@ -231,6 +235,50 @@ void EventLabelAddr(Addr addr, EventStringId id)
 }
 
 
+void EventDump(mps_lib_FILE *stream)
+{
+  Event event;
+
+  AVER(stream != NULL);
+
+  for (event = (Event)EventLast;
+       event < (Event)(EventBuffer + EventBufferSIZE);
+       event = (Event)((char *)event + event->any.size)) {
+    EVENT_CLOCK_WRITE(stream, event->any.clock);
+
+    switch (event->any.code) {
+
+#define EVENT_DUMP_PARAM_MOST(name, index, sort, ident) \
+  " $"#sort, (WriteF##sort)event->name.f##index,
+#define EVENT_DUMP_PARAM_A EVENT_DUMP_PARAM_MOST
+#define EVENT_DUMP_PARAM_P EVENT_DUMP_PARAM_MOST
+#define EVENT_DUMP_PARAM_U EVENT_DUMP_PARAM_MOST
+#define EVENT_DUMP_PARAM_W EVENT_DUMP_PARAM_MOST
+#define EVENT_DUMP_PARAM_D EVENT_DUMP_PARAM_MOST
+#define EVENT_DUMP_PARAM_B(name, index, sort, ident) \
+  " $U", (WriteFU)event->name.f##index,
+#define EVENT_DUMP_PARAM_S(name, index, sort, ident) \
+  " $S", (WriteFS)event->name.f##index.str, /* FIXME: relies on NUL? */
+#define EVENT_DUMP_PARAM(name, index, sort, ident) \
+  EVENT_DUMP_PARAM_##sort(name, index, sort, ident)
+#define EVENT_DUMP(X, name, code, always, kind) \
+    case code: \
+      WriteF(stream, " "#name, \
+             EVENT_##name##_PARAMS(EVENT_DUMP_PARAM, name) \
+             NULL); \
+      break;
+    EVENT_LIST(EVENT_DUMP, X)
+
+    default:
+      WriteF(stream, " <unknown code $U>", event->any.code, NULL);
+      /* FIXME: Should dump contents in hex. */
+      break;
+    }
+    WriteF(stream, "\n", NULL);
+  }
+}
+
+
 #else /* EVENT, not */
 
 
@@ -285,6 +333,12 @@ void (EventLabelAddr)(Addr addr, Word id)
 }
 
 
+extern void EventDump(mps_lib_FILE *stream)
+{
+  UNUSED(stream);
+}
+
+
 #endif /* EVENT */
 
 
diff --git a/mps/code/event.h b/mps/code/event.h
index d4c2ce83b95..1265aa22d19 100644
--- a/mps/code/event.h
+++ b/mps/code/event.h
@@ -18,6 +18,7 @@
 #include "eventcom.h"
 #include "mpm.h"
 #include "eventdef.h"
+#include "mpslib.h"
 
 
 typedef Word EventStringId;
@@ -32,6 +33,7 @@ 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 void EventDump(mps_lib_FILE *stream);
 
 
 #ifdef EVENT
@@ -78,12 +80,13 @@ extern Word EventKindControl;
   BEGIN \
     size_t _string_len = (length); \
     size_t size; \
-    size = offsetof(Event##name##Struct, f1.str) + _string_len; \
+    size = offsetof(Event##name##Struct, f1.str) + _string_len + sizeof('\0'); \
     EVENT_BEGIN(name, size) \
       _event->f0 = (p0); \
-      AVER(_string_len < EventStringLengthMAX); \
+      AVER(_string_len <= EventStringLengthMAX); \
       _event->f1.len = (EventStringLen)_string_len; \
       mps_lib_memcpy(_event->f1.str, (string), _string_len); \
+      _event->f1.str[_string_len] = '\0'; \
     EVENT_END(name, size); \
   END
 
diff --git a/mps/code/eventcom.h b/mps/code/eventcom.h
index d572c56bdc8..89b216132b1 100644
--- a/mps/code/eventcom.h
+++ b/mps/code/eventcom.h
@@ -33,6 +33,12 @@ typedef unsigned __int64 EventClock;
   END
 
 #define EVENT_CLOCK_PRINT(stream, clock) fprintf(stream, "%llu", clock)
+#if defined(MPS_ARCH_I3)
+#define EVENT_CLOCK_WRITE(stream, clock) \
+  WriteF(stream, "$W$W", (WriteFW)((clock) >> 32), (WriteFW)clock, NULL)
+#else /* I6 */
+  WriteF(stream, "$W", (WriteFW)(clock), NULL)
+#endif
 
 /* http://clang.llvm.org/docs/LanguageExtensions.html#builtins */
 #elif defined(MPS_BUILD_LL)
@@ -72,6 +78,9 @@ __extension__ typedef unsigned long long EventClock;
           (unsigned long)((clock) >> 32), \
           (unsigned long)(clock))
 
+#define EVENT_CLOCK_WRITE(stream, clock) \
+  WriteF(stream, "$W$W", (WriteFW)((clock) >> 32), (WriteFW)clock, NULL)
+
 #endif /* Intel, GCC or Clang */
 
 /* no fast clock, use plinth, probably from the C library */
diff --git a/mps/code/mpsliban.c b/mps/code/mpsliban.c
index 8b44f684a8c..d56073976e9 100644
--- a/mps/code/mpsliban.c
+++ b/mps/code/mpsliban.c
@@ -25,6 +25,7 @@
 #include "mpslib.h"
 
 #include "mpstd.h"
+#include "event.h"
 
 #ifdef MPS_OS_XC
 #include "osxc.h"
@@ -66,7 +67,8 @@ int mps_lib_fputs(const char *s, mps_lib_FILE *stream)
 void mps_lib_assert_fail(const char *message)
 {
   fflush(stdout); /* synchronize */
-  fprintf(stderr, "\nMPS ASSERTION FAILURE: %s\n", message);
+  fprintf(stderr, "\nMPS ASSERTION FAILURE: %s\n\nRECENT EVENTS:\n", message);
+  EventDump((mps_lib_FILE *)stderr);
   fflush(stderr); /* make sure the message is output */
   abort();
 }
diff --git a/mps/code/trace.c b/mps/code/trace.c
index c362a4809cf..d5aff875030 100644
--- a/mps/code/trace.c
+++ b/mps/code/trace.c
@@ -814,6 +814,8 @@ static void traceReclaim(Trace trace)
     PoolTraceEnd(pool, trace);
   }
 
+NOTREACHED;
+
   ArenaCompact(arena, trace);  /* let arenavm drop chunks */
 
   TracePostMessage(trace);  /* trace end */