[project @ 2005-10-21 14:02:17 by simonmar]
[ghc-hetmet.git] / ghc / rts / Stats.c
index efa3e31..62c3c52 100644 (file)
@@ -1,6 +1,6 @@
 /* -----------------------------------------------------------------------------
  *
- * (c) The GHC Team, 1998-2004
+ * (c) The GHC Team, 1998-2005
  *
  * Statistics and timing-related functions.
  *
@@ -19,7 +19,6 @@
 #include "ParTicky.h"                       /* ToDo: move into Rts.h */
 #include "Profiling.h"
 #include "Storage.h"
-#include "Task.h"
 
 #ifdef HAVE_UNISTD_H
 #include <unistd.h>
@@ -77,8 +76,6 @@
 static int TicksPerSecond = 0;
 
 static TICK_TYPE ElapsedTimeStart = 0;
-static TICK_TYPE CurrentElapsedTime = 0;
-static TICK_TYPE CurrentUserTime    = 0;
 
 static TICK_TYPE InitUserTime     = 0;
 static TICK_TYPE InitElapsedTime  = 0;
@@ -93,6 +90,7 @@ static TICK_TYPE ExitElapsedTime  = 0;
 
 static ullong GC_tot_alloc        = 0;
 static ullong GC_tot_copied       = 0;
+static ullong GC_tot_scavd_copied = 0;
 
 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 */
@@ -119,7 +117,7 @@ static lnat GC_start_faults = 0, GC_end_faults = 0;
 
 static TICK_TYPE *GC_coll_times;
 
-static void  getTimes(void);
+static void  getTimes( long *elapsed, long *user );
 static nat   pageFaults(void);
 
 static void statsPrintf( char *s, ... ) 
@@ -143,7 +141,7 @@ static void statsClose( void );
 #if defined(mingw32_HOST_OS) || defined(cygwin32_HOST_OS)
 /* cygwin32 or mingw32 version */
 static void
-getTimes(void)
+getTimes( TICK_TYPE *elapsed, TICK_TYPE *user )
 {
     static int is_win9x = -1;
 
@@ -175,29 +173,29 @@ getTimes(void)
       if (!GetProcessTimes (GetCurrentProcess(), &creationTime,
                          &exitTime, &kernelTime, &userTime)) {
        /* Probably on a Win95 box..*/
-       CurrentElapsedTime = 0;
-       CurrentUserTime = 0;
+       *elapsed = 0;
+       *user = 0;
        return;
       }
     }
 
     FT2longlong(kT,kernelTime);
     FT2longlong(uT,userTime);
-    CurrentElapsedTime = uT + kT;
-    CurrentUserTime = uT;
+    *elapsed = uT + kT;
+    *user = uT;
 
     if (is_win9x) {
       /* Adjust for the fact that we're using system time & not
         process time on Win9x. */
-      CurrentUserTime    -= ElapsedTimeStart;
-      CurrentElapsedTime -= ElapsedTimeStart;
+      *user    -= ElapsedTimeStart;
+      *elapsed -= ElapsedTimeStart;
     }
 }
 
 #else /* !win32 */
 
 static void
-getTimes(void)
+getTimes( TICK_TYPE *user, TICK_TYPE *elapsed )
 {
 
 #ifndef HAVE_TIMES
@@ -211,10 +209,9 @@ getTimes(void)
     struct tms t;
     clock_t r = times(&t);
 
-    CurrentElapsedTime = r;
-    CurrentUserTime = t.tms_utime;
+    *elapsed = r;
+    *user = t.tms_utime;
 #endif
-
 }
 #endif /* !win32 */
 
@@ -239,8 +236,9 @@ mut_user_time_during_GC( void )
 double
 mut_user_time( void )
 {
-    getTimes();
-    return TICK_TO_DBL(CurrentUserTime - GC_tot_time - PROF_VAL(RP_tot_time + HC_tot_time));
+    TICK_TYPE user, elapsed;
+    getTimes(&user, &elapsed);
+    return TICK_TO_DBL(user - GC_tot_time - PROF_VAL(RP_tot_time + HC_tot_time));
 }
 
 #ifdef PROFILING
@@ -302,6 +300,8 @@ initStats(void)
 void
 stat_startInit(void)
 {
+    TICK_TYPE user, elapsed;
+
     /* Determine TicksPerSecond ... */
 #if defined(CLK_TCK)           /* defined by POSIX */
     TicksPerSecond = CLK_TCK;
@@ -331,20 +331,21 @@ stat_startInit(void)
     TicksPerSecond = 60;
 #endif
 
-    getTimes();
-    ElapsedTimeStart = CurrentElapsedTime;
+    getTimes( &user, &elapsed );
+    ElapsedTimeStart = elapsed;
 }
 
 void 
 stat_endInit(void)
 {
-    getTimes();
-    InitUserTime = CurrentUserTime;
-    InitElapsedStamp = CurrentElapsedTime; 
-    if (ElapsedTimeStart > CurrentElapsedTime) {
+    TICK_TYPE user, elapsed;
+    getTimes( &user, &elapsed );
+    InitUserTime = user;
+    InitElapsedStamp = elapsed; 
+    if (ElapsedTimeStart > elapsed) {
        InitElapsedTime = 0;
     } else {
-       InitElapsedTime = CurrentElapsedTime - ElapsedTimeStart;
+       InitElapsedTime = elapsed - ElapsedTimeStart;
     }
 }
 
@@ -357,9 +358,11 @@ stat_endInit(void)
 void
 stat_startExit(void)
 {
-    getTimes();
-    MutElapsedStamp = CurrentElapsedTime;
-    MutElapsedTime = CurrentElapsedTime - GCe_tot_time -
+    TICK_TYPE user, elapsed;
+    getTimes( &user, &elapsed );
+
+    MutElapsedStamp = elapsed;
+    MutElapsedTime = elapsed - GCe_tot_time -
        PROF_VAL(RPe_tot_time + HCe_tot_time) - InitElapsedStamp;
     if (MutElapsedTime < 0) { MutElapsedTime = 0; }    /* sometimes -0.00 */
 
@@ -369,10 +372,10 @@ stat_startExit(void)
      * calculate the EXIT time.  The real MutUserTime is calculated
      * in stat_exit below.
      */
-#if defined(RTS_SUPPORTS_THREADS)
-    MutUserTime = CurrentUserTime;
+#if defined(THREADED_RTS)
+    MutUserTime = user;
 #else
-    MutUserTime = CurrentUserTime - GC_tot_time - PROF_VAL(RP_tot_time + HC_tot_time) - InitUserTime;
+    MutUserTime = user - GC_tot_time - PROF_VAL(RP_tot_time + HC_tot_time) - InitUserTime;
     if (MutUserTime < 0) { MutUserTime = 0; }
 #endif
 }
@@ -380,13 +383,15 @@ stat_startExit(void)
 void
 stat_endExit(void)
 {
-    getTimes();
-#if defined(RTS_SUPPORTS_THREADS)
-    ExitUserTime = CurrentUserTime - MutUserTime;
+    TICK_TYPE user, elapsed;
+    getTimes( &user, &elapsed );
+
+#if defined(THREADED_RTS)
+    ExitUserTime = user - MutUserTime;
 #else
-    ExitUserTime = CurrentUserTime - MutUserTime - GC_tot_time - PROF_VAL(RP_tot_time + HC_tot_time) - InitUserTime;
+    ExitUserTime = user - MutUserTime - GC_tot_time - PROF_VAL(RP_tot_time + HC_tot_time) - InitUserTime;
 #endif
-    ExitElapsedTime = CurrentElapsedTime - MutElapsedStamp;
+    ExitElapsedTime = elapsed - MutElapsedStamp;
     if (ExitUserTime < 0) {
        ExitUserTime = 0;
     }
@@ -410,6 +415,8 @@ void
 stat_startGC(void)
 {
     nat bell = RtsFlags.GcFlags.ringBell;
+    TICK_TYPE user, elapsed;
+
 
     if (bell) {
        if (bell > 1) {
@@ -421,16 +428,16 @@ stat_startGC(void)
     }
 
 #if defined(PROFILING) || defined(DEBUG)
-    getTimes();
-    GC_start_time = CurrentUserTime;  /* needed in mut_user_time_during_GC() */
+    getTimes( &user, &elapsed );
+    GC_start_time = user;  /* needed in mut_user_time_during_GC() */
 #endif
 
     if (RtsFlags.GcFlags.giveStats != NO_GC_STATS) {
 #if !defined(PROFILING) && !defined(DEBUG)
-       getTimes();
-        GC_start_time = CurrentUserTime;
+       getTimes( &user, &elapsed );
+        GC_start_time = user;
 #endif
-       GCe_start_time = CurrentElapsedTime;
+       GCe_start_time = elapsed;
        if (RtsFlags.GcFlags.giveStats) {
            GC_start_faults = pageFaults();
        }
@@ -442,14 +449,17 @@ stat_startGC(void)
    -------------------------------------------------------------------------- */
 
 void
-stat_endGC(lnat alloc, lnat collect, lnat live, lnat copied, lnat gen)
+stat_endGC (lnat alloc, lnat collect, lnat live, lnat copied, 
+           lnat scavd_copied, lnat gen)
 {
+    TICK_TYPE user, elapsed;
+
     if (RtsFlags.GcFlags.giveStats != NO_GC_STATS) {
        TICK_TYPE time, etime, gc_time, gc_etime;
        
-       getTimes();
-       time     = CurrentUserTime;
-       etime    = CurrentElapsedTime;
+       getTimes( &user, &elapsed );
+       time     = user;
+       etime    = elapsed;
        gc_time  = time - GC_start_time;
        gc_etime = etime - GCe_start_time;
        
@@ -474,17 +484,17 @@ stat_endGC(lnat alloc, lnat collect, lnat live, lnat copied, lnat gen)
        GC_coll_times[gen] += gc_time;
 
        GC_tot_copied += (ullong) copied;
+       GC_tot_scavd_copied += (ullong) scavd_copied;
        GC_tot_alloc  += (ullong) alloc;
        GC_tot_time   += gc_time;
        GCe_tot_time  += gc_etime;
        
-#if defined(RTS_SUPPORTS_THREADS)
+#if defined(THREADED_RTS)
        {
-           TaskInfo *task_info = taskOfId(osThreadId());
-           
-           if (task_info != NULL) {
-               task_info->gc_time += gc_time;
-               task_info->gc_etime += gc_etime;
+           Task *task;
+           if ((task = myTask()) != NULL) {
+               task->gc_time += gc_time;
+               task->gc_etime += gc_etime;
            }
        }
 #endif
@@ -511,9 +521,11 @@ stat_endGC(lnat alloc, lnat collect, lnat live, lnat copied, lnat gen)
 void
 stat_startRP(void)
 {
-  getTimes();
-  RP_start_time = CurrentUserTime;
-  RPe_start_time = CurrentElapsedTime;
+    TICK_TYPE user, elapsed;
+    getTimes( &user, &elapsed );
+
+    RP_start_time = user;
+    RPe_start_time = elapsed;
 }
 #endif /* PROFILING */
 
@@ -531,9 +543,11 @@ stat_endRP(
 #endif
   double averageNumVisit)
 {
-  getTimes();
-  RP_tot_time += CurrentUserTime - RP_start_time;
-  RPe_tot_time += CurrentElapsedTime - RPe_start_time;
+    TICK_TYPE user, elapsed;
+    getTimes( &user, &elapsed );
+
+    RP_tot_time += user - RP_start_time;
+    RPe_tot_time += elapsed - RPe_start_time;
 
   fprintf(prof_file, "Retainer Profiling: %d, at %f seconds\n", 
     retainerGeneration, mut_user_time_during_RP());
@@ -552,9 +566,11 @@ stat_endRP(
 void
 stat_startHeapCensus(void)
 {
-  getTimes();
-  HC_start_time = CurrentUserTime;
-  HCe_start_time = CurrentElapsedTime;
+    TICK_TYPE user, elapsed;
+    getTimes( &user, &elapsed );
+
+    HC_start_time = user;
+    HCe_start_time = elapsed;
 }
 #endif /* PROFILING */
 
@@ -565,9 +581,11 @@ stat_startHeapCensus(void)
 void
 stat_endHeapCensus(void) 
 {
-  getTimes();
-  HC_tot_time += CurrentUserTime - HC_start_time;
-  HCe_tot_time += CurrentElapsedTime - HCe_start_time;
+    TICK_TYPE user, elapsed;
+    getTimes( &user, &elapsed );
+
+    HC_tot_time += user - HC_start_time;
+    HCe_tot_time += elapsed - HCe_start_time;
 }
 #endif /* PROFILING */
 
@@ -583,9 +601,7 @@ stat_getTimes ( long *currentElapsedTime,
                long *currentUserTime,
                long *elapsedGCTime )
 {
-  getTimes();
-  *currentElapsedTime = CurrentElapsedTime;
-  *currentUserTime = CurrentUserTime;
+  getTimes(currentUserTime, currentElapsedTime);
   *elapsedGCTime = GCe_tot_time;
 }
 
@@ -600,6 +616,8 @@ stat_getTimes ( long *currentElapsedTime,
 void
 stat_exit(int alloc)
 {
+    TICK_TYPE user, elapsed;
+
     if (RtsFlags.GcFlags.giveStats != NO_GC_STATS) {
 
        char temp[BIG_STRING_LEN];
@@ -607,8 +625,8 @@ stat_exit(int alloc)
        TICK_TYPE etime;
        nat g, total_collections = 0;
 
-       getTimes();
-       etime = CurrentElapsedTime - ElapsedTimeStart;
+       getTimes( &user, &elapsed );
+       etime = elapsed - ElapsedTimeStart;
 
        GC_tot_alloc += alloc;
 
@@ -616,21 +634,21 @@ stat_exit(int alloc)
        for (g = 0; g < RtsFlags.GcFlags.generations; g++)
            total_collections += generations[g].collections;
 
-       /* For SMP, we have to get the user time from each thread
+       /* For THREADED_RTS, we have to get the user time from each Task
         * and try to work out the total time.
         */
-#if defined(RTS_SUPPORTS_THREADS)
+#if defined(THREADED_RTS)
        {   
-           nat i;
+           Task *task;
            MutUserTime = 0.0;
-           for (i = 0; i < taskCount; i++) {
-               MutUserTime += taskTable[i].mut_time;
+           for (task = all_tasks; task != NULL; task = task->all_link) {
+               MutUserTime += task->mut_time;
            }
        }
        time = MutUserTime + GC_tot_time + InitUserTime + ExitUserTime;
        if (MutUserTime < 0) { MutUserTime = 0; }
 #else
-       time = CurrentUserTime;
+       time = user;
 #endif
 
        /* avoid divide by zero if time is measured as 0.00 seconds -- SDM */
@@ -649,8 +667,12 @@ stat_exit(int alloc)
 
            ullong_format_string(GC_tot_copied*sizeof(W_), 
                                 temp, rtsTrue/*commas*/);
-           statsPrintf("%11s bytes copied during GC\n", temp);
+           statsPrintf("%11s bytes copied during GC (scavenged)\n", temp);
 
+           ullong_format_string(GC_tot_scavd_copied*sizeof(W_), 
+                                temp, rtsTrue/*commas*/);
+           statsPrintf("%11s bytes copied during GC (not scavenged)\n", temp);
+  
            if ( ResidencySamples > 0 ) {
                ullong_format_string(MaxResidency*sizeof(W_), 
                                     temp, rtsTrue/*commas*/);
@@ -669,18 +691,21 @@ stat_exit(int alloc)
            statsPrintf("\n%11ld Mb total memory in use\n\n", 
                    mblocks_allocated * MBLOCK_SIZE / (1024 * 1024));
 
-#if defined(RTS_SUPPORTS_THREADS)
+#if defined(THREADED_RTS)
            {
                nat i;
-               for (i = 0; i < taskCount; i++) {
+               Task *task;
+               for (i = 0, task = all_tasks; 
+                    task != NULL; 
+                    i++, task = task->all_link) {
                    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));
+                               (task->tso == NULL) ? "(worker)" : "(bound)",
+                               TICK_TO_DBL(task->mut_time),
+                               TICK_TO_DBL(task->mut_etime),
+                               TICK_TO_DBL(task->gc_time),
+                               TICK_TO_DBL(task->gc_etime));
                }
            }
 #endif
@@ -758,7 +783,9 @@ statDescribeGens(void)
   bdescr *bd;
   step *step;
 
-  debugBelch("     Gen    Steps      Max   Mutable  Step   Blocks     Live    Large\n                    Blocks  Closures  Closures                          Objects\n");
+  debugBelch(
+"     Gen    Steps      Max   Mutable  Step   Blocks     Live    Large\n"
+"                     Blocks Closures                          Objects\n");
 
   mut = 0;
   for (g = 0; g < RtsFlags.GcFlags.generations; g++) {
@@ -774,16 +801,12 @@ statDescribeGens(void)
       for (bd = step->large_objects, lge = 0; bd; bd = bd->link)
        lge++;
       live = 0;
-      if (RtsFlags.GcFlags.generations == 1) {
-       bd = step->to_blocks;
-      } else {
-       bd = step->blocks;
-      }
+      bd = step->blocks;
       for (; bd; bd = bd->link) {
        live += (bd->free - bd->start) * sizeof(W_);
       }
       if (s != 0) {
-       debugBelch("%46s","");
+       debugBelch("%36s","");
       }
       debugBelch("%6d %8d %8d %8d\n", s, step->n_blocks,
              live, lge);