[project @ 2003-10-08 09:42:34 by wolfgang]
[ghc-hetmet.git] / ghc / rts / Stats.c
index c96f63c..5d4f772 100644 (file)
@@ -1,5 +1,5 @@
 /* -----------------------------------------------------------------------------
- * $Id: Stats.c,v 1.38 2001/11/25 16:59:11 sof Exp $
+ * $Id: Stats.c,v 1.46 2002/08/19 16:02:26 simonmar Exp $
  *
  * (c) The GHC Team, 1998-1999
  *
@@ -101,19 +101,19 @@ static TICK_TYPE GCe_start_time = 0, GCe_tot_time = 0;  /* Elapsed GC time */
 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  = 0, LDV_tot_time  = 0; /* LDV prof user time */
-static TICK_TYPE LDVe_start_time = 0, 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
 
 #ifdef PROFILING
-#define PROF_VAL(x)   x
+#define PROF_VAL(x)   (x)
 #else
 #define PROF_VAL(x)   0
 #endif
 
-lnat MaxResidency = 0;     /* in words; for stats only */
-lnat AvgResidency = 0;
-lnat ResidencySamples = 0; /* for stats only */
+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;
 
@@ -227,32 +227,32 @@ getTimes(void)
 double
 mut_user_time_during_GC( void )
 {
-  return TICK_TO_DBL(GC_start_time - GC_tot_time - PROF_VAL(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 - PROF_VAL(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 */
 
@@ -354,9 +354,10 @@ 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
      * all the running threads to find out, and they haven't stopped
      * yet.  So we just timestamp MutUserTime at this point so we can
@@ -366,7 +367,7 @@ stat_startExit(void)
 #ifdef SMP
     MutUserTime = CurrentUserTime;
 #else
-    MutUserTime = CurrentUserTime - GC_tot_time - PROF_VAL(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
 }
@@ -378,7 +379,7 @@ stat_endExit(void)
 #ifdef SMP
     ExitUserTime = CurrentUserTime - MutUserTime;
 #else
-    ExitUserTime = CurrentUserTime - MutUserTime - GC_tot_time - PROF_VAL(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) {
@@ -529,9 +530,7 @@ stat_endRP(
   nat maxCStackSize,
   int maxStackSize,
 #endif
-  double averageNumVisit,
-  nat allCost,
-  nat numSet)
+  double averageNumVisit)
 {
   getTimes();
   RP_tot_time += CurrentUserTime - RP_start_time;
@@ -544,34 +543,32 @@ 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 */
 
 /* -----------------------------------------------------------------------------
-   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 */
 
 /* -----------------------------------------------------------------------------
-   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 */
 
@@ -582,17 +579,19 @@ stat_endLDV(void)
    stats for this thread into the task_ids struct for that thread.
    -------------------------------------------------------------------------- */
 
-#ifdef SMP
+#if defined(SMP)
 void
 stat_workerStop(void)
 {
     nat i;
     pthread_t me = pthread_self();
 
+    getTimes();
+
     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()
+           task_ids[i].mut_time = CurrentUserTime - task_ids[i].gc_time;
+           task_ids[i].mut_etime = CurrentElapsedTime
                - GCe_tot_time
                - task_ids[i].elapsedtimestart;
            if (task_ids[i].mut_time < 0.0)  { task_ids[i].mut_time = 0.0;  }
@@ -602,6 +601,14 @@ stat_workerStop(void)
 }
 #endif
 
+#if defined(SMP)
+long int stat_getElapsedTime ()
+{
+  getTimes();
+  return CurrentElapsedTime;
+}
+#endif
+
 /* -----------------------------------------------------------------------------
    Called at the end of execution
 
@@ -704,12 +711,10 @@ stat_exit(int alloc)
            fprintf(sf, "  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));
+           fprintf(sf, "  RP    time  %6.2fs  (%6.2fs elapsed)\n",
+                   TICK_TO_DBL(RP_tot_time), TICK_TO_DBL(RPe_tot_time));
+           fprintf(sf, "  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",
                    TICK_TO_DBL(ExitUserTime), TICK_TO_DBL(ExitElapsedTime));
@@ -719,23 +724,23 @@ stat_exit(int alloc)
                    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 - PROF_VAL(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 - 
-                                        PROF_VAL(RP_tot_time - LDV_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);
        
            fprintf(sf, "  Productivity %5.1f%% of total user, %.1f%% of total elapsed\n\n",
                    TICK_TO_DBL(time - GC_tot_time - 
-                               PROF_VAL(RP_tot_time - LDV_tot_time) - InitUserTime) * 100 
+                               PROF_VAL(RP_tot_time + HC_tot_time) - InitUserTime) * 100 
                    / TICK_TO_DBL(time), 
                    TICK_TO_DBL(time - GC_tot_time - 
-                               PROF_VAL(RP_tot_time - LDV_tot_time) - InitUserTime) * 100 
+                               PROF_VAL(RP_tot_time + HC_tot_time) - InitUserTime) * 100 
                    / TICK_TO_DBL(etime));
        }
 
@@ -744,7 +749,8 @@ stat_exit(int alloc)
          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",
                    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)),
@@ -754,7 +760,9 @@ stat_exit(int alloc)
        }
 
        fflush(sf);
-       fclose(sf);
+       if (sf != stderr) {
+           fclose(sf);
+       }
     }
 }