| 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 | // internal headers |
|---|
| 13 | #include "Trace.h" |
|---|
| 14 | |
|---|
| 15 | #ifdef TRACING |
|---|
| 16 | |
|---|
| 17 | #include "GetTime.h" |
|---|
| 18 | #include "GetEnv.h" |
|---|
| 19 | #include "Stats.h" |
|---|
| 20 | #include "eventlog/EventLog.h" |
|---|
| 21 | #include "Threads.h" |
|---|
| 22 | #include "Printer.h" |
|---|
| 23 | |
|---|
| 24 | #ifdef HAVE_UNISTD_H |
|---|
| 25 | #include <unistd.h> |
|---|
| 26 | #endif |
|---|
| 27 | |
|---|
| 28 | #ifdef DEBUG |
|---|
| 29 | // debugging flags, set with +RTS -D<something> |
|---|
| 30 | int DEBUG_sched; |
|---|
| 31 | int DEBUG_interp; |
|---|
| 32 | int DEBUG_weak; |
|---|
| 33 | int DEBUG_gccafs; |
|---|
| 34 | int DEBUG_gc; |
|---|
| 35 | int DEBUG_block_alloc; |
|---|
| 36 | int DEBUG_sanity; |
|---|
| 37 | int DEBUG_stable; |
|---|
| 38 | int DEBUG_stm; |
|---|
| 39 | int DEBUG_prof; |
|---|
| 40 | int DEBUG_gran; |
|---|
| 41 | int DEBUG_par; |
|---|
| 42 | int DEBUG_linker; |
|---|
| 43 | int DEBUG_squeeze; |
|---|
| 44 | int DEBUG_hpc; |
|---|
| 45 | int DEBUG_sparks; |
|---|
| 46 | #endif |
|---|
| 47 | |
|---|
| 48 | // events |
|---|
| 49 | int TRACE_sched; |
|---|
| 50 | int TRACE_gc; |
|---|
| 51 | int TRACE_spark_sampled; |
|---|
| 52 | int TRACE_spark_full; |
|---|
| 53 | int TRACE_user; |
|---|
| 54 | |
|---|
| 55 | #ifdef THREADED_RTS |
|---|
| 56 | static Mutex trace_utx; |
|---|
| 57 | #endif |
|---|
| 58 | |
|---|
| 59 | static rtsBool eventlog_enabled; |
|---|
| 60 | |
|---|
| 61 | /* --------------------------------------------------------------------------- |
|---|
| 62 | Starting up / shuttting down the tracing facilities |
|---|
| 63 | --------------------------------------------------------------------------- */ |
|---|
| 64 | |
|---|
| 65 | void initTracing (void) |
|---|
| 66 | { |
|---|
| 67 | #ifdef THREADED_RTS |
|---|
| 68 | initMutex(&trace_utx); |
|---|
| 69 | #endif |
|---|
| 70 | |
|---|
| 71 | #ifdef DEBUG |
|---|
| 72 | #define DEBUG_FLAG(name, class) \ |
|---|
| 73 | class = RtsFlags.DebugFlags.name ? 1 : 0; |
|---|
| 74 | |
|---|
| 75 | DEBUG_FLAG(scheduler, DEBUG_sched); |
|---|
| 76 | |
|---|
| 77 | DEBUG_FLAG(interpreter, DEBUG_interp); |
|---|
| 78 | DEBUG_FLAG(weak, DEBUG_weak); |
|---|
| 79 | DEBUG_FLAG(gccafs, DEBUG_gccafs); |
|---|
| 80 | DEBUG_FLAG(gc, DEBUG_gc); |
|---|
| 81 | DEBUG_FLAG(block_alloc, DEBUG_block_alloc); |
|---|
| 82 | DEBUG_FLAG(sanity, DEBUG_sanity); |
|---|
| 83 | DEBUG_FLAG(stable, DEBUG_stable); |
|---|
| 84 | DEBUG_FLAG(stm, DEBUG_stm); |
|---|
| 85 | DEBUG_FLAG(prof, DEBUG_prof); |
|---|
| 86 | DEBUG_FLAG(linker, DEBUG_linker); |
|---|
| 87 | DEBUG_FLAG(squeeze, DEBUG_squeeze); |
|---|
| 88 | DEBUG_FLAG(hpc, DEBUG_hpc); |
|---|
| 89 | DEBUG_FLAG(sparks, DEBUG_sparks); |
|---|
| 90 | #endif |
|---|
| 91 | |
|---|
| 92 | // -Ds turns on scheduler tracing too |
|---|
| 93 | TRACE_sched = |
|---|
| 94 | RtsFlags.TraceFlags.scheduler || |
|---|
| 95 | RtsFlags.DebugFlags.scheduler; |
|---|
| 96 | |
|---|
| 97 | // -Dg turns on gc tracing too |
|---|
| 98 | TRACE_gc = |
|---|
| 99 | RtsFlags.TraceFlags.gc || |
|---|
| 100 | RtsFlags.DebugFlags.gc || |
|---|
| 101 | RtsFlags.DebugFlags.scheduler; |
|---|
| 102 | if (TRACE_gc && RtsFlags.GcFlags.giveStats == NO_GC_STATS) { |
|---|
| 103 | RtsFlags.GcFlags.giveStats = COLLECT_GC_STATS; |
|---|
| 104 | } |
|---|
| 105 | |
|---|
| 106 | TRACE_spark_sampled = |
|---|
| 107 | RtsFlags.TraceFlags.sparks_sampled; |
|---|
| 108 | |
|---|
| 109 | // -Dr turns on full spark tracing |
|---|
| 110 | TRACE_spark_full = |
|---|
| 111 | RtsFlags.TraceFlags.sparks_full || |
|---|
| 112 | RtsFlags.DebugFlags.sparks; |
|---|
| 113 | |
|---|
| 114 | TRACE_user = |
|---|
| 115 | RtsFlags.TraceFlags.user; |
|---|
| 116 | |
|---|
| 117 | eventlog_enabled = RtsFlags.TraceFlags.tracing == TRACE_EVENTLOG; |
|---|
| 118 | |
|---|
| 119 | /* Note: we can have any of the TRACE_* flags turned on even when |
|---|
| 120 | eventlog_enabled is off. In the DEBUG way we may be tracing to stderr. |
|---|
| 121 | */ |
|---|
| 122 | |
|---|
| 123 | if (eventlog_enabled) { |
|---|
| 124 | initEventLogging(); |
|---|
| 125 | } |
|---|
| 126 | } |
|---|
| 127 | |
|---|
| 128 | void endTracing (void) |
|---|
| 129 | { |
|---|
| 130 | if (eventlog_enabled) { |
|---|
| 131 | endEventLogging(); |
|---|
| 132 | } |
|---|
| 133 | } |
|---|
| 134 | |
|---|
| 135 | void freeTracing (void) |
|---|
| 136 | { |
|---|
| 137 | if (eventlog_enabled) { |
|---|
| 138 | freeEventLogging(); |
|---|
| 139 | } |
|---|
| 140 | } |
|---|
| 141 | |
|---|
| 142 | void resetTracing (void) |
|---|
| 143 | { |
|---|
| 144 | if (eventlog_enabled) { |
|---|
| 145 | abortEventLogging(); // abort eventlog inherited from parent |
|---|
| 146 | initEventLogging(); // child starts its own eventlog |
|---|
| 147 | } |
|---|
| 148 | } |
|---|
| 149 | |
|---|
| 150 | void tracingAddCapapilities (nat from, nat to) |
|---|
| 151 | { |
|---|
| 152 | if (eventlog_enabled) { |
|---|
| 153 | moreCapEventBufs(from,to); |
|---|
| 154 | } |
|---|
| 155 | } |
|---|
| 156 | |
|---|
| 157 | /* --------------------------------------------------------------------------- |
|---|
| 158 | Emitting trace messages/events |
|---|
| 159 | --------------------------------------------------------------------------- */ |
|---|
| 160 | |
|---|
| 161 | #ifdef DEBUG |
|---|
| 162 | static void tracePreface (void) |
|---|
| 163 | { |
|---|
| 164 | #ifdef THREADED_RTS |
|---|
| 165 | debugBelch("%12lx: ", (unsigned long)osThreadId()); |
|---|
| 166 | #endif |
|---|
| 167 | if (RtsFlags.TraceFlags.timestamp) { |
|---|
| 168 | debugBelch("%9" FMT_Word64 ": ", stat_getElapsedTime()); |
|---|
| 169 | } |
|---|
| 170 | } |
|---|
| 171 | #endif |
|---|
| 172 | |
|---|
| 173 | #ifdef DEBUG |
|---|
| 174 | static char *thread_stop_reasons[] = { |
|---|
| 175 | [HeapOverflow] = "heap overflow", |
|---|
| 176 | [StackOverflow] = "stack overflow", |
|---|
| 177 | [ThreadYielding] = "yielding", |
|---|
| 178 | [ThreadBlocked] = "blocked", |
|---|
| 179 | [ThreadFinished] = "finished", |
|---|
| 180 | [THREAD_SUSPENDED_FOREIGN_CALL] = "suspended while making a foreign call", |
|---|
| 181 | [6 + BlockedOnMVar] = "blocked on an MVar", |
|---|
| 182 | [6 + BlockedOnBlackHole] = "blocked on a black hole", |
|---|
| 183 | [6 + BlockedOnRead] = "blocked on a read operation", |
|---|
| 184 | [6 + BlockedOnWrite] = "blocked on a write operation", |
|---|
| 185 | [6 + BlockedOnDelay] = "blocked on a delay operation", |
|---|
| 186 | [6 + BlockedOnSTM] = "blocked on STM", |
|---|
| 187 | [6 + BlockedOnDoProc] = "blocked on asyncDoProc", |
|---|
| 188 | [6 + BlockedOnCCall] = "blocked on a foreign call", |
|---|
| 189 | [6 + BlockedOnCCall_Interruptible] = "blocked on a foreign call (interruptible)", |
|---|
| 190 | [6 + BlockedOnMsgThrowTo] = "blocked on throwTo", |
|---|
| 191 | [6 + ThreadMigrating] = "migrating" |
|---|
| 192 | }; |
|---|
| 193 | #endif |
|---|
| 194 | |
|---|
| 195 | #ifdef DEBUG |
|---|
| 196 | static void traceSchedEvent_stderr (Capability *cap, EventTypeNum tag, |
|---|
| 197 | StgTSO *tso, |
|---|
| 198 | StgWord info1 STG_UNUSED, |
|---|
| 199 | StgWord info2 STG_UNUSED) |
|---|
| 200 | { |
|---|
| 201 | ACQUIRE_LOCK(&trace_utx); |
|---|
| 202 | |
|---|
| 203 | tracePreface(); |
|---|
| 204 | switch (tag) { |
|---|
| 205 | case EVENT_CREATE_THREAD: // (cap, thread) |
|---|
| 206 | debugBelch("cap %d: created thread %" FMT_SizeT "\n", |
|---|
| 207 | cap->no, (lnat)tso->id); |
|---|
| 208 | break; |
|---|
| 209 | case EVENT_RUN_THREAD: // (cap, thread) |
|---|
| 210 | debugBelch("cap %d: running thread %" FMT_SizeT " (%s)\n", |
|---|
| 211 | cap->no, (lnat)tso->id, what_next_strs[tso->what_next]); |
|---|
| 212 | break; |
|---|
| 213 | case EVENT_THREAD_RUNNABLE: // (cap, thread) |
|---|
| 214 | debugBelch("cap %d: thread %" FMT_SizeT " appended to run queue\n", |
|---|
| 215 | cap->no, (lnat)tso->id); |
|---|
| 216 | break; |
|---|
| 217 | case EVENT_MIGRATE_THREAD: // (cap, thread, new_cap) |
|---|
| 218 | debugBelch("cap %d: thread %" FMT_SizeT " migrating to cap %d\n", |
|---|
| 219 | cap->no, (lnat)tso->id, (int)info1); |
|---|
| 220 | break; |
|---|
| 221 | case EVENT_THREAD_WAKEUP: // (cap, thread, info1_cap) |
|---|
| 222 | debugBelch("cap %d: waking up thread %" FMT_SizeT " on cap %d\n", |
|---|
| 223 | cap->no, (lnat)tso->id, (int)info1); |
|---|
| 224 | break; |
|---|
| 225 | |
|---|
| 226 | case EVENT_STOP_THREAD: // (cap, thread, status) |
|---|
| 227 | if (info1 == 6 + BlockedOnBlackHole) { |
|---|
| 228 | debugBelch("cap %d: thread %" FMT_SizeT " stopped (blocked on black hole owned by thread %lu)\n", |
|---|
| 229 | cap->no, (lnat)tso->id, (long)info2); |
|---|
| 230 | } else { |
|---|
| 231 | debugBelch("cap %d: thread %" FMT_SizeT " stopped (%s)\n", |
|---|
| 232 | cap->no, (lnat)tso->id, thread_stop_reasons[info1]); |
|---|
| 233 | } |
|---|
| 234 | break; |
|---|
| 235 | default: |
|---|
| 236 | debugBelch("cap %d: thread %" FMT_SizeT ": event %d\n\n", |
|---|
| 237 | cap->no, (lnat)tso->id, tag); |
|---|
| 238 | break; |
|---|
| 239 | } |
|---|
| 240 | |
|---|
| 241 | RELEASE_LOCK(&trace_utx); |
|---|
| 242 | } |
|---|
| 243 | #endif |
|---|
| 244 | |
|---|
| 245 | void traceSchedEvent_ (Capability *cap, EventTypeNum tag, |
|---|
| 246 | StgTSO *tso, StgWord info1, StgWord info2) |
|---|
| 247 | { |
|---|
| 248 | #ifdef DEBUG |
|---|
| 249 | if (RtsFlags.TraceFlags.tracing == TRACE_STDERR) { |
|---|
| 250 | traceSchedEvent_stderr(cap, tag, tso, info1, info2); |
|---|
| 251 | } else |
|---|
| 252 | #endif |
|---|
| 253 | { |
|---|
| 254 | postSchedEvent(cap,tag,tso ? tso->id : 0, info1, info2); |
|---|
| 255 | } |
|---|
| 256 | } |
|---|
| 257 | |
|---|
| 258 | #ifdef DEBUG |
|---|
| 259 | static void traceGcEvent_stderr (Capability *cap, EventTypeNum tag) |
|---|
| 260 | { |
|---|
| 261 | ACQUIRE_LOCK(&trace_utx); |
|---|
| 262 | |
|---|
| 263 | tracePreface(); |
|---|
| 264 | switch (tag) { |
|---|
| 265 | case EVENT_REQUEST_SEQ_GC: // (cap) |
|---|
| 266 | debugBelch("cap %d: requesting sequential GC\n", cap->no); |
|---|
| 267 | break; |
|---|
| 268 | case EVENT_REQUEST_PAR_GC: // (cap) |
|---|
| 269 | debugBelch("cap %d: requesting parallel GC\n", cap->no); |
|---|
| 270 | break; |
|---|
| 271 | case EVENT_GC_START: // (cap) |
|---|
| 272 | debugBelch("cap %d: starting GC\n", cap->no); |
|---|
| 273 | break; |
|---|
| 274 | case EVENT_GC_END: // (cap) |
|---|
| 275 | debugBelch("cap %d: finished GC\n", cap->no); |
|---|
| 276 | break; |
|---|
| 277 | case EVENT_GC_IDLE: // (cap) |
|---|
| 278 | debugBelch("cap %d: GC idle\n", cap->no); |
|---|
| 279 | break; |
|---|
| 280 | case EVENT_GC_WORK: // (cap) |
|---|
| 281 | debugBelch("cap %d: GC working\n", cap->no); |
|---|
| 282 | break; |
|---|
| 283 | case EVENT_GC_DONE: // (cap) |
|---|
| 284 | debugBelch("cap %d: GC done\n", cap->no); |
|---|
| 285 | break; |
|---|
| 286 | case EVENT_GC_GLOBAL_SYNC: // (cap) |
|---|
| 287 | debugBelch("cap %d: all caps stopped for GC\n", cap->no); |
|---|
| 288 | break; |
|---|
| 289 | default: |
|---|
| 290 | barf("traceGcEvent: unknown event tag %d", tag); |
|---|
| 291 | break; |
|---|
| 292 | } |
|---|
| 293 | |
|---|
| 294 | RELEASE_LOCK(&trace_utx); |
|---|
| 295 | } |
|---|
| 296 | #endif |
|---|
| 297 | |
|---|
| 298 | void traceGcEvent_ (Capability *cap, EventTypeNum tag) |
|---|
| 299 | { |
|---|
| 300 | #ifdef DEBUG |
|---|
| 301 | if (RtsFlags.TraceFlags.tracing == TRACE_STDERR) { |
|---|
| 302 | traceGcEvent_stderr(cap, tag); |
|---|
| 303 | } else |
|---|
| 304 | #endif |
|---|
| 305 | { |
|---|
| 306 | /* currently all GC events are nullary events */ |
|---|
| 307 | postEvent(cap, tag); |
|---|
| 308 | } |
|---|
| 309 | } |
|---|
| 310 | |
|---|
| 311 | void traceGcEventAtT_ (Capability *cap, StgWord64 ts, EventTypeNum tag) |
|---|
| 312 | { |
|---|
| 313 | #ifdef DEBUG |
|---|
| 314 | if (RtsFlags.TraceFlags.tracing == TRACE_STDERR) { |
|---|
| 315 | traceGcEvent_stderr(cap, tag); |
|---|
| 316 | } else |
|---|
| 317 | #endif |
|---|
| 318 | { |
|---|
| 319 | /* assuming nullary events and explicitly inserting a timestamp */ |
|---|
| 320 | postEventAtTimestamp(cap, ts, tag); |
|---|
| 321 | } |
|---|
| 322 | } |
|---|
| 323 | |
|---|
| 324 | void traceHeapEvent_ (Capability *cap, |
|---|
| 325 | EventTypeNum tag, |
|---|
| 326 | CapsetID heap_capset, |
|---|
| 327 | lnat info1) |
|---|
| 328 | { |
|---|
| 329 | #ifdef DEBUG |
|---|
| 330 | if (RtsFlags.TraceFlags.tracing == TRACE_STDERR) { |
|---|
| 331 | /* no stderr equivalent for these ones */ |
|---|
| 332 | } else |
|---|
| 333 | #endif |
|---|
| 334 | { |
|---|
| 335 | postHeapEvent(cap, tag, heap_capset, info1); |
|---|
| 336 | } |
|---|
| 337 | } |
|---|
| 338 | |
|---|
| 339 | void traceEventHeapInfo_ (CapsetID heap_capset, |
|---|
| 340 | nat gens, |
|---|
| 341 | lnat maxHeapSize, |
|---|
| 342 | lnat allocAreaSize, |
|---|
| 343 | lnat mblockSize, |
|---|
| 344 | lnat blockSize) |
|---|
| 345 | { |
|---|
| 346 | #ifdef DEBUG |
|---|
| 347 | if (RtsFlags.TraceFlags.tracing == TRACE_STDERR) { |
|---|
| 348 | /* no stderr equivalent for these ones */ |
|---|
| 349 | } else |
|---|
| 350 | #endif |
|---|
| 351 | { |
|---|
| 352 | postEventHeapInfo(heap_capset, gens, |
|---|
| 353 | maxHeapSize, allocAreaSize, |
|---|
| 354 | mblockSize, blockSize); |
|---|
| 355 | } |
|---|
| 356 | } |
|---|
| 357 | |
|---|
| 358 | void traceEventGcStats_ (Capability *cap, |
|---|
| 359 | CapsetID heap_capset, |
|---|
| 360 | nat gen, |
|---|
| 361 | lnat copied, |
|---|
| 362 | lnat slop, |
|---|
| 363 | lnat fragmentation, |
|---|
| 364 | nat par_n_threads, |
|---|
| 365 | lnat par_max_copied, |
|---|
| 366 | lnat par_tot_copied) |
|---|
| 367 | { |
|---|
| 368 | #ifdef DEBUG |
|---|
| 369 | if (RtsFlags.TraceFlags.tracing == TRACE_STDERR) { |
|---|
| 370 | /* no stderr equivalent for these ones */ |
|---|
| 371 | } else |
|---|
| 372 | #endif |
|---|
| 373 | { |
|---|
| 374 | postEventGcStats(cap, heap_capset, gen, |
|---|
| 375 | copied, slop, fragmentation, |
|---|
| 376 | par_n_threads, par_max_copied, par_tot_copied); |
|---|
| 377 | } |
|---|
| 378 | } |
|---|
| 379 | |
|---|
| 380 | void traceCapEvent (Capability *cap, |
|---|
| 381 | EventTypeNum tag) |
|---|
| 382 | { |
|---|
| 383 | #ifdef DEBUG |
|---|
| 384 | if (RtsFlags.TraceFlags.tracing == TRACE_STDERR) { |
|---|
| 385 | ACQUIRE_LOCK(&trace_utx); |
|---|
| 386 | |
|---|
| 387 | tracePreface(); |
|---|
| 388 | switch (tag) { |
|---|
| 389 | case EVENT_CAP_CREATE: // (cap) |
|---|
| 390 | debugBelch("cap %d: initialised\n", cap->no); |
|---|
| 391 | break; |
|---|
| 392 | case EVENT_CAP_DELETE: // (cap) |
|---|
| 393 | debugBelch("cap %d: shutting down\n", cap->no); |
|---|
| 394 | break; |
|---|
| 395 | case EVENT_CAP_ENABLE: // (cap) |
|---|
| 396 | debugBelch("cap %d: enabling capability\n", cap->no); |
|---|
| 397 | break; |
|---|
| 398 | case EVENT_CAP_DISABLE: // (cap) |
|---|
| 399 | debugBelch("cap %d: disabling capability\n", cap->no); |
|---|
| 400 | break; |
|---|
| 401 | } |
|---|
| 402 | RELEASE_LOCK(&trace_utx); |
|---|
| 403 | } else |
|---|
| 404 | #endif |
|---|
| 405 | { |
|---|
| 406 | if (eventlog_enabled) { |
|---|
| 407 | postCapEvent(tag, (EventCapNo)cap->no); |
|---|
| 408 | } |
|---|
| 409 | } |
|---|
| 410 | } |
|---|
| 411 | |
|---|
| 412 | void traceCapsetEvent (EventTypeNum tag, |
|---|
| 413 | CapsetID capset, |
|---|
| 414 | StgWord info) |
|---|
| 415 | { |
|---|
| 416 | #ifdef DEBUG |
|---|
| 417 | if (RtsFlags.TraceFlags.tracing == TRACE_STDERR && TRACE_sched) |
|---|
| 418 | // When events go to stderr, it is annoying to see the capset |
|---|
| 419 | // events every time, so we only emit them with -Ds. |
|---|
| 420 | { |
|---|
| 421 | ACQUIRE_LOCK(&trace_utx); |
|---|
| 422 | |
|---|
| 423 | tracePreface(); |
|---|
| 424 | switch (tag) { |
|---|
| 425 | case EVENT_CAPSET_CREATE: // (capset, capset_type) |
|---|
| 426 | debugBelch("created capset %" FMT_SizeT " of type %d\n", (lnat)capset, (int)info); |
|---|
| 427 | break; |
|---|
| 428 | case EVENT_CAPSET_DELETE: // (capset) |
|---|
| 429 | debugBelch("deleted capset %" FMT_SizeT "\n", (lnat)capset); |
|---|
| 430 | break; |
|---|
| 431 | case EVENT_CAPSET_ASSIGN_CAP: // (capset, capno) |
|---|
| 432 | debugBelch("assigned cap %" FMT_SizeT " to capset %" FMT_SizeT "\n", |
|---|
| 433 | (lnat)info, (lnat)capset); |
|---|
| 434 | break; |
|---|
| 435 | case EVENT_CAPSET_REMOVE_CAP: // (capset, capno) |
|---|
| 436 | debugBelch("removed cap %" FMT_SizeT " from capset %" FMT_SizeT "\n", |
|---|
| 437 | (lnat)info, (lnat)capset); |
|---|
| 438 | break; |
|---|
| 439 | } |
|---|
| 440 | RELEASE_LOCK(&trace_utx); |
|---|
| 441 | } else |
|---|
| 442 | #endif |
|---|
| 443 | { |
|---|
| 444 | if (eventlog_enabled) { |
|---|
| 445 | postCapsetEvent(tag, capset, info); |
|---|
| 446 | } |
|---|
| 447 | } |
|---|
| 448 | } |
|---|
| 449 | |
|---|
| 450 | void traceWallClockTime_(void) { |
|---|
| 451 | if (eventlog_enabled) { |
|---|
| 452 | postWallClockTime(CAPSET_CLOCKDOMAIN_DEFAULT); |
|---|
| 453 | } |
|---|
| 454 | } |
|---|
| 455 | |
|---|
| 456 | void traceOSProcessInfo_(void) { |
|---|
| 457 | if (eventlog_enabled) { |
|---|
| 458 | postCapsetEvent(EVENT_OSPROCESS_PID, |
|---|
| 459 | CAPSET_OSPROCESS_DEFAULT, |
|---|
| 460 | getpid()); |
|---|
| 461 | |
|---|
| 462 | #if !defined(cygwin32_HOST_OS) && !defined (mingw32_HOST_OS) |
|---|
| 463 | /* Windows has no strong concept of process heirarchy, so no getppid(). |
|---|
| 464 | * In any case, this trace event is mainly useful for tracing programs |
|---|
| 465 | * that use 'forkProcess' which Windows doesn't support anyway. |
|---|
| 466 | */ |
|---|
| 467 | postCapsetEvent(EVENT_OSPROCESS_PPID, |
|---|
| 468 | CAPSET_OSPROCESS_DEFAULT, |
|---|
| 469 | getppid()); |
|---|
| 470 | #endif |
|---|
| 471 | { |
|---|
| 472 | char buf[256]; |
|---|
| 473 | snprintf(buf, sizeof(buf), "GHC-%s %s", ProjectVersion, RtsWay); |
|---|
| 474 | postCapsetStrEvent(EVENT_RTS_IDENTIFIER, |
|---|
| 475 | CAPSET_OSPROCESS_DEFAULT, |
|---|
| 476 | buf); |
|---|
| 477 | } |
|---|
| 478 | { |
|---|
| 479 | int argc = 0; char **argv; |
|---|
| 480 | getFullProgArgv(&argc, &argv); |
|---|
| 481 | if (argc != 0) { |
|---|
| 482 | postCapsetVecEvent(EVENT_PROGRAM_ARGS, |
|---|
| 483 | CAPSET_OSPROCESS_DEFAULT, |
|---|
| 484 | argc, argv); |
|---|
| 485 | } |
|---|
| 486 | } |
|---|
| 487 | { |
|---|
| 488 | int envc = 0; char **envv; |
|---|
| 489 | getProgEnvv(&envc, &envv); |
|---|
| 490 | if (envc != 0) { |
|---|
| 491 | postCapsetVecEvent(EVENT_PROGRAM_ENV, |
|---|
| 492 | CAPSET_OSPROCESS_DEFAULT, |
|---|
| 493 | envc, envv); |
|---|
| 494 | } |
|---|
| 495 | freeProgEnvv(envc, envv); |
|---|
| 496 | } |
|---|
| 497 | } |
|---|
| 498 | } |
|---|
| 499 | |
|---|
| 500 | #ifdef DEBUG |
|---|
| 501 | static void traceSparkEvent_stderr (Capability *cap, EventTypeNum tag, |
|---|
| 502 | StgWord info1) |
|---|
| 503 | { |
|---|
| 504 | ACQUIRE_LOCK(&trace_utx); |
|---|
| 505 | |
|---|
| 506 | tracePreface(); |
|---|
| 507 | switch (tag) { |
|---|
| 508 | |
|---|
| 509 | case EVENT_CREATE_SPARK_THREAD: // (cap, spark_thread) |
|---|
| 510 | debugBelch("cap %d: creating spark thread %lu\n", |
|---|
| 511 | cap->no, (long)info1); |
|---|
| 512 | break; |
|---|
| 513 | case EVENT_SPARK_CREATE: // (cap) |
|---|
| 514 | debugBelch("cap %d: added spark to pool\n", |
|---|
| 515 | cap->no); |
|---|
| 516 | break; |
|---|
| 517 | case EVENT_SPARK_DUD: // (cap) |
|---|
| 518 | debugBelch("cap %d: discarded dud spark\n", |
|---|
| 519 | cap->no); |
|---|
| 520 | break; |
|---|
| 521 | case EVENT_SPARK_OVERFLOW: // (cap) |
|---|
| 522 | debugBelch("cap %d: discarded overflowed spark\n", |
|---|
| 523 | cap->no); |
|---|
| 524 | break; |
|---|
| 525 | case EVENT_SPARK_RUN: // (cap) |
|---|
| 526 | debugBelch("cap %d: running a spark\n", |
|---|
| 527 | cap->no); |
|---|
| 528 | break; |
|---|
| 529 | case EVENT_SPARK_STEAL: // (cap, victim_cap) |
|---|
| 530 | debugBelch("cap %d: stealing a spark from cap %d\n", |
|---|
| 531 | cap->no, (int)info1); |
|---|
| 532 | break; |
|---|
| 533 | case EVENT_SPARK_FIZZLE: // (cap) |
|---|
| 534 | debugBelch("cap %d: fizzled spark removed from pool\n", |
|---|
| 535 | cap->no); |
|---|
| 536 | break; |
|---|
| 537 | case EVENT_SPARK_GC: // (cap) |
|---|
| 538 | debugBelch("cap %d: GCd spark removed from pool\n", |
|---|
| 539 | cap->no); |
|---|
| 540 | break; |
|---|
| 541 | default: |
|---|
| 542 | barf("traceSparkEvent: unknown event tag %d", tag); |
|---|
| 543 | break; |
|---|
| 544 | } |
|---|
| 545 | |
|---|
| 546 | RELEASE_LOCK(&trace_utx); |
|---|
| 547 | } |
|---|
| 548 | #endif |
|---|
| 549 | |
|---|
| 550 | void traceSparkEvent_ (Capability *cap, EventTypeNum tag, StgWord info1) |
|---|
| 551 | { |
|---|
| 552 | #ifdef DEBUG |
|---|
| 553 | if (RtsFlags.TraceFlags.tracing == TRACE_STDERR) { |
|---|
| 554 | traceSparkEvent_stderr(cap, tag, info1); |
|---|
| 555 | } else |
|---|
| 556 | #endif |
|---|
| 557 | { |
|---|
| 558 | postSparkEvent(cap,tag,info1); |
|---|
| 559 | } |
|---|
| 560 | } |
|---|
| 561 | |
|---|
| 562 | void traceSparkCounters_ (Capability *cap, |
|---|
| 563 | SparkCounters counters, |
|---|
| 564 | StgWord remaining) |
|---|
| 565 | { |
|---|
| 566 | #ifdef DEBUG |
|---|
| 567 | if (RtsFlags.TraceFlags.tracing == TRACE_STDERR) { |
|---|
| 568 | /* we currently don't do debug tracing of spark stats but we must |
|---|
| 569 | test for TRACE_STDERR because of the !eventlog_enabled case. */ |
|---|
| 570 | } else |
|---|
| 571 | #endif |
|---|
| 572 | { |
|---|
| 573 | postSparkCountersEvent(cap, counters, remaining); |
|---|
| 574 | } |
|---|
| 575 | } |
|---|
| 576 | |
|---|
| 577 | #ifdef DEBUG |
|---|
| 578 | static void traceCap_stderr(Capability *cap, char *msg, va_list ap) |
|---|
| 579 | { |
|---|
| 580 | ACQUIRE_LOCK(&trace_utx); |
|---|
| 581 | |
|---|
| 582 | tracePreface(); |
|---|
| 583 | debugBelch("cap %d: ", cap->no); |
|---|
| 584 | vdebugBelch(msg,ap); |
|---|
| 585 | debugBelch("\n"); |
|---|
| 586 | |
|---|
| 587 | RELEASE_LOCK(&trace_utx); |
|---|
| 588 | } |
|---|
| 589 | #endif |
|---|
| 590 | |
|---|
| 591 | void traceCap_(Capability *cap, char *msg, ...) |
|---|
| 592 | { |
|---|
| 593 | va_list ap; |
|---|
| 594 | va_start(ap,msg); |
|---|
| 595 | |
|---|
| 596 | #ifdef DEBUG |
|---|
| 597 | if (RtsFlags.TraceFlags.tracing == TRACE_STDERR) { |
|---|
| 598 | traceCap_stderr(cap, msg, ap); |
|---|
| 599 | } else |
|---|
| 600 | #endif |
|---|
| 601 | { |
|---|
| 602 | postCapMsg(cap, msg, ap); |
|---|
| 603 | } |
|---|
| 604 | |
|---|
| 605 | va_end(ap); |
|---|
| 606 | } |
|---|
| 607 | |
|---|
| 608 | #ifdef DEBUG |
|---|
| 609 | static void trace_stderr(char *msg, va_list ap) |
|---|
| 610 | { |
|---|
| 611 | ACQUIRE_LOCK(&trace_utx); |
|---|
| 612 | |
|---|
| 613 | tracePreface(); |
|---|
| 614 | vdebugBelch(msg,ap); |
|---|
| 615 | debugBelch("\n"); |
|---|
| 616 | |
|---|
| 617 | RELEASE_LOCK(&trace_utx); |
|---|
| 618 | } |
|---|
| 619 | #endif |
|---|
| 620 | |
|---|
| 621 | void trace_(char *msg, ...) |
|---|
| 622 | { |
|---|
| 623 | va_list ap; |
|---|
| 624 | va_start(ap,msg); |
|---|
| 625 | |
|---|
| 626 | #ifdef DEBUG |
|---|
| 627 | if (RtsFlags.TraceFlags.tracing == TRACE_STDERR) { |
|---|
| 628 | trace_stderr(msg, ap); |
|---|
| 629 | } else |
|---|
| 630 | #endif |
|---|
| 631 | { |
|---|
| 632 | postMsg(msg, ap); |
|---|
| 633 | } |
|---|
| 634 | |
|---|
| 635 | va_end(ap); |
|---|
| 636 | } |
|---|
| 637 | |
|---|
| 638 | static void traceFormatUserMsg(Capability *cap, char *msg, ...) |
|---|
| 639 | { |
|---|
| 640 | va_list ap; |
|---|
| 641 | va_start(ap,msg); |
|---|
| 642 | |
|---|
| 643 | /* Note: normally we don't check the TRACE_* flags here as they're checked |
|---|
| 644 | by the wrappers in Trace.h. But traceUserMsg is special since it has no |
|---|
| 645 | wrapper (it's called from cmm code), so we check TRACE_user here |
|---|
| 646 | */ |
|---|
| 647 | #ifdef DEBUG |
|---|
| 648 | if (RtsFlags.TraceFlags.tracing == TRACE_STDERR && TRACE_user) { |
|---|
| 649 | traceCap_stderr(cap, msg, ap); |
|---|
| 650 | } else |
|---|
| 651 | #endif |
|---|
| 652 | { |
|---|
| 653 | if (eventlog_enabled && TRACE_user) { |
|---|
| 654 | postUserMsg(cap, msg, ap); |
|---|
| 655 | } |
|---|
| 656 | } |
|---|
| 657 | dtraceUserMsg(cap->no, msg); |
|---|
| 658 | } |
|---|
| 659 | |
|---|
| 660 | void traceUserMsg(Capability *cap, char *msg) |
|---|
| 661 | { |
|---|
| 662 | traceFormatUserMsg(cap, "%s", msg); |
|---|
| 663 | } |
|---|
| 664 | |
|---|
| 665 | void traceThreadLabel_(Capability *cap, |
|---|
| 666 | StgTSO *tso, |
|---|
| 667 | char *label) |
|---|
| 668 | { |
|---|
| 669 | #ifdef DEBUG |
|---|
| 670 | if (RtsFlags.TraceFlags.tracing == TRACE_STDERR) { |
|---|
| 671 | ACQUIRE_LOCK(&trace_utx); |
|---|
| 672 | tracePreface(); |
|---|
| 673 | debugBelch("cap %d: thread %" FMT_SizeT " has label %s\n", |
|---|
| 674 | cap->no, (lnat)tso->id, label); |
|---|
| 675 | RELEASE_LOCK(&trace_utx); |
|---|
| 676 | } else |
|---|
| 677 | #endif |
|---|
| 678 | { |
|---|
| 679 | postThreadLabel(cap, tso->id, label); |
|---|
| 680 | } |
|---|
| 681 | } |
|---|
| 682 | |
|---|
| 683 | void traceThreadStatus_ (StgTSO *tso USED_IF_DEBUG) |
|---|
| 684 | { |
|---|
| 685 | #ifdef DEBUG |
|---|
| 686 | if (RtsFlags.TraceFlags.tracing == TRACE_STDERR) { |
|---|
| 687 | printThreadStatus(tso); |
|---|
| 688 | } else |
|---|
| 689 | #endif |
|---|
| 690 | { |
|---|
| 691 | /* nothing - no event for this one yet */ |
|---|
| 692 | } |
|---|
| 693 | } |
|---|
| 694 | |
|---|
| 695 | void traceEventStartup_(int nocaps) |
|---|
| 696 | { |
|---|
| 697 | if (eventlog_enabled) { |
|---|
| 698 | postEventStartup(nocaps); |
|---|
| 699 | } |
|---|
| 700 | } |
|---|
| 701 | |
|---|
| 702 | #ifdef DEBUG |
|---|
| 703 | void traceBegin (const char *str, ...) |
|---|
| 704 | { |
|---|
| 705 | va_list ap; |
|---|
| 706 | va_start(ap,str); |
|---|
| 707 | |
|---|
| 708 | ACQUIRE_LOCK(&trace_utx); |
|---|
| 709 | |
|---|
| 710 | tracePreface(); |
|---|
| 711 | vdebugBelch(str,ap); |
|---|
| 712 | } |
|---|
| 713 | |
|---|
| 714 | void traceEnd (void) |
|---|
| 715 | { |
|---|
| 716 | debugBelch("\n"); |
|---|
| 717 | RELEASE_LOCK(&trace_utx); |
|---|
| 718 | } |
|---|
| 719 | #endif /* DEBUG */ |
|---|
| 720 | |
|---|
| 721 | #endif /* TRACING */ |
|---|
| 722 | |
|---|
| 723 | // If DTRACE is enabled, but neither DEBUG nor TRACING, we need a C land |
|---|
| 724 | // wrapper for the user-msg probe (as we can't expand that in PrimOps.cmm) |
|---|
| 725 | // |
|---|
| 726 | #if !defined(DEBUG) && !defined(TRACING) && defined(DTRACE) |
|---|
| 727 | |
|---|
| 728 | void dtraceUserMsgWrapper(Capability *cap, char *msg) |
|---|
| 729 | { |
|---|
| 730 | dtraceUserMsg(cap->no, msg); |
|---|
| 731 | } |
|---|
| 732 | |
|---|
| 733 | #endif /* !defined(DEBUG) && !defined(TRACING) && defined(DTRACE) */ |
|---|