Reconciling Stacktraces with Computation Expressions

Computation expressions are an excellent F# language feature. They outline the F# way of defining monads but are immensely more flexible. Applications include Asynchronous workflows, sequence/list comprehensions and our very own cloud workflows. Overall, it’s a feature that has seen lots of use (and misuse!) by the F# community. More importantly, it can all be done at the library level without needing to modify the language itself.

For a more in-depth introduction to computation expressions, I refer you to Scott Wlaschin’s excellent series on the subject.

The Problem

Computation expressions may be great, but they’re not without problems. One of the more common annoyances is exception stacktraces; generated expressions are desugared into nested lambda invocations, which means that their corresponding stacktraces are often unreadable.

To make matters worse, implementations such as async have their own exception handling logic implemented, which often leads to stacktraces being completely erased as a side-effect of this manipulation.

Let’s make the problem a bit more concrete by presenting an example:

let rec factorial n = async {
    if n = 0 then return failwith "bug!"
    else
        let! pd = factorial (n - 1)
        return n * pd
}

Async.RunSynchronously(factorial 5)

If we attempt to execute the code we will be getting the following stacktrace (as of F# 4.0):

System.Exception: bug!
   at FSI_0008.factorial@128-2.Invoke(Unit unitVar) in C:\Users\eirik\Desktop\meta2.fsx:line 128
   at Microsoft.FSharp.Control.AsyncBuilderImpl.callA@851.Invoke(AsyncParams`1 args)
--- End of stack trace from previous location where exception was thrown ---
   at Microsoft.FSharp.Control.AsyncBuilderImpl.commit[a](Result`1 res)
   at Microsoft.FSharp.Control.CancellationTokenOps.RunSynchronously[a](CancellationToken token, FSharpAsync`1 computation, FSharpOption`1 timeout)
   at Microsoft.FSharp.Control.FSharpAsync.RunSynchronously[T](FSharpAsync`1 computation, FSharpOption`1 timeout, FSharpOption`1 cancellationToken)
   at <StartupCode$FSI_0009>.$FSI_0009.main@() in C:\Users\eirik\Desktop\meta2.fsx:line 135
Stopped due to error

Notice that method invocation information is missing: factorial was called recursively 5 times before the error occured. For reference, compare this against a native implementation of the same function:

let rec factorial n =
    if n = 0 then failwith "bug!"
    else
        n * factorial(n - 1)

factorial 5

which gives the stacktrace

System.Exception: bug!
   at FSI_0013.factorial(Int32 n) in C:\Users\eirik\Desktop\meta1.fsx:line 38
   at FSI_0013.factorial(Int32 n) in C:\Users\eirik\Desktop\meta1.fsx:line 38
   at FSI_0013.factorial(Int32 n) in C:\Users\eirik\Desktop\meta1.fsx:line 38
   at FSI_0013.factorial(Int32 n) in C:\Users\eirik\Desktop\meta1.fsx:line 38
   at FSI_0013.factorial(Int32 n) in C:\Users\eirik\Desktop\meta1.fsx:line 38
   at FSI_0013.factorial(Int32 n) in C:\Users\eirik\Desktop\meta1.fsx:line 38
   at <StartupCode$FSI_0014>.$FSI_0014.main@() in C:\Users\eirik\Desktop\meta1.fsx:line 42
Stopped due to error

At first glance, this may seem like an insignificant shortcoming. In reality though, it can be the source to a lot of confusion. Asynchronous code tends interface with system APIs that are often sources of exceptions. In many real-world applications it is impossible to determine the source of an exception simply by looking at the generated stacktrace.

We need to improve on this; the goal of this post is to identify workarounds using the current state of F# and to propose potential additions for future releases of the language.

Defining a Continuation Monad

For the purposes of this exercise, we will need to define a continuation monad on which to build our improvements on.

/// Continuation workflow that accepts a pair of
/// success and exception continuations
type Cont<'T> = ('T -> unit) -> (exn -> unit) -> unit

/// return, the monadic unit
let ret (t : 'T) : Cont<'T> = fun sc _ -> sc t

/// monadic bind combinator
let (>>=) (f : Cont<'T>) (g : 'T -> Cont<'S>) : Cont<'S> =
    fun sc ec ->
        let sc' (t : 'T) =
            match (try Choice1Of2 (g t) with e -> Choice2Of2 e) with
            | Choice1Of2 g -> g sc ec
            | Choice2Of2 e -> ec e

        f sc' ec

Let’s now define our continuation builder:

type ContBuilder() =
    member __.Zero() = ret ()
    member __.Return t = ret t
    member __.Bind(f, g) = f >>= g
    member __.Delay(f : unit -> Cont<'T>) : Cont<'T> = ret () >>= f

let cont = new ContBuilder()

and a run function for executing our continuation workflows:

let run (cont : Cont<'T>) : 'T =
    let result = ref Unchecked.defaultof<'T>
    cont (fun t -> result := t) raise
    !result

This is a toy implementation that closely mimics the implementation of F# Async. As can be expected, we can observe the same stacktrace issue as in async.

Using Symbolic Stacktraces

Before we can move on, we need to give the definition of SymbolicException. This provides a way of appending symbolic entries to the stacktrace of an exception, which can then be re-raised as a regular .NET exception. This borrows from a technique also used here.

type SymbolicException =
    {
        Source : Exception
        Stacktrace : string list
    }

[<CompilationRepresentation(CompilationRepresentationFlags.ModuleSuffix)>]
module SymbolicException =

    open System.Reflection

    /// clones an exception to avoid mutation issues related to the stacktrace
    let private clone (e : #exn) =
        let bf = new System.Runtime.Serialization.Formatters.Binary.BinaryFormatter()
        use m = new System.IO.MemoryStream()
        bf.Serialize(m, e)
        m.Position <- 0L
        bf.Deserialize m :?> exn

    let private remoteStackTraceField =
        let getField name = typeof<System.Exception>.GetField(name, BindingFlags.Instance ||| BindingFlags.NonPublic)
        match getField "remote_stack_trace" with
        | null -> getField "_remoteStackTraceString"
        | f -> f

    /// appens a line to the symbolic stacktrace
    let append (line : string) (se : SymbolicException) =
        { se with Stacktrace = line :: se.Stacktrace }

    /// Raises exception with its appended symboic stacktrace
    let raise (se : SymbolicException) =
        let e' = clone se.Source
        let stacktrace =
            seq { yield e'.StackTrace ; yield! List.rev se.Stacktrace }
            |> String.concat Environment.NewLine

        remoteStackTraceField.SetValue(e', stacktrace + Environment.NewLine)
        raise e'

    /// Captures an exception into a SymbolicException instance
    let capture (e : exn) = { Source = clone e ; Stacktrace = [] }

Symbolic Stacktraces & Computation Expressions

Now that we have established a technique for creating symbolic stacktraces, let’s see how we can make use of this in the context of computation expressions.

First, let’s examine the structure of a typical entry in a .NET stacktrace. Assuming our previous factorial example,

let rec factorial n =
    if n = 0 then failwith "bug!"
    else
        n * factorial(n - 1)

The stacktrace entry corresponding to the recursive call appears like so:

at FSI_0013.factorial(Int32 n) in C:\Users\eirik\Desktop\meta1.fsx:line 38

This evidently contains two pieces of information:

  1. the method signature that was invoked.
  2. Source code location of the call site. This assumes presence of a corresponding symbols file.

Let’s see how we could recover similar data using expression builders. First off, recovering the invoked method name. Consider the following modification to the continuation builder:

type ContBuilder() =
    ...
    member __.Delay(f : unit -> Cont<'T>) : Cont<'T> =
        printfn "%O" (f.GetType())
        ret () >>= f

which once executed on factorial yields the output FSI_0026+factorial@124-11. This (somewhat) recovers the method signature of the factorial method.

In similar fashion, we can recover information on the call site by recovering the type name of the continuation parameter in Bind:

type ContBuilder() =
    ...
    member __.Bind(f : Cont<'T>, g : 'T -> Cont<'S>) : Cont<'S> =
        printfn "%O" (g.GetType())
        f >>= g

This yields FSI_0058+factorial@129-30, which (somewhat) recovers the location of the call site (containing method and line number).

Updating the Continuation Builder

Let’s now use this information to define our updated continuation builder. First, we need to update our continuation workflow type:

type Cont<'T> =
    {
        Definition : Type option
        Body : ('T -> unit) -> (SymbolicException -> unit) -> unit
    }

It has now been changed to thread symbolic exceptions in its exception continuation and to carry the defining type for the instance, if applicable. Let’s now continue with the builder definition:

type ContBuilder() =
    let protect f x = try Choice1Of2 (f x) with e -> Choice2Of2 e
    let mkCont def bd = { Body = bd ; Definition = def }

    member __.Return(t : 'T) = mkCont None (fun sc _ -> sc t)
    member __.Zero() = __.Return()
    member __.Delay(f : unit -> Cont<'T>) : Cont<'T> =
        let def = f.GetType()
        mkCont (Some def) (fun sc ec ->
            let sc' t =
                match protect f () with
                | Choice1Of2 g -> g.Body sc ec
                | Choice2Of2 e -> ec (SymbolicException.capture e)

            __.Zero().Body sc' ec)

The definition of Delay has been changed so that instances it defines are branded with a definition type. Continuing, let’s see now how we can make use of this metadata in the implementation of Bind:

type ContBuilder() =
    ...
    member __.Bind(f : Cont<'T>, g : 'T -> Cont<'S>) : Cont<'S> =
        mkCont None (fun sc ec ->
            let sc' (t : 'T) =
                match protect g t with
                | Choice1Of2 g -> g.Body sc ec
                | Choice2Of2 e -> ec (SymbolicException.capture e)

            let ec' (se : SymbolicException) =
                match f.Definition with
                | None -> ec se
                | Some def ->
                    let callSite = g.GetType()
                    let stackMsg = sprintf "   at %O in %O" def callSite
                    ec (SymbolicException.append stackMsg se)

            f.Body sc' ec')

In this updated definition of Bind, we attach an entry to the symbolic stacktrace of the exception continuation whenever binding to a “method”, that is an expression defined using Delay.

Finally, we give the updated definition of run:

let run (cont : Cont<'T>) =
    let result = ref Unchecked.defaultof<'T>
    let sc (t : 'T) = result := t
    let ec se =
        match cont.Definition with
        | None -> SymbolicException.raise se
        | Some def ->
            let stackMsg = sprintf "   at %O in Cont.run" def
            se |> SymbolicException.append stackMsg |> SymbolicException.raise

    cont.Body sc ec
    !result

Let’s now verify that the implementation works by re-running factorial:

System.Exception: bug!
   at FSI_0058.factorial@126-29.Invoke(Unit unitVar) in C:\Users\eirik\Desktop\meta2.fsx:line 126
   at FSI_0047.ContBuilder.protect[b,c](FSharpFunc`2 f, b x) in C:\Users\eirik\Desktop\meta2.fsx:line 54
   at FSI_0058+factorial@126-29 in FSI_0058+factorial@129-30
   at FSI_0058+factorial@126-29 in FSI_0058+factorial@129-30
   at FSI_0058+factorial@126-29 in FSI_0058+factorial@129-30
   at FSI_0058+factorial@126-29 in FSI_0058+factorial@129-30
   at FSI_0058+factorial@126-29 in FSI_0058+factorial@129-30
   at FSI_0078+factorial@132-31 in Cont.run
   at FSI_0022.SymbolicExceptionModule.raise[a](SymbolicException se) in C:\Users\eirik\Desktop\meta2.fsx:line 40
   at FSI_0060.run[T](Cont`1 cont) in C:\Users\eirik\Desktop\meta2.fsx:line 101
   at <StartupCode$FSI_0061>.$FSI_0061.main@() in C:\Users\eirik\Desktop\meta2.fsx:line 124

It is left as an exercise to the reader to improve formatting of symbolic stack entries by performing further parsing of the internal type names.

Implementing ReturnFrom

Let’s now have a go at implementing ReturnFrom, the tail call keyword. By virtue of the its type signature, the call site location cannot be recovered in this context:

type ContBuilder() =
    ...
    member __.ReturnFrom (f : Cont<'T>) =
        match f.Definition with
        | None -> f
        | Some df ->
            { f with Body = fun sc ec ->
                    let ec' (se : SymbolicException) =
                        let stackMsg = sprintf "   at %O" df
                        ec (SymbolicException.append stackMsg se)

                    f.Body sc ec' }

Again, we verify by running

let rec odd (n : int) = 
    cont {
        if n = 0 then return false
        else
            return! even (n - 1)
    }

and even (n : int) =
    cont {
        if n = 0 then return failwith "bug!"
        else
            return! odd (n - 1)
    }

odd 5 |> Cont.run

which yields

System.Exception: bug!
   at FSI_0011.even@149-3.Invoke(Unit unitVar) in C:\Users\eirik\Desktop\meta2.fsx:line 149
   at FSI_0002.ContBuilder.protect[a,b](FSharpFunc`2 f, a x) in C:\Users\eirik\Desktop\meta2.fsx:line 54
   at FSI_0011+even@149-3
   at FSI_0011+odd@142-3
   at FSI_0011+even@149-3
   at FSI_0011+odd@142-3
   at FSI_0011+even@149-3
   at FSI_0011+odd@142-3 in Cont.run
   at FSI_0002.SymbolicExceptionModule.raise[a](SymbolicException se) in C:\Users\eirik\Desktop\meta2.fsx:line 40
   at FSI_0002.Cont.run[T](Cont`1 cont) in C:\Users\eirik\Desktop\meta2.fsx:line 111
   at <StartupCode$FSI_0011>.$FSI_0011.main@()
Stopped due to error

Drawbacks

The above approach has few clear drawbacks

  1. Information relayed to symbolic stacktraces are of low quality, compared to .NET stacktraces. Ideally we would like to recover the MethodInfo that corresponds to the call, but that does not appear to be possible.
  2. The implementation makes light use of reflection at places. This may affect performance unless care is taken, and could hurt compatibility with certain platforms.
  3. Impossible to distinguish between actual method calls and inlined expressions. This can result in noisy stacktraces at places.

Future Directions

The issues discussed above beg the question: what could be added to the F# language itself to improve support for stacktraces? It’s evident that the required information is known by the compiler. So here’s a proposal:

First, let’s outline a type that encodes an entry from a stacktrace:

type Location = { File : string ; Line : int ; Column : int }
type MethodInvocationInfo = { Method : MethodInfo ; Location : Location }

Now, consider the following hypothetical computation expression implementation.

type Cont<'T> = ('T -> unit) -> (SymbolicException -> unit) -> unit

type ContBuilder() =
    let protect f x = try Choice1Of2 (f x) with e -> Choice2Of2 e
    let fmt (m : MethodInvocationInfo) = sprintf "   at %O in %s:line %d" m.MethodInfo m.Location.File m.Location.Line 
    member __.Bind(data : MethodInvocationInfo, f : Cont<'T>, g : 'T -> Cont<'S>) : Cont<'S> =
        fun sc ec ->
            let sc' (t : 'T) =
                match protect g t with
                | Choice1Of2 g -> g sc ec
                | Choice2Of2 e -> ec (SymbolicException.Capture e)

            let ec' (e : SymbolicException) = ec (e.Append (fmt data))

            f sc' ec'

    member __.ReturnFrom(data : MethodInvocationInfo, f : Cont<'T>) =
        fun sc ec ->
            let ec' (e : SymbolicException) = ec (e.Append (fmt data))
            f sc ec'

Under the proposed change, it should be possible to define overloads for Bind, Return, ReturnFrom and Yield that accept an additional method invocation metadata parameter. These would be used by the compiler only in cases where corresponding keywords involved a method invocation on the right-hand side. In other words, the line

let! x = async { return 1 }

would desugar to a call to the standard Bind overload, whereas

let f i = async { return i }
let! x = f 1

would translate to the new overload, passing metadata on the invocation of function f at compile time.

Conclusions

The ability to generate exception stacktraces in computation expressions is a feature sorely missed in F# computation expressions. Adopting improvements towards this direction would greatly improve the debugging experience of asynchronous workflows and other computation expressions, including mbrace. It would be great to see such improvements added to the next release of F#.

Advertisements
Reconciling Stacktraces with Computation Expressions

One thought on “Reconciling Stacktraces with Computation Expressions

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s