Unify event logging and debug tracing.
[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 StgWord32 classes_enabled; // not static due to inline funcs
23
24 #ifdef THREADED_RTS
25 static Mutex trace_utx;
26 #endif
27
28 /* ---------------------------------------------------------------------------
29 Starting up / shuttting down the tracing facilities
30 --------------------------------------------------------------------------- */
31
32 void initTracing (void)
33 {
34 #ifdef THREADED_RTS
35 initMutex(&trace_utx);
36 #endif
37
38 #ifdef DEBUG
39 #define DEBUG_FLAG(name, class) \
40 if (RtsFlags.DebugFlags.name) classes_enabled |= class;
41
42 DEBUG_FLAG(scheduler, DEBUG_sched);
43 DEBUG_FLAG(scheduler, TRACE_sched); // -Ds enabled all sched events
44
45 DEBUG_FLAG(interpreter, DEBUG_interp);
46 DEBUG_FLAG(weak, DEBUG_weak);
47 DEBUG_FLAG(gccafs, DEBUG_gccafs);
48 DEBUG_FLAG(gc, DEBUG_gc);
49 DEBUG_FLAG(block_alloc, DEBUG_block_alloc);
50 DEBUG_FLAG(sanity, DEBUG_sanity);
51 DEBUG_FLAG(stable, DEBUG_stable);
52 DEBUG_FLAG(stm, DEBUG_stm);
53 DEBUG_FLAG(prof, DEBUG_prof);
54 DEBUG_FLAG(linker, DEBUG_linker);
55 DEBUG_FLAG(squeeze, DEBUG_squeeze);
56 DEBUG_FLAG(hpc, DEBUG_hpc);
57 DEBUG_FLAG(sparks, DEBUG_sparks);
58 #endif
59
60 #define TRACE_FLAG(name, class) \
61 if (RtsFlags.TraceFlags.name) classes_enabled |= class;
62
63 TRACE_FLAG(scheduler, TRACE_sched);
64
65 initEventLogging();
66 }
67
68 void endTracing (void)
69 {
70 endEventLogging();
71 }
72
73 void freeTracing (void)
74 {
75 freeEventLogging();
76 }
77
78 /* ---------------------------------------------------------------------------
79 Emitting trace messages/events
80 --------------------------------------------------------------------------- */
81
82 #ifdef DEBUG
83 static void tracePreface (void)
84 {
85 #ifdef THREADED_RTS
86 debugBelch("%12lx: ", (unsigned long)osThreadId());
87 #endif
88 if (RtsFlags.TraceFlags.timestamp) {
89 debugBelch("%9" FMT_Word64 ": ", stat_getElapsedTime());
90 }
91 }
92 #endif
93
94 #ifdef DEBUG
95 static char *thread_stop_reasons[] = {
96 [HeapOverflow] = "heap overflow",
97 [StackOverflow] = "stack overflow",
98 [ThreadYielding] = "yielding",
99 [ThreadBlocked] = "blocked",
100 [ThreadFinished] = "finished",
101 [THREAD_SUSPENDED_FOREIGN_CALL] = "suspended while making a foreign call"
102 };
103 #endif
104
105 #ifdef DEBUG
106 static void traceSchedEvent_stderr (Capability *cap, EventTypeNum tag,
107 StgTSO *tso,
108 StgWord64 other STG_UNUSED)
109 {
110 ACQUIRE_LOCK(&trace_utx);
111
112 tracePreface();
113 switch (tag) {
114 case EVENT_CREATE_THREAD: // (cap, thread)
115 debugBelch("cap %d: created thread %ld\n", cap->no, tso->id);
116 break;
117 case EVENT_RUN_THREAD: // (cap, thread)
118 debugBelch("cap %d: running thread %ld (%s)\n", cap->no,
119 tso->id, what_next_strs[tso->what_next]);
120 break;
121 case EVENT_THREAD_RUNNABLE: // (cap, thread)
122 debugBelch("cap %d: thread %ld appended to run queue\n",
123 cap->no, tso->id);
124 break;
125 case EVENT_RUN_SPARK: // (cap, thread)
126 debugBelch("cap %d: thread %ld running a spark\n",
127 cap->no, tso->id);
128 break;
129 case EVENT_CREATE_SPARK_THREAD: // (cap, spark_thread)
130 debugBelch("cap %d: creating spark thread %ld\n",
131 cap->no, (long)other);
132 break;
133 case EVENT_MIGRATE_THREAD: // (cap, thread, new_cap)
134 debugBelch("cap %d: thread %ld migrating to cap %d\n",
135 cap->no, tso->id, (int)other);
136 break;
137 case EVENT_STEAL_SPARK: // (cap, thread, victim_cap)
138 debugBelch("cap %d: thread %ld stealing a spark from cap %d\n",
139 cap->no, tso->id, (int)other);
140 break;
141 case EVENT_THREAD_WAKEUP: // (cap, thread, other_cap)
142 debugBelch("cap %d: waking up thread %ld on cap %d\n",
143 cap->no, tso->id, (int)other);
144 break;
145
146 case EVENT_STOP_THREAD: // (cap, thread, status)
147 debugBelch("cap %d: thread %ld stopped (%s)\n",
148 cap->no, tso->id, thread_stop_reasons[other]);
149 break;
150 case EVENT_SHUTDOWN: // (cap)
151 debugBelch("cap %d: shutting down\n", cap->no);
152 break;
153 case EVENT_REQUEST_SEQ_GC: // (cap)
154 debugBelch("cap %d: requesting sequential GC\n", cap->no);
155 break;
156 case EVENT_REQUEST_PAR_GC: // (cap)
157 debugBelch("cap %d: requesting parallel GC\n", cap->no);
158 break;
159 case EVENT_GC_START: // (cap)
160 debugBelch("cap %d: starting GC\n", cap->no);
161 break;
162 case EVENT_GC_END: // (cap)
163 debugBelch("cap %d: finished GC\n", cap->no);
164 break;
165 default:
166 debugBelch("cap %2d: thread %ld: event %d\n\n", cap->no, tso->id, tag);
167 break;
168 }
169
170 RELEASE_LOCK(&trace_utx);
171 }
172 #endif
173
174 void traceSchedEvent_ (Capability *cap, EventTypeNum tag,
175 StgTSO *tso, StgWord64 other)
176 {
177 #ifdef DEBUG
178 if (RtsFlags.TraceFlags.trace_stderr) {
179 traceSchedEvent_stderr(cap, tag, tso, other);
180 } else
181 #endif
182 {
183 postSchedEvent(cap,tag,tso ? tso->id : 0,other);
184 }
185 }
186
187 #ifdef DEBUG
188 static void traceCap_stderr(Capability *cap, char *msg, va_list ap)
189 {
190 ACQUIRE_LOCK(&trace_utx);
191
192 tracePreface();
193 debugBelch("cap %2d: ", cap->no);
194 vdebugBelch(msg,ap);
195 debugBelch("\n");
196
197 RELEASE_LOCK(&trace_utx);
198 }
199 #endif
200
201 void traceCap_(Capability *cap, char *msg, va_list ap)
202 {
203 #ifdef DEBUG
204 if (RtsFlags.TraceFlags.trace_stderr) {
205 traceCap_stderr(cap, msg, ap);
206 } else
207 #endif
208 {
209 postCapMsg(cap, msg, ap);
210 }
211 }
212
213 #ifdef DEBUG
214 static void trace_stderr(char *msg, va_list ap)
215 {
216 ACQUIRE_LOCK(&trace_utx);
217
218 tracePreface();
219 vdebugBelch(msg,ap);
220 debugBelch("\n");
221
222 RELEASE_LOCK(&trace_utx);
223 }
224 #endif
225
226 void trace_(char *msg, va_list ap)
227 {
228 #ifdef DEBUG
229 if (RtsFlags.TraceFlags.trace_stderr) {
230 trace_stderr(msg, ap);
231 } else
232 #endif
233 {
234 postMsg(msg, ap);
235 }
236 }
237
238 void traceThreadStatus_ (StgTSO *tso USED_IF_DEBUG)
239 {
240 #ifdef DEBUG
241 if (RtsFlags.TraceFlags.trace_stderr) {
242 printThreadStatus(tso);
243 } else
244 #endif
245 {
246 /* nothing - no event for this one yet */
247 }
248 }
249
250
251 #ifdef DEBUG
252 void traceBegin (const char *str, ...)
253 {
254 va_list ap;
255 va_start(ap,str);
256
257 ACQUIRE_LOCK(&trace_utx);
258
259 tracePreface();
260 vdebugBelch(str,ap);
261 }
262
263 void traceEnd (void)
264 {
265 debugBelch("\n");
266 RELEASE_LOCK(&trace_utx);
267 }
268 #endif /* DEBUG */
269
270 #endif /* TRACING */