#include "Trace.h"
#include "Capability.h"
-#include "Trace.h"
#include "RtsUtils.h"
#include "Stats.h"
#include "EventLog.h"
-#include <string.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 *capEventBuf; // one EventsBuf for each Capability
[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_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);
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 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); }
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);
}
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.
- beginHeader(&eventBuf);
+ postInt32(&eventBuf, EVENT_HEADER_BEGIN);
// Mark beginning of event types in the header.
- beginEventTypes(&eventBuf);
+ postInt32(&eventBuf, EVENT_HET_BEGIN);
for (t = 0; t < NUM_EVENT_TAGS; ++t) {
eventTypes[t].etNum = t;
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_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_LOG_CAP_MSG: // (cap,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 */
}
}
// Mark end of event types in the header.
- endEventTypes(&eventBuf);
+ postInt32(&eventBuf, EVENT_HET_END);
// Write in buffer: the header end marker.
- endHeader(&eventBuf);
+ postInt32(&eventBuf, EVENT_HEADER_END);
// Prepare event buffer for events (data).
- beginData(&eventBuf);
+ 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
* file to have events written to it.
*/
printAndClearEventBuf(&eventBuf);
+
+ for (c = 0; c < n_caps; ++c) {
+ postBlockMarker(&capEventBuf[c]);
+ }
+
+#ifdef THREADED_RTS
+ initMutex(&eventBufMutex);
+#endif
}
void
printAndClearEventBuf(&capEventBuf[c]);
}
printAndClearEventBuf(&eventBuf);
+ resetEventsBuf(&eventBuf); // we don't want the block marker
// Mark end of events (data).
- endData(&eventBuf);
+ postEventTypeNum(&eventBuf, EVENT_DATA_END);
// Flush the end of data marker.
printAndClearEventBuf(&eventBuf);
}
}
+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.
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)
}
}
+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 postMsg(char *msg, va_list ap)
+void postLogMsg(EventsBuf *eb, EventTypeNum type, char *msg, va_list ap)
{
- EventsBuf *eb;
char buf[BUF];
nat size;
size = BUF;
}
- ACQUIRE_LOCK(&eventBufMutex);
- eb = &eventBuf;
-
if (!hasRoomForVariableEvent(eb, size)) {
// Flush event buffer to make room for new event.
printAndClearEventBuf(eb);
}
- postEventTypeNum(eb, EVENT_LOG_MSG);
- postTimestamp(eb, stat_getElapsedTime() * (1000000000LL/TICKS_PER_SECOND));
+ 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)
{
- EventsBuf *eb;
- char buf[BUF];
- nat size;
+ postLogMsg(&capEventBuf[cap->no], EVENT_LOG_MSG, msg, ap);
+}
- size = vsnprintf(buf,BUF,msg,ap);
- if (size > BUF) {
- buf[BUF-1] = '\0';
- size = BUF;
+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)
+
+ 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;
}
+}
- eb = &capEventBuf[cap->no];
- if (!hasRoomForVariableEvent(eb, size)) {
- // Flush event buffer to make room for new event.
+void postBlockMarker (EventsBuf *eb)
+{
+ if (!hasRoomForEvent(eb, EVENT_BLOCK_MARKER)) {
printAndClearEventBuf(eb);
}
- postEventTypeNum(eb, EVENT_LOG_MSG);
- postTimestamp(eb, stat_getElapsedTime() * (1000000000LL/TICKS_PER_SECOND));
- postPayloadSize(eb, size + sizeof(EventCapNo));
- postCapNo(eb, cap->no);
- postBuf(eb,(StgWord8*)buf,size);
+ 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);
}
-static void printAndClearEventBuf (EventsBuf *ebuf)
+void printAndClearEventBuf (EventsBuf *ebuf)
{
StgWord64 numBytes = 0, written = 0;
+ closeBlockMarker(ebuf);
+
if (ebuf->begin != NULL && ebuf->pos != ebuf->begin)
{
numBytes = ebuf->pos - ebuf->begin;
resetEventsBuf(ebuf);
flushCount++;
- }
-}
-void
-printAndClearEventLog(Capability *cap)
-{
- printAndClearEventBuf(&capEventBuf[cap->no]);
+ postBlockMarker(ebuf);
+ }
}
-/* -----------------------------------------------------------------------------
- Actual event generation below here
- -------------------------------------------------------------------------- */
-
-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;
-}
-
-// 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);
+ eb->marker = NULL;
}
StgBool hasRoomForEvent(EventsBuf *eb, EventTypeNum eNum)
}
}
-static void postEventType(EventsBuf *eb, EventType *et)
+void postEventType(EventsBuf *eb, EventType *et)
{
StgWord8 d;
nat desclen;
projects / ghc-hetmet.git / blobdiff