Improved parser logger

[Janiczek]

Hello!

Some time ago I’ve asked about your techniques for debugging parsers and shared a "log parser combinator" there.

I’ve since made it a bit better: instead of just logging the “enter” transitions and successful “exit” transitions, it’s now also logging unsuccessful “exit” transitions.

It does this by using a technique similar to the “logging JSON decoder”: it fetches the source from the current parser and runs Parser.run itself, and logs the Ok / Err result. That allows us to see the unsuccessful results, along with the context stack, problem, and so on.

Here is the code:

shouldLog : String -> Bool
shouldLog message =
    -- You can conditionally turn some of the logging on/off per function here.
    List.member message
        [ "moduleType"
        , "plainModuleType"
        , "portModuleType"
        , "effectModuleType"
        ]


{-| Beware: what this parser logs might sometimes be a lie.

To work it needs to run `Parser.run` inside itself, and it has no way to
set the parser state itself to the state it was called in.

So it runs it with a different source string, zeroed offset, indent, position,
basically with totally different parser state.

Some parsers might not work properly in the "inner" `Parser.run` call as a result
if they depend on this state, and thus might log lies.

Note: the parser itself will still work as before, since we're not resetting the
"outer" `Parser.run` state.

-}
log : String -> Parser_ a -> Parser_ a
log message parser =
    if shouldLog message then
        P.succeed
            (\source offsetBefore ->
                let
                    _ =
                        Debug.log "+++++++++++++++++ starting" message
                in
                ( source, offsetBefore )
            )
            |= P.getSource
            |= P.getOffset
            |> P.andThen
                (\( source, offsetBefore ) ->
                    {- Kinda like that logging decoder from Thoughtbot:
                       https://thoughtbot.com/blog/debugging-dom-event-handlers-in-elm

                       Basically we run `Parser.run` ourselves so that we can
                       get at the context and say something more meaningful
                       about the failure if it happens.
                    -}
                    let
                        remainingSource =
                            String.dropLeft offsetBefore source
                                |> Debug.log "yet to parse  "
                    in
                    let
                        parseResult =
                            -- the side-effecty part; this might log lies
                            P.run
                                (P.succeed
                                    (\parseResult_ innerOffset ->
                                        let
                                            _ =
                                                Debug.log "chomped string" (String.left innerOffset remainingSource)
                                        in
                                        parseResult_
                                    )
                                    |= parser
                                    |= P.getOffset
                                )
                                remainingSource
                                |> Debug.log "parse result  "
                    in
                    let
                        _ =
                            Debug.log "----------------- ending  " message
                    in
                    parser
                )

    else
        parser

And here is an example output!

+++++++++++++++++ starting: "moduleType"
yet to parse  : "port module Foo.Bar exposing (..)"
+++++++++++++++++ starting: "plainModuleType"
yet to parse  : "port module Foo.Bar exposing (..)"
parse result  : Err [{ col = 1, contextStack = [], problem = ExpectingModuleKeyword, row = 1 }]
----------------- ending  : "plainModuleType"
+++++++++++++++++ starting: "portModuleType"
yet to parse  : "port module Foo.Bar exposing (..)"
chomped string: "port module"
parse result  : Ok PortModule
----------------- ending  : "portModuleType"
chomped string: "port module"
parse result  : Ok PortModule
----------------- ending  : "moduleType"

You can kinda make sense of it by counting the +++ and --- around. But beware

Disclaimer 1: It duplicates some of the output and so the trace isn’t precisely what happens during the execution. I believe it’s a consequence of nesting log-ed parsers together (multiple Debug.log runs because I can’t provide a way to turn off the logging inside the inner Parser.run call )

Disclaimer 2: I believe it has a problem (didn’t run into it yet though) where because the inner Parser.run can’t replicate the parser state of the outer parser it lives in (there’s API in elm/parser for getting the state but not for setting it), some parsers that depend on the offset / indentation / … might return different result in the inner Parser.run call (and thus log different stuff) from the outer one (which stays the same, fortunately).

[jxxcarlson]

Martin, this is a much-needed tool — have wanted something like it for a long time. I’ve copied the code and will use it next time I run into difficulties with making parsers.

Bravo!

[Janiczek]

Thinking about this, it might be possible to get rid of the second downside (not being able to copy the state from the outer parser to the inner parser). What about fetching the current position and indentation and then instead of

Parser.run parser remainingString

we’d do

Parser.run
  (Parser.succeed identity
     |. Parser.spaces
     |= parser
     |> Parser.withIndentation oldIndentation
  )
  ("\n\n\n     " ++ remainingString)
  -- the whitespace string dynamically generated
  -- from (row,col) position: \n for rows, ' ' for cols)

That should make it have the same state as the outer parser
For some reason a version of this didn’t do what I wanted when I first tried this idea, but I’ll probably try again later, because I don’t see why it shouldn’t work.