From 912e440e6f0277730b2ad611097f96588cc435a3 Mon Sep 17 00:00:00 2001 From: Ben Gamari Date: Tue, 5 Feb 2019 11:51:52 -0500 Subject: rts: Tracing support for nonmoving collection events This introduces a few events to mark key points in the nonmoving garbage collection cycle. These include: * `EVENT_CONC_MARK_BEGIN`, denoting the beginning of a round of marking. This may happen more than once in a single major collection since we the major collector iterates until it hits a fixed point. * `EVENT_CONC_MARK_END`, denoting the end of a round of marking. * `EVENT_CONC_SYNC_BEGIN`, denoting the beginning of the post-mark synchronization phase * `EVENT_CONC_UPD_REM_SET_FLUSH`, indicating that a capability has flushed its update remembered set. * `EVENT_CONC_SYNC_END`, denoting that all mutators have flushed their update remembered sets. * `EVENT_CONC_SWEEP_BEGIN`, denoting the beginning of the sweep portion of the major collection. * `EVENT_CONC_SWEEP_END`, denoting the end of the sweep portion of the major collection. --- rts/Trace.c | 43 ++++++++++++++++++++++++++++++++++++++++ rts/Trace.h | 16 +++++++++++++++ rts/eventlog/EventLog.c | 52 ++++++++++++++++++++++++++++++++++++++++++++++++- rts/eventlog/EventLog.h | 7 +++++++ rts/sm/NonMoving.c | 3 +++ rts/sm/NonMovingMark.c | 5 +++++ 6 files changed, 125 insertions(+), 1 deletion(-) (limited to 'rts') diff --git a/rts/Trace.c b/rts/Trace.c index de647f762b..10ad5031ab 100644 --- a/rts/Trace.c +++ b/rts/Trace.c @@ -802,6 +802,49 @@ void traceThreadLabel_(Capability *cap, } } +void traceConcMarkBegin() +{ + if (eventlog_enabled) + postEventNoCap(EVENT_CONC_MARK_BEGIN); +} + +void traceConcMarkEnd(StgWord32 marked_obj_count) +{ + if (eventlog_enabled) + postConcMarkEnd(marked_obj_count); +} + +void traceConcSyncBegin() +{ + if (eventlog_enabled) + postEventNoCap(EVENT_CONC_SYNC_BEGIN); +} + +void traceConcSyncEnd() +{ + if (eventlog_enabled) + postEventNoCap(EVENT_CONC_SYNC_END); +} + +void traceConcSweepBegin() +{ + if (eventlog_enabled) + postEventNoCap(EVENT_CONC_SWEEP_BEGIN); +} + +void traceConcSweepEnd() +{ + if (eventlog_enabled) + postEventNoCap(EVENT_CONC_SWEEP_END); +} + +void traceConcUpdRemSetFlush(Capability *cap) +{ + if (eventlog_enabled) + postConcUpdRemSetFlush(cap); +} + + void traceThreadStatus_ (StgTSO *tso USED_IF_DEBUG) { #if defined(DEBUG) diff --git a/rts/Trace.h b/rts/Trace.h index be4d844a6b..9b52c3cb65 100644 --- a/rts/Trace.h +++ b/rts/Trace.h @@ -304,6 +304,14 @@ void traceHeapProfSampleCostCentre(StgWord8 profile_id, CostCentreStack *stack, StgWord residency); #endif /* PROFILING */ +void traceConcMarkBegin(void); +void traceConcMarkEnd(StgWord32 marked_obj_count); +void traceConcSyncBegin(void); +void traceConcSyncEnd(void); +void traceConcSweepBegin(void); +void traceConcSweepEnd(void); +void traceConcUpdRemSetFlush(Capability *cap); + void flushTrace(void); #else /* !TRACING */ @@ -344,6 +352,14 @@ void flushTrace(void); #define traceHeapProfSampleCostCentre(profile_id, stack, residency) /* nothing */ #define traceHeapProfSampleString(profile_id, label, residency) /* nothing */ +#define traceConcMarkBegin() /* nothing */ +#define traceConcMarkEnd(marked_obj_count) /* nothing */ +#define traceConcSyncBegin() /* nothing */ +#define traceConcSyncEnd() /* nothing */ +#define traceConcSweepBegin() /* nothing */ +#define traceConcSweepEnd() /* nothing */ +#define traceConcUpdRemSetFlush(cap) /* nothing */ + #define flushTrace() /* nothing */ #endif /* TRACING */ diff --git a/rts/eventlog/EventLog.c b/rts/eventlog/EventLog.c index 5c6a1ca48a..60b960998f 100644 --- a/rts/eventlog/EventLog.c +++ b/rts/eventlog/EventLog.c @@ -107,7 +107,14 @@ char *EventDesc[] = { [EVENT_HEAP_PROF_SAMPLE_END] = "End of heap profile sample", [EVENT_HEAP_PROF_SAMPLE_STRING] = "Heap profile string sample", [EVENT_HEAP_PROF_SAMPLE_COST_CENTRE] = "Heap profile cost-centre sample", - [EVENT_USER_BINARY_MSG] = "User binary message" + [EVENT_USER_BINARY_MSG] = "User binary message", + [EVENT_CONC_MARK_BEGIN] = "Begin concurrent mark phase", + [EVENT_CONC_MARK_END] = "End concurrent mark phase", + [EVENT_CONC_SYNC_BEGIN] = "Begin concurrent GC synchronisation", + [EVENT_CONC_SYNC_END] = "End concurrent GC synchronisation", + [EVENT_CONC_SWEEP_BEGIN] = "Begin concurrent sweep", + [EVENT_CONC_SWEEP_END] = "End concurrent sweep", + [EVENT_CONC_UPD_REM_SET_FLUSH] = "Update remembered set flushed" }; // Event type. @@ -446,6 +453,23 @@ init_event_types(void) eventTypes[t].size = EVENT_SIZE_DYNAMIC; break; + case EVENT_CONC_MARK_BEGIN: + case EVENT_CONC_SYNC_BEGIN: + case EVENT_CONC_SYNC_END: + case EVENT_CONC_SWEEP_BEGIN: + case EVENT_CONC_SWEEP_END: + eventTypes[t].size = 0; + break; + + case EVENT_CONC_MARK_END: + eventTypes[t].size = 4; + break; + + case EVENT_CONC_UPD_REM_SET_FLUSH: // (cap) + eventTypes[t].size = + sizeof(EventCapNo); + break; + default: continue; /* ignore deprecated events */ } @@ -1004,6 +1028,15 @@ void postTaskDeleteEvent (EventTaskId taskId) RELEASE_LOCK(&eventBufMutex); } +void +postEventNoCap (EventTypeNum tag) +{ + ACQUIRE_LOCK(&eventBufMutex); + ensureRoomForEvent(&eventBuf, tag); + postEventHeader(&eventBuf, tag); + RELEASE_LOCK(&eventBufMutex); +} + void postEvent (Capability *cap, EventTypeNum tag) { @@ -1130,6 +1163,23 @@ void postThreadLabel(Capability *cap, postBuf(eb, (StgWord8*) label, strsize); } +void postConcUpdRemSetFlush(Capability *cap) +{ + EventsBuf *eb = &capEventBuf[cap->no]; + ensureRoomForEvent(eb, EVENT_CONC_UPD_REM_SET_FLUSH); + postEventHeader(eb, EVENT_CONC_UPD_REM_SET_FLUSH); + postCapNo(eb, cap->no); +} + +void postConcMarkEnd(StgWord32 marked_obj_count) +{ + ACQUIRE_LOCK(&eventBufMutex); + ensureRoomForEvent(&eventBuf, EVENT_CONC_MARK_END); + postEventHeader(&eventBuf, EVENT_CONC_MARK_END); + postWord32(&eventBuf, marked_obj_count); + RELEASE_LOCK(&eventBufMutex); +} + void closeBlockMarker (EventsBuf *ebuf) { if (ebuf->marker) diff --git a/rts/eventlog/EventLog.h b/rts/eventlog/EventLog.h index d8a614b45c..16c7670cb3 100644 --- a/rts/eventlog/EventLog.h +++ b/rts/eventlog/EventLog.h @@ -39,6 +39,7 @@ void postSchedEvent(Capability *cap, EventTypeNum tag, * Post a nullary event. */ void postEvent(Capability *cap, EventTypeNum tag); +void postEventNoCap(EventTypeNum tag); void postEventAtTimestamp (Capability *cap, EventTimestamp ts, EventTypeNum tag); @@ -159,6 +160,9 @@ void postHeapProfSampleCostCentre(StgWord8 profile_id, StgWord64 residency); #endif /* PROFILING */ +void postConcUpdRemSetFlush(Capability *cap); +void postConcMarkEnd(StgWord32 marked_obj_count); + #else /* !TRACING */ INLINE_HEADER void postSchedEvent (Capability *cap STG_UNUSED, @@ -172,6 +176,9 @@ INLINE_HEADER void postEvent (Capability *cap STG_UNUSED, EventTypeNum tag STG_UNUSED) { /* nothing */ } +INLINE_HEADER void postEventNoCap (EventTypeNum tag STG_UNUSED) +{ /* nothing */ } + INLINE_HEADER void postMsg (char *msg STG_UNUSED, va_list ap STG_UNUSED) { /* nothing */ } diff --git a/rts/sm/NonMoving.c b/rts/sm/NonMoving.c index 24464a43f9..36df09692b 100644 --- a/rts/sm/NonMoving.c +++ b/rts/sm/NonMoving.c @@ -735,6 +735,8 @@ static void nonmovingMark_(MarkQueue *mark_queue, StgWeak **dead_weaks, StgTSO * * Sweep ****************************************************/ + traceConcSweepBegin(); + // Because we can't mark large object blocks (no room for mark bit) we // collect them in a map in mark_queue and we pass it here to sweep large // objects @@ -744,6 +746,7 @@ static void nonmovingMark_(MarkQueue *mark_queue, StgWeak **dead_weaks, StgTSO * nonmovingSweep(); ASSERT(nonmovingHeap.sweep_list == NULL); debugTrace(DEBUG_nonmoving_gc, "Finished sweeping."); + traceConcSweepEnd(); // TODO: Remainder of things done by GarbageCollect (update stats) diff --git a/rts/sm/NonMovingMark.c b/rts/sm/NonMovingMark.c index 72a3ca69cb..050b7ca24f 100644 --- a/rts/sm/NonMovingMark.c +++ b/rts/sm/NonMovingMark.c @@ -238,6 +238,7 @@ void nonmovingFlushCapUpdRemSetBlocks(Capability *cap) debugTrace(DEBUG_nonmoving_gc, "Capability %d flushing update remembered set: %d", cap->no, markQueueLength(&cap->upd_rem_set.queue)); + traceConcUpdRemSetFlush(cap); nonmovingAddUpdRemSetBlocks(&cap->upd_rem_set.queue); atomic_inc(&upd_rem_set_flush_count, 1); signalCondition(&upd_rem_set_flushed_cond); @@ -251,6 +252,7 @@ void nonmovingFlushCapUpdRemSetBlocks(Capability *cap) void nonmovingBeginFlush(Task *task) { debugTrace(DEBUG_nonmoving_gc, "Starting update remembered set flush..."); + traceConcSyncBegin(); upd_rem_set_flush_count = 0; stopAllCapabilitiesWith(NULL, task, SYNC_FLUSH_UPD_REM_SET); @@ -342,6 +344,7 @@ void nonmovingFinishFlush(Task *task) upd_rem_set_block_list = NULL; debugTrace(DEBUG_nonmoving_gc, "Finished update remembered set flush..."); + traceConcSyncEnd(); releaseAllCapabilities(n_capabilities, NULL, task); } #endif @@ -1434,6 +1437,7 @@ mark_closure (MarkQueue *queue, StgClosure *p, StgClosure **origin) GNUC_ATTR_HOT void nonmovingMark (MarkQueue *queue) { + traceConcMarkBegin(); debugTrace(DEBUG_nonmoving_gc, "Starting mark pass"); unsigned int count = 0; while (true) { @@ -1474,6 +1478,7 @@ nonmovingMark (MarkQueue *queue) } else { // Nothing more to do debugTrace(DEBUG_nonmoving_gc, "Finished mark pass: %d", count); + traceConcMarkEnd(count); return; } } -- cgit v1.2.1