warnings are printed more than once if log_messages/log_warnings/log_errors are called repeatedly

jkeuskamp commented 3 years ago

Logger repeats the message caught by log_messages/log_warnings/log_errors as many times as these functions are called (see example below). In all scenarios I can think of this is unwanted behaviour, and I would suggest to limit the number of repetitions to one.

library('logger')
log_messages()
warning('some warning')

WARN [2021-08-18 12:43:08] some warning Warning message: some warning

I assume that that is expected behaviour, However, when calling log_messages again, logger repeats the message twice.

log_messages()
warning('some warning')

WARN [2021-08-18 12:43:10] some warning WARN [2021-08-18 12:43:10] some warning Warning message: some warning

DanChaltiel commented 2 years ago

This is because you can have more than one handler for the same condition.

For instance, consider running this code (unfortunately, logger is not compatible with reprex):

globalCallingHandlers(NULL) #reset
globalCallingHandlers() #empty list
logger::log_warnings()
globalCallingHandlers()#warning
logger::log_warnings()
globalCallingHandlers()#warning and warning
globalCallingHandlers(warning = function(m) {
  print(paste("foobar -", m$message))
})
globalCallingHandlers()#warning and warning and warning
warning("I wish I could use reprex") #4 outputs

There are several options here.

Don't allow more than one handler per condition

I don't know why you would want more than one so this may be sufficient. You could also imagin a system with getOptions() to bypass this check so it is not limiting for the advanced user.

check_condition_already_managed_lite = function(condition){
  condition = match.arg(condition, c("warning", "error", "message"))
  x = globalCallingHandlers()[names(globalCallingHandlers())==condition]
  length(x)==0
}
check_condition_already_managed_lite("warning")#TRUE

Don't allow more than one handler per condition to be handled by `{logger}`

This one is more precise but the code is not very elegant. It should probably deserve a bit more testing.

#' check if the condition's handler is already managed by `{logger}`
#'
#' @param condition "warning", "error"...
#'
#' @return TRUE/FALSE
#' @keywords internal
#' @noRd
check_condition_already_managed = function(condition){
  condition = match.arg(condition, c("warning", "error", "message"))
  globalCallingHandlers()[names(globalCallingHandlers())==condition] %>% 
    sapply(function(x){
      body(x) %>% as.character() %>% str_detect("logger::") %>% any()
    }) %>% 
    any()
}
check_condition_already_managed("warning")#TRUE

These functions should be inserted in logger::log_warnings(), logger::log_errors(), and their friends so that they take effect only if needed.

I can make a PR but for now there would be some conflicts with my other PR (https://github.com/daroczig/logger/pull/100).

daroczig commented 10 months ago

Thanks for reporting this and also for the related options above! I have something in mind regarding the last option - will try to get a related commit out by EOD.

daroczig commented 10 months ago

PS @DanChaltiel can you pls open a separate ticket re reprex issue you referred to above?

daroczig / logger