Stampa traccia stack e continua dopo errore si verifica in R

Question

Sto scrivendo un codice R che chiama altro codice che potrebbe non riuscire. Se lo fa, voglio stampare una traccia di stack (per rintracciare cosa è andato storto), quindi continuare a prescindere. Tuttavia, la funzione traceback() fornisce solo informazioni sulle eccezioni non rilevate. Posso ottenere il risultato che voglio tramite una costruzione piuttosto complessa, che coinvolge tryCatch e dump.frames, ma non c'è un modo più semplice per farlo?

Answer 1

ho finito per scrivere un registratore di general-purpose che produce messaggi di logging Java-like quando lo standard R Vengono chiamati i metodi "messaggio", "avviso" e "stop". Include timestamp e impila le tracce per gli avvisi e sopra.

Mille grazie a Man Group per il permesso di distribuire questo! Grazie anche a Bob Albright, la cui risposta mi ha dato un vantaggio rispetto a quello che stavo cercando.

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

Per usarlo, basta avvolgerlo intorno al vostro codice:

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

Per un'uscita tranquilla, in assenza di errori, impostare il flag silentSuccess (utile per le prove!). I messaggi verranno emessi solo se si verifica un errore, per dare un contesto all'errore.

Per raggiungere l'obiettivo originale (dump di stack trace + portare avanti), basta usare try:

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

Answer 2

Penso che sarà necessario utilizzare tryCatch(). Puoi fare tutto ciò che vuoi nella funzione tryCatch(), quindi non mi è chiaro il motivo per cui lo stai guardando come complesso. Forse postare il tuo esempio di codice?

Answer 3

Hai provato l'impostazione

options(error=recover) 

? Il software Chambers for Data Analysis ha alcuni utili suggerimenti sul debugging.

Answer 4

Ho scritto questo codice circa una settimana fa per aiutarmi a rintracciare gli errori che provengono principalmente dalle sessioni R non interattive. È ancora un po 'approssimativo, ma stampa una traccia dello stack e continua. Fammi sapere se questo è utile, sarei interessato a come renderebbe questo più informativo. Sono anche aperto a modi più puliti per ottenere queste informazioni.

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: si potrebbe non vuole mettere in guardia = 2 (avvertimenti convertiti in errori)

Answer 5

Se qualcosa che fa scattare in opzione (errore ...) è di interesse, è anche possibile fare questo:

Da quello che posso dire, fa la maggior parte di ciò che la soluzione suggerita da Bob fa, ma ha il vantaggio di essere molto più breve.

(Sentitevi liberi di combinare con keep.source = TRUE, avvertono = 2, ecc, se necessario.)

Answer 6

senza numeri di linea, ma questo è il più vicino che ho trovato finora:

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

Answer 7

I ha scritto una soluzione che funziona come try, tranne che restituisce anche lo stack di chiamate.

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

Maggiori informazioni nella mia risposta qui: https://stackoverflow.com/a/40899766/1587132

Answer 8

Si tratta di un follow-up a @ di Chrispy risposta di cui sopra dove ha presentato una funzione withJavaLogging. Ho commentato che la sua soluzione è stimolante, ma per me, è segnata da qualche output all'inizio della traccia dello stack che non voglio vedere.

Per illustrare, si consideri questo codice:

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") 
    } 

Se eseguo la linea withJavaLogging(f1()) ottengo l'uscita

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 

Non voglio vedere che at .handleSimpleError(function (obj) linea seguita dal codice sorgente di la funzione logger definita all'interno della funzione withJavaLogging. Ho commentato in precedenza che ho potuto reprimere che la produzione indesiderata cambiando trace = trace[length(trace):1] a trace = trace[(length(trace) - 1):1]

Per la comodità di chiunque altro leggendo questo, ecco una versione completa della funzione che ora uso (rinominato da withJavaLogging a logFully, e un po 'riformattato per soddisfare le mie preferenze di leggibilità):

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

Se eseguo la linea logFully(f1()) ottengo l'uscita che desidero, che è semplicemente

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