UNREG: use __builtin___clear_cache where available
[ghc.git] / rts / Trace.c
index 7f70957..8978e27 100644 (file)
 // internal headers
 #include "Trace.h"
 
-#ifdef TRACING
+#if defined(TRACING)
 
 #include "GetTime.h"
 #include "GetEnv.h"
 #include "Stats.h"
 #include "eventlog/EventLog.h"
+#include "rts/EventLogWriter.h"
 #include "Threads.h"
 #include "Printer.h"
+#include "RtsFlags.h"
 
-#ifdef HAVE_UNISTD_H
+#if defined(HAVE_UNISTD_H)
 #include <unistd.h>
 #endif
 
-#ifdef DEBUG
-// debugging flags, set with +RTS -D<something>
-int DEBUG_sched;
-int DEBUG_interp;
-int DEBUG_weak;
-int DEBUG_gccafs;
-int DEBUG_gc;
-int DEBUG_block_alloc;
-int DEBUG_sanity;
-int DEBUG_stable;
-int DEBUG_stm;
-int DEBUG_prof;
-int DEBUG_gran;
-int DEBUG_par;
-int DEBUG_linker;
-int DEBUG_squeeze;
-int DEBUG_hpc;
-int DEBUG_sparks;
-#endif
-
 // events
 int TRACE_sched;
 int TRACE_gc;
-int TRACE_spark;
+int TRACE_spark_sampled;
+int TRACE_spark_full;
+int TRACE_user;
+int TRACE_cap;
 
-#ifdef THREADED_RTS
+#if defined(THREADED_RTS)
 static Mutex trace_utx;
 #endif
 
-static rtsBool eventlog_enabled;
+static bool eventlog_enabled;
 
 /* ---------------------------------------------------------------------------
-   Starting up / shuttting down the tracing facilities
+   Starting up / shutting down the tracing facilities
  --------------------------------------------------------------------------- */
 
-void initTracing (void)
+static const EventLogWriter *getEventLogWriter(void)
 {
-#ifdef THREADED_RTS
-    initMutex(&trace_utx);
-#endif
-
-#ifdef DEBUG
-#define DEBUG_FLAG(name, class) \
-    class = RtsFlags.DebugFlags.name ? 1 : 0;
+    return rtsConfig.eventlog_writer;
+}
 
-    DEBUG_FLAG(scheduler,    DEBUG_sched);
+void initTracing (void)
+{
+    const EventLogWriter *eventlog_writer = getEventLogWriter();
 
-    DEBUG_FLAG(interpreter,  DEBUG_interp);
-    DEBUG_FLAG(weak,         DEBUG_weak);
-    DEBUG_FLAG(gccafs,       DEBUG_gccafs);
-    DEBUG_FLAG(gc,           DEBUG_gc);
-    DEBUG_FLAG(block_alloc,  DEBUG_block_alloc);
-    DEBUG_FLAG(sanity,       DEBUG_sanity);
-    DEBUG_FLAG(stable,       DEBUG_stable);
-    DEBUG_FLAG(stm,          DEBUG_stm);
-    DEBUG_FLAG(prof,         DEBUG_prof);
-    DEBUG_FLAG(linker,       DEBUG_linker);
-    DEBUG_FLAG(squeeze,      DEBUG_squeeze);
-    DEBUG_FLAG(hpc,          DEBUG_hpc);
-    DEBUG_FLAG(sparks,       DEBUG_sparks);
+#if defined(THREADED_RTS)
+    initMutex(&trace_utx);
 #endif
 
     // -Ds turns on scheduler tracing too
@@ -95,21 +66,40 @@ void initTracing (void)
     // -Dg turns on gc tracing too
     TRACE_gc =
         RtsFlags.TraceFlags.gc ||
-        RtsFlags.DebugFlags.gc;
+        RtsFlags.DebugFlags.gc ||
+        RtsFlags.DebugFlags.scheduler;
+    if (TRACE_gc && RtsFlags.GcFlags.giveStats == NO_GC_STATS) {
+        RtsFlags.GcFlags.giveStats = COLLECT_GC_STATS;
+    }
+
+    TRACE_spark_sampled =
+        RtsFlags.TraceFlags.sparks_sampled;
 
-    // -Dr turns on spark tracing
-    TRACE_spark =
-        RtsFlags.TraceFlags.sparks ||
+    // -Dr turns on full spark tracing
+    TRACE_spark_full =
+        RtsFlags.TraceFlags.sparks_full ||
         RtsFlags.DebugFlags.sparks;
 
-    eventlog_enabled = RtsFlags.TraceFlags.tracing == TRACE_EVENTLOG;
+    TRACE_user =
+        RtsFlags.TraceFlags.user;
+
+    // We trace cap events if we're tracing anything else
+    TRACE_cap =
+        TRACE_sched ||
+        TRACE_gc ||
+        TRACE_spark_sampled ||
+        TRACE_spark_full ||
+        TRACE_user;
 
-    /* Note: we can have TRACE_sched or TRACE_spark turned on even when
+    eventlog_enabled = RtsFlags.TraceFlags.tracing == TRACE_EVENTLOG &&
+                        eventlog_writer != NULL;
+
+    /* Note: we can have any of the TRACE_* flags turned on even when
        eventlog_enabled is off. In the DEBUG way we may be tracing to stderr.
      */
 
     if (eventlog_enabled) {
-        initEventLogging();
+        initEventLogging(eventlog_writer);
     }
 }
 
@@ -129,9 +119,21 @@ void freeTracing (void)
 
 void resetTracing (void)
 {
+    const EventLogWriter *eventlog_writer;
+    eventlog_writer = getEventLogWriter();
+
     if (eventlog_enabled) {
         abortEventLogging(); // abort eventlog inherited from parent
-        initEventLogging(); // child starts its own eventlog
+        if (eventlog_writer != NULL) {
+            initEventLogging(eventlog_writer); // child starts its own eventlog
+        }
+    }
+}
+
+void tracingAddCapapilities (uint32_t from, uint32_t to)
+{
+    if (eventlog_enabled) {
+        moreCapEventBufs(from,to);
     }
 }
 
@@ -139,19 +141,19 @@ void resetTracing (void)
    Emitting trace messages/events
  --------------------------------------------------------------------------- */
 
-#ifdef DEBUG
+#if defined(DEBUG)
 static void tracePreface (void)
 {
-#ifdef THREADED_RTS
+#if defined(THREADED_RTS)
     debugBelch("%12lx: ", (unsigned long)osThreadId());
 #endif
     if (RtsFlags.TraceFlags.timestamp) {
-       debugBelch("%9" FMT_Word64 ": ", stat_getElapsedTime());
+        debugBelch("%9" FMT_Word64 ": ", stat_getElapsedTime());
     }
 }
 #endif
 
-#ifdef DEBUG
+#if defined(DEBUG)
 static char *thread_stop_reasons[] = {
     [HeapOverflow] = "heap overflow",
     [StackOverflow] = "stack overflow",
@@ -160,6 +162,7 @@ static char *thread_stop_reasons[] = {
     [ThreadFinished] = "finished",
     [THREAD_SUSPENDED_FOREIGN_CALL] = "suspended while making a foreign call",
     [6 + BlockedOnMVar]         = "blocked on an MVar",
+    [6 + BlockedOnMVarRead]     = "blocked on an atomic MVar read",
     [6 + BlockedOnBlackHole]    = "blocked on a black hole",
     [6 + BlockedOnRead]         = "blocked on a read operation",
     [6 + BlockedOnWrite]        = "blocked on a write operation",
@@ -173,9 +176,9 @@ static char *thread_stop_reasons[] = {
 };
 #endif
 
-#ifdef DEBUG
-static void traceSchedEvent_stderr (Capability *cap, EventTypeNum tag, 
-                                    StgTSO *tso, 
+#if defined(DEBUG)
+static void traceSchedEvent_stderr (Capability *cap, EventTypeNum tag,
+                                    StgTSO *tso,
                                     StgWord info1 STG_UNUSED,
                                     StgWord info2 STG_UNUSED)
 {
@@ -184,53 +187,38 @@ static void traceSchedEvent_stderr (Capability *cap, EventTypeNum tag,
     tracePreface();
     switch (tag) {
     case EVENT_CREATE_THREAD:   // (cap, thread)
-        debugBelch("cap %d: created thread %lu\n", 
-                   cap->no, (lnat)tso->id);
+        debugBelch("cap %d: created thread %" FMT_Word "\n",
+                   cap->no, (W_)tso->id);
         break;
     case EVENT_RUN_THREAD:      //  (cap, thread)
-        debugBelch("cap %d: running thread %lu (%s)\n", 
-                   cap->no, (lnat)tso->id, what_next_strs[tso->what_next]);
+        debugBelch("cap %d: running thread %" FMT_Word " (%s)\n",
+                   cap->no, (W_)tso->id, what_next_strs[tso->what_next]);
         break;
     case EVENT_THREAD_RUNNABLE: // (cap, thread)
-        debugBelch("cap %d: thread %lu appended to run queue\n", 
-                   cap->no, (lnat)tso->id);
-        break;
-    case EVENT_RUN_SPARK:       // (cap, thread)
-        debugBelch("cap %d: thread %lu running a spark\n", 
-                   cap->no, (lnat)tso->id);
-        break;
-    case EVENT_CREATE_SPARK_THREAD: // (cap, spark_thread)
-        debugBelch("cap %d: creating spark thread %lu\n", 
-                   cap->no, (long)info1);
+        debugBelch("cap %d: thread %" FMT_Word " appended to run queue\n",
+                   cap->no, (W_)tso->id);
         break;
     case EVENT_MIGRATE_THREAD:  // (cap, thread, new_cap)
-        debugBelch("cap %d: thread %lu migrating to cap %d\n", 
-                   cap->no, (lnat)tso->id, (int)info1);
-        break;
-    case EVENT_STEAL_SPARK:     // (cap, thread, victim_cap)
-        debugBelch("cap %d: thread %lu stealing a spark from cap %d\n", 
-                   cap->no, (lnat)tso->id, (int)info1);
+        debugBelch("cap %d: thread %" FMT_Word " migrating to cap %d\n",
+                   cap->no, (W_)tso->id, (int)info1);
         break;
     case EVENT_THREAD_WAKEUP:   // (cap, thread, info1_cap)
-        debugBelch("cap %d: waking up thread %lu on cap %d\n", 
-                   cap->no, (lnat)tso->id, (int)info1);
+        debugBelch("cap %d: waking up thread %" FMT_Word " on cap %d\n",
+                   cap->no, (W_)tso->id, (int)info1);
         break;
-        
+
     case EVENT_STOP_THREAD:     // (cap, thread, status)
         if (info1 == 6 + BlockedOnBlackHole) {
-            debugBelch("cap %d: thread %lu stopped (blocked on black hole owned by thread %lu)\n",
-                       cap->no, (lnat)tso->id, (long)info2);
+            debugBelch("cap %d: thread %" FMT_Word " stopped (blocked on black hole owned by thread %lu)\n",
+                       cap->no, (W_)tso->id, (long)info2);
         } else {
-            debugBelch("cap %d: thread %lu stopped (%s)\n",
-                       cap->no, (lnat)tso->id, thread_stop_reasons[info1]);
+            debugBelch("cap %d: thread %" FMT_Word " stopped (%s)\n",
+                       cap->no, (W_)tso->id, thread_stop_reasons[info1]);
         }
         break;
-    case EVENT_SHUTDOWN:        // (cap)
-        debugBelch("cap %d: shutting down\n", cap->no);
-        break;
     default:
-        debugBelch("cap %d: thread %lu: event %d\n\n", 
-                   cap->no, (lnat)tso->id, tag);
+        debugBelch("cap %d: thread %" FMT_Word ": event %d\n\n",
+                   cap->no, (W_)tso->id, tag);
         break;
     }
 
@@ -238,10 +226,10 @@ static void traceSchedEvent_stderr (Capability *cap, EventTypeNum tag,
 }
 #endif
 
-void traceSchedEvent_ (Capability *cap, EventTypeNum tag, 
+void traceSchedEvent_ (Capability *cap, EventTypeNum tag,
                        StgTSO *tso, StgWord info1, StgWord info2)
 {
-#ifdef DEBUG
+#if defined(DEBUG)
     if (RtsFlags.TraceFlags.tracing == TRACE_STDERR) {
         traceSchedEvent_stderr(cap, tag, tso, info1, info2);
     } else
@@ -251,7 +239,7 @@ void traceSchedEvent_ (Capability *cap, EventTypeNum tag,
     }
 }
 
-#ifdef DEBUG
+#if defined(DEBUG)
 static void traceGcEvent_stderr (Capability *cap, EventTypeNum tag)
 {
     ACQUIRE_LOCK(&trace_utx);
@@ -279,6 +267,9 @@ static void traceGcEvent_stderr (Capability *cap, EventTypeNum tag)
       case EVENT_GC_DONE:         // (cap)
           debugBelch("cap %d: GC done\n", cap->no);
           break;
+      case EVENT_GC_GLOBAL_SYNC:  // (cap)
+          debugBelch("cap %d: all caps stopped for GC\n", cap->no);
+          break;
       default:
           barf("traceGcEvent: unknown event tag %d", tag);
           break;
@@ -290,7 +281,7 @@ static void traceGcEvent_stderr (Capability *cap, EventTypeNum tag)
 
 void traceGcEvent_ (Capability *cap, EventTypeNum tag)
 {
-#ifdef DEBUG
+#if defined(DEBUG)
     if (RtsFlags.TraceFlags.tracing == TRACE_STDERR) {
         traceGcEvent_stderr(cap, tag);
     } else
@@ -301,29 +292,134 @@ void traceGcEvent_ (Capability *cap, EventTypeNum tag)
     }
 }
 
-void traceCapsetModify_ (EventTypeNum tag,
-                         CapsetID capset,
-                         StgWord32 other)
+void traceGcEventAtT_ (Capability *cap, StgWord64 ts, EventTypeNum tag)
+{
+#if defined(DEBUG)
+    if (RtsFlags.TraceFlags.tracing == TRACE_STDERR) {
+        traceGcEvent_stderr(cap, tag);
+    } else
+#endif
+    {
+        /* assuming nullary events and explicitly inserting a timestamp */
+        postEventAtTimestamp(cap, ts, tag);
+    }
+}
+
+void traceHeapEvent_ (Capability   *cap,
+                      EventTypeNum  tag,
+                      CapsetID      heap_capset,
+                      W_          info1)
+{
+#if defined(DEBUG)
+    if (RtsFlags.TraceFlags.tracing == TRACE_STDERR) {
+        /* no stderr equivalent for these ones */
+    } else
+#endif
+    {
+        postHeapEvent(cap, tag, heap_capset, info1);
+    }
+}
+
+void traceEventHeapInfo_ (CapsetID    heap_capset,
+                          uint32_t  gens,
+                          W_        maxHeapSize,
+                          W_        allocAreaSize,
+                          W_        mblockSize,
+                          W_        blockSize)
 {
-#ifdef DEBUG
+#if defined(DEBUG)
     if (RtsFlags.TraceFlags.tracing == TRACE_STDERR) {
+        /* no stderr equivalent for these ones */
+    } else
+#endif
+    {
+        postEventHeapInfo(heap_capset, gens,
+                          maxHeapSize, allocAreaSize,
+                          mblockSize, blockSize);
+    }
+}
+
+void traceEventGcStats_  (Capability *cap,
+                          CapsetID    heap_capset,
+                          uint32_t  gen,
+                          W_        copied,
+                          W_        slop,
+                          W_        fragmentation,
+                          uint32_t  par_n_threads,
+                          W_        par_max_copied,
+                          W_        par_tot_copied)
+{
+#if defined(DEBUG)
+    if (RtsFlags.TraceFlags.tracing == TRACE_STDERR) {
+        /* no stderr equivalent for these ones */
+    } else
+#endif
+    {
+        postEventGcStats(cap, heap_capset, gen,
+                         copied, slop, fragmentation,
+                         par_n_threads, par_max_copied, par_tot_copied);
+    }
+}
+
+void traceCapEvent_ (Capability   *cap,
+                     EventTypeNum  tag)
+{
+#if defined(DEBUG)
+    if (RtsFlags.TraceFlags.tracing == TRACE_STDERR) {
+        ACQUIRE_LOCK(&trace_utx);
+
+        tracePreface();
+        switch (tag) {
+        case EVENT_CAP_CREATE:   // (cap)
+            debugBelch("cap %d: initialised\n", cap->no);
+            break;
+        case EVENT_CAP_DELETE:   // (cap)
+            debugBelch("cap %d: shutting down\n", cap->no);
+            break;
+        case EVENT_CAP_ENABLE:   // (cap)
+            debugBelch("cap %d: enabling capability\n", cap->no);
+            break;
+        case EVENT_CAP_DISABLE:  // (cap)
+            debugBelch("cap %d: disabling capability\n", cap->no);
+            break;
+        }
+        RELEASE_LOCK(&trace_utx);
+    } else
+#endif
+    {
+        if (eventlog_enabled) {
+            postCapEvent(tag, (EventCapNo)cap->no);
+        }
+    }
+}
+
+void traceCapsetEvent_ (EventTypeNum tag,
+                        CapsetID     capset,
+                        StgWord      info)
+{
+#if defined(DEBUG)
+    if (RtsFlags.TraceFlags.tracing == TRACE_STDERR && TRACE_sched)
+        // When events go to stderr, it is annoying to see the capset
+        // events every time, so we only emit them with -Ds.
+    {
         ACQUIRE_LOCK(&trace_utx);
 
         tracePreface();
         switch (tag) {
         case EVENT_CAPSET_CREATE:   // (capset, capset_type)
-            debugBelch("created capset %lu of type %d\n", (lnat)capset, (int)other);
+            debugBelch("created capset %" FMT_Word32 " of type %d\n", capset,
+                       (int)info);
             break;
         case EVENT_CAPSET_DELETE:   // (capset)
-            debugBelch("deleted capset %lu\n", (lnat)capset);
+            debugBelch("deleted capset %" FMT_Word32 "\n", capset);
             break;
         case EVENT_CAPSET_ASSIGN_CAP:  // (capset, capno)
-            debugBelch("assigned cap %lu to capset %lu\n",
-                       (lnat)other, (lnat)capset);
+            debugBelch("assigned cap %" FMT_Word " to capset %" FMT_Word32 "\n",
+                       info, capset);
             break;
         case EVENT_CAPSET_REMOVE_CAP:  // (capset, capno)
-            debugBelch("removed cap %lu from capset %lu\n",
-                       (lnat)other, (lnat)capset);
+            debugBelch("removed cap %" FMT_Word " from capset %" FMT_Word32
+                       "\n", info, capset);
             break;
         }
         RELEASE_LOCK(&trace_utx);
@@ -331,25 +427,31 @@ void traceCapsetModify_ (EventTypeNum tag,
 #endif
     {
         if (eventlog_enabled) {
-            postCapsetModifyEvent(tag, capset, other);
+            postCapsetEvent(tag, capset, info);
         }
     }
 }
 
+void traceWallClockTime_(void) {
+    if (eventlog_enabled) {
+        postWallClockTime(CAPSET_CLOCKDOMAIN_DEFAULT);
+    }
+}
+
 void traceOSProcessInfo_(void) {
     if (eventlog_enabled) {
-        postCapsetModifyEvent(EVENT_OSPROCESS_PID,
-                              CAPSET_OSPROCESS_DEFAULT,
-                              getpid());
+        postCapsetEvent(EVENT_OSPROCESS_PID,
+                        CAPSET_OSPROCESS_DEFAULT,
+                        getpid());
 
-#if !defined(cygwin32_HOST_OS) && !defined (mingw32_HOST_OS)
-/* Windows has no strong concept of process heirarchy, so no getppid().
+#if !defined (mingw32_HOST_OS)
+/* Windows has no strong concept of process hierarchy, so no getppid().
  * In any case, this trace event is mainly useful for tracing programs
  * that use 'forkProcess' which Windows doesn't support anyway.
  */
-        postCapsetModifyEvent(EVENT_OSPROCESS_PPID,
-                              CAPSET_OSPROCESS_DEFAULT,
-                              getppid());
+        postCapsetEvent(EVENT_OSPROCESS_PPID,
+                        CAPSET_OSPROCESS_DEFAULT,
+                        getppid());
 #endif
         {
             char buf[256];
@@ -380,11 +482,73 @@ void traceOSProcessInfo_(void) {
     }
 }
 
+#if defined(DEBUG)
+static void traceSparkEvent_stderr (Capability *cap, EventTypeNum tag,
+                                    StgWord info1)
+{
+    ACQUIRE_LOCK(&trace_utx);
+
+    tracePreface();
+    switch (tag) {
+
+    case EVENT_CREATE_SPARK_THREAD: // (cap, spark_thread)
+        debugBelch("cap %d: creating spark thread %lu\n",
+                   cap->no, (long)info1);
+        break;
+    case EVENT_SPARK_CREATE:        // (cap)
+        debugBelch("cap %d: added spark to pool\n",
+                   cap->no);
+        break;
+    case EVENT_SPARK_DUD:           //  (cap)
+        debugBelch("cap %d: discarded dud spark\n",
+                   cap->no);
+        break;
+    case EVENT_SPARK_OVERFLOW:      // (cap)
+        debugBelch("cap %d: discarded overflowed spark\n",
+                   cap->no);
+        break;
+    case EVENT_SPARK_RUN:           // (cap)
+        debugBelch("cap %d: running a spark\n",
+                   cap->no);
+        break;
+    case EVENT_SPARK_STEAL:         // (cap, victim_cap)
+        debugBelch("cap %d: stealing a spark from cap %d\n",
+                   cap->no, (int)info1);
+        break;
+    case EVENT_SPARK_FIZZLE:        // (cap)
+        debugBelch("cap %d: fizzled spark removed from pool\n",
+                   cap->no);
+        break;
+    case EVENT_SPARK_GC:            // (cap)
+        debugBelch("cap %d: GCd spark removed from pool\n",
+                   cap->no);
+        break;
+    default:
+        barf("traceSparkEvent: unknown event tag %d", tag);
+        break;
+    }
+
+    RELEASE_LOCK(&trace_utx);
+}
+#endif
+
+void traceSparkEvent_ (Capability *cap, EventTypeNum tag, StgWord info1)
+{
+#if defined(DEBUG)
+    if (RtsFlags.TraceFlags.tracing == TRACE_STDERR) {
+        traceSparkEvent_stderr(cap, tag, info1);
+    } else
+#endif
+    {
+        postSparkEvent(cap,tag,info1);
+    }
+}
+
 void traceSparkCounters_ (Capability *cap,
                           SparkCounters counters,
                           StgWord remaining)
 {
-#ifdef DEBUG
+#if defined(DEBUG)
     if (RtsFlags.TraceFlags.tracing == TRACE_STDERR) {
         /* we currently don't do debug tracing of spark stats but we must
            test for TRACE_STDERR because of the !eventlog_enabled case. */
@@ -395,8 +559,97 @@ void traceSparkCounters_ (Capability *cap,
     }
 }
 
-#ifdef DEBUG
-static void traceCap_stderr(Capability *cap, char *msg, va_list ap)
+void traceTaskCreate_ (Task       *task,
+                       Capability *cap)
+{
+#if defined(DEBUG)
+    if (RtsFlags.TraceFlags.tracing == TRACE_STDERR) {
+        /* We currently don't do debug tracing of tasks but we must
+           test for TRACE_STDERR because of the !eventlog_enabled case. */
+    } else
+#endif
+    {
+        EventTaskId         taskid = serialisableTaskId(task);
+        EventKernelThreadId tid    = kernelThreadId();
+        postTaskCreateEvent(taskid, cap->no, tid);
+    }
+}
+
+void traceTaskMigrate_ (Task       *task,
+                        Capability *cap,
+                        Capability *new_cap)
+{
+#if defined(DEBUG)
+    if (RtsFlags.TraceFlags.tracing == TRACE_STDERR) {
+        /* We currently don't do debug tracing of tasks but we must
+           test for TRACE_STDERR because of the !eventlog_enabled case. */
+    } else
+#endif
+    {
+        EventTaskId taskid = serialisableTaskId(task);
+        postTaskMigrateEvent(taskid, cap->no, new_cap->no);
+    }
+}
+
+void traceTaskDelete_ (Task *task)
+{
+#if defined(DEBUG)
+    if (RtsFlags.TraceFlags.tracing == TRACE_STDERR) {
+        /* We currently don't do debug tracing of tasks but we must
+           test for TRACE_STDERR because of the !eventlog_enabled case. */
+    } else
+#endif
+    {
+        EventTaskId taskid = serialisableTaskId(task);
+        postTaskDeleteEvent(taskid);
+    }
+}
+
+void traceHeapProfBegin(StgWord8 profile_id)
+{
+    if (eventlog_enabled) {
+        postHeapProfBegin(profile_id);
+    }
+}
+
+void traceHeapProfSampleBegin(StgInt era)
+{
+    if (eventlog_enabled) {
+        postHeapProfSampleBegin(era);
+    }
+}
+
+void traceHeapProfSampleString(StgWord8 profile_id,
+                               const char *label, StgWord residency)
+{
+    if (eventlog_enabled) {
+        postHeapProfSampleString(profile_id, label, residency);
+    }
+}
+
+#if defined(PROFILING)
+void traceHeapProfCostCentre(StgWord32 ccID,
+                             const char *label,
+                             const char *module,
+                             const char *srcloc,
+                             StgBool is_caf)
+{
+    if (eventlog_enabled) {
+        postHeapProfCostCentre(ccID, label, module, srcloc, is_caf);
+    }
+}
+
+void traceHeapProfSampleCostCentre(StgWord8 profile_id,
+                                   CostCentreStack *stack, StgWord residency)
+{
+    if (eventlog_enabled) {
+        postHeapProfSampleCostCentre(profile_id, stack, residency);
+    }
+}
+#endif
+
+#if defined(DEBUG)
+static void vtraceCap_stderr(Capability *cap, char *msg, va_list ap)
 {
     ACQUIRE_LOCK(&trace_utx);
 
@@ -407,16 +660,24 @@ static void traceCap_stderr(Capability *cap, char *msg, va_list ap)
 
     RELEASE_LOCK(&trace_utx);
 }
+
+static void traceCap_stderr(Capability *cap, char *msg, ...)
+{
+  va_list ap;
+  va_start(ap,msg);
+  vtraceCap_stderr(cap, msg, ap);
+  va_end(ap);
+}
 #endif
 
 void traceCap_(Capability *cap, char *msg, ...)
 {
     va_list ap;
     va_start(ap,msg);
-    
-#ifdef DEBUG
+
+#if defined(DEBUG)
     if (RtsFlags.TraceFlags.tracing == TRACE_STDERR) {
-        traceCap_stderr(cap, msg, ap);
+        vtraceCap_stderr(cap, msg, ap);
     } else
 #endif
     {
@@ -426,8 +687,8 @@ void traceCap_(Capability *cap, char *msg, ...)
     va_end(ap);
 }
 
-#ifdef DEBUG
-static void trace_stderr(char *msg, va_list ap)
+#if defined(DEBUG)
+static void vtrace_stderr(char *msg, va_list ap)
 {
     ACQUIRE_LOCK(&trace_utx);
 
@@ -444,9 +705,9 @@ void trace_(char *msg, ...)
     va_list ap;
     va_start(ap,msg);
 
-#ifdef DEBUG
+#if defined(DEBUG)
     if (RtsFlags.TraceFlags.tracing == TRACE_STDERR) {
-        trace_stderr(msg, ap);
+        vtrace_stderr(msg, ap);
     } else
 #endif
     {
@@ -456,49 +717,76 @@ void trace_(char *msg, ...)
     va_end(ap);
 }
 
-static void traceFormatUserMsg(Capability *cap, char *msg, ...)
+void traceUserMsg(Capability *cap, char *msg)
 {
-    va_list ap;
-    va_start(ap,msg);
-
-#ifdef DEBUG
-    if (RtsFlags.TraceFlags.tracing == TRACE_STDERR) {
-        traceCap_stderr(cap, msg, ap);
+    /* Note: normally we don't check the TRACE_* flags here as they're checked
+       by the wrappers in Trace.h. But traceUserMsg is special since it has no
+       wrapper (it's called from cmm code), so we check TRACE_user here
+     */
+#if defined(DEBUG)
+    if (RtsFlags.TraceFlags.tracing == TRACE_STDERR && TRACE_user) {
+        // Use "%s" as format string to ignore format specifiers in msg (#3874).
+        traceCap_stderr(cap, "%s", msg);
     } else
 #endif
     {
-        if (eventlog_enabled) {
-            postUserMsg(cap, msg, ap);
+        if (eventlog_enabled && TRACE_user) {
+            postUserEvent(cap, EVENT_USER_MSG, msg);
         }
     }
     dtraceUserMsg(cap->no, msg);
 }
 
-void traceUserMsg(Capability *cap, char *msg)
+void traceUserMarker(Capability *cap, char *markername)
 {
-    traceFormatUserMsg(cap, "%s", msg);
+    /* Note: traceUserMarker is special since it has no wrapper (it's called
+       from cmm code), so we check eventlog_enabled and TRACE_user here.
+     */
+#if defined(DEBUG)
+    if (RtsFlags.TraceFlags.tracing == TRACE_STDERR && TRACE_user) {
+        traceCap_stderr(cap, "User marker: %s", markername);
+    } else
+#endif
+    {
+        if (eventlog_enabled && TRACE_user) {
+            postUserEvent(cap, EVENT_USER_MARKER, markername);
+        }
+    }
+    dtraceUserMarker(cap->no, markername);
 }
 
-void traceThreadStatus_ (StgTSO *tso USED_IF_DEBUG)
+
+void traceThreadLabel_(Capability *cap,
+                       StgTSO     *tso,
+                       char       *label)
 {
-#ifdef DEBUG
+#if defined(DEBUG)
     if (RtsFlags.TraceFlags.tracing == TRACE_STDERR) {
-        printThreadStatus(tso);
+        ACQUIRE_LOCK(&trace_utx);
+        tracePreface();
+        debugBelch("cap %d: thread %" FMT_Word " has label %s\n",
+                   cap->no, (W_)tso->id, label);
+        RELEASE_LOCK(&trace_utx);
     } else
 #endif
     {
-        /* nothing - no event for this one yet */
+        postThreadLabel(cap, tso->id, label);
     }
 }
 
-void traceEventStartup_(int nocaps)
+void traceThreadStatus_ (StgTSO *tso USED_IF_DEBUG)
 {
-    if (eventlog_enabled) {
-        postEventStartup(nocaps);
+#if defined(DEBUG)
+    if (RtsFlags.TraceFlags.tracing == TRACE_STDERR) {
+        printThreadStatus(tso);
+    } else
+#endif
+    {
+        /* nothing - no event for this one yet */
     }
 }
 
-#ifdef DEBUG
+#if defined(DEBUG)
 void traceBegin (const char *str, ...)
 {
     va_list ap;
@@ -508,6 +796,7 @@ void traceBegin (const char *str, ...)
 
     tracePreface();
     vdebugBelch(str,ap);
+    va_end(ap);
 }
 
 void traceEnd (void)
@@ -529,4 +818,9 @@ void dtraceUserMsgWrapper(Capability *cap, char *msg)
     dtraceUserMsg(cap->no, msg);
 }
 
+void dtraceUserMarkerWrapper(Capability *cap, char *msg)
+{
+    dtraceUserMarker(cap->no, msg);
+}
+
 #endif /* !defined(DEBUG) && !defined(TRACING) && defined(DTRACE) */