Add a way to generate tracing events programmatically
authorSimon Marlow <marlowsd@gmail.com>
Fri, 25 Sep 2009 15:02:43 +0000 (15:02 +0000)
committerSimon Marlow <marlowsd@gmail.com>
Fri, 25 Sep 2009 15:02:43 +0000 (15:02 +0000)
added:

 primop  TraceEventOp "traceEvent#" GenPrimOp
   Addr# -> State# s -> State# s
   { Emits an event via the RTS tracing framework.  The contents
     of the event is the zero-terminated byte string passed as the first
     argument.  The event will be emitted either to the .eventlog file,
     or to stderr, depending on the runtime RTS flags. }

and added the required RTS functionality to support it.  Also a bit of
refactoring in the RTS tracing code.

compiler/prelude/primops.txt.pp
includes/rts/EventLogFormat.h
includes/rts/Flags.h
includes/stg/MiscClosures.h
rts/Linker.c
rts/PrimOps.cmm
rts/RtsFlags.c
rts/Trace.c
rts/Trace.h
rts/eventlog/EventLog.c
rts/eventlog/EventLog.h

index 0af4c88..3aa093a 100644 (file)
@@ -1769,6 +1769,16 @@ pseudoop   "unsafeCoerce#"
 -- the wrapper had type () -> (), and hence the wrapper de-constructed the (), the worker re-constructed
 -- a new (), with the result that the code ended up with "case () of (a,b) -> ...".
 
+primop  TraceEventOp "traceEvent#" GenPrimOp
+   Addr# -> State# s -> State# s
+   { Emits an event via the RTS tracing framework.  The contents
+     of the event is the zero-terminated byte string passed as the first
+     argument.  The event will be emitted either to the .eventlog file,
+     or to stderr, depending on the runtime RTS flags. }
+   with
+   has_side_effects = True
+   out_of_line      = True
+
 ------------------------------------------------------------------------
 ---                                                                  ---
 ------------------------------------------------------------------------
index c4551c1..eaad0f2 100644 (file)
 #define EVENT_LOG_MSG             16 /* (message ...)          */
 #define EVENT_STARTUP             17 /* (num_capabilities)     */
 #define EVENT_BLOCK_MARKER        18 /* (size, end_time, capability) */
+#define EVENT_USER_MSG            19 /* (message ...)          */
 
-#define NUM_EVENT_TAGS            19
+#define NUM_EVENT_TAGS            20
 
 #if 0  /* DEPRECATED EVENTS: */
 #define EVENT_CREATE_SPARK        13 /* (cap, thread) */
index 733318a..e78bed2 100644 (file)
@@ -117,8 +117,12 @@ struct PROFILING_FLAGS {
 
 };
 
+#define TRACE_NONE      0
+#define TRACE_EVENTLOG  1
+#define TRACE_STDERR    2
+
 struct TRACE_FLAGS {
-    rtsBool trace_stderr;
+    int tracing;
     rtsBool timestamp;      /* show timestamp in stderr output */
 
     rtsBool scheduler;      /* trace scheduler events */
index 031c74b..24323cd 100644 (file)
@@ -593,6 +593,7 @@ RTS_FUN(stg_getSparkzh);
 RTS_FUN(stg_noDuplicatezh);
 
 RTS_FUN(stg_traceCcszh);
+RTS_FUN(stg_traceEventzh);
 
 /* Other misc stuff */
 // See wiki:Commentary/Compiler/Backends/PprC#Prototypes
index d7e7886..6cb61f4 100644 (file)
@@ -823,6 +823,7 @@ typedef struct _RtsSymbolVal {
       SymI_HasProto(stopTimer)                         \
       SymI_HasProto(n_capabilities)                    \
       SymI_HasProto(stg_traceCcszh)                     \
+      SymI_HasProto(stg_traceEventzh)                   \
       RTS_USER_SIGNALS_SYMBOLS
 
 
index baadca4..d5b6c46 100644 (file)
@@ -1894,3 +1894,13 @@ stg_getSparkzh
    }
 #endif
 }
+
+stg_traceEventzh
+{
+   W_ msg;
+   msg = R1;
+#if defined(TRACING) || defined(DEBUG)
+   foreign "C" traceUserMsg(MyCapability() "ptr", msg "ptr") [];
+#endif
+   jump %ENTRY_CODE(Sp(0));
+}
index 397ea8b..1403801 100644 (file)
@@ -135,7 +135,7 @@ void initRtsFlagsDefaults(void)
 #endif
 
 #ifdef TRACING
-    RtsFlags.TraceFlags.trace_stderr  = rtsFalse;
+    RtsFlags.TraceFlags.tracing       = TRACE_NONE;
     RtsFlags.TraceFlags.timestamp     = rtsFalse;
     RtsFlags.TraceFlags.scheduler     = rtsFalse;
 #endif
@@ -652,7 +652,7 @@ error = rtsTrue;
                  }
                   // -Dx also turns on -v.  Use -l to direct trace
                   // events to the .eventlog file instead.
-                  RtsFlags.TraceFlags.trace_stderr = rtsTrue;
+                  RtsFlags.TraceFlags.tracing = TRACE_STDERR;
                  break;
              }
 #endif
@@ -760,20 +760,21 @@ error = rtsTrue;
 #ifdef TRACING
                 switch(rts_argv[arg][2]) {
                case '\0':
-                  RtsFlags.TraceFlags.trace_stderr = rtsFalse;
-                  break;
+                    RtsFlags.TraceFlags.tracing = TRACE_EVENTLOG;
+                    break;
                 case 's':
-                  RtsFlags.TraceFlags.scheduler = rtsTrue;
-                  break;
+                    RtsFlags.TraceFlags.tracing = TRACE_EVENTLOG;
+                    RtsFlags.TraceFlags.scheduler = rtsTrue;
+                    break;
                default:
                    errorBelch("unknown RTS option: %s",rts_argv[arg]);
                    error = rtsTrue;
                    break;
                 }
 #else
-                  errorBelch("not built for: -eventlog");
+                errorBelch("not built for: -eventlog");
 #endif
-                  break;
+                break;
 
              case 'P': /* detailed cost centre profiling (time/alloc) */
              case 'p': /* cost centre profiling (time/alloc) */
@@ -1080,7 +1081,7 @@ error = rtsTrue;
                 switch(rts_argv[arg][2]) {
 #ifdef TRACING
                 case '\0':
-                    RtsFlags.TraceFlags.trace_stderr = rtsTrue;
+                    RtsFlags.TraceFlags.tracing = TRACE_STDERR;
                     break;
                case 't':
                    RtsFlags.TraceFlags.timestamp = rtsTrue;
index 7eabce9..a26a919 100644 (file)
@@ -85,24 +85,7 @@ void initTracing (void)
     DEBUG_FLAG(sparks,       DEBUG_sparks);
 #endif
 
-    eventlog_enabled = !RtsFlags.TraceFlags.trace_stderr && (
-                       TRACE_sched
-#ifdef DEBUG
-                       | DEBUG_sched
-                       | DEBUG_interp
-                       | DEBUG_weak
-                       | DEBUG_gccafs
-                       | DEBUG_gc
-                       | DEBUG_block_alloc
-                       | DEBUG_sanity
-                       | DEBUG_stable
-                       | DEBUG_stm
-                       | DEBUG_prof
-                       | DEBUG_linker
-                       | DEBUG_squeeze
-                       | DEBUG_hpc
-#endif
-        );
+    eventlog_enabled = RtsFlags.TraceFlags.tracing == TRACE_EVENTLOG;
 
     if (eventlog_enabled) {
         initEventLogging();
@@ -225,7 +208,7 @@ void traceSchedEvent_ (Capability *cap, EventTypeNum tag,
                       StgTSO *tso, StgWord64 other)
 {
 #ifdef DEBUG
-    if (RtsFlags.TraceFlags.trace_stderr) {
+    if (RtsFlags.TraceFlags.tracing == TRACE_STDERR) {
         traceSchedEvent_stderr(cap, tag, tso, other);
     } else
 #endif
@@ -254,7 +237,7 @@ void traceCap_(Capability *cap, char *msg, ...)
     va_start(ap,msg);
     
 #ifdef DEBUG
-    if (RtsFlags.TraceFlags.trace_stderr) {
+    if (RtsFlags.TraceFlags.tracing == TRACE_STDERR) {
         traceCap_stderr(cap, msg, ap);
     } else
 #endif
@@ -284,7 +267,7 @@ void trace_(char *msg, ...)
     va_start(ap,msg);
 
 #ifdef DEBUG
-    if (RtsFlags.TraceFlags.trace_stderr) {
+    if (RtsFlags.TraceFlags.tracing == TRACE_STDERR) {
         trace_stderr(msg, ap);
     } else
 #endif
@@ -295,10 +278,24 @@ void trace_(char *msg, ...)
     va_end(ap);
 }
 
+void traceUserMsg(Capability *cap, char *msg)
+{
+#ifdef DEBUG
+    if (RtsFlags.TraceFlags.tracing == TRACE_STDERR) {
+        traceCap_stderr(cap, msg, NULL);
+    } else
+#endif
+    {
+        if (eventlog_enabled) {
+            postUserMsg(cap, msg);
+        }
+    }
+}
+
 void traceThreadStatus_ (StgTSO *tso USED_IF_DEBUG)
 {
 #ifdef DEBUG
-    if (RtsFlags.TraceFlags.trace_stderr) {
+    if (RtsFlags.TraceFlags.tracing == TRACE_STDERR) {
         printThreadStatus(tso);
     } else
 #endif
index 775f235..f422b5f 100644 (file)
@@ -104,6 +104,11 @@ void traceCap_(Capability *cap, char *msg, ...);
 void trace_(char *msg, ...);
 
 /* 
+ * A message or event emitted by the program
+ */
+void traceUserMsg(Capability *cap, char *msg);
+
+/* 
  * Emit a debug message (only when DEBUG is defined)
  */
 #ifdef DEBUG
index e5e71e6..65eff8a 100644 (file)
@@ -62,6 +62,7 @@ char *EventDesc[] = {
   [EVENT_REQUEST_PAR_GC]      = "Request parallel GC",
   [EVENT_CREATE_SPARK_THREAD] = "Create spark thread",
   [EVENT_LOG_MSG]             = "Log message",
+  [EVENT_USER_MSG]            = "User message",
   [EVENT_STARTUP]             = "Startup",
   [EVENT_BLOCK_MARKER]        = "Block marker"
 };
@@ -82,7 +83,7 @@ static void printAndClearEventBuf (EventsBuf *eventsBuf);
 
 static void postEventType(EventsBuf *eb, EventType *et);
 
-static void postLogMsg(EventsBuf *eb, char *msg, va_list ap);
+static void postLogMsg(EventsBuf *eb, EventTypeNum type, char *msg, va_list ap);
 
 static void postBlockMarker(EventsBuf *eb);
 static void closeBlockMarker(EventsBuf *ebuf);
@@ -242,6 +243,7 @@ initEventLogging(void)
             break;
 
         case EVENT_LOG_MSG:          // (msg)
+        case EVENT_USER_MSG:         // (msg)
             eventTypes[t].size = 0xffff;
             break;
 
@@ -393,7 +395,7 @@ postSchedEvent (Capability *cap,
 
 #define BUF 512
 
-void postLogMsg(EventsBuf *eb, char *msg, va_list ap)
+void postLogMsg(EventsBuf *eb, EventTypeNum type, char *msg, va_list ap)
 {
     char buf[BUF];
     nat size;
@@ -409,7 +411,7 @@ void postLogMsg(EventsBuf *eb, char *msg, va_list ap)
         printAndClearEventBuf(eb);
     }
 
-    postEventHeader(eb, EVENT_LOG_MSG);
+    postEventHeader(eb, type);
     postPayloadSize(eb, size);
     postBuf(eb,(StgWord8*)buf,size);
 }
@@ -417,15 +419,20 @@ void postLogMsg(EventsBuf *eb, char *msg, va_list ap)
 void postMsg(char *msg, va_list ap)
 {
     ACQUIRE_LOCK(&eventBufMutex);
-    postLogMsg(&eventBuf, msg, ap);
+    postLogMsg(&eventBuf, EVENT_LOG_MSG, msg, ap);
     RELEASE_LOCK(&eventBufMutex);
 }
 
 void postCapMsg(Capability *cap, char *msg, va_list ap)
 {
-    postLogMsg(&capEventBuf[cap->no], msg, ap);
+    postLogMsg(&capEventBuf[cap->no], EVENT_LOG_MSG, msg, ap);
 }
 
+void postUserMsg(Capability *cap, char *msg)
+{
+    postLogMsg(&capEventBuf[cap->no], EVENT_USER_MSG, msg, NULL);
+}    
+
 void closeBlockMarker (EventsBuf *ebuf)
 {
     StgInt8* save_pos;
index 364d12a..557ee77 100644 (file)
@@ -33,6 +33,8 @@ void postSchedEvent(Capability *cap, EventTypeNum tag,
 
 void postMsg(char *msg, va_list ap);
 
+void postUserMsg(Capability *cap, char *msg);
+
 void postCapMsg(Capability *cap, char *msg, va_list ap);
 
 #else /* !TRACING */