get stack trace on tryCatch'ed error in R

Question

This is related to some other questions, but I can't seem to figure out how to apply the answer, so I'm asking a new question.

I'm trying to figure out an uninformative error from a piece of code that looks like this:

tryCatch(MainLoop(), 
  error=function(e) { fatal(lgr, paste('caught fatal error:', as.character(e))); 
                      exit.status <<- 1 })

The problem is that the error appears to be related to something buried in a library function:

Error in nrow(x): (subscript) logical subscript too long

That nrow is not in my code, as the C-level error above only applies to a type of indexing that never happens in any of my nrow calls.

So I'd really like to get a stack trace from within that tryCatch. Here's an analogous problem:

x <- function() { y(); }
y <- function() { z(); }
z <- function() { stop("asdf") }

> x()
Error in z() : asdf
> tryCatch(x(), error=function(e) { print(conditionCall(e)) } )
z()
> tryCatch(x(), error=function(e) { dump.frames() } )
> last.dump
$`tryCatch(x(), error = function(e) {
    dump.frames()
})`
<environment: 0x1038e43b8>

$`tryCatchList(expr, classes, parentenv, handlers)`
<environment: 0x1038e4c60>

$`tryCatchOne(expr, names, parentenv, handlers[[1]])`
<environment: 0x1038e4918>

$`value[[3]](cond)`
<environment: 0x1038ea578>

attr(,"error.message")
[1] "asdf"
attr(,"class")
[1] "dump.frames"

How do I get the stack trace that includes the call to y()? Do I have to stop using tryCatch? What's a better way?

Sultry

So what debugging have you tried so far after the error? traceback() options(error=recover)? Does the latter not drop you into the stack? It should do so even in libraries until it hits C code at least. If you're hitting C code, then you may have to use GDB with R – Soelch

This is for code running in production, where I get an error I've yet to reproduce in development, so dropping into recover mode isn't an option, unfortunately... I'm hoping that better instrumentation will point me more closely at the error. Thanks! – Sultry

Answer 1

For interactive use one might trace(stop, quote(print(sys.calls()))) to print the call stack at the time stop() is invoked.

From ?tryCatch,

 The function 'tryCatch' evaluates its expression argument in a
 context where the handlers provided in the '...'  argument are
 available.

whereas

 Calling handlers are established by 'withCallingHandlers'...
 the handler is called... in the context where the condition
 was signaled...

so

>     withCallingHandlers(x(), error=function(e) print(sys.calls()))
[[1]]
withCallingHandlers(x(), error = function(e) print(sys.calls()))

[[2]]
x()

[[3]]
y()

[[4]]
z()

[[5]]
stop("asdf")

[[6]]
.handleSimpleError(function (e) 
print(sys.calls()), "asdf", quote(z()))

[[7]]
h(simpleError(msg, call))

Error in z() : asdf

This is thwarted if there is an inner tryCatch

withCallingHandlers({
    tryCatch(x(), error=function(e) stop("oops"))
}, error=function(e) print(sys.calls()))

as we only have access to the call stack after the tryCatch has 'handled' the error.

Abott

This makes sense and seems to work -- thank you! I've replaced tryCatch with withCallingHandlers, and put the following handy expression in the error handler block: dump.frames(format(Sys.time(), format="dump_%Y%m%d%H%M%S"), to.file=TRUE). Hopefully I'll be able to figure out the bug now... – Sultry

Answer 2

Yes, it is possible. It is not too elegant in coding, but very helpful in output! Any comments are welcome!

I put it in my misc package, use it from there if you want the documentation. https://github.com/brry/berryFunctions/blob/master/R/tryStack.R The next CRAN version is planned to be released soon, until then:

devtools::install_github("brry/berryFunctions")
# or use:
source("http://raw.githubusercontent.com/brry/berryFunctions/master/R/instGit.R")
instGit("brry/berryFunctions")

library(berryFunctions)
?tryStack

Here it is for fast reference:

tryStack <- function(
expr,
silent=FALSE
)
{
tryenv <- new.env()
out <- try(withCallingHandlers(expr, error=function(e)
  {
  stack <- sys.calls()
  stack <- stack[-(2:7)]
  stack <- head(stack, -2)
  stack <- sapply(stack, deparse)
  if(!silent && isTRUE(getOption("show.error.messages"))) 
    cat("This is the error stack: ", stack, sep="\n")
  assign("stackmsg", value=paste(stack,collapse="\n"), envir=tryenv)
  }), silent=silent)
if(inherits(out, "try-error")) out[2] <- tryenv$stackmsg
out
}

lower <- function(a) a+10
upper <- function(b) {plot(b, main=b) ; lower(b) }

d <- tryStack(upper(4))
d <- tryStack(upper("4"))
cat(d[2])

d <- tryStack(upper("4"))

This is the error stack:

tryStack(upper("4"))

upper("4")

lower(b)

Error in a + 10 : non-numeric argument to binary operator

Ammonic

Answer 3

I am a fan of evaluate::try_capture_stack().

x <- function() {
  y()
}
y <- function() {
  z()
}
z <- function() {
  stop("asdf")
}
env <- environment()
e <- evaluate::try_capture_stack(quote(x()), env)
names(e)
#> [1] "message" "call"    "calls"
e$calls
#> [[1]]
#> x()
#> 
#> [[2]]
#> y()
#> 
#> [[3]]
#> z()
#> 
#> [[4]]
#> stop("asdf")

Airdrie

Answer 4

I'm a bit late to the party, but I found the best way was to use an exit handler in the function you are trying.

main <- function()
{
  on.exit({
    msg <- capture.output(traceback())
    if (msg != "No traceback available ")
    {
      print(msg)
    }
  }
  )
  # rest of code
}

withCallingHandlers(
  expr =
    {
      main()
    },
  error = function(e) 
  {
    print(e)
  }
)

Theda