diff options
Diffstat (limited to 'rts/eventlog/EventLog.c')
| -rw-r--r-- | rts/eventlog/EventLog.c | 467 |
1 files changed, 467 insertions, 0 deletions
diff --git a/rts/eventlog/EventLog.c b/rts/eventlog/EventLog.c new file mode 100644 index 0000000000..8e74215dbb --- /dev/null +++ b/rts/eventlog/EventLog.c @@ -0,0 +1,467 @@ +/* ----------------------------------------------------------------------------- + * + * (c) The GHC Team, 2008-2009 + * + * Support for fast binary event logging. + * + * ---------------------------------------------------------------------------*/ + +#ifdef EVENTLOG + +#include "Rts.h" +#include "EventLog.h" +#include "Capability.h" +#include "Trace.h" +#include "RtsUtils.h" +#include "Stats.h" +#include <string.h> +#include <stdio.h> + +static char *event_log_filename = NULL; + +// File for logging events +FILE *event_log_file = NULL; + +#define EVENT_LOG_SIZE 2 * (1024 * 1024) // 2MB + +static int flushCount; + +// Struct for record keeping of buffer to store event types and events. +typedef struct _EventsBuf { + StgInt8 *begin; + StgInt8 *pos; + StgWord64 size; +} EventsBuf; + +EventsBuf *eventsBuf; + +char *EventDesc[] = { + "Create thread", + "Run thread", + "Stop thread", + "Thread runnable", + "Migrate thread", + "Run spark", + "Steal spark", + "Shutdown", + "Wakeup thread", + "Request sequential GC", + "Request parallel GC", + "Starting GC", + "Finished GC" +}; + +// Event type. + +typedef struct _EventType { + EventTypeNum etNum; // Event Type number. + nat size; // size of the payload in bytes + char *desc; // Description +} EventType; + +EventType eventTypes[NUM_EVENT_TAGS]; + +static void printAndClearEventBuf (EventsBuf *eventsBuf); +static void initEventsBuf(EventsBuf* eb, StgWord64 size); +static void resetEventsBuf(EventsBuf* eb); + +static void beginHeader(EventsBuf *eb); +static void endHeader(EventsBuf *eb); + +static void beginData(EventsBuf *eb); +static void endData(EventsBuf *eb); + +static void beginEventTypes(EventsBuf *eb); +static void endEventTypes(EventsBuf *eb); + +static void postEventType(EventsBuf *eb, EventType *et); + +static StgBool hasRoomForEvent(EventsBuf *eb, EventTypeNum eNum); + +static inline void postInt8(EventsBuf *eb, StgInt8 i); +static inline void postInt16(EventsBuf *eb, StgInt16 i); +static inline void postInt32(EventsBuf *eb, StgInt32 i); +static inline void postInt64(EventsBuf *eb, StgInt64 i); +static inline void postWord8(EventsBuf *eb, StgWord8 i); +static inline void postWord16(EventsBuf *eb, StgWord16 i); +static inline void postWord32(EventsBuf *eb, StgWord32 i); +static inline void postWord64(EventsBuf *eb, StgWord64 i); + +static inline void postEventTypeNum(EventsBuf *eb, EventTypeNum etNum); +static inline void postTimestamp(EventsBuf *eb, Timestamp t); + +void +initEventLogging(void) +{ + StgWord8 t, c; + + debugTrace(DEBUG_eventlog, "intiEventLog: start"); + + event_log_filename = stgMallocBytes(strlen(prog_name) + 9, + "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); + + /* 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); + stg_exit(EXIT_FAILURE); + } + + /* + * Allocate buffer(s) to store events. + * Create buffer large enough for the header begin marker, all event + * types, and header end marker to prevent checking if buffer has room + * for each of these steps, and remove the need to flush the buffer to + * disk during initialization. + * + * Use a single buffer to store the header with event types, then flush + * the buffer so all buffers are empty for writing events. + */ + eventsBuf = stgMallocBytes(n_capabilities * sizeof(EventsBuf),"initEventLogging"); + + for (c = 0; c < n_capabilities; ++c) { + // Init buffer for events. + initEventsBuf(&eventsBuf[c], EVENT_LOG_SIZE); + } + + // Write in buffer: the header begin marker. + beginHeader(&eventsBuf[0]); + + // Mark beginning of event types in the header. + beginEventTypes(&eventsBuf[0]); + for (t = 0; t < NUM_EVENT_TAGS; ++t) { + + eventTypes[t].etNum = t; + eventTypes[t].desc = EventDesc[t]; + + switch (t) { + case EVENT_CREATE_THREAD: // (cap, thread) + case EVENT_RUN_THREAD: // (cap, thread) + case EVENT_THREAD_RUNNABLE: // (cap, thread) + case EVENT_RUN_SPARK: // (cap, thread) + eventTypes[t].size = sizeof(CapabilityNum) + sizeof(ThreadID); + 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(CapabilityNum) + sizeof(ThreadID) + + sizeof(CapabilityNum); + break; + + case EVENT_STOP_THREAD: // (cap, thread, status) + eventTypes[t].size = + sizeof(CapabilityNum) + sizeof(ThreadID) + sizeof(StgWord16); + break; + + 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) + eventTypes[t].size = sizeof(CapabilityNum); + break; + } + + // Write in buffer: the start event type. + postEventType(&eventsBuf[0], &eventTypes[t]); + } + + // Mark end of event types in the header. + endEventTypes(&eventsBuf[0]); + + // Write in buffer: the header end marker. + endHeader(&eventsBuf[0]); + + // Prepare event buffer for events (data). + beginData(&eventsBuf[0]); + + // Flush eventsBuf with header. + /* + * Flush header and data begin marker to the file, thus preparing the + * file to have events written to it. + */ + printAndClearEventBuf(&eventsBuf[0]); + + debugTrace(DEBUG_eventlog, "initEventLog: finish"); +} + +void +endEventLogging(void) +{ + nat c; + + debugTrace(DEBUG_eventlog,"endEventLog: start"); + + // Flush all events remaining in the buffers. + for (c = 0; c < n_capabilities; ++c) { + printAndClearEventBuf(&eventsBuf[c]); + } + + // Mark end of events (data). + endData(&eventsBuf[0]); + + // Flush the end of data marker. + printAndClearEventBuf(&eventsBuf[0]); + + if (event_log_file != NULL) { + fclose(event_log_file); + } + + debugTrace(DEBUG_eventlog,"endEventLog: finish"); +} + +void +freeEventLogging(void) +{ + StgWord8 c; + + debugTrace(DEBUG_eventlog,"freeEventLog: start"); + + // Free events buffer. + for (c = 0; c < n_capabilities; ++c) { + if (eventsBuf[c].begin != NULL) + stgFree(eventsBuf[c].begin); + } + if (eventsBuf != NULL) { + stgFree(eventsBuf); + } + if (event_log_filename != NULL) { + stgFree(event_log_filename); + } + + debugTrace(DEBUG_eventlog,"freeEventLog: finish"); +} + +/* + * Post an event message to the capability's eventlog buffer. + * If the buffer is full, prints out the buffer and clears it. + */ +void +postEvent_(Capability *cap, EventTypeNum tag, StgThreadID thread, nat other_cap) +{ + EventsBuf *eb; + + debugTrace(DEBUG_eventlog,"postEvent: start"); + + eb = &eventsBuf[cap->no]; + + if (!hasRoomForEvent(eb, tag)) { + // Flush event buffer to make room for new event. + printAndClearEventBuf(eb); + } + + postEventTypeNum(eb, tag); + postTimestamp(eb, stat_getElapsedTime() * (1000000000LL/TICKS_PER_SECOND)); + postWord16(eb, cap->no); + + switch (tag) { + case EVENT_CREATE_THREAD: // (cap, thread) + case EVENT_RUN_THREAD: // (cap, thread) + case EVENT_THREAD_RUNNABLE: // (cap, thread) + case EVENT_RUN_SPARK: // (cap, thread) + { + postWord64(eb,thread); + 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) + { + postWord64(eb,thread); + postWord16(eb,other_cap); + break; + } + + case EVENT_STOP_THREAD: // (cap, thread, status) + { + postWord64(eb,thread); + postWord16(eb,other_cap); + break; + } + + 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); + } + + debugTrace(DEBUG_eventlog,"postEvent: finish"); +} + +static void printAndClearEventBuf (EventsBuf *eventsBuf) +{ + StgWord64 numBytes = 0, written = 0; + + if (eventsBuf->begin != NULL && eventsBuf->pos != eventsBuf->begin) + { + numBytes = eventsBuf->pos - eventsBuf->begin; + + debugTrace(DEBUG_eventlog, + "printAndEventLog: numbytes %" FMT_Word64 + " bytes to fwrite()", + numBytes); + + written = fwrite(eventsBuf->begin, 1, numBytes, event_log_file); + if (written != numBytes) { + debugBelch( + "printAndClearEventLog: fwrite() failed, written=%" FMT_Word64 + " doesn't match numBytes=%" FMT_Word64, written, numBytes); + return; + } + + debugTrace(DEBUG_eventlog, + "printAndClearEventLog: fwrite(): %" FMT_Word64 + " bytes written", written); + + resetEventsBuf(eventsBuf); + flushCount++; + } +} + +void +printAndClearEventLog(Capability *cap) +{ + debugTrace(DEBUG_eventlog,"printAndClearEventLog: start"); + + printAndClearEventBuf(&eventsBuf[cap->no]); + + debugTrace(DEBUG_eventlog,"printAndClearEventLog: finish"); +} + +/* ----------------------------------------------------------------------------- + Actual event generation below here + -------------------------------------------------------------------------- */ + +void initEventsBuf(EventsBuf* eb, StgWord64 size) +{ + eb->begin = eb->pos = malloc(size); + eb->size = size; +} + +void resetEventsBuf(EventsBuf* eb) +{ + eb->pos = eb->begin; +} + +// N.B.: Assuming buffer contains enough space for the header begin marker. +void beginHeader(EventsBuf *eb) +{ + postInt32(eb, EVENT_HEADER_BEGIN); +} + +// N.B.: Assuming buffer contains enough space for the header end marker. +void endHeader(EventsBuf *eb) +{ + postInt32(eb, EVENT_HEADER_END); +} + +void beginData(EventsBuf *eb) +{ + postInt32(eb, EVENT_DATA_BEGIN); +} + +void endData(EventsBuf *eb) +{ + postEventTypeNum(eb, EVENT_DATA_END); +} + +void beginEventTypes(EventsBuf *eb) +{ + postInt32(eb, EVENT_HET_BEGIN); +} + +void endEventTypes(EventsBuf *eb) +{ + postInt32(eb, EVENT_HET_END); +} + +StgBool hasRoomForEvent(EventsBuf *eb, EventTypeNum eNum) +{ + nat size = 0; + + size += sizeof(EventTypeNum) + sizeof(Timestamp) + eventTypes[eNum].size; + + if (eb->pos + size > eb->begin + eb->size) { + return 0; // Not enough space. + } else { + return 1; // Buf has enough space for the event. + } +} + +static void postEventType(EventsBuf *eb, EventType *et) +{ + StgWord8 d; + nat desclen; + + postInt32(eb, EVENT_ET_BEGIN); + postEventTypeNum(eb, et->etNum); + postWord16(eb, (StgWord16)et->size); + desclen = strlen(et->desc); + postWord32(eb, desclen); + for (d = 0; d < desclen; ++d) { + postInt8(eb, (StgInt8)et->desc[d]); + } + postWord32(eb, 0); // no extensions yet + postInt32(eb, EVENT_ET_END); +} + +static inline void postEventTypeNum(EventsBuf *eb, EventTypeNum etNum) +{ postWord16(eb, etNum); } + +static inline void postEventTypeID(EventsBuf *eb, StgWord16 etID) +{ postWord16(eb, etID); } + +static inline void postTimestamp(EventsBuf *eb, Timestamp t) +{ postWord64(eb,t); } + +static inline void postInt8(EventsBuf *eb, StgInt8 i) +{ postWord8(eb, (StgWord8)i); } + +static inline void postInt16(EventsBuf *eb, StgInt16 i) +{ postWord16(eb, (StgWord16)i); } + +static inline void postInt32(EventsBuf *eb, StgInt32 i) +{ postWord32(eb, (StgWord32)i); } + +static inline void postInt64(EventsBuf *eb, StgInt64 i) +{ postWord64(eb, (StgWord64)i); } + +static inline void postWord8(EventsBuf *eb, StgWord8 i) +{ + *(eb->pos++) = i; +} + +static inline void postWord16(EventsBuf *eb, StgWord16 i) +{ + postWord8(eb, (StgWord8)(i >> 8)); + postWord8(eb, (StgWord8)i); +} + +static inline void postWord32(EventsBuf *eb, StgWord32 i) +{ + postWord16(eb, (StgWord16)(i >> 16)); + postWord16(eb, (StgWord16)i); +} + +static inline void postWord64(EventsBuf *eb, StgWord64 i) +{ + postWord32(eb, (StgWord32)(i >> 32)); + postWord32(eb, (StgWord32)i); +} + +#endif /* EVENTLOG */ |