Commit e459b0d1 authored by Simon Marlow's avatar Simon Marlow

Event tracing: put the capability in the block marker, omit it from the events

This makes events smaller and tracing quicker, and speeds up reading
and sorting the trace file.

HEADS UP: this changes the format of event log files.  Corresponding
changes to the ghc-events package are required (and will be pushed
soon).  Normally we would make backwards-compatible changes, but this
changes the format of every event (to remove the capability) so I'm
breaking the rules this time.  This will be the only time we can do
this, since the format becomes public in 6.12.1.
parent d7161575
......@@ -99,26 +99,25 @@
/*
* Types of event
*/
#define EVENT_CREATE_THREAD 0 /* (cap, thread) */
#define EVENT_RUN_THREAD 1 /* (cap, thread) */
#define EVENT_STOP_THREAD 2 /* (cap, thread, status) */
#define EVENT_THREAD_RUNNABLE 3 /* (cap, thread) */
#define EVENT_MIGRATE_THREAD 4 /* (cap, thread, new_cap) */
#define EVENT_RUN_SPARK 5 /* (cap, thread) */
#define EVENT_STEAL_SPARK 6 /* (cap, thread, victim_cap) */
#define EVENT_SHUTDOWN 7 /* (cap) */
#define EVENT_THREAD_WAKEUP 8 /* (cap, thread, other_cap) */
#define EVENT_GC_START 9 /* (cap) */
#define EVENT_GC_END 10 /* (cap) */
#define EVENT_REQUEST_SEQ_GC 11 /* (cap) */
#define EVENT_REQUEST_PAR_GC 12 /* (cap) */
#define EVENT_CREATE_SPARK_THREAD 15 /* (cap, thread, spark_thread) */
#define EVENT_LOG_CAP_MSG 16 /* (cap, message ...) */
#define EVENT_LOG_MSG 17 /* (message ...) */
#define EVENT_STARTUP 18 /* (num_capabilities) */
#define EVENT_BLOCK_MARKER 19 /* (size, end_time) */
#define EVENT_CREATE_THREAD 0 /* (thread) */
#define EVENT_RUN_THREAD 1 /* (thread) */
#define EVENT_STOP_THREAD 2 /* (thread, status) */
#define EVENT_THREAD_RUNNABLE 3 /* (thread) */
#define EVENT_MIGRATE_THREAD 4 /* (thread, new_cap) */
#define EVENT_RUN_SPARK 5 /* (thread) */
#define EVENT_STEAL_SPARK 6 /* (thread, victim_cap) */
#define EVENT_SHUTDOWN 7 /* () */
#define EVENT_THREAD_WAKEUP 8 /* (thread, other_cap) */
#define EVENT_GC_START 9 /* () */
#define EVENT_GC_END 10 /* () */
#define EVENT_REQUEST_SEQ_GC 11 /* () */
#define EVENT_REQUEST_PAR_GC 12 /* () */
#define EVENT_CREATE_SPARK_THREAD 15 /* (thread, spark_thread) */
#define EVENT_LOG_MSG 16 /* (message ...) */
#define EVENT_STARTUP 17 /* (num_capabilities) */
#define EVENT_BLOCK_MARKER 18 /* (size, end_time, capability) */
#define NUM_EVENT_TAGS 20
#define NUM_EVENT_TAGS 19
#if 0 /* DEPRECATED EVENTS: */
#define EVENT_CREATE_SPARK 13 /* (cap, thread) */
......
......@@ -36,6 +36,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,7 +61,6 @@ 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_STARTUP] = "Startup",
[EVENT_BLOCK_MARKER] = "Block marker"
......@@ -76,12 +76,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, char *msg, va_list ap);
static void postBlockMarker(EventsBuf *eb);
static void closeBlockMarker(EventsBuf *ebuf);
......@@ -195,9 +197,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 +217,19 @@ 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);
break;
case EVENT_SHUTDOWN: // (cap)
......@@ -235,20 +237,17 @@ 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_STARTUP:
eventTypes[t].size = 0;
break;
case EVENT_LOG_MSG: // (msg)
case EVENT_LOG_CAP_MSG: // (cap,msg)
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 +267,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
......@@ -290,6 +293,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);
......@@ -340,7 +344,6 @@ postSchedEvent (Capability *cap,
}
postEventHeader(eb, tag);
postCapNo(eb, cap->no);
switch (tag) {
case EVENT_CREATE_THREAD: // (cap, thread)
......@@ -390,9 +393,8 @@ postSchedEvent (Capability *cap,
#define BUF 512
void postMsg(char *msg, va_list ap)
void postLogMsg(EventsBuf *eb, char *msg, va_list ap)
{
EventsBuf *eb;
char buf[BUF];
nat size;
......@@ -402,9 +404,6 @@ void postMsg(char *msg, va_list ap)
size = BUF;
}
ACQUIRE_LOCK(&eventBufMutex);
eb = &eventBuf;
if (!hasRoomForVariableEvent(eb, size)) {
// Flush event buffer to make room for new event.
printAndClearEventBuf(eb);
......@@ -413,42 +412,34 @@ void postMsg(char *msg, va_list ap)
postEventHeader(eb, EVENT_LOG_MSG);
postPayloadSize(eb, size);
postBuf(eb,(StgWord8*)buf,size);
}
void postMsg(char *msg, va_list ap)
{
ACQUIRE_LOCK(&eventBufMutex);
postLogMsg(&eventBuf, msg, ap);
RELEASE_LOCK(&eventBufMutex);
}
void postCapMsg(Capability *cap, char *msg, va_list ap)
{
EventsBuf *eb;
char buf[BUF];
nat size;
size = vsnprintf(buf,BUF,msg,ap);
if (size > BUF) {
buf[BUF-1] = '\0';
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);
postBuf(eb,(StgWord8*)buf,size);
postLogMsg(&capEventBuf[cap->no], 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 +457,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 +485,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)
......
Markdown is supported
0% or .
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment