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 %lu\n",
 116                    cap->no, (lnat)tso->id);
 117         break;
 118     case EVENT_RUN_THREAD:      //  (cap, thread)
 119         debugBelch("cap %d: running thread %lu (%s)\n",
 120                    cap->no, (lnat)tso->id, what_next_strs[tso->what_next]);
 121         break;
 122     case EVENT_THREAD_RUNNABLE: // (cap, thread)
 123         debugBelch("cap %d: thread %lu appended to run queue\n",
 124                    cap->no, (lnat)tso->id);
 125         break;
 126     case EVENT_RUN_SPARK:       // (cap, thread)
 127         debugBelch("cap %d: thread %lu running a spark\n",
 128                    cap->no, (lnat)tso->id);
 129         break;
 130     case EVENT_CREATE_SPARK_THREAD: // (cap, spark_thread)
 131         debugBelch("cap %d: creating spark thread %lu\n",
 132                    cap->no, (long)other);
 133         break;
 134     case EVENT_MIGRATE_THREAD:  // (cap, thread, new_cap)
 135         debugBelch("cap %d: thread %lu migrating to cap %d\n",
 136                    cap->no, (lnat)tso->id, (int)other);
 137         break;
 138     case EVENT_STEAL_SPARK:     // (cap, thread, victim_cap)
 139         debugBelch("cap %d: thread %lu stealing a spark from cap %d\n",
 140                    cap->no, (lnat)tso->id, (int)other);
 141         break;
 142     case EVENT_THREAD_WAKEUP:   // (cap, thread, other_cap)
 143         debugBelch("cap %d: waking up thread %lu on cap %d\n",
 144                    cap->no, (lnat)tso->id, (int)other);
 145         break;
 146
 147     case EVENT_STOP_THREAD:     // (cap, thread, status)
 148         debugBelch("cap %d: thread %lu stopped (%s)\n",
 149                    cap->no, (lnat)tso->id, thread_stop_reasons[other]);
 150         break;
 151     case EVENT_SHUTDOWN:        // (cap)
 152         debugBelch("cap %d: shutting down\n", cap->no);
 153         break;
 154     case EVENT_REQUEST_SEQ_GC:  // (cap)
 155         debugBelch("cap %d: requesting sequential GC\n", cap->no);
 156         break;
 157     case EVENT_REQUEST_PAR_GC:  // (cap)
 158         debugBelch("cap %d: requesting parallel GC\n", cap->no);
 159         break;
 160     case EVENT_GC_START:        // (cap)
 161         debugBelch("cap %d: starting GC\n", cap->no);
 162         break;
 163     case EVENT_GC_END:          // (cap)
 164         debugBelch("cap %d: finished GC\n", cap->no);
 165         break;
 166     default:
 167         debugBelch("cap %2d: thread %lu: event %d\n\n",
 168                    cap->no, (lnat)tso->id, tag);
 169         break;
 170     }
 171
 172     RELEASE_LOCK(&trace_utx);
 173 }
 174 #endif
 175
 176 void traceSchedEvent_ (Capability *cap, EventTypeNum tag,
 177                       StgTSO *tso, StgWord64 other)
 178 {
 179 #ifdef DEBUG
 180     if (RtsFlags.TraceFlags.trace_stderr) {
 181         traceSchedEvent_stderr(cap, tag, tso, other);
 182     } else
 183 #endif
 184     {
 185         postSchedEvent(cap,tag,tso ? tso->id : 0,other);
 186     }
 187 }
 188
 189 #ifdef DEBUG
 190 static void traceCap_stderr(Capability *cap, char *msg, va_list ap)
 191 {
 192     ACQUIRE_LOCK(&trace_utx);
 193
 194     tracePreface();
 195     debugBelch("cap %2d: ", cap->no);
 196     vdebugBelch(msg,ap);
 197     debugBelch("\n");
 198
 199     RELEASE_LOCK(&trace_utx);
 200 }
 201 #endif
 202
 203 void traceCap_(Capability *cap, char *msg, va_list ap)
 204 {
 205 #ifdef DEBUG
 206     if (RtsFlags.TraceFlags.trace_stderr) {
 207         traceCap_stderr(cap, msg, ap);
 208     } else
 209 #endif
 210     {
 211         postCapMsg(cap, msg, ap);
 212     }
 213 }
 214
 215 #ifdef DEBUG
 216 static void trace_stderr(char *msg, va_list ap)
 217 {
 218     ACQUIRE_LOCK(&trace_utx);
 219
 220     tracePreface();
 221     vdebugBelch(msg,ap);
 222     debugBelch("\n");
 223
 224     RELEASE_LOCK(&trace_utx);
 225 }
 226 #endif
 227
 228 void trace_(char *msg, va_list ap)
 229 {
 230 #ifdef DEBUG
 231     if (RtsFlags.TraceFlags.trace_stderr) {
 232         trace_stderr(msg, ap);
 233     } else
 234 #endif
 235     {
 236         postMsg(msg, ap);
 237     }
 238 }
 239
 240 void traceThreadStatus_ (StgTSO *tso USED_IF_DEBUG)
 241 {
 242 #ifdef DEBUG
 243     if (RtsFlags.TraceFlags.trace_stderr) {
 244         printThreadStatus(tso);
 245     } else
 246 #endif
 247     {
 248         /* nothing - no event for this one yet */
 249     }
 250 }
 251
 252
 253 #ifdef DEBUG
 254 void traceBegin (const char *str, ...)
 255 {
 256     va_list ap;
 257     va_start(ap,str);
 258
 259     ACQUIRE_LOCK(&trace_utx);
 260
 261     tracePreface();
 262     vdebugBelch(str,ap);
 263 }
 264
 265 void traceEnd (void)
 266 {
 267     debugBelch("\n");
 268     RELEASE_LOCK(&trace_utx);
 269 }
 270 #endif /* DEBUG */
 271
 272 #endif /* TRACING */