Add common pipeline timestamp

DESCRIPTION

@@ -13,6 +13,8 @@ Suggests:
     testthat (>= 3.0.0),
     crayon,
     dplyr,
+    ggplot2,
+    stringr,
     tictoc,
     knitr,
     rmarkdown

NAMESPACE

@@ -3,3 +3,4 @@
 export(get_log)
 export(rm_log)
 export(time_pipe)
+importFrom(stats,setNames)

R/emit.R → R/emit_time.R

@@ -2,8 +2,8 @@
 #'
 #' Prints and/or logs the execution time of an operation.
 #'
-#' @param start POSIXct. Operation start time.
-#' @param end POSIXct. Operation end time.
+#' @param start_time POSIXct. Pipeline start time.
+#' @param duration Numeric. Duration since pipeline start.
 #' @param label Character. Operation label.
 #' @param unit Character. Time unit ("secs", "mins", "hours", "days", or "weeks").
 #' @param console Logical. Print timing to the console?
@@ -12,40 +12,36 @@
 #' @return Invisibly, the numeric duration of the operation.
 #' @keywords internal
 #' @noRd
-emit <- function(start, end, label, unit, console, log) {
-  duration <- as.numeric(difftime(end, start, units = unit))
-  duration <- sprintf("%.4f", duration)
-  timestamp <- format(start, "%Y-%m-%d %H:%M:%OS3")
+emit_time <- function(start_time, duration, label, unit, console, log) {
+  duration_fmt <- sprintf("%.4f", duration)
+  timestamp_fmt <- format(start_time, "%Y-%m-%d %H:%M:%OS3")
 
-  build_msg <- function(timestamp, label, duration, unit) {
-    paste0("[", timestamp, "] ", label, ": ", duration, " ", unit)
+  build_msg <- function(ts, label, dur, unit) {
+    paste0("[", ts, "] ", label, ": ", dur, " ", unit)
   }
 
-  # Console message
+  # Console
   if (isTRUE(console)) {
     if (requireNamespace("crayon", quietly = TRUE)) {
-      console_msg <- build_msg(
-        timestamp,
+      msg <- build_msg(
+        timestamp_fmt,
         crayon::blue(label),
-        crayon::green(duration),
+        crayon::green(paste0("+", duration_fmt)),
         crayon::green(unit)
       )
     } else {
-      console_msg <- build_msg(timestamp, label, duration, unit)
+      msg <- build_msg(timestamp_fmt, label, paste0("+", duration_fmt), unit)
     }
-    message(console_msg)
+    message(msg)
   }
 
-  # Log to .pipetime_env
+  # Log
   if (!is.null(log)) {
-    if (!is.character(log)) {
-      stop("'log' must be a character string.")
-    }
-
+    stopifnot(is.character(log), length(log) == 1)
     new_row <- data.frame(
-      timestamp = timestamp,
+      timestamp = start_time,
       label = label,
-      duration = as.numeric(duration),
+      duration = duration,
       unit = unit,
       stringsAsFactors = FALSE
     )

R/get_log.R

@@ -1,13 +1,40 @@
-#' Retrieve a stored timing log
+#' Retrieve a timing log (or all logs)
 #'
-#' @param log Character. Name of the data frame to load from `.pipetime_env`.
+#' Return a stored timing log from `.pipetime_env`.
+#' If `log = NULL`, return all logs as a named list.
+#'
+#' @param log Character string or `NULL`. Name of the log to retrieve. If `NULL`, all logs are returned.
+#'
+#' @return Either:
+#' - A data frame with columns:
+#'   - `timestamp` (`POSIXct`): Pipeline start time
+#'   - `label` (`character`): Operation label
+#'   - `duration` (`numeric`): Elapsed time since pipeline start
+#'   - `unit` (`character`): Time unit used
+#' - Or, if `log = NULL`, a named list of such data frames.
+#'
+#' @seealso [rm_log()]
+#'
+#' @importFrom stats setNames
 #'
-#' @return A data frame of timing logs.
 #' @export
-get_log <- function(log) {
-  if (exists(log, envir = .pipetime_env, inherits = FALSE)) {
-    get(log, envir = .pipetime_env)
+get_log <- function(log = NULL) {
+  logs <- setdiff(ls(envir = .pipetime_env), "start_times")
+  if (!length(logs)) {
+    return(list())
+  }
+
+  if (is.null(log)) {
+    # Return all logs
+    stats::setNames(
+      lapply(logs, function(x) get(x, envir = .pipetime_env)),
+      logs
+    )
   } else {
-    stop("No data frame named '", log, "' found in .pipetime_env.")
+    stopifnot(is.character(log), length(log) == 1)
+    if (!exists(log, envir = .pipetime_env, inherits = FALSE)) {
+      stop("No log named '", log, "' found in .pipetime_env.")
+    }
+    get(log, envir = .pipetime_env)
   }
 }

R/rm_log.R

@@ -1,17 +1,36 @@
-#' Remove a stored timing log
+#' Remove a timing log (or all logs)
 #'
-#' @param log Character. Name of the timing log to delete from `.pipetime_env`.
+#' Delete a timing log from `.pipetime_env`.
+#' If `log = NULL`, all logs are removed, but only when `force = TRUE`.
 #'
+#' @param log Character string or `NULL`. Name of the log to remove. If `NULL`, all logs are targeted.
+#' @param force Logical. To remove all logs, `force` must be `TRUE`. Default: `FALSE`.
+#'
+#' @return Invisibly, `TRUE`.
+#' @seealso [get_log()]
 #' @export
-rm_log <- function(log) {
-  if (!is.character(log) || length(log) != 1) {
-    stop("`log` must be a single character string.")
+rm_log <- function(log = NULL, force = FALSE) {
+  logs <- setdiff(ls(envir = .pipetime_env), "start_times")
+  if (!length(logs)) {
+    warning("No logs to remove.")
+    return(invisible(FALSE))
   }
-  if (exists(log, envir = .pipetime_env, inherits = FALSE)) {
-    rm(list = log, envir = .pipetime_env)
-    invisible(TRUE)
+
+  if (is.null(log)) {
+    if (!force) {
+      stop("To remove all logs, set force = TRUE.")
+    }
+    rm(list = logs, envir = .pipetime_env)
+    .pipetime_env$start_times <- list()
   } else {
-    warning("No data frame named '", log, "' found in pipetime environment.")
-    invisible(FALSE)
+    if (!is.character(log) || length(log) != 1) {
+      stop("`log` must be a single character string.")
+    }
+    if (!exists(log, envir = .pipetime_env, inherits = FALSE)) {
+      stop("No log named '", log, "' found in .pipetime_env.")
+    }
+    rm(list = log, envir = .pipetime_env)
+    .pipetime_env$start_times[[log]] <- NULL
   }
+  invisible(TRUE)
 }

R/time_pipe.R

@@ -1,19 +1,26 @@
 #' Measure execution time in a pipeline
 #'
-#' Records the runtime of pipeline (|>) operation.
-#' Can print the timing to the console and optionally log it to a data frame in `.pipetime_env`.
-#' Defaults can be set via `options()`.
+#' Records the runtime of a pipeline (`|>`) from its start to the point where `time_pipe()` is called.
+#' Prints results to the console and/or logs them in `.pipetime_env`.
+#' Defaults can be set via `options(pipetime.*)`.
 #'
 #' @param .data Input object passed through the pipeline.
-#' @param label Optional. Name for the operation. Defaults to the expression if not provided.
-#' @param log Character or NULL. Name of a data frame to store logs in `.pipetime_env`. Defaults to NULL (no storage).
-#' @param console Logical. Print timing to the console? Defaults to TRUE.
-#' @param unit Character. Time unit passed to [base::difftime()]. One of `"secs"`, `"mins"`, `"hours"`, `"days"`, or `"weeks"`. Defaults to `"secs"`.
+#' @param label Character string. Operation name. Defaults to the expression if `NULL`.
+#' @param log Character string or `NULL`. Name of a log data frame in `.pipetime_env`. Default: `NULL`.
+#' @param console Logical. Print timing to console? Default: `TRUE`.
+#' @param unit Character string. Time unit for [base::difftime()]. One of `"secs"`, `"mins"`, `"hours"`, `"days"`, `"weeks"`. Default: `"secs"`.
 #'
-#' @return The input object, unchanged. Timing information is printed or stored separately.
+#' @return `.data`, unchanged. Timing information is printed and/or stored separately.
 #'
 #' @details
-#' `time_pipe()` measures the elapsed time of the pipeline from its start to the point where `time_pipe()` is called.
+#' `time_pipe()` measures elapsed time from pipeline start to the call.
+#' If `log` is set, results are appended to a data frame in `.pipetime_env` with columns:
+#' - `timestamp`: Pipeline start time (`POSIXct`)
+#' - `label`: Operation label
+#' - `duration`: Elapsed time since pipeline start (`numeric`)
+#' - `unit`: Time unit used
+#'
+#' Stored logs can be retrieved with [get_log()].
 #'
 #' @examples
 #' library(dplyr)
@@ -24,29 +31,37 @@
 #' time_pipe("total pipeline")
 #'
 #' @export
-#'
 time_pipe <- function(
   .data,
   label = NULL,
   log = getOption("pipetime.log", NULL),
   console = getOption("pipetime.console", TRUE),
   unit = getOption("pipetime.unit", "secs")
 ) {
-  unit <- match.arg(
-    unit,
-    choices = c("secs", "mins", "hours", "days", "weeks")
-  )
+  # Track pipeline start
+  if (!is.null(log)) {
+    if (is.null(.pipetime_env$start_times[[log]])) {
+      .pipetime_env$start_times[[log]] <- Sys.time()
+      on.exit(.pipetime_env$start_times[[log]] <- NULL, add = TRUE)
+    }
+    start_time <- .pipetime_env$start_times[[log]]
+  } else {
+    start_time <- Sys.time()
+  }
 
-  start <- Sys.time()
+  # Force evaluation and calculate duration
   result <- .data
-  end <- Sys.time()
+  end_time <- Sys.time()
+  duration <- as.numeric(difftime(end_time, start_time, units = unit))
 
+  # Generate label if not provided
   if (is.null(label)) {
-    expr <- substitute(.data)
-    label <- gsub("\\s+", "", paste(deparse(expr), collapse = ""))
+    label <- paste(deparse(substitute(.data)), collapse = "")
+    label <- gsub("\\s+", " ", trimws(label))
   }
 
-  emit(start, end, label, unit, console, log)
+  # Output results
+  emit_time(start_time, duration, label, unit, console, log)
 
   result
 }

R/zzz.R

@@ -1 +1,3 @@
+# Environment for pipetime
 .pipetime_env <- new.env(parent = emptyenv())
+.pipetime_env$start_times <- list()

README.Rmd

@@ -9,62 +9,90 @@ knitr::opts_chunk$set(
 )
 ```
 
-# pipetime <img src="man/figures/logo.png" align="right" height="127"/>
+# pipetime <img src="man/figures/logo.png" align="right" height="136" alt="" />
+
 <!-- badges: start -->
-[![R-CMD-check](https://github.com/CyGei/pipetime/actions/workflows/R-CMD-check.yaml/badge.svg)](https://github.com/CyGei/pipetime/actions/workflows/R-CMD-check.yaml)
-[![CodeFactor](https://www.codefactor.io/repository/github/cygei/pipetime/badge)](https://www.codefactor.io/repository/github/cygei/pipetime)
+
+[![R-CMD-check](https://github.com/CyGei/pipetime/actions/workflows/R-CMD-check.yaml/badge.svg)](https://github.com/CyGei/pipetime/actions/workflows/R-CMD-check.yaml) [![CodeFactor](https://www.codefactor.io/repository/github/cygei/pipetime/badge)](https://www.codefactor.io/repository/github/cygei/pipetime)
+
 <!-- badges: end -->
 
-`pipetime` measures the runtime of a pipeline from its start up to the `time_pipe()` call. It works with the native R pipe (`|>`) and integrates seamlessly into '*tidy workflows*'.
+⏳ `pipetime` measures elapsed time in R pipelines.
+
+Insert `time_pipe()` anywhere in a pipeline to print or log the time since the pipeline started. It works with the native R pipe (`|>`) and fits naturally into [tidyverse](https://www.tidyverse.org/) workflows.
 
 # Installation
+
+Install from GitHub and load alongside `dplyr` for examples:
+
 ```{r setup, message=FALSE, warning=FALSE}
 # devtools::install_github("CyGei/pipetime")
 library(pipetime)
 library(dplyr)
 ```
 
 # Example
-Place `time_pipe()` anywhere in a pipeline to measure elapsed time from the start up to that point.
+
+Place `time_pipe()` at the end of a pipeline to measure total elapsed time:
+
 ```{r}
+slow_op <- function(delay, x) {
+  Sys.sleep(delay)  # Simulate a time-consuming operation
+  rnorm(n = length(x), mean = x, sd = 1)
+}
+
 data.frame(x = 1:3) |>
-  mutate(sleep = Sys.sleep(0.1)) |> # e.g. a complex operation
+  mutate(sleep = slow_op(0.1, x)) |>
   summarise(mean_x = mean(x)) |>
-  time_pipe("total pipeline") # ~0.1 sec
+  time_pipe("total pipeline") # ~+0.1 sec
 ```
 
-Insert multiple `time_pipe()` calls to add *timestamps* along the pipeline:
-```{r}
-complex_fn <- function(duration,x) {
-  Sys.sleep(duration)  # Simulate a time-consuming operation
-  rnorm(n = length(x), mean = x, sd = 1)
-}
+Use multiple `time_pipe()` calls to mark steps along a pipeline:
 
+```{r}
 data.frame(x = 1:5) |> 
-  mutate(y = complex_fn(0.5, x)) |>
+  mutate(y = slow_op(0.5, x)) |>
   time_pipe("compute y") |> 
-  mutate(z = complex_fn(0.5, y)) |> 
+  mutate(z = slow_op(0.5, y)) |> 
   time_pipe("compute z") |>
   summarise(mean_z = mean(z)) |>
   time_pipe("total pipeline")
 
 ```
 
-Each `time_pipe()` reports the cumulative time since the start of the pipeline.
+⏱️ **Each `time_pipe()` reports the cumulative time since the pipeline started.**
 
-# Logging to a dataframe
-Save timings to a dataframe in the package’s private environment (`.pipetime_env`) with the `log` argument:
-```{r}
-df_1 <- data.frame(x = 1:5) |> 
-  mutate(y = complex_fn(0.5, x)) |>
-  time_pipe("compute y", log = "timings")
+# Logging
+
+📝 Use `log` to save timings to a hidden environment (`.pipetime_env`):
 
-df_2 <- df_1 |> 
-  mutate(z = complex_fn(0.5, y)) |>
+```{r}
+df <- data.frame(x = 1:5) |> 
+  mutate(y = slow_op(0.5, x)) |>
+  time_pipe("compute y", log = "timings") |>
+  mutate(z = slow_op(0.5, y)) |>
   time_pipe("compute z", log = "timings")
 
 get_log("timings")
-rm_log("timings") # delete "timings" from .pipetime_env
+rm_log("timings") #delete the dataframe in .pipetime_env
 ```
 
-Set a global default for the session using: `options(pipetime.log = "timings")`.
+## Managing logs
+
+-   `get_log("name")` → return one log
+
+-   `get_log(NULL)` → return all logs as a named list
+
+-   `rm_log("name")` → remove one log
+
+-   `rm_log(NULL, force = TRUE)` → remove all logs
+
+# Options
+
+You can also set **session‑wide** defaults:
+
+```{r}
+options(pipetime.log = "timings",
+        pipetime.console = TRUE,
+        pipetime.unit = "secs")
+```