timings for individual compiler passes (in rc3)
Hi. There is this (closed) https://ghc.haskell.org/trac/ghc/ticket/11653 and it's landed in 8.rc3. Thats good, and I want to make an effort to use this. But how? Just "-v2"? This gives a lot of noise. And no summary? Automatic analysis (of the output text stream, by external program) could be somewhat easier if each data set (starting at "\n!!!") did occupy exactly one line (currently, line breaks do occur). Anyway, what do I look for? Any large or suspicious number - but what exactly is "suspicious"? Anything above 1 second? Are we to believe the assignment of cost to pass, or could there be mis-attribution because result of an earlier pass is only forced later? Oh, and where do you want discussion of this feature (mailing list, ticket, ...)? I do hope that it will prove useful, in the sense that it could allow non-developers like me, or even build bots, to help spot performance problems. (E.g., you could advertise to enable this on travis. Yes, their build times depend on a lot of things, but still.) - J.W.
Johannes Waldmann
Hi.
There is this (closed) https://ghc.haskell.org/trac/ghc/ticket/11653 and it's landed in 8.rc3.
Thats good, and I want to make an effort to use this. But how? Just "-v2"? This gives a lot of noise. And no summary?
Indeed, -v2 does produce a lot of noise. We considered adding a dedicated -ftimings flag but ultimately decided that it wouldn't be necessary. Afterall, the most obvious users of this functionality are not end-users but tooling and compiler developers since the timings themselves are quite tricky to interpret. I think there are two likely use-cases for this functionality, 1. for long-term tracking of the performance of various compiler subsystems on a set of stable benchmarks (e.g. nofib) 2. for precise characterization of the effects of optimizations on individual compiler passes while working on the compiler In both cases you'll likely want to feed the compiler's output through some sort of analysis tool so I thought it wouldn't really be worth cluttering the implementation with any sort of nice summarization. Ömer has already [1] put together some nice tooling for extracting and summarizing timings and I believe he is interested in continuing this line of work. Perhaps you two should chat! Finally, note that we still have a fair amount of work to do to verify that the timings produced actually reflect the amount of work done by each pass. Laziness makes this rather tricky. The original feature request ticket (#11653) is one obvious place to hang comments; this list is also appropriate. Cheers, - Ben [1] https://github.com/osa1/analyze-ghc-timings
Hi,
... to compile it with a profiled GHC and look at the report?
How hard is it to build hackage or stackage with a profiled ghc? (Does it require ghc magic, or can I do it?)
... some obvious sub-optimal algorithms in GHC.
obvious to whom? you mean sub-optimality is already known, or that it would become obvious once the reports are there? Even without profiling - does hackage collect timing information from its automated builds? What needs to be done to add timing information in places like https://hackage.haskell.org/package/obdd-0.6.1/reports/1 ? - J.W.
Johannes Waldmann
Hi,
... to compile it with a profiled GHC and look at the report?
How hard is it to build hackage or stackage with a profiled ghc? (Does it require ghc magic, or can I do it?)
Not terribly hard although it could be made smoother. To start you'll need to compile a profiled GHC. To do this you simply want to something like the following, 1. install the necessary build dependencies [1] 2. get the sources [2] 3. configure the tree to produce a profiled compiler: a. cp mk/build.mk.sample mk/build.mk b. uncomment the line `BuildFlavour=prof` in mk/build.mk 4. `./boot && ./configure --prefix=$dest && make && make install` Then for a particular package, 1. get a working directory: `cabal unpack $pkg && cd $pkg-*` 2. `args="--with-ghc=$dest/bin/ghc --allow-newer=base,ghc-prim,template-haskell,..."` 3. install dependencies: `cabal install --only-dependencies $args .` 4. run the build, `cabal configure --ghc-options="-p -hc" $args && cabal build` You should end up with a .prof and .hp file. Honestly, I often skip the `cabal` step entirely and just use `ghc` to compile a module of interest directly. [1] https://ghc.haskell.org/trac/ghc/wiki/Building/Preparation [2] https://ghc.haskell.org/trac/ghc/wiki/Building/GettingTheSources
... some obvious sub-optimal algorithms in GHC.
obvious to whom? you mean sub-optimality is already known, or that it would become obvious once the reports are there?
I think "obvious" may have been a bit of a strong word here. There are sub-optimal algorithms in the compiler and they can be found with a bit of work. If you have a good testcase tickling such an algorithm finding the issue can be quite straightforward; if not then the process can be a bit trickier. However, GHC is just another Haskell program and performance issues are approached just like in any other project.
Even without profiling - does hackage collect timing information from its automated builds?
Sadly it doesn't. But...
What needs to be done to add timing information in places like https://hackage.haskell.org/package/obdd-0.6.1/reports/1 ?
I've discussed the possibility with Herbert to add instrumentation in his matrix builder [3] to collect this sort of information. As a general note, keep in mind that timings are quite unstable, dependent upon factors beyond our control at all levels of the stack. For this reason, I generally prefer to rely on allocations, not runtimes, while profiling. As always, don't hesitate to drop by #ghc if you run into trouble. Cheers, - Ben [3] http://matrix.hackage.haskell.org/packages
Hi Ben, thanks,
4. run the build, `cabal configure --ghc-options="-p -hc" $args && cabal build`
cabal configure $args --ghc-options="+RTS -p -hc -RTS"
You should end up with a .prof and .hp file.
Yes, that works. - Typical output starts like this COST CENTRE MODULE %time %alloc SimplTopBinds SimplCore 60.7 57.3 OccAnal SimplCore 6.0 6.0 Simplify SimplCore 3.0 0.5 These files are always called ghc.{prof,hp}, how could this be changed? Ideally, the output file name would depend on the package being compiled, then the mechanism could probably be used with 'stack' builds. Building executables mentioned in the cabal file will already overwrite profiling info from building libraries. When I 'cabal build' the 'text' package, then the last actual compilation (which leaves the profiling info) is for cbits/cbits.c I don't see how to build Data/Text.hs alone (with ghc, not via cabal), I am getting Failed to load interface for ‘Data.Text.Show’ - J.
Hi, Am Mittwoch, den 07.12.2016, 11:34 +0100 schrieb Johannes Waldmann:
When I 'cabal build' the 'text' package, then the last actual compilation (which leaves the profiling info) is for cbits/cbits.c
I don't see how to build Data/Text.hs alone (with ghc, not via cabal), I am getting Failed to load interface for ‘Data.Text.Show’
you can run $ cabal build -v and then copy’n’paste the command line that you are intested in, add the flags +RTS -p -hc -RTS -fforce-recomp and run that again. Greetings, Joachim -- Joachim “nomeata” Breitner mail@joachim-breitner.de • https://www.joachim-breitner.de/ XMPP: nomeata@joachim-breitner.de • OpenPGP-Key: 0xF0FBF51F Debian Developer: nomeata@debian.org
Johannes Waldmann
Hi Ben, thanks,
4. run the build, `cabal configure --ghc-options="-p -hc" $args && cabal build`
cabal configure $args --ghc-options="+RTS -p -hc -RTS"
Ahh, yes, of course. I should have tried this before hitting send.
You should end up with a .prof and .hp file.
Yes, that works. - Typical output starts like this
COST CENTRE MODULE %time %alloc
SimplTopBinds SimplCore 60.7 57.3 OccAnal SimplCore 6.0 6.0 Simplify SimplCore 3.0 0.5
Ahh yes. So one of the things I neglected to mention is that the profiled build flavour includes only a few cost centers. One of the tricky aspects of the cost-center profiler is that it affects core-to-core optimizations, meaning that the act of profiling may actually shift around costs. Consequently by default the the build flavour includes a rather conservative set of cost-centers to avoid distorting the results and preserve compiler performance. Typically when I've profiled the compiler I already have a region of interest in mind. I simply add `OPTIONS_GHC -fprof-auto` pragmas to the modules involved. The build system already adds this flag to a few top-level modules, hence the cost-centers which you observe (see compiler/ghc.mk; search for GhcProfiled). If you don't have a particular piece of the compiler in mind to study, you certainly can just pepper every module with cost centers by adding -fprof-auto to GhcStage2HcOpts (e.g. in mk/build.mk). The resulting compiler may be a bit slow and you may need to be just a tad more careful in evaluating the profile. It might be nice if we had a more aggressive profiled build flavour which added cost centers to a larger fraction of machinery of the compiler, which excluding low-level utilities like FastString, which are critical to the compiler's performance.
These files are always called ghc.{prof,hp}, how could this be changed? Ideally, the output file name would depend on the package being compiled, then the mechanism could probably be used with 'stack' builds.
We really should have a way to do this but sadly do not currently. Ideally we would also have a way to change the default eventlog destination path.
Building executables mentioned in the cabal file will already overwrite profiling info from building libraries.
Note that you can instruct `cabal` to only build a single component of a package. For instance, in the case of the `text` package you can build just the library component with `cabal build text`.
When I 'cabal build' the 'text' package, then the last actual compilation (which leaves the profiling info) is for cbits/cbits.c
Ahh right. Moreover, there is likely another GHC invocation after that to link the final library. This is why I typically just use GHC directly, perhaps stealing the command line produced by `cabal` (with `-v`).
I don't see how to build Data/Text.hs alone (with ghc, not via cabal), I am getting Failed to load interface for ‘Data.Text.Show’
Hmm, I'm not sure I see the issue. In the case of `text` I can just run `ghc` from the source root (ensuring that I set the #include path with `-I`), $ git clone git://github.com/bos/text $ cd text $ ghc Data/Text.hs -Iinclude However, some other packages (particularly those that make heavy use of CPP) aren't entirely straightforward. In these cases I often find myself copying bits from the command line produced by cabal. Cheers, - Ben
participants (3)
-
Ben Gamari -
Joachim Breitner -
Johannes Waldmann