diff options
| -rw-r--r-- | includes/rts/EventLogFormat.h | 5 | ||||
| -rw-r--r-- | rts/Trace.c | 6 | ||||
| -rw-r--r-- | rts/Trace.h | 10 | ||||
| -rw-r--r-- | rts/eventlog/EventLog.c | 52 | ||||
| -rw-r--r-- | rts/eventlog/EventLog.h | 2 |
5 files changed, 73 insertions, 2 deletions
diff --git a/includes/rts/EventLogFormat.h b/includes/rts/EventLogFormat.h index 925aec4ed1..7773bae6a9 100644 --- a/includes/rts/EventLogFormat.h +++ b/includes/rts/EventLogFormat.h @@ -141,9 +141,10 @@ #define EVENT_SPARK_FIZZLE 40 /* () */ #define EVENT_SPARK_GC 41 /* () */ #define EVENT_INTERN_STRING 42 /* (string, id) {not used by ghc} */ +#define EVENT_WALL_CLOCK_TIME 43 /* (capset, unix_epoch_seconds, nanoseconds) */ -/* Range 43 - 59 is available for new GHC and common events */ +/* Range 44 - 59 is available for new GHC and common events */ /* Range 60 - 80 is used by eden for parallel tracing * see http://www.mathematik.uni-marburg.de/~eden/ @@ -156,7 +157,7 @@ * ranges higher than this are reserved but not currently emitted by ghc. * This must match the size of the EventDesc[] array in EventLog.c */ -#define NUM_GHC_EVENT_TAGS 42 +#define NUM_GHC_EVENT_TAGS 44 #if 0 /* DEPRECATED EVENTS: */ /* we don't actually need to record the thread, it's implicit */ diff --git a/rts/Trace.c b/rts/Trace.c index 7aa0f7b444..9d29f2a8fa 100644 --- a/rts/Trace.c +++ b/rts/Trace.c @@ -328,6 +328,12 @@ void traceCapsetEvent_ (EventTypeNum tag, } } +void traceWallClockTime_(void) { + if (eventlog_enabled) { + postWallClockTime(CAPSET_CLOCKDOMAIN_DEFAULT); + } +} + void traceOSProcessInfo_(void) { if (eventlog_enabled) { postCapsetEvent(EVENT_OSPROCESS_PID, diff --git a/rts/Trace.h b/rts/Trace.h index 7143a5b221..f7894ca994 100644 --- a/rts/Trace.h +++ b/rts/Trace.h @@ -37,6 +37,7 @@ enum CapsetType { CapsetTypeCustom = CAPSET_TYPE_CUSTOM, CapsetTypeOsProcess = CAPSET_TYPE_OSPROCESS, CapsetTypeClockdomain = CAPSET_TYPE_CLOCKDOMAIN }; #define CAPSET_OSPROCESS_DEFAULT 0 +#define CAPSET_CLOCKDOMAIN_DEFAULT 1 // ----------------------------------------------------------------------------- // Message classes @@ -199,6 +200,8 @@ void traceCapsetEvent_ (EventTypeNum tag, CapsetID capset, StgWord info); +void traceWallClockTime_(void); + void traceOSProcessInfo_ (void); void traceSparkCounters_ (Capability *cap, @@ -219,6 +222,7 @@ void traceSparkCounters_ (Capability *cap, #define traceThreadStatus(class, tso) /* nothing */ INLINE_HEADER void traceEventStartup_ (int n_caps STG_UNUSED) {}; #define traceCapsetEvent_(tag, capset, info) /* nothing */ +#define traceWallClockTime_() /* nothing */ #define traceOSProcessInfo_() /* nothing */ #define traceSparkCounters_(cap, counters, remaining) /* nothing */ @@ -492,6 +496,12 @@ INLINE_HEADER void traceCapsetRemoveCap(CapsetID capset STG_UNUSED, dtraceCapsetRemoveCap(capset, capno); } +INLINE_HEADER void traceWallClockTime(void) +{ + traceWallClockTime_(); + /* Note: no DTrace equivalent because it is available to DTrace directly */ +} + INLINE_HEADER void traceOSProcessInfo(void) { traceOSProcessInfo_(); diff --git a/rts/eventlog/EventLog.c b/rts/eventlog/EventLog.c index d5bfd19130..09e12a2fa3 100644 --- a/rts/eventlog/EventLog.c +++ b/rts/eventlog/EventLog.c @@ -83,6 +83,7 @@ char *EventDesc[] = { [EVENT_PROGRAM_ENV] = "Program environment variables", [EVENT_OSPROCESS_PID] = "Process ID", [EVENT_OSPROCESS_PPID] = "Parent process ID", + [EVENT_WALL_CLOCK_TIME] = "Wall clock time", [EVENT_SPARK_COUNTERS] = "Spark counters", [EVENT_SPARK_CREATE] = "Spark create", [EVENT_SPARK_DUD] = "Spark dud", @@ -299,6 +300,11 @@ initEventLogging(void) sizeof(EventCapsetID) + sizeof(StgWord32); break; + case EVENT_WALL_CLOCK_TIME: // (capset, unix_epoch_seconds, nanoseconds) + eventTypes[t].size = + sizeof(EventCapsetID) + sizeof(StgWord64) + sizeof(StgWord32); + break; + case EVENT_SPARK_STEAL: // (cap, victim_cap) eventTypes[t].size = sizeof(EventCapNo); @@ -668,6 +674,52 @@ void postCapsetVecEvent (EventTypeNum tag, RELEASE_LOCK(&eventBufMutex); } +void postWallClockTime (EventCapsetID capset) +{ + StgWord64 ts; + StgWord64 sec; + StgWord32 nsec; + + ACQUIRE_LOCK(&eventBufMutex); + + /* The EVENT_WALL_CLOCK_TIME event is intended to allow programs + reading the eventlog to match up the event timestamps with wall + clock time. The normal event timestamps measure time since the + start of the program. To align eventlogs from concurrent + processes we need to be able to match up the timestamps. One way + to do this is if we know how the timestamps and wall clock time + match up (and of course if both processes have sufficiently + synchronised clocks). + + So we want to make sure that the timestamp that we generate for + this event matches up very closely with the wall clock time. + Unfortunately we currently have to use two different APIs to get + the elapsed time vs the wall clock time. So to minimise the + difference we just call them very close together. + */ + + getUnixEpochTime(&sec, &nsec); /* Get the wall clock time */ + ts = time_ns(); /* Get the eventlog timestamp */ + + if (!hasRoomForEvent(&eventBuf, EVENT_WALL_CLOCK_TIME)) { + // Flush event buffer to make room for new event. + printAndClearEventBuf(&eventBuf); + } + + /* Normally we'd call postEventHeader(), but that generates its own + timestamp, so we go one level lower so we can write out the + timestamp we already generated above. */ + postEventTypeNum(&eventBuf, EVENT_WALL_CLOCK_TIME); + postWord64(&eventBuf, ts); + + /* EVENT_WALL_CLOCK_TIME (capset, unix_epoch_seconds, nanoseconds) */ + postCapsetID(&eventBuf, capset); + postWord64(&eventBuf, sec); + postWord32(&eventBuf, nsec); + + RELEASE_LOCK(&eventBufMutex); +} + void postEvent (Capability *cap, EventTypeNum tag) { diff --git a/rts/eventlog/EventLog.h b/rts/eventlog/EventLog.h index e09da07e6b..d7368c30bf 100644 --- a/rts/eventlog/EventLog.h +++ b/rts/eventlog/EventLog.h @@ -69,6 +69,8 @@ void postCapsetVecEvent (EventTypeNum tag, int argc, char *msg[]); +void postWallClockTime (EventCapsetID capset); + /* * Post a `par` spark event */ |