Dear GHC team, It looks like ghc-6.12.1 reports erroneous time profiling -- when the Main module of the project is made under -O. This is for ghc-6.12.1 made from source for Debian Linux and i386-like. Main.main calls for Complete.complete, `complete' calls for eLoop inside its source. eLoop must take almost all the time. My whole user library is made under -O -prof, and --enable-library-profiling. Main is compiled by ghc $dmCpOpt -prof --make Main and run by ./Main +RTS -M400m -pT -RTS For this key, the profiling report Main.prof looks natural and shows eLoop -- 97%. But for ghc $dmCpOpt -O -prof --make Make, it shows a different thing: zero for eLoop and 99% for `main'. How could this additional -O mislead the compiler? Also, as I recall, -O is still by default -- ? Could you explain, please? Regards, ----------------- Serge Mechveliani mechvel@botik.ru
Am Mittwoch 03 Februar 2010 16:44:31 schrieb Serge D. Mechveliani:
Dear GHC team,
It looks like ghc-6.12.1 reports erroneous time profiling -- when the Main module of the project is made under -O.
This is for ghc-6.12.1 made from source for Debian Linux and i386-like.
Main.main calls for Complete.complete, `complete' calls for eLoop inside its source. eLoop must take almost all the time. My whole user library is made under -O -prof, and --enable-library-profiling. Main is compiled by ghc $dmCpOpt -prof --make Main and run by ./Main +RTS -M400m -pT -RTS For this key, the profiling report Main.prof looks natural and shows eLoop -- 97%.
But for ghc $dmCpOpt -O -prof --make Make,
it shows a different thing: zero for eLoop and 99% for `main'.
Could be that eLoop is inlined with -O. Try ghc $dmCpOpt -O -prof -auto-all --make That should show eLoop (if that's a top-level declaration, otherwise you'd have to insert a pragma {-# SCC "eLoop" #-} manually).
How could this additional -O mislead the compiler? Also, as I recall, -O is still by default -- ?
No, default is "comile as fast as possible", no optimisations (-O0).
Could you explain, please?
Regards,
----------------- Serge Mechveliani mechvel@botik.ru
To my
Dear GHC team,
It looks like ghc-6.12.1 reports erroneous time profiling -- when the Main module of the project is made under -O. [..] This is for ghc-6.12.1 made from source for Debian Linux and i386-like.
Main.main calls for Complete.complete, `complete' calls for eLoop inside its source. eLoop must take almost all the time. My whole user library is made under -O -prof, and --enable-library-profiling. Main is compiled by ghc $dmCpOpt -prof --make Main and run by ./Main +RTS -M400m -pT -RTS For this key, the profiling report Main.prof looks natural and shows eLoop -- 97%.
But for ghc $dmCpOpt -O -prof --make Make,
it shows a different thing: zero for eLoop and 99% for `main'.
On Wed, Feb 03, 2010 at 05:38:36PM +0100, Daniel Fischer wrote:
Could be that eLoop is inlined with -O.
Thank you. I also thought about this. But the question still looks difficult.
Try
ghc $dmCpOpt -O -prof -auto-all --make
That should show eLoop (if that's a top-level declaration, otherwise you'd have to insert a pragma {-# SCC "eLoop" #-} manually).
eLoop is not a top-level declaration, and I do set {-# SCC "eLoop" #-}. The key combination ghc $dmCpOpt -prof --make Main shows 95% for eLoop, and adding -O to this line shows 0% for eLoop, independently on presence of -auto-all in this line (the whole library is made under -O -prof). Yes, I recall that the effect may be of inlining. But, generally, how to detect sensibly the time consuming functions? This inlining presents a puzzle here. Is it possible to compile Main.hs and Complete.hs under -O0 -inline-not, compile all the other modules under -O ? (how?). If it is possible, will this make easier to understand the profiling report? Regards, ----------------- Serge Mechveliani mechvel@botik.ru
Am Mittwoch 03 Februar 2010 18:59:01 schrieb Serge D. Mechveliani:
To my
Dear GHC team,
It looks like ghc-6.12.1 reports erroneous time profiling -- when the Main module of the project is made under -O. [..] This is for ghc-6.12.1 made from source for Debian Linux and i386-like.
Main.main calls for Complete.complete, `complete' calls for eLoop inside its source. eLoop must take almost all the time. My whole user library is made under -O -prof, and --enable-library-profiling. Main is compiled by ghc $dmCpOpt -prof --make Main and run by ./Main +RTS -M400m -pT -RTS For this key, the profiling report Main.prof looks natural and shows eLoop -- 97%.
But for ghc $dmCpOpt -O -prof --make Make,
it shows a different thing: zero for eLoop and 99% for `main'.
On Wed, Feb 03, 2010 at 05:38:36PM +0100, Daniel Fischer wrote:
Could be that eLoop is inlined with -O.
Thank you. I also thought about this. But the question still looks difficult.
Try
ghc $dmCpOpt -O -prof -auto-all --make
That should show eLoop (if that's a top-level declaration, otherwise you'd have to insert a pragma {-# SCC "eLoop" #-} manually).
eLoop is not a top-level declaration, and I do set {-# SCC "eLoop" #-}.
I had a similar issue recently, whether a cost centre shows in the profile depends on where exactly you put it, it might be worthwhile to move it around a bit or add {-# SCC "eLoop" #-} to a few more places in eLoop.
The key combination ghc $dmCpOpt -prof --make Main shows 95% for eLoop, and adding -O to this line shows 0% for eLoop, independently on presence of -auto-all in this line (the whole library is made under -O -prof).
Yes, I recall that the effect may be of inlining. But, generally, how to detect sensibly the time consuming functions?
Insert lots of cost centres. The downside is, the more cost centres you have, the less optimisations are possible. Sometimes that changes the code's behaviour much, so it is possible that things show up as consuming much time which would be optimised to low-cost without profiling. But that should be rare, in general, what shows up as expensive in the profile is also expensive in production code, just somewhat less (or more).
This inlining presents a puzzle here.
Is it possible to compile Main.hs and Complete.hs under -O0 -inline-not, compile all the other modules under -O ? (how?).
Put {-# OPTIONS_GHC -O1 #-} at the top (but after LANGUAGE pragmas) of all modules except Main and Complete. Then don't give an -O flag on the command line (touch Main.hs and Complete.hs to make sure those are recompiled, perhaps pass -fforce-recomp to recompile everything).
If it is possible, will this make easier to understand the profiling report?
Hopefully :)
Regards,
----------------- Serge Mechveliani mechvel@botik.ru
On 03/02/2010 17:59, Serge D. Mechveliani wrote:
To my
Dear GHC team,
It looks like ghc-6.12.1 reports erroneous time profiling -- when the Main module of the project is made under -O. [..] This is for ghc-6.12.1 made from source for Debian Linux and i386-like.
Main.main calls for Complete.complete, `complete' calls for eLoop inside its source. eLoop must take almost all the time. My whole user library is made under -O -prof, and --enable-library-profiling. Main is compiled by ghc $dmCpOpt -prof --make Main and run by ./Main +RTS -M400m -pT -RTS For this key, the profiling report Main.prof looks natural and shows eLoop -- 97%.
But for ghc $dmCpOpt -O -prof --make Make,
it shows a different thing: zero for eLoop and 99% for `main'.
On Wed, Feb 03, 2010 at 05:38:36PM +0100, Daniel Fischer wrote:
Could be that eLoop is inlined with -O.
Thank you. I also thought about this. But the question still looks difficult.
Try
ghc $dmCpOpt -O -prof -auto-all --make
That should show eLoop (if that's a top-level declaration, otherwise you'd have to insert a pragma {-# SCC "eLoop" #-} manually).
eLoop is not a top-level declaration, and I do set {-# SCC "eLoop" #-}. The key combination ghc $dmCpOpt -prof --make Main shows 95% for eLoop, and adding -O to this line shows 0% for eLoop, independently on presence of -auto-all in this line (the whole library is made under -O -prof).
There are known bugs in this area, see e.g. http://hackage.haskell.org/trac/ghc/ticket/2552
Yes, I recall that the effect may be of inlining.
Inlining should not in general affect the shape of the profile. I can't say much else here without seeing the specific code. Cheers, Simon
participants (3)
-
Daniel Fischer -
Serge D. Mechveliani -
Simon Marlow