Ticket #4005: BONZO

File BONZO, 10.5 KB (added by hwloidl, 9 years ago)

log of compilation and execution

Line 
1 -*- outline -*-
2
3* The Problem
4
5paraffinsL.hs seems to give a slowdown of almost a factor of
62 when using -O2 during compilation (also with -O)..
7I noticed that when tinkering with parallel variants, but
8happens even just for seq compilation.
9pL.hs is a cleaned-up, stand-alone version that triggers this
10behaviour.
11
12The sources are in
13  http://james.mathematik.uni-marburg.de:8080/darcs/parfib/paraffins
14
15I checked this with ghc-6.13 (HEAD as of 1.4.2010) and with
16ghc-6.12.2rc2 (as of 20.4.2010), with the commands below.
17
18This is on a i386-unknown-linux machine
19
20* LOGs
21
22** with ghc-6.13
23
24/u1/staff/hwloidl/OPT/bin/ghc-6.13.20100401 --version
25The Glorious Glasgow Haskell Compilation System, version 6.13.20100401
26
27*** no opt
28
29lxpara2[173](3.2)> make GHC=/u1/staff/hwloidl/OPT/bin/ghc-6.13.20100401 EXTRA="-rtsopts" pL
30Compiling sequential prg paraffinsL; do 'make way=thr_l' for parallel build, 'make way=thr_l launch' for running it
31/u1/staff/hwloidl/OPT/bin/ghc-6.13.20100401 --make -cpp   -rtsopts   -o pL pL.hs
32[1 of 1] Compiling Main             ( pL.hs, pL.o )
33Linking pL ...
34lxpara2[174](3.2)> ./pL 28 +RTS -sstderr
35./pL 28 +RTS -sstderr
36[1,1,1,2,3,5,9,18,35,75,159,355,802,1858,4347,10359,24894,60523,148284,366319,910726,2278658,5731580,14490245,36797588,93839412,240215803,617105614]
37  47,090,084,280 bytes allocated in the heap
38       7,505,292 bytes copied during GC
39         924,728 bytes maximum residency (2 sample(s))
40         132,688 bytes maximum slop
41               3 MB total memory in use (0 MB lost due to fragmentation)
42
43  Generation 0: 89818 collections,     0 parallel,  0.26s,  0.36s elapsed
44  Generation 1:     2 collections,     0 parallel,  0.00s,  0.00s elapsed
45
46  INIT  time    0.00s  (  0.00s elapsed)
47  MUT   time   19.63s  ( 19.69s elapsed)
48  GC    time    0.26s  (  0.37s elapsed)
49  EXIT  time    0.00s  (  0.00s elapsed)
50  Total time   19.90s  ( 20.06s elapsed)
51
52  %GC time       1.3%  (1.8% elapsed)
53
54  Alloc rate    2,398,516,145 bytes per MUT second
55
56  Productivity  98.7% of total user, 97.9% of total elapsed
57
58lxpara2[175](3.2)> rm *.o paraffinsL paraffinsL_thr paraffinsL_thr_l pL.o pL_thr.o pL
59rm: cannot remove `*.o': No such file or directory
60rm: cannot remove `paraffinsL': No such file or directory
61removed `paraffinsL_thr'
62rm: cannot remove `paraffinsL_thr_l': No such file or directory
63rm: cannot remove `pL.o': No such file or directory
64rm: cannot remove `pL_thr.o': No such file or directory
65removed `pL'
66
67*** opt: -O
68
69rm *.o paraffinsL paraffinsL_thr paraffinsL_thr_l pL.o pL_thr.o pL
70removed `pL.o'
71rm: cannot remove `paraffinsL': No such file or directory
72rm: cannot remove `paraffinsL_thr': No such file or directory
73rm: cannot remove `paraffinsL_thr_l': No such file or directory
74rm: cannot remove `pL.o': No such file or directory
75rm: cannot remove `pL_thr.o': No such file or directory
76removed `pL'
77lxpara2[227](3.2)> make GHC=/u1/staff/hwloidl/OPT/bin/ghc-6.13.20100401 EXTRA="-rtsopts -O" pL
78Compiling sequential prg paraffinsL; do 'make way=thr_l' for parallel build, 'make way=thr_l launch' for running it
79/u1/staff/hwloidl/OPT/bin/ghc-6.13.20100401 --make -cpp   -rtsopts -O   -o pL pL.hs
80[1 of 1] Compiling Main             ( pL.hs, pL.o )
81Linking pL ...
82lxpara2[228](3.2)> ./pL 28 +RTS -sstderr
83./pL 28 +RTS -sstderr
84[1,1,1,2,3,5,9,18,35,75,159,355,802,1858,4347,10359,24894,60523,148284,366319,910726,2278658,5731580,14490245,36797588,93839412,240215803,617105614]
85  47,044,173,772 bytes allocated in the heap
86   7,074,033,020 bytes copied during GC
87         961,624 bytes maximum residency (4228 sample(s))
88         219,808 bytes maximum slop
89               4 MB total memory in use (0 MB lost due to fragmentation)
90
91  Generation 0: 85505 collections,     0 parallel, 10.37s, 10.49s elapsed
92  Generation 1:  4228 collections,     0 parallel,  7.02s,  7.03s elapsed
93
94  INIT  time    0.00s  (  0.00s elapsed)
95  MUT   time   19.41s  ( 19.46s elapsed)
96  GC    time   17.39s  ( 17.52s elapsed)
97  EXIT  time    0.00s  (  0.00s elapsed)
98  Total time   36.80s  ( 36.98s elapsed)
99
100  %GC time      47.3%  (47.4% elapsed)
101
102  Alloc rate    2,424,198,411 bytes per MUT second
103
104  Productivity  52.7% of total user, 52.5% of total elapsed
105
106
107*** opt: -O2
108
109lxpara2[176](3.2)> make GHC=/u1/staff/hwloidl/OPT/bin/ghc-6.13.20100401 EXTRA="-rtsopts -O2" pL
110Compiling sequential prg paraffinsL; do 'make way=thr_l' for parallel build, 'make way=thr_l launch' for running it
111/u1/staff/hwloidl/OPT/bin/ghc-6.13.20100401 --make -cpp   -rtsopts -O2   -o pL pL.hs
112[1 of 1] Compiling Main             ( pL.hs, pL.o )
113Linking pL ...
114lxpara2[177](3.2)> ./pL 28 +RTS -sstderr./pL 28 +RTS -sstderr
115[1,1,1,2,3,5,9,18,35,75,159,355,802,1858,4347,10359,24894,60523,148284,366319,910726,2278658,5731580,14490245,36797588,93839412,240215803,617105614]
116  47,051,708,496 bytes allocated in the heap
117   7,050,626,672 bytes copied during GC
118         961,612 bytes maximum residency (4223 sample(s))
119         218,932 bytes maximum slop
120               4 MB total memory in use (0 MB lost due to fragmentation)
121
122  Generation 0: 85524 collections,     0 parallel, 10.44s, 10.54s elapsed
123  Generation 1:  4223 collections,     0 parallel,  7.19s,  7.18s elapsed
124
125  INIT  time    0.00s  (  0.00s elapsed)
126  MUT   time   19.24s  ( 19.34s elapsed)
127  GC    time   17.63s  ( 17.73s elapsed)
128  EXIT  time    0.00s  (  0.00s elapsed)
129  Total time   36.87s  ( 37.06s elapsed)
130
131  %GC time      47.8%  (47.8% elapsed)
132
133  Alloc rate    2,445,247,720 bytes per MUT second
134
135  Productivity  52.2% of total user, 51.9% of total elapsed
136
137
138** with ghc 6.12.2
139
140/u1/staff/hwloidl/BUILDS/ghc-6.12.2/i386-unknown-linux/inplace/bin/ghc-stage2 --version
141The Glorious Glasgow Haskell Compilation System, version 6.12.2
142
143*** no opt
144
145lxpara2[181](3.2)> make GHC=/u1/staff/hwloidl/BUILDS/ghc-6.12.2/i386-unknown-linux/inplace/bin/ghc-stage2 EXTRA="-rtsopts" pL
146Compiling sequential prg paraffinsL; do 'make way=thr_l' for parallel build, 'make way=thr_l launch' for running it
147/u1/staff/hwloidl/BUILDS/ghc-6.12.2/i386-unknown-linux/inplace/bin/ghc-stage2 --make -cpp   -rtsopts   -o pL pL.hs
148[1 of 1] Compiling Main             ( pL.hs, pL.o )
149Linking pL ...
150lxpara2[182](3.2)> ./pL 28 +RTS -sstderr
151./pL 28 +RTS -sstderr
152[1,1,1,2,3,5,9,18,35,75,159,355,802,1858,4347,10359,24894,60523,148284,366319,910726,2278658,5731580,14490245,36797588,93839412,240215803,617105614]
153  47,090,084,212 bytes allocated in the heap
154       7,505,544 bytes copied during GC
155         924,680 bytes maximum residency (2 sample(s))
156         132,676 bytes maximum slop
157               3 MB total memory in use (0 MB lost due to fragmentation)
158
159  Generation 0: 89818 collections,     0 parallel,  0.31s,  0.38s elapsed
160  Generation 1:     2 collections,     0 parallel,  0.00s,  0.00s elapsed
161
162  INIT  time    0.00s  (  0.00s elapsed)
163  MUT   time   19.08s  ( 19.17s elapsed)
164  GC    time    0.31s  (  0.38s elapsed)
165  EXIT  time    0.00s  (  0.00s elapsed)
166  Total time   19.40s  ( 19.55s elapsed)
167
168  %GC time       1.6%  (2.0% elapsed)
169
170  Alloc rate    2,467,632,062 bytes per MUT second
171
172  Productivity  98.4% of total user, 97.6% of total elapsed
173
174lxpara2[183](3.2)> rm *.o paraffinsL paraffinsL_thr paraffinsL_thr_l pL.o pL_thr.o pL
175removed `pL.o'
176rm: cannot remove `paraffinsL': No such file or directory
177removed `paraffinsL_thr'
178rm: cannot remove `paraffinsL_thr_l': No such file or directory
179rm: cannot remove `pL.o': No such file or directory
180rm: cannot remove `pL_thr.o': No such file or directory
181removed `pL'
182
183*** opt -O
184
185lxpara2[222](3.2)> rm *.o paraffinsL paraffinsL_thr paraffinsL_thr_l pL.o pL_thr.o pL
186removed `pL.o'
187rm: cannot remove `paraffinsL': No such file or directory
188rm: cannot remove `paraffinsL_thr': No such file or directory
189rm: cannot remove `paraffinsL_thr_l': No such file or directory
190rm: cannot remove `pL.o': No such file or directory
191rm: cannot remove `pL_thr.o': No such file or directory
192removed `pL'
193lxpara2[223](3.2)> make GHC=/u1/staff/hwloidl/BUILDS/ghc-6.12.2/i386-unknown-linux/inplace/bin/ghc-stage2 EXTRA="-rtsopts -O" pL
194Compiling sequential prg paraffinsL; do 'make way=thr_l' for parallel build, 'make way=thr_l launch' for running it
195/u1/staff/hwloidl/BUILDS/ghc-6.12.2/i386-unknown-linux/inplace/bin/ghc-stage2 --make -cpp   -rtsopts -O   -o pL pL.hs
196[1 of 1] Compiling Main             ( pL.hs, pL.o )
197Linking pL ...
198lxpara2[224](3.2)> ./pL 28 +RTS -sstderr
199./pL 28 +RTS -sstderr
200[1,1,1,2,3,5,9,18,35,75,159,355,802,1858,4347,10359,24894,60523,148284,366319,910726,2278658,5731580,14490245,36797588,93839412,240215803,617105614]
201  47,044,178,716 bytes allocated in the heap
202   7,069,606,076 bytes copied during GC
203         961,580 bytes maximum residency (4225 sample(s))
204         219,140 bytes maximum slop
205               4 MB total memory in use (0 MB lost due to fragmentation)
206
207  Generation 0: 85508 collections,     0 parallel, 11.06s, 10.94s elapsed
208  Generation 1:  4225 collections,     0 parallel,  7.28s,  7.27s elapsed
209
210  INIT  time    0.00s  (  0.00s elapsed)
211  MUT   time   18.70s  ( 19.02s elapsed)
212  GC    time   18.34s  ( 18.21s elapsed)
213  EXIT  time    0.00s  (  0.00s elapsed)
214  Total time   37.03s  ( 37.24s elapsed)
215
216  %GC time      49.5%  (48.9% elapsed)
217
218  Alloc rate    2,516,248,725 bytes per MUT second
219
220  Productivity  50.5% of total user, 50.2% of total elapsed
221
222
223*** opt -O2
224
225lxpara2[184](3.2)> make GHC=/u1/staff/hwloidl/BUILDS/ghc-6.12.2/i386-unknown-linux/inplace/bin/ghc-stage2 EXTRA="-rtsopts -O2" pL
226Compiling sequential prg paraffinsL; do 'make way=thr_l' for parallel build, 'make way=thr_l launch' for running it
227/u1/staff/hwloidl/BUILDS/ghc-6.12.2/i386-unknown-linux/inplace/bin/ghc-stage2 --make -cpp   -rtsopts -O2   -o pL pL.hs
228[1 of 1] Compiling Main             ( pL.hs, pL.o )
229Linking pL ...
230lxpara2[185](3.2)> ./pL 28 +RTS -sstderr
231./pL 28 +RTS -sstderr
232[1,1,1,2,3,5,9,18,35,75,159,355,802,1858,4347,10359,24894,60523,148284,366319,910726,2278658,5731580,14490245,36797588,93839412,240215803,617105614]
233  47,051,712,016 bytes allocated in the heap
234   7,052,409,768 bytes copied during GC
235         961,568 bytes maximum residency (4224 sample(s))
236         218,976 bytes maximum slop
237               4 MB total memory in use (0 MB lost due to fragmentation)
238
239  Generation 0: 85523 collections,     0 parallel, 10.22s, 10.36s elapsed
240  Generation 1:  4224 collections,     0 parallel,  7.36s,  7.36s elapsed
241
242  INIT  time    0.00s  (  0.00s elapsed)
243  MUT   time   19.08s  ( 19.13s elapsed)
244  GC    time   17.58s  ( 17.72s elapsed)
245  EXIT  time    0.00s  (  0.00s elapsed)
246  Total time   36.66s  ( 36.86s elapsed)
247
248  %GC time      47.9%  (48.1% elapsed)
249
250  Alloc rate    2,465,489,486 bytes per MUT second
251
252  Productivity  52.1% of total user, 51.8% of total