Skip to content

Commit 9adf2c4

Browse files
daroczigdaroczig
authored
Merge pull request #233 from thomasp85/custom-timestamp
Add .timestamp argument to overwrite log time
2 parents 8993047 + 89fa37a commit 9adf2c4

15 files changed

+136
-54
lines changed

‎NEWS.md‎

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -5,7 +5,8 @@
55
* `log_errors()` gains a `traceback` argument that toggles whether the error traceback should be logged along with the message (fix #86 via #223, @thomasp85)
66
* File and line location of the log call is now available to the layouts (fix #110 via #224, @thomasp85)
77
* New `formatter_cli()` allows you to use the syntax from the cli package to create log messages (fix #210 via #225, @thomasp85)
8-
* New `log_chunk_time()` helper function to automatically log the execution time of knitr code chunks (fix #222 via ##227, @thomasp85)
8+
* New `log_chunk_time()` helper function to automatically log the execution time of knitr code chunks (fix #222 via #227, @thomasp85)
9+
* Allow user to overwrite the timestamp during logging if needed (fix #230, @thomasp85)
910

1011
# logger 0.4.0 (2024-10-19)
1112

‎R/helpers.R‎

Lines changed: 4 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -102,7 +102,8 @@ log_separator <- function(level = INFO,
102102
width = 80,
103103
.logcall = sys.call(),
104104
.topcall = sys.call(-1),
105-
.topenv = parent.frame()) {
105+
.topenv = parent.frame(),
106+
.timestamp = Sys.time()) {
106107
stopifnot(length(separator) == 1, nchar(separator) == 1)
107108

108109
base_info_chars <- nchar(catch_base_log(level, namespace, .topcall = .topcall, .topenv = .topenv))
@@ -113,7 +114,8 @@ log_separator <- function(level = INFO,
113114
namespace = namespace,
114115
.logcall = .logcall,
115116
.topcall = .topcall,
116-
.topenv = .topenv
117+
.topenv = .topenv,
118+
.timestamp = .timestamp
117119
)
118120
}
119121

‎R/layouts.R‎

Lines changed: 26 additions & 15 deletions
Original file line numberDiff line numberDiff line change
@@ -37,9 +37,9 @@ get_logger_meta_variables <- function(log_level = NULL,
3737
namespace = NA_character_,
3838
.logcall = sys.call(),
3939
.topcall = sys.call(-1),
40-
.topenv = parent.frame()) {
40+
.topenv = parent.frame(),
41+
.timestamp = Sys.time()) {
4142
sysinfo <- Sys.info()
42-
timestamp <- Sys.time()
4343

4444
list(
4545
ns = namespace,
@@ -48,7 +48,7 @@ get_logger_meta_variables <- function(log_level = NULL,
4848
fn = deparse_to_one_line(.topcall[[1]]),
4949
call = deparse_to_one_line(.topcall),
5050
location = log_call_location(.logcall),
51-
time = timestamp,
51+
time = .timestamp,
5252
levelr = log_level,
5353
level = attr(log_level, "level"),
5454
pid = Sys.getpid(),
@@ -104,7 +104,8 @@ layout_glue_generator <- function(format = '{level} [{format(time, "%Y-%m-%d %H:
104104
namespace = NA_character_,
105105
.logcall = sys.call(),
106106
.topcall = sys.call(-1),
107-
.topenv = parent.frame()) {
107+
.topenv = parent.frame(),
108+
.timestamp = Sys.time()) {
108109
fail_on_missing_package("glue")
109110
if (!inherits(level, "loglevel")) {
110111
stop("Invalid log level, see ?log_levels")
@@ -116,6 +117,7 @@ layout_glue_generator <- function(format = '{level} [{format(time, "%Y-%m-%d %H:
116117
.logcall = .logcall,
117118
.topcall = .topcall,
118119
.topenv = .topenv,
120+
.timestamp = .timestamp,
119121
parent = environment()
120122
)
121123
glue::glue(format, .envir = meta)
@@ -135,7 +137,8 @@ layout_blank <- function(level,
135137
namespace = NA_character_,
136138
.logcall = sys.call(),
137139
.topcall = sys.call(-1),
138-
.topenv = parent.frame()) {
140+
.topenv = parent.frame(),
141+
.timestamp = Sys.time()) {
139142
msg
140143
}
141144
attr(layout_blank, "generator") <- quote(layout_blank())
@@ -152,8 +155,9 @@ layout_simple <- function(level,
152155
namespace = NA_character_,
153156
.logcall = sys.call(),
154157
.topcall = sys.call(-1),
155-
.topenv = parent.frame()) {
156-
paste0(attr(level, "level"), " [", format(Sys.time(), "%Y-%m-%d %H:%M:%S"), "] ", msg)
158+
.topenv = parent.frame(),
159+
.timestamp = Sys.time()) {
160+
paste0(attr(level, "level"), " [", format(.timestamp, "%Y-%m-%d %H:%M:%S"), "] ", msg)
157161
}
158162
attr(layout_simple, "generator") <- quote(layout_simple())
159163

@@ -179,16 +183,18 @@ layout_logging <- function(level,
179183
namespace = NA_character_,
180184
.logcall = sys.call(),
181185
.topcall = sys.call(-1),
182-
.topenv = parent.frame()) {
186+
.topenv = parent.frame(),
187+
.timestamp = Sys.time()) {
183188
meta <- logger_meta_env(
184189
log_level = level,
185190
namespace = namespace,
186191
.logcall = .logcall,
187192
.topcall = .topcall,
188-
.topenv = .topenv
193+
.topenv = .topenv,
194+
.timestamp = .timestamp
189195
)
190196
paste0(
191-
format(Sys.time(), "%Y-%m-%d %H:%M:%S"), " ",
197+
format(meta$time, "%Y-%m-%d %H:%M:%S"), " ",
192198
attr(level, "level"), ":",
193199
ifelse(meta$ns == "global", "", meta$ns), ":",
194200
msg
@@ -267,15 +273,17 @@ layout_json <- function(fields = default_fields()) {
267273
namespace = NA_character_,
268274
.logcall = sys.call(),
269275
.topcall = sys.call(-1),
270-
.topenv = parent.frame()) {
276+
.topenv = parent.frame(),
277+
.timestamp = Sys.time()) {
271278
fail_on_missing_package("jsonlite")
272279

273280
meta <- logger_meta_env(
274281
log_level = level,
275282
namespace = namespace,
276283
.logcall = .logcall,
277284
.topcall = .topcall,
278-
.topenv = .topenv
285+
.topenv = .topenv,
286+
.timestamp = .timestamp
279287
)
280288
json <- mget(fields, meta)
281289
sapply(msg, function(msg) jsonlite::toJSON(c(json, list(msg = msg)), auto_unbox = TRUE))
@@ -317,15 +325,17 @@ layout_json_parser <- function(fields = default_fields()) {
317325
namespace = NA_character_,
318326
.logcall = sys.call(),
319327
.topcall = sys.call(-1),
320-
.topenv = parent.frame()) {
328+
.topenv = parent.frame(),
329+
.timestamp = Sys.time()) {
321330
fail_on_missing_package("jsonlite")
322331

323332
meta <- logger_meta_env(
324333
log_level = level,
325334
namespace = namespace,
326335
.logcall = .logcall,
327336
.topcall = .topcall,
328-
.topenv = .topenv
337+
.topenv = .topenv,
338+
.timestamp = .timestamp
329339
)
330340
meta <- mget(fields, meta)
331341
field_names <- names(fields)
@@ -363,7 +373,8 @@ layout_syslognet <- structure(
363373
namespace = NA_character_,
364374
.logcall = sys.call(),
365375
.topcall = sys.call(-1),
366-
.topenv = parent.frame()) {
376+
.topenv = parent.frame(),
377+
.timestamp = Sys.time()) {
367378
ret <- paste(attr(level, "level"), msg)
368379
attr(ret, "severity") <- switch(
369380
attr(level, "level", exact = TRUE),

‎R/logger-meta.R‎

Lines changed: 2 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -3,9 +3,8 @@ logger_meta_env <- function(log_level = NULL,
33
.logcall = sys.call(),
44
.topcall = sys.call(-1),
55
.topenv = parent.frame(),
6+
.timestamp = Sys.time(),
67
parent = emptyenv()) {
7-
timestamp <- Sys.time()
8-
98
env <- new.env(parent = parent)
109
env$ns <- namespace
1110
env$ans <- fallback_namespace(namespace)
@@ -17,7 +16,7 @@ logger_meta_env <- function(log_level = NULL,
1716
delayedAssign("topenv", top_env_name(.topenv), assign.env = env)
1817
delayedAssign("location", log_call_location(.logcall), assign.env = env)
1918

20-
env$time <- timestamp
19+
env$time <- .timestamp
2120
env$levelr <- log_level
2221
env$level <- attr(log_level, "level")
2322

‎R/logger.R‎

Lines changed: 39 additions & 17 deletions
Original file line numberDiff line numberDiff line change
@@ -51,7 +51,8 @@ logger <- function(threshold, formatter, layout, appender) {
5151
force(appender)
5252

5353
function(level, ..., namespace = NA_character_,
54-
.logcall = sys.call(), .topcall = sys.call(-1), .topenv = parent.frame()) {
54+
.logcall = sys.call(), .topcall = sys.call(-1),
55+
.topenv = parent.frame(), .timestamp = Sys.time()) {
5556
res <- list(
5657
level = level,
5758
namespace = namespace,
@@ -83,7 +84,10 @@ logger <- function(threshold, formatter, layout, appender) {
8384
res$record <- layout(
8485
level, res$message,
8586
namespace = namespace,
86-
.logcall = substitute(.logcall), .topcall = substitute(.topcall), .topenv = .topenv
87+
.logcall = substitute(.logcall),
88+
.topcall = substitute(.topcall),
89+
.topenv = .topenv,
90+
.timestamp = .timestamp
8791
)
8892

8993
appender(res$record)
@@ -307,6 +311,8 @@ log_indices <- function(namespace = "global") {
307311
#' @param .topenv original frame of the `.topcall` calling function
308312
#' where the formatter function will be evaluated and that is used
309313
#' to look up the `namespace` as well via `logger:::top_env_name`
314+
#' @param .timestamp The time the logging occured. Defaults to the current time
315+
#' but may be overwritten if the logging is delayed from the time it happend
310316
#' @export
311317
#' @examples
312318
#' \dontshow{old <- logger:::namespaces_set()}
@@ -329,7 +335,8 @@ log_indices <- function(namespace = "global") {
329335
#' \dontshow{logger:::namespaces_set(old)}
330336
#' @return Invisible `list` of `logger` objects. See [logger()] for more details on the format.
331337
log_level <- function(level, ..., namespace = NA_character_,
332-
.logcall = sys.call(), .topcall = sys.call(-1), .topenv = parent.frame()) {
338+
.logcall = sys.call(), .topcall = sys.call(-1),
339+
.topenv = parent.frame(), .timestamp = Sys.time()) {
333340
## guess namespace
334341
if (is.na(namespace)) {
335342
topenv <- top_env_name(.topenv)
@@ -354,6 +361,7 @@ log_level <- function(level, ..., namespace = NA_character_,
354361
NA
355362
}
356363
log_arg$.topenv <- .topenv
364+
log_arg$.timestamp <- .timestamp
357365
log_arg$namespace <- namespace
358366

359367
invisible(lapply(definitions, function(definition) {
@@ -385,44 +393,58 @@ validate_log_level <- function(level) {
385393
#' @export
386394
#' @rdname log_level
387395
log_fatal <- function(..., namespace = NA_character_,
388-
.logcall = sys.call(), .topcall = sys.call(-1), .topenv = parent.frame()) {
389-
log_level(FATAL, ..., namespace = namespace, .logcall = .logcall, .topcall = .topcall, .topenv = .topenv)
396+
.logcall = sys.call(), .topcall = sys.call(-1),
397+
.topenv = parent.frame(), .timestamp = Sys.time()) {
398+
log_level(FATAL, ..., namespace = namespace, .logcall = .logcall,
399+
.topcall = .topcall, .topenv = .topenv, .timestamp = .timestamp)
390400
}
391401
#' @export
392402
#' @rdname log_level
393403
log_error <- function(..., namespace = NA_character_,
394-
.logcall = sys.call(), .topcall = sys.call(-1), .topenv = parent.frame()) {
395-
log_level(ERROR, ..., namespace = namespace, .logcall = .logcall, .topcall = .topcall, .topenv = .topenv)
404+
.logcall = sys.call(), .topcall = sys.call(-1),
405+
.topenv = parent.frame(), .timestamp = Sys.time()) {
406+
log_level(ERROR, ..., namespace = namespace, .logcall = .logcall,
407+
.topcall = .topcall, .topenv = .topenv, .timestamp = .timestamp)
396408
}
397409
#' @export
398410
#' @rdname log_level
399411
log_warn <- function(..., namespace = NA_character_,
400-
.logcall = sys.call(), .topcall = sys.call(-1), .topenv = parent.frame()) {
401-
log_level(WARN, ..., namespace = namespace, .logcall = .logcall, .topcall = .topcall, .topenv = .topenv)
412+
.logcall = sys.call(), .topcall = sys.call(-1),
413+
.topenv = parent.frame(), .timestamp = Sys.time()) {
414+
log_level(WARN, ..., namespace = namespace, .logcall = .logcall,
415+
.topcall = .topcall, .topenv = .topenv, .timestamp = .timestamp)
402416
}
403417
#' @export
404418
#' @rdname log_level
405419
log_success <- function(..., namespace = NA_character_,
406-
.logcall = sys.call(), .topcall = sys.call(-1), .topenv = parent.frame()) {
407-
log_level(SUCCESS, ..., namespace = namespace, .logcall = .logcall, .topcall = .topcall, .topenv = .topenv)
420+
.logcall = sys.call(), .topcall = sys.call(-1),
421+
.topenv = parent.frame(), .timestamp = Sys.time()) {
422+
log_level(SUCCESS, ..., namespace = namespace, .logcall = .logcall,
423+
.topcall = .topcall, .topenv = .topenv, .timestamp = .timestamp)
408424
}
409425
#' @export
410426
#' @rdname log_level
411427
log_info <- function(..., namespace = NA_character_,
412-
.logcall = sys.call(), .topcall = sys.call(-1), .topenv = parent.frame()) {
413-
log_level(INFO, ..., namespace = namespace, .logcall = .logcall, .topcall = .topcall, .topenv = .topenv)
428+
.logcall = sys.call(), .topcall = sys.call(-1),
429+
.topenv = parent.frame(), .timestamp = Sys.time()) {
430+
log_level(INFO, ..., namespace = namespace, .logcall = .logcall,
431+
.topcall = .topcall, .topenv = .topenv, .timestamp = .timestamp)
414432
}
415433
#' @export
416434
#' @rdname log_level
417435
log_debug <- function(..., namespace = NA_character_,
418-
.logcall = sys.call(), .topcall = sys.call(-1), .topenv = parent.frame()) {
419-
log_level(DEBUG, ..., namespace = namespace, .logcall = .logcall, .topcall = .topcall, .topenv = .topenv)
436+
.logcall = sys.call(), .topcall = sys.call(-1),
437+
.topenv = parent.frame(), .timestamp = Sys.time()) {
438+
log_level(DEBUG, ..., namespace = namespace, .logcall = .logcall,
439+
.topcall = .topcall, .topenv = .topenv, .timestamp = .timestamp)
420440
}
421441
#' @export
422442
#' @rdname log_level
423443
log_trace <- function(..., namespace = NA_character_,
424-
.logcall = sys.call(), .topcall = sys.call(-1), .topenv = parent.frame()) {
425-
log_level(TRACE, ..., namespace = namespace, .logcall = .logcall, .topcall = .topcall, .topenv = .topenv)
444+
.logcall = sys.call(), .topcall = sys.call(-1),
445+
.topenv = parent.frame(), .timestamp = Sys.time()) {
446+
log_level(TRACE, ..., namespace = namespace, .logcall = .logcall,
447+
.topcall = .topcall, .topenv = .topenv, .timestamp = .timestamp)
426448
}
427449

428450

‎man/get_logger_meta_variables.Rd‎

Lines changed: 5 additions & 1 deletion
Some generated files are not rendered by default. Learn more about customizing how changed files appear on GitHub.

‎man/layout_blank.Rd‎

Lines changed: 5 additions & 1 deletion
Some generated files are not rendered by default. Learn more about customizing how changed files appear on GitHub.

‎man/layout_glue.Rd‎

Lines changed: 5 additions & 1 deletion
Some generated files are not rendered by default. Learn more about customizing how changed files appear on GitHub.

‎man/layout_glue_colors.Rd‎

Lines changed: 5 additions & 1 deletion
Some generated files are not rendered by default. Learn more about customizing how changed files appear on GitHub.

0 commit comments

Comments
 (0)