I'm trying to profile my program.
I compile it like that:
ghc -rtsopts -O3 -prof -auto-all Main.hs
And run:
./Main +RTS -p
And read Main.prof
:
Fri Jul 15 13:06 2011 Time and Allocation Profiling Report (Final)
Main +RTS -p -RTS
total time = 0.00 secs (0 ticks @ 20 ms)
total alloc = 266,726,496 bytes (excludes profiling overheads)
COST CENTRE MODULE %time %alloc
trySub Main 0.0 14.3
ourPalindroms Main 0.0 15.0
isPalindromic Main 0.0 70.7
individual inherited
COST CENTRE MODULE no. entries %time %alloc %time %alloc
MAIN MAIN 1 0 0.0 0.0 0.0 100.0
CAF Main 240 10 0.0 0.0 0.0 100.0
asSquareSum Main 253 0 0.0 0.0 0.0 0.0
squares Main 252 2 0.0 0.1 0.0 0.1
maxN Main 248 1 0.0 0.0 0.0 0.0
ourPalindroms Main 247 1 0.0 15.0 0.0 85.7
isPalindromic Main 249 1000000 0.0 70.7 0.0 70.7
main Main 246 1 0.0 0.0 0.0 14.3
asSquareSum Main 250 1998 0.0 0.0 0.0 14.3
trySub Main 251 1998 0.0 14.3 0.0 14.3
CAF GHC.IO.Handle.FD 176 2 0.0 0.0 0.0 0.0
CAF GHC.IO.Encoding.Iconv 137 2 0.0 0.0 0.0 0.0
CAF GHC.Conc.Signal 130 1 0.0 0.0 0.0 0.0
This awesome speed of my program is actually a lie:
[.../P125]$ time ./Main +RTS -p
...output...
real 0m4.995s
user 0m4.977s
sys 0m0.010s
(Yes, I tried running both with and without time
, and profiler keeps telling lies)
What can I do?
[.../P125]$ ghc --version
The Glorious Glasgow Haskell Compilation System, version 7.0.3
The OS Mac OS X 10.6.8. I'm pretty sure I've installed ghc
from homebrew
Short answer: The workaround is to compile with -threaded
.
Details for over-interested souls: The reason is a GHC bug (see #5282): The profiling timer always gets triggered when the run time system wants to perform garbage collection. As at that point the execution is not in Haskell code, the cost gets attributed to the "SYSTEM" cost centre - which is then dropped from the profiling view.
The reason -threaded
fixes the problem is probably that it makes the profiling timer tick in "real" time instead of the time the process was actually executing. Even though that is a less accurate form of profiling, it seems to decouple the timer enough from the program's execution to not trigger the bug.
If you love us? You can donate to us via Paypal or buy me a coffee so we can maintain and grow! Thank you!
Donate Us With