[Haskell-cafe] runStateT execution times measurement baffling

[thomas burt]

Hello -

I've been trying to measure execution time for some code I'm running with
the StateT monad transformer.

I have a function f :: StateT MyState IO a

Now, I measure the time it takes to run an invocation of this function from
beginning to end, i.e.

f = do
  t0 <- getCurrentTime
  stuffToDo
  t1 <- getCurrentTime
  liftIO $ putStrLn (show $ diffUTCTime t1 t0)

And also measure like this:

g :: IO
g = do
  t0 <- getCurrentTime
  (val,newState) <- runStateT f initialState
  t1 <- getCurrentTime
  putStrLn  $ "outside: " ++ (show $ diffUTCTime t1 t0)


Curiously, the times reported for "outside" are about 5-8 times as long.
I should probably note that stuffToDo calls itself a few hundred times (and
uses liftIO once per loop).

Anyone with ideas on why runStateT apparently has so much overhead?

By the way I'm using ghc-6.10.4 and Control.Monad.Trans.State.Strict.

Thanks for any suggestions or advice.
Thomas
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://www.haskell.org/pipermail/haskell-cafe/attachments/20111020/8667cd95/attachment.htm>