in rts/Stats.c [667:867]
static void report_summary(const RTSSummaryStats* sum)
{
// We should do no calculation, other than unit changes and formatting, and
// we should not not use any data from outside of globals, sum and stats
// here. See Note [RTS Stats Reporting]
uint32_t g;
char temp[512];
showStgWord64(stats.allocated_bytes, temp, true/*commas*/);
statsPrintf("%16s bytes allocated in the heap\n", temp);
showStgWord64(stats.copied_bytes, temp, true/*commas*/);
statsPrintf("%16s bytes copied during GC\n", temp);
if ( stats.major_gcs > 0 ) {
showStgWord64(stats.max_live_bytes, temp, true/*commas*/);
statsPrintf("%16s bytes maximum residency (%" FMT_Word32
" sample(s))\n",
temp, stats.major_gcs);
}
showStgWord64(stats.max_slop_bytes, temp, true/*commas*/);
statsPrintf("%16s bytes maximum slop\n", temp);
statsPrintf("%16" FMT_Word64 " MB total memory in use (%"
FMT_Word64 " MB lost due to fragmentation)\n\n",
stats.max_live_bytes / (1024 * 1024),
sum->fragmentation_bytes / (1024 * 1024));
/* Print garbage collections in each gen */
statsPrintf(" Tot time (elapsed) Avg pause Max pause\n");
for (g = 0; g < RtsFlags.GcFlags.generations; g++) {
const GenerationSummaryStats * gen_stats =
&sum->gc_summary_stats[g];
statsPrintf(" Gen %2d %5d colls"
", %5d par %6.3fs %6.3fs %3.4fs %3.4fs\n",
g, // REVIEWERS: this used to be gen->no
//, this can't ever be different right?
gen_stats->collections,
gen_stats->par_collections,
TimeToSecondsDbl(gen_stats->cpu_ns),
TimeToSecondsDbl(gen_stats->elapsed_ns),
TimeToSecondsDbl(gen_stats->avg_pause_ns),
TimeToSecondsDbl(gen_stats->max_pause_ns));
}
statsPrintf("\n");
#if defined(THREADED_RTS)
if (RtsFlags.ParFlags.parGcEnabled && sum->work_balance > 0) {
// See Note [Work Balance]
statsPrintf(" Parallel GC work balance: "
"%.2f%% (serial 0%%, perfect 100%%)\n\n",
sum->work_balance * 100);
}
statsPrintf(" TASKS: %d "
"(%d bound, %d peak workers (%d total), using -N%d)\n\n",
taskCount, sum->bound_task_count,
peakWorkerCount, workerCount,
n_capabilities);
statsPrintf(" SPARKS: %" FMT_Word64
" (%" FMT_Word " converted, %" FMT_Word " overflowed, %"
FMT_Word " dud, %" FMT_Word " GC'd, %" FMT_Word " fizzled)\n\n",
sum->sparks_count,
sum->sparks.converted, sum->sparks.overflowed,
sum->sparks.dud, sum->sparks.gcd,
sum->sparks.fizzled);
#endif
statsPrintf(" INIT time %7.3fs (%7.3fs elapsed)\n",
TimeToSecondsDbl(stats.init_cpu_ns),
TimeToSecondsDbl(stats.init_elapsed_ns));
statsPrintf(" MUT time %7.3fs (%7.3fs elapsed)\n",
TimeToSecondsDbl(stats.mutator_cpu_ns),
TimeToSecondsDbl(stats.mutator_elapsed_ns));
statsPrintf(" GC time %7.3fs (%7.3fs elapsed)\n",
TimeToSecondsDbl(stats.gc_cpu_ns),
TimeToSecondsDbl(stats.gc_elapsed_ns));
#if defined(PROFILING)
statsPrintf(" RP time %7.3fs (%7.3fs elapsed)\n",
TimeToSecondsDbl(sum->rp_cpu_ns),
TimeToSecondsDbl(sum->rp_elapsed_ns));
statsPrintf(" PROF time %7.3fs (%7.3fs elapsed)\n",
TimeToSecondsDbl(sum->hc_cpu_ns),
TimeToSecondsDbl(sum->hc_elapsed_ns));
#endif
statsPrintf(" EXIT time %7.3fs (%7.3fs elapsed)\n",
TimeToSecondsDbl(sum->exit_cpu_ns),
TimeToSecondsDbl(sum->exit_elapsed_ns));
statsPrintf(" Total time %7.3fs (%7.3fs elapsed)\n\n",
TimeToSecondsDbl(stats.cpu_ns),
TimeToSecondsDbl(stats.elapsed_ns));
#if !defined(THREADED_RTS)
statsPrintf(" %%GC time %5.1f%% (%.1f%% elapsed)\n\n",
sum->gc_cpu_percent * 100,
sum->gc_elapsed_percent * 100);
#endif
showStgWord64(sum->alloc_rate, temp, true/*commas*/);
statsPrintf(" Alloc rate %s bytes per MUT second\n\n", temp);
statsPrintf(" Productivity %5.1f%% of total user, "
"%.1f%% of total elapsed\n\n",
sum->productivity_cpu_percent * 100,
sum->productivity_elapsed_percent * 100);
// See Note [Internal Counter Stats] for a description of the
// following counters. If you add a counter here, please remember
// to update the Note.
if (RtsFlags.MiscFlags.internalCounters) {
#if defined(THREADED_RTS) && defined(PROF_SPIN)
const int32_t col_width[] = {4, -30, 14, 14};
statsPrintf("Internal Counters:\n");
statsPrintf("%*s" "%*s" "%*s" "%*s" "\n"
, col_width[0], ""
, col_width[1], "SpinLock"
, col_width[2], "Spins"
, col_width[3], "Yields");
statsPrintf("%*s" "%*s" "%*" FMT_Word64 "%*" FMT_Word64 "\n"
, col_width[0], ""
, col_width[1], "gc_alloc_block_sync"
, col_width[2], gc_alloc_block_sync.spin
, col_width[3], gc_alloc_block_sync.yield);
statsPrintf("%*s" "%*s" "%*" FMT_Word64 "%*" FMT_Word64 "\n"
, col_width[0], ""
, col_width[1], "gc_spin"
, col_width[2], stats.gc_spin_spin
, col_width[3], stats.gc_spin_yield);
statsPrintf("%*s" "%*s" "%*" FMT_Word64 "%*" FMT_Word64 "\n"
, col_width[0], ""
, col_width[1], "mut_spin"
, col_width[2], stats.mut_spin_spin
, col_width[3], stats.mut_spin_yield);
statsPrintf("%*s" "%*s" "%*" FMT_Word64 "%*s\n"
, col_width[0], ""
, col_width[1], "whitehole_gc"
, col_width[2], whitehole_gc_spin
, col_width[3], "n/a");
statsPrintf("%*s" "%*s" "%*" FMT_Word64 "%*s\n"
, col_width[0], ""
, col_width[1], "whitehole_threadPaused"
, col_width[2], whitehole_threadPaused_spin
, col_width[3], "n/a");
statsPrintf("%*s" "%*s" "%*" FMT_Word64 "%*s\n"
, col_width[0], ""
, col_width[1], "whitehole_executeMessage"
, col_width[2], whitehole_executeMessage_spin
, col_width[3], "n/a");
statsPrintf("%*s" "%*s" "%*" FMT_Word64 "%*" FMT_Word64 "\n"
, col_width[0], ""
, col_width[1], "whitehole_lockClosure"
, col_width[2], whitehole_lockClosure_spin
, col_width[3], whitehole_lockClosure_yield);
// waitForGcThreads isn't really spin-locking(see the function)
// but these numbers still seem useful.
statsPrintf("%*s" "%*s" "%*" FMT_Word64 "%*" FMT_Word64 "\n"
, col_width[0], ""
, col_width[1], "waitForGcThreads"
, col_width[2], waitForGcThreads_spin
, col_width[3], waitForGcThreads_yield);
for (g = 0; g < RtsFlags.GcFlags.generations; g++) {
int prefix_length = 0;
statsPrintf("%*s" "gen[%" FMT_Word32 "%n",
col_width[0], "", g, &prefix_length);
prefix_length -= col_width[0];
int suffix_length = col_width[1] + prefix_length;
suffix_length =
suffix_length > 0 ? col_width[1] : suffix_length;
statsPrintf("%*s" "%*" FMT_Word64 "%*" FMT_Word64 "\n"
, suffix_length, "].sync"
, col_width[2], generations[g].sync.spin
, col_width[3], generations[g].sync.yield);
}
statsPrintf("\n");
statsPrintf("%*s" "%*s" "%*" FMT_Word64 "\n"
, col_width[0], ""
, col_width[1], "any_work"
, col_width[2], stats.any_work);
statsPrintf("%*s" "%*s" "%*" FMT_Word64 "\n"
, col_width[0], ""
, col_width[1], "no_work"
, col_width[2], stats.no_work);
statsPrintf("%*s" "%*s" "%*" FMT_Word64 "\n"
, col_width[0], ""
, col_width[1], "scav_find_work"
, col_width[2], stats.scav_find_work);
#elif defined(THREADED_RTS) // THREADED_RTS && PROF_SPIN
statsPrintf("Internal Counters require the RTS to be built "
"with PROF_SPIN"); // PROF_SPIN is not #defined here
#else // THREADED_RTS
statsPrintf("Internal Counters require the threaded RTS");
#endif
}
}