[project @ 2002-07-05 01:23:45 by mthomas]
[ghc-hetmet.git] / ghc / rts / Profiling.c
index 38d620d..902c391 100644 (file)
@@ -1,5 +1,5 @@
 /* -----------------------------------------------------------------------------
- * $Id: Profiling.c,v 1.18 2000/04/05 15:21:28 simonmar Exp $
+ * $Id: Profiling.c,v 1.32 2002/07/05 01:23:45 mthomas Exp $
  *
  * (c) The GHC Team, 1998-2000
  *
@@ -9,6 +9,7 @@
 
 #ifdef PROFILING
 
+#include "PosixSource.h"
 #include "Rts.h"
 #include "RtsUtils.h"
 #include "RtsFlags.h"
 #include "Proftimer.h"
 #include "Itimer.h"
 #include "ProfHeap.h"
+#include "Arena.h"
+#include "RetainerProfile.h"
+#include "LdvProfile.h"
+
+/*
+ * Profiling allocation arena.
+ */
+Arena *prof_arena;
 
 /*
  * Global variables used to assign unique IDs to cc's, ccs's, and 
@@ -27,30 +36,18 @@ unsigned int CC_ID;
 unsigned int CCS_ID;
 unsigned int HP_ID;
 
-/* Table sizes from old profiling system.  Not sure if we'll need
- * these.
- */
-nat time_intervals = 0;
-nat earlier_ticks  = 0;
-nat max_cc_no      = 0;
-nat max_mod_no     = 0;
-nat max_grp_no     = 0;
-nat max_descr_no   = 0;
-nat max_type_no    = 0;
-
-/* Are we time-profiling?
- */
-rtsBool time_profiling = rtsFalse;
-
 /* figures for the profiling report.
  */
 static lnat total_alloc, total_prof_ticks;
 
-/* Globals for opening the profiling log file
+/* Globals for opening the profiling log file(s)
  */
 static char *prof_filename; /* prof report file name = <program>.prof */
 FILE *prof_file;
 
+static char *hp_filename;      /* heap profile (hp2ps style) log file */
+FILE *hp_file;
+
 /* The Current Cost Centre Stack (for attributing costs)
  */
 CostCentreStack *CCCS;
@@ -116,29 +113,27 @@ CCS_DECLARE(CCS_DONT_CARE,  CC_DONT_CARE, );
  * Static Functions
  */
 
-static CostCentreStack * ActualPush_ ( CostCentreStack *ccs, CostCentre *cc, 
-                                      CostCentreStack *new_ccs );
-
-static rtsBool ccs_to_ignore       ( CostCentreStack *ccs );
-static    void count_ticks         ( CostCentreStack *ccs );
-static    void reportCCS           ( CostCentreStack *ccs, nat indent );
-static    void DecCCS              ( CostCentreStack *ccs );
-static    void DecBackEdge ( CostCentreStack *ccs, CostCentreStack *oldccs );
-static    CostCentreStack *CheckLoop ( CostCentreStack *ccs, CostCentre *cc );
-static    CostCentreStack *pruneCCSTree ( CostCentreStack *ccs );
-
-static    CostCentreStack *ActualPush ( CostCentreStack *, CostCentre * );
-static    CostCentreStack *IsInIndexTable ( IndexTable *, CostCentre * );
-static    IndexTable *AddToIndexTable ( IndexTable *, CostCentreStack *, 
-                                       CostCentre *, unsigned int );
-
-#ifdef DEBUG
-static    void printCCS            ( CostCentreStack *ccs );
-#endif
-static    void initTimeProfiling   ( void );
-static    void initProfilingLogFile( void );
-
-static    void reportCCS_XML       ( CostCentreStack *ccs );
+static  CostCentreStack * ActualPush_     ( CostCentreStack *ccs, CostCentre *cc, 
+                                           CostCentreStack *new_ccs );
+static  rtsBool           ccs_to_ignore   ( CostCentreStack *ccs );
+static  void              count_ticks     ( CostCentreStack *ccs );
+static  void              inherit_costs   ( CostCentreStack *ccs );
+static  void              reportCCS       ( CostCentreStack *ccs, nat indent );
+static  void              DecCCS          ( CostCentreStack *ccs );
+static  void              DecBackEdge     ( CostCentreStack *ccs, 
+                                           CostCentreStack *oldccs );
+static  CostCentreStack * CheckLoop       ( CostCentreStack *ccs, CostCentre *cc );
+static  CostCentreStack * pruneCCSTree    ( CostCentreStack *ccs );
+static  CostCentreStack * ActualPush      ( CostCentreStack *, CostCentre * );
+static  CostCentreStack * IsInIndexTable  ( IndexTable *, CostCentre * );
+static  IndexTable *      AddToIndexTable ( IndexTable *, CostCentreStack *, 
+                                           CostCentre *, unsigned int );
+static  void              ccsSetSelected  ( CostCentreStack *ccs );
+
+static  void              initTimeProfiling   ( void );
+static  void              initProfilingLogFile( void );
+
+static  void              reportCCS_XML       ( CostCentreStack *ccs );
 
 /* -----------------------------------------------------------------------------
    Initialise the profiling environment
@@ -147,9 +142,12 @@ static    void reportCCS_XML       ( CostCentreStack *ccs );
 void
 initProfiling1 (void)
 {
+  // initialise our arena
+  prof_arena = newArena();
+
   /* for the benefit of allocate()... */
   CCCS = CCS_SYSTEM;
-
+  
   /* Initialize counters for IDs */
   CC_ID  = 1;
   CCS_ID = 1;
@@ -198,7 +196,9 @@ initProfiling2 (void)
    */
   ASSERT(CCS_MAIN->prevStack == 0);
   CCS_MAIN->root = CC_MAIN;
+  ccsSetSelected(CCS_MAIN);
   DecCCS(CCS_MAIN);
+
   for (ccs = CCS_LIST; ccs != CCS_MAIN; ) {
     next = ccs->prevStack;
     ccs->prevStack = 0;
@@ -215,42 +215,96 @@ initProfiling2 (void)
     initHeapProfiling();
   }
 }
-  
-static void
-initProfilingLogFile(void)
+
+// Decide whether closures with this CCS should contribute to the heap
+// profile.
+static void 
+ccsSetSelected( CostCentreStack *ccs )
 {
-  /* Initialise the log file name */
-  prof_filename = stgMallocBytes(strlen(prog_argv[0]) + 6, "initProfiling");
-  sprintf(prof_filename, "%s.prof", prog_argv[0]);
+    if (RtsFlags.ProfFlags.modSelector) {
+       if (! strMatchesSelector( ccs->cc->module,
+                                 RtsFlags.ProfFlags.modSelector ) ) {
+           ccs->selected = 0;
+           return;
+       }
+    }
+    if (RtsFlags.ProfFlags.ccSelector) {
+       if (! strMatchesSelector( ccs->cc->label,
+                                 RtsFlags.ProfFlags.ccSelector ) ) {
+           ccs->selected = 0;
+           return;
+       }
+    }
+    if (RtsFlags.ProfFlags.ccsSelector) {
+       CostCentreStack *c;
+       for (c = ccs; c != NULL; c = c->prevStack) {
+           if ( strMatchesSelector( c->cc->label,
+                                    RtsFlags.ProfFlags.ccsSelector )) {
+               break; 
+           }
+       }
+       if (c == NULL) {
+           ccs->selected = 0;
+           return;
+       }
+    }
 
-  /* open the log file */
-  if ((prof_file = fopen(prof_filename, "w")) == NULL) {
-    fprintf(stderr, "Can't open profiling report file %s\n", prof_filename);
-    RtsFlags.CcFlags.doCostCentres = 0;
+    ccs->selected = 1;
     return;
-  }
+}
 
-  if (RtsFlags.CcFlags.doCostCentres == COST_CENTRES_XML) {
-    /* dump the time, and the profiling interval */
-    fprintf(prof_file, "\"%s\"\n", time_str());
-    fprintf(prof_file, "\"%d ms\"\n", TICK_MILLISECS);
+
+static void
+initProfilingLogFile(void)
+{
+    /* Initialise the log file name */
+    prof_filename = arenaAlloc(prof_arena, strlen(prog_argv[0]) + 6);
+    sprintf(prof_filename, "%s.prof", prog_argv[0]);
+
+    /* open the log file */
+    if ((prof_file = fopen(prof_filename, "w")) == NULL) {
+       fprintf(stderr, "Can't open profiling report file %s\n", prof_filename);
+       RtsFlags.CcFlags.doCostCentres = 0;
+        // The following line was added by Sung; retainer/LDV profiling may need
+        // two output files, i.e., <program>.prof/hp.
+        if (RtsFlags.ProfFlags.doHeapProfile == HEAP_BY_RETAINER)
+            RtsFlags.ProfFlags.doHeapProfile = 0;
+       return;
+    }
+
+    if (RtsFlags.CcFlags.doCostCentres == COST_CENTRES_XML) {
+       /* dump the time, and the profiling interval */
+       fprintf(prof_file, "\"%s\"\n", time_str());
+       fprintf(prof_file, "\"%d ms\"\n", TICK_MILLISECS);
+       
+       /* declare all the cost centres */
+       {
+           CostCentre *cc;
+           for (cc = CC_LIST; cc != NULL; cc = cc->link) {
+               fprintf(prof_file, "%d %d \"%s\" \"%s\"\n",
+                       CC_UQ, cc->ccID, cc->label, cc->module);
+           }
+       }
+    }
     
-    /* declare all the cost centres */
-    {
-      CostCentre *cc;
-      for (cc = CC_LIST; cc != NULL; cc = cc->link) {
-       fprintf(prof_file, "%d %d \"%s\" \"%s\"\n",
-               CC_UQ, cc->ccID, cc->label, cc->module);
-      }
+    if (RtsFlags.ProfFlags.doHeapProfile) {
+       /* Initialise the log file name */
+       hp_filename = arenaAlloc(prof_arena, strlen(prog_argv[0]) + 6);
+       sprintf(hp_filename, "%s.hp", prog_argv[0]);
+       
+       /* open the log file */
+       if ((hp_file = fopen(hp_filename, "w")) == NULL) {
+           fprintf(stderr, "Can't open profiling report file %s\n", 
+                   hp_filename);
+           RtsFlags.ProfFlags.doHeapProfile = 0;
+           return;
+       }
     }
-  }
 }
 
 void
 initTimeProfiling(void)
 {
-  time_profiling = rtsTrue;
-
   /* Start ticking */
   startProfTimer();
 };
@@ -299,7 +353,7 @@ PushCostCentre ( CostCentreStack *ccs, CostCentre *cc )
 {
   IF_DEBUG(prof, 
           fprintf(stderr,"Pushing %s on ", cc->label);
-          printCCS(ccs);
+          fprintCCS(stderr,ccs);
           fprintf(stderr,"\n"));
   return PushCostCentre(ccs,cc);
 }
@@ -361,9 +415,9 @@ AppendCCS ( CostCentreStack *ccs1, CostCentreStack *ccs2 )
   IF_DEBUG(prof, 
           if (ccs1 != ccs2) {
             fprintf(stderr,"Appending ");
-            printCCS(ccs1);
+            fprintCCS(stderr,ccs1);
             fprintf(stderr," to ");
-            printCCS(ccs2);
+            fprintCCS(stderr,ccs2);
             fprintf(stderr,"\n");});
   return AppendCCS(ccs1,ccs2);
 }
@@ -395,7 +449,7 @@ ActualPush ( CostCentreStack *ccs, CostCentre *cc )
   CostCentreStack *new_ccs;
   
   /* allocate space for a new CostCentreStack */
-  new_ccs = (CostCentreStack *) stgMallocBytes(sizeof(CostCentreStack), "Error allocating space for CostCentreStack");
+  new_ccs = (CostCentreStack *) arenaAlloc(prof_arena, sizeof(CostCentreStack));
   
   return ActualPush_(ccs, cc, new_ccs);
 }
@@ -414,17 +468,20 @@ ActualPush_ ( CostCentreStack *ccs, CostCentre *cc, CostCentreStack *new_ccs )
   /* Initialise the various _scc_ counters to zero
    */
   new_ccs->scc_count        = 0;
-  new_ccs->sub_scc_count    = 0;
-  new_ccs->sub_cafcc_count  = 0;
   
   /* Initialize all other stats here.  There should be a quick way
    * that's easily used elsewhere too 
    */
   new_ccs->time_ticks = 0;
   new_ccs->mem_alloc = 0;
+  new_ccs->inherited_ticks = 0;
+  new_ccs->inherited_alloc = 0;
   
   new_ccs->root = ccs->root;
 
+  // Set the selected field.
+  ccsSetSelected(new_ccs);
+
   /* update the memoization table for the parent stack */
   if (ccs != EMPTY_STACK)
     ccs->indexTable = AddToIndexTable(ccs->indexTable, new_ccs, cc, 
@@ -460,7 +517,7 @@ AddToIndexTable(IndexTable *it, CostCentreStack *new_ccs,
 {
   IndexTable *new_it;
   
-  new_it = stgMallocBytes(sizeof(IndexTable), "AddToIndexTable");
+  new_it = arenaAlloc(prof_arena, sizeof(IndexTable));
   
   new_it->cc = cc;
   new_it->ccs = new_ccs;
@@ -470,27 +527,6 @@ AddToIndexTable(IndexTable *it, CostCentreStack *new_ccs,
 }
 
 
-void
-print_ccs (FILE *fp, CostCentreStack *ccs)
-{
-  if (ccs == CCCS) {
-    fprintf(fp, "Cost-Centre Stack: ");
-  }
-  
-  if (ccs != CCS_MAIN)
-    {
-      print_ccs(fp, ccs->prevStack);
-      fprintf(fp, "->[%s,%s]", ccs->cc->label, ccs->cc->module);
-    } else {
-      fprintf(fp, "[%s,%s]", ccs->cc->label, ccs->cc->module);
-    }
-      
-  if (ccs == CCCS) {
-    fprintf(fp, "\n");
-  }
-}
-
-
 static void
 DecCCS(CostCentreStack *ccs)
 {
@@ -521,6 +557,35 @@ DecBackEdge( CostCentreStack *ccs, CostCentreStack *oldccs )
    Generating a time & allocation profiling report.
    -------------------------------------------------------------------------- */
 
+/* We omit certain system-related CCs and CCSs from the default
+ * reports, so as not to cause confusion.
+ */
+static rtsBool
+cc_to_ignore (CostCentre *cc)
+{
+    if (    cc == CC_OVERHEAD 
+        || cc == CC_DONT_CARE
+        || cc == CC_GC 
+        || cc == CC_SYSTEM) {
+       return rtsTrue;
+    } else {
+       return rtsFalse;
+    }
+}
+
+static rtsBool
+ccs_to_ignore (CostCentreStack *ccs)
+{
+    if (    ccs == CCS_OVERHEAD 
+        || ccs == CCS_DONT_CARE
+        || ccs == CCS_GC 
+        || ccs == CCS_SYSTEM) {
+       return rtsTrue;
+    } else {
+       return rtsFalse;
+    }
+}
+
 /* -----------------------------------------------------------------------------
    Generating the aggregated per-cost-centre time/alloc report.
    -------------------------------------------------------------------------- */
@@ -572,12 +637,13 @@ report_per_cc_costs( void )
   for (cc = CC_LIST; cc != NULL; cc = next) {
     next = cc->link;
     if (cc->time_ticks > total_prof_ticks/100
-       || cc->mem_alloc > total_alloc/100) {
+       || cc->mem_alloc > total_alloc/100
+       || RtsFlags.CcFlags.doCostCentres >= COST_CENTRES_ALL) {
       insert_cc_in_sorted_list(cc);
     }
   }
   
-  fprintf(prof_file, "%-20s %-10s", "COST CENTRE", "MODULE");  
+  fprintf(prof_file, "%-30s %-20s", "COST CENTRE", "MODULE");  
   fprintf(prof_file, "%6s %6s", "%time", "%alloc");
   if (RtsFlags.CcFlags.doCostCentres >= COST_CENTRES_VERBOSE) {
     fprintf(prof_file, "  %5s %9s", "ticks", "bytes");
@@ -585,17 +651,20 @@ report_per_cc_costs( void )
   fprintf(prof_file, "\n\n");
 
   for (cc = sorted_cc_list; cc != NULL; cc = cc->link) {
-    fprintf(prof_file, "%-20s %-10s", cc->label, cc->module);
-    fprintf(prof_file, "%6.1f %6.1f",
-           total_prof_ticks == 0 ? 0.0 : (cc->time_ticks / (StgFloat) total_prof_ticks * 100),
-           total_alloc == 0 ? 0.0 : (cc->mem_alloc / (StgFloat)
-                                     total_alloc * 100)
-           );
-
-    if (RtsFlags.CcFlags.doCostCentres >= COST_CENTRES_VERBOSE) {
-      fprintf(prof_file, "  %5ld %9ld", cc->time_ticks, cc->mem_alloc);
-    }
-    fprintf(prof_file, "\n");
+      if (cc_to_ignore(cc)) {
+         continue;
+      }
+      fprintf(prof_file, "%-30s %-20s", cc->label, cc->module);
+      fprintf(prof_file, "%6.1f %6.1f",
+             total_prof_ticks == 0 ? 0.0 : (cc->time_ticks / (StgFloat) total_prof_ticks * 100),
+             total_alloc == 0 ? 0.0 : (cc->mem_alloc / (StgFloat)
+                                       total_alloc * 100)
+         );
+      
+      if (RtsFlags.CcFlags.doCostCentres >= COST_CENTRES_VERBOSE) {
+         fprintf(prof_file, "  %5ld %9lld", cc->time_ticks, cc->mem_alloc);
+      }
+      fprintf(prof_file, "\n");
   }
 
   fprintf(prof_file,"\n\n");
@@ -608,9 +677,10 @@ report_per_cc_costs( void )
 static void 
 fprint_header( void )
 {
-  fprintf(prof_file, "%-24s %-10s", "COST CENTRE", "MODULE");  
+  fprintf(prof_file, "%-24s %-10s                                                            individual    inherited\n", "", "");
 
-  fprintf(prof_file, "%8s %5s %5s %8s %5s", "scc", "%time", "%alloc", "inner", "cafs");
+  fprintf(prof_file, "%-24s %-50s", "COST CENTRE", "MODULE");  
+  fprintf(prof_file, "%6s %10s  %5s %5s   %5s %5s", "no.", "entries", "%time", "%alloc", "%time", "%alloc");
 
   if (RtsFlags.CcFlags.doCostCentres >= COST_CENTRES_VERBOSE) {
     fprintf(prof_file, "  %5s %9s", "ticks", "bytes");
@@ -624,7 +694,7 @@ fprint_header( void )
 }
 
 void
-report_ccs_profiling( void )
+reportCCSProfiling( void )
 {
     nat count;
     char temp[128]; /* sigh: magic constant */
@@ -673,10 +743,10 @@ report_ccs_profiling( void )
 
     report_per_cc_costs();
 
+    inherit_costs(CCS_MAIN);
+
     fprint_header();
     reportCCS(pruneCCSTree(CCS_MAIN), 0);
-
-    fclose(prof_file);
 }
 
 static void 
@@ -694,17 +764,19 @@ reportCCS(CostCentreStack *ccs, nat indent)
        /* force printing of *all* cost centres if -P -P */ 
     {
 
-    fprintf(prof_file, "%-*s%-*s %-10s", 
+    fprintf(prof_file, "%-*s%-*s %-50s", 
            indent, "", 24-indent, cc->label, cc->module);
 
-    fprintf(prof_file, "%8ld %5.1f %5.1f %8ld %5ld",
-           ccs->scc_count, 
-           total_prof_ticks == 0 ? 0.0 : (ccs->time_ticks / (StgFloat) total_prof_ticks * 100),
-           total_alloc == 0 ? 0.0 : (ccs->mem_alloc / (StgFloat) total_alloc * 100),
-           ccs->sub_scc_count, ccs->sub_cafcc_count);
-    
+    fprintf(prof_file, "%6d %11.0f %5.1f  %5.1f   %5.1f  %5.1f",
+           ccs->ccsID, (double) ccs->scc_count, 
+           total_prof_ticks == 0 ? 0.0 : ((double)ccs->time_ticks / (double)total_prof_ticks * 100.0),
+           total_alloc == 0 ? 0.0 : ((double)ccs->mem_alloc / (double)total_alloc * 100.0),
+           total_prof_ticks == 0 ? 0.0 : ((double)ccs->inherited_ticks / (double)total_prof_ticks * 100.0),
+           total_alloc == 0 ? 0.0 : ((double)ccs->inherited_alloc / (double)total_alloc * 100.0)
+           );
+
     if (RtsFlags.CcFlags.doCostCentres >= COST_CENTRES_VERBOSE) {
-      fprintf(prof_file, "  %5ld %9ld", ccs->time_ticks, ccs->mem_alloc*sizeof(W_));
+      fprintf(prof_file, "  %5ld %9lld", ccs->time_ticks, ccs->mem_alloc*sizeof(W_));
 #if defined(PROFILING_DETAIL_COUNTS)
       fprintf(prof_file, "  %8ld %8ld %8ld %8ld %8ld %8ld %8ld",
              ccs->mem_allocs, ccs->thunk_count,
@@ -723,6 +795,7 @@ reportCCS(CostCentreStack *ccs, nat indent)
   }
 }
 
+
 /* Traverse the cost centre stack tree and accumulate
  * ticks/allocations.
  */
@@ -741,21 +814,26 @@ count_ticks(CostCentreStack *ccs)
     }
 }
 
-/* return rtsTrue if it is one of the ones that
- * should not be reported normally (because it confuses
- * the users)
+/* Traverse the cost centre stack tree and inherit ticks & allocs.
  */
-static rtsBool
-ccs_to_ignore (CostCentreStack *ccs)
+static void
+inherit_costs(CostCentreStack *ccs)
 {
-    if (    ccs == CCS_OVERHEAD 
-        || ccs == CCS_DONT_CARE
-        || ccs == CCS_GC 
-        || ccs == CCS_SYSTEM) {
-       return rtsTrue;
-    } else {
-       return rtsFalse;
-    }
+  IndexTable *i;
+
+  if (ccs_to_ignore(ccs)) { return; }
+
+  ccs->inherited_ticks += ccs->time_ticks;
+  ccs->inherited_alloc += ccs->mem_alloc;
+
+  for (i = ccs->indexTable; i != NULL; i = i->next)
+      if (!i->back_edge) {
+         inherit_costs(i->ccs);
+         ccs->inherited_ticks += i->ccs->inherited_ticks;
+         ccs->inherited_alloc += i->ccs->inherited_alloc;
+      }
+  
+  return;
 }
 
 static CostCentreStack *
@@ -780,17 +858,11 @@ pruneCCSTree( CostCentreStack *ccs )
        /* force printing of *all* cost centres if -P -P */ )
        
        || ( ccs->indexTable != 0 )
-       || ( (ccs->scc_count || ccs->sub_scc_count || 
-            ccs->time_ticks || ccs->mem_alloc
-            || (RtsFlags.CcFlags.doCostCentres >= COST_CENTRES_VERBOSE
-                && (ccs->sub_cafcc_count
-#if defined(PROFILING_DETAIL_COUNTS)
-                    || cc->thunk_count || cc->function_count || cc->pap_count
-#endif
-                    ))))) {
-    return ccs;
+       || ( ccs->scc_count || ccs->time_ticks || ccs->mem_alloc )
+      ) {
+      return ccs;
   } else {
-    return NULL;
+      return NULL;
   }
 }
 
@@ -820,7 +892,7 @@ reportCCS_XML(CostCentreStack *ccs)
 
   cc = ccs->cc;
   
-  fprintf(prof_file, " 1 %d %lu %lu %lu", 
+  fprintf(prof_file, " 1 %d %llu %lu %llu", 
          ccs->ccsID, ccs->scc_count, ccs->time_ticks, ccs->mem_alloc);
 
   for (i = ccs->indexTable; i != 0; i = i->next) {
@@ -830,19 +902,17 @@ reportCCS_XML(CostCentreStack *ccs)
   }
 }
 
-#ifdef DEBUG
-static void
-printCCS ( CostCentreStack *ccs )
+void
+fprintCCS( FILE *f, CostCentreStack *ccs )
 {
-  fprintf(stderr,"<");
-  for (; ccs; ccs = ccs->prevStack ) {
-    fprintf(stderr,ccs->cc->label);
-    if (ccs->prevStack) {
-      fprintf(stderr,",");
-    }
+  fprintf(f,"<");
+  for (; ccs && ccs != CCS_MAIN; ccs = ccs->prevStack ) {
+      fprintf(f,"%s.%s", ccs->cc->module, ccs->cc->label);
+      if (ccs->prevStack && ccs->prevStack != CCS_MAIN) {
+         fprintf(f,",");
+      }
   }
-  fprintf(stderr,">");
+  fprintf(f,">");
 }
-#endif
 
 #endif /* PROFILING */