Add +RTS -vg flag for requesting some GC trace messages, outside DEBUG

DEBUG imposes a significant performance hit in the GC, yet we often
want some of the debugging output, so -vg gives us the cheap trace
messages without the sanity checking of DEBUG, just like -vs for the
scheduler.

9 files changed, 45 insertions, 14 deletions

diff --git a/includes/RtsFlags.h b/includes/RtsFlags.h
index 902e6c064b..7d0b418aa1 100644
--- a/includes/RtsFlags.h
+++ b/includes/RtsFlags.h
@@ -301,6 +301,7 @@ struct TICKY_FLAGS {
 
 struct TRACE_FLAGS {
     rtsBool sched;		/* trace scheduler events for profiling */
+    rtsBool gc;                 /* trace GC events */
     rtsBool timestamp;          /* add timestamps to traces */
 };
 
diff --git a/rts/RtsFlags.c b/rts/RtsFlags.c
index 535d0fdcd2..4f69f49fec 100644
--- a/rts/RtsFlags.c
+++ b/rts/RtsFlags.c
@@ -317,6 +317,7 @@ void initRtsFlagsDefaults(void)
 
     RtsFlags.TraceFlags.timestamp	= rtsFalse;
     RtsFlags.TraceFlags.sched 		= rtsFalse;
+    RtsFlags.TraceFlags.gc 		= rtsFalse;
 
 #ifdef USE_PAPI
     /* By default no special measurements taken */
@@ -1221,6 +1222,9 @@ error = rtsTrue;
 		case 's':
 		    RtsFlags.TraceFlags.sched = rtsTrue;
 		    break;
+		case 'g':
+		    RtsFlags.TraceFlags.gc = rtsTrue;
+		    break;
 		default:
 		    errorBelch("unknown RTS option: %s",rts_argv[arg]);
 		    error = rtsTrue;
diff --git a/rts/Stats.c b/rts/Stats.c
index 8c24b299b6..2fdd0a8b3c 100644
--- a/rts/Stats.c
+++ b/rts/Stats.c
@@ -668,7 +668,6 @@ stat_exit(int alloc)
 
    Produce some detailed info on the state of the generational GC.
    -------------------------------------------------------------------------- */
-#ifdef DEBUG
 void
 statDescribeGens(void)
 {
@@ -709,7 +708,6 @@ statDescribeGens(void)
   }
   debugBelch("\n");
 }
-#endif
 
 /* -----------------------------------------------------------------------------
    Stats available via a programmatic interface, so eg. GHCi can time
diff --git a/rts/Trace.c b/rts/Trace.c
index 0b30e92819..06de1c49de 100644
--- a/rts/Trace.c
+++ b/rts/Trace.c
@@ -108,6 +108,7 @@ void initTracing (void)
     GRAN_FLAG(blockedOnFetch_sanity, GRAN_DEBUG_BOF_sanity);
 
     TRACE_FLAG(sched, TRACE_sched);
+    TRACE_FLAG(gc, TRACE_gc);
 }
 
 static void tracePreface (void)
diff --git a/rts/Trace.h b/rts/Trace.h
index 530ed1bc12..0e142f5238 100644
--- a/rts/Trace.h
+++ b/rts/Trace.h
@@ -73,14 +73,11 @@ void traceEnd (void);
 #define DEBUG_par		   (1<<11)
 #define DEBUG_linker		   (1<<12)
 #define DEBUG_squeeze              (1<<13)
+#define DEBUG_hpc                  (1<<14)
 
-
-
-// Profiling flags
-#define TRACE_sched                (1<<29)
-
-// Coverge flags
-#define DEBUG_hpc                  (1<<30)
+// Tracing flags
+#define TRACE_sched                (1<<20)
+#define TRACE_gc                   (1<<21)
 
 // -----------------------------------------------------------------------------
 // PRIVATE below here
diff --git a/rts/sm/GC.c b/rts/sm/GC.c
index 80ec6f2019..250d07fa4e 100644
--- a/rts/sm/GC.c
+++ b/rts/sm/GC.c
@@ -305,9 +305,6 @@ GarbageCollect ( rtsBool force_major_gc )
   inc_running();
   wakeup_gc_threads(n_gc_threads);
 
-  // Initialise stats
-  copied = 0;
-
   // this is the main thread
   gct = gc_threads[0];
 
@@ -463,6 +460,21 @@ GarbageCollect ( rtsBool force_major_gc )
 
   /* run through all the generations/steps and tidy up 
    */
+  copied = 0;
+  { 
+      nat i;
+      for (i=0; i < n_gc_threads; i++) {
+          if (major_gc) {
+              trace(TRACE_gc,"thread %d:", i);
+              trace(TRACE_gc,"   copied           %ld", gc_threads[i]->copied * sizeof(W_));
+              trace(TRACE_gc,"   any_work         %ld", gc_threads[i]->any_work);
+              trace(TRACE_gc,"   scav_global_work %ld", gc_threads[i]->scav_global_work);
+              trace(TRACE_gc,"   scav_local_work  %ld", gc_threads[i]->scav_local_work);
+          }
+          copied += gc_threads[i]->copied;
+      }
+  }
+
   for (g = 0; g < RtsFlags.GcFlags.generations; g++) {
 
     if (g <= N) {
@@ -644,7 +656,7 @@ GarbageCollect ( rtsBool force_major_gc )
   IF_DEBUG(sanity, checkSanity());
 
   // extra GC trace info 
-  IF_DEBUG(gc, statDescribeGens());
+  if (traceClass(TRACE_gc)) statDescribeGens();
 
 #ifdef DEBUG
   // symbol-table based profiling 
@@ -1348,6 +1360,10 @@ init_gc_thread (gc_thread *t)
     t->failed_to_evac = rtsFalse;
     t->eager_promotion = rtsTrue;
     t->thunk_selector_depth = 0;
+    t->copied = 0;
+    t->any_work = 0;
+    t->scav_global_work = 0;
+    t->scav_local_work = 0;
 }
 
 /* -----------------------------------------------------------------------------
diff --git a/rts/sm/GC.h b/rts/sm/GC.h
index f98e4a1535..5183837f1e 100644
--- a/rts/sm/GC.h
+++ b/rts/sm/GC.h
@@ -148,6 +148,14 @@ typedef struct gc_thread_ {
 #endif
 
     // -------------------
+    // stats
+
+    lnat copied;
+    lnat any_work;
+    lnat scav_global_work;
+    lnat scav_local_work;
+
+    // -------------------
     // workspaces
 
     // array of workspaces, indexed by stp->abs_no.  This is placed
diff --git a/rts/sm/GCUtils.c b/rts/sm/GCUtils.c
index 103430abed..636f23dc23 100644
--- a/rts/sm/GCUtils.c
+++ b/rts/sm/GCUtils.c
@@ -92,7 +92,7 @@ push_scan_block (bdescr *bd, step_workspace *ws)
     ASSERT(bd->link == NULL);
 
     // update stats: this is a block that has been copied & scavenged
-    copied += bd->free - bd->start;
+    gct->copied += bd->free - bd->start;
 
     // put the scan block on the ws->scavd_list.
     bd->link = ws->scavd_list;
diff --git a/rts/sm/Scav.c b/rts/sm/Scav.c
index b22f2442a1..674078f558 100644
--- a/rts/sm/Scav.c
+++ b/rts/sm/Scav.c
@@ -1405,6 +1405,8 @@ scavenge_find_global_work (void)
     rtsBool flag;
     step_workspace *ws;
 
+    gct->scav_global_work++;
+
     flag = rtsFalse;
     for (s = total_steps-1; s>=0; s--)
     {
@@ -1457,6 +1459,8 @@ scavenge_find_local_work (void)
     step_workspace *ws;
     rtsBool flag;
 
+    gct->scav_local_work++;
+
     flag = rtsFalse;
     for (s = total_steps-1; s >= 0; s--) {
         if (s == 0 && RtsFlags.GcFlags.generations > 1) { 
@@ -1551,6 +1555,8 @@ any_work (void)
     int s;
     step_workspace *ws;
 
+    gct->any_work++;
+
     write_barrier();
 
     // scavenge static objects