[RFC] Compiler pipeline timings visualization

[Matthew Pickering]

Hi Sergej,

I definitely agree adding the capability for GHC to emit telemetry
would be useful. I also prefer the eventlog like other people has
already mentioned. We should at least ship with compiler so it can
emit these user events even if it can't emit RTS events.

In future we should probably look more into uprobes in order to make
tracing more efficient but we have what we have for now.

Recently I have been working with Dimity Ivanov on some tooling
related to this. He has implemented a standard tracing format and
exporters for many common diagnostic tools.

https://github.com/ethercrow/opentelemetry-haskell

You can see some examples of eventlogs generated by GHC in this issue:

https://github.com/ethercrow/opentelemetry-haskell/issues/9

Cheers,

Matt


On Fri, May 1, 2020 at 5:55 PM Ben Gamari <ben at well-typed.com> wrote:
>
> Sergej Jaskiewicz via ghc-devs <ghc-devs at haskell.org> writes:
>
> > tl;dr: I propose adding a new GHC flag for generating a log that allows
> > visualizing how much time each stage in the compiler pipleline took, similar
> > to Clang's -ftime-trace.
> >
> > Hello, everyone.
>
> Hi Sergej,
>
>
> [snip]
>
> > The latter option is much closer to what we need. If we link the GHC executable
> > with the -eventlog flag, then various significant events will be written to
> > a special log file. For example, "Parser began parsing the Main.hs file after
> > 5 ms since GHC has started, and ended parsing it 3 ms after that".
> > The resulting log file can be parsed with the ghc-events library [4], and also
> > visualized using the ThreadScope app [5].
> >
> I'm a bit short on time but here are a few points in no particular order:
>
> Out of curiosity, have you seen Alp's work [1] in this area? This work
> allows use to the ghc-events-analyze package [2] to visualize (e.g. [3])
> the existing withTiming eventlog output in a reasonably easy-to-consume
> format.
>
> That being said, I can certainly see the benefit of using the Chrome
> tracing infrastructure for this; it would make for a nicer user
> experience than the static image that ghc-events-analyze spits out.
>
> I also know that Matthew Pickering has been working in this area and I'm
> sure will have something interesting to add.
>
> I will admit that I am a bit reluctant to add support for a *particular*
> tracing format to GHC itself. I think it would make the most sense for
> GHC to produce a consumer-agnostic trace representation (via our
> existing eventlog mechanism) and for users to transform this into the
> format their tools require.
>
> Our current withTimings infrastructure is quite ad-hoc and could perhaps
> expose more detail. It would be great to know what sorts of detail
> people would find useful.
>
> Cheers,
>
> - Ben
>
>
> [1] https://www.haskell.org/ghc/blog/20190924-eventful-ghc.html
> [2] https://hackage.haskell.org/package/ghc-events-analyze
> [3] https://www.haskell.org/ghc/blog/images/eventful-ghc/ghc-events-viz.svg
> _______________________________________________
> ghc-devs mailing list
> ghc-devs at haskell.org
> http://mail.haskell.org/cgi-bin/mailman/listinfo/ghc-devs