Печать трассировки стека и продолжение после ошибки в R

18

Я пишу код R, который вызывает другой код, который может завершиться неудачей. Если это так, я хочу напечатать трассировку стека (чтобы отследить, что пошло не так), а затем продолжить независимо. Однако функция traceback () предоставляет информацию о неперехваченных исключениях. Я могу получить результат, который я хочу, с помощью довольно сложной, насыщенной конструкции с участием tryCatch и dump.frames, но нет ли более простого способа сделать это?

    
задан Alice Purcell 29.12.2009 в 16:07
источник

8 ответов

8

Я закончил тем, что написал журнал общего назначения, который выдает сообщения о ведомости, подобные Java, когда вызываются стандартные методы «сообщение», «предупреждение» и «стоп». Он включает отметки времени и трассировку стека для предупреждений и выше.

Большое спасибо Man Group за разрешение распространять это! Спасибо также Бобу Олбрайт, чей ответ дал мне ногу для того, что я искал.

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))
    
ответ дан Alice Purcell 22.07.2014 в 12:01
  • Напоминает мне пакет оценки Хэдли, хотя я уверен, что не выполняет трассировку стека. Однако я не вижу в нем упоминания, и это, безусловно, может оказаться полезным для других, которым не нужен весь механизм, который вы здесь предоставляете. –  Aaron 14.08.2014 в 16:04
  • Отличная работа! BTW: Какова цель добавления атрибута «calls» через limitedLabels (c (вызовы, attr (obj, «calls»)))? Когда я проверяю атрибуты (obj), я нахожу только атрибут с именем «call» (единственное!) ... –  R Yoda 10.10.2016 в 21:23
  • @RYoda Странно, это сработало для меня, когда я это написал. Опять же, R не является самым последовательным языком на планете. –  Alice Purcell 25.10.2016 в 17:56
  • chrispy: это самое блестящее решение. Большое спасибо! –  HaroldFinch 17.02.2017 в 23:45
  • @chrispy: (... сожжено правилом редактирования комментариев 5 минут, теперь заканчивается ...) Единственная проблема, которую я испытываю при использовании вашего кода, - это то, что я получаю действительно уродливый вывод в начале моего стека след. В частности, первая строка находится в .handleSimpleError (function (obj), за которой следуют первые две строки внутренней функции logger. Я не хочу этого видеть, поэтому я обнаружил, что могу подавить ее, изменив trace = trace [ length (trace): 1] to trace = trace [(length (trace) - 1): 1]. Я буду следить за новым ответом, который является полной версией. –  HaroldFinch 17.02.2017 в 23:54
19

Я написал этот код около недели назад, чтобы помочь мне отслеживать ошибки, которые происходят в основном из неинтерактивных сеансов R. Это все еще немного грубо, но он печатает трассировку стека и продолжается. Дайте мне знать, если это полезно, мне было бы интересно, как вы сделаете это более информативным. Я также открываю более чистые способы получить эту информацию.

options(warn = 2, keep.source = TRUE, error = 
  quote({ 
    cat("Environment:\n", file=stderr()); 

    # 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

    #
    # 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.

    n <- length(last.dump)
    calls <- names(last.dump)
    cat(paste("  ", 1L:n, ": ", calls, sep = ""), sep = "\n", file=stderr())
    cat("\n", file=stderr())

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

PS: вам может не понадобиться предупреждение = 2 (предупреждения, преобразованные в ошибки)

    
ответ дан Bob Albright 04.01.2010 в 18:00
  • Мне это нравится. Чтобы сделать его более информативным, вы можете вызвать ls.str () для каждой среды в last.dump. (Это может сделать вывод довольно длинным, хотя.) –  Richie Cotton 06.01.2010 в 12:28
  • Не совсем то, чем я был, но он, по крайней мере, адресует печать трассировки стека. Благодаря! –  Alice Purcell 08.01.2010 в 11:12
8

Если что-то, что срабатывает по опции (ошибка ...), представляет интерес, вы также можете сделать это:

options(error=traceback)

Из того, что я могу сказать, он делает большую часть предлагаемого решения Боба, но имеет то преимущество, что он намного короче.

(Не стесняйтесь комбинировать с keep.source = TRUE, warn = 2 и т. д. по мере необходимости.)

    
ответ дан Christian Hudon 18.10.2011 в 21:41
  • К сожалению, мне нужно продолжить потом, то есть запуститься в блоке try (), чтобы он не включался по опции (error = ...). –  Alice Purcell 14.08.2014 в 16:12
4

Вы пробовали

 options(error=recover)

настройка? Chambers 'Software for Data Analysis' содержит полезные советы по отладке.

    
ответ дан Dirk Eddelbuettel 29.12.2009 в 16:14
  • Мне не нужна интерактивная подсказка, я хочу, чтобы программа распечатывала трассировку стека и выполнялась независимо. –  Alice Purcell 29.12.2009 в 17:29
  • Работаете ли вы только с R-кодом или другими языками, которые вы склеиваете с R? –  Dirk Eddelbuettel 29.12.2009 в 18:26
  • Я работаю только с R-кодом –  Alice Purcell 29.12.2009 в 19:13
1

нет номеров строк, но это ближайший я нашел до сих пор:

run = function() {
    // Your code here...
}
withCallingHandlers(run(), error=function(e)cat(conditionMessage(e), sapply(sys.calls(),function(sc)deparse(sc)[1]), sep="\n   ")) 
    
ответ дан user1133275 12.08.2014 в 18:07
0

Я думаю, что вам нужно будет использовать tryCatch() . Вы можете делать все, что хотите, в функции tryCatch (), поэтому мне непонятно, почему вы рассматриваете это как сложное. Может быть, разместите свой пример кода?

    
ответ дан Shane 29.12.2009 в 16:14
  • Комплекс по сравнению с большинством других языков, которые я использую, например. Java или Python, в которых печать трассировки стека из исключения - это не-мозговой однострочный. –  Alice Purcell 29.12.2009 в 16:32
  • Я до сих пор не понимаю, почему то, что вы описываете, будет намного больше, чем однострочный. Единственная трудность заключается в том, что вы пытаетесь создать конкретный тип исключения, потому что это не всегда поддерживается. –  Shane 29.12.2009 в 16:37
  • Возможно, это не так - если да, напишите, как вы это сделаете! :) –  Alice Purcell 29.12.2009 в 17:36
0

Это ответ на ответ @ chrispy выше, где он представил функцию 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

Я не хочу видеть, что строка at .handleSimpleError(function (obj) сопровождается исходным кодом функции журнала, определенной внутри функции withJavaLogging . Я прокомментировал выше, что могу подавить этот нежелательный результат, изменив trace = trace[length(trace):1] на trace = trace[(length(trace) - 1):1]

Для удобства других, кто читает это, вот полная версия функции, которую я сейчас использую (переименован из JavaLogging в 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
    
ответ дан HaroldFinch 18.02.2017 в 00:13
-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])

Больше информации в моем ответе здесь: Ссылка

    
ответ дан Berry Boessenkool 30.11.2016 в 23:57