X-Git-Url: http://git.megacz.com/?a=blobdiff_plain;f=ghc%2Frts%2FProfiling.c;h=902c3919938316cfdaa1b5962e97ac800b77b075;hb=2c7eeab5a799bbe6f1de84079c28ff6367bfb294;hp=38d620d67abba0bce5e36c213bed73cdcf72bdd4;hpb=1023a232739fdf50420ac3d43dff1b4f6ca90f66;p=ghc-hetmet.git diff --git a/ghc/rts/Profiling.c b/ghc/rts/Profiling.c index 38d620d..902c391 100644 --- a/ghc/rts/Profiling.c +++ b/ghc/rts/Profiling.c @@ -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" @@ -17,6 +18,14 @@ #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 = .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., .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 */