[Haskell-cafe] ghc profiling

[Daniel Gröber]

Hi,

tl;dr: I got a fix for this merged:

    https://gitlab.haskell.org/ghc/ghc/-/merge_requests/3091

However I don't think this has landed in a GHC release yet.

On Wed, Jul 22, 2020 at 05:11:29PM +0200, Mika Pöhls wrote:
> But after that an extra sample is created, that contains no data (no
> cost centers, it is just begin sample followed by end sample). This
> sample is also created out of the 0.1 second gaps used before.

FYI the final sample is created when the RTS is being torn down, that's why
it's potentially outside of the sampling interval but the reason for the
time skew is that we were using the wrong timebase when printing that last
sample in the RTS.

> For example the last "correct" sample is at 17s and the empty sample is
> at 40s. When plotting the data, this results in an monotonous increasing
> graph (for all centers), that has its maximum at the last correct sample
> (17s) followed by a straight line to zero (40s).

The way us GHC devs used to deal with that is to just edit that last sample
out of the hp file ;)

A quick shell one-liner to do this:

    tac foo.hp | tail -n+3 | tac > foo.fixed.hp

The `tac` reverses the order of lines and `tail -n+3` ignores the first two
lines.

I'm not sure why the RTS emits this last empty sample to begin with, maybe
we should just remove it since the tools don't seem to care either way.

> Does anyone know, what leads to this behavior and how it can be prevented?

I think you could also try using eventlog profiling instead of the old .hp
stuff to work around this if you like, but I'm not very familliar with that
either so I can't help there.

--Daniel