Explicit Stack Traces

ghc.exe: panic! (the 'impossible' happened)
  (GHC version 6.11.20081202 for i386-unknown-mingw32):
        idInfo

Argh!  When working on GHC, or in any Haskell in general, it is occasionally useful to know something about what was going on when a program crashed.  Currently we have several ways of doing this; for example the ghci-debugger or using the cost-center-stacks that are part of the profiling tools in GHC.  For my internship here at MSR, I’ve been looking at putting another tool in the GHC-users toolbelt, that of selective explicit-call-stack (ecs) traces (in a theme of things described on this wiki page); and today I’ve had a breakthrough in terms of using the tool I’ve been working on to actually help debug a real issue I was having in GHC! So, our panic above was coming from this bit of source:

varIdInfo :: Var -> IdInfo
varIdInfo (GlobalId {idInfo_ = info}) = info
varIdInfo (LocalId {idInfo_ = info}) = info
varIdInfo other_var = pprPanic "idInfo" (ppr other_var)

What the ecs-extension I’m working on does is allow you to add an annotation (an awesome new feature from that’s been recently folded into GHC Head) onto this function to say that I want to debug this function.

import GHC.ExplicitCallStack.Annotations
{-# ANN varIdInfo Debug #-}

And because there’s a few things that need neatening up in the implementation, the pprPanic needs rewriting slightly:

varIdInfo :: Var -> IdInfo
varIdInfo (GlobalId {idInfo_ = info}) = info
varIdInfo (LocalId {idInfo_ = info}) = info
varIdInfo other_var = throwStack (\s -> pprPanic ("idInfo\n" ++ show s) (ppr other_var) :: SomeException)

Recompiling this source (for the curious, recompiling meant building a stage3 ghc), passing in a -fexplicit-call-stack argument to GHC will essentially create a version of this function that tells all callers of this function to pass in their source locations, and will make the pprPanic print out this location.

What this really means is that the original panic becomes slightly more helpful:

ghc.exe: panic! (the 'impossible' happened)
  (GHC version 6.11.20081202 for i386-unknown-mingw32):
        idInfo
in varIdInfo, basicTypes/Var.lhs:238,30

I’ve been told that just having one level of stack information is enough to help debug many problems; in this case it wasn’t quite, but we can just go an add a Debug annotation to varIdInfo to get more stack information.  If a function that has a Debug annotation calls a function with a Debug annotation, the stack is grown an extra level.  So, lather-rinse-repeat enough times, and it’s possible to get quite a lot of information.

ghc.exe: panic! (the 'impossible' happened)
  (GHC version 6.11.20081202 for i386-unknown-mingw32):
        idInfo
in varIdInfo, basicTypes/Var.lhs:238,30
in idInfo, basicTypes/Id.lhs:168,10
in idInlinePragma, basicTypes/Id.lhs:633,37
in preInlineUnconditionally, simplCore/SimplUtils.lhs:619,12
in simplNonRecE, simplCore/Simplify.lhs:964,5
in simplLam, simplCore/Simplify.lhs:925,13
in simplExprF', simplCore/Simplify.lhs:754,5
in simplExprF, simplCore/Simplify.lhs:741,5
in completeCall, simplCore/Simplify.lhs:1120,24
in simplVar, simplCore/Simplify.lhs:1032,29
in simplExprF', simplCore/Simplify.lhs:746,39
...
in simplExprF', simplCore/Simplify.lhs:750,39
...
in simplLazyBind, simplCore/Simplify.lhs:339,33
in simplRecOrTopPair, simplCore/Simplify.lhs:295,5
in simplTopBinds, simplCore/Simplify.lhs:237,35
in simplifyPgmIO, simplCore/SimplCore.lhs:629,5
in simplifyPgm, simplCore/SimplCore.lhs:562,22
in doCorePass, simplCore/SimplCore.lhs:156,40

But what, I hear you cry, are those “…”‘s?  Well since Haskell uses recursion to implement iteration, it would be a very bad thing if we tried to keep a stack that included all sites recursively entered.  Instead, we have a rule that any call site may appear in the stack only once, and if it would appear multiple times, only the newest one is kept, with any others being replaced by “…”s.  Here we can see that simplExprF’ recursively called itself a few times.

Anyways, there are several issues to solve before this is completely usable for prime time, so I can’t promise when it’ll be available; but just thought I’d share what I’m working on;

Tristan (ToRA|MSR)

About these ads
This entry was posted in Uncategorized. Bookmark the permalink.

3 Responses to Explicit Stack Traces

  1. tora8msr says:

    Oops, due to a copy-paste error the first improved panic looked less helpful than it really is:

    ghc.exe: panic! (the ‘impossible’ happened)
    (GHC version 6.11.20081202 for i386-unknown-mingw32):
    idInfo
    in varIdInfo, basicTypes/Var.lhs:238,30
    in idInfo, basicTypes/Id.lhs:168,10

    i.e. the stack contains both the location of the panic, and the caller of varIdInfo. We can then go and Debug idInfo, and then lather-rinse-repeat…

  2. timchevalier says:

    Very cool!

  3. saizan says:

    can we also have something like -auto-all for these Debug annotations?

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