void
stat_endInit(void)
{
getProcessTimes(&end_init_cpu, &end_init_elapsed);
#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
}
void
stat_endGC (Capability *cap, gc_thread *gct,
W_ live, W_ copied, W_ slop, nat gen,
nat par_n_threads, W_ par_max_copied, W_ par_tot_copied)
{
W_ tot_alloc;
W_ alloc;
if (RtsFlags.GcFlags.giveStats != NO_GC_STATS ||
RtsFlags.ProfFlags.doHeapProfile)
// heap profiling needs GC_tot_time
{
Time cpu, elapsed, gc_cpu, gc_elapsed;
// Has to be emitted while all caps stopped for GC, but before GC_END.
// See trac.haskell.org/ThreadScope/wiki/RTSsummaryEvents
// for a detailed design rationale of the current setup
// of GC eventlog events.
traceEventGcGlobalSync(cap);
// Emitted before GC_END on all caps, which simplifies tools code.
traceEventGcStats(cap,
CAPSET_HEAP_DEFAULT,
gen,
copied * sizeof(W_),
slop * sizeof(W_),
/* current loss due to fragmentation */
(mblocks_allocated * BLOCKS_PER_MBLOCK - n_alloc_blocks)
* BLOCK_SIZE_W * sizeof(W_),
par_n_threads,
par_max_copied * sizeof(W_),
par_tot_copied * sizeof(W_));
getProcessTimes(&cpu, &elapsed);
// Post EVENT_GC_END with the same timestamp as used for stats
// (though converted from Time=StgInt64 to EventTimestamp=StgWord64).
// Here, as opposed to other places, the event is emitted on the cap
// that initiates the GC and external tools expect it to have the same
// timestamp as used in +RTS -s calculcations.
traceEventGcEndAtT(cap, TimeToNS(elapsed - start_init_elapsed));
gc_elapsed = elapsed - gct->gc_start_elapsed;
gc_cpu = cpu - gct->gc_start_cpu;
/* For the moment we calculate both per-HEC and total allocation.
* There is thus redundancy here, but for the moment we will calculate
* it both the old and new way and assert they're the same.
* When we're sure it's working OK then we can simplify things.
*/
tot_alloc = calcTotalAllocated();
// allocated since the last GC
alloc = tot_alloc - GC_tot_alloc;
GC_tot_alloc = tot_alloc;
if (RtsFlags.GcFlags.giveStats == VERBOSE_GC_STATS) {
W_ faults = getPageFaults();
statsPrintf("%9" FMT_SizeT " %9" FMT_SizeT " %9" FMT_SizeT,
alloc*sizeof(W_), copied*sizeof(W_),
live*sizeof(W_));
statsPrintf(" %6.3f %6.3f %8.3f %8.3f %4" FMT_Word " %4" FMT_Word " (Gen: %2d)\n",
TimeToSecondsDbl(gc_cpu),
TimeToSecondsDbl(gc_elapsed),
TimeToSecondsDbl(cpu),
TimeToSecondsDbl(elapsed - start_init_elapsed),
faults - gct->gc_start_faults,
gct->gc_start_faults - GC_end_faults,
gen);
GC_end_faults = faults;
statsFlush();
}
GC_coll_cpu[gen] += gc_cpu;
GC_coll_elapsed[gen] += gc_elapsed;
if (GC_coll_max_pause[gen] < gc_elapsed) {
GC_coll_max_pause[gen] = gc_elapsed;
}
GC_tot_copied += (StgWord64) copied;
GC_par_max_copied += (StgWord64) par_max_copied;
GC_par_tot_copied += (StgWord64) par_tot_copied;
GC_tot_cpu += gc_cpu;
traceEventHeapSize(cap,
CAPSET_HEAP_DEFAULT,
mblocks_allocated * MBLOCK_SIZE_W * sizeof(W_));
if (gen == RtsFlags.GcFlags.generations-1) { /* major GC? */
if (live > max_residency) {
max_residency = live;
}
current_residency = live;
residency_samples++;
cumulative_residency += live;
traceEventHeapLive(cap,
CAPSET_HEAP_DEFAULT,
live * sizeof(W_));
}
if (slop > max_slop) max_slop = slop;
}
if (rub_bell) {
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
}
void
stat_endGC (gc_thread *gct,
lnat alloc, lnat live, lnat copied, nat gen,
lnat max_copied, lnat avg_copied, lnat slop)
{
if (RtsFlags.GcFlags.giveStats != NO_GC_STATS ||
RtsFlags.ProfFlags.doHeapProfile)
// heap profiling needs GC_tot_time
{
Ticks cpu, elapsed, thread_gc_cpu, gc_cpu, gc_elapsed;
getProcessTimes(&cpu, &elapsed);
gc_elapsed = elapsed - gct->gc_start_elapsed;
thread_gc_cpu = getThreadCPUTime() - gct->gc_start_thread_cpu;
gc_cpu = cpu - gct->gc_start_cpu;
taskDoneGC(gct->cap->running_task, thread_gc_cpu, gc_elapsed);
if (RtsFlags.GcFlags.giveStats == VERBOSE_GC_STATS) {
nat faults = getPageFaults();
statsPrintf("%9ld %9ld %9ld",
alloc*sizeof(W_), copied*sizeof(W_),
live*sizeof(W_));
statsPrintf(" %5.2f %5.2f %7.2f %7.2f %4ld %4ld (Gen: %2d)\n",
TICK_TO_DBL(gc_cpu),
TICK_TO_DBL(gc_elapsed),
TICK_TO_DBL(cpu),
TICK_TO_DBL(elapsed - start_init_elapsed),
faults - gct->gc_start_faults,
gct->gc_start_faults - GC_end_faults,
gen);
GC_end_faults = faults;
statsFlush();
}
GC_coll_cpu[gen] += gc_cpu;
GC_coll_elapsed[gen] += gc_elapsed;
if (GC_coll_max_pause[gen] < gc_elapsed) {
GC_coll_max_pause[gen] = gc_elapsed;
}
GC_tot_copied += (StgWord64) copied;
GC_tot_alloc += (StgWord64) alloc;
GC_par_max_copied += (StgWord64) max_copied;
GC_par_avg_copied += (StgWord64) avg_copied;
GC_tot_cpu += gc_cpu;
if (gen == RtsFlags.GcFlags.generations-1) { /* major GC? */
if (live > max_residency) {
max_residency = live;
}
current_residency = live;
residency_samples++;
cumulative_residency += live;
}
if (slop > max_slop) max_slop = slop;
}
if (rub_bell) {
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
}