Move GC tracing into a separate trace class

Previously GC was included in the scheduler trace class. It can be
enabled specifically with +RTS -vg or -lg, though note that both -v
and -l on their own now default to a sensible set of trace classes,
currently: scheduler, gc and sparks.

4 files changed, 93 insertions, 70 deletions

diff --git a/rts/RtsFlags.c b/rts/RtsFlags.c
index abeffc79a6..2a1f4040a7 100644
--- a/rts/RtsFlags.c
+++ b/rts/RtsFlags.c
@@ -163,6 +163,7 @@ void initRtsFlagsDefaults(void)
     RtsFlags.TraceFlags.tracing       = TRACE_NONE;
     RtsFlags.TraceFlags.timestamp     = rtsFalse;
     RtsFlags.TraceFlags.scheduler     = rtsFalse;
+    RtsFlags.TraceFlags.gc            = rtsFalse;
     RtsFlags.TraceFlags.sparks        = rtsFalse;
 #endif
 
@@ -289,6 +290,7 @@ usage_text[] = {
 #  endif
 "             where [flags] can contain:",
 "                s    scheduler events",
+"                g    GC events",
 "                p    par spark events",
 #  ifdef DEBUG
 "                t    add time stamps (only useful with -v)",
@@ -1452,6 +1454,7 @@ static void read_trace_flags(char *arg)
      * scheduler or GC tracing.
      */
     RtsFlags.TraceFlags.scheduler = rtsTrue;
+    RtsFlags.TraceFlags.gc        = rtsTrue;
     RtsFlags.TraceFlags.sparks = rtsTrue;
 
     for (c  = arg; *c != '\0'; c++) {
@@ -1463,6 +1466,7 @@ static void read_trace_flags(char *arg)
             break;
         case 'a':
             RtsFlags.TraceFlags.scheduler = enabled;
+            RtsFlags.TraceFlags.gc        = enabled;
             RtsFlags.TraceFlags.sparks = enabled;
             enabled = rtsTrue;
             break;
@@ -1480,7 +1484,7 @@ static void read_trace_flags(char *arg)
             enabled = rtsTrue;
             break;
         case 'g':
-            // ignored for backwards-compat
+            RtsFlags.TraceFlags.gc        = enabled;
             enabled = rtsTrue;
             break;
         default:
diff --git a/rts/Trace.c b/rts/Trace.c
index 7d856d6dd7..7f70957fcf 100644
--- a/rts/Trace.c
+++ b/rts/Trace.c
@@ -47,6 +47,7 @@ int DEBUG_sparks;
 
 // events
 int TRACE_sched;
+int TRACE_gc;
 int TRACE_spark;
 
 #ifdef THREADED_RTS
@@ -91,6 +92,11 @@ void initTracing (void)
         RtsFlags.TraceFlags.scheduler ||
         RtsFlags.DebugFlags.scheduler;
 
+    // -Dg turns on gc tracing too
+    TRACE_gc =
+        RtsFlags.TraceFlags.gc ||
+        RtsFlags.DebugFlags.gc;
+
     // -Dr turns on spark tracing
     TRACE_spark =
         RtsFlags.TraceFlags.sparks ||
@@ -222,27 +228,6 @@ static void traceSchedEvent_stderr (Capability *cap, EventTypeNum tag,
     case EVENT_SHUTDOWN:        // (cap)
         debugBelch("cap %d: shutting down\n", cap->no);
         break;
-    case EVENT_REQUEST_SEQ_GC:  // (cap)
-        debugBelch("cap %d: requesting sequential GC\n", cap->no);
-        break;
-    case EVENT_REQUEST_PAR_GC:  // (cap)
-        debugBelch("cap %d: requesting parallel GC\n", cap->no);
-        break;
-    case EVENT_GC_START:        // (cap)
-        debugBelch("cap %d: starting GC\n", cap->no);
-        break;
-    case EVENT_GC_END:          // (cap)
-        debugBelch("cap %d: finished GC\n", cap->no);
-        break;
-    case EVENT_GC_IDLE:        // (cap)
-        debugBelch("cap %d: GC idle\n", cap->no);
-        break;
-    case EVENT_GC_WORK:          // (cap)
-        debugBelch("cap %d: GC working\n", cap->no);
-        break;
-    case EVENT_GC_DONE:          // (cap)
-        debugBelch("cap %d: GC done\n", cap->no);
-        break;
     default:
         debugBelch("cap %d: thread %lu: event %d\n\n", 
                    cap->no, (lnat)tso->id, tag);
@@ -266,6 +251,56 @@ void traceSchedEvent_ (Capability *cap, EventTypeNum tag,
     }
 }
 
+#ifdef DEBUG
+static void traceGcEvent_stderr (Capability *cap, EventTypeNum tag)
+{
+    ACQUIRE_LOCK(&trace_utx);
+
+    tracePreface();
+    switch (tag) {
+      case EVENT_REQUEST_SEQ_GC:  // (cap)
+          debugBelch("cap %d: requesting sequential GC\n", cap->no);
+          break;
+      case EVENT_REQUEST_PAR_GC:  // (cap)
+          debugBelch("cap %d: requesting parallel GC\n", cap->no);
+          break;
+      case EVENT_GC_START:        // (cap)
+          debugBelch("cap %d: starting GC\n", cap->no);
+          break;
+      case EVENT_GC_END:          // (cap)
+          debugBelch("cap %d: finished GC\n", cap->no);
+          break;
+      case EVENT_GC_IDLE:         // (cap)
+          debugBelch("cap %d: GC idle\n", cap->no);
+          break;
+      case EVENT_GC_WORK:         // (cap)
+          debugBelch("cap %d: GC working\n", cap->no);
+          break;
+      case EVENT_GC_DONE:         // (cap)
+          debugBelch("cap %d: GC done\n", cap->no);
+          break;
+      default:
+          barf("traceGcEvent: unknown event tag %d", tag);
+          break;
+    }
+
+    RELEASE_LOCK(&trace_utx);
+}
+#endif
+
+void traceGcEvent_ (Capability *cap, EventTypeNum tag)
+{
+#ifdef DEBUG
+    if (RtsFlags.TraceFlags.tracing == TRACE_STDERR) {
+        traceGcEvent_stderr(cap, tag);
+    } else
+#endif
+    {
+        /* currently all GC events are nullary events */
+        postEvent(cap, tag);
+    }
+}
+
 void traceCapsetModify_ (EventTypeNum tag,
                          CapsetID capset,
                          StgWord32 other)
@@ -360,19 +395,6 @@ void traceSparkCounters_ (Capability *cap,
     }
 }
 
-
-void traceEvent_ (Capability *cap, EventTypeNum tag)
-{
-#ifdef DEBUG
-    if (RtsFlags.TraceFlags.tracing == TRACE_STDERR) {
-        traceSchedEvent_stderr(cap, tag, 0, 0, 0);
-    } else
-#endif
-    {
-        postEvent(cap,tag);
-    }
-}
-
 #ifdef DEBUG
 static void traceCap_stderr(Capability *cap, char *msg, va_list ap)
 {
diff --git a/rts/Trace.h b/rts/Trace.h
index 34efdf6d87..676fa58515 100644
--- a/rts/Trace.h
+++ b/rts/Trace.h
@@ -62,6 +62,7 @@ extern int DEBUG_sparks;
 
 // events
 extern int TRACE_sched;
+extern int TRACE_gc;
 extern int TRACE_spark;
 
 // -----------------------------------------------------------------------------
@@ -102,16 +103,15 @@ void traceEnd (void);
 void traceSchedEvent_ (Capability *cap, EventTypeNum tag, 
                        StgTSO *tso, StgWord info1, StgWord info2);
 
-
-/*
- * Record a nullary event
+/* 
+ * Record a GC event
  */
-#define traceEvent(cap, tag)                    \
-    if (RTS_UNLIKELY(TRACE_sched)) {            \
-        traceEvent_(cap, tag);                  \
+#define traceGcEvent(cap, tag)    \
+    if (RTS_UNLIKELY(TRACE_gc)) { \
+        traceGcEvent_(cap, tag);  \
     }
 
-void traceEvent_ (Capability *cap, EventTypeNum tag);
+void traceGcEvent_ (Capability *cap, EventTypeNum tag);
 
 // variadic macros are C99, and supported by gcc.  However, the
 // ##__VA_ARGS syntax is a gcc extension, which allows the variable
@@ -198,8 +198,8 @@ void traceSparkCounters_ (Capability *cap,
 
 #define traceSchedEvent(cap, tag, tso, other) /* nothing */
 #define traceSchedEvent2(cap, tag, tso, other, info) /* nothing */
+#define traceGcEvent(cap, tag) /* nothing */
 #define traceSparkEvent(cap, tag, tso, other) /* nothing */
-#define traceEvent(cap, tag) /* nothing */
 #define traceCap(class, cap, msg, ...) /* nothing */
 #define trace(class, msg, ...) /* nothing */
 #define debugTrace(class, str, ...) /* nothing */
@@ -384,28 +384,47 @@ INLINE_HEADER void traceEventThreadWakeup(Capability *cap       STG_UNUSED,
 
 INLINE_HEADER void traceEventGcStart(Capability *cap STG_UNUSED)
 {
-    traceSchedEvent(cap, EVENT_GC_START, 0, 0);
+    traceGcEvent(cap, EVENT_GC_START);
     dtraceGcStart((EventCapNo)cap->no);
 }
 
 INLINE_HEADER void traceEventGcEnd(Capability *cap STG_UNUSED)
 {
-    traceSchedEvent(cap, EVENT_GC_END, 0, 0);
+    traceGcEvent(cap, EVENT_GC_END);
     dtraceGcEnd((EventCapNo)cap->no);
 }
 
 INLINE_HEADER void traceEventRequestSeqGc(Capability *cap STG_UNUSED)
 {
-    traceSchedEvent(cap, EVENT_REQUEST_SEQ_GC, 0, 0);
+    traceGcEvent(cap, EVENT_REQUEST_SEQ_GC);
     dtraceRequestSeqGc((EventCapNo)cap->no);
 }
 
 INLINE_HEADER void traceEventRequestParGc(Capability *cap STG_UNUSED)
 {
-    traceSchedEvent(cap, EVENT_REQUEST_PAR_GC, 0, 0);
+    traceGcEvent(cap, EVENT_REQUEST_PAR_GC);
     dtraceRequestParGc((EventCapNo)cap->no);
 }
 
+INLINE_HEADER void traceEventGcIdle(Capability *cap STG_UNUSED)
+{
+    traceGcEvent(cap, EVENT_GC_IDLE);
+    dtraceGcIdle((EventCapNo)cap->no);
+}
+
+INLINE_HEADER void traceEventGcWork(Capability *cap STG_UNUSED)
+{
+    traceGcEvent(cap, EVENT_GC_WORK);
+    dtraceGcWork((EventCapNo)cap->no);
+}
+
+INLINE_HEADER void traceEventGcDone(Capability *cap STG_UNUSED)
+{
+    traceGcEvent(cap, EVENT_GC_DONE);
+    dtraceGcDone((EventCapNo)cap->no);
+}
+
+
 INLINE_HEADER void traceEventRunSpark(Capability *cap STG_UNUSED, 
                                       StgTSO     *tso STG_UNUSED)
 {
@@ -443,24 +462,6 @@ INLINE_HEADER void traceEventStartup(void)
     dtraceStartup(n_caps);
 }
 
-INLINE_HEADER void traceEventGcIdle(Capability *cap STG_UNUSED)
-{
-    traceEvent(cap, EVENT_GC_IDLE);
-    dtraceGcIdle((EventCapNo)cap->no);
-}
-
-INLINE_HEADER void traceEventGcWork(Capability *cap STG_UNUSED)
-{
-    traceEvent(cap, EVENT_GC_WORK);
-    dtraceGcWork((EventCapNo)cap->no);
-}
-
-INLINE_HEADER void traceEventGcDone(Capability *cap STG_UNUSED)
-{
-    traceEvent(cap, EVENT_GC_DONE);
-    dtraceGcDone((EventCapNo)cap->no);
-}
-
 INLINE_HEADER void traceCapsetCreate(CapsetID   capset      STG_UNUSED,
                                      CapsetType capset_type STG_UNUSED)
 {
diff --git a/rts/eventlog/EventLog.c b/rts/eventlog/EventLog.c
index 1e63a94c88..54e4cb4096 100644
--- a/rts/eventlog/EventLog.c
+++ b/rts/eventlog/EventLog.c
@@ -470,16 +470,12 @@ postSchedEvent (Capability *cap,
     }
 
     case EVENT_SHUTDOWN:        // (cap)
-    case EVENT_REQUEST_SEQ_GC:  // (cap)
-    case EVENT_REQUEST_PAR_GC:  // (cap)
-    case EVENT_GC_START:        // (cap)
-    case EVENT_GC_END:          // (cap)
     {
         break;
     }
 
     default:
-        barf("postEvent: unknown event tag %d", tag);
+        barf("postSchedEvent: unknown event tag %d", tag);
     }
 }