Filter not injecting data to text file logs

[jonnybaik]

I am using a logger that logs to the console and a text file, but the filter that I add to the logger is only writing the messages to the console appender and not writing the data to the text file.

Reproducible example:

library(lgr)
packageVersion("lgr")
# [1] ‘0.4.3’

# Get root logger
(lg <- get_logger())
# <LoggerRoot> [info] root
#
# appenders:
#   console: <AppenderConsole> [all] -> console

# Function to generate some logs
panic <- function() {
  lg$info("Writing info message to log")
  lg$warn("A big fat warning for you")
  lg$error("Something bad happened!")
}

# Test
panic()
# INFO  [18:36:53.476] Writing info message to log 
# WARN  [18:36:53.507] A big fat warning for you 
# ERROR [18:36:53.515] Something bad happened! 

# Inject message into logs
lg$add_filter(FilterInject$new(hello = "world", foo = "bar"), name = "inject")
panic()
# INFO  [18:37:23.928] Writing info message to log {foo: `bar`, hello: `world`}
# WARN  [18:37:23.932] A big fat warning for you {foo: `bar`, hello: `world`}
# ERROR [18:37:23.940] Something bad happened! {foo: `bar`, hello: `world`}

# Add a file appender to log to a file
tf <- tempfile()
lg$add_appender(AppenderFile$new(tf), name = "txtfile")
panic()
# INFO  [18:37:23.928] Writing info message to log {foo: `bar`, hello: `world`}
# WARN  [18:37:23.932] A big fat warning for you {foo: `bar`, hello: `world`}
# ERROR [18:37:23.940] Something bad happened! {foo: `bar`, hello: `world`}

# But no data injected to the text file!
readLines(tf)
# [1] "INFO  [2022-03-11 18:37:47.150] Writing info message to log"
# [2] "WARN  [2022-03-11 18:37:47.154] A big fat warning for you"  
# [3] "ERROR [2022-03-11 18:37:47.157] Something bad happened!" 

Bug (?): data is injected to the console logs but not injected to the log entries in the text file

Expected behavior: The log entries in both the console and text file contain the injected data

[s-fleck]

This is because your inject filter injects custom fields, but the text file appender by default does not display them

lg$appenders$txtfile$layout$fmt  # display the format configuration for writing to text files
lg$appenders$txtfile$layout$set_fmt("%L [%t] %m %f")
lg$info("now it works!")

See ?format.LogEvent for details.

I'm leaving this open, because actually it's kinda dumb that the text file logger ignores the custom fields by default. I should probably change that.

[jonnybaik]

Thanks for the fast reply. I was tearing my hair out wondering why it wasn't working. Updating the log formatting fixes things!

I see it is explained in the formatting documentation at ?format.LogEvent and it was something that I overlooked.