在R中发生错误后打印堆栈跟踪并继续执行

27

我正在编写一些调用其他代码的R语言代码,如果出现错误,我希望打印出堆栈跟踪信息(以便追踪问题),然后继续执行。但是,traceback()函数只提供有关未捕获异常的信息。我可以通过使用tryCatch和dump.frames的相当复杂的构造来获得所需的结果,但是否没有更简单的方法呢?

8个回答

26

大约一周前,我写了这段代码来帮助我追踪主要来自非交互R会话的错误。它还有些粗糙,但它会打印出堆栈跟踪并继续运行。如果这对你有用,请告诉我,我很想知道你如何使其更加信息丰富。我也愿意采用更清晰的方式来获取这些信息。

options(warn = 2, keep.source = TRUE, error = quote({
  # Debugging in R
  #   http://www.stats.uwo.ca/faculty/murdoch/software/debuggingR/index.shtml
  #
  # Post-mortem debugging
  #   http://www.stats.uwo.ca/faculty/murdoch/software/debuggingR/pmd.shtml
  #
  # Relation functions:
  #   dump.frames
  #   recover
  # >>limitedLabels  (formatting of the dump with source/line numbers)
  #   sys.frame (and associated)
  #   traceback
  #   geterrmessage
  #
  # Output based on the debugger function definition.

  # TODO: setup option for dumping to a file (?)
  # Set `to.file` argument to write this to a file for post-mortem debugging    
  dump.frames()  # writes to last.dump
  n <- length(last.dump)
  if (n > 0) {
    calls <- names(last.dump)
    cat("Environment:\n", file = stderr())
    cat(paste0("  ", seq_len(n), ": ", calls), sep = "\n", file = stderr())
    cat("\n", file = stderr())
  }

  if (!interactive()) q()
}))

提示:您可能不希望使用warn=2(将警告转换为错误)


1
我喜欢这个。为了使其更具信息性,您可以对“last.dump”中的每个环境调用“ls.str()”。 (不过,这可能会使输出非常冗长。) - Richie Cotton
不完全是我想要的,但至少它解决了打印堆栈跟踪的问题。谢谢! - Alice Purcell
非常有启发性的回答,谢谢!但我发现一些函数参数没有保存。你知道该怎么办吗?当检查dump.frames()的转储时,在debugger()中一些函数参数不可用 - Tomas

13

我最终编写了一个通用记录器,当调用标准的R语言消息“message”、“warning”和“stop”方法时,它会生成类似Java的日志消息。它包括时间戳以及警告和以上级别的堆栈跟踪。

非常感谢Man Group允许分发这个记录器!同时也要感谢Bob Albright,他的答案帮助了我。

withJavaLogging = function(expr, silentSuccess=FALSE, stopIsFatal=TRUE) {
    hasFailed = FALSE
    messages = list()
    warnings = list()
    logger = function(obj) {
        # Change behaviour based on type of message
        level = sapply(class(obj), switch, debug="DEBUG", message="INFO", warning="WARN", caughtError = "ERROR",
                error=if (stopIsFatal) "FATAL" else "ERROR", "")
        level = c(level[level != ""], "ERROR")[1]
        simpleMessage = switch(level, DEBUG=,INFO=TRUE, FALSE)
        quashable = switch(level, DEBUG=,INFO=,WARN=TRUE, FALSE)

        # Format message
        time  = format(Sys.time(), "%Y-%m-%d %H:%M:%OS3")
        txt   = conditionMessage(obj)
        if (!simpleMessage) txt = paste(txt, "\n", sep="")
        msg = paste(time, level, txt, sep=" ")
        calls = sys.calls()
        calls = calls[1:length(calls)-1]
        trace = limitedLabels(c(calls, attr(obj, "calls")))
        if (!simpleMessage && length(trace) > 0) {
            trace = trace[length(trace):1]
            msg = paste(msg, "  ", paste("at", trace, collapse="\n  "), "\n", sep="")
        }

        # Output message
        if (silentSuccess && !hasFailed && quashable) {
            messages <<- append(messages, msg)
            if (level == "WARN") warnings <<- append(warnings, msg)
        } else {
            if (silentSuccess && !hasFailed) {
                cat(paste(messages, collapse=""))
                hasFailed <<- TRUE
            }
            cat(msg)
        }

        # Muffle any redundant output of the same message
        optionalRestart = function(r) { res = findRestart(r); if (!is.null(res)) invokeRestart(res) }
        optionalRestart("muffleMessage")
        optionalRestart("muffleWarning")
    }
    vexpr = withCallingHandlers(withVisible(expr),
            debug=logger, message=logger, warning=logger, caughtError=logger, error=logger)
    if (silentSuccess && !hasFailed) {
        cat(paste(warnings, collapse=""))
    }
    if (vexpr$visible) vexpr$value else invisible(vexpr$value)
}

使用它时,只需将其包装在您的代码周围:

withJavaLogging({
  // Your code here...
})

如果需要安静输出而没有错误(对于测试非常有用!),请设置 silentSuccess 标志。仅当发生错误时,消息才会被输出,以便为失败提供上下文。

要实现原始目标(转储堆栈跟踪并继续执行),只需使用 try:

try(withJavaLogging({
  // Your code here...
}, stopIsFatal=FALSE))

1
这让我想起了 Hadley 的 evaluate 包,虽然我很确定它没有做堆栈跟踪。我还没有在这里看到它被提到,但对于不需要您提供的整个机制的其他人来说,它肯定会证明有用。 - Aaron left Stack Overflow
干得好!顺便问一下:通过 limitedLabels(c(calls, attr(obj, "calls"))) 添加“calls”属性的意图是什么?当我检查 attributes(obj) 时,我只发现一个名为“call”(单数!)的属性... - R Yoda
@RYoda 奇怪,当我写的时候它对我起作用了。不过话说回来,R并不是地球上最一致的语言。 - Alice Purcell
chrispy:这是一个非常出色的解决方案。非常感谢! - HaroldFinch
@chrispy:(...被5分钟评论编辑规则烧伤,现在完成...)我使用你的代码时唯一的问题是,在我的堆栈跟踪开始处得到了一些非常丑陋的输出。特别是,第一行是at .handleSimpleError(function (obj),后面跟着你的记录器内部函数的前几行。我不想看到那个,所以我发现我可以通过将trace = trace[length(trace):1]更改为trace = trace[(length(trace) - 1):1]来抑制它。我将跟进一个新答案,这是一个完整的版本。 - HaroldFinch

11

如果你对触发选项(error...)的某些内容感兴趣,你也可以这样做:

options(error=traceback)

从我所看到的,它实现了Bob提出的大部分解决方案所具备的功能,但有一个优点,就是代码要短得多。

(如有需要,可以随意与keep.source=TRUE、warn=2等结合使用。)


2
不幸的是,我需要在之后继续运行,即在try()块中运行,这样它就不会触发option(error=...)。 - Alice Purcell
同时它并不总是有效。当这里给出“无回溯可用”时,Bob的解决方案却能给我提供一个。 - flying sheep

7
你尝试过吗?
 options(error=recover)

调试? Chambers的“数据分析软件”提供了一些有用的提示。


我不想要交互式提示,我希望程序打印出堆栈跟踪并继续执行。 - Alice Purcell
你是只使用 R 代码还是也使用其他编程语言与 R 集成工作? - Dirk Eddelbuettel

2
这是对Alice上面答案的跟进,她提出了一个withJavaLogging函数。我评论说她的解决方案很有启发性,但对我而言,堆栈跟踪开始处的一些输出会影响阅读体验。
举个例子,考虑以下代码:
f1 = function() {
        # line #2 of the function definition; add this line to confirm that the stack trace line number for this function is line #3 below
        catA("f2 = ", f2(), "\n", sep = "")
    }
    
    f2 = function() {
        # line #2 of the function definition; add this line to confirm that the stack trace line number for this function is line #4 below
        # line #3 of the function definition; add this line to confirm that the stack trace line number for this function is line #4 below
        stop("f2 always causes an error for testing purposes")
    }

如果我执行withJavaLogging( f1() )这一行,我将得到以下输出。
2017-02-17 17:58:29.556 FATAL f2 always causes an error for testing purposes
      at .handleSimpleError(function (obj) 
    {
        level = sapply(class(obj), switch, debug = "DEBUG", message = "INFO", warning = "WARN", caughtError = "ERROR", error = if (stopIsFatal) 
            "FATAL"
        else "ERROR", "")
        level = c(level[level != ""], "ERROR")[1]
        simpleMessage = switch(level, DEBUG = , INFO = TRUE
      at #4: stop("f2 always causes an error for testing purposes")
      at f2()
      at catA.R#8: cat(...)
      at #3: catA("f2 = ", f2(), "\n", sep = "")
      at f1()
      at withVisible(expr)
      at #43: withCallingHandlers(withVisible(expr), debug = logger, message = logger, warning = logger, caughtError = logger, error = logger)
      at withJavaLogging(f1())
    Error in f2() : f2 always causes an error for testing purposes

我不想看到源代码中的logger函数在withJavaLogging函数内定义时,紧随其后跟随at .handleSimpleError(function (obj)的行。我之前曾评论过,可以通过将trace = trace[length(trace):1]更改为trace = trace[(length(trace) - 1):1]来消除这种不必要的输出。
为了方便其他人阅读,以下是我现在使用的完整函数版本(从withJavaLogging重命名为logFully,并稍微重新格式化以适应我的可读性喜好):
logFully = function(expr, silentSuccess = FALSE, stopIsFatal = TRUE) {
    hasFailed = FALSE
    messages = list()
    warnings = list()
    
    logger = function(obj) {
        # Change behaviour based on type of message
        level = sapply(
            class(obj),
            switch,
            debug = "DEBUG",
            message = "INFO",
            warning = "WARN",
            caughtError = "ERROR",
            error = if (stopIsFatal) "FATAL" else "ERROR",
            ""
        )
        level = c(level[level != ""], "ERROR")[1]
        simpleMessage = switch(level, DEBUG = TRUE, INFO = TRUE, FALSE)
        quashable = switch(level, DEBUG = TRUE, INFO = TRUE, WARN = TRUE, FALSE)
        
        # Format message
        time = format(Sys.time(), "%Y-%m-%d %H:%M:%OS3")
        txt = conditionMessage(obj)
        if (!simpleMessage) txt = paste(txt, "\n", sep = "")
        msg = paste(time, level, txt, sep = " ")
        calls = sys.calls()
        calls = calls[1:length(calls) - 1]
        trace = limitedLabels(c(calls, attr(obj, "calls")))
        if (!simpleMessage && length(trace) > 0) {
            trace = trace[(length(trace) - 1):1]
            msg = paste(msg, "  ", paste("at", trace, collapse = "\n  "), "\n", sep = "")
        }
        
        # Output message
        if (silentSuccess && !hasFailed && quashable) {
            messages <<- append(messages, msg)
            if (level == "WARN") warnings <<- append(warnings, msg)
        } else {
            if (silentSuccess && !hasFailed) {
                cat(paste(messages, collapse = ""))
                hasFailed <<- TRUE
            }
            cat(msg)
        }
        
        # Muffle any redundant output of the same message
        optionalRestart = function(r) { res = findRestart(r); if (!is.null(res)) invokeRestart(res) }
        optionalRestart("muffleMessage")
        optionalRestart("muffleWarning")
    }
    
    vexpr = withCallingHandlers( withVisible(expr), debug = logger, message = logger, warning = logger, caughtError = logger, error = logger )
    
    if (silentSuccess && !hasFailed) {
        cat(paste(warnings, collapse = ""))
    }
    
    if (vexpr$visible) vexpr$value else invisible(vexpr$value)
}

如果我执行logFully(f1())这一行,我会得到所需的输出,即:
2017-02-17 18:05:05.778 FATAL f2 always causes an error for testing purposes
  at #4: stop("f2 always causes an error for testing purposes")
  at f2()
  at catA.R#8: cat(...)
  at #3: catA("f2 = ", f2(), "\n", sep = "")
  at f1()
  at withVisible(expr)
  at logFully.R#110: withCallingHandlers(withVisible(expr), debug = logger, message = logger, warning = logger, caughtError = logger, error = logger)
  at logFully(f1())
Error in f2() : f2 always causes an error for testing purposes

1

没有行号,但这是我目前找到的最接近的:

run = function() {
    // Your code here...
}
withCallingHandlers(run(), error=function(e)cat(conditionMessage(e), sapply(sys.calls(),function(sc)deparse(sc)[1]), sep="\n   ")) 

-1

我写了一个类似于try的解决方案,除了它还返回调用堆栈。

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])

这里有更多信息:https://dev59.com/9GUp5IYBdhLWcg3wbXJf#40899766


-1

我认为你需要使用tryCatch()。在tryCatch()函数中,你可以按照自己的想法去做任何事情,因此我不明白为什么你认为它很复杂。或许你可以发一下你的代码示例?


1
与我使用的大多数其他语言(例如Java或Python)相比,它更为复杂。在这些语言中,从异常中打印堆栈跟踪是一个不需要思考的一行代码。 - Alice Purcell
我仍然不明白你所描述的为什么不止是一行代码。唯一的困难在于如果你想抛出一个特定的异常类型,因为这并没有得到很好的支持。 - Shane
2
也许不是这样的,如果不是,请发表您的想法! :) - Alice Purcell

网页内容由stack overflow 提供, 点击上面的
可以查看英文原文,
原文链接