18. Eventlog encodings

This section documents the encodings of the events emitted to GHC’s event log. 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. GHC ships with a C header file (EventlogFormat.h) which provides symbolic names for the event type IDs described in this file.

18.1. Event log format

The log format is designed to be extensible: old tools should be able to parse (but not necessarily understand all of) new versions of the format, and new tools will be able to understand old log files.

• The format is endian-independent: all values are represented in big-endian order.

• The format is extensible:

  • The header describes each event type and its length. Tools that don’t recognise a particular event type can skip those events.
  • There is room for extra information in the event type specification, which can be ignored by older tools.
  • Events can have extra information added, but existing fields cannot be changed. Tools should ignore extra fields at the end of the event record.

The event-log stream begins with a header describing the event types present in the file. The header is followed by the event records themselves, each of which consist of a 64-bit timestamp

log : EVENT_HEADER_BEGIN
      EventType*
      EVENT_HEADER_END
      EVENT_DATA_BEGIN
      Event*
      EVENT_DATA_END

EventType :
      EVENT_ET_BEGIN
      Word16         -- unique identifier for this event
      Int16          -- >=0  size of the event in bytes (minus the header)
                     -- -1   variable size
      Word32         -- length of the next field in bytes
      Word8*         -- string describing the event
      Word32         -- length of the next field in bytes
      Word8*         -- extra info (for future extensions)
      EVENT_ET_END

Event :
      Word16         -- event_type
      Word64         -- time (nanosecs)
      [Word16]       -- length of the rest (for variable-sized events only)
      ... extra event-specific info ...

There are two classes of event types:

• Fixed size: All event records of a fixed-sized type are of the same length, given in the header event-log header.
• Variable size: Each event record includes a length field.

18.2. Runtime system diagnostics

• ThreadId ~ Word32
• CapNo ~ Word16
• CapSetId ~ Word32

18.2.1. Capability sets

TODO

18.2.2. Environment information

These events are typically produced during program startup and describe the environment which the program is being run in.

RTS_IDENTIFIER

Tag

29

Length

variable

Field CapSetId

Capability set

Field String

Runtime system name and version.

Describes the name and version of the runtime system responsible for the indicated capability set.

PROGRAM_ARGS

Tag

30

Length

variable

Field CapSetId

Capability set

Field [String]

The command-line arguments passed to the program

Describes the command-line used to start the program.

PROGRAM_ENV

Tag

31

Length

variable

Field CapSetId

Capability set

Field [String]

The environment variable name/value pairs. (TODO: encoding?)

Describes the environment variables present in the program’s environment.

18.2.3. Thread and scheduling events

CREATE_THREAD

Tag

0

Length

fixed

Field ThreadId

thread id

Marks the creation of a Haskell thread.

RUN_THREAD

Tag

1

Length

fixed

Field ThreadId

thread id

The indicated thread has started running.

STOP_THREAD

Tag

2

Length

fixed

Field ThreadId

thread id

Field Word16

status

• 1: HeapOverflow
• 2: StackOverflow
• 3: ThreadYielding
• 4: ThreadBlocked
• 5: ThreadFinished
• 6: ForeignCall
• 7: BlockedOnMVar
• 8: BlockedOnBlackHole
• 9: BlockedOnRead
• 10: BlockedOnWrite
• 11: BlockedOnDelay
• 12: BlockedOnSTM
• 13: BlockedOnDoProc
• 16: BlockedOnMsgThrowTo

Field ThreadId

thread id of thread being blocked on (only for some status values)

The indicated thread has stopped running for the reason given by status.

THREAD_RUNNABLE

Tag

3

Length

fixed

Field ThreadId

thread id

The indicated thread is has been marked as ready to run.

MIGRATE_THREAD

Tag

4

Length

fixed

Field ThreadId

thread id

Field CapNo

capability

The indicated thread has been migrated to a new capability.

THREAD_WAKEUP

Tag

8

Length

fixed

Field ThreadId

thread id

Field CapNo

other capability

The indicated thread has been been woken up on another capability.

THREAD_LABEL

Tag

44

Length

fixed

Field ThreadId

thread id

Field String

label

The indicated thread has been given a label (e.g. with Control.Concurrent.setThreadLabel).

18.2.4. Garbage collector events

GC_START

Tag

9

Length

fixed

A garbage collection pass has been started.

GC_END

Tag

10

Length

fixed

A garbage collection pass has been finished.

REQUEST_SEQ_GC

Tag

11

Length

fixed

A sequential garbage collection has been requested by a capability.

REQUEST_PAR_GC

Tag

12

Length

fixed

A parallel garbage collection has been requested by a capability.

GC_IDLE

Tag

20

Length

fixed

An idle-time garbage collection has been started.

GC_WORK

Tag

21

Length

fixed

Marks the start of concurrent scavenging.

GC_DONE

Tag

22

Length

fixed

Marks the end of concurrent scavenging.

GC_STATS_GHC

Tag

53

Length

fixed

Field CapSetId

heap capability set

Field Word16

generation of collection

Field Word64

bytes copied

Field Word64

bytes of slop found

Field Word64

TODO

Field Word64

number of parallel garbage collection threads

Field Word64

maximum number of bytes copied by any single collector thread

Field Word64

total bytes copied by all collector threads

Report various information about the heap configuration. Typically produced during RTS initialization..

GC_GLOBAL_SYNC

Tag

54

Length

fixed

TODO

18.2.5. Heap events and statistics

HEAP_ALLOCATED

Tag

49

Length

fixed

Field CapSetId

heap capability set

Field Word64

allocated bytes

A new chunk of heap has been allocated by the indicated capability set.

HEAP_SIZE

Tag

50

Length

fixed

Field CapSetId

heap capability set

Field Word64

heap size in bytes

Report the heap size.

HEAP_LIVE

Tag

51

Length

fixed

Field CapSetId

heap capability set

Field Word64

heap size in bytes

Report the live heap size.

HEAP_INFO_GHC

Tag

52

Length

fixed

Field CapSetId

heap capability set

Field Word16

number of garbage collection generations

Field Word64

maximum heap size

Field Word64

allocation area size

Field Word64

MBlock size

Field Word64

Block size

Report various information about the heap configuration. Typically produced during RTS initialization..

18.2.6. Spark events

CREATE_SPARK_THREAD

Tag

15

Length

fixed

A thread has been created to perform spark evaluation.

SPARK_COUNTERS

Tag

34

Length

fixed

A periodic reporting of various statistics of spark evaluation.

SPARK_CREATE

Tag

35

Length

fixed

A spark has been added to the spark pool.

SPARK_DUD

Tag

36

Length

fixed

TODO

SPARK_OVERFLOW

Tag

37

Length

fixed

TODO

SPARK_RUN

Tag

38

Length

fixed

Evaluation has started on a spark.

SPARK_STEAL

Tag

39

Length

fixed

Field Word16

capability from which the spark was stolen

A spark has been stolen from another capability for evaluation.

SPARK_FIZZLE

Tag

40

Length

fixed

A spark has been GC’d before being evaluated.

SPARK_GC

Tag

41

Length

fixed

An unevaluated spark has been garbage collected.

18.2.7. Capability events

CAP_CREATE

Tag

45

Length

fixed

Field CapNo

the capability number

A capability has been started.

CAP_DELETE

Tag

46

Length

fixed

A capability has been deleted.

CAP_DISABLE

Tag

47

Length

fixed

A capability has been disabled.

CAP_ENABLE

Tag

48

Length

fixed

A capability has been enabled.

18.2.8. Task events

TASK_CREATE

Tag

55

Length

fixed

Field TaskId

task id

Field CapNo

capability number

Field ThreadId

TODO

Marks the creation of a task.

TASK_MIGRATE

Tag

56

Length

fixed

Field TaskId

task id

Field CapNo

old capability

Field CapNo

new capability

Marks the migration of a task to a new capability.

18.2.9. Tracing events

LOG_MSG

Tag

16

Length

variable

Field String

The message

A log message from the runtime system.

BLOCK_MARKER

Tag

18

Length

variable

Field Word32

size

Field Word64

end time in nanoseconds

Field String

marker name

TODO

USER_MSG

Tag

19

Length

variable

Field String

message

A user log message (from, e.g., Control.Concurrent.traceEvent).

USER_MARKER

Tag

58

Length

variable

Field String

marker name

A user marker (from Debug.Trace.traceMarker).

18.3. 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.

18.3.1. Metadata event types

18.3.1.1. Beginning of sample stream

A single fixed-width event emitted during program start-up describing the samples that follow.

HEAP_PROF_BEGIN

Tag

160

Length

variable

Field Word8

profile ID

Field Word64

sampling period in nanoseconds

Field Word32

sample breadown type. One of,

• HEAP_PROF_BREAKDOWN_COST_CENTER (output from -hc)
• HEAP_PROF_BREAKDOWN_CLOSURE_DESCR (output from -hd)
• HEAP_PROF_BREAKDOWN_RETAINER (output from -hr)
• HEAP_PROF_BREAKDOWN_MODULE (output from -hm)
• HEAP_PROF_BREAKDOWN_TYPE_DESCR (output from -hy)
• HEAP_PROF_BREAKDOWN_BIOGRAPHY (output from -hb)
• HEAP_PROF_BREAKDOWN_CLOSURE_TYPE (output from -hT)

Field String

module filter

Field String

closure description filter

Field String

type description filter

Field String

cost centre filter

Field String

cost centre stack filter

Field String

retainer filter

Field String

biography filter

18.3.1.2. Cost centre definitions

A variable-length packet produced once for each cost centre,

HEAP_PROF_COST_CENTRE

Tag

161

Length

fixed

Field Word32

cost centre number

Field String

label

Field String

module

Field String

source location

Field Word8

flags:

• bit 0: is the cost-centre a CAF?

18.3.1.3. Sample event types

A sample (consisting of a list of break-down classes, e.g. cost centres, and heap residency sizes), is to be encoded in the body of one or more events.

We normally mark the beginning of a new sample with an EVENT_HEAP_PROF_SAMPLE_BEGIN event,

HEAP_PROF_SAMPLE_BEGIN

Length

fixed

Field Word64

sample number

Marks the beginning of a heap profile sample.

Biographical profiling samples start with the EVENT_HEAP_BIO_PROF_SAMPLE_BEGIN event. These events also include a timestamp which indicates when the sample was taken. This is because all these samples will appear at the end of the eventlog due to how the biographical profiling mode works. You can use the timestamp to reorder the samples relative to the other events.

HEAP_BIO_PROF_SAMPLE_BEGIN

Tag

166

Length

fixed

Field Word64

sample number

Field Word64

eventlog timestamp in ns

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.

At the end of the sample period the EVENT_HEAP_PROF_SAMPLE_END event if emitted. This is useful to properly delimit the sampling period and to record the total time spent profiling.

HEAP_PROF_SAMPLE_END

Tag

165

Length

fixed

Field Word64

sample number

Marks the end of a heap profile sample.

18.3.1.4. Cost-centre break-down

A variable-length packet encoding a heap profile sample broken down by,

• cost-centre (-hc)

HEAP_PROF_SAMPLE_COST_CENTRE

Tag

163

Length

variable

Field Word8

profile ID

Field Word64

heap residency in bytes

Field Word8

stack depth

Field Word32[]

cost centre stack starting with inner-most (cost centre numbers)

18.3.1.5. String break-down

A variable-length event encoding a heap sample broken down by,

• type description (-hy)
• closure description (-hd)
• module (-hm)

HEAP_PROF_SAMPLE_STRING

Tag

164

Length

variable

Field Word8

profile ID

Field Word64

heap residency in bytes

Field String

type or closure description, or module name

18.4. Time profiler event log output

The time profiling mode enabled by -p also emits sample events to the eventlog. At the start of profiling the tick interval is emitted to the eventlog and then on each tick the current cost centre stack is emitted. Together these enable a user to construct an approximate track of the executation of their program.

18.4.1. Profile begin event

PROF_BEGIN

Tag

168

Length

fixed

Field Word64

tick interval, in nanoseconds

Marks the beginning of a time profile.

18.4.2. Profile sample event

A variable-length packet encoding a profile sample.

PROF_SAMPLE_COST_CENTRE

Tag

167

Length

variable

Field Word32

capability

Field Word64

current profiling tick

Field Word8

stack depth

Field Word32[]

cost centre stack starting with inner-most (cost centre numbers)

18.5. Biographical profile sample event

A variable-length packet encoding a profile sample.

BIO_PROF_SAMPLE_BEGIN

Tag

166

TODO

18.6. Non-moving GC event output

These events mark various stages of the non-moving collection lifecycle. These are enabled with the +RTS -lg event-set.

CONC_MARK_BEGIN

Tag

200

Length

fixed

Marks the beginning of marking by the concurrent collector.

CONC_MARK_END

Tag

201

Length

fixed

Marks the end of marking by the concurrent collector.

CONC_SYNC_BEGIN

Tag

202

Length

fixed

Marks the beginning of the concurrent garbage collector’s post-mark synchronization phase.

CONC_SYNC_END

Tag

203

Length

fixed

Marks the end of the concurrent garbage collector’s post-mark synchronization phase.

CONC_SWEEP_BEGIN

Tag

204

Length

fixed

Marks the beginning of the concurrent garbage collector’s sweep phase.

CONC_SWEEP_END

Tag

205

Length

fixed

Marks the end of the concurrent garbage collector’s sweep phase.

CONC_UPD_REM_SET_FLUSH

Tag

206

Length

fixed

Marks a capability flushing its local update remembered set accumulator.

18.6.1. Non-moving heap census

The non-moving heap census events (enabled with the +RTS -ln event-set) are intended to provide insight into fragmentation of the non-moving heap.

NONMOVING_HEAP_CENSUS

Tag

207

Length

fixed

Field Word8

base-2 logarithm of blk_sz.

Field Word32

number of active segments.

Field Word32

number of filled segments.

Field Word32

number of live blocks.

Describes the occupancy of the blk_sz sub-heap.