Log heap profiler samples to event log
authorBen Gamari <bgamari.foss@gmail.com>
Thu, 16 Jun 2016 13:03:01 +0000 (15:03 +0200)
committerBen Gamari <ben@smart-cactus.org>
Sat, 16 Jul 2016 18:31:47 +0000 (20:31 +0200)
Test Plan: Try it

Reviewers: hvr, simonmar, austin, erikd

Subscribers: thomie

Differential Revision: https://phabricator.haskell.org/D1722

GHC Trac Issues: #11094

15 files changed:
compiler/main/DynFlags.hs
compiler/main/Packages.hs
docs/users_guide/8.2.1-notes.rst
docs/users_guide/eventlog-formats.rst [new file with mode: 0644]
docs/users_guide/index.rst
docs/users_guide/profiling.rst
includes/rts/Config.h
includes/rts/EventLogFormat.h
mk/config.mk.in
mk/ways.mk
rts/ProfHeap.c
rts/Trace.c
rts/Trace.h
rts/eventlog/EventLog.c
rts/eventlog/EventLog.h

index ffb5b33..24746d6 100644 (file)
@@ -1264,6 +1264,7 @@ allowed_combination way = and [ x `allowedWith` y
         (WayCustom {}) `allowedWith` _          = True
         WayThreaded `allowedWith` WayProf       = True
         WayThreaded `allowedWith` WayEventLog   = True
+        WayProf     `allowedWith` WayEventLog   = True
         _ `allowedWith` _                       = False
 
 mkBuildTag :: [Way] -> String
index 4710de1..ecec982 100644 (file)
@@ -1233,8 +1233,8 @@ packageHsLibs dflags p = map (mkDynName . addSuffix) (hsLibraries p)
         -- the name of a shared library is libHSfoo-ghc<version>.so
         -- we leave out the _dyn, because it is superfluous
 
-        -- debug RTS includes support for -eventlog
-        ways2 | WayDebug `elem` ways1
+        -- debug and profiled RTSs include support for -eventlog
+        ways2 | WayDebug `elem` ways1 || WayProf `elem` ways1
               = filter (/= WayEventLog) ways1
               | otherwise
               = ways1
index 7b271cd..2ae804d 100644 (file)
@@ -56,6 +56,10 @@ Runtime system
 
 -  TODO FIXME.
 
+- The :ref:`heap profiler <prof-heap>` can now emit heap census data to the GHC
+  event log, allowing heap profiles to be correlated with other tracing events
+  (see :ghc-ticket:`11094`).
+
 Build system
 ~~~~~~~~~~~~
 
diff --git a/docs/users_guide/eventlog-formats.rst b/docs/users_guide/eventlog-formats.rst
new file mode 100644 (file)
index 0000000..74a62f2
--- /dev/null
@@ -0,0 +1,119 @@
+Eventlog encodings
+==================
+
+This section documents the encodings of the events emitted to GHC's
+:ref:`event log <rts-eventlog>`. These events can include information about the
+thread scheduling events, garbage collection statistics, profiling information,
+user-defined tracing events.
+
+This section is intended for implementors of tooling which consume these events.
+
+
+.. _heap-profiler-events:
+
+Heap profiler event log output
+------------------------------
+
+The heap profiler can produce output to GHC's event log, allowing samples to
+be correlated with other event log events over the program's lifecycle.
+
+This section defines the layout of these events. The ``String`` type below is
+defined to be a UTF-8 encoded NUL-terminated string.
+
+Metadata event types
+~~~~~~~~~~~~~~~~~~~~
+
+Beginning of sample stream
+^^^^^^^^^^^^^^^^^^^^^^^^^^
+
+A single fixed-width event emitted during program start-up describing the samples that follow.
+
+ * ``EVENT_HEAP_PROF_BEGIN``
+   * ``Word8``: Profile ID
+   * ``Word64``: Sampling period in nanoseconds
+   * ``Word32``: Sample break-down type. One of,
+      * ``SAMPLE_TYPE_COST_CENTER`` (output from ``-hc``)
+      * ``SAMPLE_TYPE_CLOSURE_DESCR`` (output from ``-hd``)
+      * ``SAMPLE_TYPE_RETAINER`` (output from ``-hr``)
+      * ``SAMPLE_TYPE_MODULE`` (output from ``-hm``)
+      * ``SAMPLE_TYPE_TYPE_DESCR`` (output from ``-hy``)
+      * ``SAMPLE_TYPE_BIOGRAPHY`` (output from ``-hb``)
+   * ``String``: Cost centre filter
+   * ``String``: Closure description filter
+   * ``String``: Retainer filter
+   * ``String``: Module filter
+   * ``String``: Type description filter
+
+Cost center definitions
+^^^^^^^^^^^^^^^^^^^^^^^
+
+A variable-length packet produced once for each cost center,
+
+ * ``EVENT_HEAP_PROF_COST_CENTRE``
+   * ``Word32``: cost center number
+   * ``String``: label
+   * ``String``: module
+   * ``String``: source location
+   * ``Word8``: flags
+     * bit 0: is the cost-center a CAF?
+
+
+Sample event types
+~~~~~~~~~~~~~~~~~~
+
+A sample (consisting of a list of break-down classes, e.g. cost centers, and
+heap residency sizes), is to be encoded in the body of one or more events.
+
+We mark the beginning of a new sample with an ``EVENT_HEAP_PROF_SAMPLE_BEGIN``
+event,
+
+ * ``EVENT_HEAP_PROF_SAMPLE_BEGIN``
+   * ``Word64``: sample number
+
+A heap residency census will follow. Since events may only be up to 2^16^ bytes
+in length a single sample may need to be split among multiple
+``EVENT_HEAP_PROF_SAMPLE`` events. The precise format of the census entries is
+determined by the break-down type.
+
+
+Cost-center break-down
+^^^^^^^^^^^^^^^^^^^^^^
+
+A variable-length packet encoding a heap profile sample broken down by,
+ * cost-center (``-hc``)
+ * retainer (``-hr``)
+
+ * ``EVENT_HEAP_PROF_SAMPLE``
+   * ``Word8``: Profile ID
+   * ``Word64``: heap residency in bytes
+   * ``Word8``: stack depth
+   * ``Word32[]``: cost center stack starting with inner-most (cost center numbers)
+
+
+String break-down
+^^^^^^^^^^^^^^^^^
+
+A variable-length event encoding a heap sample broken down by,
+ * type description (``-hy``)
+ * closure description (``-hd``)
+ * module (``-hm``)
+
+ * ``EVENT_HEAP_PROF_SAMPLE``
+   * ``Word8``: Profile ID
+   * The event shall contain packed pairs of,
+     * ``String``: type description
+     * ``Word64``: heap residency in bytes
+
+
+Biography break-down
+^^^^^^^^^^^^^^^^^^^^
+
+A fixed-length event encoding a biography heap sample.
+
+ * ``EVENT_HEAP_PROF_SAMPLE``
+   * ``Word8``: Profile ID
+   * ``Word64``: Void
+   * ``Word64``: Lag
+   * ``Word64``: Use
+   * ``Word64``: Inherent use
+   * ``Word64``: Drag
index b7ff4c0..57b04c6 100644 (file)
@@ -26,6 +26,7 @@ Contents:
    utils
    win32-dlls
    bugs
+   eventlog-formats
    editing-guide
 
 
index 4d0bb3a..daae780 100644 (file)
@@ -425,10 +425,14 @@ To generate a heap profile from your program:
 
 2. Run it with one of the heap profiling options described below (eg.
    :rts-flag:`-h` for a basic producer profile). This generates the file
-   ``prog.hp``.
+   :file:`{prog}.hp`.
 
-3. Run ``hp2ps`` to produce a Postscript file, ``prog.ps``. The
-   ``hp2ps`` utility is described in detail in :ref:`hp2ps`.
+   If the :ref:`event log <rts-eventlog>` is enabled (with the :rts-flag:`-l`
+   runtime system flag) heap samples will additionally be emitted to the GHC
+   event log (see :ref:`heap-profiler-events` for details about event format).
+
+3. Run :command:`hp2ps` to produce a Postscript file, :file:`{prog}.ps`. The
+   :command:`hp2ps` utility is described in detail in :ref:`hp2ps`.
 
 4. Display the heap profile using a postscript viewer such as Ghostview,
    or print it out on a Postscript-capable printer.
@@ -485,6 +489,18 @@ following RTS options select which break-down to use:
     Break down the graph by biography. Biographical profiling is
     described in more detail below (:ref:`biography-prof`).
 
+.. rts-flag:: -l
+
+    :noindex:
+
+    .. index::
+       single: eventlog; and heap profiling
+
+    Emit profile samples to the :ref:`GHC event log <rts-eventlog>`.
+    This format is both more expressive than the old ``.hp`` format
+    and can be correlated with other events over the program's runtime.
+    See :ref:`heap-profiler-events` for details on the produced event structure.
+
 In addition, the profile can be restricted to heap data which satisfies
 certain criteria - for example, you might want to display a profile by
 type but only for data produced by a certain module, or a profile by
@@ -747,7 +763,7 @@ Usage:
 
     hp2ps [flags] [<file>[.hp]]
 
-The program :command:`hp2ps` program converts a heap profile as produced
+The program :command:`hp2ps` program converts a ``.hp`` file produced
 by the ``-h<break-down>`` runtime option into a PostScript graph of the
 heap profile. By convention, the file to be processed by :command:`hp2ps` has a
 ``.hp`` extension. The PostScript output is written to :file:`{file}@.ps`.
index 043bf2d..51ee74f 100644 (file)
 #define USING_LIBBFD 1
 #endif
 
-/* DEBUG implies TRACING and TICKY_TICKY
- */
+/* DEBUG implies TRACING and TICKY_TICKY  */
 #if defined(DEBUG)
+#if !defined(TRACING)
 #define TRACING
+#endif
+#if !defined(TICKY_TICKY)
 #define TICKY_TICKY
 #endif
+#endif
+
 
 /* -----------------------------------------------------------------------------
    Signals - supported on non-PAR versions of the runtime.  See RtsSignals.h.
index 68d0d08..d6838ab 100644 (file)
 #define EVENT_USER_MARKER         58 /* (marker_name) */
 #define EVENT_HACK_BUG_T9003      59 /* Hack: see trac #9003 */
 
-/* Range 59 - 59 is available for new GHC and common events. */
-
 /* Range 60 - 80 is used by eden for parallel tracing
  * see http://www.mathematik.uni-marburg.de/~eden/
  */
 
 /* Range 140 - 159 is reserved for Perf events. */
 
+/* Range 160 - 180 is reserved for cost-centre heap profiling events. */
+
+#define EVENT_HEAP_PROF_BEGIN              160
+#define EVENT_HEAP_PROF_COST_CENTRE        161
+#define EVENT_HEAP_PROF_SAMPLE_BEGIN       162
+#define EVENT_HEAP_PROF_SAMPLE_COST_CENTRE 163
+#define EVENT_HEAP_PROF_SAMPLE_STRING      164
 /*
  * The highest event code +1 that ghc itself emits. Note that some event
  * ranges higher than this are reserved but not currently emitted by ghc.
  * This must match the size of the EventDesc[] array in EventLog.c
  */
-#define NUM_GHC_EVENT_TAGS        60
+#define NUM_GHC_EVENT_TAGS        165
 
 #if 0  /* DEPRECATED EVENTS: */
 /* we don't actually need to record the thread, it's implicit */
index 47198b9..56a63fd 100644 (file)
@@ -274,14 +274,21 @@ BuildSharedLibs=$(strip $(if $(findstring dyn,$(GhcLibWays)),YES,NO))
 # In addition, the RTS is built in some further variations.  Ways that
 # make sense here:
 #
-#   thr         : threaded
-#   thr_p       : threaded profiled
-#   debug       : debugging (compile with -g for the C compiler, and -DDEBUG)
-#   debug_p     : debugging profiled
-#   thr_debug   : debugging threaded
-#   thr_debug_p : debugging threaded profiled
-#   l           : event logging
-#   thr_l       : threaded and event logging
+#   thr           : threaded
+#   thr_p         : threaded + profiled + eventlog
+#   debug         : debugging + eventlog
+#   thr_debug     : debugging + threaded, + eventlog
+#   l             : eventlog
+#   p             : profiled + eventlog
+#   thr_l         : threaded + eventlog
+#
+# Note how there are a few cases which are handled specially (in packageHsLibs)
+# to reduce the number of distinct ways,
+#
+#   debug     implies  eventlog
+#   profiled  implies  eventlog
+#
+# This means, for instance, that there is no debug_l way.
 #
 GhcRTSWays=l
 
index 996530e..870b4a5 100644 (file)
@@ -1,6 +1,6 @@
 #
-# Options for compiling in different `ways'. 
-# 
+# Options for compiling in different `ways'.
+#
 # To configure up your own way, have a look at some of the standard ways
 # such as profiling, and create your own set of WAY_*_OPTS defs below.
 # After having done that, add your way string to WAYS, and after having
@@ -10,7 +10,7 @@
 
 #
 # Definitions of the different ways:
-#   
+#
 #   * their name:
 #          - tag, e.g., p
 #          - description, e.g., profiling
 #          - WAY_p_HC_OPTS gives the list of command-line options
 #            to the driver.
 #
+# For consistency, the way name should be formed from the tags in the following
+# order (the same ordering defined in DynFlags.Way),
+#
+#    - thr:   threaded
+#    - debug: debugging
+#    - p:     profiled
+#    - l:     eventlog
+#    - dyn:   dynamically-linked
 
 #
 # The ways currently defined.
 #
-ALL_WAYS=v p l debug dyn thr thr_l p_dyn debug_dyn thr_dyn thr_p_dyn thr_debug_dyn thr_p thr_debug debug_p thr_debug_p l_dyn thr_l_dyn
+ALL_WAYS=v l debug dyn thr thr_l p_dyn p debug_dyn thr_dyn thr_p_dyn thr_debug_dyn thr_debug debug_p thr_debug_p l_dyn thr_l_dyn thr_p
 
 #
 # The following ways currently are treated specially,
 # as the driver script treats these guys specially and needs to carefully be told
 # about the options for these. Hence, we hide the required command line options
 # for these in the driver, as this is the only place they are needed.
-# 
+#
 # If you want to add to these default options, fill in the variables below:
 
 # Way 'v':
@@ -38,7 +46,7 @@ WAY_v_HC_OPTS= -static
 
 # Way 'p':
 WAY_p_NAME=profiling
-WAY_p_HC_OPTS= -static -prof
+WAY_p_HC_OPTS= -static -prof -eventlog
 
 # Way 'l':
 WAY_l_NAME=event logging
@@ -53,8 +61,8 @@ WAY_thr_NAME=threaded
 WAY_thr_HC_OPTS= -static -optc-DTHREADED_RTS
 
 # Way 'thr_p':
-WAY_thr_p_NAME=threaded profiled
-WAY_thr_p_HC_OPTS= -static -optc-DTHREADED_RTS -prof
+WAY_thr_p_NAME=threaded profiling
+WAY_thr_p_HC_OPTS= -static -prof -eventlog -optc-DTHREADED_RTS
 
 # Way 'thr_l':
 WAY_thr_l_NAME=threaded event logging
@@ -62,29 +70,35 @@ WAY_thr_l_HC_OPTS= -static -optc-DTHREADED_RTS -eventlog
 
 # Way 'debug':
 WAY_debug_NAME=debug
-WAY_debug_HC_OPTS= -static -optc-DDEBUG -ticky -DTICKY_TICKY
+WAY_debug_HC_OPTS= -static -optc-DDEBUG -ticky -DTICKY_TICKY -eventlog
 
 # Way 'debug_p':
 WAY_debug_p_NAME=debug profiled
-WAY_debug_p_HC_OPTS= -static -optc-DDEBUG -prof
+WAY_debug_p_HC_OPTS= -static -optc-DDEBUG -prof -eventlog
+
+# Way 'p':
+WAY_p_NAME=profiling
+WAY_p_HC_OPTS= -static -prof -eventlog
 
 # Way 'thr_debug':
 WAY_thr_debug_NAME=threaded debug
-WAY_thr_debug_HC_OPTS= -static -optc-DTHREADED_RTS -optc-DDEBUG
+WAY_thr_debug_HC_OPTS= -static -optc-DTHREADED_RTS -optc-DDEBUG -eventlog
 
 # Way 'thr_debug_p':
-WAY_thr_debug_p_NAME=threaded debug profiling
-WAY_thr_debug_p_HC_OPTS= -static -optc-DTHREADED_RTS -optc-DDEBUG -prof
+WAY_thr_debug_p_NAME=threaded debug profiling event logging
+WAY_thr_debug_p_HC_OPTS= -static -optc-DTHREADED_RTS -optc-DDEBUG -prof -eventlog
 
 # Way 'dyn': build dynamic shared libraries
 WAY_dyn_NAME=dyn
 WAY_dyn_HC_OPTS=-fPIC -dynamic
 
+# Way 'p_dyn':
 WAY_p_dyn_NAME=p_dyn
-WAY_p_dyn_HC_OPTS=-fPIC -dynamic -prof
+WAY_p_dyn_HC_OPTS=-fPIC -dynamic -prof -eventlog
 
+# Way 'thr_p_dyn':
 WAY_thr_p_dyn_NAME=thr_p_dyn
-WAY_thr_p_dyn_HC_OPTS=-fPIC -dynamic -prof -optc-DTHREADED_RTS
+WAY_thr_p_dyn_HC_OPTS=-fPIC -dynamic -prof -eventlog -optc-DTHREADED_RTS
 
 # Way 'thr_dyn':
 WAY_thr_dyn_NAME=thr_dyn
@@ -92,11 +106,11 @@ WAY_thr_dyn_HC_OPTS=-fPIC -dynamic -optc-DTHREADED_RTS
 
 # Way 'thr_debug_dyn':
 WAY_thr_debug_dyn_NAME=thr_debug_dyn
-WAY_thr_debug_dyn_HC_OPTS=-fPIC -dynamic -optc-DTHREADED_RTS -optc-DDEBUG
+WAY_thr_debug_dyn_HC_OPTS=-fPIC -dynamic -optc-DTHREADED_RTS -optc-DDEBUG -eventlog
 
 # Way 'debug_dyn':
 WAY_debug_dyn_NAME=debug_dyn
-WAY_debug_dyn_HC_OPTS=-fPIC -dynamic -optc-DDEBUG -ticky -DTICKY_TICKY
+WAY_debug_dyn_HC_OPTS=-fPIC -dynamic -optc-DDEBUG -ticky -DTICKY_TICKY -eventlog
 
 # Way 'l_dyn':
 WAY_l_dyn_NAME=event logging dynamic
@@ -105,4 +119,3 @@ WAY_l_dyn_HC_OPTS= -fPIC -dynamic -eventlog
 # Way 'thr_l_dyn':
 WAY_thr_l_dyn_NAME=threaded event logging dynamic
 WAY_thr_l_dyn_HC_OPTS= -fPIC -dynamic -optc-DTHREADED_RTS -eventlog
-
index 18c3e41..664ee50 100644 (file)
@@ -20,6 +20,7 @@
 #include "LdvProfile.h"
 #include "Arena.h"
 #include "Printer.h"
+#include "Trace.h"
 #include "sm/GCThread.h"
 
 #include <string.h>
@@ -371,6 +372,19 @@ printSample(rtsBool beginSample, StgDouble sampleValue)
     }
 }
 
+static void
+dumpCostCentresToEventLog(void)
+{
+#ifdef PROFILING
+    CostCentre *cc, *next;
+    for (cc = CC_LIST; cc != NULL; cc = next) {
+        next = cc->link;
+        traceHeapProfCostCentre(cc->ccID, cc->label, cc->module,
+                                cc->srcloc, cc->is_caf);
+    }
+#endif
+}
+
 /* --------------------------------------------------------------------------
  * Initialize the heap profilier
  * ----------------------------------------------------------------------- */
@@ -400,7 +414,7 @@ initHeapProfiling(void)
     }
 
     // max_era = 2^LDV_SHIFT
-        max_era = 1 << LDV_SHIFT;
+    max_era = 1 << LDV_SHIFT;
 
     n_censuses = 32;
     censuses = stgMallocBytes(sizeof(Census) * n_censuses, "initHeapProfiling");
@@ -437,6 +451,9 @@ initHeapProfiling(void)
     }
 #endif
 
+    traceHeapProfBegin(0);
+    dumpCostCentresToEventLog();
+
     return 0;
 }
 
@@ -744,10 +761,12 @@ dumpCensus( Census *census )
     ssize_t count;
 
     printSample(rtsTrue, census->time);
+    traceHeapProfSampleBegin(era);
 
 #ifdef PROFILING
     if (RtsFlags.ProfFlags.doHeapProfile == HEAP_BY_LDV) {
-      fprintf(hp_file, "VOID\t%lu\n", (unsigned long)(census->void_total) * sizeof(W_));
+        fprintf(hp_file, "VOID\t%lu\n",
+                (unsigned long)(census->void_total) * sizeof(W_));
         fprintf(hp_file, "LAG\t%lu\n",
                 (unsigned long)(census->not_used - census->void_total) * sizeof(W_));
         fprintf(hp_file, "USE\t%lu\n",
@@ -788,6 +807,8 @@ dumpCensus( Census *census )
         switch (RtsFlags.ProfFlags.doHeapProfile) {
         case HEAP_BY_CLOSURE_TYPE:
             fprintf(hp_file, "%s", (char *)ctr->identity);
+            traceHeapProfSampleString(0, (char *)ctr->identity,
+                                      count * sizeof(W_));
             break;
         }
 #endif
@@ -795,12 +816,17 @@ dumpCensus( Census *census )
 #ifdef PROFILING
         switch (RtsFlags.ProfFlags.doHeapProfile) {
         case HEAP_BY_CCS:
-            fprint_ccs(hp_file, (CostCentreStack *)ctr->identity, RtsFlags.ProfFlags.ccsLength);
+            fprint_ccs(hp_file, (CostCentreStack *)ctr->identity,
+                       RtsFlags.ProfFlags.ccsLength);
+            traceHeapProfSampleCostCentre(0, (CostCentreStack *)ctr->identity,
+                                          count * sizeof(W_));
             break;
         case HEAP_BY_MOD:
         case HEAP_BY_DESCR:
         case HEAP_BY_TYPE:
             fprintf(hp_file, "%s", (char *)ctr->identity);
+            traceHeapProfSampleString(0, (char *)ctr->identity,
+                                      count * sizeof(W_));
             break;
         case HEAP_BY_RETAINER:
         {
index 8480f10..fdf8049 100644 (file)
@@ -622,6 +622,49 @@ void traceTaskDelete_ (Task *task)
     }
 }
 
+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);
+    }
+}
+
+#ifdef 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
+
 #ifdef DEBUG
 static void vtraceCap_stderr(Capability *cap, char *msg, va_list ap)
 {
index cad65b0..ab79671 100644 (file)
@@ -275,6 +275,20 @@ void traceTaskMigrate_ (Task       *task,
 
 void traceTaskDelete_ (Task       *task);
 
+void traceHeapProfBegin(StgWord8 profile_id);
+void traceHeapProfSampleBegin(StgInt era);
+void traceHeapProfSampleString(StgWord8 profile_id,
+                               const char *label, StgWord residency);
+#ifdef PROFILING
+void traceHeapProfCostCentre(StgWord32 ccID,
+                             const char *label,
+                             const char *module,
+                             const char *srcloc,
+                             StgBool is_caf);
+void traceHeapProfSampleCostCentre(StgWord8 profile_id,
+                                   CostCentreStack *stack, StgWord residency);
+#endif /* PROFILING */
+
 #else /* !TRACING */
 
 #define traceSchedEvent(cap, tag, tso, other) /* nothing */
@@ -304,6 +318,11 @@ void traceTaskDelete_ (Task       *task);
 #define traceTaskCreate_(taskID, cap) /* nothing */
 #define traceTaskMigrate_(taskID, cap, new_cap) /* nothing */
 #define traceTaskDelete_(taskID) /* nothing */
+#define traceHeapProfBegin(profile_id) /* nothing */
+#define traceHeapProfCostCentre(ccID, label, module, srcloc, is_caf) /* nothing */
+#define traceHeapProfSampleBegin(era) /* nothing */
+#define traceHeapProfSampleCostCentre(profile_id, stack, residency) /* nothing */
+#define traceHeapProfSampleString(profile_id, label, residency) /* nothing */
 
 #endif /* TRACING */
 
index 7cb69e8..4e4bdb5 100644 (file)
@@ -106,6 +106,11 @@ char *EventDesc[] = {
   [EVENT_TASK_MIGRATE]        = "Task migrate",
   [EVENT_TASK_DELETE]         = "Task delete",
   [EVENT_HACK_BUG_T9003]      = "Empty event for bug #9003",
+  [EVENT_HEAP_PROF_BEGIN]     = "Start of heap profile",
+  [EVENT_HEAP_PROF_COST_CENTRE]   = "Cost center definition",
+  [EVENT_HEAP_PROF_SAMPLE_BEGIN]  = "Start of heap profile sample",
+  [EVENT_HEAP_PROF_SAMPLE_STRING] = "Heap profile string sample",
+  [EVENT_HEAP_PROF_SAMPLE_COST_CENTRE] = "Heap profile cost-centre sample",
 };
 
 // Event type.
@@ -164,6 +169,22 @@ static inline void postBuf(EventsBuf *eb, StgWord8 *buf, uint32_t size)
     eb->pos += size;
 }
 
+/* Post a null-terminated string to the event log.
+ * It is the caller's responsibility to ensure that there is
+ * enough room for strlen(buf)+1 bytes.
+ */
+static inline void postString(EventsBuf *eb, const char *buf)
+{
+    if (buf) {
+        int len = strlen(buf);
+        ASSERT(eb->begin + eb->size > eb->pos + len);
+        memcpy(eb->pos, buf, len);
+        eb->pos += len;
+    }
+    *eb->pos = 0;
+    eb->pos++;
+}
+
 static inline StgWord64 time_ns(void)
 { return TimeToNS(stat_getElapsedTime()); }
 
@@ -209,6 +230,7 @@ static inline void postInt8(EventsBuf *eb, StgInt8 i)
 static inline void postInt32(EventsBuf *eb, StgInt32 i)
 { postWord32(eb, (StgWord32)i); }
 
+#define EVENT_SIZE_DYNAMIC (-1)
 
 void
 initEventLogging(void)
@@ -429,6 +451,26 @@ initEventLogging(void)
             eventTypes[t].size = 0;
             break;
 
+        case EVENT_HEAP_PROF_BEGIN:
+            eventTypes[t].size = EVENT_SIZE_DYNAMIC;
+            break;
+
+        case EVENT_HEAP_PROF_COST_CENTRE:
+            eventTypes[t].size = EVENT_SIZE_DYNAMIC;
+            break;
+
+        case EVENT_HEAP_PROF_SAMPLE_BEGIN:
+            eventTypes[t].size = 8;
+            break;
+
+        case EVENT_HEAP_PROF_SAMPLE_STRING:
+            eventTypes[t].size = EVENT_SIZE_DYNAMIC;
+            break;
+
+        case EVENT_HEAP_PROF_SAMPLE_COST_CENTRE:
+            eventTypes[t].size = EVENT_SIZE_DYNAMIC;
+            break;
+
         default:
             continue; /* ignore deprecated events */
         }
@@ -1098,6 +1140,147 @@ void postBlockMarker (EventsBuf *eb)
     postCapNo(eb, eb->capno);
 }
 
+typedef enum {
+    HEAP_PROF_BREAKDOWN_COST_CENTRE = 0x1,
+    HEAP_PROF_BREAKDOWN_MODULE,
+    HEAP_PROF_BREAKDOWN_CLOSURE_DESCR,
+    HEAP_PROF_BREAKDOWN_TYPE_DESCR,
+    HEAP_PROF_BREAKDOWN_RETAINER,
+    HEAP_PROF_BREAKDOWN_BIOGRAPHY,
+} HeapProfBreakdown;
+
+static HeapProfBreakdown getHeapProfBreakdown(void)
+{
+    switch (RtsFlags.ProfFlags.doHeapProfile) {
+    case HEAP_BY_CCS:
+        return HEAP_PROF_BREAKDOWN_COST_CENTRE;
+    case HEAP_BY_MOD:
+        return HEAP_PROF_BREAKDOWN_MODULE;
+    case HEAP_BY_DESCR:
+        return HEAP_PROF_BREAKDOWN_CLOSURE_DESCR;
+    case HEAP_BY_TYPE:
+        return HEAP_PROF_BREAKDOWN_TYPE_DESCR;
+    case HEAP_BY_RETAINER:
+        return HEAP_PROF_BREAKDOWN_RETAINER;
+    case HEAP_BY_LDV:
+        return HEAP_PROF_BREAKDOWN_BIOGRAPHY;
+    default:
+        barf("getHeapProfBreakdown: unknown heap profiling mode");
+    }
+}
+
+void postHeapProfBegin(StgWord8 profile_id)
+{
+    ACQUIRE_LOCK(&eventBufMutex);
+    PROFILING_FLAGS *flags = &RtsFlags.ProfFlags;
+    StgWord modSelector_len   =
+        flags->modSelector ? strlen(flags->modSelector) : 0;
+    StgWord descrSelector_len =
+        flags->descrSelector ? strlen(flags->descrSelector) : 0;
+    StgWord typeSelector_len  =
+        flags->typeSelector ? strlen(flags->typeSelector) : 0;
+    StgWord ccSelector_len    =
+        flags->ccSelector ? strlen(flags->ccSelector) : 0;
+    StgWord ccsSelector_len   =
+        flags->ccsSelector ? strlen(flags->ccsSelector) : 0;
+    StgWord retainerSelector_len =
+        flags->retainerSelector ? strlen(flags->retainerSelector) : 0;
+    StgWord bioSelector_len   =
+        flags->bioSelector ? strlen(flags->bioSelector) : 0;
+    StgWord len =
+        1+8+4 + modSelector_len + descrSelector_len +
+        typeSelector_len + ccSelector_len + ccsSelector_len +
+        retainerSelector_len + bioSelector_len + 7;
+    ensureRoomForVariableEvent(&eventBuf, len);
+    postEventHeader(&eventBuf, EVENT_HEAP_PROF_BEGIN);
+    postPayloadSize(&eventBuf, len);
+    postWord8(&eventBuf, profile_id);
+    postWord64(&eventBuf, TimeToNS(flags->heapProfileInterval));
+    postWord32(&eventBuf, getHeapProfBreakdown());
+    postString(&eventBuf, flags->modSelector);
+    postString(&eventBuf, flags->descrSelector);
+    postString(&eventBuf, flags->typeSelector);
+    postString(&eventBuf, flags->ccSelector);
+    postString(&eventBuf, flags->ccsSelector);
+    postString(&eventBuf, flags->retainerSelector);
+    postString(&eventBuf, flags->bioSelector);
+    RELEASE_LOCK(&eventBufMutex);
+}
+
+void postHeapProfSampleBegin(StgInt era)
+{
+    ACQUIRE_LOCK(&eventBufMutex);
+    ensureRoomForEvent(&eventBuf, EVENT_HEAP_PROF_SAMPLE_BEGIN);
+    postEventHeader(&eventBuf, EVENT_HEAP_PROF_SAMPLE_BEGIN);
+    postWord64(&eventBuf, era);
+    RELEASE_LOCK(&eventBufMutex);
+}
+
+void postHeapProfSampleString(StgWord8 profile_id,
+                              const char *label,
+                              StgWord64 residency)
+{
+    ACQUIRE_LOCK(&eventBufMutex);
+    StgWord label_len = strlen(label);
+    StgWord len = 1+8+label_len+1;
+    ensureRoomForVariableEvent(&eventBuf, len);
+    postEventHeader(&eventBuf, EVENT_HEAP_PROF_SAMPLE_STRING);
+    postPayloadSize(&eventBuf, len);
+    postWord8(&eventBuf, profile_id);
+    postWord64(&eventBuf, residency);
+    postString(&eventBuf, label);
+    RELEASE_LOCK(&eventBufMutex);
+}
+
+#ifdef PROFILING
+void postHeapProfCostCentre(StgWord32 ccID,
+                            const char *label,
+                            const char *module,
+                            const char *srcloc,
+                            StgBool is_caf)
+{
+    ACQUIRE_LOCK(&eventBufMutex);
+    StgWord label_len = strlen(label);
+    StgWord module_len = strlen(module);
+    StgWord srcloc_len = strlen(srcloc);
+    StgWord len = 4+label_len+module_len+srcloc_len+3+1;
+    ensureRoomForVariableEvent(&eventBuf, len);
+    postEventHeader(&eventBuf, EVENT_HEAP_PROF_COST_CENTRE);
+    postPayloadSize(&eventBuf, len);
+    postWord32(&eventBuf, ccID);
+    postString(&eventBuf, label);
+    postString(&eventBuf, module);
+    postString(&eventBuf, srcloc);
+    postWord8(&eventBuf, is_caf);
+    RELEASE_LOCK(&eventBufMutex);
+}
+
+void postHeapProfSampleCostCentre(StgWord8 profile_id,
+                                  CostCentreStack *stack,
+                                  StgWord64 residency)
+{
+    ACQUIRE_LOCK(&eventBufMutex);
+    StgWord depth = 0;
+    CostCentreStack *ccs;
+    for (ccs = stack; ccs != NULL && ccs != CCS_MAIN; ccs = ccs->prevStack)
+        depth++;
+    if (depth > 0xff) depth = 0xff;
+
+    StgWord len = 1+8+1+depth*4;
+    ensureRoomForVariableEvent(&eventBuf, len);
+    postEventHeader(&eventBuf, EVENT_HEAP_PROF_SAMPLE_COST_CENTRE);
+    postPayloadSize(&eventBuf, len);
+    postWord8(&eventBuf, profile_id);
+    postWord64(&eventBuf, residency);
+    postWord8(&eventBuf, depth);
+    for (ccs = stack;
+         depth>0 && ccs != NULL && ccs != CCS_MAIN;
+         ccs = ccs->prevStack, depth--)
+        postWord32(&eventBuf, ccs->cc->ccID);
+    RELEASE_LOCK(&eventBufMutex);
+}
+#endif /* PROFILING */
+
 void printAndClearEventBuf (EventsBuf *ebuf)
 {
     closeBlockMarker(ebuf);
index ed783bc..462f5f5 100644 (file)
@@ -133,6 +133,26 @@ void postTaskMigrateEvent (EventTaskId taskId,
 
 void postTaskDeleteEvent (EventTaskId taskId);
 
+void postHeapProfBegin(StgWord8 profile_id);
+
+void postHeapProfSampleBegin(StgInt era);
+
+void postHeapProfSampleString(StgWord8 profile_id,
+                              const char *label,
+                              StgWord64 residency);
+
+#ifdef PROFILING
+void postHeapProfCostCentre(StgWord32 ccID,
+                            const char *label,
+                            const char *module,
+                            const char *srcloc,
+                            StgBool is_caf);
+
+void postHeapProfSampleCostCentre(StgWord8 profile_id,
+                                  CostCentreStack *stack,
+                                  StgWord64 residency);
+#endif /* PROFILING */
+
 #else /* !TRACING */
 
 INLINE_HEADER void postSchedEvent (Capability *cap  STG_UNUSED,