X-Git-Url: http://git.megacz.com/?a=blobdiff_plain;f=rts%2FStats.c;h=1127b81566632a8a9f39993be949f71f6b3770f8;hb=a84385fa752d8fa800a2155cce95f47c68b74e2b;hp=ec8d5838fbc7a0132e12e95bf1fef3afcd62fff7;hpb=5a2769f0273dd389977e8283375e7920d183bdd4;p=ghc-hetmet.git diff --git a/rts/Stats.c b/rts/Stats.c index ec8d583..1127b81 100644 --- a/rts/Stats.c +++ b/rts/Stats.c @@ -10,13 +10,17 @@ #include "RtsFlags.h" #include "RtsUtils.h" #include "MBlock.h" +#include "Storage.h" #include "Schedule.h" #include "Stats.h" #include "ParTicky.h" /* ToDo: move into Rts.h */ #include "Profiling.h" -#include "Storage.h" #include "GetTime.h" +#if USE_PAPI +#include "Papi.h" +#endif + /* huh? */ #define BIG_STRING_LEN 512 @@ -37,7 +41,6 @@ static Ticks ExitElapsedTime = 0; static ullong GC_tot_alloc = 0; static ullong GC_tot_copied = 0; -static ullong GC_tot_scavd_copied = 0; static Ticks GC_start_time = 0, GC_tot_time = 0; /* User GC Time */ static Ticks GCe_start_time = 0, GCe_tot_time = 0; /* Elapsed GC time */ @@ -64,9 +67,6 @@ static lnat GC_start_faults = 0, GC_end_faults = 0; static Ticks *GC_coll_times; -static void statsPrintf( char *s, ... ) - GNUC3_ATTRIBUTE(format (printf, 1, 2)); - static void statsFlush( void ); static void statsClose( void ); @@ -170,6 +170,16 @@ stat_endInit(void) } else { InitElapsedTime = elapsed - ElapsedTimeStart; } +#if USE_PAPI + /* We start counting events for the mutator + * when garbage collection starts + * we switch to the GC event set. */ + papi_start_mutator_count(); + + /* This flag is needed to avoid counting the last GC */ + papi_is_reporting = 1; + +#endif } /* ----------------------------------------------------------------------------- @@ -192,6 +202,16 @@ stat_startExit(void) MutUserTime = user - GC_tot_time - PROF_VAL(RP_tot_time + HC_tot_time) - InitUserTime; if (MutUserTime < 0) { MutUserTime = 0; } + +#if USE_PAPI + /* We stop counting mutator events + * GC events are not being counted at this point */ + papi_stop_mutator_count(); + + /* This flag is needed, because GC is run once more after this function */ + papi_is_reporting = 0; + +#endif } void @@ -249,6 +269,15 @@ stat_startGC(void) GC_start_faults = getPageFaults(); } } + +#if USE_PAPI + if(papi_is_reporting) { + /* Switch to counting GC events */ + papi_stop_mutator_count(); + papi_start_gc_count(); + } +#endif + } /* ----------------------------------------------------------------------------- @@ -256,8 +285,7 @@ stat_startGC(void) -------------------------------------------------------------------------- */ void -stat_endGC (lnat alloc, lnat live, lnat copied, - lnat scavd_copied, lnat gen) +stat_endGC (lnat alloc, lnat live, lnat copied, lnat gen) { if (RtsFlags.GcFlags.giveStats != NO_GC_STATS) { Ticks time, etime, gc_time, gc_etime; @@ -270,7 +298,7 @@ stat_endGC (lnat alloc, lnat live, lnat copied, nat faults = getPageFaults(); statsPrintf("%9ld %9ld %9ld", - alloc*sizeof(W_), (copied+scavd_copied)*sizeof(W_), + alloc*sizeof(W_), copied*sizeof(W_), live*sizeof(W_)); statsPrintf(" %5.2f %5.2f %7.2f %7.2f %4ld %4ld (Gen: %2ld)\n", TICK_TO_DBL(gc_time), @@ -288,7 +316,6 @@ stat_endGC (lnat alloc, lnat live, lnat copied, 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; @@ -316,6 +343,14 @@ stat_endGC (lnat alloc, lnat live, lnat copied, debugBelch("\b\b\b \b\b\b"); rub_bell = 0; } + +#if USE_PAPI + if(papi_is_reporting) { + /* Switch to counting mutator events */ + papi_stop_gc_count(); + papi_start_mutator_count(); + } +#endif } /* ----------------------------------------------------------------------------- @@ -401,6 +436,52 @@ stat_endHeapCensus(void) were left unused when the heap-check failed. -------------------------------------------------------------------------- */ +#ifdef DEBUG +#define TICK_VAR(arity) \ + extern StgInt SLOW_CALLS_##arity; \ + extern StgInt RIGHT_ARITY_##arity; \ + extern StgInt TAGGED_PTR_##arity; + +#define TICK_VAR_INI(arity) \ + StgInt SLOW_CALLS_##arity = 1; \ + StgInt RIGHT_ARITY_##arity = 1; \ + StgInt TAGGED_PTR_##arity = 0; + +extern StgInt TOTAL_CALLS; + +TICK_VAR(1) +TICK_VAR(2) + +TICK_VAR_INI(1) +TICK_VAR_INI(2) + +StgInt TOTAL_CALLS=1; +#endif + +/* Report the value of a counter */ +#define REPORT(counter) \ + { \ + ullong_format_string(counter,temp,rtsTrue/*commas*/); \ + statsPrintf(" (" #counter ") : %s\n",temp); \ + } + +/* Report the value of a counter as a percentage of another counter */ +#define REPORT_PCT(counter,countertot) \ + statsPrintf(" (" #counter ") %% of (" #countertot ") : %.1f%%\n", \ + counter*100.0/countertot) + +#define TICK_PRINT(arity) \ + REPORT(SLOW_CALLS_##arity); \ + REPORT_PCT(RIGHT_ARITY_##arity,SLOW_CALLS_##arity); \ + REPORT_PCT(TAGGED_PTR_##arity,RIGHT_ARITY_##arity); \ + REPORT(RIGHT_ARITY_##arity); \ + REPORT(TAGGED_PTR_##arity) + +#define TICK_PRINT_TOT(arity) \ + statsPrintf(" (SLOW_CALLS_" #arity ") %% of (TOTAL_CALLS) : %.1f%%\n", \ + SLOW_CALLS_##arity * 100.0/TOTAL_CALLS) + + void stat_exit(int alloc) { @@ -436,12 +517,8 @@ stat_exit(int alloc) ullong_format_string(GC_tot_copied*sizeof(W_), temp, rtsTrue/*commas*/); - statsPrintf("%11s bytes copied during GC (scavenged)\n", temp); + statsPrintf("%11s bytes copied during GC\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*/); @@ -517,6 +594,18 @@ stat_exit(int alloc) TICK_TO_DBL(time - GC_tot_time - PROF_VAL(RP_tot_time + HC_tot_time) - InitUserTime) * 100 / TICK_TO_DBL(etime)); + + /* + TICK_PRINT(1); + TICK_PRINT(2); + REPORT(TOTAL_CALLS); + TICK_PRINT_TOT(1); + TICK_PRINT_TOT(2); + */ + +#if USE_PAPI + papi_stats_report(); +#endif } if (RtsFlags.GcFlags.giveStats == ONELINE_GC_STATS) { @@ -537,6 +626,9 @@ stat_exit(int alloc) statsFlush(); statsClose(); } + if (GC_coll_times) + stgFree(GC_coll_times); + GC_coll_times = NULL; } /* ----------------------------------------------------------------------------- @@ -554,13 +646,13 @@ statDescribeGens(void) step *step; debugBelch( -" Gen Steps Max Mutable Step Blocks Live Large\n" -" Blocks Closures Objects\n"); +" Gen Steps Max Mut-list Step Blocks Live Large\n" +" Blocks Bytes Objects\n"); mut = 0; for (g = 0; g < RtsFlags.GcFlags.generations; g++) { for (bd = generations[g].mut_list; bd != NULL; bd = bd->link) { - mut += bd->free - bd->start; + mut += (bd->free - bd->start) * sizeof(W_); } debugBelch("%8d %8d %8d %9d", g, generations[g].n_steps, @@ -603,7 +695,7 @@ extern HsInt64 getAllocations( void ) Dumping stuff in the stats file, or via the debug message interface -------------------------------------------------------------------------- */ -static void +void statsPrintf( char *s, ... ) { FILE *sf = RtsFlags.GcFlags.statsFile;