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.
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 (EventType
) present in the file. The header is followed by the event records (Event
) themselves, each of which start with the event type id and a 64-bit timestamp:
EventLog : EVENT_HEADER_BEGIN EVENT_HET_BEGIN -- header event types begin EventType* EVENT_HET_END -- header event types end EVENT_HEADER_END EVENT_DATA_BEGIN Event* EVENT_DATA_END EventType : EVENT_ET_BEGIN Word16 -- event type id, unique identifier for this event Int16 -- >=0 size of the event record in bytes (minus the event type id and timestamp fields) -- -1 variable size Word32 -- size of the event description in bytes Word8* -- event description, UTF8 encoded string describing the event Word32 -- size of the extra info in bytes Word8* -- extra info (for future extensions) EVENT_ET_END Event : Word16 -- event type id, as included in the event log header Word64 -- timestamp (nanoseconds) [Word16] -- length of the rest (optional, for variable-sized events only) ... event specific info ...
There are two classes of event types:
17.2. Runtime system diagnostics¶
Fixed size: All event records of a fixed-sized type are of the same length, the size given in the header event-log header.
Variable size: Each event record includes a length field.
17.2.1. Capability sets¶
ThreadId ~ Word32
CapNo ~ Word16
CapSetId ~ Word32
TODO
17.2.2. Environment information¶These events are typically produced during program startup and describe the environment which the program is being run in.
29
variable
Capability set
Runtime system name and version.
Describes the name and version of the runtime system responsible for the indicated capability set.
30
variable
Capability set
The command-line arguments passed to the program
Describes the command-line used to start the program.
31
variable
Capability set
The environment variable name/value pairs. (TODO: encoding?)
Describes the environment variables present in the programâs environment.
43
fixed
Capability set
Unix epoch seconds
Nanoseconds
Records the wall clock time to make it possible to correlate events from elsewhere with the eventlog.
0
fixed
thread id
Marks the creation of a Haskell thread.
1
fixed
thread id
The indicated thread has started running.
2
fixed
thread id
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
20: BlockedOnMVarRead
thread id of thread being blocked on (only for some status values)
The indicated thread has stopped running for the reason given by status
.
3
fixed
thread id
The indicated thread is has been marked as ready to run.
4
fixed
thread id
capability
The indicated thread has been migrated to a new capability.
8
fixed
thread id
other capability
The indicated thread has been woken up on another capability.
44
variable
thread id
label
The indicated thread has been given a label (e.g. with GHC.Conc.labelThread).
The following events mark various points of the lifecycle of a moving garbage collection.
A typical garbage collection will look something like the following:
A capability realizes that it needs a garbage collection (e.g. as a result of running out of nursery) and requests a garbage collection. This is marked by REQUEST_SEQ_GC
or REQUEST_PAR_GC
.
As other capabilities reach yield points and suspend execution they emit STOP_THREAD
events.
When all capabilities have suspended execution, collection will begin, marked by a GC_START
event.
As individual parallel GC threads commence with scavenging they will emit GC_WORK
events.
If a parallel GC thread runs out of work it will emit a GC_IDLE
event. If it is later handed more work it will emit another GC_WORK
event.
Eventually when scavenging has finished a GC_DONE
event will be emitted by each GC thread.
A bit of book-keeping is performed.
A GC_END
event will be emitted marking the end of the GC cycle.
A HEAP_SIZE
event will be emitted giving the current size of the heap, in bytes, calculated by how many megablocks are allocated.
A BLOCKS_SIZE
event will be emitted giving the current size of the heap, in bytes, calculated by how many blocks are allocated.
A GC_STATS_GHC
event will be emitted containing various details of the collection and heap state.
In the case of a major collection, a HEAP_LIVE
event will be emitted describing the current size of the live on-heap data.
In the case of the -threaded
RTS, a SPARK_COUNTERS
event will be emitted giving details on how many sparks have been created, evaluated, and GCâd.
As mutator threads resume execution they will emit RUN_THREAD
events.
A MEM_RETURN
event will be emitted containing details about currently live mblocks, how many we think we need and whether we could return excess to the OS.
Note that in the case of the concurrent non-moving collector additional events will be emitted during the concurrent phase of collection. These are described in Non-moving GC event output.
9
fixed
A garbage collection pass has been started.
10
fixed
A garbage collection pass has been finished.
11
fixed
A sequential garbage collection has been requested by a capability.
12
fixed
A parallel garbage collection has been requested by a capability.
20
fixed
An idle-time garbage collection has been started.
21
fixed
Marks the start of concurrent scavenging.
22
fixed
Marks the end of concurrent scavenging.
53
fixed
heap capability set
generation of collection
bytes copied
bytes of slop found
bytes of fragmentation, the difference between total mblock size and total block size. When all mblocks are full of full blocks, this number is 0.
number of parallel garbage collection threads
maximum number of bytes copied by any single collector thread
total bytes copied by all collector threads
the amount of balanced data copied by all threads
Report various information about a major collection.
54
fixed
TODO
90
fixed
heap capability set
currently allocated mblocks
the number of mblocks we would like to retain
the number of mblocks which we returned to the OS
Report information about currently allocation megablocks and attempts made to return them to the operating system. If your heap is fragmented then the current value will be greater than needed value but returned will be less than the difference between the two.
49
fixed
heap capability set
allocated bytes
A new chunk of heap has been allocated by the indicated capability set.
50
fixed
heap capability set
heap size in bytes
Report the heap size, calculated by the number of megablocks currently allocated.
91
fixed
heap capability set
heap size in bytes
Report the heap size, calculated by the number of blocks currently allocated.
51
fixed
heap capability set
heap size in bytes
Report the live heap size.
52
fixed
heap capability set
number of garbage collection generations
maximum heap size
allocation area size
MBlock size
Block size
Report various information about the heap configuration. Typically produced during RTS initialization..
15
fixed
A thread has been created to perform spark evaluation.
34
fixed
A periodic reporting of various statistics of spark evaluation.
35
fixed
A spark has been added to the spark pool.
36
fixed
TODO
37
fixed
TODO
38
fixed
Evaluation has started on a spark.
39
fixed
capability from which the spark was stolen
A spark has been stolen from another capability for evaluation.
40
fixed
A spark has been GCâd before being evaluated.
41
fixed
An unevaluated spark has been garbage collected.
45
fixed
the capability number
A capability has been started.
46
fixed
A capability has been deleted.
47
fixed
A capability has been disabled.
48
fixed
A capability has been enabled.
55
fixed
task id
capability number
The thread-id of the kernel thread which created the task.
Marks the creation of a task.
56
fixed
task id
old capability
new capability
Marks the migration of a task to a new capability.
57
fixed
task id
Marks the deletion of a task.
16
variable
The message
A log message from the runtime system.
18
fixed
block size
end time in nanoseconds
capability number, invalid if 0xffff
.
Marks a chunk of events. The events that fit in the next block size
bytes all belong to the block marker capability.
19
variable
message
A user log message (from, e.g., Control.Concurrent.traceEvent).
58
variable
marker name
A user marker (from Debug.Trace.traceMarker).
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.
A single fixed-width event emitted during program start-up describing the samples that follow.
160
variable
profile ID
sampling period in nanoseconds
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
)
module filter
closure description filter
type description filter
cost centre filter
cost centre stack filter
retainer filter
biography filter
A variable-length packet produced once for each cost centre,
161
fixed
cost centre number
label
module
source location
flags:
bit 0: is the cost-centre a CAF?
A message which describes an approximate source position for info tables. See -finfo-table-map
for more information.
169
fixed
info table address
table name
closure type
type
source position label
source position module
source position location
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,
fixed
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.
166
fixed
sample number
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.
165
fixed
sample number
Marks the end of a heap profile sample.
cost-centre (-hc
)
163
variable
profile ID
heap residency in bytes
stack depth
cost centre stack starting with inner-most (cost centre numbers)
A variable-length event encoding a heap sample broken down by,
164
variable
profile ID
heap residency in bytes
type or closure description, or module name
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.
168
fixed
tick interval, in nanoseconds
Marks the beginning of a time profile.
A variable-length packet encoding a profile sample.
167
variable
capability
current profiling tick
stack depth
cost centre stack starting with inner-most (cost centre numbers)
A variable-length packet encoding a profile sample.
166
TODO
These events mark various stages of the non-moving collection
lifecycle. These are enabled with the +RTS -lg
event-set.
A typical non-moving collection cycle will look something like the following:
The preparatory phase of collection will emit the usual events associated with a moving collection. See Garbage collector events for details.
The concurrent write barrier is enabled and the concurrent mark thread is started. From this point forward mutator threads may emit CONC_UPD_REM_SET_FLUSH
events, indicating that they have flushed their capability-local update remembered sets.
Concurrent marking begins, denoted by a CONC_MARK_BEGIN
event.
When the mark queue is depleted a CONC_MARK_END
is emitted.
If necessary (e.g. due to weak pointer marking), the marking process will continue, returning to step (3) above.
When the collector has done as much concurrent marking as it can it will enter the post-mark synchronization phase of collection, denoted by a CONC_SYNC_BEGIN
event.
Mutator threads will suspend execution and, if necessary, flush their update remembered sets (indicated by CONC_UPD_REM_SET_FLUSH
events).
The collector will do any final marking necessary (indicated by CONC_MARK_BEGIN
and CONC_MARK_END
events).
The collector will do a small amount of sweeping, disable the write barrier, emit a CONC_SYNC_END
event, and allow mutators to resume
The collector will begin the concurrent sweep phase, indicated by a CONC_SWEEP_BEGIN
event.
Once sweeping has concluded a CONC_SWEEP_END
event will be emitted and the concurrent collector thread will terminate.
A NONMOVING_HEAP_CENSUS
event will be emitted describing the fragmentation state of the non-moving heap.
A NONMOVING_PRUNED_SEGMENTS
event will be emitted showing information about freeing of segments.
200
fixed
Marks the beginning of marking by the concurrent collector.
201
fixed
number of objects which were marked in this marking phase.
Marks the end of marking by the concurrent collector.
202
fixed
Marks the beginning of the concurrent garbage collectorâs post-mark synchronization phase.
203
fixed
Marks the end of the concurrent garbage collectorâs post-mark synchronization phase.
204
fixed
Marks the beginning of the concurrent garbage collectorâs sweep phase.
205
fixed
Marks the end of the concurrent garbage collectorâs sweep phase.
206
fixed
Marks a capability flushing its local update remembered set accumulator.
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.
207
fixed
blk_sz in bytes.
number of active segments.
number of filled segments.
number of live blocks.
Describes the occupancy of the blk_sz sub-heap.
208
fixed
number of pruned segments.
number of segments remaining on the free list.
Report the amount of segments pruned and those remaining on the nonmoving heapâs segment free list. Segments will be retained on the free list until the entire megablock containing them can be freed.
Programs compiled with -ticky
and -eventlog
and invoked with +RTS -lT
will emit periodic samples of the ticky entry counters to the eventlog.
210
variable
counter ID
arity/field count
argument kinds. This is the same as the synonymous field in the textual ticky summary.
counter name
info table address
json encoded information about the counter
Defines a ticky counter.
212
fixed
Denotes the beginning of an atomic set of ticky-ticky profiler counter samples.
211
fixed
counter ID
number of times closures of this type has been entered.
number of allocations (words)
number of times this has been allocated (words). Only produced for modules compiled with -ticky-allocd
.
Records the number of âticksâ recorded by a ticky-ticky counter single the last sample.
RetroSearch is an open source project built by @garambo | Open a GitHub Issue
Search and Browse the WWW like it's 1997 | Search results from DuckDuckGo
HTML:
3.2
| Encoding:
UTF-8
| Version:
0.7.4