The Anatomy of a Log Request

To make a successful log record, logger requires the below components:

• a log request, eg

  log_error('Oops')

  • including the log level (importance) of the record, which will be later used to decide if the log record is to be delivered or not: ERROR in this case
  • R objects to be logged: a simple string in this case, although it could be a character vector or any R object(s) that can be converted into a character vector by the formatter function

• the environment and meta-information of the log request, eg actual timestamp, hostname of the computer, the name of the user running the R script, the pid of the R process, calling function and the actual call etc.

  f <- function() get_logger_meta_variables(log_level = INFO)
  f()
  #> $ns
  #> [1] NA
  #> 
  #> $ans
  #> [1] "global"
  #> 
  #> $topenv
  #> [1] "R_GlobalEnv"
  #> 
  #> $fn
  #> [1] "f"
  #> 
  #> $call
  #> [1] "f()"
  #> 
  #> $time
  #> [1] "2019-01-02 15:49:58 CET"
  #> 
  #> $levelr
  #> [1] 400
  #> attr(,"level")
  #> [1] "INFO"
  #> attr(,"class")
  #> [1] "loglevel" "integer" 
  #> 
  #> $level
  #> [1] "INFO"
  #> 
  #> $pid
  #> [1] 5164
  #> 
  #> $node
  #> [1] "nevermind"
  #> 
  #> $arch
  #> [1] "x86_64"
  #> 
  #> $os_name
  #> [1] "Linux"
  #> 
  #> $os_release
  #> [1] "4.15.0-20-generic"
  #> 
  #> $os_version
  #> [1] "#21-Ubuntu SMP Tue Apr 24 06:16:15 UTC 2018"
  #> 
  #> $user
  #> [1] "daroczig"

• a logger definition to process the log request, including

  • log level threshold, eg INFO, which defines the minimum log level required for actual logging – all log requests with lower log level will be thrown away

    log_threshold()
    #> [1] 600
    #> attr(,"level")
    #> [1] "TRACE"
    #> attr(,"class")
    #> [1] "loglevel" "integer"
    ERROR <= INFO
    #> [1] TRUE
    log_error('Oops')
    #> ERROR [2019-01-02 15:49:58] Oops

  • formatter function, which takes R objects and converts those into actual log message(s) to be then passed to the layout function for the log record rendering – such as paste, sprintf, glue or eg the below custom example:

    formatter <- function(...) paste(..., collapse = ' ', sep = ' ')
    formatter(1:3, c('foo', 'bar'))
    #> [1] "1 foo 2 bar 3 foo"

  • layout function, which takes log message(s) and further information on the log request (such as timestamp, hostname, username, calling function etc) to render the actual log records eg human-readable text, JSON etc

    library(jsonlite)
    layout <- function(level, msg) toJSON(level = level, timestamp = time, hostname = node, message = msg)
    layout(INFO, 'Happy Thursday!')
    #> {'level': 'INFO', 'timestamp': '1970-01-01 00:00:00', 'hostname': 'foobar', 'message': 'Happy Thursday!'}

  • appender function, which takes fully-rendered log record(s) and delivers to somewhere, eg stdout, a file or a streaming service, eg

    appender <- function(line) cat(line, '\n')
    appender('INFO [now] I am a log message')
    #> INFO [now] I am a log message

Putting all these together (by explicitly setting the default config in the global namespace):

log_threshold(INFO)
log_formatter(formatter_glue)
log_layout(layout_simple)
log_appender(appender_console)
log_debug('I am a low level log message that will not be printed with a high log level threshold')
log_warn('I am a higher level log message that is very likely to be printed')
#> WARN [2019-01-02 15:49:58] I am a higher level log message that is very likely to be printed

Note, that all logger definitions and requests are tied to a logging namespace, and one log request might trigger multiple logger definitions as well (stacking). Find more information on these in the Customizing the format and destination of log records vignette.