Am Donnerstag 24 Dezember 2009 02:14:51 schrieb Michael Lesniak:
> Hello haskell-cafe (and merry christmas!),
>
> I have a strange problem with the garbage collector / memory which I'm
> unable to find a solution for. I think the source of my problems has to do
> with lazy evaluation, but currently I'm unable to find it.
>
> Using the attached program and threadscope I see that the GC is using a lot
> of time and the program comes (more or less) to a halt (see exa-1.png).
> When I increase the heap the program takes much longer and the GC is
> running more or less all the time (see exa-2.png).
>
> Some more detailled information:
>
> * I can see the described behaviour under both GHC 10.4 and GHC 12.1
> * Linux kernel 2.6.31-16 on a dualcore
> * Program compiled with ghc --make -O2 -threaded -eventlog Example.hs -o
> exa * Started with exa +RTS -ls and one of { -N, -N1, -N2 }
>
> Any help (pointing into the right direction, mention possibly helpful
> blog articles
> or paper, constructive critic in general) is appreciated!
I can't reproduce that (ghc-6.12.1, Linux linux-mkk1 2.6.27.39-0.2-pae #1 SMP 2009-11-23 12:57:38 +0100 i686 i686 i386 GNU/Linux, dual core):
$ time ./exa +RTS -ls -N2 -sstderr
./exa +RTS -ls -N2 -sstderr
1
3
0
0
9
3
6
9
1
8
8
9
2
5
5
8
6
5
7
8
4
72,499,126,908 bytes allocated in the heap
45,280,708 bytes copied during GC
177,504 bytes maximum residency (10 sample(s))
183,844 bytes maximum slop
4 MB total memory in use (1 MB lost due to fragmentation)
Generation 0: 131527 collections, 131526 parallel, 7.18s, 3.88s elapsed
Generation 1: 10 collections, 10 parallel, 0.00s, 0.00s elapsed
Parallel GC work balance: 1.16 (10931266 / 9433437, ideal 2)
MUT time (elapsed) GC time (elapsed)
Task 0 (worker) : 115.10s (126.56s) 3.34s ( 1.84s)
Task 1 (worker) : 124.21s (126.56s) 3.84s ( 2.04s)
Task 2 (worker) : 0.09s (126.56s) 0.00s ( 0.00s)
Task 3 (worker) : 0.00s (126.56s) 0.00s ( 0.00s)
SPARKS: 21 (21 converted, 0 pruned)
INIT time 0.00s ( 0.13s elapsed)
MUT time 238.05s (126.56s elapsed)
GC time 7.19s ( 3.88s elapsed)
EXIT time 0.00s ( 0.00s elapsed)
Total time 244.46s (130.57s elapsed)
%GC time 2.9% (3.0% elapsed)
Alloc rate 305,559,453 bytes per MUT second
Productivity 97.1% of total user, 181.7% of total elapsed
gc_alloc_block_sync: 151252
whitehole_spin: 0
gen[0].steps[0].sync_large_objects: 75620
gen[0].steps[1].sync_large_objects: 9662
gen[1].steps[0].sync_large_objects: 0
244.45user 2.06system 2:10.58elapsed 188%CPU (0avgtext+0avgdata 0maxresident)k
0inputs+35736outputs (0major+2426minor)pagefaults 0swaps
Garbage collection isn't even visible in the threadscope profile.
With -N1:
71,999,280,108 bytes allocated in the heap
20,729,380 bytes copied during GC
92,492 bytes maximum residency (2 sample(s))
190,872 bytes maximum slop
3 MB total memory in use (0 MB lost due to fragmentation)
Generation 0: 130901 collections, 0 parallel, 2.64s, 2.68s elapsed
Generation 1: 2 collections, 0 parallel, 0.00s, 0.00s elapsed
Parallel GC work balance: nan (0 / 0, ideal 1)
MUT time (elapsed) GC time (elapsed)
Task 0 (worker) : 184.86s (206.14s) 2.38s ( 2.40s)
Task 1 (worker) : 0.00s (216.71s) 0.00s ( 0.00s)
Task 2 (worker) : 20.90s (216.71s) 0.26s ( 0.28s)
SPARKS: 21 (19 converted, 2 pruned)
INIT time 0.00s ( 0.05s elapsed)
MUT time 215.33s (216.71s elapsed)
GC time 2.64s ( 2.68s elapsed)
EXIT time 0.00s ( 0.00s elapsed)
Total time 217.96s (219.44s elapsed)
%GC time 1.2% (1.2% elapsed)
Alloc rate 334,374,215 bytes per MUT second
Productivity 98.8% of total user, 98.1% of total elapsed
gc_alloc_block_sync: 0
whitehole_spin: 0
gen[0].steps[0].sync_large_objects: 0
gen[0].steps[1].sync_large_objects: 0
gen[1].steps[0].sync_large_objects: 0
217.96user 0.88system 3:39.52elapsed 99%CPU (0avgtext+0avgdata 0maxresident)k
1576inputs+19552outputs (5major+1686minor)pagefaults 0swaps
>
> Best wishes,
> Michael