[Haskell-cafe] Re: Benchmarking and Garbage Collection

[Simon Marlow]

On 04/03/2010 22:01, Neil Brown wrote:
> Jesper Louis Andersen wrote:
>> On Thu, Mar 4, 2010 at 8:35 PM, Neil Brown <nccb2 at kent.ac.uk> wrote:
>>> CML is indeed the library that has the most markedly different
>>> behaviour.
>>> In Haskell, the CML package manages to produce timings like this for
>>> fairly
>>> simple benchmarks:
>>>
>>> %GC time 96.3% (96.0% elapsed)
>>>
>>> I knew from reading the code that CML's implementation would do
>>> something
>>> like this, although I do wonder if it triggers some pathological case
>>> in the
>>> GC.
>>
>> That result is peculiar. What are you doing to the library, and what
>> do you expect happens? Since I have some code invested on top of CML,
>> I'd like to gain a little insight if possible.
>
> In trying to simplify my code, the added time has moved from GC time to
> EXIT time (and increased!). This shift isn't too surprising -- I believe
> the time is really spent trying to kill lots of threads. Here's my very
> simple benchmark; the main thread repeatedly chooses between receiving
> from two threads that are sending to it:
>
> ====
> import Control.Concurrent
> import Control.Concurrent.CML
> import Control.Monad
>
> main :: IO ()
> main = do let numChoices = 2
> cs <- replicateM numChoices channel
> mapM_ forkIO [replicateM_ (100000 `div` numChoices) $ sync $ transmit c
> () | c <- cs]
> replicateM_ 100000 $ sync $ choose [receive c (const True) | c <- cs]
> ====
>
> Compiling with -threaded, and running with +RTS -s, I get:
>
> INIT time 0.00s ( 0.00s elapsed)
> MUT time 2.68s ( 3.56s elapsed)
> GC time 1.84s ( 1.90s elapsed)
> EXIT time 89.30s ( 90.71s elapsed)
> Total time 93.82s ( 96.15s elapsed)

FYI, I've now fixed this in my working branch:

   INIT  time    0.00s  (  0.00s elapsed)
   MUT   time    0.88s  (  0.88s elapsed)
   GC    time    0.85s  (  1.04s elapsed)
   EXIT  time    0.05s  (  0.07s elapsed)
   Total time    1.78s  (  1.97s elapsed)

Cheers,
	Simon