1 /* -----------------------------------------------------------------------------
3 * (c) The GHC Team 2006-2009
5 * Debug and performance tracing
7 * ---------------------------------------------------------------------------*/
20 #include "eventlog/EventLog.h"
29 // debugging flags, set with +RTS -D<something>
35 int DEBUG_block_alloc;
52 static Mutex trace_utx;
55 static rtsBool eventlog_enabled;
57 /* ---------------------------------------------------------------------------
58 Starting up / shuttting down the tracing facilities
59 --------------------------------------------------------------------------- */
61 void initTracing (void)
64 initMutex(&trace_utx);
68 #define DEBUG_FLAG(name, class) \
69 class = RtsFlags.DebugFlags.name ? 1 : 0;
71 DEBUG_FLAG(scheduler, DEBUG_sched);
73 DEBUG_FLAG(interpreter, DEBUG_interp);
74 DEBUG_FLAG(weak, DEBUG_weak);
75 DEBUG_FLAG(gccafs, DEBUG_gccafs);
76 DEBUG_FLAG(gc, DEBUG_gc);
77 DEBUG_FLAG(block_alloc, DEBUG_block_alloc);
78 DEBUG_FLAG(sanity, DEBUG_sanity);
79 DEBUG_FLAG(stable, DEBUG_stable);
80 DEBUG_FLAG(stm, DEBUG_stm);
81 DEBUG_FLAG(prof, DEBUG_prof);
82 DEBUG_FLAG(linker, DEBUG_linker);
83 DEBUG_FLAG(squeeze, DEBUG_squeeze);
84 DEBUG_FLAG(hpc, DEBUG_hpc);
85 DEBUG_FLAG(sparks, DEBUG_sparks);
88 // -Ds turns on scheduler tracing too
90 RtsFlags.TraceFlags.scheduler ||
91 RtsFlags.DebugFlags.scheduler;
93 eventlog_enabled = RtsFlags.TraceFlags.tracing == TRACE_EVENTLOG;
95 if (eventlog_enabled) {
100 void endTracing (void)
102 if (eventlog_enabled) {
107 void freeTracing (void)
109 if (eventlog_enabled) {
114 void resetTracing (void)
116 if (eventlog_enabled) {
117 abortEventLogging(); // abort eventlog inherited from parent
118 initEventLogging(); // child starts its own eventlog
122 /* ---------------------------------------------------------------------------
123 Emitting trace messages/events
124 --------------------------------------------------------------------------- */
127 static void tracePreface (void)
130 debugBelch("%12lx: ", (unsigned long)osThreadId());
132 if (RtsFlags.TraceFlags.timestamp) {
133 debugBelch("%9" FMT_Word64 ": ", stat_getElapsedTime());
139 static char *thread_stop_reasons[] = {
140 [HeapOverflow] = "heap overflow",
141 [StackOverflow] = "stack overflow",
142 [ThreadYielding] = "yielding",
143 [ThreadBlocked] = "blocked",
144 [ThreadFinished] = "finished",
145 [THREAD_SUSPENDED_FOREIGN_CALL] = "suspended while making a foreign call",
146 [6 + BlockedOnMVar] = "blocked on an MVar",
147 [6 + BlockedOnBlackHole] = "blocked on a black hole",
148 [6 + BlockedOnRead] = "blocked on a read operation",
149 [6 + BlockedOnWrite] = "blocked on a write operation",
150 [6 + BlockedOnDelay] = "blocked on a delay operation",
151 [6 + BlockedOnSTM] = "blocked on STM",
152 [6 + BlockedOnDoProc] = "blocked on asyncDoProc",
153 [6 + BlockedOnCCall] = "blocked on a foreign call",
154 [6 + BlockedOnCCall_Interruptible] = "blocked on a foreign call (interruptible)",
155 [6 + BlockedOnMsgThrowTo] = "blocked on throwTo",
156 [6 + ThreadMigrating] = "migrating"
161 static void traceSchedEvent_stderr (Capability *cap, EventTypeNum tag,
163 StgWord info1 STG_UNUSED,
164 StgWord info2 STG_UNUSED)
166 ACQUIRE_LOCK(&trace_utx);
170 case EVENT_CREATE_THREAD: // (cap, thread)
171 debugBelch("cap %d: created thread %lu\n",
172 cap->no, (lnat)tso->id);
174 case EVENT_RUN_THREAD: // (cap, thread)
175 debugBelch("cap %d: running thread %lu (%s)\n",
176 cap->no, (lnat)tso->id, what_next_strs[tso->what_next]);
178 case EVENT_THREAD_RUNNABLE: // (cap, thread)
179 debugBelch("cap %d: thread %lu appended to run queue\n",
180 cap->no, (lnat)tso->id);
182 case EVENT_RUN_SPARK: // (cap, thread)
183 debugBelch("cap %d: thread %lu running a spark\n",
184 cap->no, (lnat)tso->id);
186 case EVENT_CREATE_SPARK_THREAD: // (cap, spark_thread)
187 debugBelch("cap %d: creating spark thread %lu\n",
188 cap->no, (long)info1);
190 case EVENT_MIGRATE_THREAD: // (cap, thread, new_cap)
191 debugBelch("cap %d: thread %lu migrating to cap %d\n",
192 cap->no, (lnat)tso->id, (int)info1);
194 case EVENT_STEAL_SPARK: // (cap, thread, victim_cap)
195 debugBelch("cap %d: thread %lu stealing a spark from cap %d\n",
196 cap->no, (lnat)tso->id, (int)info1);
198 case EVENT_THREAD_WAKEUP: // (cap, thread, info1_cap)
199 debugBelch("cap %d: waking up thread %lu on cap %d\n",
200 cap->no, (lnat)tso->id, (int)info1);
203 case EVENT_STOP_THREAD: // (cap, thread, status)
204 if (info1 == 6 + BlockedOnBlackHole) {
205 debugBelch("cap %d: thread %lu stopped (blocked on black hole owned by thread %lu)\n",
206 cap->no, (lnat)tso->id, (long)info2);
208 debugBelch("cap %d: thread %lu stopped (%s)\n",
209 cap->no, (lnat)tso->id, thread_stop_reasons[info1]);
212 case EVENT_SHUTDOWN: // (cap)
213 debugBelch("cap %d: shutting down\n", cap->no);
215 case EVENT_REQUEST_SEQ_GC: // (cap)
216 debugBelch("cap %d: requesting sequential GC\n", cap->no);
218 case EVENT_REQUEST_PAR_GC: // (cap)
219 debugBelch("cap %d: requesting parallel GC\n", cap->no);
221 case EVENT_GC_START: // (cap)
222 debugBelch("cap %d: starting GC\n", cap->no);
224 case EVENT_GC_END: // (cap)
225 debugBelch("cap %d: finished GC\n", cap->no);
227 case EVENT_GC_IDLE: // (cap)
228 debugBelch("cap %d: GC idle\n", cap->no);
230 case EVENT_GC_WORK: // (cap)
231 debugBelch("cap %d: GC working\n", cap->no);
233 case EVENT_GC_DONE: // (cap)
234 debugBelch("cap %d: GC done\n", cap->no);
237 debugBelch("cap %d: thread %lu: event %d\n\n",
238 cap->no, (lnat)tso->id, tag);
242 RELEASE_LOCK(&trace_utx);
246 void traceSchedEvent_ (Capability *cap, EventTypeNum tag,
247 StgTSO *tso, StgWord info1, StgWord info2)
250 if (RtsFlags.TraceFlags.tracing == TRACE_STDERR) {
251 traceSchedEvent_stderr(cap, tag, tso, info1, info2);
255 postSchedEvent(cap,tag,tso ? tso->id : 0, info1, info2);
259 void traceCapsetModify_ (EventTypeNum tag,
264 if (RtsFlags.TraceFlags.tracing == TRACE_STDERR) {
265 ACQUIRE_LOCK(&trace_utx);
269 case EVENT_CAPSET_CREATE: // (capset, capset_type)
270 debugBelch("created capset %d of type %d\n", capset, other);
272 case EVENT_CAPSET_DELETE: // (capset)
273 debugBelch("deleted capset %d\n", capset);
275 case EVENT_CAPSET_ASSIGN_CAP: // (capset, capno)
276 debugBelch("assigned cap %d to capset %d\n", other, capset);
278 case EVENT_CAPSET_REMOVE_CAP: // (capset, capno)
279 debugBelch("removed cap %d from capset %d\n", other, capset);
282 RELEASE_LOCK(&trace_utx);
286 if (eventlog_enabled) {
287 postCapsetModifyEvent(tag, capset, other);
292 void traceOSProcessInfo_(void) {
293 if (eventlog_enabled) {
294 postCapsetModifyEvent(EVENT_OSPROCESS_PID,
295 CAPSET_OSPROCESS_DEFAULT,
298 #if !defined(cygwin32_HOST_OS) && !defined (mingw32_HOST_OS)
299 /* Windows has no strong concept of process heirarchy, so no getppid().
300 * In any case, this trace event is mainly useful for tracing programs
301 * that use 'forkProcess' which Windows doesn't support anyway.
303 postCapsetModifyEvent(EVENT_OSPROCESS_PPID,
304 CAPSET_OSPROCESS_DEFAULT,
309 snprintf(buf, sizeof(buf), "GHC-%s %s", ProjectVersion, RtsWay);
310 postCapsetStrEvent(EVENT_RTS_IDENTIFIER,
311 CAPSET_OSPROCESS_DEFAULT,
315 int argc = 0; char **argv;
316 getFullProgArgv(&argc, &argv);
318 postCapsetVecEvent(EVENT_PROGRAM_ARGS,
319 CAPSET_OSPROCESS_DEFAULT,
324 int envc = 0; char **envv;
325 getProgEnvv(&envc, &envv);
327 postCapsetVecEvent(EVENT_PROGRAM_ENV,
328 CAPSET_OSPROCESS_DEFAULT,
331 freeProgEnvv(envc, envv);
336 void traceEvent_ (Capability *cap, EventTypeNum tag)
339 if (RtsFlags.TraceFlags.tracing == TRACE_STDERR) {
340 traceSchedEvent_stderr(cap, tag, 0, 0, 0);
349 static void traceCap_stderr(Capability *cap, char *msg, va_list ap)
351 ACQUIRE_LOCK(&trace_utx);
354 debugBelch("cap %d: ", cap->no);
358 RELEASE_LOCK(&trace_utx);
362 void traceCap_(Capability *cap, char *msg, ...)
368 if (RtsFlags.TraceFlags.tracing == TRACE_STDERR) {
369 traceCap_stderr(cap, msg, ap);
373 postCapMsg(cap, msg, ap);
380 static void trace_stderr(char *msg, va_list ap)
382 ACQUIRE_LOCK(&trace_utx);
388 RELEASE_LOCK(&trace_utx);
392 void trace_(char *msg, ...)
398 if (RtsFlags.TraceFlags.tracing == TRACE_STDERR) {
399 trace_stderr(msg, ap);
409 static void traceFormatUserMsg(Capability *cap, char *msg, ...)
415 if (RtsFlags.TraceFlags.tracing == TRACE_STDERR) {
416 traceCap_stderr(cap, msg, ap);
420 if (eventlog_enabled) {
421 postUserMsg(cap, msg, ap);
424 dtraceUserMsg(cap->no, msg);
427 void traceUserMsg(Capability *cap, char *msg)
429 traceFormatUserMsg(cap, "%s", msg);
432 void traceThreadStatus_ (StgTSO *tso USED_IF_DEBUG)
435 if (RtsFlags.TraceFlags.tracing == TRACE_STDERR) {
436 printThreadStatus(tso);
440 /* nothing - no event for this one yet */
444 void traceEventStartup_(int nocaps)
446 if (eventlog_enabled) {
447 postEventStartup(nocaps);
452 void traceBegin (const char *str, ...)
457 ACQUIRE_LOCK(&trace_utx);
466 RELEASE_LOCK(&trace_utx);
472 // If DTRACE is enabled, but neither DEBUG nor TRACING, we need a C land
473 // wrapper for the user-msg probe (as we can't expand that in PrimOps.cmm)
475 #if !defined(DEBUG) && !defined(TRACING) && defined(DTRACE)
477 void dtraceUserMsgWrapper(Capability *cap, char *msg)
479 dtraceUserMsg(cap->no, msg);
482 #endif /* !defined(DEBUG) && !defined(TRACING) && defined(DTRACE) */