From 46b70749971341678c3e4d5cdb2b1ab1a13d039e Mon Sep 17 00:00:00 2001 From: Duncan Coutts Date: Thu, 14 Jul 2011 17:31:16 +0100 Subject: Move GC tracing into a separate trace class Previously GC was included in the scheduler trace class. It can be enabled specifically with +RTS -vg or -lg, though note that both -v and -l on their own now default to a sensible set of trace classes, currently: scheduler, gc and sparks. --- rts/RtsFlags.c | 6 +++- rts/Trace.c | 90 ++++++++++++++++++++++++++++++------------------- rts/Trace.h | 61 ++++++++++++++++----------------- rts/eventlog/EventLog.c | 6 +--- 4 files changed, 93 insertions(+), 70 deletions(-) (limited to 'rts') diff --git a/rts/RtsFlags.c b/rts/RtsFlags.c index abeffc79a6..2a1f4040a7 100644 --- a/rts/RtsFlags.c +++ b/rts/RtsFlags.c @@ -163,6 +163,7 @@ void initRtsFlagsDefaults(void) RtsFlags.TraceFlags.tracing = TRACE_NONE; RtsFlags.TraceFlags.timestamp = rtsFalse; RtsFlags.TraceFlags.scheduler = rtsFalse; + RtsFlags.TraceFlags.gc = rtsFalse; RtsFlags.TraceFlags.sparks = rtsFalse; #endif @@ -289,6 +290,7 @@ usage_text[] = { # endif " where [flags] can contain:", " s scheduler events", +" g GC events", " p par spark events", # ifdef DEBUG " t add time stamps (only useful with -v)", @@ -1452,6 +1454,7 @@ static void read_trace_flags(char *arg) * scheduler or GC tracing. */ RtsFlags.TraceFlags.scheduler = rtsTrue; + RtsFlags.TraceFlags.gc = rtsTrue; RtsFlags.TraceFlags.sparks = rtsTrue; for (c = arg; *c != '\0'; c++) { @@ -1463,6 +1466,7 @@ static void read_trace_flags(char *arg) break; case 'a': RtsFlags.TraceFlags.scheduler = enabled; + RtsFlags.TraceFlags.gc = enabled; RtsFlags.TraceFlags.sparks = enabled; enabled = rtsTrue; break; @@ -1480,7 +1484,7 @@ static void read_trace_flags(char *arg) enabled = rtsTrue; break; case 'g': - // ignored for backwards-compat + RtsFlags.TraceFlags.gc = enabled; enabled = rtsTrue; break; default: diff --git a/rts/Trace.c b/rts/Trace.c index 7d856d6dd7..7f70957fcf 100644 --- a/rts/Trace.c +++ b/rts/Trace.c @@ -47,6 +47,7 @@ int DEBUG_sparks; // events int TRACE_sched; +int TRACE_gc; int TRACE_spark; #ifdef THREADED_RTS @@ -91,6 +92,11 @@ void initTracing (void) RtsFlags.TraceFlags.scheduler || RtsFlags.DebugFlags.scheduler; + // -Dg turns on gc tracing too + TRACE_gc = + RtsFlags.TraceFlags.gc || + RtsFlags.DebugFlags.gc; + // -Dr turns on spark tracing TRACE_spark = RtsFlags.TraceFlags.sparks || @@ -222,27 +228,6 @@ static void traceSchedEvent_stderr (Capability *cap, EventTypeNum tag, case EVENT_SHUTDOWN: // (cap) debugBelch("cap %d: shutting down\n", cap->no); break; - case EVENT_REQUEST_SEQ_GC: // (cap) - debugBelch("cap %d: requesting sequential GC\n", cap->no); - break; - case EVENT_REQUEST_PAR_GC: // (cap) - debugBelch("cap %d: requesting parallel GC\n", cap->no); - break; - case EVENT_GC_START: // (cap) - debugBelch("cap %d: starting GC\n", cap->no); - break; - case EVENT_GC_END: // (cap) - debugBelch("cap %d: finished GC\n", cap->no); - break; - case EVENT_GC_IDLE: // (cap) - debugBelch("cap %d: GC idle\n", cap->no); - break; - case EVENT_GC_WORK: // (cap) - debugBelch("cap %d: GC working\n", cap->no); - break; - case EVENT_GC_DONE: // (cap) - debugBelch("cap %d: GC done\n", cap->no); - break; default: debugBelch("cap %d: thread %lu: event %d\n\n", cap->no, (lnat)tso->id, tag); @@ -266,6 +251,56 @@ void traceSchedEvent_ (Capability *cap, EventTypeNum tag, } } +#ifdef DEBUG +static void traceGcEvent_stderr (Capability *cap, EventTypeNum tag) +{ + ACQUIRE_LOCK(&trace_utx); + + tracePreface(); + switch (tag) { + case EVENT_REQUEST_SEQ_GC: // (cap) + debugBelch("cap %d: requesting sequential GC\n", cap->no); + break; + case EVENT_REQUEST_PAR_GC: // (cap) + debugBelch("cap %d: requesting parallel GC\n", cap->no); + break; + case EVENT_GC_START: // (cap) + debugBelch("cap %d: starting GC\n", cap->no); + break; + case EVENT_GC_END: // (cap) + debugBelch("cap %d: finished GC\n", cap->no); + break; + case EVENT_GC_IDLE: // (cap) + debugBelch("cap %d: GC idle\n", cap->no); + break; + case EVENT_GC_WORK: // (cap) + debugBelch("cap %d: GC working\n", cap->no); + break; + case EVENT_GC_DONE: // (cap) + debugBelch("cap %d: GC done\n", cap->no); + break; + default: + barf("traceGcEvent: unknown event tag %d", tag); + break; + } + + RELEASE_LOCK(&trace_utx); +} +#endif + +void traceGcEvent_ (Capability *cap, EventTypeNum tag) +{ +#ifdef DEBUG + if (RtsFlags.TraceFlags.tracing == TRACE_STDERR) { + traceGcEvent_stderr(cap, tag); + } else +#endif + { + /* currently all GC events are nullary events */ + postEvent(cap, tag); + } +} + void traceCapsetModify_ (EventTypeNum tag, CapsetID capset, StgWord32 other) @@ -360,19 +395,6 @@ void traceSparkCounters_ (Capability *cap, } } - -void traceEvent_ (Capability *cap, EventTypeNum tag) -{ -#ifdef DEBUG - if (RtsFlags.TraceFlags.tracing == TRACE_STDERR) { - traceSchedEvent_stderr(cap, tag, 0, 0, 0); - } else -#endif - { - postEvent(cap,tag); - } -} - #ifdef DEBUG static void traceCap_stderr(Capability *cap, char *msg, va_list ap) { diff --git a/rts/Trace.h b/rts/Trace.h index 34efdf6d87..676fa58515 100644 --- a/rts/Trace.h +++ b/rts/Trace.h @@ -62,6 +62,7 @@ extern int DEBUG_sparks; // events extern int TRACE_sched; +extern int TRACE_gc; extern int TRACE_spark; // ----------------------------------------------------------------------------- @@ -102,16 +103,15 @@ void traceEnd (void); void traceSchedEvent_ (Capability *cap, EventTypeNum tag, StgTSO *tso, StgWord info1, StgWord info2); - -/* - * Record a nullary event +/* + * Record a GC event */ -#define traceEvent(cap, tag) \ - if (RTS_UNLIKELY(TRACE_sched)) { \ - traceEvent_(cap, tag); \ +#define traceGcEvent(cap, tag) \ + if (RTS_UNLIKELY(TRACE_gc)) { \ + traceGcEvent_(cap, tag); \ } -void traceEvent_ (Capability *cap, EventTypeNum tag); +void traceGcEvent_ (Capability *cap, EventTypeNum tag); // variadic macros are C99, and supported by gcc. However, the // ##__VA_ARGS syntax is a gcc extension, which allows the variable @@ -198,8 +198,8 @@ void traceSparkCounters_ (Capability *cap, #define traceSchedEvent(cap, tag, tso, other) /* nothing */ #define traceSchedEvent2(cap, tag, tso, other, info) /* nothing */ +#define traceGcEvent(cap, tag) /* nothing */ #define traceSparkEvent(cap, tag, tso, other) /* nothing */ -#define traceEvent(cap, tag) /* nothing */ #define traceCap(class, cap, msg, ...) /* nothing */ #define trace(class, msg, ...) /* nothing */ #define debugTrace(class, str, ...) /* nothing */ @@ -384,28 +384,47 @@ INLINE_HEADER void traceEventThreadWakeup(Capability *cap STG_UNUSED, INLINE_HEADER void traceEventGcStart(Capability *cap STG_UNUSED) { - traceSchedEvent(cap, EVENT_GC_START, 0, 0); + traceGcEvent(cap, EVENT_GC_START); dtraceGcStart((EventCapNo)cap->no); } INLINE_HEADER void traceEventGcEnd(Capability *cap STG_UNUSED) { - traceSchedEvent(cap, EVENT_GC_END, 0, 0); + traceGcEvent(cap, EVENT_GC_END); dtraceGcEnd((EventCapNo)cap->no); } INLINE_HEADER void traceEventRequestSeqGc(Capability *cap STG_UNUSED) { - traceSchedEvent(cap, EVENT_REQUEST_SEQ_GC, 0, 0); + traceGcEvent(cap, EVENT_REQUEST_SEQ_GC); dtraceRequestSeqGc((EventCapNo)cap->no); } INLINE_HEADER void traceEventRequestParGc(Capability *cap STG_UNUSED) { - traceSchedEvent(cap, EVENT_REQUEST_PAR_GC, 0, 0); + traceGcEvent(cap, EVENT_REQUEST_PAR_GC); dtraceRequestParGc((EventCapNo)cap->no); } +INLINE_HEADER void traceEventGcIdle(Capability *cap STG_UNUSED) +{ + traceGcEvent(cap, EVENT_GC_IDLE); + dtraceGcIdle((EventCapNo)cap->no); +} + +INLINE_HEADER void traceEventGcWork(Capability *cap STG_UNUSED) +{ + traceGcEvent(cap, EVENT_GC_WORK); + dtraceGcWork((EventCapNo)cap->no); +} + +INLINE_HEADER void traceEventGcDone(Capability *cap STG_UNUSED) +{ + traceGcEvent(cap, EVENT_GC_DONE); + dtraceGcDone((EventCapNo)cap->no); +} + + INLINE_HEADER void traceEventRunSpark(Capability *cap STG_UNUSED, StgTSO *tso STG_UNUSED) { @@ -443,24 +462,6 @@ INLINE_HEADER void traceEventStartup(void) dtraceStartup(n_caps); } -INLINE_HEADER void traceEventGcIdle(Capability *cap STG_UNUSED) -{ - traceEvent(cap, EVENT_GC_IDLE); - dtraceGcIdle((EventCapNo)cap->no); -} - -INLINE_HEADER void traceEventGcWork(Capability *cap STG_UNUSED) -{ - traceEvent(cap, EVENT_GC_WORK); - dtraceGcWork((EventCapNo)cap->no); -} - -INLINE_HEADER void traceEventGcDone(Capability *cap STG_UNUSED) -{ - traceEvent(cap, EVENT_GC_DONE); - dtraceGcDone((EventCapNo)cap->no); -} - INLINE_HEADER void traceCapsetCreate(CapsetID capset STG_UNUSED, CapsetType capset_type STG_UNUSED) { diff --git a/rts/eventlog/EventLog.c b/rts/eventlog/EventLog.c index 1e63a94c88..54e4cb4096 100644 --- a/rts/eventlog/EventLog.c +++ b/rts/eventlog/EventLog.c @@ -470,16 +470,12 @@ postSchedEvent (Capability *cap, } case EVENT_SHUTDOWN: // (cap) - case EVENT_REQUEST_SEQ_GC: // (cap) - case EVENT_REQUEST_PAR_GC: // (cap) - case EVENT_GC_START: // (cap) - case EVENT_GC_END: // (cap) { break; } default: - barf("postEvent: unknown event tag %d", tag); + barf("postSchedEvent: unknown event tag %d", tag); } } -- cgit v1.2.1