rts: Post ticky entry counts to the eventlog

We currently only post the entry counters, not the other global
counters as in my experience the former are more useful. We use the heap
profiler's census period to decide when to dump.

Also spruces up the documentation surrounding ticky-ticky a bit.

9 files changed, 150 insertions, 2 deletions

diff --git a/rts/Proftimer.c b/rts/Proftimer.c
index 24f82ead6d..00b92a227d 100644
--- a/rts/Proftimer.c
+++ b/rts/Proftimer.c
@@ -20,6 +20,12 @@ static bool do_prof_ticks = false;       // enable profiling ticks
 
 static bool do_heap_prof_ticks = false;  // enable heap profiling ticks
 
+// Sampling of Ticky-Ticky profiler to eventlog
+#if defined(TICKY_TICKY) && defined(TRACING)
+static int ticks_to_ticky_sample = 0;
+bool performTickySample = false;
+#endif
+
 // Number of ticks until next heap census
 static int ticks_to_heap_profile;
 
@@ -83,6 +89,16 @@ handleProfTick(void)
     }
 #endif
 
+#if defined(TICKY_TICKY) && defined(TRACING)
+    if (RtsFlags.TraceFlags.ticky) {
+        ticks_to_ticky_sample--;
+        if (ticks_to_ticky_sample <= 0) {
+            ticks_to_ticky_sample = RtsFlags.ProfFlags.heapProfileIntervalTicks;
+            performTickySample = true;
+        }
+    }
+#endif
+
     if (RELAXED_LOAD(&do_heap_prof_ticks)) {
         ticks_to_heap_profile--;
         if (ticks_to_heap_profile <= 0) {
diff --git a/rts/Proftimer.h b/rts/Proftimer.h
index 89fb100b44..ad50ccb9a6 100644
--- a/rts/Proftimer.h
+++ b/rts/Proftimer.h
@@ -17,5 +17,6 @@ void stopHeapProfTimer  ( void );
 void startHeapProfTimer ( void );
 
 extern bool performHeapProfile;
+extern bool performTickySample;
 
 #include "EndPrivate.h"
diff --git a/rts/RtsFlags.c b/rts/RtsFlags.c
index e7375a0746..b23b19752b 100644
--- a/rts/RtsFlags.c
+++ b/rts/RtsFlags.c
@@ -235,6 +235,7 @@ void initRtsFlagsDefaults(void)
     RtsFlags.TraceFlags.sparks_sampled= false;
     RtsFlags.TraceFlags.sparks_full   = false;
     RtsFlags.TraceFlags.user          = false;
+    RtsFlags.TraceFlags.ticky         = false;
     RtsFlags.TraceFlags.trace_output  = NULL;
 #endif
 
@@ -403,6 +404,9 @@ usage_text[] = {
 "                p    par spark events (sampled)",
 "                f    par spark events (full detail)",
 "                u    user events (emitted from Haskell code)",
+#if defined(TICKY_TICKY)
+"                T    ticky-ticky counter samples",
+#endif
 "                a    all event classes above",
 #  if defined(DEBUG)
 "                t    add time stamps (only useful with -v)",
@@ -1855,6 +1859,11 @@ static void normaliseRtsOpts (void)
                    "the compacting collector.");
         errorUsage();
     }
+
+    if (RtsFlags.TraceFlags.ticky && RtsFlags.TickyFlags.showTickyStats) {
+        barf("The ticky-ticky eventlog output cannot be used in conjunction with\n"
+             "+RTS -r<file>.");
+    }
 }
 
 static void errorUsage (void)
@@ -2297,6 +2306,15 @@ static void read_trace_flags(const char *arg)
             RtsFlags.TraceFlags.user      = enabled;
             enabled = true;
             break;
+        case 'T':
+#if defined(TICKY_TICKY)
+            RtsFlags.TraceFlags.ticky     = enabled;
+            enabled = true;
+            break;
+#else
+            errorBelch("Program not compiled with ticky-ticky support");
+            break;
+#endif
         default:
             errorBelch("unknown trace option: %c",*c);
             break;
diff --git a/rts/RtsStartup.c b/rts/RtsStartup.c
index 02e32106d2..107a74dc5b 100644
--- a/rts/RtsStartup.c
+++ b/rts/RtsStartup.c
@@ -487,6 +487,17 @@ hs_exit_(bool wait_foreign)
      */
     exitTimer(true);
 
+    /*
+     * Dump the ticky counter definitions
+     * We do this at the end of execution since tickers are registered in the
+     * course of program execution.
+     */
+#if defined(TICKY_TICKY) && defined(TRACING)
+    if (RtsFlags.TraceFlags.ticky) {
+        emitTickyCounterDefs();
+    }
+#endif
+
     // set the terminal settings back to what they were
 #if !defined(mingw32_HOST_OS)
     resetTerminalSettings();
diff --git a/rts/Ticky.c b/rts/Ticky.c
index b46f91b204..83ba70887c 100644
--- a/rts/Ticky.c
+++ b/rts/Ticky.c
@@ -10,6 +10,8 @@
 #include "PosixSource.h"
 #include "Rts.h"
 
+#include "eventlog/EventLog.h"
+
 /* Catch-all top-level counter struct.  Allocations from CAFs will go
  * here.
  */
@@ -46,6 +48,10 @@ static void printRegisteredCounterInfo (FILE *); /* fwd decl */
 void
 PrintTickyInfo(void)
 {
+  if (RtsFlags.TraceFlags.ticky) {
+      barf("Ticky eventlog output can't be used with +RTS -r<file>");
+  }
+
   unsigned long i;
 
   unsigned long tot_thk_enters = ENT_STATIC_THK_MANY_ctr + ENT_DYN_THK_MANY_ctr
@@ -374,4 +380,19 @@ printRegisteredCounterInfo (FILE *tf)
 
     }
 }
+
+void emitTickyCounterDefs()
+{
+#if defined(TRACING)
+    postTickyCounterDefs(ticky_entry_ctrs);
+#endif
+}
+
+void emitTickyCounterSamples()
+{
+#if defined(TRACING)
+    postTickyCounterSamples(ticky_entry_ctrs);
+#endif
+}
+
 #endif /* TICKY_TICKY */
diff --git a/rts/Ticky.h b/rts/Ticky.h
index 1a5357d8db..a8c2f1ae9b 100644
--- a/rts/Ticky.h
+++ b/rts/Ticky.h
@@ -8,4 +8,11 @@
 
 #pragma once
 
-RTS_PRIVATE void PrintTickyInfo(void);
+#include "BeginPrivate.h"
+
+void PrintTickyInfo(void);
+
+void emitTickyCounterSamples(void);
+void emitTickyCounterDefs(void);
+
+#include "EndPrivate.h"
diff --git a/rts/eventlog/EventLog.c b/rts/eventlog/EventLog.c
index 11e8a5e0b6..d093d595c7 100644
--- a/rts/eventlog/EventLog.c
+++ b/rts/eventlog/EventLog.c
@@ -119,7 +119,9 @@ char *EventDesc[] = {
   [EVENT_CONC_SWEEP_BEGIN]       = "Begin concurrent sweep",
   [EVENT_CONC_SWEEP_END]         = "End concurrent sweep",
   [EVENT_CONC_UPD_REM_SET_FLUSH] = "Update remembered set flushed",
-  [EVENT_NONMOVING_HEAP_CENSUS]  = "Nonmoving heap census"
+  [EVENT_NONMOVING_HEAP_CENSUS]  = "Nonmoving heap census",
+  [EVENT_TICKY_COUNTER_DEF]    = "Ticky-ticky entry counter definition",
+  [EVENT_TICKY_COUNTER_SAMPLE] = "Ticky-ticky entry counter sample",
 };
 
 // Event type.
@@ -487,6 +489,14 @@ init_event_types(void)
             eventTypes[t].size = 13;
             break;
 
+        case EVENT_TICKY_COUNTER_DEF: // (counter_id, arity, arg_kinds, name)
+            eventTypes[t].size = EVENT_SIZE_DYNAMIC;
+            break;
+
+        case EVENT_TICKY_COUNTER_SAMPLE: // (counter_id, entry_count, allocs, allocd)
+            eventTypes[t].size = 8*4;
+            break;
+
         default:
             continue; /* ignore deprecated events */
         }
@@ -1472,6 +1482,53 @@ void postProfBegin(void)
 }
 #endif /* PROFILING */
 
+#if defined(TICKY_TICKY)
+static void postTickyCounterDef(EventsBuf *eb, StgEntCounter *p)
+{
+    StgWord len = 8 + 2 + strlen(p->arg_kinds)+1 + strlen(p->str)+1;
+    ensureRoomForVariableEvent(eb, len);
+    postEventHeader(eb, EVENT_TICKY_COUNTER_DEF);
+    postPayloadSize(eb, len);
+    postWord64(eb, (uint64_t) p);
+    postWord16(eb, (uint16_t) p->arity);
+    postString(eb, p->arg_kinds);
+    postString(eb, p->str);
+}
+
+void postTickyCounterDefs(StgEntCounter *counters)
+{
+    ACQUIRE_LOCK(&eventBufMutex);
+    for (StgEntCounter *p = counters; p != NULL; p = p->link) {
+        postTickyCounterDef(&eventBuf, p);
+    }
+    RELEASE_LOCK(&eventBufMutex);
+}
+
+static void postTickyCounterSample(EventsBuf *eb, StgEntCounter *p)
+{
+    if (   p->entry_count == 0
+        && p->allocs == 0
+        && p->allocd == 0)
+        return;
+
+    ensureRoomForEvent(eb, EVENT_TICKY_COUNTER_SAMPLE);
+    postEventHeader(eb, EVENT_TICKY_COUNTER_SAMPLE);
+    postWord64(eb, (uint64_t) p);
+    postWord64(eb, p->entry_count);
+    postWord64(eb, p->allocs);
+    postWord64(eb, p->allocd);
+}
+
+void postTickyCounterSamples(StgEntCounter *counters)
+{
+    ACQUIRE_LOCK(&eventBufMutex);
+    for (StgEntCounter *p = counters; p != NULL; p = p->link) {
+        postTickyCounterSample(&eventBuf, p);
+    }
+    RELEASE_LOCK(&eventBufMutex);
+}
+#endif /* TICKY_TICKY */
+
 void printAndClearEventBuf (EventsBuf *ebuf)
 {
     closeBlockMarker(ebuf);
diff --git a/rts/eventlog/EventLog.h b/rts/eventlog/EventLog.h
index eca76619cd..cf94a25ed6 100644
--- a/rts/eventlog/EventLog.h
+++ b/rts/eventlog/EventLog.h
@@ -173,6 +173,11 @@ void postConcMarkEnd(StgWord32 marked_obj_count);
 void postNonmovingHeapCensus(int log_blk_size,
                              const struct NonmovingAllocCensus *census);
 
+#if defined(TICKY_TICKY)
+void postTickyCounterDefs(StgEntCounter *p);
+void postTickyCounterSamples(StgEntCounter *p);
+#endif /* TICKY_TICKY */
+
 #else /* !TRACING */
 
 INLINE_HEADER void postSchedEvent (Capability *cap  STG_UNUSED,
diff --git a/rts/sm/GC.c b/rts/sm/GC.c
index 0dc92a29a0..0edc5f72ca 100644
--- a/rts/sm/GC.c
+++ b/rts/sm/GC.c
@@ -38,6 +38,7 @@
 #include "Sanity.h"
 #include "BlockAlloc.h"
 #include "ProfHeap.h"
+#include "Proftimer.h"
 #include "Weak.h"
 #include "Prelude.h"
 #include "RtsSignals.h"
@@ -52,6 +53,7 @@
 #include "CNF.h"
 #include "RtsFlags.h"
 #include "NonMoving.h"
+#include "Ticky.h"
 
 #include <string.h> // for memset()
 #include <unistd.h>
@@ -903,6 +905,16 @@ GarbageCollect (uint32_t collect_gen,
       ACQUIRE_SM_LOCK;
   }
 
+#if defined(TICKY_TICKY)
+  // Post ticky counter sample.
+  // We do this at the end of execution since tickers are registered in the
+  // course of program execution.
+  if (performTickySample) {
+      emitTickyCounterSamples();
+      performTickySample = false;
+  }
+#endif
+
   // send exceptions to any threads which were about to die
   RELEASE_SM_LOCK;
   resurrectThreads(resurrected_threads);