How to log call graph in Elm?

Please help, this is driving me absolutely insane!

How do I make Elm log a call graph?

Sounds simple, doesn't it? The Debug.log function should make this quiet easy. But no, try as I might, I just cannot force Elm to log the events in the correct order. I'm losing my mind here...

Let's take a trivial function like this:

factorial : Int -> Int
factorial n = if n < 2 then 1 else n * factorial (n-1)

What I want to do is write a custom trace function so I can do something similar to

factorial n = trace ("factorial " + toString n) (if n < 2 ...)

and it will log something like

factorial 3: ENTER
factorial 2: ENTER
factorial 1: ENTER
factorial 1: 1
factorial 2: 2
factorial 3: 6

So you can see it enter each function, and you can see it return from each function (and what value it actually returned).

What doesn't work:

Obvious first attempt is to do something like
```
trace : String -> x -> x
trace label x =
  let
    _ = Debug.log label "ENTER"
    _ = Debug.log label x
  in x
```
But I don't think that can ever work. Since Elm is strict (?), x was evaluated before you ever even called trace. So all the traces print out backwards.
Alright, let's make the input a function then:
```
trace : String -> (() -> x) -> x
trace label fx =
  let
    _ = Debug.log label "ENTER"
    x = fx ()
    _ = Debug.log label x
  in x
```
That really, really looks like it should work perfectly. But somehow, this manages to print the entry and exit together, followed by all of the subordinate calls afterwards, which is obviously wrong.
I'm particularly disturbed by the fact that
```
let
  _ = Debug.log label "ENTER"
  x = fx ()
in x
```
prints all the enters forwards, yet the identical expression
```
let
  _ = Debug.log label "ENTER"
in fx ()
```
prints all the enters backwards. (??!) I guess that's what I get for trying to control order of side-effects in a pure-functional programming language...
Alright, let's make it a case-block then:
```
trace label fx =
  case Debug.log label "ENTER" of
    _ -> case Debug.log label (fx ()) of
      x -> x
```
Nope, that prints everything backwards. Well that's weird. What if I just swap both of the case expressions? ...Nope, that prints enter+exit together followed by the child calls.
OK, let's get hard-core. Lambdas FTW!
```
trace label fx = Debug.log label ((\ _ -> fx ()) (Debug.log label "ENTER"))
```
That lots all the exits followed by all the enters. I'll just swap the expressions:
```
trace label fx = (\ x -> (\ _ -> x) (Debug.log label "ENTER")) (Debug.log label (fx ()))
```
No dice. That prints enter+exit for each call groups together again.
Umm...

Seriously, there must be a way to get this to work! >_< Plz help... :'{

Solution

By using Debug.log, you're trying to do something impure in a pure language. Even if you do get it to a point where it's working, as @Luke Woodward pointed out, I would hesitate relying on that because the log output could very well shift between compiler versions.

Instead, we could build a slimmed down Writer monad to keep a stateful representation of logs in the order they occur.

type Writer w a = Writer (a, List w)

runWriter : Writer w a -> (a, List w)
runWriter (Writer x) = x

pure : a -> Writer w a
pure x = Writer (x, [])

andThen : (a -> Writer w b) -> Writer w a -> Writer w b
andThen f (Writer (x, v)) =
    let (Writer (y, v_)) = f x
    in Writer (y, v ++ v_)

log : String -> a -> Writer String a
log label x = Writer (x, [label ++ ": " ++ Debug.toString x])

You could then sprinkle it in your factorial function, which means the function would now have to return a Writer String Int instead of just an Int:

factorial : Int -> Writer String Int
factorial n = 
    let logic =
            if n < 2 then
                pure 1
            else
                factorial (n-1)
                    |> andThen (\z -> pure (n * z))
    in
    log ("factorial " ++ Debug.toString n) "ENTER"
        |> andThen (\_ -> logic)
        |> andThen (\result -> log ("factorial " ++ Debug.toString n) result)

Though this looks more cumbersome and intrusive (Elm syntax is not as monad-friendly as Haskell), this will give you predictable results every time rather than having to depend upon unreliable side-effects.

The result of running factorial 3 |> runWriter |> Tuple.second is:

[ "factorial 3: \"ENTER\""
, "factorial 2: \"ENTER\""
, "factorial 1: \"ENTER\""
, "factorial 1: 1"
, "factorial 2: 2"
, "factorial 3: 6"
]

Note that this writer is not optimized (it concatenates lists, yuck!) but the idea is tried and true