*
* ---------------------------------------------------------------------------*/
-#ifdef EVENTLOG
-
+#include "PosixSource.h"
#include "Rts.h"
-#include "EventLog.h"
-#include "Capability.h"
+
+#ifdef TRACING
+
#include "Trace.h"
+#include "Capability.h"
#include "RtsUtils.h"
#include "Stats.h"
-#include <string.h>
+#include "EventLog.h"
+
+#include <string.h>
#include <stdio.h>
+#ifdef HAVE_SYS_TYPES_H
+#include <sys/types.h>
+#endif
+#ifdef HAVE_UNISTD_H
+#include <unistd.h>
+#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;
typedef struct _EventsBuf {
StgInt8 *begin;
StgInt8 *pos;
+ StgInt8 *marker;
StgWord64 size;
+ EventCapNo capno; // which capability this buffer belongs to, or -1
} EventsBuf;
-EventsBuf *eventsBuf;
+EventsBuf *capEventBuf; // one EventsBuf for each Capability
+
+EventsBuf eventBuf; // an EventsBuf not associated with any Capability
+#ifdef THREADED_RTS
+Mutex eventBufMutex; // protected by this mutex
+#endif
char *EventDesc[] = {
- "Create thread",
- "Run thread",
- "Stop thread",
- "Thread runnable",
- "Migrate thread",
- "Run spark",
- "Steal spark",
- "Shutdown",
- "Wakeup thread",
- "Starting GC",
- "Finished GC",
- "Request sequential GC",
- "Request parallel GC",
- "Create spark",
- "Spark to thread", /* DEPRECATED! */
- "Create spark thread"
+ [EVENT_CREATE_THREAD] = "Create thread",
+ [EVENT_RUN_THREAD] = "Run thread",
+ [EVENT_STOP_THREAD] = "Stop thread",
+ [EVENT_THREAD_RUNNABLE] = "Thread runnable",
+ [EVENT_MIGRATE_THREAD] = "Migrate thread",
+ [EVENT_RUN_SPARK] = "Run spark",
+ [EVENT_STEAL_SPARK] = "Steal spark",
+ [EVENT_SHUTDOWN] = "Shutdown",
+ [EVENT_THREAD_WAKEUP] = "Wakeup thread",
+ [EVENT_GC_START] = "Starting GC",
+ [EVENT_GC_END] = "Finished GC",
+ [EVENT_REQUEST_SEQ_GC] = "Request sequential GC",
+ [EVENT_REQUEST_PAR_GC] = "Request parallel GC",
+ [EVENT_CREATE_SPARK_THREAD] = "Create spark thread",
+ [EVENT_LOG_MSG] = "Log message",
+ [EVENT_USER_MSG] = "User message",
+ [EVENT_STARTUP] = "Startup",
+ [EVENT_GC_IDLE] = "GC idle",
+ [EVENT_GC_WORK] = "GC working",
+ [EVENT_GC_DONE] = "GC done",
+ [EVENT_BLOCK_MARKER] = "Block marker"
};
// Event type.
EventType eventTypes[NUM_EVENT_TAGS];
-static void printAndClearEventBuf (EventsBuf *eventsBuf);
-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 beginHeader(EventsBuf *eb);
-static void endHeader(EventsBuf *eb);
-
-static void beginData(EventsBuf *eb);
-static void endData(EventsBuf *eb);
+static void postEventType(EventsBuf *eb, EventType *et);
-static void beginEventTypes(EventsBuf *eb);
-static void endEventTypes(EventsBuf *eb);
+static void postLogMsg(EventsBuf *eb, EventTypeNum type, char *msg, va_list ap);
-static void postEventType(EventsBuf *eb, EventType *et);
+static void postBlockMarker(EventsBuf *eb);
+static void closeBlockMarker(EventsBuf *ebuf);
static StgBool hasRoomForEvent(EventsBuf *eb, EventTypeNum eNum);
+static StgBool hasRoomForVariableEvent(EventsBuf *eb, nat payload_bytes);
static inline void postWord8(EventsBuf *eb, StgWord8 i)
{
postWord32(eb, (StgWord32)i);
}
+static inline void postBuf(EventsBuf *eb, StgWord8 *buf, nat size)
+{
+ memcpy(eb->pos, buf, size);
+ eb->pos += size;
+}
+
+static inline StgWord64 time_ns(void)
+{ return stat_getElapsedTime() * (1000000000LL/TICKS_PER_SECOND); }
+
static inline void postEventTypeNum(EventsBuf *eb, EventTypeNum etNum)
{ postWord16(eb, etNum); }
-static inline void postTimestamp(EventsBuf *eb, EventTimestamp t)
-{ postWord64(eb,t); }
+static inline void postTimestamp(EventsBuf *eb)
+{ postWord64(eb, time_ns()); }
static inline void postThreadID(EventsBuf *eb, EventThreadID id)
{ postWord32(eb,id); }
static inline void postCapNo(EventsBuf *eb, EventCapNo no)
{ postWord16(eb,no); }
+static inline void postPayloadSize(EventsBuf *eb, EventPayloadSize size)
+{ postWord16(eb,size); }
+
+static inline void postEventHeader(EventsBuf *eb, EventTypeNum type)
+{
+ postEventTypeNum(eb, type);
+ postTimestamp(eb);
+}
+
static inline void postInt8(EventsBuf *eb, StgInt8 i)
{ postWord8(eb, (StgWord8)i); }
initEventLogging(void)
{
StgWord8 t, c;
+ nat n_caps;
- debugTrace(DEBUG_eventlog, "intiEventLog: start");
-
- event_log_filename = stgMallocBytes(strlen(prog_name) + 9,
+ 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);
}
* 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) {
+#ifdef THREADED_RTS
+ // XXX n_capabilities hasn't been initislised yet
+ n_caps = RtsFlags.ParFlags.nNodes;
+#else
+ n_caps = 1;
+#endif
+ capEventBuf = stgMallocBytes(n_caps * sizeof(EventsBuf),"initEventLogging");
+
+ for (c = 0; c < n_caps; ++c) {
// Init buffer for events.
- initEventsBuf(&eventsBuf[c], EVENT_LOG_SIZE);
+ initEventsBuf(&capEventBuf[c], EVENT_LOG_SIZE, c);
}
+ initEventsBuf(&eventBuf, EVENT_LOG_SIZE, (EventCapNo)(-1));
// Write in buffer: the header begin marker.
- beginHeader(&eventsBuf[0]);
+ postInt32(&eventBuf, EVENT_HEADER_BEGIN);
// Mark beginning of event types in the header.
- beginEventTypes(&eventsBuf[0]);
+ postInt32(&eventBuf, EVENT_HET_BEGIN);
for (t = 0; t < NUM_EVENT_TAGS; ++t) {
eventTypes[t].etNum = t;
case EVENT_CREATE_THREAD: // (cap, thread)
case EVENT_RUN_THREAD: // (cap, thread)
case EVENT_THREAD_RUNNABLE: // (cap, thread)
- case EVENT_CREATE_SPARK: // (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_STARTUP: // (cap count)
+ eventTypes[t].size = sizeof(EventCapNo);
break;
case EVENT_SHUTDOWN: // (cap)
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_USER_MSG: // (msg)
+ eventTypes[t].size = 0xffff;
+ break;
+
+ case EVENT_BLOCK_MARKER:
+ eventTypes[t].size = sizeof(StgWord32) + sizeof(EventTimestamp) +
+ sizeof(EventCapNo);
+ break;
+
+ default:
+ continue; /* ignore deprecated events */
}
// Write in buffer: the start event type.
- postEventType(&eventsBuf[0], &eventTypes[t]);
+ postEventType(&eventBuf, &eventTypes[t]);
}
// Mark end of event types in the header.
- endEventTypes(&eventsBuf[0]);
+ postInt32(&eventBuf, EVENT_HET_END);
// Write in buffer: the header end marker.
- endHeader(&eventsBuf[0]);
+ postInt32(&eventBuf, EVENT_HEADER_END);
// Prepare event buffer for events (data).
- beginData(&eventsBuf[0]);
+ postInt32(&eventBuf, EVENT_DATA_BEGIN);
- // Flush eventsBuf with header.
+ // 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
* file to have events written to it.
*/
- printAndClearEventBuf(&eventsBuf[0]);
+ printAndClearEventBuf(&eventBuf);
+
+ for (c = 0; c < n_caps; ++c) {
+ postBlockMarker(&capEventBuf[c]);
+ }
- debugTrace(DEBUG_eventlog, "initEventLog: finish");
+#ifdef THREADED_RTS
+ initMutex(&eventBufMutex);
+#endif
}
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]);
+ printAndClearEventBuf(&capEventBuf[c]);
}
+ printAndClearEventBuf(&eventBuf);
+ resetEventsBuf(&eventBuf); // we don't want the block marker
// Mark end of events (data).
- endData(&eventsBuf[0]);
+ postEventTypeNum(&eventBuf, EVENT_DATA_END);
// Flush the end of data marker.
- printAndClearEventBuf(&eventsBuf[0]);
+ printAndClearEventBuf(&eventBuf);
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 (capEventBuf[c].begin != NULL)
+ stgFree(capEventBuf[c].begin);
}
- if (eventsBuf != NULL) {
- stgFree(eventsBuf);
+ if (capEventBuf != NULL) {
+ stgFree(capEventBuf);
}
if (event_log_filename != NULL) {
stgFree(event_log_filename);
}
-
- debugTrace(DEBUG_eventlog,"freeEventLog: finish");
}
+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.
*/
void
-postEvent_(Capability *cap, EventTypeNum tag, StgThreadID thread, StgWord64 other)
+postSchedEvent (Capability *cap,
+ EventTypeNum tag,
+ StgThreadID thread,
+ StgWord64 other)
{
EventsBuf *eb;
- debugTrace(DEBUG_eventlog,"postEvent: start");
-
- eb = &eventsBuf[cap->no];
+ eb = &capEventBuf[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));
- postCapNo(eb, cap->no);
+ postEventHeader(eb, tag);
switch (tag) {
case EVENT_CREATE_THREAD: // (cap, thread)
case EVENT_RUN_THREAD: // (cap, thread)
case EVENT_THREAD_RUNNABLE: // (cap, thread)
- case EVENT_CREATE_SPARK: // (cap, thread)
case EVENT_RUN_SPARK: // (cap, thread)
{
postThreadID(eb,thread);
postThreadID(eb,thread);
postCapNo(eb,other /* new_cap | victim_cap | other_cap */);
break;
- }
+ }
case EVENT_STOP_THREAD: // (cap, thread, status)
{
default:
barf("postEvent: unknown event tag %d", tag);
}
-
- debugTrace(DEBUG_eventlog,"postEvent: finish");
}
-static void printAndClearEventBuf (EventsBuf *eventsBuf)
+void
+postEvent (Capability *cap, EventTypeNum tag)
{
- StgWord64 numBytes = 0, written = 0;
+ EventsBuf *eb;
- 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++;
+ eb = &capEventBuf[cap->no];
+
+ if (!hasRoomForEvent(eb, tag)) {
+ // Flush event buffer to make room for new event.
+ printAndClearEventBuf(eb);
}
-}
-void
-printAndClearEventLog(Capability *cap)
-{
- debugTrace(DEBUG_eventlog,"printAndClearEventLog: start");
-
- printAndClearEventBuf(&eventsBuf[cap->no]);
-
- debugTrace(DEBUG_eventlog,"printAndClearEventLog: finish");
+ postEventHeader(eb, tag);
}
-/* -----------------------------------------------------------------------------
- Actual event generation below here
- -------------------------------------------------------------------------- */
+#define BUF 512
-void initEventsBuf(EventsBuf* eb, StgWord64 size)
+void postLogMsg(EventsBuf *eb, EventTypeNum type, char *msg, va_list ap)
{
- eb->begin = eb->pos = malloc(size);
- eb->size = size;
+ char buf[BUF];
+ nat size;
+
+ size = vsnprintf(buf,BUF,msg,ap);
+ if (size > BUF) {
+ buf[BUF-1] = '\0';
+ size = BUF;
+ }
+
+ if (!hasRoomForVariableEvent(eb, size)) {
+ // Flush event buffer to make room for new event.
+ printAndClearEventBuf(eb);
+ }
+
+ postEventHeader(eb, type);
+ postPayloadSize(eb, size);
+ postBuf(eb,(StgWord8*)buf,size);
}
-void resetEventsBuf(EventsBuf* eb)
+void postMsg(char *msg, va_list ap)
{
- eb->pos = eb->begin;
+ ACQUIRE_LOCK(&eventBufMutex);
+ postLogMsg(&eventBuf, EVENT_LOG_MSG, msg, ap);
+ RELEASE_LOCK(&eventBufMutex);
}
-// N.B.: Assuming buffer contains enough space for the header begin marker.
-void beginHeader(EventsBuf *eb)
+void postCapMsg(Capability *cap, char *msg, va_list ap)
{
- postInt32(eb, EVENT_HEADER_BEGIN);
+ postLogMsg(&capEventBuf[cap->no], EVENT_LOG_MSG, msg, ap);
}
-// N.B.: Assuming buffer contains enough space for the header end marker.
-void endHeader(EventsBuf *eb)
+void postUserMsg(Capability *cap, char *msg, va_list ap)
{
- postInt32(eb, EVENT_HEADER_END);
+ 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)
+
+ 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;
+ }
}
-void beginData(EventsBuf *eb)
+
+void postBlockMarker (EventsBuf *eb)
{
- postInt32(eb, EVENT_DATA_BEGIN);
+ if (!hasRoomForEvent(eb, EVENT_BLOCK_MARKER)) {
+ printAndClearEventBuf(eb);
+ }
+
+ closeBlockMarker(eb);
+
+ eb->marker = eb->pos;
+ postEventHeader(eb, EVENT_BLOCK_MARKER);
+ postWord32(eb,0); // these get filled in later by closeBlockMarker();
+ postWord64(eb,0);
+ postCapNo(eb, eb->capno);
}
-void endData(EventsBuf *eb)
+void printAndClearEventBuf (EventsBuf *ebuf)
{
- postEventTypeNum(eb, EVENT_DATA_END);
+ StgWord64 numBytes = 0, written = 0;
+
+ closeBlockMarker(ebuf);
+
+ if (ebuf->begin != NULL && ebuf->pos != ebuf->begin)
+ {
+ numBytes = ebuf->pos - ebuf->begin;
+
+ written = fwrite(ebuf->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;
+ }
+
+ resetEventsBuf(ebuf);
+ flushCount++;
+
+ postBlockMarker(ebuf);
+ }
}
-void beginEventTypes(EventsBuf *eb)
+void initEventsBuf(EventsBuf* eb, StgWord64 size, EventCapNo capno)
{
- postInt32(eb, EVENT_HET_BEGIN);
+ eb->begin = eb->pos = stgMallocBytes(size, "initEventsBuf");
+ eb->size = size;
+ eb->marker = NULL;
+ eb->capno = capno;
}
-void endEventTypes(EventsBuf *eb)
+void resetEventsBuf(EventsBuf* eb)
{
- postInt32(eb, EVENT_HET_END);
+ eb->pos = eb->begin;
+ eb->marker = NULL;
}
StgBool hasRoomForEvent(EventsBuf *eb, EventTypeNum eNum)
{
- nat size = 0;
+ nat size;
- size += sizeof(EventTypeNum) + sizeof(EventTimestamp) + eventTypes[eNum].size;
+ size = sizeof(EventTypeNum) + sizeof(EventTimestamp) + eventTypes[eNum].size;
if (eb->pos + size > eb->begin + eb->size) {
return 0; // Not enough space.
}
}
-static void postEventType(EventsBuf *eb, EventType *et)
+StgBool hasRoomForVariableEvent(EventsBuf *eb, nat payload_bytes)
+{
+ nat size;
+
+ size = sizeof(EventTypeNum) + sizeof(EventTimestamp) +
+ sizeof(EventPayloadSize) + payload_bytes;
+
+ if (eb->pos + size > eb->begin + eb->size) {
+ return 0; // Not enough space.
+ } else {
+ return 1; // Buf has enough space for the event.
+ }
+}
+
+void postEventType(EventsBuf *eb, EventType *et)
{
StgWord8 d;
nat desclen;
postInt32(eb, EVENT_ET_END);
}
-#endif /* EVENTLOG */
+#endif /* TRACING */
projects / ghc-hetmet.git / blobdiff