#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
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 */
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 Ticks *GC_coll_etimes;
static void statsFlush( void );
static void statsClose( void );
return GCe_tot_time;
}
+Ticks stat_getElapsedTime(void)
+{
+ return getProcessElapsedTime() - ElapsedTimeStart;
+}
+
/* mut_user_time_during_GC() and mut_user_time()
*
* The former function can be used to get the current mutator time
(Ticks *)stgMallocBytes(
sizeof(Ticks)*RtsFlags.GcFlags.generations,
"initStats");
+ GC_coll_etimes =
+ (Ticks *)stgMallocBytes(
+ sizeof(Ticks)*RtsFlags.GcFlags.generations,
+ "initStats");
for (i = 0; i < RtsFlags.GcFlags.generations; i++) {
GC_coll_times[i] = 0;
+ GC_coll_etimes[i] = 0;
}
}
} 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
}
/* -----------------------------------------------------------------------------
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
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
+
}
/* -----------------------------------------------------------------------------
-------------------------------------------------------------------------- */
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;
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),
}
GC_coll_times[gen] += gc_time;
+ GC_coll_etimes[gen] += gc_etime;
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;
debugBelch("\b\b\b \b\b\b");
rub_bell = 0;
}
+
+#if USE_PAPI
+ if(papi_is_reporting) {
+ /* Switch to counting mutator events */
+ if (gen == 0) {
+ papi_stop_gc0_count();
+ } else {
+ papi_stop_gc1_count();
+ }
+ papi_start_mutator_count();
+ }
+#endif
}
/* -----------------------------------------------------------------------------
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)
{
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*/);
/* Print garbage collections in each gen */
for (g = 0; g < RtsFlags.GcFlags.generations; g++) {
- statsPrintf("%11d collections in generation %d (%6.2fs)\n",
+ statsPrintf("%11d collections in generation %d, %6.2fs, %6.2fs elapsed\n",
generations[g].collections, g,
- TICK_TO_DBL(GC_coll_times[g]));
+ TICK_TO_DBL(GC_coll_times[g]),
+ TICK_TO_DBL(GC_coll_etimes[g]));
}
statsPrintf("\n%11ld Mb total memory in use\n\n",
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) {
statsFlush();
statsClose();
}
+ if (GC_coll_times)
+ stgFree(GC_coll_times);
+ GC_coll_times = NULL;
}
/* -----------------------------------------------------------------------------
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,
if (s != 0) {
debugBelch("%36s","");
}
- debugBelch("%6d %8d %8d %8d\n", s, step->n_blocks,
+ debugBelch("%6d %8d %8ld %8d\n", s, step->n_blocks,
live, lge);
}
}
Dumping stuff in the stats file, or via the debug message interface
-------------------------------------------------------------------------- */
-static void
+void
statsPrintf( char *s, ... )
{
FILE *sf = RtsFlags.GcFlags.statsFile;
projects / ghc-hetmet.git / blobdiff