Add +RTS -vg flag for requesting some GC trace messages, outside DEBUG
authorSimon Marlow <simonmarhaskell@gmail.com>
Wed, 16 Apr 2008 21:35:04 +0000 (21:35 +0000)
committerSimon Marlow <simonmarhaskell@gmail.com>
Wed, 16 Apr 2008 21:35:04 +0000 (21:35 +0000)
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.

includes/RtsFlags.h
rts/RtsFlags.c
rts/Stats.c
rts/Trace.c
rts/Trace.h
rts/sm/GC.c
rts/sm/GC.h
rts/sm/GCUtils.c
rts/sm/Scav.c

index 902e6c0..7d0b418 100644 (file)
@@ -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 */
 };
 
index 535d0fd..4f69f49 100644 (file)
@@ -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;
index 8c24b29..2fdd0a8 100644 (file)
@@ -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
index 0b30e92..06de1c4 100644 (file)
@@ -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)
index 530ed1b..0e142f5 100644 (file)
@@ -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
index 80ec6f2..250d07f 100644 (file)
@@ -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;
 }
 
 /* -----------------------------------------------------------------------------
index f98e4a1..5183837 100644 (file)
@@ -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
index 103430a..636f23d 100644 (file)
@@ -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;
index b22f244..674078f 100644 (file)
@@ -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