[project @ 2005-04-07 15:53:01 by simonmar]
[ghc-hetmet.git] / ghc / rts / Stats.c
index e34492b..efa3e31 100644 (file)
@@ -1,7 +1,6 @@
 /* -----------------------------------------------------------------------------
- * $Id: Stats.c,v 1.37 2001/11/23 10:27:58 simonmar Exp $
  *
- * (c) The GHC Team, 1998-1999
+ * (c) The GHC Team, 1998-2004
  *
  * Statistics and timing-related functions.
  *
 #include "Rts.h"
 #include "RtsFlags.h"
 #include "RtsUtils.h"
-#include "StoragePriv.h"
 #include "MBlock.h"
 #include "Schedule.h"
 #include "Stats.h"
-#include "ParTicky.h"                       // ToDo: move into Rts.h
+#include "ParTicky.h"                       /* ToDo: move into Rts.h */
 #include "Profiling.h"
+#include "Storage.h"
+#include "Task.h"
 
 #ifdef HAVE_UNISTD_H
 #include <unistd.h>
 #endif
 
-#ifndef mingw32_TARGET_OS
+#ifndef mingw32_HOST_OS
 # ifdef HAVE_SYS_TIMES_H
 #  include <sys/times.h>
 # endif
@@ -41,7 +41,7 @@
 # endif
 #endif
 
-#if ! irix_TARGET_OS && ! defined(mingw32_TARGET_OS)
+#if ! irix_HOST_OS && ! defined(mingw32_HOST_OS)
 # if defined(HAVE_SYS_RESOURCE_H)
 #  include <sys/resource.h>
 # endif
@@ -59,7 +59,7 @@
 #include <windows.h>
 #endif
 
-#if defined(PAR) || !(!defined(HAVE_GETRUSAGE) || irix_TARGET_OS || defined(mingw32_TARGET_OS) || defined(cygwin32_TARGET_OS))
+#if defined(PAR) || !(!defined(HAVE_GETRUSAGE) || irix_HOST_OS || defined(mingw32_HOST_OS) || defined(cygwin32_HOST_OS))
 #include <sys/resource.h>
 #endif
 
@@ -94,18 +94,26 @@ static TICK_TYPE ExitElapsedTime  = 0;
 static ullong GC_tot_alloc        = 0;
 static ullong GC_tot_copied       = 0;
 
-static TICK_TYPE GC_start_time,  GC_tot_time = 0;    // User GC Time
-static TICK_TYPE GCe_start_time, GCe_tot_time = 0;   // Elapsed GC time
+static TICK_TYPE GC_start_time = 0,  GC_tot_time  = 0;  /* User GC Time */
+static TICK_TYPE GCe_start_time = 0, GCe_tot_time = 0;  /* Elapsed GC time */
 
-static TICK_TYPE RP_start_time, RP_tot_time = 0;     // retainer prof user time
-static TICK_TYPE RPe_start_time, RPe_tot_time = 0;   // retainer prof elap time
+#ifdef PROFILING
+static TICK_TYPE RP_start_time  = 0, RP_tot_time  = 0;  /* retainer prof user time */
+static TICK_TYPE RPe_start_time = 0, RPe_tot_time = 0;  /* retainer prof elap time */
 
-static TICK_TYPE LDV_start_time, LDV_tot_time = 0;   // LDV prof user time
-static TICK_TYPE LDVe_start_time, LDVe_tot_time = 0; // LDV prof elap time
+static TICK_TYPE HC_start_time, HC_tot_time = 0;     // heap census prof user time
+static TICK_TYPE HCe_start_time, HCe_tot_time = 0;   // heap census prof elap time
+#endif
 
-lnat MaxResidency = 0;     /* in words; for stats only */
-lnat AvgResidency = 0;
-lnat ResidencySamples = 0; /* for stats only */
+#ifdef PROFILING
+#define PROF_VAL(x)   (x)
+#else
+#define PROF_VAL(x)   0
+#endif
+
+static lnat MaxResidency = 0;     // in words; for stats only
+static lnat AvgResidency = 0;
+static lnat ResidencySamples = 0; // for stats only
 
 static lnat GC_start_faults = 0, GC_end_faults = 0;
 
@@ -114,9 +122,15 @@ static TICK_TYPE *GC_coll_times;
 static void  getTimes(void);
 static nat   pageFaults(void);
 
+static void statsPrintf( char *s, ... ) 
+    GNUC3_ATTRIBUTE(format (printf, 1, 2));
+
+static void statsFlush( void );
+static void statsClose( void );
+
 /* elapsedtime() -- The current elapsed time in seconds */
 
-#if defined(mingw32_TARGET_OS) || defined(cygwin32_TARGET_OS)
+#if defined(mingw32_HOST_OS) || defined(cygwin32_HOST_OS)
 #define HNS_PER_SEC 10000000LL /* FILETIMES are in units of 100ns */
 /* Convert FILETIMEs into secs */
 #define FT2longlong(ll,ft)    \
@@ -126,7 +140,7 @@ static nat   pageFaults(void);
     (ll) /= (unsigned long long) (HNS_PER_SEC / CLOCKS_PER_SEC)
 #endif
 
-#if defined(mingw32_TARGET_OS) || defined(cygwin32_TARGET_OS)
+#if defined(mingw32_HOST_OS) || defined(cygwin32_HOST_OS)
 /* cygwin32 or mingw32 version */
 static void
 getTimes(void)
@@ -190,7 +204,7 @@ getTimes(void)
     /* We will #ifdef around the fprintf for machines
        we *know* are unsupported. (WDP 94/05)
     */
-    fprintf(stderr, "NOTE: `getTimes' does nothing!\n");
+    debugBelch("NOTE: `getTimes' does nothing!\n");
     return 0.0;
 
 #else /* not stumped */
@@ -219,41 +233,41 @@ getTimes(void)
 double
 mut_user_time_during_GC( void )
 {
-  return TICK_TO_DBL(GC_start_time - GC_tot_time - RP_tot_time - LDV_tot_time);
+  return TICK_TO_DBL(GC_start_time - GC_tot_time - PROF_VAL(RP_tot_time + HC_tot_time));
 }
 
 double
 mut_user_time( void )
 {
     getTimes();
-    return TICK_TO_DBL(CurrentUserTime - GC_tot_time - RP_tot_time - LDV_tot_time);
+    return TICK_TO_DBL(CurrentUserTime - GC_tot_time - PROF_VAL(RP_tot_time + HC_tot_time));
 }
 
 #ifdef PROFILING
 /*
   mut_user_time_during_RP() is similar to mut_user_time_during_GC();
   it returns the MUT time during retainer profiling.
-  The same is for mut_user_time_during_LDV();
+  The same is for mut_user_time_during_HC();
  */
 double
 mut_user_time_during_RP( void )
 {
-  return TICK_TO_DBL(RP_start_time - GC_tot_time - RP_tot_time - LDV_tot_time);
+  return TICK_TO_DBL(RP_start_time - GC_tot_time - RP_tot_time - HC_tot_time);
 }
 
 double
-mut_user_time_during_LDV( void )
+mut_user_time_during_heap_census( void )
 {
-  return TICK_TO_DBL(LDV_start_time - GC_tot_time - RP_tot_time - LDV_tot_time);
+  return TICK_TO_DBL(HC_start_time - GC_tot_time - RP_tot_time - HC_tot_time);
 }
-#endif // PROFILING
+#endif /* PROFILING */
 
 static nat
 pageFaults(void)
 {
   /* ToDo (on NT): better, get this via the performance data
      that's stored in the registry. */
-# if !defined(HAVE_GETRUSAGE) || irix_TARGET_OS || defined(mingw32_TARGET_OS) || defined(cygwin32_TARGET_OS)
+# if !defined(HAVE_GETRUSAGE) || irix_HOST_OS || defined(mingw32_HOST_OS) || defined(cygwin32_HOST_OS)
     return 0;
 # else
     struct rusage t;
@@ -267,11 +281,10 @@ void
 initStats(void)
 {
     nat i;
-    FILE *sf = RtsFlags.GcFlags.statsFile;
   
     if (RtsFlags.GcFlags.giveStats >= VERBOSE_GC_STATS) {
-       fprintf(sf, "    Alloc    Collect    Live    GC    GC     TOT     TOT  Page Flts\n");
-       fprintf(sf, "    bytes     bytes     bytes  user  elap    user    elap\n");
+       statsPrintf("    Alloc    Collect    Live    GC    GC     TOT     TOT  Page Flts\n");
+       statsPrintf("    bytes     bytes     bytes  user  elap    user    elap\n");
     }
     GC_coll_times = 
        (TICK_TYPE *)stgMallocBytes(
@@ -298,7 +311,7 @@ stat_startInit(void)
 
     ticks = sysconf(_SC_CLK_TCK);
     if ( ticks == -1 ) {
-       fprintf(stderr, "stat_init: bad call to 'sysconf'!\n");
+       debugBelch("stat_init: bad call to 'sysconf'!\n");
        stg_exit(EXIT_FAILURE);
     }
     TicksPerSecond = ticks;
@@ -314,7 +327,7 @@ stat_startInit(void)
     /* We will #ifdef around the fprintf for machines
        we *know* are unsupported. (WDP 94/05)
     */
-    fprintf(stderr, "NOTE: Guessing `TicksPerSecond = 60'!\n");
+    debugBelch("NOTE: Guessing `TicksPerSecond = 60'!\n");
     TicksPerSecond = 60;
 #endif
 
@@ -346,19 +359,20 @@ stat_startExit(void)
 {
     getTimes();
     MutElapsedStamp = CurrentElapsedTime;
-    MutElapsedTime = CurrentElapsedTime - GCe_tot_time - InitElapsedStamp;
+    MutElapsedTime = CurrentElapsedTime - GCe_tot_time -
+       PROF_VAL(RPe_tot_time + HCe_tot_time) - InitElapsedStamp;
     if (MutElapsedTime < 0) { MutElapsedTime = 0; }    /* sometimes -0.00 */
-    
-    /* for SMP, we don't know the mutator time yet, we have to inspect
+
+    /* for threads, we don't know the mutator time yet, we have to inspect
      * all the running threads to find out, and they haven't stopped
      * yet.  So we just timestamp MutUserTime at this point so we can
      * calculate the EXIT time.  The real MutUserTime is calculated
      * in stat_exit below.
      */
-#ifdef SMP
+#if defined(RTS_SUPPORTS_THREADS)
     MutUserTime = CurrentUserTime;
 #else
-    MutUserTime = CurrentUserTime - GC_tot_time - RP_tot_time - LDV_tot_time - InitUserTime;
+    MutUserTime = CurrentUserTime - GC_tot_time - PROF_VAL(RP_tot_time + HC_tot_time) - InitUserTime;
     if (MutUserTime < 0) { MutUserTime = 0; }
 #endif
 }
@@ -367,10 +381,10 @@ void
 stat_endExit(void)
 {
     getTimes();
-#ifdef SMP
+#if defined(RTS_SUPPORTS_THREADS)
     ExitUserTime = CurrentUserTime - MutUserTime;
 #else
-    ExitUserTime = CurrentUserTime - MutUserTime - GC_tot_time - RP_tot_time - LDV_tot_time - InitUserTime;
+    ExitUserTime = CurrentUserTime - MutUserTime - GC_tot_time - PROF_VAL(RP_tot_time + HC_tot_time) - InitUserTime;
 #endif
     ExitElapsedTime = CurrentElapsedTime - MutElapsedStamp;
     if (ExitUserTime < 0) {
@@ -399,10 +413,10 @@ stat_startGC(void)
 
     if (bell) {
        if (bell > 1) {
-           fprintf(stderr, " GC ");
+           debugBelch(" GC ");
            rub_bell = 1;
        } else {
-           fprintf(stderr, "\007");
+           debugBelch("\007");
        }
     }
 
@@ -430,8 +444,6 @@ stat_startGC(void)
 void
 stat_endGC(lnat alloc, lnat collect, lnat live, lnat copied, lnat gen)
 {
-    FILE *sf = RtsFlags.GcFlags.statsFile;
-
     if (RtsFlags.GcFlags.giveStats != NO_GC_STATS) {
        TICK_TYPE time, etime, gc_time, gc_etime;
        
@@ -441,12 +453,12 @@ stat_endGC(lnat alloc, lnat collect, lnat live, lnat copied, lnat gen)
        gc_time  = time - GC_start_time;
        gc_etime = etime - GCe_start_time;
        
-       if (RtsFlags.GcFlags.giveStats == VERBOSE_GC_STATS && sf != NULL) {
+       if (RtsFlags.GcFlags.giveStats == VERBOSE_GC_STATS) {
            nat faults = pageFaults();
            
-           fprintf(sf, "%9ld %9ld %9ld",
+           statsPrintf("%9ld %9ld %9ld",
                    alloc*sizeof(W_), collect*sizeof(W_), live*sizeof(W_));
-           fprintf(sf, " %5.2f %5.2f %7.2f %7.2f %4ld %4ld  (Gen: %2ld)\n", 
+           statsPrintf(" %5.2f %5.2f %7.2f %7.2f %4ld %4ld  (Gen: %2ld)\n", 
                    TICK_TO_DBL(gc_time),
                    TICK_TO_DBL(gc_etime),
                    TICK_TO_DBL(time),
@@ -456,7 +468,7 @@ stat_endGC(lnat alloc, lnat collect, lnat live, lnat copied, lnat gen)
                    gen);
 
            GC_end_faults = faults;
-           fflush(sf);
+           statsFlush();
        }
 
        GC_coll_times[gen] += gc_time;
@@ -466,17 +478,13 @@ stat_endGC(lnat alloc, lnat collect, lnat live, lnat copied, lnat gen)
        GC_tot_time   += gc_time;
        GCe_tot_time  += gc_etime;
        
-#ifdef SMP
+#if defined(RTS_SUPPORTS_THREADS)
        {
-           nat i;
-           pthread_t me = pthread_self();
-
-           for (i = 0; i < RtsFlags.ParFlags.nNodes; i++) {
-               if (me == task_ids[i].id) {
-                   task_ids[i].gc_time += gc_time;
-                   task_ids[i].gc_etime += gc_etime;
-                   break;
-               }
+           TaskInfo *task_info = taskOfId(osThreadId());
+           
+           if (task_info != NULL) {
+               task_info->gc_time += gc_time;
+               task_info->gc_etime += gc_etime;
            }
        }
 #endif
@@ -491,7 +499,7 @@ stat_endGC(lnat alloc, lnat collect, lnat live, lnat copied, lnat gen)
     }
 
     if (rub_bell) {
-       fprintf(stderr, "\b\b\b  \b\b\b");
+       debugBelch("\b\b\b  \b\b\b");
        rub_bell = 0;
     }
 }
@@ -507,7 +515,7 @@ stat_startRP(void)
   RP_start_time = CurrentUserTime;
   RPe_start_time = CurrentElapsedTime;
 }
-#endif // PROFILING
+#endif /* PROFILING */
 
 /* -----------------------------------------------------------------------------
    Called at the end of each Retainer Profiliing
@@ -521,9 +529,7 @@ stat_endRP(
   nat maxCStackSize,
   int maxStackSize,
 #endif
-  double averageNumVisit,
-  nat allCost,
-  nat numSet)
+  double averageNumVisit)
 {
   getTimes();
   RP_tot_time += CurrentUserTime - RP_start_time;
@@ -536,63 +542,52 @@ stat_endRP(
   fprintf(prof_file, "\tMax auxiliary stack size = %u\n", maxStackSize);
 #endif
   fprintf(prof_file, "\tAverage number of visits per object = %f\n", averageNumVisit);
-  fprintf(prof_file, "\tCurrent total costs in bytes = %u\n", allCost * sizeof(StgWord));
-  fprintf(prof_file, "\tNumber of retainer sets = %u\n\n", numSet);
 }
-#endif // PROFILING
+#endif /* PROFILING */
 
 /* -----------------------------------------------------------------------------
-   Called at the beginning of each LDV Profiliing
+   Called at the beginning of each heap census
    -------------------------------------------------------------------------- */
 #ifdef PROFILING
 void
-stat_startLDV(void)
+stat_startHeapCensus(void)
 {
   getTimes();
-  LDV_start_time = CurrentUserTime;
-  LDVe_start_time = CurrentElapsedTime;
+  HC_start_time = CurrentUserTime;
+  HCe_start_time = CurrentElapsedTime;
 }
-#endif // PROFILING
+#endif /* PROFILING */
 
 /* -----------------------------------------------------------------------------
-   Called at the end of each LDV Profiliing
+   Called at the end of each heap census
    -------------------------------------------------------------------------- */
 #ifdef PROFILING
 void
-stat_endLDV(void) 
+stat_endHeapCensus(void) 
 {
   getTimes();
-  LDV_tot_time += CurrentUserTime - LDV_start_time;
-  LDVe_tot_time += CurrentElapsedTime - LDVe_start_time;
+  HC_tot_time += CurrentUserTime - HC_start_time;
+  HCe_tot_time += CurrentElapsedTime - HCe_start_time;
 }
-#endif // PROFILING
+#endif /* PROFILING */
 
 /* -----------------------------------------------------------------------------
    stat_workerStop
 
    Called under SMP when a worker thread finishes.  We drop the timing
-   stats for this thread into the task_ids struct for that thread.
+   stats for this thread into the taskTable struct for that thread.
    -------------------------------------------------------------------------- */
 
-#ifdef SMP
 void
-stat_workerStop(void)
+stat_getTimes ( long *currentElapsedTime, 
+               long *currentUserTime,
+               long *elapsedGCTime )
 {
-    nat i;
-    pthread_t me = pthread_self();
-
-    for (i = 0; i < RtsFlags.ParFlags.nNodes; i++) {
-       if (task_ids[i].id == me) {
-           task_ids[i].mut_time = usertime() - task_ids[i].gc_time;
-           task_ids[i].mut_etime = elapsedtime()
-               - GCe_tot_time
-               - task_ids[i].elapsedtimestart;
-           if (task_ids[i].mut_time < 0.0)  { task_ids[i].mut_time = 0.0;  }
-           if (task_ids[i].mut_etime < 0.0) { task_ids[i].mut_etime = 0.0; }
-       }
-    }
+  getTimes();
+  *currentElapsedTime = CurrentElapsedTime;
+  *currentUserTime = CurrentUserTime;
+  *elapsedGCTime = GCe_tot_time;
 }
-#endif
 
 /* -----------------------------------------------------------------------------
    Called at the end of execution
@@ -605,8 +600,6 @@ stat_workerStop(void)
 void
 stat_exit(int alloc)
 {
-    FILE *sf = RtsFlags.GcFlags.statsFile;
-    
     if (RtsFlags.GcFlags.giveStats != NO_GC_STATS) {
 
        char temp[BIG_STRING_LEN];
@@ -615,15 +608,10 @@ stat_exit(int alloc)
        nat g, total_collections = 0;
 
        getTimes();
-       time = CurrentUserTime;
        etime = CurrentElapsedTime - ElapsedTimeStart;
 
        GC_tot_alloc += alloc;
 
-       /* avoid divide by zero if time is measured as 0.00 seconds -- SDM */
-       if (time  == 0.0)  time = 1;
-       if (etime == 0.0) etime = 1;
-       
        /* Count total garbage collections */
        for (g = 0; g < RtsFlags.GcFlags.generations; g++)
            total_collections += generations[g].collections;
@@ -631,109 +619,119 @@ stat_exit(int alloc)
        /* For SMP, we have to get the user time from each thread
         * and try to work out the total time.
         */
-#ifdef SMP
-       {   nat i;
+#if defined(RTS_SUPPORTS_THREADS)
+       {   
+           nat i;
            MutUserTime = 0.0;
-           for (i = 0; i < RtsFlags.ParFlags.nNodes; i++) {
-               MutUserTime += task_ids[i].mut_time;
+           for (i = 0; i < taskCount; i++) {
+               MutUserTime += taskTable[i].mut_time;
            }
        }
        time = MutUserTime + GC_tot_time + InitUserTime + ExitUserTime;
        if (MutUserTime < 0) { MutUserTime = 0; }
+#else
+       time = CurrentUserTime;
 #endif
 
-       if (RtsFlags.GcFlags.giveStats >= VERBOSE_GC_STATS && sf != NULL) {
-           fprintf(sf, "%9ld %9.9s %9.9s", (lnat)alloc*sizeof(W_), "", "");
-           fprintf(sf, " %5.2f %5.2f\n\n", 0.0, 0.0);
+       /* avoid divide by zero if time is measured as 0.00 seconds -- SDM */
+       if (time  == 0.0)  time = 1;
+       if (etime == 0.0) etime = 1;
+       
+       if (RtsFlags.GcFlags.giveStats >= VERBOSE_GC_STATS) {
+           statsPrintf("%9ld %9.9s %9.9s", (lnat)alloc*sizeof(W_), "", "");
+           statsPrintf(" %5.2f %5.2f\n\n", 0.0, 0.0);
        }
 
-       if (RtsFlags.GcFlags.giveStats >= SUMMARY_GC_STATS && sf != NULL) {
+       if (RtsFlags.GcFlags.giveStats >= SUMMARY_GC_STATS) {
            ullong_format_string(GC_tot_alloc*sizeof(W_), 
                                 temp, rtsTrue/*commas*/);
-           fprintf(sf, "%11s bytes allocated in the heap\n", temp);
+           statsPrintf("%11s bytes allocated in the heap\n", temp);
 
            ullong_format_string(GC_tot_copied*sizeof(W_), 
                                 temp, rtsTrue/*commas*/);
-           fprintf(sf, "%11s bytes copied during GC\n", temp);
+           statsPrintf("%11s bytes copied during GC\n", temp);
 
            if ( ResidencySamples > 0 ) {
                ullong_format_string(MaxResidency*sizeof(W_), 
                                     temp, rtsTrue/*commas*/);
-               fprintf(sf, "%11s bytes maximum residency (%ld sample(s))\n",
+               statsPrintf("%11s bytes maximum residency (%ld sample(s))\n",
                        temp, ResidencySamples);
            }
-           fprintf(sf,"\n");
+           statsPrintf("\n");
 
            /* Print garbage collections in each gen */
            for (g = 0; g < RtsFlags.GcFlags.generations; g++) {
-               fprintf(sf, "%11d collections in generation %d (%6.2fs)\n", 
+               statsPrintf("%11d collections in generation %d (%6.2fs)\n", 
                        generations[g].collections, g, 
                        TICK_TO_DBL(GC_coll_times[g]));
            }
 
-           fprintf(sf,"\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));
 
-#ifdef SMP
+#if defined(RTS_SUPPORTS_THREADS)
            {
                nat i;
-               for (i = 0; i < RtsFlags.ParFlags.nNodes; i++) {
-                   fprintf(sf, "  Task %2d:  MUT time: %6.2fs  (%6.2fs elapsed)\n"
-                           "            GC  time: %6.2fs  (%6.2fs elapsed)\n\n", 
-                           i, 
-                           TICK_TO_DBL(task_ids[i].mut_time),
-                           TICK_TO_DBL(task_ids[i].mut_etime),
-                           TICK_TO_DBL(task_ids[i].gc_time),
-                           TICK_TO_DBL(task_ids[i].gc_etime));
+               for (i = 0; i < taskCount; i++) {
+                   statsPrintf("  Task %2d %-8s :  MUT time: %6.2fs  (%6.2fs elapsed)\n"
+                           "                      GC  time: %6.2fs  (%6.2fs elapsed)\n\n", 
+                               i,
+                               taskTable[i].is_worker ? "(worker)" : "(bound)",
+                               TICK_TO_DBL(taskTable[i].mut_time),
+                               TICK_TO_DBL(taskTable[i].mut_etime),
+                               TICK_TO_DBL(taskTable[i].gc_time),
+                               TICK_TO_DBL(taskTable[i].gc_etime));
                }
            }
 #endif
 
-           fprintf(sf, "  INIT  time  %6.2fs  (%6.2fs elapsed)\n",
+           statsPrintf("  INIT  time  %6.2fs  (%6.2fs elapsed)\n",
                    TICK_TO_DBL(InitUserTime), TICK_TO_DBL(InitElapsedTime));
-           fprintf(sf, "  MUT   time  %6.2fs  (%6.2fs elapsed)\n",
+           statsPrintf("  MUT   time  %6.2fs  (%6.2fs elapsed)\n",
                    TICK_TO_DBL(MutUserTime), TICK_TO_DBL(MutElapsedTime));
-           fprintf(sf, "  GC    time  %6.2fs  (%6.2fs elapsed)\n",
+           statsPrintf("  GC    time  %6.2fs  (%6.2fs elapsed)\n",
                    TICK_TO_DBL(GC_tot_time), TICK_TO_DBL(GCe_tot_time));
 #ifdef PROFILING
-      if (RtsFlags.ProfFlags.doHeapProfile == HEAP_BY_RETAINER)
-             fprintf(sf, "  RP    time  %6.2fs  (%6.2fs elapsed)\n",
-                     TICK_TO_DBL(RP_tot_time), TICK_TO_DBL(RPe_tot_time));
-      if (RtsFlags.ProfFlags.doHeapProfile == HEAP_BY_LDV)
-             fprintf(sf, "  LDV   time  %6.2fs  (%6.2fs elapsed)\n",
-                     TICK_TO_DBL(LDV_tot_time), TICK_TO_DBL(LDVe_tot_time));
+           statsPrintf("  RP    time  %6.2fs  (%6.2fs elapsed)\n",
+                   TICK_TO_DBL(RP_tot_time), TICK_TO_DBL(RPe_tot_time));
+           statsPrintf("  PROF  time  %6.2fs  (%6.2fs elapsed)\n",
+                   TICK_TO_DBL(HC_tot_time), TICK_TO_DBL(HCe_tot_time));
 #endif 
-           fprintf(sf, "  EXIT  time  %6.2fs  (%6.2fs elapsed)\n",
+           statsPrintf("  EXIT  time  %6.2fs  (%6.2fs elapsed)\n",
                    TICK_TO_DBL(ExitUserTime), TICK_TO_DBL(ExitElapsedTime));
-           fprintf(sf, "  Total time  %6.2fs  (%6.2fs elapsed)\n\n",
+           statsPrintf("  Total time  %6.2fs  (%6.2fs elapsed)\n\n",
                    TICK_TO_DBL(time), TICK_TO_DBL(etime));
-           fprintf(sf, "  %%GC time     %5.1f%%  (%.1f%% elapsed)\n\n",
+           statsPrintf("  %%GC time     %5.1f%%  (%.1f%% elapsed)\n\n",
                    TICK_TO_DBL(GC_tot_time)*100/TICK_TO_DBL(time),
                    TICK_TO_DBL(GCe_tot_time)*100/TICK_TO_DBL(etime));
 
-           if (time - GC_tot_time - RP_tot_time - LDV_tot_time == 0)
+           if (time - GC_tot_time - PROF_VAL(RP_tot_time + HC_tot_time) == 0)
                ullong_format_string(0, temp, rtsTrue/*commas*/);
            else
                ullong_format_string(
                    (ullong)((GC_tot_alloc*sizeof(W_))/
-                            TICK_TO_DBL(time - GC_tot_time - RP_tot_time - LDV_tot_time)),
+                            TICK_TO_DBL(time - GC_tot_time - 
+                                        PROF_VAL(RP_tot_time + HC_tot_time))),
                    temp, rtsTrue/*commas*/);
            
-           fprintf(sf, "  Alloc rate    %s bytes per MUT second\n\n", temp);
+           statsPrintf("  Alloc rate    %s bytes per MUT second\n\n", temp);
        
-           fprintf(sf, "  Productivity %5.1f%% of total user, %.1f%% of total elapsed\n\n",
-                   TICK_TO_DBL(time - GC_tot_time - RP_tot_time - LDV_tot_time - InitUserTime) * 100 
+           statsPrintf("  Productivity %5.1f%% of total user, %.1f%% of total elapsed\n\n",
+                   TICK_TO_DBL(time - GC_tot_time - 
+                               PROF_VAL(RP_tot_time + HC_tot_time) - InitUserTime) * 100 
                    / TICK_TO_DBL(time), 
-                   TICK_TO_DBL(time - GC_tot_time - RP_tot_time - LDV_tot_time - InitUserTime) * 100 
+                   TICK_TO_DBL(time - GC_tot_time - 
+                               PROF_VAL(RP_tot_time + HC_tot_time) - InitUserTime) * 100 
                    / TICK_TO_DBL(etime));
        }
 
-       if (RtsFlags.GcFlags.giveStats == ONELINE_GC_STATS && sf != NULL) {
+       if (RtsFlags.GcFlags.giveStats == ONELINE_GC_STATS) {
          /* print the long long separately to avoid bugginess on mingwin (2001-07-02, mingw-0.5) */
-         fprintf(sf, "<<ghc: %llu bytes, ", GC_tot_alloc*sizeof(W_));
-         fprintf(sf, "%d GCs, %ld/%ld avg/max bytes residency (%ld samples), %luM in use, %.2f INIT (%.2f elapsed), %.2f MUT (%.2f elapsed), %.2f GC (%.2f elapsed) :ghc>>\n",
+         statsPrintf("<<ghc: %llu bytes, ", GC_tot_alloc*(ullong)sizeof(W_));
+         statsPrintf("%d GCs, %ld/%ld avg/max bytes residency (%ld samples), %luM in use, %.2f INIT (%.2f elapsed), %.2f MUT (%.2f elapsed), %.2f GC (%.2f elapsed) :ghc>>\n",
                    total_collections,
-                   AvgResidency*sizeof(W_)/ResidencySamples, 
+                   ResidencySamples == 0 ? 0 : 
+                       AvgResidency*sizeof(W_)/ResidencySamples, 
                    MaxResidency*sizeof(W_), 
                    ResidencySamples,
                    (unsigned long)(mblocks_allocated * MBLOCK_SIZE / (1024L * 1024L)),
@@ -742,8 +740,8 @@ stat_exit(int alloc)
                    TICK_TO_DBL(GC_tot_time), TICK_TO_DBL(GCe_tot_time));
        }
 
-       fflush(sf);
-       fclose(sf);
+       statsFlush();
+       statsClose();
     }
 }
 
@@ -756,22 +754,20 @@ stat_exit(int alloc)
 void
 statDescribeGens(void)
 {
-  nat g, s, mut, mut_once, lge, live;
-  StgMutClosure *m;
+  nat g, s, mut, lge, live;
   bdescr *bd;
   step *step;
 
-  fprintf(stderr, "     Gen    Steps      Max   Mutable  Mut-Once  Step   Blocks     Live    Large\n                    Blocks  Closures  Closures                          Objects\n");
+  debugBelch("     Gen    Steps      Max   Mutable  Step   Blocks     Live    Large\n                    Blocks  Closures  Closures                          Objects\n");
 
+  mut = 0;
   for (g = 0; g < RtsFlags.GcFlags.generations; g++) {
-    for (m = generations[g].mut_list, mut = 0; m != END_MUT_LIST; 
-        m = m->mut_link) 
-      mut++;
-    for (m = generations[g].mut_once_list, mut_once = 0; m != END_MUT_LIST; 
-        m = m->mut_link) 
-      mut_once++;
-    fprintf(stderr, "%8d %8d %8d %9d %9d", g, generations[g].n_steps,
-           generations[g].max_blocks, mut, mut_once);
+      for (bd = generations[g].mut_list; bd != NULL; bd = bd->link) {
+         mut += bd->free - bd->start;
+      }
+
+    debugBelch("%8d %8d %8d %9d", g, generations[g].n_steps,
+           generations[g].max_blocks, mut);
 
     for (s = 0; s < generations[g].n_steps; s++) {
       step = &generations[g].steps[s];
@@ -787,13 +783,13 @@ statDescribeGens(void)
        live += (bd->free - bd->start) * sizeof(W_);
       }
       if (s != 0) {
-       fprintf(stderr,"%46s","");
+       debugBelch("%46s","");
       }
-      fprintf(stderr,"%6d %8d %8d %8d\n", s, step->n_blocks,
+      debugBelch("%6d %8d %8d %8d\n", s, step->n_blocks,
              live, lge);
     }
   }
-  fprintf(stderr,"\n");
+  debugBelch("\n");
 }
 #endif
 
@@ -802,5 +798,42 @@ statDescribeGens(void)
    each compilation and expression evaluation.
    -------------------------------------------------------------------------- */
 
-extern HsInt getAllocations( void ) 
-{ return (HsInt)(total_allocated * sizeof(W_)); }
+extern HsInt64 getAllocations( void ) 
+{ return (HsInt64)total_allocated * sizeof(W_); }
+
+/* -----------------------------------------------------------------------------
+   Dumping stuff in the stats file, or via the debug message interface
+   -------------------------------------------------------------------------- */
+
+static void
+statsPrintf( char *s, ... )
+{
+    FILE *sf = RtsFlags.GcFlags.statsFile;
+    va_list ap;
+    
+    va_start(ap,s);
+    if (sf == NULL) {
+       vdebugBelch(s,ap);
+    } else {
+       vfprintf(sf, s, ap);
+    }
+    va_end(ap);
+}
+
+static void
+statsFlush( void )
+{
+    FILE *sf = RtsFlags.GcFlags.statsFile;
+    if (sf != NULL) {
+       fflush(sf);
+    }
+}
+
+static void
+statsClose( void )
+{
+    FILE *sf = RtsFlags.GcFlags.statsFile;
+    if (sf != NULL) {
+       fclose(sf);
+    }
+}