使用futile.logger记录所有警告

Question

尝试记录所有错误和警告futile.logger.

对于处理错误有点满意:

library(futile.logger)
options(error = function() { flog.error(geterrmessage()) ; traceback() ; stop() })
log("a")
# Error in log("a") : argument non numérique pour une fonction mathématique
# ERROR [2016-12-01 21:12:07] Error in log("a") : argument non numérique pour une fonction mathématique
# 
# No traceback available 
# Erreur pendant l'emballage (wrapup) : 

有冗余,但我可以很容易地之间的分离stderr,stdout以及日志文件,所以它不是一个问题.它肯定不漂亮,有一个额外的"总结"错误消息,不知何故由stop()我不理解的决赛造成,所以我愿意接受建议.

我找不到类似的警告解决方案.我尝试了什么:

options(warn = 1L)
options(warning.expression = expression(flog.warn(last.warning)))
log(- 1)
# [1] NaN

但无济于事.

后续问题:我是否在不知不觉中忽略了最佳做法？

Answer 1

怎么样:

options(warning.expression = 
        quote({
            if(exists("last.warning",baseenv()) && !is.null(last.warning)){
                txt = paste0(names(last.warning),collapse=" ")
                try(suppressWarnings(flog.warn(txt)))
                cat("Warning message:\n",txt,'\n',sep = "")
            } 
        }))

Answer 2

In可以提供两个选项来记录R条件,如警告futile.logger和捕获所有警告,无论函数调用堆栈有多深:

1. 将代码包装withCallingHandlers为基本解决方案
2. 使用我的包tryCatchLog获得高级解决方案(出于合规性原因:我是作者)

为了解释解决方案,我创建了一个产生警告和错误的简单R脚本:

# Store this using the file name "your_code_file.R"
# This could be your code...

f1 <- function(value) {
  print("f1() called")
  f2(value)                 # call another function to show what happens
  print("f1() returns")
}

f2 <- function(value) {
  print("f2() called")
  a <- log(-1)           # This throws a warning: "NaNs produced"
  print(paste("log(-1) =", a))
  b <- log(value)        # This throws an error if you pass a string as value
  print("f2() returns")
}

f1(1)  # produces a warning
f1("not a number") # produces a warning and an error

执行"按原样"(不记录)此代码生成此输出:

[1] "f1() called"
[1] "f2() called"
[1] "log(-1) = NaN"
[1] "f2() returns"
[1] "f1() returns"
[1] "f1() called"
[1] "f2() called"
[1] "log(-1) = NaN"
Error in log(value) : non-numeric argument to mathematical function
Calls: source -> withVisible -> eval -> eval -> f1 -> f2
In addition: Warning messages:
1: In log(-1) : NaNs produced
2: In log(-1) : NaNs produced

解决方案1(withCallingHandlers)

创建一个由R调用的新R文件,并提供未更改的(!)原始R脚本:

# Store this using the file name "logging_injector_withCallingHandlers.R"
# Main function to inject logging of warnings without changing your original source code

library(futile.logger)

flog.threshold(INFO)

# Injecting the logging of errors and warnings:
tryCatch(withCallingHandlers({
  source("your_code_file.R")     # call your unchanged code by sourcing it!
}, error = function(e) {
     call.stack <- sys.calls()   # "sys.calls" within "withCallingHandlers" is like a traceback!
     log.message <- e$message
     flog.error(log.message)     # let's ignore the call.stack for now since it blows-up the output
}, warning = function(w) {
     call.stack <- sys.calls()   # "sys.calls" within "withCallingHandlers" is like a traceback!
     log.message <- w$message
     flog.warn(log.message)      # let's ignore the call.stack for now since it blows-up the output
     invokeRestart("muffleWarning")  # avoid warnings to "bubble up" to being printed at the end by the R runtime
})
 , error = function(e) {
  flog.info("Logging injector: The called user code had errors...")
})

如果执行此包装器代码,则R输出为:

$ Rscript logging_injector_withCallingHandlers.R
NULL
[1] "f1() called"
[1] "f2() called"
WARN [2017-06-08 22:35:53] NaNs produced
[1] "log(-1) = NaN"
[1] "f2() returns"
[1] "f1() returns"
[1] "f1() called"
[1] "f2() called"
WARN [2017-06-08 22:35:53] NaNs produced
[1] "log(-1) = NaN"
ERROR [2017-06-08 22:35:53] non-numeric argument to mathematical function
INFO [2017-06-08 22:35:53] Logging injector: The called user code had errors...

如你看到的

• 现在记录警告
• 调用堆栈也可以输出(我已禁用此功能以避免充斥此答案)

参考文献:https://stackoverflow.com/a/19446931/4468078

解决方案2 - 包tryCatchLog(我是作者)

解决方案1有一些缺点,主要是:

• 堆栈跟踪("traceback")不包含文件名和行号
• 堆栈跟踪充斥着您不想看到的内部函数调用(相信我或者使用非trival R脚本尝试它;-)

我没有一次又一次地复制和粘贴上面的代码片段,而是开发了一个包,将上述withCallingHandlers逻辑封装在一个函数中,并添加其他功能,如

• 记录错误,警告和消息
• 通过使用对源文件名和行号的引用来记录堆栈跟踪来识别错误和警告的来源
• 通过创建包含全局环境(工作空间)的所有变量的转储文件以及调用的每个函数(通过dump.frames)来支持错误后的事后分析 - 对于无法直接在服务器上调试以重现错误的批处理作业非常有用!

使用tryCatchLog创建包装文件来包装上面的R脚本文件

# Store this using the file name "logging_injector_tryCatchLog.R"
# Main function to inject logging of warnings without changing your original source code

# install.packages("devtools")
# library(devtools)
# install_github("aryoda/tryCatchLog")
library(tryCatchLog)
library(futile.logger)

flog.threshold(INFO)

tryCatchLog({
  source("your_code_file.R")     # call your unchanged code by sourcing it!
  #, dump.errors.to.file = TRUE  # Saves a dump of the workspace and the call stack named dump_<YYYYMMDD_HHMMSS>.rda
})

并执行它Rscript来获得此(缩短!)结果:

# $ Rscript -e "options(keep.source = TRUE); source('logging_injector_tryCatchLog.R')" > log.txt
[1] "f1() called"
[1] "f2() called"
WARN [2017-06-08 23:13:31] NaNs produced
Compact call stack:
  1 source("logging_injector_tryCatchLog.R")
  2 logging_injector_tryCatchLog.R#12: tryCatchLog({
  3 logging_injector_tryCatchLog.R#13: source("your_code_file.R")
  4 your_code_file.R#18: f1(1)
  5 your_code_file.R#6: f2(value)
  6 your_code_file.R#12: .signalSimpleWarning("NaNs produced", quote(log(-1)))
Full call stack:
  1 source("logging_injector_tryCatchLog.R")
  2 withVisible(eval(ei, envir))

  ...
<a lot of logging output omitted here...>

正如您在调用堆栈级别6清楚地看到的那样,源代码文件名和行号(#12)被记录为警告源以及抛出警告的源代码片段:

6 your_code_file.R#12 .signalSimpleWarning("NaNs产生",引用(log(-1)))