lgr icon indicating copy to clipboard operation
lgr copied to clipboard

suggestion: allow optional `tz` parameter for `timestamp_fmt` in Layout(s)

Open mmuurr opened this issue 4 years ago • 5 comments

Sometimes it's helpful to have logs across disparate machines output timestamps with the same TZ offset.

Currently, the best way to do this is:

  • Not do it at all, but set the timestamp_fmt string to something like %FT%T%z, a proper ISO8601 with TZ offset (%z).
  • Change the default TZ of the R session (either from within R or prior to launching the R process from the shell; the latter approach is somewhat error-prone and dependent on how different OSes and Linux distros manage timezones).

But(!), base::format.POSIXct includes a tz parameter; here's the signature:

format.POSIXct <-  function(x, format = "", tz = "", usetz = FALSE, ...)

... and lgr's default Layouts simply delegate to that function.

I wonder if it'd be possible to pass on the tz argument, or perhaps even more generally simply 'pass the dots' and allow timestamp_tz setters to specify a dots (...) arg that is captured, stored, then spliced into the eventual format.POSIXct dispatch.

Only a suggestion :-) ... and thanks much for all the work you've put into lgr, it's quite nice!

mmuurr avatar Feb 04 '21 04:02 mmuurr

So you want Layouts to be able to convert between different timezones?

So getting timezones right is kinda tricky, and I think general best practice would be to log everything in UTC, especially if you work across several systems in different timezones. I understand that It would be more convenient if lgr supported converting timezones directly, but if it did that should probably be at global level - so that all Appenders log in the same timezone.

I will leave this open, but It might be a while before I get around to work on lgr again because I'm kinda tied up in other projects at the moment.

s-fleck avatar Feb 04 '21 07:02 s-fleck

I agree that UTC is the best timezone to use for logging timestamps. Is there a recommended approach to configuring the lgr package to log everything in UTC? Currently the lgr package seems to be writing to the local timezone by default.

GitForrest avatar Oct 25 '21 15:10 GitForrest

No there is not. I'd really like to improve timezone handling in lgr but it seems to be a problem that is a bit convoluted and I'm not yet sure how to go about it.

You COULD attach a filter to the logger as a workaround if you really need UTC timestamps right now, but this is probably something I should support natively:

lg <- lgr::get_logger("test/logger")
lg$add_filter(function(event){
  attr(event$timestamp, "tzone") <- "UTC"
  TRUE
}, "UTCify")

lg$info("Test")

s-fleck avatar Oct 25 '21 16:10 s-fleck

I think I found another workaround that may interest you.

Below I simply set the Sys.timezone() to 'UTC' and all timestamps using Sys.time() will be returned in the 'UTC' timezone with appropriate offset from my local time.

` #### EXAMPLE #####

library(lgr)

# get a logger object
lg <- lgr::get_logger(name = "logger")

lg$set_threshold('info')

# set up logger to write to the console
lg$set_appenders(list(cons = lgr::AppenderConsole$new()))

# Not certain what this does, yet follows all examples in the package
# documentation.
lg$set_propagate(FALSE)

# set the formatting of the logging events
format_string <- paste0("%t - %L: %m")

lg$appenders$cons$layout$set_fmt(format_string)
lg$appenders$cons$layout$set_timestamp_fmt("%Y-%m-%d %H:%M:%OS3")


print(Sys.timezone())
lg$info("Some message with local timestamp")

# Ensure the Sys.time() will return timestamp in UTC
Sys.setenv(TZ = 'UTC')
print(Sys.timezone())

lg$info("Some message with UTC timestamp")

`

OUTPUT

[1] "America/New_York" 2021-10-25 15:07:05.372 - INFO : Some message with local timestamp [1] "UTC" 2021-10-25 19:07:05.383 - INFO : Some message with UTC timestamp

GitForrest avatar Oct 25 '21 19:10 GitForrest

lgr$set_propagate(FALSE) makes it so that the log messages are not propageted to the logger parents. In a real-world Scenario you usually want propagate to be TRUE (the default), but it makes sense for examples to keep the exemple-loggers "isolated" form your "real" R-Session!

I am not sure what Sys.setenv(TZ = 'UTC') does, but I guess the least it does is changing the timezone for your whole R-Session, which is a fine solution if that is what you really want!

s-fleck avatar Oct 25 '21 19:10 s-fleck