Program runs faster with profiling than without
This program, reported by Doaitse, runs nearly twice as fast when it is profiled than when it isn't. You need to install the Utrecht library uulib
:
cabal install -p uulib
Now compile and run UULib.hs
with and without -prof -auto-all
. (It makes little difference whether or not you use -O.) When you run, here are the stats for GHC 7.0.3:
---------------- NOT PROFILED ----------------
bash-3.1$ ./uulib +RTS -s
c:\tmp\uulib.exe +RTS -s
138000
51,077,556 bytes allocated in the heap
19,153,500 bytes copied during GC
4,914,980 bytes maximum residency (5 sample(s))
519,828 bytes maximum slop
12 MB total memory in use (0 MB lost due to fragmentation)
Generation 0: 93 collections, 0 parallel, 4.71s, 4.70s elapsed
Generation 1: 5 collections, 0 parallel, 2.73s, 2.76s elapsed
INIT time 0.00s ( 0.00s elapsed)
MUT time 0.05s ( 0.11s elapsed)
GC time 7.44s ( 7.45s elapsed)
EXIT time 0.00s ( 0.00s elapsed)
Total time 7.49s ( 7.56s elapsed)
%GC time 99.4% (98.6% elapsed)
Alloc rate 1,091,377,449 bytes per MUT second
Productivity 0.6% of total user, 0.6% of total elapsed
------------- PROFILED ------------------------
bash-3.1$ ./uulib +RTS -s
c:\tmp\uulib.exe +RTS -s
138000
79,692,548 bytes allocated in the heap
31,874,676 bytes copied during GC
7,774,720 bytes maximum residency (5 sample(s))
257,912 bytes maximum slop
19 MB total memory in use (0 MB lost due to fragmentation)
Generation 0: 147 collections, 0 parallel, 2.65s, 2.66s elapsed
Generation 1: 5 collections, 0 parallel, 1.33s, 1.34s elapsed
INIT time 0.00s ( 0.00s elapsed)
MUT time 0.09s ( 0.16s elapsed)
GC time 3.98s ( 3.99s elapsed)
RP time 0.00s ( 0.00s elapsed)
PROF time 0.00s ( 0.00s elapsed)
EXIT time 0.00s ( 0.00s elapsed)
Total time 4.07s ( 4.15s elapsed)
%GC time 97.7% (96.1% elapsed)
Alloc rate 851,407,014 bytes per MUT second
Productivity 2.3% of total user, 2.3% of total elapsed
The profiled one:
- Allocates more
- But runs nearly twice as fast
Looking at the stats, though, you can see that in both cases 99% of execution time spent in the garbage collector. I don't think I've ever seen a program spend that much time in GC.
So I don't really know what's going on, but it's clearly a rather amazing program.
Trac metadata
Trac field | Value |
---|---|
Version | 7.0.3 |
Type | Bug |
TypeOfFailure | OtherFailure |
Priority | normal |
Resolution | Unresolved |
Component | Compiler |
Test case | |
Differential revisions | |
BlockedBy | |
Related | |
Blocking | |
CC | doaitse@uu.nl, scpmw@leeds.ac.uk |
Operating system | Unknown/Multiple |
Architecture |