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