Commit a609027d authored by Duncan Coutts's avatar Duncan Coutts

Add a new traceMarker# primop for use in profiling output

In time-based profiling visualisations (e.g. heap profiles and ThreadScope)
it would be useful to be able to mark particular points in the execution and
have those points in time marked in the visualisation.

The traceMarker# primop currently emits an event into the eventlog. In
principle it could be extended to do something in the heap profiling too.
parent 8af2d940
......@@ -2203,6 +2203,17 @@ primop TraceEventOp "traceEvent#" GenPrimOp
has_side_effects = True
out_of_line = True
primop TraceMarkerOp "traceMarker#" GenPrimOp
Addr# -> State# s -> State# s
{ Emits a marker event via the RTS tracing framework. The contents
of the event is the zero-terminated byte string passed as the first
argument. The event will be emitted either to the .eventlog file,
or to stderr, depending on the runtime RTS flags. }
with
has_side_effects = True
out_of_line = True
------------------------------------------------------------------------
--- ---
------------------------------------------------------------------------
......
......@@ -161,8 +161,8 @@
#define EVENT_TASK_CREATE 55 /* (taskID, cap, tid) */
#define EVENT_TASK_MIGRATE 56 /* (taskID, cap, new_cap) */
#define EVENT_TASK_DELETE 57 /* (taskID) */
/* Range 58 - 59 is available for new GHC and common events. */
#define EVENT_USER_MARKER 58 /* (marker_name) */
/* Range 59 - 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/
......@@ -177,7 +177,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 58
#define NUM_GHC_EVENT_TAGS 59
#if 0 /* DEPRECATED EVENTS: */
/* we don't actually need to record the thread, it's implicit */
......
......@@ -431,6 +431,7 @@ RTS_FUN_DECL(stg_noDuplicatezh);
RTS_FUN_DECL(stg_traceCcszh);
RTS_FUN_DECL(stg_traceEventzh);
RTS_FUN_DECL(stg_traceMarkerzh);
/* Other misc stuff */
// See wiki:Commentary/Compiler/Backends/PprC#Prototypes
......
......@@ -1309,6 +1309,7 @@ typedef struct _RtsSymbolVal {
SymI_HasProto(n_capabilities) \
SymI_HasProto(stg_traceCcszh) \
SymI_HasProto(stg_traceEventzh) \
SymI_HasProto(stg_traceMarkerzh) \
SymI_HasProto(getMonotonicNSec) \
SymI_HasProto(lockFile) \
SymI_HasProto(unlockFile) \
......
......@@ -2034,3 +2034,28 @@ stg_traceEventzh ( W_ msg )
return ();
}
// Same code as stg_traceEventzh above but a different kind of event
// Before changing this code, read the comments in the impl above
stg_traceMarkerzh ( W_ msg )
{
#if defined(TRACING) || defined(DEBUG)
ccall traceUserMarker(MyCapability() "ptr", msg "ptr");
#elif defined(DTRACE)
W_ enabled;
#if !defined(solaris2_TARGET_OS)
(enabled) = ccall __dtrace_isenabled$HaskellEvent$user__marker$v1();
#else
enabled = 1;
#endif
if (enabled != 0) {
ccall dtraceUserMarkerWrapper(MyCapability() "ptr", msg "ptr");
}
#endif
return ();
}
......@@ -99,4 +99,5 @@ provider HaskellEvent {
/* probe log__msg (char *); */
/* we don't need EVENT_BLOCK_MARKER with dtrace */
probe user__msg (EventCapNo, char *);
probe user__marker (EventCapNo, char *);
};
......@@ -708,6 +708,28 @@ void traceUserMsg(Capability *cap, char *msg)
traceFormatUserMsg(cap, "%s", msg);
}
void traceUserMarker(Capability *cap, char *markername)
{
/* Note: traceUserMarker is special since it has no wrapper (it's called
from cmm code), so we check eventlog_enabled and TRACE_user here.
*/
#ifdef DEBUG
if (RtsFlags.TraceFlags.tracing == TRACE_STDERR && TRACE_user) {
ACQUIRE_LOCK(&trace_utx);
tracePreface();
debugBelch("cap %d: User marker: %s\n", cap->no, markername);
RELEASE_LOCK(&trace_utx);
} else
#endif
{
if (eventlog_enabled && TRACE_user) {
postUserMarker(cap, markername);
}
}
dtraceUserMarker(cap->no, markername);
}
void traceThreadLabel_(Capability *cap,
StgTSO *tso,
char *label)
......
......@@ -197,6 +197,12 @@ void trace_(char *msg, ...);
*/
void traceUserMsg(Capability *cap, char *msg);
/*
* A marker event emitted by the program
* Used by Debug.Trace.{traceMarker, traceMarkerIO}
*/
void traceUserMarker(Capability *cap, char *msg);
/*
* An event to record a Haskell thread's label/name
* Used by GHC.Conc.labelThread
......@@ -310,6 +316,7 @@ INLINE_HEADER void traceEventStartup_ (int n_caps STG_UNUSED) {};
#if !defined(DEBUG) && !defined(TRACING) && defined(DTRACE)
void dtraceUserMsgWrapper(Capability *cap, char *msg);
void dtraceUserMarkerWrapper(Capability *cap, char *msg);
#endif /* !defined(DEBUG) && !defined(TRACING) && defined(DTRACE) */
......@@ -356,6 +363,8 @@ INLINE_HEADER void dtraceStartup (int num_caps) {
HASKELLEVENT_CAP_DISABLE(cap)
#define dtraceUserMsg(cap, msg) \
HASKELLEVENT_USER_MSG(cap, msg)
#define dtraceUserMarker(cap, msg) \
HASKELLEVENT_USER_MARKER(cap, msg)
#define dtraceGcIdle(cap) \
HASKELLEVENT_GC_IDLE(cap)
#define dtraceGcWork(cap) \
......@@ -435,6 +444,7 @@ INLINE_HEADER void dtraceStartup (int num_caps) {
#define dtraceThreadLabel(cap, tso, label) /* nothing */
INLINE_HEADER void dtraceStartup (int num_caps STG_UNUSED) {};
#define dtraceUserMsg(cap, msg) /* nothing */
#define dtraceUserMarker(cap, msg) /* nothing */
#define dtraceGcIdle(cap) /* nothing */
#define dtraceGcWork(cap) /* nothing */
#define dtraceGcDone(cap) /* nothing */
......
......@@ -80,6 +80,7 @@ char *EventDesc[] = {
[EVENT_CREATE_SPARK_THREAD] = "Create spark thread",
[EVENT_LOG_MSG] = "Log message",
[EVENT_USER_MSG] = "User message",
[EVENT_USER_MARKER] = "User marker",
[EVENT_GC_IDLE] = "GC idle",
[EVENT_GC_WORK] = "GC working",
[EVENT_GC_DONE] = "GC done",
......@@ -369,6 +370,7 @@ initEventLogging(void)
case EVENT_LOG_MSG: // (msg)
case EVENT_USER_MSG: // (msg)
case EVENT_USER_MARKER: // (markername)
case EVENT_RTS_IDENTIFIER: // (capset, str)
case EVENT_PROGRAM_ARGS: // (capset, strvec)
case EVENT_PROGRAM_ENV: // (capset, strvec)
......@@ -1086,6 +1088,27 @@ void postEventStartup(EventCapNo n_caps)
RELEASE_LOCK(&eventBufMutex);
}
void postUserMarker(Capability *cap, char *markername)
{
EventsBuf *eb;
int size = strlen(markername);
eb = &capEventBuf[cap->no];
if (!hasRoomForVariableEvent(eb, size)){
printAndClearEventBuf(eb);
if (!hasRoomForVariableEvent(eb, size)){
// Event size exceeds buffer size, bail out:
return;
}
}
postEventHeader(eb, EVENT_USER_MARKER);
postPayloadSize(eb, size);
postBuf(eb, (StgWord8*) markername, size);
}
void postThreadLabel(Capability *cap,
EventThreadID id,
char *label)
......
......@@ -49,6 +49,8 @@ void postUserMsg(Capability *cap, char *msg, va_list ap);
void postCapMsg(Capability *cap, char *msg, va_list ap);
void postUserMarker(Capability *cap, char *markername);
void postEventStartup(EventCapNo n_caps);
/*
......
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