GitLab

This introduces a few events to mark key points in the nonmoving
garbage collection cycle. These include:

 * `EVENT_CONC_MARK_BEGIN`, denoting the beginning of a round of
   marking. This may happen more than once in a single major collection
   since we the major collector iterates until it hits a fixed point.

 * `EVENT_CONC_MARK_END`, denoting the end of a round of marking.

 * `EVENT_CONC_SYNC_BEGIN`, denoting the beginning of the post-mark
   synchronization phase

 * `EVENT_CONC_UPD_REM_SET_FLUSH`, indicating that a capability has
   flushed its update remembered set.

 * `EVENT_CONC_SYNC_END`, denoting that all mutators have flushed their
   update remembered sets.

 * `EVENT_CONC_SWEEP_BEGIN`, denoting the beginning of the sweep portion
   of the major collection.

 * `EVENT_CONC_SWEEP_END`, denoting the end of the sweep portion of the
   major collection.

This patch adds a new eventlog event which indicates the start of
a biographical profiler sample. These are different to normal events as
they also include the timestamp of when the census took place. This is
because the LDV profiler only emits samples at the end of the run.

Now all the different profiling modes emit consumable events to the
eventlog.

This allows a user to observe how long a sampling period lasts so that
the time taken can be removed from the profiling output.

Fixes #16697

This adds a new primop called traceBinaryEvent# that takes the length
of binary data and a pointer to the data, then emits it to the eventlog.

There is some example code that uses this primop and the new event:

* [traceBinaryEventIO][1] that calls `traceBinaryEvent#`

* [A patch to ghc-events][2] that parses the new `EVENT_USER_BINARY_MSG`

There's no corresponding issue on Trac but it was discussed at
ghc-devs [3].

[1] https://github.com/maoe/ghc-trace-events/blob
    /fb226011ef1f85a97b4da7cc9d5f98f9fe6316ae/src/Debug/Trace/Binary.hs#L29)
[2] https://github.com/maoe/ghc-events/commit
    /239ca77c24d18cdd10d6d85a0aef98e4a7c56ae6)
[3] https://mail.haskell.org/pipermail/ghc-devs/2018-May/015791.html

Reviewers: bgamari, erikd, simonmar

Reviewed By: bgamari

Subscribers: rwbarton, thomie, carter

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

This trailing comma snuck in in a recent patch. There is nothing wrong with the
comma; it's perfectly valid C99, yet nevertheless Mac OS X's dtrace utility
chokes on it with,

    dtrace: failed to compile script rts/RtsProbes.d:
            "includes/rts/EventLogFormat.h", line 245: syntax error near "}"
    make[1]: *** [rts/dist/build/RtsProbes.h] Error 1

Test Plan: Build, program with `-eventlog`, try running with `+RTS -h`

Reviewers: austin, erikd, simonmar

Subscribers: rwbarton, thomie

GHC Trac Issues: #14096

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

Reviewers: austin, erikd, simonmar

Subscribers: rwbarton, thomie

GHC Trac Issues: #14096

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

An additional stat is tracked per gc: par_balanced_copied This is the
the number of bytes copied by each gc thread under the balanced lmit,
which is simply (copied_bytes / num_gc_threads).  The stat is added to
all the appropriate GC structures, so is visible in the eventlog and in
GHC.Stats.

A note is added explaining how work balance is computed.

Remove some end of line whitespace

Test Plan:
./validate
experiment with the program attached to the ticket
examine code changes carefully

Reviewers: simonmar, austin, hvr, bgamari, erikd

Reviewed By: simonmar

Subscribers: Phyx, rwbarton, thomie

GHC Trac Issues: #13830

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

Our new CPP linter enforces this.

This both says what we mean and silences a bunch of spurious CPP linting
warnings. This pragma is supported by all CPP implementations which we
support.

Reviewers: austin, erikd, simonmar, hvr

Reviewed By: simonmar

Subscribers: rwbarton, thomie

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

Test Plan: Try it

Reviewers: hvr, simonmar, austin, erikd

Subscribers: thomie

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

GHC Trac Issues: #11094

This has been unnecessary for quite some time due to the create/delete
capability events.

The TL;DR is that by adding this, we can distinguish GHC 7.8.3 from
7.8.2, which had a buggy implementation. See the ticket for details.
Signed-off-by: Austin Seipp <austin@well-typed.com>

In time-based profiling visualisations (e.g. heap profiles and ThreadScope)
it would be useful to be able to mark particular points in the execution and
have those points in time marked in the visualisation.

The traceMarker# primop currently emits an event into the eventlog. In
principle it could be extended to do something in the heap profiling too.

Based on initial patches by Mikolaj Konarski <mikolaj@well-typed.com>

These new eventlog events are to let profiling tools keep track of all
the OS threads that belong to an RTS capability at any moment in time.
In the RTS, OS threads correspond to the Task abstraction, so that is
what we track. There are events for tasks being created, migrated
between capabilities and deleted. In particular the task creation event
also records the kernel thread id which lets us match up the OS thread
with data collected by others tools (in the initial use case with
Linux's perf tool, but in principle also with DTrace).

Quoting design rationale by dcoutts: The event indicates that we're doing
a stop-the-world GC and all other HECs should be between their GC_START
and GC_END events at that moment. We don't want to use GC_STATS_GHC
for that, because GC_STATS_GHC is for extra GHC-specific info,
not something we have to rely on to be able to match the GC pauses
across HECs to a particular global GC.

The EventLogFormat.h described the spark counter fields in a different
order to that which ghc emits (the GC'd and fizzled fields were
reversed). At this stage it is easier to fix the ghc-events lib and
to have ghc continue to emit them in the current order.

They cover much the same info as is available via the GHC.Stats module
or via the '+RTS -s' textual output, but via the eventlog and with a
better sampling frequency.

We have three new generic heap info events and two very GHC-specific
ones. (The hope is the general ones are usable by other implementations
that use the same eventlog system, or indeed not so sensitive to changes
in GHC itself.)

The general ones are:

 * total heap mem allocated since prog start, on a per-HEC basis
 * current size of the heap (MBlocks reserved from OS for the heap)
 * current size of live data in the heap

Currently these are all emitted by GHC at GC time (live data only at
major GC).

The GHC specific ones are:

 * an event giving various static heap paramaters:
   * number of generations (usually 2)
   * max size if any
   * nursary size
   * MBlock and block sizes
 * a event emitted on each GC containing:
   * GC generation (usually just 0,1)
   * total bytes copied
   * bytes lost to heap slop and fragmentation
   * the number of threads in the parallel GC (1 for serial)
   * the maximum number of bytes copied by any par GC thread
   * the total number of bytes copied by all par GC threads
     (these last three can be used to calculate an estimate of the
      work balance in parallel GCs)

Now that we can adjust the number of capabilities on the fly, we need
this reflected in the eventlog. Previously the eventlog had a single
startup event that declared a static number of capabilities. Obviously
that's no good anymore.

For compatability we're keeping the EVENT_STARTUP but adding new
EVENT_CAP_CREATE/DELETE. The EVENT_CAP_DELETE is actually just the old
EVENT_SHUTDOWN but renamed and extended (using the existing mechanism
to extend eventlog events in a compatible way). So we now emit both
EVENT_STARTUP and EVENT_CAP_CREATE. One day we will drop EVENT_STARTUP.

Since reducing the number of capabilities at runtime does not really
delete them, it just disables them, then we also have new events for
disable/enable.

The old EVENT_SHUTDOWN was in the scheduler class of events. The new
EVENT_CAP_* events are in the unconditional class, along with the
EVENT_CAPSET_* ones. Knowing when capabilities are created and deleted
is crucial to making sense of eventlogs, you always want those events.
In any case, they're extremely low volume.

The existing GHC.Conc.labelThread will now also emit the the thread
label into the eventlog. Profiling tools like ThreadScope could then
use the thread labels rather than thread numbers.

Eventlog timestamps are elapsed times (in nanoseconds) relative to the
process start. To be able to merge eventlogs from multiple processes we
need to be able to align their timelines. If they share a clock domain
(or a user judges that their clocks are sufficiently closely
synchronised) then it is sufficient to know how the eventlog timestamps
match up with the clock.

The EVENT_WALL_CLOCK_TIME contains the clock time with (up to)
nanosecond precision. It is otherwise an ordinary event and so contains
the usual timestamp for the same moment in time. It therefore enables
us to match up all the eventlog timestamps with clock time.

Replaces the existing EVENT_RUN/STEAL_SPARK events with 7 new events
covering all stages of the spark lifcycle:
  create, dud, overflow, run, steal, fizzle, gc

The sampled spark events are still available. There are now two event
classes for sparks, the sampled and the fully accurate. They can be
enabled/disabled independently. By default +RTS -l includes the sampled
but not full detail spark events. Use +RTS -lf-p to enable the detailed
'f' and disable the sampled 'p' spark.

Includes work by Mikolaj <mikolaj.konarski@gmail.com>

A new eventlog event containing 7 spark counters/statistics: sparks
created, dud, overflowed, converted, GC'd, fizzled and remaining.
These are maintained and logged separately for each capability.
We log them at startup, on each GC (minor and major) and on shutdown.

The process ID, parent process ID, rts name and version
The program arguments and environment.

This reverts commit 58532eb4.
Turns out it didn't work on Windows and it'll need some non-trivial changes
to make it work on Windows. We'll get it in later once that's sorted out.

So we can now get these in ThreadScope:

  19487000: cap 1: stopping thread 6 (blocked on black hole owned by thread 4)

Note: needs an update to ghc-events.  Older ThreadScopes will just
ignore the new information.

- Defines a DTrace provider, called 'HaskellEvent', that provides a probe
  for every event of the eventlog framework.
- In contrast to the original eventlog, the DTrace probes are available in
  all flavours of the runtime system (DTrace probes have virtually no
  overhead if not enabled); when -DTRACING is defined both the regular
  event log as well as DTrace probes can be used.
- Currently, Mac OS X only.  User-space DTrace probes are implemented
  differently on Mac OS X than in the original DTrace implementation.
  Nevertheless, it shouldn't be too hard to enable these probes on other
  platforms, too.
- Documentation is at http://hackage.haskell.org/trac/ghc/wiki/DTrace

The log file format was still using 32 bits, this just updates the
header file to match; there should be no functional changes.

added:

 primop  TraceEventOp "traceEvent#" GenPrimOp
   Addr# -> State# s -> State# s
   { Emits an event via the RTS tracing framework.  The contents
     of the event is the zero-terminated byte string passed as the first
     argument.  The event will be emitted either to the .eventlog file,
     or to stderr, depending on the runtime RTS flags. }

and added the required RTS functionality to support it.  Also a bit of
refactoring in the RTS tracing code.

This makes events smaller and tracing quicker, and speeds up reading
and sorting the trace file.

HEADS UP: this changes the format of event log files.  Corresponding
changes to the ghc-events package are required (and will be pushed
soon).  Normally we would make backwards-compatible changes, but this
changes the format of every event (to remove the capability) so I'm
breaking the rules this time.  This will be the only time we can do
this, since the format becomes public in 6.12.1.

These indicate the size and time span of a sequence of events in the
event log, to make it easier to sort and navigate a large event log.

  - tracing facilities are now enabled with -DTRACING, and -DDEBUG
    additionally enables debug-tracing.  -DEVENTLOG has been
    removed.

  - -debug now implies -eventlog

  - events can be printed to stderr instead of being sent to the
    binary .eventlog file by adding +RTS -v (which is implied by the
    +RTS -Dx options).

  - -Dx debug messages can be sent to the binary .eventlog file
    by adding +RTS -l.  This should help debugging by reducing
    the impact of debug tracing on execution time.

  - Various debug messages that duplicated the information in events
    have been removed.

The first phase of this tidyup is focussed on the header files, and in
particular making sure we are exposinng publicly exactly what we need
to, and no more.

 - Rts.h now includes everything that the RTS exposes publicly,
   rather than a random subset of it.

 - Most of the public header files have moved into subdirectories, and
   many of them have been renamed.  But clients should not need to
   include any of the other headers directly, just #include the main
   public headers: Rts.h, HsFFI.h, RtsAPI.h.

 - All the headers needed for via-C compilation have moved into the
   stg subdirectory, which is self-contained.  Most of the headers for
   the rest of the RTS APIs have moved into the rts subdirectory.

 - I left MachDeps.h where it is, because it is so widely used in
   Haskell code.
 
 - I left a deprecated stub for RtsFlags.h in place.  The flag
   structures are now exposed by Rts.h.

 - Various internal APIs are no longer exposed by public header files.

 - Various bits of dead code and declarations have been removed

 - More gcc warnings are turned on, and the RTS code is more
   warning-clean.

 - More source files #include "PosixSource.h", and hence only use
   standard POSIX (1003.1c-1995) interfaces.

There is a lot more tidying up still to do, this is just the first
pass.  I also intend to standardise the names for external RTS APIs
(e.g use the rts_ prefix consistently), and declare the internal APIs
as hidden for shared libraries.

Also some tidyups and renaming