add hidden .rawMsg property to LogEvent for storing msg without string interpolation

Author: s-fleck

NEWS.md

@@ -13,6 +13,10 @@
 
 * added `as_LogEvent()` to coerce various event-like objects to `LogEvents`
 
+* added hidden `.rawMsg` property to LogEvents to store message without
+  string interpolation (e.g. that still contains the placeholders from 
+  `sprintf()` or `glue()`)
+
 
 # lgr 0.4.3
 

R/LogEvent.R

@@ -53,6 +53,7 @@ LogEvent <- R6::R6Class(
       timestamp = Sys.time(),
       caller = NA,
       msg = NA,
+      .rawMsg = msg,
       ...
     ){
       assert(inherits(logger, "Logger"))
@@ -64,6 +65,7 @@ LogEvent <- R6::R6Class(
       assign("timestamp", timestamp, self)
       assign("caller", caller, self)
       assign("msg", msg, self)
+      assign(".rawMsg", .rawMsg, self)
 
       # custom values
       if (!missing(...)){
@@ -94,18 +96,22 @@ LogEvent <- R6::R6Class(
 
     #' @field .logger [Logger]. A reference to the Logger that created the
     #' event (equivalent to `get_logger(event$logger)`).
-    .logger = NULL
+    .logger = NULL,
+
+    #' @field .rawMsg `character`. The raw log message without string
+    #'   interpolation.
+    .rawMsg = NULL
   ),
 
   active = list(
 
     #' @field values `list`. All values stored in the `LogEvent`, including
-    #' all *custom fields*, but not including `event$.logger`.
+    #' all *custom fields*, but not including `event$.logger` and `event$.rawMsg`.
     values = function(){
       fixed_vals   <- c("level", "timestamp", "logger", "caller", "msg")
       custom_vals <- setdiff(
         names(get(".__enclos_env__", self)[["self"]]),
-        c(".__enclos_env__", "level_name", "initialize", "clone", "values",
+        c(".__enclos_env__", "level_name", "initialize", "clone", "values", ".rawMsg",
           ".logger")
       )
       valnames <- union(fixed_vals, custom_vals) # to enforce order of fixed_vals

R/Logger.R

@@ -226,14 +226,16 @@ Logger <- R6::R6Class(
         }
 
         force(caller)
+        rawMsg <- msg
 
         if (missing(...)){
           vals <- list(
             logger = self,
             level = level,
             timestamp = timestamp,
             caller = caller,
-            msg = msg
+            msg = msg,
+            .rawMsg = rawMsg
           )
         } else {
           dots <- list(...)
@@ -245,7 +247,8 @@ Logger <- R6::R6Class(
               level = level,
               timestamp = timestamp,
               caller = caller,
-              msg = msg
+              msg = msg,
+              .rawMsg = rawMsg
             )
           } else {
             not_named <- vapply(names(dots), is_blank, TRUE, USE.NAMES = FALSE)
@@ -259,7 +262,8 @@ Logger <- R6::R6Class(
                 level = level,
                 timestamp = timestamp,
                 caller = caller,
-                msg = msg
+                msg = msg,
+                .rawMsg = rawMsg
               ),
               dots[!not_named]
             )
@@ -896,6 +900,7 @@ LoggerGlue <- R6::R6Class(
           }
         })
 
+        rawMsg <- dots[[1]]
         msg <- do.call(glue::glue, args = c(dots, list(.envir = .envir)))
 
         # Check if LogEvent should be created
@@ -914,7 +919,8 @@ LoggerGlue <- R6::R6Class(
             level = level,
             timestamp = timestamp,
             caller = caller,
-            msg = msg
+            msg = msg,
+            .rawMsg = rawMsg
           )
         } else {
           dots <- list(...)
@@ -926,7 +932,8 @@ LoggerGlue <- R6::R6Class(
               level = level,
               timestamp = timestamp,
               caller = caller,
-              msg = msg
+              msg = msg,
+              .rawMsg = rawMsg
             ),
             dots[custom_fields]
           )

man/LogEvent.Rd

@@ -1,6 +1,9 @@
 context("Logger")
 
 
+# Logger ------------------------------------------------------------------
+
+
 
 test_that("logging conditions works", {
   e <- error("blahblah")
@@ -379,11 +382,17 @@ test_that("$config works with lists", {
 
 
 
+# Multi-Logger tests -------------------------------------------------------------
 
 test_that("Logger$log() dispatches to all appenders, even if some throw an error", {
   ln <- Logger$new("normal", propagate = FALSE)
   lg <- LoggerGlue$new("glue", propagate = FALSE)
 
+  on.exit({
+    ln$config(NULL)
+    lg$config(NULL)
+  })
+
   AppErr <- R6::R6Class(
     inherit = AppenderConsole,
     public = list(
@@ -416,6 +425,11 @@ test_that("Logger error contains useful call object", {
   l <- get_logger("test")
   g <- get_logger_glue("testglue")
 
+  on.exit({
+    l$config(NULL)
+    g$config(NULL)
+  })
+
   expect_warning(l$info("this will fail", e = stop()), "l\\$info")
   expect_warning(g$info("this will fail", e = stop()), "g\\$info")
 })
@@ -428,6 +442,11 @@ test_that("Appender error contains useful call object", {
   l <- get_logger("test")$set_propagate(FALSE)
   g <- get_logger_glue("testglue")$set_propagate(FALSE)
 
+  on.exit({
+    l$config(NULL)
+    g$config(NULL)
+  })
+
   AppenderFail <- R6::R6Class(
     "AppenderFail",
     inherit = Appender,
@@ -445,3 +464,24 @@ test_that("Appender error contains useful call object", {
   expect_warning(g$info("this will fail"), ".*AppenderFail.*g\\$info")
 })
 
+
+
+
+test_that(".rawMsg works", {
+  l <- get_logger("test")$set_propagate(FALSE)
+  g <- get_logger_glue("testglue")$set_propagate(FALSE)
+
+  on.exit({
+    l$config(NULL)
+    g$config(NULL)
+  })
+
+  l$info("foo %s", "bar")
+  g$fatal("hash {x}", x = "baz")
+
+  expect_identical(l$last_event$msg, "foo bar")
+  expect_identical(l$last_event$.rawMsg, "foo %s")
+
+  expect_identical(as.character(g$last_event$msg), "hash baz")
+  expect_identical(g$last_event$.rawMsg, "hash {x}")
+})