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 */