diff options
author | Ben Gamari <bgamari.foss@gmail.com> | 2016-06-16 15:03:01 +0200 |
---|---|---|
committer | Ben Gamari <ben@smart-cactus.org> | 2016-07-16 20:31:47 +0200 |
commit | a9bc54766ddd1bdb011f1656ad58fb409055d08f (patch) | |
tree | 4d91f1a2c4c0b44b61c910a11b998bc71154f71a /rts | |
parent | b35e01c6c39d9f2d58009722e24d89049aa94287 (diff) | |
download | haskell-a9bc54766ddd1bdb011f1656ad58fb409055d08f.tar.gz |
Log heap profiler samples to event log
Test Plan: Try it
Reviewers: hvr, simonmar, austin, erikd
Subscribers: thomie
Differential Revision: https://phabricator.haskell.org/D1722
GHC Trac Issues: #11094
Diffstat (limited to 'rts')
-rw-r--r-- | rts/ProfHeap.c | 32 | ||||
-rw-r--r-- | rts/Trace.c | 43 | ||||
-rw-r--r-- | rts/Trace.h | 19 | ||||
-rw-r--r-- | rts/eventlog/EventLog.c | 183 | ||||
-rw-r--r-- | rts/eventlog/EventLog.h | 20 |
5 files changed, 294 insertions, 3 deletions
diff --git a/rts/ProfHeap.c b/rts/ProfHeap.c index 18c3e41a32..664ee50d70 100644 --- a/rts/ProfHeap.c +++ b/rts/ProfHeap.c @@ -20,6 +20,7 @@ #include "LdvProfile.h" #include "Arena.h" #include "Printer.h" +#include "Trace.h" #include "sm/GCThread.h" #include <string.h> @@ -371,6 +372,19 @@ printSample(rtsBool beginSample, StgDouble sampleValue) } } +static void +dumpCostCentresToEventLog(void) +{ +#ifdef PROFILING + CostCentre *cc, *next; + for (cc = CC_LIST; cc != NULL; cc = next) { + next = cc->link; + traceHeapProfCostCentre(cc->ccID, cc->label, cc->module, + cc->srcloc, cc->is_caf); + } +#endif +} + /* -------------------------------------------------------------------------- * Initialize the heap profilier * ----------------------------------------------------------------------- */ @@ -400,7 +414,7 @@ initHeapProfiling(void) } // max_era = 2^LDV_SHIFT - max_era = 1 << LDV_SHIFT; + max_era = 1 << LDV_SHIFT; n_censuses = 32; censuses = stgMallocBytes(sizeof(Census) * n_censuses, "initHeapProfiling"); @@ -437,6 +451,9 @@ initHeapProfiling(void) } #endif + traceHeapProfBegin(0); + dumpCostCentresToEventLog(); + return 0; } @@ -744,10 +761,12 @@ dumpCensus( Census *census ) ssize_t count; printSample(rtsTrue, census->time); + traceHeapProfSampleBegin(era); #ifdef PROFILING if (RtsFlags.ProfFlags.doHeapProfile == HEAP_BY_LDV) { - fprintf(hp_file, "VOID\t%lu\n", (unsigned long)(census->void_total) * sizeof(W_)); + fprintf(hp_file, "VOID\t%lu\n", + (unsigned long)(census->void_total) * sizeof(W_)); fprintf(hp_file, "LAG\t%lu\n", (unsigned long)(census->not_used - census->void_total) * sizeof(W_)); fprintf(hp_file, "USE\t%lu\n", @@ -788,6 +807,8 @@ dumpCensus( Census *census ) switch (RtsFlags.ProfFlags.doHeapProfile) { case HEAP_BY_CLOSURE_TYPE: fprintf(hp_file, "%s", (char *)ctr->identity); + traceHeapProfSampleString(0, (char *)ctr->identity, + count * sizeof(W_)); break; } #endif @@ -795,12 +816,17 @@ dumpCensus( Census *census ) #ifdef PROFILING switch (RtsFlags.ProfFlags.doHeapProfile) { case HEAP_BY_CCS: - fprint_ccs(hp_file, (CostCentreStack *)ctr->identity, RtsFlags.ProfFlags.ccsLength); + fprint_ccs(hp_file, (CostCentreStack *)ctr->identity, + RtsFlags.ProfFlags.ccsLength); + traceHeapProfSampleCostCentre(0, (CostCentreStack *)ctr->identity, + count * sizeof(W_)); break; case HEAP_BY_MOD: case HEAP_BY_DESCR: case HEAP_BY_TYPE: fprintf(hp_file, "%s", (char *)ctr->identity); + traceHeapProfSampleString(0, (char *)ctr->identity, + count * sizeof(W_)); break; case HEAP_BY_RETAINER: { diff --git a/rts/Trace.c b/rts/Trace.c index 8480f10bbd..fdf80496f8 100644 --- a/rts/Trace.c +++ b/rts/Trace.c @@ -622,6 +622,49 @@ void traceTaskDelete_ (Task *task) } } +void traceHeapProfBegin(StgWord8 profile_id) +{ + if (eventlog_enabled) { + postHeapProfBegin(profile_id); + } +} + +void traceHeapProfSampleBegin(StgInt era) +{ + if (eventlog_enabled) { + postHeapProfSampleBegin(era); + } +} + +void traceHeapProfSampleString(StgWord8 profile_id, + const char *label, StgWord residency) +{ + if (eventlog_enabled) { + postHeapProfSampleString(profile_id, label, residency); + } +} + +#ifdef PROFILING +void traceHeapProfCostCentre(StgWord32 ccID, + const char *label, + const char *module, + const char *srcloc, + StgBool is_caf) +{ + if (eventlog_enabled) { + postHeapProfCostCentre(ccID, label, module, srcloc, is_caf); + } +} + +void traceHeapProfSampleCostCentre(StgWord8 profile_id, + CostCentreStack *stack, StgWord residency) +{ + if (eventlog_enabled) { + postHeapProfSampleCostCentre(profile_id, stack, residency); + } +} +#endif + #ifdef DEBUG static void vtraceCap_stderr(Capability *cap, char *msg, va_list ap) { diff --git a/rts/Trace.h b/rts/Trace.h index cad65b0644..ab79671c4c 100644 --- a/rts/Trace.h +++ b/rts/Trace.h @@ -275,6 +275,20 @@ void traceTaskMigrate_ (Task *task, void traceTaskDelete_ (Task *task); +void traceHeapProfBegin(StgWord8 profile_id); +void traceHeapProfSampleBegin(StgInt era); +void traceHeapProfSampleString(StgWord8 profile_id, + const char *label, StgWord residency); +#ifdef PROFILING +void traceHeapProfCostCentre(StgWord32 ccID, + const char *label, + const char *module, + const char *srcloc, + StgBool is_caf); +void traceHeapProfSampleCostCentre(StgWord8 profile_id, + CostCentreStack *stack, StgWord residency); +#endif /* PROFILING */ + #else /* !TRACING */ #define traceSchedEvent(cap, tag, tso, other) /* nothing */ @@ -304,6 +318,11 @@ void traceTaskDelete_ (Task *task); #define traceTaskCreate_(taskID, cap) /* nothing */ #define traceTaskMigrate_(taskID, cap, new_cap) /* nothing */ #define traceTaskDelete_(taskID) /* nothing */ +#define traceHeapProfBegin(profile_id) /* nothing */ +#define traceHeapProfCostCentre(ccID, label, module, srcloc, is_caf) /* nothing */ +#define traceHeapProfSampleBegin(era) /* nothing */ +#define traceHeapProfSampleCostCentre(profile_id, stack, residency) /* nothing */ +#define traceHeapProfSampleString(profile_id, label, residency) /* nothing */ #endif /* TRACING */ diff --git a/rts/eventlog/EventLog.c b/rts/eventlog/EventLog.c index 7cb69e8d7d..4e4bdb5191 100644 --- a/rts/eventlog/EventLog.c +++ b/rts/eventlog/EventLog.c @@ -106,6 +106,11 @@ char *EventDesc[] = { [EVENT_TASK_MIGRATE] = "Task migrate", [EVENT_TASK_DELETE] = "Task delete", [EVENT_HACK_BUG_T9003] = "Empty event for bug #9003", + [EVENT_HEAP_PROF_BEGIN] = "Start of heap profile", + [EVENT_HEAP_PROF_COST_CENTRE] = "Cost center definition", + [EVENT_HEAP_PROF_SAMPLE_BEGIN] = "Start 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 type. @@ -164,6 +169,22 @@ static inline void postBuf(EventsBuf *eb, StgWord8 *buf, uint32_t size) eb->pos += size; } +/* Post a null-terminated string to the event log. + * It is the caller's responsibility to ensure that there is + * enough room for strlen(buf)+1 bytes. + */ +static inline void postString(EventsBuf *eb, const char *buf) +{ + if (buf) { + int len = strlen(buf); + ASSERT(eb->begin + eb->size > eb->pos + len); + memcpy(eb->pos, buf, len); + eb->pos += len; + } + *eb->pos = 0; + eb->pos++; +} + static inline StgWord64 time_ns(void) { return TimeToNS(stat_getElapsedTime()); } @@ -209,6 +230,7 @@ static inline void postInt8(EventsBuf *eb, StgInt8 i) static inline void postInt32(EventsBuf *eb, StgInt32 i) { postWord32(eb, (StgWord32)i); } +#define EVENT_SIZE_DYNAMIC (-1) void initEventLogging(void) @@ -429,6 +451,26 @@ initEventLogging(void) eventTypes[t].size = 0; break; + case EVENT_HEAP_PROF_BEGIN: + eventTypes[t].size = EVENT_SIZE_DYNAMIC; + break; + + case EVENT_HEAP_PROF_COST_CENTRE: + eventTypes[t].size = EVENT_SIZE_DYNAMIC; + break; + + case EVENT_HEAP_PROF_SAMPLE_BEGIN: + eventTypes[t].size = 8; + break; + + case EVENT_HEAP_PROF_SAMPLE_STRING: + eventTypes[t].size = EVENT_SIZE_DYNAMIC; + break; + + case EVENT_HEAP_PROF_SAMPLE_COST_CENTRE: + eventTypes[t].size = EVENT_SIZE_DYNAMIC; + break; + default: continue; /* ignore deprecated events */ } @@ -1098,6 +1140,147 @@ void postBlockMarker (EventsBuf *eb) postCapNo(eb, eb->capno); } +typedef enum { + HEAP_PROF_BREAKDOWN_COST_CENTRE = 0x1, + HEAP_PROF_BREAKDOWN_MODULE, + HEAP_PROF_BREAKDOWN_CLOSURE_DESCR, + HEAP_PROF_BREAKDOWN_TYPE_DESCR, + HEAP_PROF_BREAKDOWN_RETAINER, + HEAP_PROF_BREAKDOWN_BIOGRAPHY, +} HeapProfBreakdown; + +static HeapProfBreakdown getHeapProfBreakdown(void) +{ + switch (RtsFlags.ProfFlags.doHeapProfile) { + case HEAP_BY_CCS: + return HEAP_PROF_BREAKDOWN_COST_CENTRE; + case HEAP_BY_MOD: + return HEAP_PROF_BREAKDOWN_MODULE; + case HEAP_BY_DESCR: + return HEAP_PROF_BREAKDOWN_CLOSURE_DESCR; + case HEAP_BY_TYPE: + return HEAP_PROF_BREAKDOWN_TYPE_DESCR; + case HEAP_BY_RETAINER: + return HEAP_PROF_BREAKDOWN_RETAINER; + case HEAP_BY_LDV: + return HEAP_PROF_BREAKDOWN_BIOGRAPHY; + default: + barf("getHeapProfBreakdown: unknown heap profiling mode"); + } +} + +void postHeapProfBegin(StgWord8 profile_id) +{ + ACQUIRE_LOCK(&eventBufMutex); + PROFILING_FLAGS *flags = &RtsFlags.ProfFlags; + StgWord modSelector_len = + flags->modSelector ? strlen(flags->modSelector) : 0; + StgWord descrSelector_len = + flags->descrSelector ? strlen(flags->descrSelector) : 0; + StgWord typeSelector_len = + flags->typeSelector ? strlen(flags->typeSelector) : 0; + StgWord ccSelector_len = + flags->ccSelector ? strlen(flags->ccSelector) : 0; + StgWord ccsSelector_len = + flags->ccsSelector ? strlen(flags->ccsSelector) : 0; + StgWord retainerSelector_len = + flags->retainerSelector ? strlen(flags->retainerSelector) : 0; + StgWord bioSelector_len = + flags->bioSelector ? strlen(flags->bioSelector) : 0; + StgWord len = + 1+8+4 + modSelector_len + descrSelector_len + + typeSelector_len + ccSelector_len + ccsSelector_len + + retainerSelector_len + bioSelector_len + 7; + ensureRoomForVariableEvent(&eventBuf, len); + postEventHeader(&eventBuf, EVENT_HEAP_PROF_BEGIN); + postPayloadSize(&eventBuf, len); + postWord8(&eventBuf, profile_id); + postWord64(&eventBuf, TimeToNS(flags->heapProfileInterval)); + postWord32(&eventBuf, getHeapProfBreakdown()); + postString(&eventBuf, flags->modSelector); + postString(&eventBuf, flags->descrSelector); + postString(&eventBuf, flags->typeSelector); + postString(&eventBuf, flags->ccSelector); + postString(&eventBuf, flags->ccsSelector); + postString(&eventBuf, flags->retainerSelector); + postString(&eventBuf, flags->bioSelector); + RELEASE_LOCK(&eventBufMutex); +} + +void postHeapProfSampleBegin(StgInt era) +{ + ACQUIRE_LOCK(&eventBufMutex); + ensureRoomForEvent(&eventBuf, EVENT_HEAP_PROF_SAMPLE_BEGIN); + postEventHeader(&eventBuf, EVENT_HEAP_PROF_SAMPLE_BEGIN); + postWord64(&eventBuf, era); + RELEASE_LOCK(&eventBufMutex); +} + +void postHeapProfSampleString(StgWord8 profile_id, + const char *label, + StgWord64 residency) +{ + ACQUIRE_LOCK(&eventBufMutex); + StgWord label_len = strlen(label); + StgWord len = 1+8+label_len+1; + ensureRoomForVariableEvent(&eventBuf, len); + postEventHeader(&eventBuf, EVENT_HEAP_PROF_SAMPLE_STRING); + postPayloadSize(&eventBuf, len); + postWord8(&eventBuf, profile_id); + postWord64(&eventBuf, residency); + postString(&eventBuf, label); + RELEASE_LOCK(&eventBufMutex); +} + +#ifdef PROFILING +void postHeapProfCostCentre(StgWord32 ccID, + const char *label, + const char *module, + const char *srcloc, + StgBool is_caf) +{ + ACQUIRE_LOCK(&eventBufMutex); + StgWord label_len = strlen(label); + StgWord module_len = strlen(module); + StgWord srcloc_len = strlen(srcloc); + StgWord len = 4+label_len+module_len+srcloc_len+3+1; + ensureRoomForVariableEvent(&eventBuf, len); + postEventHeader(&eventBuf, EVENT_HEAP_PROF_COST_CENTRE); + postPayloadSize(&eventBuf, len); + postWord32(&eventBuf, ccID); + postString(&eventBuf, label); + postString(&eventBuf, module); + postString(&eventBuf, srcloc); + postWord8(&eventBuf, is_caf); + RELEASE_LOCK(&eventBufMutex); +} + +void postHeapProfSampleCostCentre(StgWord8 profile_id, + CostCentreStack *stack, + StgWord64 residency) +{ + ACQUIRE_LOCK(&eventBufMutex); + StgWord depth = 0; + CostCentreStack *ccs; + for (ccs = stack; ccs != NULL && ccs != CCS_MAIN; ccs = ccs->prevStack) + depth++; + if (depth > 0xff) depth = 0xff; + + StgWord len = 1+8+1+depth*4; + ensureRoomForVariableEvent(&eventBuf, len); + postEventHeader(&eventBuf, EVENT_HEAP_PROF_SAMPLE_COST_CENTRE); + postPayloadSize(&eventBuf, len); + postWord8(&eventBuf, profile_id); + postWord64(&eventBuf, residency); + postWord8(&eventBuf, depth); + for (ccs = stack; + depth>0 && ccs != NULL && ccs != CCS_MAIN; + ccs = ccs->prevStack, depth--) + postWord32(&eventBuf, ccs->cc->ccID); + RELEASE_LOCK(&eventBufMutex); +} +#endif /* PROFILING */ + void printAndClearEventBuf (EventsBuf *ebuf) { closeBlockMarker(ebuf); diff --git a/rts/eventlog/EventLog.h b/rts/eventlog/EventLog.h index ed783bc361..462f5f594e 100644 --- a/rts/eventlog/EventLog.h +++ b/rts/eventlog/EventLog.h @@ -133,6 +133,26 @@ void postTaskMigrateEvent (EventTaskId taskId, void postTaskDeleteEvent (EventTaskId taskId); +void postHeapProfBegin(StgWord8 profile_id); + +void postHeapProfSampleBegin(StgInt era); + +void postHeapProfSampleString(StgWord8 profile_id, + const char *label, + StgWord64 residency); + +#ifdef PROFILING +void postHeapProfCostCentre(StgWord32 ccID, + const char *label, + const char *module, + const char *srcloc, + StgBool is_caf); + +void postHeapProfSampleCostCentre(StgWord8 profile_id, + CostCentreStack *stack, + StgWord64 residency); +#endif /* PROFILING */ + #else /* !TRACING */ INLINE_HEADER void postSchedEvent (Capability *cap STG_UNUSED, |