Keep track of an accurate count of live words in each step
[ghc-hetmet.git] / rts / Stats.c
index b9df019..cd61116 100644 (file)
@@ -16,6 +16,9 @@
 #include "ParTicky.h"                       /* ToDo: move into Rts.h */
 #include "Profiling.h"
 #include "GetTime.h"
+#include "GC.h"
+#include "GCUtils.h"
+#include "Evac.h"
 
 #if USE_PAPI
 #include "Papi.h"
@@ -65,8 +68,8 @@ static lnat ResidencySamples = 0; // for stats only
 
 static lnat GC_start_faults = 0, GC_end_faults = 0;
 
-static Ticks *GC_coll_times;
-static Ticks *GC_coll_etimes;
+static Ticks *GC_coll_times = NULL;
+static Ticks *GC_coll_etimes = NULL;
 
 static void statsFlush( void );
 static void statsClose( void );
@@ -546,7 +549,7 @@ stat_exit(int alloc)
                         TICK_TO_DBL(GC_coll_etimes[g]));
            }
 
-           statsPrintf("\n%11ld Mb total memory in use\n\n", 
+           statsPrintf("\n%11ld MB total memory in use\n\n", 
                    mblocks_allocated * MBLOCK_SIZE / (1024 * 1024));
 
 #if defined(THREADED_RTS)
@@ -635,12 +638,32 @@ stat_exit(int alloc)
                    TICK_TO_DBL(GC_tot_time), TICK_TO_DBL(GCe_tot_time));
        }
 
+#if defined(THREADED_RTS) && defined(PROF_SPIN)
+        {
+            nat g, s;
+            
+            statsPrintf("recordMutableGen_sync: %"FMT_Word64"\n", recordMutableGen_sync.spin);
+            statsPrintf("gc_alloc_block_sync: %"FMT_Word64"\n", gc_alloc_block_sync.spin);
+            statsPrintf("whitehole_spin: %"FMT_Word64"\n", whitehole_spin);
+            for (g = 0; g < RtsFlags.GcFlags.generations; g++) {
+                for (s = 0; s < generations[g].n_steps; s++) {
+                    statsPrintf("gen[%d].steps[%d].sync_todo: %"FMT_Word64"\n", g, s, generations[g].steps[s].sync_todo.spin);
+                    statsPrintf("gen[%d].steps[%d].sync_large_objects: %"FMT_Word64"\n", g, s, generations[g].steps[s].sync_large_objects.spin);
+                }
+            }
+        }
+#endif
+
        statsFlush();
        statsClose();
     }
+
     if (GC_coll_times)
       stgFree(GC_coll_times);
     GC_coll_times = NULL;
+    if (GC_coll_etimes)
+      stgFree(GC_coll_etimes);
+    GC_coll_etimes = NULL;
 }
 
 /* -----------------------------------------------------------------------------
@@ -648,48 +671,52 @@ stat_exit(int alloc)
 
    Produce some detailed info on the state of the generational GC.
    -------------------------------------------------------------------------- */
-#ifdef DEBUG
 void
 statDescribeGens(void)
 {
   nat g, s, mut, lge;
-  lnat live;
+  lnat live, slop;
+  lnat tot_live, tot_slop;
   bdescr *bd;
   step *step;
 
   debugBelch(
-"     Gen    Steps      Max  Mut-list  Step   Blocks     Live    Large\n"
-"                    Blocks     Bytes                          Objects\n");
+"-----------------------------------------------------------------\n"
+"  Gen     Max  Mut-list  Step   Blocks    Large     Live     Slop\n"
+"       Blocks     Bytes                 Objects                  \n"
+"-----------------------------------------------------------------\n");
 
-  mut = 0;
+  tot_live = 0;
+  tot_slop = 0;
   for (g = 0; g < RtsFlags.GcFlags.generations; g++) {
+      mut = 0;
       for (bd = generations[g].mut_list; bd != NULL; bd = bd->link) {
          mut += (bd->free - bd->start) * sizeof(W_);
       }
 
-    debugBelch("%8d %8d %8d %9d", g, generations[g].n_steps,
-           generations[g].max_blocks, mut);
+    debugBelch("%5d %7d %9d", g, generations[g].max_blocks, mut);
 
     for (s = 0; s < generations[g].n_steps; s++) {
       step = &generations[g].steps[s];
-      live = 0;
       for (bd = step->large_objects, lge = 0; bd; bd = bd->link) {
        lge++;
       }
-      // This live figure will be slightly less that the "live" figure
-      // given by +RTS -Sstderr, because we take don't count the
-      // slop at the end of each block.
-      live += countOccupied(step->blocks) + countOccupied(step->large_objects);
+      live = step->n_words + countOccupied(step->large_objects);
       if (s != 0) {
-       debugBelch("%36s","");
+       debugBelch("%23s","");
       }
-      debugBelch("%6d %8d %8ld %8d\n", s, step->n_blocks,
-             live, lge);
+      slop = (step->n_blocks + step->n_large_blocks) * BLOCK_SIZE_W - live;
+      debugBelch("%6d %8d %8d %8ld %8ld\n", s, step->n_blocks, lge,
+                 live*sizeof(W_), slop*sizeof(W_));
+      tot_live += live;
+      tot_slop += slop;
     }
   }
+  debugBelch("-----------------------------------------------------------------\n");
+  debugBelch("%48s%8ld %8ld\n","",tot_live*sizeof(W_),tot_slop*sizeof(W_));
+  debugBelch("-----------------------------------------------------------------\n");
   debugBelch("\n");
 }
-#endif
 
 /* -----------------------------------------------------------------------------
    Stats available via a programmatic interface, so eg. GHCi can time