When debugging my State Monad, reverses order depending on where trace is

Question

So I was building a State Monad and ran into some problems with its lazy nature that is making it hard for me to debug.

My State monad operates by getting in a list of values, pushing them one by one on to part of the state, then I analyze what values are on the state after each one to produce the other part of the state.

I came up with this simple example to illustrate why it is hard to debug.

module Main where

import Control.Monad.State
import Debug.Trace

runSim :: [Int] -> State String String
runSim [] = return =<< get
runSim (cur:xs) = do
    lst <- get
    let val =  (show $ 2*cur)
    put $ trace ((show $ length lst) ++ " " ++ (show cur)) ((val) ++ "," ++ lst)
    runSim xs

main :: IO ()
main = print $ evalState (runSim [1..10]) ""

The output of this is:

0 1
2 2
4 3
6 4
8 5
11 6
14 7
17 8
20 9
23 10
"20,18,16,14,12,10,8,6,4,2,"

However if I change my trace line to this:

put $ trace ((show cur)) ((val) ++ "," ++ lst)

The output is reversed:

10
9
8
7
6
5
4
3
2
1
"20,18,16,14,12,10,8,6,4,2,"

But the end result is the same. Is there a better way to handle the laziness of the State Monad in debugging so it is more naturally sequential?

Answer 1

The problem is that the trace calls are only evaluated at the end.

The computation builds the state like (taking a list of only two elements for brevity)

runSim [1, 2] "" ~> ( (), state1@(trace (output 1 "") (logString 1 "")))
~> runSim [2] ( (), trace (output 2 state1) (logString2 state1))

so in the final state, the trace for the last pushed list element is the outermost.

Now in the second case, where

output i _ = show i

the tracing output doesn't depend on what happened earlier, so the trace pushed last is run first etc.

But in the first case, where

output i state = show (length state) ++ " " ++ show i

the tracing output depends on the state, so the state has to be evaluated before the tracing output can be printed. But state is a call to the previously pushed trace, so that trace needs to run first, etc. And so the data-dependencies in the tracing output ensure the traces are run in the order of pushing.

To ensure that the traces are run in that order without data-dependencies, you must pull the trace call out of the put, or force evaluation of the put state,

put $! trace ((show $ length lst) ++ " " ++ (show cur)) ((val) ++ "," ++ lst)

or

trace ((show $ length lst) ++ " " ++ (show cur)) $ put ((val) ++ "," ++ lst)