@@ -117,8 +117,11 @@ #define EVENT_STARTUP 17 /* (num_capabilities) */ #define EVENT_BLOCK_MARKER 18 /* (size, end_time, capability) */ #define EVENT_USER_MSG 19 /* (message ...) */ +#define EVENT_GC_IDLE 20 /* () */ +#define EVENT_GC_WORK 21 /* () */ +#define EVENT_GC_DONE 22 /* () */ -#define NUM_EVENT_TAGS 20 +#define NUM_EVENT_TAGS 23 #if 0 /* DEPRECATED EVENTS: */ #define EVENT_CREATE_SPARK 13 /* (cap, thread) */ includes/rts/EventLogFormat.h @@ -193,6 +193,15 @@ static void traceSchedEvent_stderr (Capability *cap, EventTypeNum tag, 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 %2d: thread %lu: event %d\n\n", cap->no, (lnat)tso->id, tag); @@ -216,6 +225,18 @@ void traceSchedEvent_ (Capability *cap, EventTypeNum tag, } } +void traceEvent_ (Capability *cap, EventTypeNum tag) +{ +#ifdef DEBUG + if (RtsFlags.TraceFlags.tracing == TRACE_STDERR) { + traceSchedEvent_stderr(cap, tag, 0, 0); + } else +#endif + { + postEvent(cap,tag); + } +} + #ifdef DEBUG static void traceCap_stderr(Capability *cap, char *msg, va_list ap) { rts/Trace.c @@ -79,6 +79,17 @@ void traceEnd (void); void traceSchedEvent_ (Capability *cap, EventTypeNum tag, StgTSO *tso, StgWord64 other); + +/* + * Record a nullary event + */ +#define traceEvent(cap, tag) \ + if (RTS_UNLIKELY(TRACE_sched)) { \ + traceEvent_(cap, tag); \ + } + +void traceEvent_ (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 // argument list to be empty (see gcc docs for details). @@ -133,6 +144,7 @@ void traceThreadStatus_ (StgTSO *tso); #else /* !TRACING */ #define traceSchedEvent(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 */ rts/Trace.h @@ -64,6 +64,9 @@ char *EventDesc[] = { [EVENT_LOG_MSG] = "Log message", [EVENT_USER_MSG] = "User message", [EVENT_STARTUP] = "Startup", + [EVENT_GC_IDLE] = "GC idle", + [EVENT_GC_WORK] = "GC working", + [EVENT_GC_DONE] = "GC done", [EVENT_BLOCK_MARKER] = "Block marker" }; @@ -239,6 +242,9 @@ initEventLogging(void) case EVENT_GC_START: // (cap) case EVENT_GC_END: // (cap) case EVENT_STARTUP: + case EVENT_GC_IDLE: + case EVENT_GC_WORK: + case EVENT_GC_DONE: eventTypes[t].size = 0; break; @@ -393,6 +399,21 @@ postSchedEvent (Capability *cap, } } +void +postEvent (Capability *cap, EventTypeNum tag) +{ + EventsBuf *eb; + + eb = &capEventBuf[cap->no]; + + if (!hasRoomForEvent(eb, tag)) { + // Flush event buffer to make room for new event. + printAndClearEventBuf(eb); + } + + postEventHeader(eb, tag); +} + #define BUF 512 void postLogMsg(EventsBuf *eb, EventTypeNum type, char *msg, va_list ap) rts/eventlog/EventLog.c @@ -26,11 +26,17 @@ void endEventLogging(void); void freeEventLogging(void); /* - * Post an event to the capability's event buffer. + * Post a scheduler event to the capability's event buffer (an event + * that has an associated thread). */ void postSchedEvent(Capability *cap, EventTypeNum tag, StgThreadID id, StgWord64 other); +/* + * Post a nullary event. + */ +void postEvent(Capability *cap, EventTypeNum tag); + void postMsg(char *msg, va_list ap); void postUserMsg(Capability *cap, char *msg); @@ -45,6 +51,10 @@ INLINE_HEADER void postSchedEvent (Capability *cap STG_UNUSED, StgWord64 other STG_UNUSED) { /* nothing */ } +INLINE_HEADER void postEvent (Capability *cap STG_UNUSED, + EventTypeNum tag STG_UNUSED) +{ /* nothing */ } + INLINE_HEADER void postMsg (char *msg STG_UNUSED, va_list ap STG_UNUSED) { /* nothing */ } rts/eventlog/EventLog.h @@ -1020,9 +1020,10 @@ scavenge_until_all_done (void) { nat r; - debugTrace(DEBUG_gc, "GC thread %d working", gct->thread_index); loop: + traceEvent(&capabilities[gct->thread_index], EVENT_GC_WORK); + #if defined(THREADED_RTS) if (n_gc_threads > 1) { scavenge_loop(); @@ -1036,8 +1037,9 @@ loop: // scavenge_loop() only exits when there's no work to do r = dec_running(); - debugTrace(DEBUG_gc, "GC thread %d idle (%d still running)", - gct->thread_index, r); + traceEvent(&capabilities[gct->thread_index], EVENT_GC_IDLE); + + debugTrace(DEBUG_gc, "%d GC threads still running", r); while (gc_running_threads != 0) { // usleep(1); @@ -1051,8 +1053,7 @@ loop: // scavenge_loop() to perform any pending work. } - // All threads are now stopped - debugTrace(DEBUG_gc, "GC thread %d finished.", gct->thread_index); + traceEvent(&capabilities[gct->thread_index], EVENT_GC_DONE); } #if defined(THREADED_RTS) rts/sm/GC.c c4d48f161628fedc5888112cccb64e3baa95bee6 Simon Marlow marlowsd@gmail.com http://github.com/ghc-hq/ghc/commit/67d7171ab02f30ef3a5c77e6d9d601f0cb0ad839 67d7171ab02f30ef3a5c77e6d9d601f0cb0ad839 2009-10-15T03:02:12-07:00 2009-10-15T03:02:12-07:00 Add events to show when GC threads are idle/working 0798f163e329b1adb955007b99dde7620c8502eb Simon Marlow marlowsd@gmail.com