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 %lu of type %d\n", (lnat)capset, (int)other);
272 case EVENT_CAPSET_DELETE: // (capset)
273 debugBelch("deleted capset %lu\n", (lnat)capset);
275 case EVENT_CAPSET_ASSIGN_CAP: // (capset, capno)
276 debugBelch("assigned cap %lu to capset %lu\n",
277 (lnat)other, (lnat)capset);
279 case EVENT_CAPSET_REMOVE_CAP: // (capset, capno)
280 debugBelch("removed cap %lu from capset %lu\n",
281 (lnat)other, (lnat)capset);
284 RELEASE_LOCK(&trace_utx);
288 if (eventlog_enabled) {
289 postCapsetModifyEvent(tag, capset, other);
294 void traceOSProcessInfo_(void) {
295 if (eventlog_enabled) {
296 postCapsetModifyEvent(EVENT_OSPROCESS_PID,
297 CAPSET_OSPROCESS_DEFAULT,
300 #if !defined(cygwin32_HOST_OS) && !defined (mingw32_HOST_OS)
301 /* Windows has no strong concept of process heirarchy, so no getppid().
302 * In any case, this trace event is mainly useful for tracing programs
303 * that use 'forkProcess' which Windows doesn't support anyway.
305 postCapsetModifyEvent(EVENT_OSPROCESS_PPID,
306 CAPSET_OSPROCESS_DEFAULT,
311 snprintf(buf, sizeof(buf), "GHC-%s %s", ProjectVersion, RtsWay);
312 postCapsetStrEvent(EVENT_RTS_IDENTIFIER,
313 CAPSET_OSPROCESS_DEFAULT,
317 int argc = 0; char **argv;
318 getFullProgArgv(&argc, &argv);
320 postCapsetVecEvent(EVENT_PROGRAM_ARGS,
321 CAPSET_OSPROCESS_DEFAULT,
326 int envc = 0; char **envv;
327 getProgEnvv(&envc, &envv);
329 postCapsetVecEvent(EVENT_PROGRAM_ENV,
330 CAPSET_OSPROCESS_DEFAULT,
333 freeProgEnvv(envc, envv);
338 void traceEvent_ (Capability *cap, EventTypeNum tag)
341 if (RtsFlags.TraceFlags.tracing == TRACE_STDERR) {
342 traceSchedEvent_stderr(cap, tag, 0, 0, 0);
351 static void traceCap_stderr(Capability *cap, char *msg, va_list ap)
353 ACQUIRE_LOCK(&trace_utx);
356 debugBelch("cap %d: ", cap->no);
360 RELEASE_LOCK(&trace_utx);
364 void traceCap_(Capability *cap, char *msg, ...)
370 if (RtsFlags.TraceFlags.tracing == TRACE_STDERR) {
371 traceCap_stderr(cap, msg, ap);
375 postCapMsg(cap, msg, ap);
382 static void trace_stderr(char *msg, va_list ap)
384 ACQUIRE_LOCK(&trace_utx);
390 RELEASE_LOCK(&trace_utx);
394 void trace_(char *msg, ...)
400 if (RtsFlags.TraceFlags.tracing == TRACE_STDERR) {
401 trace_stderr(msg, ap);
411 static void traceFormatUserMsg(Capability *cap, char *msg, ...)
417 if (RtsFlags.TraceFlags.tracing == TRACE_STDERR) {
418 traceCap_stderr(cap, msg, ap);
422 if (eventlog_enabled) {
423 postUserMsg(cap, msg, ap);
426 dtraceUserMsg(cap->no, msg);
429 void traceUserMsg(Capability *cap, char *msg)
431 traceFormatUserMsg(cap, "%s", msg);
434 void traceThreadStatus_ (StgTSO *tso USED_IF_DEBUG)
437 if (RtsFlags.TraceFlags.tracing == TRACE_STDERR) {
438 printThreadStatus(tso);
442 /* nothing - no event for this one yet */
446 void traceEventStartup_(int nocaps)
448 if (eventlog_enabled) {
449 postEventStartup(nocaps);
454 void traceBegin (const char *str, ...)
459 ACQUIRE_LOCK(&trace_utx);
468 RELEASE_LOCK(&trace_utx);
474 // If DTRACE is enabled, but neither DEBUG nor TRACING, we need a C land
475 // wrapper for the user-msg probe (as we can't expand that in PrimOps.cmm)
477 #if !defined(DEBUG) && !defined(TRACING) && defined(DTRACE)
479 void dtraceUserMsgWrapper(Capability *cap, char *msg)
481 dtraceUserMsg(cap->no, msg);
484 #endif /* !defined(DEBUG) && !defined(TRACING) && defined(DTRACE) */