Merge pull request #227 from thomasp85/issue222-knitr-hook

Add knitr hook

Author: daroczig

NAMESPACE

@@ -53,6 +53,7 @@ export(layout_logging)
 export(layout_simple)
 export(layout_syslognet)
 export(log_appender)
+export(log_chunk_time)
 export(log_debug)
 export(log_elapsed)
 export(log_elapsed_start)

NEWS.md

@@ -5,6 +5,7 @@
 * `log_errors()` gains a `traceback` argument that toggles whether the error traceback should be logged along with the message (fix #86 via #223, @thomasp85)
 * File and line location of the log call is now available to the layouts (fix #110 via #224, @thomasp85)
 * New `formatter_cli()` allows you to use the syntax from the cli package to create log messages (fix #210 via #225, @thomasp85)
+* New `log_chunk_time()` helper function to automatically log the execution time of knitr code chunks (fix #222 via ##227, @thomasp85)
 
 # logger 0.4.0 (2024-10-19)
 

R/helpers.R

@@ -300,3 +300,40 @@ log_failure <- function(expression) {
     }
   )
 }
+
+#' Automatically log execution time of knitr chunks
+#'
+#' Calling this function in the first chunk of a document will instruct knitr
+#' to automatically log the execution time of each chunk. If using
+#' [formatter_glue()] or [formatter_cli()] then the `options` variable will be
+#' available, providing the chunk options such as chunk label etc.
+#'
+#' @inheritParams log_elapsed
+#'
+#' @export
+#'
+#' @examples
+#' # To be put in the first chunk of a document
+#' log_chunk_time("chunk {options$label}")
+#'
+log_chunk_time <- function(..., level = INFO, namespace = NA_character_) {
+  if (!requireNamespace("knitr", quietly = TRUE)) {
+    stop("knitr is required to use this functionality", call. = FALSE)
+  }
+  if (!isTRUE(getOption("knitr.in.progress"))) {
+    return(invisible())
+  }
+  args <- list(...)
+  args$level <- level
+  args$namespace <- namespace
+  knitr::knit_hooks$set(logger_timer = function(before, options) {
+    if (before) {
+      log_elapsed_start(namespace = namespace, quiet = TRUE)
+    } else {
+      do.call(log_elapsed, args)
+    }
+  })
+  knitr::opts_chunk$set(logger_timer = TRUE)
+
+  invisible()
+}

_pkgdown.yml

@@ -27,6 +27,7 @@ reference:
   - log_separator
   - log_with_separator
   - with_log_threshold
+  - log_chunk_time
 
 - title: Appenders
   desc: >

man/log_chunk_time.Rd

@@ -96,3 +96,17 @@ test_that("lower log level", {
   local_test_logger(TRACE, layout = layout_glue_generator("{level} {msg}"))
   expect_output(log_eval(4), sprintf("TRACE %s => %s", shQuote(4), shQuote(4)))
 })
+
+test_that("knitr hook gets applied", {
+  local_test_logger()
+  mock_doc <- c(
+    "```{r, include = FALSE}",
+    "library(logger)",
+    "log_chunk_time()",
+    "```",
+    "```{r}",
+    "Sys.sleep(0.2)",
+    "```"
+  )
+  expect_output(knitr::knit(text = mock_doc, quiet = TRUE), "global timer 0.2")
+})