Add fast event logging

Generate binary log files from the RTS containing a log of runtime
events with timestamps.  The log file can be visualised in various
ways, for investigating runtime behaviour and debugging performance
problems.  See for example the forthcoming ThreadScope viewer.

New GHC option:

  -eventlog   (link-time option) Enables event logging.

  +RTS -l     (runtime option) Generates <prog>.eventlog with
              the binary event information.

This replaces some of the tracing machinery we already had in the RTS:
e.g. +RTS -vg  for GC tracing (we should do this using the new event
logging instead).

Event logging has almost no runtime cost when it isn't enabled, though
in the future we might add more fine-grained events and this might
change; hence having a link-time option and compiling a separate
version of the RTS for event logging.  There's a small runtime cost
for enabling event-logging, for most programs it shouldn't make much
difference.

(Todo: docs)

3 files changed, 10 insertions, 10 deletions

diff --git a/rts/sm/GC.c b/rts/sm/GC.c
index 501a9e52d4..cb5623ab86 100644
--- a/rts/sm/GC.c
+++ b/rts/sm/GC.c
@@ -264,7 +264,7 @@ GarbageCollect (rtsBool force_major_gc,
   n_gc_threads = 1;
 #endif
 
-  trace(TRACE_gc|DEBUG_gc, "GC (gen %d): %d KB to collect, %ld MB in use, using %d thread(s)",
+  debugTrace(DEBUG_gc, "GC (gen %d): %d KB to collect, %ld MB in use, using %d thread(s)",
         N, n * (BLOCK_SIZE / 1024), mblocks_allocated, n_gc_threads);
 
 #ifdef RTS_GTK_FRONTPANEL
@@ -534,12 +534,12 @@ GarbageCollect (rtsBool force_major_gc,
       nat i;
       for (i=0; i < n_gc_threads; i++) {
           if (n_gc_threads > 1) {
-              trace(TRACE_gc,"thread %d:", i);
-              trace(TRACE_gc,"   copied           %ld", gc_threads[i]->copied * sizeof(W_));
-              trace(TRACE_gc,"   scanned          %ld", gc_threads[i]->scanned * sizeof(W_));
-              trace(TRACE_gc,"   any_work         %ld", gc_threads[i]->any_work);
-              trace(TRACE_gc,"   no_work          %ld", gc_threads[i]->no_work);
-              trace(TRACE_gc,"   scav_find_work %ld",   gc_threads[i]->scav_find_work);
+              debugTrace(DEBUG_gc,"thread %d:", i);
+              debugTrace(DEBUG_gc,"   copied           %ld", gc_threads[i]->copied * sizeof(W_));
+              debugTrace(DEBUG_gc,"   scanned          %ld", gc_threads[i]->scanned * sizeof(W_));
+              debugTrace(DEBUG_gc,"   any_work         %ld", gc_threads[i]->any_work);
+              debugTrace(DEBUG_gc,"   no_work          %ld", gc_threads[i]->no_work);
+              debugTrace(DEBUG_gc,"   scav_find_work %ld",   gc_threads[i]->scav_find_work);
           }
           copied += gc_threads[i]->copied;
           max_copied = stg_max(gc_threads[i]->copied, max_copied);
@@ -764,7 +764,7 @@ GarbageCollect (rtsBool force_major_gc,
   IF_DEBUG(sanity, checkSanity());
 
   // extra GC trace info 
-  if (traceClass(TRACE_gc|DEBUG_gc)) statDescribeGens();
+  IF_DEBUG(gc, statDescribeGens());
 
 #ifdef DEBUG
   // symbol-table based profiling 
diff --git a/rts/sm/GCUtils.c b/rts/sm/GCUtils.c
index 84b7564980..86d2282980 100644
--- a/rts/sm/GCUtils.c
+++ b/rts/sm/GCUtils.c
@@ -194,7 +194,7 @@ todo_block_full (nat size, step_workspace *ws)
         {
             step *stp;
             stp = ws->step;
-            trace(TRACE_gc|DEBUG_gc, "push todo block %p (%ld words), step %d, todo_q: %ld", 
+            debugTrace(DEBUG_gc, "push todo block %p (%ld words), step %d, todo_q: %ld", 
                   bd->start, (unsigned long)(bd->free - bd->u.scan),
                   stp->abs_no, dequeElements(ws->todo_q));
 
diff --git a/rts/sm/Sweep.c b/rts/sm/Sweep.c
index 9251290c90..444c3d5111 100644
--- a/rts/sm/Sweep.c
+++ b/rts/sm/Sweep.c
@@ -70,7 +70,7 @@ sweep(step *step)
 
     step->live_estimate = live;
 
-    trace(DEBUG_gc|TRACE_gc, "sweeping: %d blocks, %d were copied, %d freed (%d%%), %d are fragmented, live estimate: %ld%%",
+    debugTrace(DEBUG_gc, "sweeping: %d blocks, %d were copied, %d freed (%d%%), %d are fragmented, live estimate: %ld%%",
           step->n_old_blocks + freed,
           step->n_old_blocks - blocks + freed,
           freed,