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

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

15.2. Runtime system diagnostics¶

ThreadId ~ Word32

CapNo ~ Word16

CapSetId ~ Word32

15.2.1. Capability sets¶

TODO

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

15.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 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).

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

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

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

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

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

15.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).

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

15.3.1. Metadata event types¶

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

15.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?

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

15.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)

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

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

15.4.1. Profile begin event¶

PROF_BEGIN¶

Tag:	168
Length:	fixed
Field Word64:	tick interval, in nanoseconds

Marks the beginning of a time profile.

15.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)

15.5. Biographical profile sample event¶

A variable-length packet encoding a profile sample.

BIO_PROF_SAMPLE_BEGIN¶

Tag:	166

TODO

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

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