a26a919561cc7f04ba843d9f5239a973a0e0a7c6
[ghc.git] / rts / Trace.c
1 /* -----------------------------------------------------------------------------
2 *
3 * (c) The GHC Team 2006-2009
4 *
5 * Debug and performance tracing
6 *
7 * ---------------------------------------------------------------------------*/
8
9 // external headers
10 #include "Rts.h"
11
12 #ifdef TRACING
13
14 // internal headers
15 #include "Trace.h"
16 #include "GetTime.h"
17 #include "Stats.h"
18 #include "eventlog/EventLog.h"
19 #include "Threads.h"
20 #include "Printer.h"
21
22 #ifdef DEBUG
23 // debugging flags, set with +RTS -D<something>
24 int DEBUG_sched;
25 int DEBUG_interp;
26 int DEBUG_weak;
27 int DEBUG_gccafs;
28 int DEBUG_gc;
29 int DEBUG_block_alloc;
30 int DEBUG_sanity;
31 int DEBUG_stable;
32 int DEBUG_stm;
33 int DEBUG_prof;
34 int DEBUG_gran;
35 int DEBUG_par;
36 int DEBUG_linker;
37 int DEBUG_squeeze;
38 int DEBUG_hpc;
39 int DEBUG_sparks;
40 #endif
41
42 // events
43 int TRACE_sched;
44
45 #ifdef THREADED_RTS
46 static Mutex trace_utx;
47 #endif
48
49 static rtsBool eventlog_enabled;
50
51 /* ---------------------------------------------------------------------------
52 Starting up / shuttting down the tracing facilities
53 --------------------------------------------------------------------------- */
54
55 void initTracing (void)
56 {
57 #ifdef THREADED_RTS
58 initMutex(&trace_utx);
59 #endif
60
61 #define TRACE_FLAG(name, class) \
62 class = RtsFlags.TraceFlags.name ? 1 : 0;
63
64 TRACE_FLAG(scheduler, TRACE_sched);
65
66 #ifdef DEBUG
67 #define DEBUG_FLAG(name, class) \
68 class = RtsFlags.DebugFlags.name ? 1 : 0;
69
70 DEBUG_FLAG(scheduler, DEBUG_sched);
71 DEBUG_FLAG(scheduler, TRACE_sched); // -Ds enabled all sched events
72
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);
86 #endif
87
88 eventlog_enabled = RtsFlags.TraceFlags.tracing == TRACE_EVENTLOG;
89
90 if (eventlog_enabled) {
91 initEventLogging();
92 }
93 }
94
95 void endTracing (void)
96 {
97 if (eventlog_enabled) {
98 endEventLogging();
99 }
100 }
101
102 void freeTracing (void)
103 {
104 if (eventlog_enabled) {
105 freeEventLogging();
106 }
107 }
108
109 /* ---------------------------------------------------------------------------
110 Emitting trace messages/events
111 --------------------------------------------------------------------------- */
112
113 #ifdef DEBUG
114 static void tracePreface (void)
115 {
116 #ifdef THREADED_RTS
117 debugBelch("%12lx: ", (unsigned long)osThreadId());
118 #endif
119 if (RtsFlags.TraceFlags.timestamp) {
120 debugBelch("%9" FMT_Word64 ": ", stat_getElapsedTime());
121 }
122 }
123 #endif
124
125 #ifdef DEBUG
126 static char *thread_stop_reasons[] = {
127 [HeapOverflow] = "heap overflow",
128 [StackOverflow] = "stack overflow",
129 [ThreadYielding] = "yielding",
130 [ThreadBlocked] = "blocked",
131 [ThreadFinished] = "finished",
132 [THREAD_SUSPENDED_FOREIGN_CALL] = "suspended while making a foreign call"
133 };
134 #endif
135
136 #ifdef DEBUG
137 static void traceSchedEvent_stderr (Capability *cap, EventTypeNum tag,
138 StgTSO *tso,
139 StgWord64 other STG_UNUSED)
140 {
141 ACQUIRE_LOCK(&trace_utx);
142
143 tracePreface();
144 switch (tag) {
145 case EVENT_CREATE_THREAD: // (cap, thread)
146 debugBelch("cap %d: created thread %lu\n",
147 cap->no, (lnat)tso->id);
148 break;
149 case EVENT_RUN_THREAD: // (cap, thread)
150 debugBelch("cap %d: running thread %lu (%s)\n",
151 cap->no, (lnat)tso->id, what_next_strs[tso->what_next]);
152 break;
153 case EVENT_THREAD_RUNNABLE: // (cap, thread)
154 debugBelch("cap %d: thread %lu appended to run queue\n",
155 cap->no, (lnat)tso->id);
156 break;
157 case EVENT_RUN_SPARK: // (cap, thread)
158 debugBelch("cap %d: thread %lu running a spark\n",
159 cap->no, (lnat)tso->id);
160 break;
161 case EVENT_CREATE_SPARK_THREAD: // (cap, spark_thread)
162 debugBelch("cap %d: creating spark thread %lu\n",
163 cap->no, (long)other);
164 break;
165 case EVENT_MIGRATE_THREAD: // (cap, thread, new_cap)
166 debugBelch("cap %d: thread %lu migrating to cap %d\n",
167 cap->no, (lnat)tso->id, (int)other);
168 break;
169 case EVENT_STEAL_SPARK: // (cap, thread, victim_cap)
170 debugBelch("cap %d: thread %lu stealing a spark from cap %d\n",
171 cap->no, (lnat)tso->id, (int)other);
172 break;
173 case EVENT_THREAD_WAKEUP: // (cap, thread, other_cap)
174 debugBelch("cap %d: waking up thread %lu on cap %d\n",
175 cap->no, (lnat)tso->id, (int)other);
176 break;
177
178 case EVENT_STOP_THREAD: // (cap, thread, status)
179 debugBelch("cap %d: thread %lu stopped (%s)\n",
180 cap->no, (lnat)tso->id, thread_stop_reasons[other]);
181 break;
182 case EVENT_SHUTDOWN: // (cap)
183 debugBelch("cap %d: shutting down\n", cap->no);
184 break;
185 case EVENT_REQUEST_SEQ_GC: // (cap)
186 debugBelch("cap %d: requesting sequential GC\n", cap->no);
187 break;
188 case EVENT_REQUEST_PAR_GC: // (cap)
189 debugBelch("cap %d: requesting parallel GC\n", cap->no);
190 break;
191 case EVENT_GC_START: // (cap)
192 debugBelch("cap %d: starting GC\n", cap->no);
193 break;
194 case EVENT_GC_END: // (cap)
195 debugBelch("cap %d: finished GC\n", cap->no);
196 break;
197 default:
198 debugBelch("cap %2d: thread %lu: event %d\n\n",
199 cap->no, (lnat)tso->id, tag);
200 break;
201 }
202
203 RELEASE_LOCK(&trace_utx);
204 }
205 #endif
206
207 void traceSchedEvent_ (Capability *cap, EventTypeNum tag,
208 StgTSO *tso, StgWord64 other)
209 {
210 #ifdef DEBUG
211 if (RtsFlags.TraceFlags.tracing == TRACE_STDERR) {
212 traceSchedEvent_stderr(cap, tag, tso, other);
213 } else
214 #endif
215 {
216 postSchedEvent(cap,tag,tso ? tso->id : 0,other);
217 }
218 }
219
220 #ifdef DEBUG
221 static void traceCap_stderr(Capability *cap, char *msg, va_list ap)
222 {
223 ACQUIRE_LOCK(&trace_utx);
224
225 tracePreface();
226 debugBelch("cap %2d: ", cap->no);
227 vdebugBelch(msg,ap);
228 debugBelch("\n");
229
230 RELEASE_LOCK(&trace_utx);
231 }
232 #endif
233
234 void traceCap_(Capability *cap, char *msg, ...)
235 {
236 va_list ap;
237 va_start(ap,msg);
238
239 #ifdef DEBUG
240 if (RtsFlags.TraceFlags.tracing == TRACE_STDERR) {
241 traceCap_stderr(cap, msg, ap);
242 } else
243 #endif
244 {
245 postCapMsg(cap, msg, ap);
246 }
247
248 va_end(ap);
249 }
250
251 #ifdef DEBUG
252 static void trace_stderr(char *msg, va_list ap)
253 {
254 ACQUIRE_LOCK(&trace_utx);
255
256 tracePreface();
257 vdebugBelch(msg,ap);
258 debugBelch("\n");
259
260 RELEASE_LOCK(&trace_utx);
261 }
262 #endif
263
264 void trace_(char *msg, ...)
265 {
266 va_list ap;
267 va_start(ap,msg);
268
269 #ifdef DEBUG
270 if (RtsFlags.TraceFlags.tracing == TRACE_STDERR) {
271 trace_stderr(msg, ap);
272 } else
273 #endif
274 {
275 postMsg(msg, ap);
276 }
277
278 va_end(ap);
279 }
280
281 void traceUserMsg(Capability *cap, char *msg)
282 {
283 #ifdef DEBUG
284 if (RtsFlags.TraceFlags.tracing == TRACE_STDERR) {
285 traceCap_stderr(cap, msg, NULL);
286 } else
287 #endif
288 {
289 if (eventlog_enabled) {
290 postUserMsg(cap, msg);
291 }
292 }
293 }
294
295 void traceThreadStatus_ (StgTSO *tso USED_IF_DEBUG)
296 {
297 #ifdef DEBUG
298 if (RtsFlags.TraceFlags.tracing == TRACE_STDERR) {
299 printThreadStatus(tso);
300 } else
301 #endif
302 {
303 /* nothing - no event for this one yet */
304 }
305 }
306
307
308 #ifdef DEBUG
309 void traceBegin (const char *str, ...)
310 {
311 va_list ap;
312 va_start(ap,str);
313
314 ACQUIRE_LOCK(&trace_utx);
315
316 tracePreface();
317 vdebugBelch(str,ap);
318 }
319
320 void traceEnd (void)
321 {
322 debugBelch("\n");
323 RELEASE_LOCK(&trace_utx);
324 }
325 #endif /* DEBUG */
326
327 #endif /* TRACING */