From f732e7862bb1fcc65fcfbcfb6eaaf6dde39fdd5f Mon Sep 17 00:00:00 2001 From: Simon Marlow Date: Wed, 16 Apr 2008 21:35:04 +0000 Subject: [PATCH] Add +RTS -vg flag for requesting some GC trace messages, outside DEBUG DEBUG imposes a significant performance hit in the GC, yet we often want some of the debugging output, so -vg gives us the cheap trace messages without the sanity checking of DEBUG, just like -vs for the scheduler. --- includes/RtsFlags.h | 1 + rts/RtsFlags.c | 4 ++++ rts/Stats.c | 2 -- rts/Trace.c | 1 + rts/Trace.h | 11 ++++------- rts/sm/GC.c | 24 ++++++++++++++++++++---- rts/sm/GC.h | 8 ++++++++ rts/sm/GCUtils.c | 2 +- rts/sm/Scav.c | 6 ++++++ 9 files changed, 45 insertions(+), 14 deletions(-) diff --git a/includes/RtsFlags.h b/includes/RtsFlags.h index 902e6c0..7d0b418 100644 --- a/includes/RtsFlags.h +++ b/includes/RtsFlags.h @@ -301,6 +301,7 @@ struct TICKY_FLAGS { struct TRACE_FLAGS { rtsBool sched; /* trace scheduler events for profiling */ + rtsBool gc; /* trace GC events */ rtsBool timestamp; /* add timestamps to traces */ }; diff --git a/rts/RtsFlags.c b/rts/RtsFlags.c index 535d0fd..4f69f49 100644 --- a/rts/RtsFlags.c +++ b/rts/RtsFlags.c @@ -317,6 +317,7 @@ void initRtsFlagsDefaults(void) RtsFlags.TraceFlags.timestamp = rtsFalse; RtsFlags.TraceFlags.sched = rtsFalse; + RtsFlags.TraceFlags.gc = rtsFalse; #ifdef USE_PAPI /* By default no special measurements taken */ @@ -1221,6 +1222,9 @@ error = rtsTrue; case 's': RtsFlags.TraceFlags.sched = rtsTrue; break; + case 'g': + RtsFlags.TraceFlags.gc = rtsTrue; + break; default: errorBelch("unknown RTS option: %s",rts_argv[arg]); error = rtsTrue; diff --git a/rts/Stats.c b/rts/Stats.c index 8c24b29..2fdd0a8 100644 --- a/rts/Stats.c +++ b/rts/Stats.c @@ -668,7 +668,6 @@ stat_exit(int alloc) Produce some detailed info on the state of the generational GC. -------------------------------------------------------------------------- */ -#ifdef DEBUG void statDescribeGens(void) { @@ -709,7 +708,6 @@ statDescribeGens(void) } debugBelch("\n"); } -#endif /* ----------------------------------------------------------------------------- Stats available via a programmatic interface, so eg. GHCi can time diff --git a/rts/Trace.c b/rts/Trace.c index 0b30e92..06de1c4 100644 --- a/rts/Trace.c +++ b/rts/Trace.c @@ -108,6 +108,7 @@ void initTracing (void) GRAN_FLAG(blockedOnFetch_sanity, GRAN_DEBUG_BOF_sanity); TRACE_FLAG(sched, TRACE_sched); + TRACE_FLAG(gc, TRACE_gc); } static void tracePreface (void) diff --git a/rts/Trace.h b/rts/Trace.h index 530ed1b..0e142f5 100644 --- a/rts/Trace.h +++ b/rts/Trace.h @@ -73,14 +73,11 @@ void traceEnd (void); #define DEBUG_par (1<<11) #define DEBUG_linker (1<<12) #define DEBUG_squeeze (1<<13) +#define DEBUG_hpc (1<<14) - - -// Profiling flags -#define TRACE_sched (1<<29) - -// Coverge flags -#define DEBUG_hpc (1<<30) +// Tracing flags +#define TRACE_sched (1<<20) +#define TRACE_gc (1<<21) // ----------------------------------------------------------------------------- // PRIVATE below here diff --git a/rts/sm/GC.c b/rts/sm/GC.c index 80ec6f2..250d07f 100644 --- a/rts/sm/GC.c +++ b/rts/sm/GC.c @@ -305,9 +305,6 @@ GarbageCollect ( rtsBool force_major_gc ) inc_running(); wakeup_gc_threads(n_gc_threads); - // Initialise stats - copied = 0; - // this is the main thread gct = gc_threads[0]; @@ -463,6 +460,21 @@ GarbageCollect ( rtsBool force_major_gc ) /* run through all the generations/steps and tidy up */ + copied = 0; + { + nat i; + for (i=0; i < n_gc_threads; i++) { + if (major_gc) { + trace(TRACE_gc,"thread %d:", i); + trace(TRACE_gc," copied %ld", gc_threads[i]->copied * sizeof(W_)); + trace(TRACE_gc," any_work %ld", gc_threads[i]->any_work); + trace(TRACE_gc," scav_global_work %ld", gc_threads[i]->scav_global_work); + trace(TRACE_gc," scav_local_work %ld", gc_threads[i]->scav_local_work); + } + copied += gc_threads[i]->copied; + } + } + for (g = 0; g < RtsFlags.GcFlags.generations; g++) { if (g <= N) { @@ -644,7 +656,7 @@ GarbageCollect ( rtsBool force_major_gc ) IF_DEBUG(sanity, checkSanity()); // extra GC trace info - IF_DEBUG(gc, statDescribeGens()); + if (traceClass(TRACE_gc)) statDescribeGens(); #ifdef DEBUG // symbol-table based profiling @@ -1348,6 +1360,10 @@ init_gc_thread (gc_thread *t) t->failed_to_evac = rtsFalse; t->eager_promotion = rtsTrue; t->thunk_selector_depth = 0; + t->copied = 0; + t->any_work = 0; + t->scav_global_work = 0; + t->scav_local_work = 0; } /* ----------------------------------------------------------------------------- diff --git a/rts/sm/GC.h b/rts/sm/GC.h index f98e4a1..5183837 100644 --- a/rts/sm/GC.h +++ b/rts/sm/GC.h @@ -148,6 +148,14 @@ typedef struct gc_thread_ { #endif // ------------------- + // stats + + lnat copied; + lnat any_work; + lnat scav_global_work; + lnat scav_local_work; + + // ------------------- // workspaces // array of workspaces, indexed by stp->abs_no. This is placed diff --git a/rts/sm/GCUtils.c b/rts/sm/GCUtils.c index 103430a..636f23d 100644 --- a/rts/sm/GCUtils.c +++ b/rts/sm/GCUtils.c @@ -92,7 +92,7 @@ push_scan_block (bdescr *bd, step_workspace *ws) ASSERT(bd->link == NULL); // update stats: this is a block that has been copied & scavenged - copied += bd->free - bd->start; + gct->copied += bd->free - bd->start; // put the scan block on the ws->scavd_list. bd->link = ws->scavd_list; diff --git a/rts/sm/Scav.c b/rts/sm/Scav.c index b22f244..674078f 100644 --- a/rts/sm/Scav.c +++ b/rts/sm/Scav.c @@ -1405,6 +1405,8 @@ scavenge_find_global_work (void) rtsBool flag; step_workspace *ws; + gct->scav_global_work++; + flag = rtsFalse; for (s = total_steps-1; s>=0; s--) { @@ -1457,6 +1459,8 @@ scavenge_find_local_work (void) step_workspace *ws; rtsBool flag; + gct->scav_local_work++; + flag = rtsFalse; for (s = total_steps-1; s >= 0; s--) { if (s == 0 && RtsFlags.GcFlags.generations > 1) { @@ -1551,6 +1555,8 @@ any_work (void) int s; step_workspace *ws; + gct->any_work++; + write_barrier(); // scavenge static objects -- 1.7.10.4