I think the first field of ProfSampleCostCentre should be profCap :: !CapNo instead of profCapset :: !Capset.

https://github.com/ghc/ghc/blob/73b22ff196160036ac10b762bf3a363fa8a451ad/rts/eventlog/EventLog.c#L1317-L1340 has

void postProfSampleCostCentre(Capability *cap,
                              CostCentreStack *stack,
                              StgWord64 tick)
{
    /* SNIP */
    postEventHeader(&eventBuf, EVENT_PROF_SAMPLE_COST_CENTRE);
    postPayloadSize(&eventBuf, len);
    postWord32(&eventBuf, cap->no);                                                /* THIS IS THE NOTABLE LINE */
    postWord64(&eventBuf, tick);
    /* SNIP */
}

• This seems to be an inconsistency between ghc master and ghc-events master -- I haven't done the due diligence to check wheter ghc master has changed this recently, eg.

• Or perhaps there's an implicit assumption that CapNo i is the sole member of Capset i?

So either there's a mismatch that should be fixed or I think it's deserving of a comment on profCapset. Thanks!

While running the 0.15.0 testsuite for Stackage Nightly:

    test/queens-ghc-6.12.1.eventlog: success
    test/queens-ghc-7.0.2.eventlog: success
    test/mandelbrot-mmc-2011-06-14.eventlog: success
    test/nonmoving-gc.eventlog: success
    test/nonmoving-gc-census.eventlog: success
    test/parallelTest.eventlog: success
    test/pre77stop.eventlog: success
    test/782stop.eventlog: success
    test/783stop.eventlog: success
    test/sleep.h.eventlog: success
    test/sleep.hC.eventlog: success
    test/sleep.hm.eventlog: success
    test/sleep.hd.eventlog: success
    test/sleep.hy.eventlog: success
    test/stop.hT.eventlog: success
    test/hello-ghc-8.2.2.eventlog: success
    test/hello-ghc-8.6.5.eventlog: success
    test/biographical-samples.eventlog: success
    test/time-prof.eventlog: success
    test/trace-binary-event.eventlog: success
    test/unicode.eventlog: success
    test-versions: test/ticky-ticky.eventlog: openBinaryFile: does not exist (No such file or directory)

to investigate later

The logic for printing UserBinaryMessages assumes that the payload is utf8 encoded. Non-utf8 encoded payloads, like those produced by programs that use the opentelemetry library, will lead to a runtime error.

You can reproduce this by running the following to produce an eventlog:

module Main where

import Debug.Trace.Binary
import Data.ByteString

main :: IO ()
main = traceBinaryEventIO (pack [0x0080])

and then when you load this into ghc-events you will get output like the following:

> ghc-events inc repro.eventlog 
93401: cap 0: creating thread 1
94801: cap 0: running thread 1
102801: cap 0: stopping thread 1 (making a foreign call)
103101: cap 0: running thread 1
ghc-events: user error (Cannot decode byte '\x80': Data.Text.Internal.Encoding.decodeUtf8: Invalid UTF-8 stream)

Threadscope will also crash when showing relevant events.

I'll try to fix this. I feel like if we fail to decode as utf8 then we should have some sort of fallback format like base64 rather than throwing an error. Or perhaps we can just use decodeUtf8Lenient

I notice that the README speaks of a 0.5 release, but on Hackage the latest release currently is 0.4.4.0. Any plans to upload v0.5 to Hackage?

The maintainer field in the cabal file says this library is maintained by @simonmar but it seems to me that it's currently maintained by @Mikolaj and probably @kvelicka. Should we update the cabal file?

This would make debugging issues with incomplete/partial/corrupted eventlogs easier.

In 8.8, the eventlog now also emits the stack size when the stack overflows. This change needs to be reflected in ghc-events.

https://gitlab.haskell.org/ghc/ghc/commit/7e570676bd0a57f8a77e5577d9f27e2d3159193e

The version on Hackage does not yet support heap profiling. It would be nice to get that released, I think.

ghc-events currently fails to deserialize some events that it serializes. To reproduce, first generate a minimal eventlog file from the program main = return () (tried GHC 8.4), then run

import Data.Binary.Get
import Data.Binary.Put
import qualified Data.ByteString as BS
import qualified Data.ByteString.Lazy as LBS
import GHC.RTS.Events
import GHC.RTS.Events.Binary
import GHC.RTS.Events.Incremental

main = do
    bs <- LBS.readFile "empty.eventlog"
    let header = runGet getHeader bs
    let parsers = mkEventParsers header

    let event = Event
          { evTime = 415731793
          , evSpec = GCStatsGHC
              { heapCapset = 0
              , gen = 1
              , copied = 305104
              , slop = 250088
              , frag = 3088384
              , parNThreads = 12
              , parMaxCopied = 4246
              , parTotCopied = 305104
              }
          , evCap = Nothing
          }

    print (runGet (getEvent parsers) (runPut (putEvent event)))

Output:

bug: Data.Binary.Get.runGet at position 60: not enough bytes
CallStack (from HasCallStack):
  error, called at libraries/binary/src/Data/Binary/Get.hs:351:5 in binary-0.8.5.1:Data.Binary.Get

The new test suite write-merge fails on master (f5ac7a0) with an index-out-of-bounds error:

Test suite write-merge: RUNNING...
write-merge: Ix{Int}.index: Index (39) out of range ((0,19))
Test suite write-merge: FAIL

(This is with GHC-7.8.4) but does not seem to relate to the GHC version used to compile the library.
A quick first analysis indicates that serialiseEventLog is causing the failure for older trace files. It seems as though some assumptions about the admissible events are baked into the code?

GHCI session:

*WriteMerge> testFile "test/queens-ghc-7.0.2.eventlog"
Loading package array-0.5.0.0 ... linking ... done.
Loading package deepseq-1.3.0.2 ... linking ... done.
Loading package bytestring-0.10.4.0 ... linking ... done.
Loading package containers-0.5.5.1 ... linking ... done.
Loading package binary-0.7.1.0 ... linking ... done.
*** Exception: Ix{Int}.index: Index (39) out of range ((0,22))
*WriteMerge> testFile "test/queens-ghc-6.12.1.eventlog"
*** Exception: Ix{Int}.index: Index (39) out of range ((0,19))
*WriteMerge> 

GHC-6.12.3 knew 19 event types, GHC-7.0.2 knew 22, test files produced by newer GHCs contain many more event types, and those files work as expected:

*WriteMerge> testFile "test/mdlLogMPI1.eventlog"
test/mdlLogMPI1.eventlog: success
True
*WriteMerge> testFile "test/782stop.eventlog"
Different output at line 95:
Original:  10678973: cap 0: stopping thread 1 (blocked on black hole owned by thread 2)
New:       10678973: cap 0: stopping thread 1 (blocked reading an MVar)
test/782stop.eventlog: failure re-written file does not match the original
False
*WriteMerge> testFile "test/pre77stop.eventlog"
test/pre77stop.eventlog: success
True
*WriteMerge> testFile "test/783stop.eventlog"
test/783stop.eventlog: success
True
*WriteMerge> testFile "test/mandelbrot-mmc-2011-06-14.eventlog"
*** Exception: eventTypeNum UnknownEvent
*WriteMerge> :q

The failure with GHC-7.8.2 is expected (see code https://github.com/haskell/ghc-events/blob/master/GHC/RTS/Events.hs#L1184 ) . One could probably modify the file header of the written log file (adding the event that identifies GHC-7.8.3) to fix it - the format which is written is the one of 7.8.3.

Unclear what causes the failure with mandelbrot-mmc-2011-06-14.eventlog. This file has many event types, whose numbers are neither consecutive nor ordered in the file, which might be the reason.

By "roundtrip property" I mean for any event if I serialize it with putEvent,
getEvent on the resulting ByteString should give me the original event. #41
shows that we currently don't have this property.

Motivation

I'm trying to improve large eventlog handling of ThreadScope [1]. For this I
need some kind of filesystem-backed data structure to be able to serialize
unused events [2] to a file and read the ones that are needed. As shown in #41
we currently can't do this.

Problem

The reason why we currently don't have this property is GHC expects that event
parsers should be able to parse an event using only a prefix of the
serialization of the event, and ghc-events is implemented accordingly. This
means that GHC can add more fields to an event as long as (1) it updates the
event size in the .eventlog file header (2) it puts the new field at the end of
the event. [3] is an example where this happens. Event parsers can then check
size of an event using the .eventlog file header, and skip any space between
the assumed size of the event and what the header says the event's size is [4].

The problem occurs because the serializer (putEvent and friends) do not take
these extra fields into account and serializes events based on their assumed
size by ghc-events [5]. So if we try to parse the serialized event using the
original parser used to read the .eventlog file the parse fails.

Proposed fix

I propose fixing this by adding a new "extras" field to events:

data Event = Event
  { evTime   :: {-# UNPACK #-}!Timestamp
  , evSpec   :: EventInfo
  , evCap    :: Maybe Int
  , evExtras :: ByteString -- NEW FIELD
  } deriving Show

Parsers can then put the skipped data in this field and serializers can
directly serialize that field after serializing the event.

Because this is a breaking change a major version bump will be needed. A major
user is ThreadScope, which already has an upper bound <0.9.0 so I don't think
this will cause major breakage, and I'll also update ThreadScope so that the
next version will be compatible with new ghc-events.

[1]: haskell/ThreadScope#29
[2]: e.g. with the help of an LRU cache
[3]: https://phabricator.haskell.org/D3658
[4]: See padParser and its call site for the implementation of this.
[5]: In putEventSpec

How does that sound? @maoe I think these days you're maintaining the library,
is there anyone else I should ping about this? The implementation should be
simple but I just wanted to get some opinions before investing more into it.

I think we should add CONTRIBUTING.md which suggests that every new event support should be accompanied by a small example eventlog and its expected ghc-events show output.

The project currently has its own copy of EventLogFormat.h that ships with GHC. This strikes me as an unfortunate situation: if the upstream version of that file as found in GHC is to be considered the authoritative definition of what events are supported, then we shouldn't be forking our own copy.

Now, the trouble with switching to the upstream version is that it is a lot smaller. Many long ago deprecated events have been removed entirely. The Mercury events are not defined. Neither are the Eden events. But at least this way we know for sure that GHC and ghc-events agree about event definitions because they share the exact same interface file.

Further, this looks like a good opportunity to remove support for events that are no longer supported. Should we really still be aiming for compatibility all the way to 6.12.* along with the funny quirks we encounter in those compilers? Does Mercury really still use ghc-events? Is Eden still an active project?

Another point is that if we use whatever EventLogFormat.h we find in the currently installed GHC, then the resulting ghc-events binary is tuned for that installed GHC version and only that GHC version. But that's a feature. Some of the complexity in the existing code base stems from having a single binary support eventlogs produced by any version of GHC, past present and future. Which makes sense in a pre project environments world, which both cabal-install and Stack now support. But with cabal-install and Stack projects, it makes sense to have a project local ghc-events that is guaranteed to work well with the eventlogs that are created as part of that project and the GHC version used in that project.

As visible on hackage, some package bounds are not strict enough.

The binary is no longer separate on the development branch.

Similarly the test script has to be updated to the new way of invoking "show". Git grep for more.

This field was added in this commit.

I would like to add support for this to ghc-events, if you could provide some guidance on how you would like this done.

The options I see are:

• add a Maybe Int to the GCStatsGC constructor
• Add a GCStatsGC data type, with two constructors (perhaps GCStatsGC_V1, GCStatsGC_V2?) where the second has an additional field. This is my preference.

I would also like to add a function

--| Computes the cumulative parallel work balance of the argument garbage collections.   
workBalance :: [GCStatsGC] -> Double

My understanding is that this library has to work around incompatibilities between different encodings used by old versions of GHC.

I feel like dropping support for those old versions would help simplify the library and unblock some of the open issues.

I'm suggesting dropping compatibility with anything before GHC 8.0.1, which was released in May 2016. I think that's quite conservative but would still allow dropping all the special cases to deal with old GHCs afaict.

While writing an analysis tool, the need for sorting the events in an eventlog file arose. The problem with the existing GHC.RTS.Events.sortEvents is that it is not memory bounded, leading to heap exhaustion on large inputs.

How about we provide a memory bounded version?

I ended up writing something similar to this. It splits events per capability to different temporary files, and then merges the events back into a single list.

I could submit a PR if it looks useful to others.

This version is a bit wasteful in that it has to deserialize and serialize all the events, where for the sake of splitting the events, only the capability number and the encoded form of the event would be needed.

Another odd aspect is that I couldn't make it stream when using Data.ByteString.Builder to write the events to the temporary files. Heap would be exhausted the same.

The eventlog is structured as a list of blocks of events.

A block has a capability number that specifies the capability of upcoming events, and some information about when the block was written.

Currently we erase block events when reading the eventlog. This leads to two issues:

• when writing the eventlog back out, we have to recreate blocks. But can't do so properly since information has been lost leading to roundtripping failures. I believe this would be a big step towards addressing #14
• we cannot currently figure out from the eventlog when the application is busy writing to the eventlog, but this is exactly what the two timestamps on the block event tell us.

My proposal is to keep the block events during parsing and require their presence when writing out eventlogs. This introduces some new illegal states, ie, an eventlog without block events could not now be written to a file. How does this sound?

An alternative is to change the types to make these states unrepresentable but I don't think the breaking change from that would be worth it.

The eventlog file uploaded by @Unselfish at haskell/ThreadScope#108 (comment) causes ghc-events inc to fail:

ghc-events: Ix{Int}.index: Index (23637) out of range ((0,164))

It was produced with GHC 8.6.5 on Windows.

Please, comment purpose of evCap field in Event.
Is it a thread id?