The structure of a logger and the flow of a log record 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] "2021-04-14 15:58:02 UTC"
    #> 
    #> $levelr
    #> [1] 400
    #> attr(,"level")
    #> [1] "INFO"
    #> attr(,"class")
    #> [1] "loglevel" "integer" 
    #> 
    #> $level
    #> [1] "INFO"
    #> 
    #> $pid
    #> [1] 19920
    #> 
    #> $r_version
    #> [1] "4.0.2"
    #> 
    #> $ns_pkg_version
    #> [1] NA
    #> 
    #> $node
    #> [1] "travis-job-db29fc9d-2154-46fe-a7c4-8e4423407e4f"
    #> 
    #> $arch
    #> [1] "x86_64"
    #> 
    #> $os_name
    #> [1] "Linux"
    #> 
    #> $os_release
    #> [1] "4.15.0-1028-gcp"
    #> 
    #> $os_version
    #> [1] "#29~16.04.1-Ubuntu SMP Tue Feb 12 16:31:10 UTC 2019"
    #> 
    #> $user
    #> [1] "travis"
  • 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] 400
      #> attr(,"level")
      #> [1] "INFO"
      #> attr(,"class")
      #> [1] "loglevel" "integer"
      ERROR <= INFO
      #> [1] TRUE
      log_error('Oops')
      #> ERROR [2021-04-14 15:58:02] 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')

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.