Better Haskell stack traces via user annotations

Getting an accurate and precise backtrace is the key to debugging unexpected exceptions in Haskell programs. We recently implemented a family of functions that enable the user to push user-defined annotations to the native Haskell stack. The native stack decoder can display this information to the user when an unexpected exception is thrown.

This facility offers a number of advantages over the existing backtrace collection mechanisms:

• It is not necessary modify the function API (unlike HasCallStack)
• A “continuous chain” of modifications is not necessary (unlike HasCallStack)
• The annotations work in all ways of compilation (unlike cost centre stacks)
• The backtrace is expressed in terms of predictable source locations (unlike some IPE backtraces)

In this post we wil introduce the API for stack annotation, give some examples of how to use the annotation functions and discuss some trade-offs we have noticed with the design.

We’re interested in feedback from users on this feature. We’re expecting it to be available from GHC 9.16, as our implementation already landed in GHC HEAD (!14538).

Annotation stack frames

The core of the design is a new primop, annotateStack#, which when executed pushes an “annotation stack-frame” to the stack. Semantically, the frame is a no-op, but the payload contains a pointer to an arbitrary user-defined annotation. When decoding the native Haskell stack the annotation can be rendered to provide the user with additional context about the current location of the program.

The primop annotateStack# is exposed to the user via an IO-based API in GHC.Stack.Annotation.Experimental from the ghc-experimental package:¹

annotateStackIO :: (Typeable a, StackAnnotation a) => a -> IO b -> IO b

This will push the annotation value a onto the stack for the duration of the IO b action. The constraints allow the value to be rendered to a string or have its type inspected, similarly to the Exception class.

There are also specialised variants:

annotateCallStackIO   :: HasCallStack => IO b -> IO b  -- Annotate with the current source location
annotateStackStringIO :: String       -> IO b -> IO b  -- Annotate with an arbitrary String 
annotateStackShowIO   :: Show a => a  -> IO b -> IO b  -- Annotate with the result of 'show' on a value

In addition, there are “pure” variants for use in non-IO code. However, these tend to be less intuitive due to the combination of lazy evaluation and imprecise exceptions, so the IO versions will generally produce better stack traces more reliably.

Example of the status quo

Let’s use the annotation functions to improve the backtrace for a program reported in a GHC ticket (#26040). The program implements a simple REST API using servant. When the endpoint is requested with a parameter which is larger than or equal to 100, the endpoint will error. topHandler catches all exceptions thrown by the handler and turns them into an HTTP 505 error. Finally, the exception handler prints any exceptions that might be thrown by the endpoint.

main :: IO ()
main = do
  setBacktraceMechanismState IPEBacktrace True
  run 8086 mkServer

type Api = Capture "x" Int :> Get '[PlainText] Text

mkServer :: Application
mkServer =
  serve
    (Proxy @Api)
    (hoistServer (Proxy @Api) topHandler api)

topHandler :: IO a -> Handler a
topHandler action = do
  result <- liftIO $
    (Right <$> action) `catch` \(exc :: SomeException) -> do
      liftIO $ putStrLn $ "Exception: " <> displayExceptionWithInfo exc
      pure $ Left err500

  either throwError pure result

api :: ServerT Api IO
api = handler

handler :: Int -> IO Text
handler x =
  if x >= 100
    then throw $ ErrorCall "Oh no!"
    else pure (pack "handler")

With the current version of GHC, when calling this API via http://localhost:8086/105, this stack trace is printed:

Exception: ghc-internal:GHC.Internal.Exception.ErrorCall:

Oh no!

IPE backtrace:
  Main.liftIO (src/Servant/Server/Internal/Handler.hs:30:36-42)
  Servant.Server.Internal.Delayed.runHandler' (src/Servant/Server/Internal/Handler.hs:27:31-41)
  Control.Monad.Trans.Resource.runResourceT (./Control/Monad/Trans/Resource.hs:(192,14)-(197,18))
  Network.Wai.Handler.Warp.HTTP1.processRequest (./Network/Wai/Handler/Warp/HTTP1.hs:195:20-22)
  Network.Wai.Handler.Warp.HTTP1.processRequest (./Network/Wai/Handler/Warp/HTTP1.hs:(195,5)-(203,31))
  Network.Wai.Handler.Warp.HTTP1.http1server.loop (./Network/Wai/Handler/Warp/HTTP1.hs:(141,9)-(157,42))
HasCallStack backtrace:
  collectExceptionAnnotation, called at libraries/ghc-internal/src/GHC/Internal/Exception.hs:170:37 in ghc-internal:GHC.Internal.Exception
  toExceptionWithBacktrace, called at libraries/ghc-internal/src/GHC/Internal/Exception.hs:90:42 in ghc-internal:GHC.Internal.Exception
  throw, called at app/Main.hs:42:10 in backtrace-0.1.0.0-inplace-server:Main

In this example there are two different backtraces:

• The “IPE backtrace” is constructed by decoding the Haskell stack, using information stored in the binary by -finfo-table-map, where each frame is automatically associated with a source location. (The compiler option -finfo-table-map was originally introduced for profiling.)
• On the the other hand, the “HasCallStack backtrace” is built using the implicitly passed HasCallStack constraints, which are automatically supplied by the type-checker, provided HasCallStack appears in the type.

The HasCallStack backtrace seems the most useful, telling us exactly where our program went wrong. However, the backtrace is very brief, as the rest of the program doesn’t have any HasCallStack constraints. As such, this stack trace might be unhelpful in larger programs, if the call to error was placed behind many layers of abstraction.

The IPE backtrace looks impressive, but doesn’t even show us where the exception is thrown! We get more intermediate source locations, but not the source of the exception. The function from which the exception is thrown is not even listed.

The reason the IPE backtrace may be unhelpful lies in the way the Haskell call stack works. We show the IPE info for each stack frame, which doesn’t relate precisely to the original source code and the resulting stack trace feels unintuitive. One reason for this is many function calls are tail-calls which don’t result in stack frames.

For more of an overview of the different backtrace mechanisms consult the discussion section of GHC Proposal #330.

Better stack traces with annotateCallStackIO

The IPE backtrace can be improved by manually annotating important parts of the program which should always appear in a backtrace.

For example, we always want to know in which handler the exception was thrown in, so the handler function is annotated with annotateCallStackIO. Further, we annotate the location where the exception is thrown.

handler :: Int -> IO Text
handler x = annotateCallStackIO $ do
  if x >= 100
    then annotateCallStackIO $ throw $ ErrorCall "Oh no!"
    else pure (pack "handleIndex")

When running this program again, the stack trace will now contain the source location of the handler where exception was thrown from:

Exception: ghc-internal:GHC.Internal.Exception.ErrorCall:

Oh no!

IPE backtrace:
  annotateCallStackIO, called at app/Main.hs:42:10 in backtrace-0.1.0.0-inplace-server:Main
  annotateCallStackIO, called at app/Main.hs:40:13 in backtrace-0.1.0.0-inplace-server:Main
  Main.handler (app/Main.hs:(40,1)-(43,30))
  Main.liftIO (src/Servant/Server/Internal/Handler.hs:30:36-42)
  Servant.Server.Internal.Delayed.runHandler' (src/Servant/Server/Internal/Handler.hs:27:31-41)
  Control.Monad.Trans.Resource.runResourceT (./Control/Monad/Trans/Resource.hs:(192,14)-(197,18))
  Network.Wai.Handler.Warp.HTTP1.processRequest (./Network/Wai/Handler/Warp/HTTP1.hs:195:20-22)
  Network.Wai.Handler.Warp.HTTP1.processRequest (./Network/Wai/Handler/Warp/HTTP1.hs:(195,5)-(203,31))
  Network.Wai.Handler.Warp.HTTP1.http1server.loop (./Network/Wai/Handler/Warp/HTTP1.hs:(141,9)-(157,42))
HasCallStack backtrace:
  collectExceptionAnnotation, called at libraries/ghc-internal/src/GHC/Internal/Exception.hs:170:37 in ghc-internal:GHC.Internal.Exception
  toExceptionWithBacktrace, called at libraries/ghc-internal/src/GHC/Internal/Exception.hs:90:42 in ghc-internal:GHC.Internal.Exception
  throw, called at app/Main.hs:42:32 in backtrace-0.1.0.0-inplace-server:Main

Note the first two entries of the IPE backtrace:

annotateCallStackIO, called at app/Main.hs:42:10 in backtrace-0.1.0.0-inplace-server:Main
annotateCallStackIO, called at app/Main.hs:40:13 in backtrace-0.1.0.0-inplace-server:Main

These have been added due to our manual annotation of our source program via annotateCallStackIO!

They give us precise source location where the exception is thrown, making the IPE backtrace just as useful as the HasCallStack backtrace. However, note, we did not have to change the type signature of handler at all to get a much more informative stack trace.

throwIO vs throw vs error

Some readers may have noticed that we used throw instead of error, which is usually the go to function for throwing example errors (or from within pure code). At the moment, throw and error produce noticeably different stack traces, because error evaluates the exception annotations lazier than throw, which leads to failing to capture the call stack when throwing the exception. This should be possible to resolve; see GHC issue #25430.

On the other hand, throwIO behaves more predictably within IO code and the IPE backtrace includes the source location of the exception throwing:

IPE backtrace:
  Main.handler (app/Main.hs:42:10-45)
  Main.liftIO (src/Servant/Server/Internal/Handler.hs:30:36-42)
  Servant.Server.Internal.Delayed.runHandler' (src/Servant/Server/Internal/Handler.hs:27:31-41)
  Control.Monad.Trans.Resource.runResourceT (./Control/Monad/Trans/Resource.hs:(192,14)-(197,18))
  Network.Wai.Handler.Warp.HTTP1.processRequest (./Network/Wai/Handler/Warp/HTTP1.hs:195:20-22)
  Network.Wai.Handler.Warp.HTTP1.processRequest (./Network/Wai/Handler/Warp/HTTP1.hs:(195,5)-(203,31))
  Network.Wai.Handler.Warp.HTTP1.http1server.loop (./Network/Wai/Handler/Warp/HTTP1.hs:(141,9)-(157,42))

This means that how the exception is thrown is important to get reasonable stack traces. Unsurprisingly, you should use throwIO whenever you are within the IO monad.

Summary

Annotation stack frames are a lightweight way to add extra information to stack traces. By modifying the execution stack, the information is always available and can be used by the native stack decoder to display informative backtraces to users. We’re interested to hear what users think about this feature and how libraries will be adapted to take advantage of the new annotation frames.

This work has been performed in collaboration with Mercury, who have a long-term commitment to the scalability and robustness of the Haskell ecosystem. Well-Typed are always interested in projects and looking for funding to improve GHC and other Haskell tools. Please contact info@well-typed.com if we might be able to work with you!