[Haskell-cafe] GHC 6.10, strange behaviour when profiling?

[Thomas Schilling]

I think you hit bug http://hackage.haskell.org/trac/ghc/ticket/2747,
which is an accounting bug in the garbage collector and goes away when
you trigger more garbage collections (which -hc does, I think).
Please file a bug report anyway, so we can verify that it is indeed
not a new bug.  (Since the profiler modifies the program it can turn
on or off different optimisations, so it's quite possible that there
are other reasons for this behaviour.)


2008/11/10 Aleš Bizjak <ales.bizjak0 at gmail.com>:
> Hello,
>
> I'm experiencing some strange behaviour with GHC 6.10 and would like an
> explanation why.
>
> Here's the problem. With GHC 6.8.[23] memory usage of a program was about
> 250mb (computing pi to 10^6 decimals).
> Now I tried recompiling and running with GHC 6.10 and I got more than 1.4gb
> before I killed it, so naturally I tried profiling but
> here's the strangeness. When I compile for profiling with -prof -auto-all
> and run with +RTS -p -RTS memory use is
> still about the same as before (> 1.4gb), but when I try running with +RTS
> -hc -RTS memory only reaches about 250mb.
>
> What is the explanation for this behaviour?
>
> I would send a program but it requires HERA, which is not on hackage ...
>
> Here is the output of -s
>
> ./Test 100000 +RTS -s
>      47,467,176 bytes allocated in the heap
>      18,046,776 bytes copied during GC
>       9,215,104 bytes maximum residency (6 sample(s))
>         711,520 bytes maximum slop
>              80 MB total memory in use (11 MB lost due to fragmentation)
>
>  Generation 0:    84 collections,     0 parallel,  0.01s,  0.01s elapsed
>  Generation 1:     6 collections,     0 parallel,  0.01s,  0.01s elapsed
>
>  INIT  time    0.00s  (  0.00s elapsed)
>  MUT   time    3.66s  (  3.71s elapsed)
>  GC    time    0.02s  (  0.02s elapsed)
>  RP    time    0.00s  (  0.00s elapsed)
>  PROF  time    0.00s  (  0.00s elapsed)
>  EXIT  time    0.00s  (  0.00s elapsed)
>  Total time    3.68s  (  3.73s elapsed)
>
>  %GC time       0.5%  (0.6% elapsed)
>
>  Alloc rate    12,982,553 bytes per MUT second
>
>  Productivity  99.5% of total user, 97.9% of total elapsed
>
>
>
>
> ./Test 100000 +RTS -s -hc
>      47,471,160 bytes allocated in the heap
>      18,637,752 bytes copied during GC
>      13,580,144 bytes maximum residency (37 sample(s))
>         810,712 bytes maximum slop
>              33 MB total memory in use (7 MB lost due to fragmentation)
>
>  Generation 0:    85 collections,     0 parallel,  0.02s,  0.02s elapsed
>  Generation 1:    37 collections,     0 parallel,  0.00s,  0.01s elapsed
>
>  INIT  time    0.00s  (  0.00s elapsed)
>  MUT   time    3.67s  (  3.73s elapsed)
>  GC    time    0.02s  (  0.03s elapsed)
>  RP    time    0.00s  (  0.00s elapsed)
>  PROF  time    0.00s  (  0.00s elapsed)
>  EXIT  time    0.00s  (  0.00s elapsed)
>  Total time    3.70s  (  3.77s elapsed)
>
>  %GC time       0.6%  (0.8% elapsed)
>
>  Alloc rate    12,941,165 bytes per MUT second
>
>  Productivity  99.2% of total user, 97.4% of total elapsed
>
>
>
>
> --
> Best regards, Aleš
> _______________________________________________
> Haskell-Cafe mailing list
> Haskell-Cafe at haskell.org
> http://www.haskell.org/mailman/listinfo/haskell-cafe
>