Re: Initial compile time benchmarks

I just benchmarked another set of packages, this time using -O2 optimized libs + stage 2 (6ea42c7): https://gist.githubusercontent.com/osa1/b483216953e3b02c0c79f9e4c8f8f931/raw... For me the most surprising part is that CodeGen is sometimes taking 86% of the time. It seems like we can start looking for improvements there. (I'll do that myself but I'm too busy for a few more days) Joachim, I think the difference is because of how thunk evaluation and cost centers work. If you generate a thunk with cost-center "X", you attribute the evaluation costs of that thunk to the cost-center "X". This is unlike how GHC currently printing the timing information: We essentially measure the time of thunk creation, not normalization of thunks. So the numbers you get from the profiling output may be more correct. We should try actually forcing the values in `withTiming` and see how it'll effect the timings. I feel like some of the costs attributed to CodeGen step is because of thunks we generate in previous steps. It's probably not possible to completely evaluate the values (because of cycles), but we can still do a better job probably. One last thing is that profiling can prevent some optimizations and cause different runtime behavior. Problems with instrumentation ... 2016-03-31 12:01 GMT-04:00 Ömer Sinan Ağacan :

Forgot to mention that I use `cabal install <package name> --ghc-options="-v3" -v3` to install the packages.

2016-03-31 12:00 GMT-04:00 Ömer Sinan Ağacan :

...

Hi Joachim,

That's GHC HEAD at the time with -O1 for stage 2 + libs.

The way I generate the logs is:

- I create a cabal sandbox and run `cabal exec zsh` to set up the env variables.

- I install packages in that shell.

- $ (cat .cabal-sandbox/logs/*.log | analyze-ghc-timings) > output

I don't know why there would be that much difference. Note that my setup was not perfect, I run some other (although lightweight) processes on the side.

2016-03-31 4:49 GMT-04:00 Joachim Breitner :

...

Hi Ömer,

thanks for the log. This is roughly GHC HEAD, right?

I wanted to check for low-hanging fruit in “my” code, so I compiled Data.Reflection, where your tool reports 12% time spent in Call Arity.

But if I run it with profiling, it says 3.5% of time is spent in that pass, and if I run your tool on the timing output produced by a profiled GHC, I get 8.3%, and on the output of a a development build, I get 3.8%.

So what is your setup: How did you compile GHC, and with what options are you running it?

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

_______________________________________________ ghc-devs mailing list ghc-devs@haskell.org http://mail.haskell.org/cgi-bin/mailman/listinfo/ghc-devs