runStateT execution times measurement baffling

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

On Thu, Oct 20, 2011 at 11:59 AM, David Barbour
On Thu, Oct 20, 2011 at 10:38 AM, thomas burt
wrote: Curiously, the times reported for "outside" are about 5-8 times as long.
What is the cost of putStrLn relative to performing `stuffToDo` a few hundred times?
I am not sure.... it still takes about 5-8 times longer whether `stuffToDo` recurs a few times, a hunded times, or about a thousand times.
Perhaps I will try and force `stuffToDo` not to leave any partially evaluated thunks behind.... and compare the cost then.

On Saturday 22 October 2011, 13:55:36, Bas van Dijk wrote:
On 20 October 2011 22:16, thomas burt
wrote: Perhaps I will try and force `stuffToDo` not to leave any partially evaluated thunks behind.... and compare the cost then.
What happens when you switch to a strict StateT?
He already uses the strict StateT:
By the way I'm using ghc-6.10.4 and Control.Monad.Trans.State.Strict.
We need to see more of the code to find out what's going on.

Sorry, thought I had replied to this with my result! I added `seq` and $! inside `stuffToDo` to ensure that there weren't any thunks left around after it was called. The measured times were only a few hundredths of a second apart after that. So, apparently even with a strict StateT, partially evaluated references can easily be left around all the way until the call to runStateT returns. In this case my state is a record, if that makes any difference. It's not what I expected... I can see why my example is too small to show why it behaved this way though. I thought pattern matching (in Haskell98) was itself strict, so I don't see what the difference between a lazy and strict stateT is, except perhaps in cases that the value of runStateT is bound via a different mechanism than pattern matching. On Sat, Oct 22, 2011 at 6:13 AM, Daniel Fischer < daniel.is.fischer@googlemail.com> wrote:
On Saturday 22 October 2011, 13:55:36, Bas van Dijk wrote:
On 20 October 2011 22:16, thomas burt
wrote: Perhaps I will try and force `stuffToDo` not to leave any partially evaluated thunks behind.... and compare the cost then.
What happens when you switch to a strict StateT?
He already uses the strict StateT:
By the way I'm using ghc-6.10.4 and Control.Monad.Trans.State.Strict.
We need to see more of the code to find out what's going on.

On Saturday 22 October 2011, 23:07:44, thomas burt wrote:
Sorry, thought I had replied to this with my result!
I added `seq` and $! inside `stuffToDo` to ensure that there weren't any thunks left around after it was called.
The measured times were only a few hundredths of a second apart after that.
So, apparently even with a strict StateT, partially evaluated references can easily be left around all the way until the call to runStateT returns.
Yes. The 'Strict' isn't very deep, it just means that on 'bind' (>>=), the state/value pair is evaluated to whnf. The components can easily contain unevaluated thunks. The strictness analyser (supposing you compile with optimisations) then can often see further and find that it's good to keep more things evaluated. It's easier for the strictness analyser than for the lazy variant (where the state/value pair is bound by a lazy pattern), but it still doesn't detect all opportunities for strict evaluation, so you're often enough left with accumulating unevaluated thunks. (The compiler may only add strictness where it can prove that doesn't change the semantics of the programme, so the strictness analyser has a pretty hard job.)
In this case my state is a record, if that makes any difference.
Well, it does, in comparison to simpler types. If the state is a plain Int, it's *relatively* easy to find out whether demanding the end result requires the evaluation of intermediate states. The more components and/or layers your state has, the harder it is to determine which ones of them are necessary to evaluate for the end result, the more opportunities for strictness will go unnoticed. Strict fields in the record can greatly help then.
It's not what I expected... I can see why my example is too small to show why it behaved this way though.
I thought pattern matching (in Haskell98) was itself strict, so I don't
Yes, but that only means that the value is evaluated to the outermost constructor (or, in the case of nested patterns, as far as required). The constructor fields by default remain unevaluated (but they are now directly accessible thunks and no longer thunks hidden inside another thunk).
see what the difference between a lazy and strict stateT is, except perhaps in cases that the value of runStateT is bound via a different mechanism than pattern matching.
The difference is that (>>=) in the strict StateT takes apart the state/value pair, creating two blobs and a constructor combing those to a pair, while (>>=) in the lazy StateT doesn't take apart the state/value blob. The latter makes it easier for thunks to accumulate (but on the other hand, it allows some feats that can't be done with the former, much less with even stricter variants).

On 11-10-20 01:38 PM, thomas burt wrote:
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)
Where can I find stuffToDo? How do you get away with getCurrentTime (as opposed to liftIO getCurrentTime) inside f? Does not type-check. How much should I trust this code?
participants (5)
-
Albert Y. C. Lai
-
Bas van Dijk
-
Daniel Fischer
-
David Barbour
-
thomas burt