`trace` function in ghci does not print on second invocation

Question

Problem:

The trace function does not work on the second invocation but this only happens if the function containing trace is loaded into ghci.

Question

1. Why does this happen?
2. How can I load in Haskel modules and still have the expected behaviour?

Unexpected behaviour:

I have a file called test.hs

import Debug.Trace (trace)
main = trace "test" return "main is called"

Then I type following in ghci. Note on the second invocation of main trace did not print "test"

Prelude> :l test
[1 of 1] Compiling Main             ( test.hs, interpreted )
Ok, one module loaded.
*Main> main
test
"main is called"
*Main> main      -- No output from trace?
"main is called"

Expected behaviour

However, if I type the main function in ghci, I get the expected behaviour

Prelude> import Debug.Trace (trace)
Prelude Debug.Trace> main = trace "test" return "main is called" 
Prelude Debug.Trace> main
test
"main is called"
Prelude Debug.Trace> main -- Output from trace
test
"main is called"
Prelude Debug.Trace> 

Update

@Robin Zigmond suggestion, I tried out different parenthesis but without success

main = trace "test" (return "main is called")
main = return(trace "test" "main is called") -- Joins the outputs into one string

Answer 1

First, a general idea of how Haskell evaluates things. Consider this expression

(\x -> x * x) (2 + 2)

Haskell is lazy; functions don't evaluate their arguments before invocation, so a naive way of doing this would be:

(2 + 2) * (2 + 2)

But that would double the work!

What is done instead is something like:

    *
   /  \
   \  /
   (2+2)

That is, the runtime remembers that 2 + 2 came from a single place, and when it's evaluated, the result is reused in other parts of the expression:

    *
   /  \
   \  /
     4

and then

     16

The trace function wraps an expression and only prints the message the first time the expression is "popped". It doesn't print the message again if the result is requested again:

ghci> (\x -> x * x) (trace "pop!" (2 + 2))
pop!
16

The next part of the puzzle are IO actions. In Haskell, statement-like things like IO actions are actually values like anything else. They can be passed as arguments to functions, and they can be returned from functions. It's just that the runtime interprets them as descriptions of effectful actions to perform in the real world.

Therefore, expressions whose type is IO something must be evaluated (in the pure, lazy sense) before being executed (in the "interacts with the world" sense). For example:

(\x -> x >> x) (trace "test" (putStrLn "foo"))

becomes

        (>>)
       /  \
       \  /
(trace "test" (putStrLn "foo"))

here we pop the expression and "test" is printed a single time

        (>>)
       /  \
       \  /
    putStrLn "foo"

the runtime sees something like

putStrLn "foo", then putStrLn "foo" again

Actually, what you wrote is slightly different: (trace "test" return) "main is called". In your code trace is wrapping the return function, not the resulting IO String value. But the effect is similar, functions are also values in Haskell. Expressions whose type is a function must be evaluated before the function is called.

Also, in your case, what's happening is that the main action is evaluated once, and executed several times.

Notice that trace's effects (printing stuff on console) are out-of-band with the normal flow of IO actions. They happen according to the vagaries of lazy evaluation. It's a debug function that shouldn't be used for "real" work.

---

Update: I forgot to answer this part of the question: why does trace have the behavior you expect in your ghci experiments?

trace "test" (return "foo") is a polymorphic value, it doesn't actually specify a concrete monad (try :t return "foo"). ghci's defaulting rules instantiate it to IO before executing it. This polymorphism makes ghci recalculate the value each time you enter main. The effect should disappear if you provide an explicit type annotation, like main = (trace "test" (return "foo")) :: IO String.