X-Git-Url: http://git.megacz.com/?a=blobdiff_plain;f=rts%2Feventlog%2FEventLog.c;h=d2e3de35ffd03407fdc3bc23a2c03faaedda0481;hb=58532eb46041aec8d4cbb48b054cb5b001edb43c;hp=178dfb3fd7653bc0d3d52787ccf4e61fdf477870;hpb=d71615757d0462b1721ee3664c5fa9f79325d666;p=ghc-hetmet.git diff --git a/rts/eventlog/EventLog.c b/rts/eventlog/EventLog.c index 178dfb3..d2e3de3 100644 --- a/rts/eventlog/EventLog.c +++ b/rts/eventlog/EventLog.c @@ -13,13 +13,21 @@ #include "Trace.h" #include "Capability.h" -#include "Trace.h" #include "RtsUtils.h" #include "Stats.h" #include "EventLog.h" -#include +#include #include +#ifdef HAVE_SYS_TYPES_H +#include +#endif +#ifdef HAVE_UNISTD_H +#include +#endif + +// PID of the process that writes to event_log_filename (#4512) +static pid_t event_log_pid = -1; static char *event_log_filename = NULL; @@ -36,6 +44,7 @@ typedef struct _EventsBuf { StgInt8 *pos; StgInt8 *marker; StgWord64 size; + EventCapNo capno; // which capability this buffer belongs to, or -1 } EventsBuf; EventsBuf *capEventBuf; // one EventsBuf for each Capability @@ -60,10 +69,21 @@ char *EventDesc[] = { [EVENT_REQUEST_SEQ_GC] = "Request sequential GC", [EVENT_REQUEST_PAR_GC] = "Request parallel GC", [EVENT_CREATE_SPARK_THREAD] = "Create spark thread", - [EVENT_LOG_CAP_MSG] = "Log Capability message", [EVENT_LOG_MSG] = "Log message", + [EVENT_USER_MSG] = "User message", [EVENT_STARTUP] = "Startup", - [EVENT_BLOCK_MARKER] = "Block marker" + [EVENT_GC_IDLE] = "GC idle", + [EVENT_GC_WORK] = "GC working", + [EVENT_GC_DONE] = "GC done", + [EVENT_BLOCK_MARKER] = "Block marker", + [EVENT_CAPSET_CREATE] = "Create capability set", + [EVENT_CAPSET_DELETE] = "Delete capability set", + [EVENT_CAPSET_ASSIGN_CAP] = "Add capability to capability set", + [EVENT_CAPSET_REMOVE_CAP] = "Remove capability from capability set", + [EVENT_RTS_IDENTIFIER] = "Identify the RTS version", + [EVENT_PROGRAM_ARGS] = "Identify the program arguments", + [EVENT_PROGRAM_ENV] = "Identify the environment variables", + [EVENT_OSPROCESS_PID] = "Identify the process ID of a capability set" }; // Event type. @@ -76,12 +96,14 @@ typedef struct _EventType { EventType eventTypes[NUM_EVENT_TAGS]; -static void initEventsBuf(EventsBuf* eb, StgWord64 size); +static void initEventsBuf(EventsBuf* eb, StgWord64 size, EventCapNo capno); static void resetEventsBuf(EventsBuf* eb); static void printAndClearEventBuf (EventsBuf *eventsBuf); static void postEventType(EventsBuf *eb, EventType *et); +static void postLogMsg(EventsBuf *eb, EventTypeNum type, char *msg, va_list ap); + static void postBlockMarker(EventsBuf *eb); static void closeBlockMarker(EventsBuf *ebuf); @@ -132,6 +154,12 @@ static inline void postThreadID(EventsBuf *eb, EventThreadID id) static inline void postCapNo(EventsBuf *eb, EventCapNo no) { postWord16(eb,no); } +static inline void postCapsetID(EventsBuf *eb, EventCapsetID id) +{ postWord32(eb,id); } + +static inline void postCapsetType(EventsBuf *eb, EventCapsetType type) +{ postWord16(eb,type); } + static inline void postPayloadSize(EventsBuf *eb, EventPayloadSize size) { postWord16(eb,size); } @@ -160,18 +188,29 @@ initEventLogging(void) StgWord8 t, c; nat n_caps; - event_log_filename = stgMallocBytes(strlen(prog_name) + 10, + event_log_filename = stgMallocBytes(strlen(prog_name) + + 10 /* .%d */ + + 10 /* .eventlog */, "initEventLogging"); if (sizeof(EventDesc) / sizeof(char*) != NUM_EVENT_TAGS) { barf("EventDesc array has the wrong number of elements"); } - - sprintf(event_log_filename, "%s.eventlog", prog_name); - + + if (event_log_pid == -1) { // #4512 + // Single process + sprintf(event_log_filename, "%s.eventlog", prog_name); + event_log_pid = getpid(); + } else { + // Forked process, eventlog already started by the parent + // before fork + event_log_pid = getpid(); + sprintf(event_log_filename, "%s.%d.eventlog", prog_name, event_log_pid); + } + /* Open event log file for writing. */ if ((event_log_file = fopen(event_log_filename, "wb")) == NULL) { - sysErrorBelch("initEventLoggin: can't open %s", event_log_filename); + sysErrorBelch("initEventLogging: can't open %s", event_log_filename); stg_exit(EXIT_FAILURE); } @@ -195,9 +234,9 @@ initEventLogging(void) for (c = 0; c < n_caps; ++c) { // Init buffer for events. - initEventsBuf(&capEventBuf[c], EVENT_LOG_SIZE); + initEventsBuf(&capEventBuf[c], EVENT_LOG_SIZE, c); } - initEventsBuf(&eventBuf, EVENT_LOG_SIZE); + initEventsBuf(&eventBuf, EVENT_LOG_SIZE, (EventCapNo)(-1)); // Write in buffer: the header begin marker. postInt32(&eventBuf, EVENT_HEADER_BEGIN); @@ -215,19 +254,43 @@ initEventLogging(void) case EVENT_THREAD_RUNNABLE: // (cap, thread) case EVENT_RUN_SPARK: // (cap, thread) case EVENT_CREATE_SPARK_THREAD: // (cap, spark_thread) - eventTypes[t].size = sizeof(EventCapNo) + sizeof(EventThreadID); + eventTypes[t].size = sizeof(EventThreadID); break; case EVENT_MIGRATE_THREAD: // (cap, thread, new_cap) case EVENT_STEAL_SPARK: // (cap, thread, victim_cap) case EVENT_THREAD_WAKEUP: // (cap, thread, other_cap) eventTypes[t].size = - sizeof(EventCapNo) + sizeof(EventThreadID) + sizeof(EventCapNo); + sizeof(EventThreadID) + sizeof(EventCapNo); break; case EVENT_STOP_THREAD: // (cap, thread, status) eventTypes[t].size = - sizeof(EventCapNo) + sizeof(EventThreadID) + sizeof(StgWord16); + sizeof(EventThreadID) + sizeof(StgWord16) + sizeof(EventThreadID); + break; + + case EVENT_STARTUP: // (cap count) + eventTypes[t].size = sizeof(EventCapNo); + break; + + case EVENT_CAPSET_CREATE: // (capset, capset_type) + eventTypes[t].size = + sizeof(EventCapsetID) + sizeof(EventCapsetType); + break; + + case EVENT_CAPSET_DELETE: // (capset) + eventTypes[t].size = sizeof(EventCapsetID); + break; + + case EVENT_CAPSET_ASSIGN_CAP: // (capset, cap) + case EVENT_CAPSET_REMOVE_CAP: + eventTypes[t].size = + sizeof(EventCapsetID) + sizeof(EventCapNo); + break; + + case EVENT_OSPROCESS_PID: // (cap, pid, parent pid) + eventTypes[t].size = + sizeof(EventCapsetID) + 2*sizeof(StgWord32); break; case EVENT_SHUTDOWN: // (cap) @@ -235,20 +298,23 @@ initEventLogging(void) case EVENT_REQUEST_PAR_GC: // (cap) case EVENT_GC_START: // (cap) case EVENT_GC_END: // (cap) - eventTypes[t].size = sizeof(EventCapNo); + case EVENT_GC_IDLE: + case EVENT_GC_WORK: + case EVENT_GC_DONE: + eventTypes[t].size = 0; break; case EVENT_LOG_MSG: // (msg) - case EVENT_LOG_CAP_MSG: // (cap,msg) + case EVENT_USER_MSG: // (msg) + case EVENT_RTS_IDENTIFIER: // (capset, str) + case EVENT_PROGRAM_ARGS: // (capset, strvec) + case EVENT_PROGRAM_ENV: // (capset, strvec) eventTypes[t].size = 0xffff; break; - case EVENT_STARTUP: - eventTypes[t].size = sizeof(EventCapNo); - break; - case EVENT_BLOCK_MARKER: - eventTypes[t].size = sizeof(StgWord32) + sizeof(EventTimestamp); + eventTypes[t].size = sizeof(StgWord32) + sizeof(EventTimestamp) + + sizeof(EventCapNo); break; default: @@ -268,6 +334,10 @@ initEventLogging(void) // Prepare event buffer for events (data). postInt32(&eventBuf, EVENT_DATA_BEGIN); + // Post a STARTUP event with the number of capabilities + postEventHeader(&eventBuf, EVENT_STARTUP); + postCapNo(&eventBuf, n_caps); + // Flush capEventBuf with header. /* * Flush header and data begin marker to the file, thus preparing the @@ -278,6 +348,10 @@ initEventLogging(void) for (c = 0; c < n_caps; ++c) { postBlockMarker(&capEventBuf[c]); } + +#ifdef THREADED_RTS + initMutex(&eventBufMutex); +#endif } void @@ -290,6 +364,7 @@ endEventLogging(void) printAndClearEventBuf(&capEventBuf[c]); } printAndClearEventBuf(&eventBuf); + resetEventsBuf(&eventBuf); // we don't want the block marker // Mark end of events (data). postEventTypeNum(&eventBuf, EVENT_DATA_END); @@ -320,6 +395,22 @@ freeEventLogging(void) } } +void +flushEventLog(void) +{ + if (event_log_file != NULL) { + fflush(event_log_file); + } +} + +void +abortEventLogging(void) +{ + freeEventLogging(); + if (event_log_file != NULL) { + fclose(event_log_file); + } +} /* * Post an event message to the capability's eventlog buffer. * If the buffer is full, prints out the buffer and clears it. @@ -328,7 +419,8 @@ void postSchedEvent (Capability *cap, EventTypeNum tag, StgThreadID thread, - StgWord64 other) + StgWord info1, + StgWord info2) { EventsBuf *eb; @@ -340,7 +432,6 @@ postSchedEvent (Capability *cap, } postEventHeader(eb, tag); - postCapNo(eb, cap->no); switch (tag) { case EVENT_CREATE_THREAD: // (cap, thread) @@ -354,7 +445,7 @@ postSchedEvent (Capability *cap, case EVENT_CREATE_SPARK_THREAD: // (cap, spark_thread) { - postThreadID(eb,other /* spark_thread */); + postThreadID(eb,info1 /* spark_thread */); break; } @@ -363,14 +454,15 @@ postSchedEvent (Capability *cap, case EVENT_THREAD_WAKEUP: // (cap, thread, other_cap) { postThreadID(eb,thread); - postCapNo(eb,other /* new_cap | victim_cap | other_cap */); + postCapNo(eb,info1 /* new_cap | victim_cap | other_cap */); break; } case EVENT_STOP_THREAD: // (cap, thread, status) { postThreadID(eb,thread); - postWord16(eb,other /* status */); + postWord16(eb,info1 /* status */); + postThreadID(eb,info2 /* blocked on thread */); break; } @@ -388,38 +480,135 @@ postSchedEvent (Capability *cap, } } -#define BUF 512 +void postCapsetModifyEvent (EventTypeNum tag, + EventCapsetID capset, + StgWord32 other, + StgWord32 other2) +{ + ACQUIRE_LOCK(&eventBufMutex); -void postMsg(char *msg, va_list ap) + if (!hasRoomForEvent(&eventBuf, tag)) { + // Flush event buffer to make room for new event. + printAndClearEventBuf(&eventBuf); + } + + postEventHeader(&eventBuf, tag); + postCapsetID(&eventBuf, capset); + + switch (tag) { + case EVENT_CAPSET_CREATE: // (capset, capset_type) + { + postCapsetType(&eventBuf, other /* capset_type */); + break; + } + + case EVENT_CAPSET_DELETE: // (capset) + { + break; + } + + case EVENT_CAPSET_ASSIGN_CAP: // (capset, capno) + case EVENT_CAPSET_REMOVE_CAP: // (capset, capno) + { + postCapNo(&eventBuf, other /* capno */); + break; + } + case EVENT_OSPROCESS_PID: + { + postWord32(&eventBuf, other); + postWord32(&eventBuf, other2); + break; + } + default: + barf("postCapsetModifyEvent: unknown event tag %d", tag); + } + + RELEASE_LOCK(&eventBufMutex); +} + +void postCapsetStrEvent (EventTypeNum tag, + EventCapsetID capset, + char *msg) { - EventsBuf *eb; - char buf[BUF]; - nat size; + int strsize = strlen(msg); + int size = strsize + sizeof(EventCapsetID) - size = vsnprintf(buf,BUF,msg,ap); - if (size > BUF) { - buf[BUF-1] = '\0'; - size = BUF; + ACQUIRE_LOCK(&eventBufMutex); + + if (!hasRoomForVariableEvent(&eventBuf, size)){ + printAndClearEventBuf(&eventBuf); + + if (!hasRoomForVariableEvent(&eventBuf, size)){ + // Event size exceeds buffer size, bail out: + RELEASE_LOCK(&eventBufMutex); + return; + } + } + + postEventHeader(&eventBuf, tag); + postPayloadSize(&eventBuf, size); + postCapsetID(&eventBuf, capset); + + postBuf(&eventBuf, (StgWord8*) msg, strsize); + + RELEASE_LOCK(&eventBufMutex); +} + +void postCapsetVecEvent (EventTypeNum tag, + EventCapsetID capset, + int argc, + char *argv[]) +{ + int i, size = sizeof(EventCapsetID); + + for (i = 0; i < argc; i++) { + // 1 + strlen to account for the trailing \0, used as separator + size += 1 + strlen(argv[i]); } ACQUIRE_LOCK(&eventBufMutex); - eb = &eventBuf; - if (!hasRoomForVariableEvent(eb, size)) { - // Flush event buffer to make room for new event. - printAndClearEventBuf(eb); + if (!hasRoomForVariableEvent(&eventBuf, size)){ + printAndClearEventBuf(&eventBuf); + + if(!hasRoomForVariableEvent(&eventBuf, size)){ + // Event size exceeds buffer size, bail out: + RELEASE_LOCK(&eventBufMutex); + return; + } } - postEventHeader(eb, EVENT_LOG_MSG); - postPayloadSize(eb, size); - postBuf(eb,(StgWord8*)buf,size); + postEventHeader(&eventBuf, tag); + postPayloadSize(&eventBuf, size); + postCapsetID(&eventBuf, capset); + + for( i = 0; i < argc; i++ ) { + // again, 1 + to account for \0 + postBuf(&eventBuf, (StgWord8*) argv[i], 1 + strlen(argv[i])); + } RELEASE_LOCK(&eventBufMutex); } -void postCapMsg(Capability *cap, char *msg, va_list ap) +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) +{ char buf[BUF]; nat size; @@ -429,26 +618,47 @@ void postCapMsg(Capability *cap, char *msg, va_list ap) size = BUF; } - eb = &capEventBuf[cap->no]; - if (!hasRoomForVariableEvent(eb, size)) { // Flush event buffer to make room for new event. printAndClearEventBuf(eb); } - postEventHeader(eb, EVENT_LOG_MSG); - postPayloadSize(eb, size + sizeof(EventCapNo)); - postCapNo(eb, cap->no); + postEventHeader(eb, type); + postPayloadSize(eb, size); postBuf(eb,(StgWord8*)buf,size); } +void postMsg(char *msg, va_list ap) +{ + ACQUIRE_LOCK(&eventBufMutex); + postLogMsg(&eventBuf, EVENT_LOG_MSG, msg, ap); + RELEASE_LOCK(&eventBufMutex); +} + +void postCapMsg(Capability *cap, char *msg, va_list ap) +{ + postLogMsg(&capEventBuf[cap->no], EVENT_LOG_MSG, msg, ap); +} + +void postUserMsg(Capability *cap, char *msg, va_list ap) +{ + postLogMsg(&capEventBuf[cap->no], EVENT_USER_MSG, msg, ap); +} + void closeBlockMarker (EventsBuf *ebuf) { + StgInt8* save_pos; + if (ebuf->marker) { // (type:16, time:64, size:32, end_time:64) - *(StgWord32 *)(ebuf->marker + 10) = ebuf->pos - ebuf->marker; - *(StgWord64 *)(ebuf->marker + 14) = time_ns(); + + save_pos = ebuf->pos; + ebuf->pos = ebuf->marker + sizeof(EventTypeNum) + + sizeof(EventTimestamp); + postWord32(ebuf, save_pos - ebuf->marker); + postTimestamp(ebuf); + ebuf->pos = save_pos; ebuf->marker = NULL; } } @@ -466,6 +676,7 @@ void postBlockMarker (EventsBuf *eb) postEventHeader(eb, EVENT_BLOCK_MARKER); postWord32(eb,0); // these get filled in later by closeBlockMarker(); postWord64(eb,0); + postCapNo(eb, eb->capno); } void printAndClearEventBuf (EventsBuf *ebuf) @@ -493,16 +704,18 @@ void printAndClearEventBuf (EventsBuf *ebuf) } } -void initEventsBuf(EventsBuf* eb, StgWord64 size) +void initEventsBuf(EventsBuf* eb, StgWord64 size, EventCapNo capno) { eb->begin = eb->pos = stgMallocBytes(size, "initEventsBuf"); eb->size = size; eb->marker = NULL; + eb->capno = capno; } void resetEventsBuf(EventsBuf* eb) { eb->pos = eb->begin; + eb->marker = NULL; } StgBool hasRoomForEvent(EventsBuf *eb, EventTypeNum eNum)