futile.logger warn to stderr

Question

How could I send all logs with level "warn" to stderr instead of stdout but still keep all "info" and "debug" logs in stdout? My setting looks like this:

library(futile.logger)
options(warn=1)

logFileName <- paste0(outdir, "/", projectID, ".log")
flog.appender(appender.tee(logFileName))
flog.threshold(DEBUG)
flog.carp(TRUE)

Answer 1

The appender function is responsible for sending the log line to an output destination; You’ll need to define a custom appender.

In futile.logger, the appender only receives the log line, not the log level associated with it. You could try to infer the log level based on the line, and choose the destination based on that. The exact logic to do that will depend on your layout function. With the default option (layout.simple()) that logic could look something like this:

appender.custom <- function(file) {
  function(line) {
    level <- regmatches(line, regexpr("\\w+(?= \\[)", line, perl = TRUE))
    dest <- if (get(level) > WARN) stdout() else stderr()
    cat(line, file = dest, sep = "")
    cat(line, file = file, append = TRUE, sep = "")
  }
}

Then you just swap this custom appender for appender.tee():

library(futile.logger)

logFileName <- tempfile(fileext = ".log")
flog.appender(appender.custom(logFileName))
#> NULL
flog.threshold(DEBUG)
#> NULL

local({
  flog.debug("Debug message.")
  flog.info("Info message.")
  flog.warn("Warning message.")
  flog.error("Error message.")
})
#> DEBUG [2020-11-17 16:52:31] Debug message.
#> INFO [2020-11-17 16:52:31] Info message.

cat(readLines(logFileName), sep = "\n")
#> DEBUG [2020-11-17 16:52:31] Debug message.
#> INFO [2020-11-17 16:52:31] Info message.
#> WARN [2020-11-17 16:52:31] Warning message.
#> ERROR [2020-11-17 16:52:31] Error message.
unlink(logFileName)

Above, the captured output doesn’t include stderr, but here’s a screenshot of what the output looks like in the ineractive console:

Longer term, the way to approach this would probably be a feature request to the package authors to also pass the log level of the message to the appender function.

Alternatively, if you’re not commited to sticking with futile.logger, you could use log4r which does give the level to the appender. You’ll still need a custom appender, but there’s no need to try to parse the level:

library(log4r)
#> 
#> Attaching package: 'log4r'
#> The following object is masked from 'package:base':
#> 
#>     debug

custom_appender <- function(layout = log4r::default_log_layout()) {
  WARN <- log4r::as.loglevel("WARN")
  function(level, ...) {
    msg <- layout(level, ...)
    level <- log4r::as.loglevel(level)
    dest <- if (level >= WARN) stderr() else stdout()
    cat(msg, file = dest, sep = "")
  }
}

log_file <- tempfile(fileext = ".log")
appenders <- list(file_appender(log_file), custom_appender())
logger <- logger("DEBUG", appenders = appenders)

local({
  debug(logger, "Debug message.")
  info(logger, "Info message.")
  warn(logger, "Warning message.")
  error(logger, "Error message.")
})
#> DEBUG [2020-11-17 16:52:31] Debug message.
#> INFO  [2020-11-17 16:52:31] Info message.

cat(readLines(log_file), sep = "\n")
#> DEBUG [2020-11-17 16:52:31] Debug message.
#> INFO  [2020-11-17 16:52:31] Info message.
#> WARN  [2020-11-17 16:52:31] Warning message.
#> ERROR [2020-11-17 16:52:31] Error message.
unlink(log_file)