diff --git a/CLAUDE.md b/CLAUDE.md index eba106e55..0852e7cdd 100644 --- a/CLAUDE.md +++ b/CLAUDE.md @@ -18,10 +18,13 @@ General advice: - `devtools::test_file("tests/testthat/test-filename.R")` - Run tests in a specific file - DO NOT USE `devtools::test_active_file()` - `devtools::load_all()` - Load package for development -- `devtools::document()` - Generate documentation - `devtools::check()` - Run R CMD check - `devtools::install()` - Install package locally +### Documentation + +- Always run `devtools::document()` after changing any roxygen2 docs. + ## Core Architecture ### Main Components diff --git a/NAMESPACE b/NAMESPACE index 1d06507d0..ee6dcd8be 100644 --- a/NAMESPACE +++ b/NAMESPACE @@ -45,6 +45,7 @@ export(ProgressReporter) export(RStudioReporter) export(Reporter) export(SilentReporter) +export(SlowReporter) export(StopReporter) export(SummaryReporter) export(TapReporter) diff --git a/NEWS.md b/NEWS.md index b6076f438..c049ea22e 100644 --- a/NEWS.md +++ b/NEWS.md @@ -1,5 +1,6 @@ # testthat (development version) +* New `SlowReporter` makes it easier to find the slowest tests in your package. The easiest way to run it is with `devtools::test(reporter = "slow")` (#1466). * Power `expect_mapequal()` with `waldo::compare(list_as_map = TRUE)` (#1521). * On CRAN, `test_that()` now automatically skips if a package is not installed (#1585). Practically, this means that you no longer need to check that suggested packages are installed. (We don't do this in the tidyverse because we think it has limited payoff, but other styles advise differently.) * `expect_snapshot()` no longer skips on CRAN, as that skips the rest of the test. Instead it just returns, neither succeeding nor failing (#1585). diff --git a/R/reporter-slow.R b/R/reporter-slow.R new file mode 100644 index 000000000..26ea10c6a --- /dev/null +++ b/R/reporter-slow.R @@ -0,0 +1,106 @@ +#' Test reporter: show timings for slow tests +#' +#' @description +#' `SlowReporter` is designed to identify slow tests. It reports the +#' execution time for each test and can optionally filter out tests that +#' run faster than a specified threshold (default: 1 second). This reporter +#' is useful for performance optimization and identifying tests that may +#' benefit from optimization or parallelization. +#' +#' @export +#' @family reporters +SlowReporter <- R6::R6Class( + "SlowReporter", + inherit = Reporter, + public = list( + min_time = 0.5, + test_timings = NULL, + current_test_start = NULL, + current_file = NULL, + + initialize = function(min_time = 0.5, ...) { + super$initialize(...) + self$min_time <- min_time + self$test_timings <- list() + }, + + start_reporter = function(context) { + self$cat_line( + cli::style_bold("Slow tests"), + " (showing tests >= ", + self$min_time, + "s)" + ) + self$cat_line() + }, + + start_file = function(file) { + self$current_file <- file + }, + + start_test = function(context, test) { + self$current_test_start <- proc.time()[[3]] + }, + + end_test = function(context, test) { + if (is.null(self$current_test_start)) { + return() + } + + time_taken <- proc.time()[[3]] - self$current_test_start + + # Store timing information + timing <- list( + file = self$current_file, + test = test, + time = time_taken + ) + self$test_timings[[length(self$test_timings) + 1]] <- timing + + if (time_taken >= self$min_time) { + self$show_timing(timing) + } + + self$current_test_start <- NULL + }, + + end_reporter = function() { + if (length(self$test_timings) == 0) { + return() + } + + all_times <- map_dbl(self$test_timings, \(x) x$time) + is_slow <- all_times >= self$min_time + + self$cat_line() + self$rule(cli::style_bold("Summary"), line = 2) + self$cat_line("All tests: ", sprintf("%.2fs", sum(all_times))) + self$cat_line("Slow tests: ", sprintf("%.2fs", sum(all_times[is_slow]))) + + if (sum(is_slow) <= 10) { + return() + } + + # Sort by time descending for summary + slowest <- self$test_timings[order(all_times, decreasing = TRUE)] + + self$cat_line() + self$rule(cli::style_bold("Slowest tests:"), line = 1) + + # Show top 10 slowest tests + for (i in 1:10) { + self$show_timing(slowest[[i]]) + } + + if (length(slowest) > 10) { + self$cat_line("... and ", length(slowest) - 10, " more slow tests") + } + + self$cat_line() + }, + show_timing = function(timing) { + time <- sprintf("%.2fs", timing$time) + self$cat_line("[", time, "] ", time, " ", timing$file, ": ", timing$test) + } + ) +) diff --git a/R/reporter-timing.R b/R/reporter-timing.R new file mode 100644 index 000000000..84a89633e --- /dev/null +++ b/R/reporter-timing.R @@ -0,0 +1,99 @@ +#' Test reporter: show timings for slow tests +#' +#' @description +#' `SlowReporter` is designed to identify slow tests. It reports the +#' execution time for each test, ignoring tests faster than a specified +#' threshold (default: 0.5s). +#' +#' The easiest way to run it over your package is with +#' `devtools::test(reporter = "slow")`. +#' +#' @export +#' @family reporters +SlowReporter <- R6::R6Class( + "SlowReporter", + inherit = Reporter, + public = list( + min_time = NA_real_, + test_timings = NULL, + current_test_start = NULL, + current_file = NULL, + + initialize = function(min_time = 0.5, ...) { + check_number_decimal(min_time, min = 0) + + super$initialize(...) + self$min_time <- min_time + self$test_timings <- list() + }, + + start_file = function(file) { + self$current_file <- file + }, + + start_test = function(context, test) { + self$current_test_start <- proc.time()[[3]] + }, + + end_test = function(context, test) { + if (is.null(self$current_test_start)) { + return() + } + + time_taken <- proc.time()[[3]] - self$current_test_start + + # Store timing information + timing <- list( + file = self$current_file, + test = test, + time = time_taken + ) + self$test_timings[[length(self$test_timings) + 1]] <- timing + + if (time_taken >= self$min_time) { + self$show_timing(timing) + } + + self$current_test_start <- NULL + }, + + end_reporter = function() { + if (length(self$test_timings) == 0) { + return() + } + + all_times <- map_dbl(self$test_timings, \(x) x$time) + is_slow <- all_times >= self$min_time + + self$cat_line() + self$rule(cli::style_bold("Summary"), line = 2) + self$cat_line("All tests: ", sprintf("%.2fs", sum(all_times))) + self$cat_line("Slow tests: ", sprintf("%.2fs", sum(all_times[is_slow]))) + + if (sum(is_slow) <= 10) { + return() + } + + # Sort by time descending for summary + slowest <- self$test_timings[order(all_times, decreasing = TRUE)] + + self$cat_line() + self$rule(cli::style_bold("Slowest tests:"), line = 1) + + # Show top 10 slowest tests + for (i in 1:10) { + self$show_timing(slowest[[i]]) + } + + if (length(slowest) > 10) { + self$cat_line("... and ", length(slowest) - 10, " more slow tests") + } + + self$cat_line() + }, + show_timing = function(timing) { + time <- sprintf("%.2fs", timing$time) + self$cat_line("[", time, "] ", timing$file, ": ", timing$test) + } + ) +) diff --git a/man/CheckReporter.Rd b/man/CheckReporter.Rd index a32c58c3d..872f5c213 100644 --- a/man/CheckReporter.Rd +++ b/man/CheckReporter.Rd @@ -20,6 +20,7 @@ Other reporters: \code{\link{RStudioReporter}}, \code{\link{Reporter}}, \code{\link{SilentReporter}}, +\code{\link{SlowReporter}}, \code{\link{StopReporter}}, \code{\link{SummaryReporter}}, \code{\link{TapReporter}}, diff --git a/man/DebugReporter.Rd b/man/DebugReporter.Rd index 2ad10ba08..41693e314 100644 --- a/man/DebugReporter.Rd +++ b/man/DebugReporter.Rd @@ -20,6 +20,7 @@ Other reporters: \code{\link{RStudioReporter}}, \code{\link{Reporter}}, \code{\link{SilentReporter}}, +\code{\link{SlowReporter}}, \code{\link{StopReporter}}, \code{\link{SummaryReporter}}, \code{\link{TapReporter}}, diff --git a/man/FailReporter.Rd b/man/FailReporter.Rd index 1b9d0d2a7..2728512f6 100644 --- a/man/FailReporter.Rd +++ b/man/FailReporter.Rd @@ -21,6 +21,7 @@ Other reporters: \code{\link{RStudioReporter}}, \code{\link{Reporter}}, \code{\link{SilentReporter}}, +\code{\link{SlowReporter}}, \code{\link{StopReporter}}, \code{\link{SummaryReporter}}, \code{\link{TapReporter}}, diff --git a/man/JunitReporter.Rd b/man/JunitReporter.Rd index c822771ac..b89164afc 100644 --- a/man/JunitReporter.Rd +++ b/man/JunitReporter.Rd @@ -35,6 +35,7 @@ Other reporters: \code{\link{RStudioReporter}}, \code{\link{Reporter}}, \code{\link{SilentReporter}}, +\code{\link{SlowReporter}}, \code{\link{StopReporter}}, \code{\link{SummaryReporter}}, \code{\link{TapReporter}}, diff --git a/man/ListReporter.Rd b/man/ListReporter.Rd index dbcb62f77..60c0cd29b 100644 --- a/man/ListReporter.Rd +++ b/man/ListReporter.Rd @@ -21,6 +21,7 @@ Other reporters: \code{\link{RStudioReporter}}, \code{\link{Reporter}}, \code{\link{SilentReporter}}, +\code{\link{SlowReporter}}, \code{\link{StopReporter}}, \code{\link{SummaryReporter}}, \code{\link{TapReporter}}, diff --git a/man/LocationReporter.Rd b/man/LocationReporter.Rd index f0b5d86ca..494942357 100644 --- a/man/LocationReporter.Rd +++ b/man/LocationReporter.Rd @@ -21,6 +21,7 @@ Other reporters: \code{\link{RStudioReporter}}, \code{\link{Reporter}}, \code{\link{SilentReporter}}, +\code{\link{SlowReporter}}, \code{\link{StopReporter}}, \code{\link{SummaryReporter}}, \code{\link{TapReporter}}, diff --git a/man/MinimalReporter.Rd b/man/MinimalReporter.Rd index 5365d7e46..26561b621 100644 --- a/man/MinimalReporter.Rd +++ b/man/MinimalReporter.Rd @@ -22,6 +22,7 @@ Other reporters: \code{\link{RStudioReporter}}, \code{\link{Reporter}}, \code{\link{SilentReporter}}, +\code{\link{SlowReporter}}, \code{\link{StopReporter}}, \code{\link{SummaryReporter}}, \code{\link{TapReporter}}, diff --git a/man/MultiReporter.Rd b/man/MultiReporter.Rd index bb5d9cb34..f35575b6b 100644 --- a/man/MultiReporter.Rd +++ b/man/MultiReporter.Rd @@ -20,6 +20,7 @@ Other reporters: \code{\link{RStudioReporter}}, \code{\link{Reporter}}, \code{\link{SilentReporter}}, +\code{\link{SlowReporter}}, \code{\link{StopReporter}}, \code{\link{SummaryReporter}}, \code{\link{TapReporter}}, diff --git a/man/ProgressReporter.Rd b/man/ProgressReporter.Rd index be63cf3b4..6a1ba4ba8 100644 --- a/man/ProgressReporter.Rd +++ b/man/ProgressReporter.Rd @@ -31,6 +31,7 @@ Other reporters: \code{\link{RStudioReporter}}, \code{\link{Reporter}}, \code{\link{SilentReporter}}, +\code{\link{SlowReporter}}, \code{\link{StopReporter}}, \code{\link{SummaryReporter}}, \code{\link{TapReporter}}, diff --git a/man/RStudioReporter.Rd b/man/RStudioReporter.Rd index a25c39f9d..9a8e8ffcf 100644 --- a/man/RStudioReporter.Rd +++ b/man/RStudioReporter.Rd @@ -20,6 +20,7 @@ Other reporters: \code{\link{ProgressReporter}}, \code{\link{Reporter}}, \code{\link{SilentReporter}}, +\code{\link{SlowReporter}}, \code{\link{StopReporter}}, \code{\link{SummaryReporter}}, \code{\link{TapReporter}}, diff --git a/man/Reporter.Rd b/man/Reporter.Rd index eeb7a0ab2..891c58987 100644 --- a/man/Reporter.Rd +++ b/man/Reporter.Rd @@ -36,6 +36,7 @@ Other reporters: \code{\link{ProgressReporter}}, \code{\link{RStudioReporter}}, \code{\link{SilentReporter}}, +\code{\link{SlowReporter}}, \code{\link{StopReporter}}, \code{\link{SummaryReporter}}, \code{\link{TapReporter}}, diff --git a/man/SilentReporter.Rd b/man/SilentReporter.Rd index dde2f9641..5da9f8b82 100644 --- a/man/SilentReporter.Rd +++ b/man/SilentReporter.Rd @@ -22,6 +22,7 @@ Other reporters: \code{\link{ProgressReporter}}, \code{\link{RStudioReporter}}, \code{\link{Reporter}}, +\code{\link{SlowReporter}}, \code{\link{StopReporter}}, \code{\link{SummaryReporter}}, \code{\link{TapReporter}}, diff --git a/man/SlowReporter.Rd b/man/SlowReporter.Rd new file mode 100644 index 000000000..4897e6e36 --- /dev/null +++ b/man/SlowReporter.Rd @@ -0,0 +1,57 @@ +% Generated by roxygen2: do not edit by hand +% Please edit documentation in R/reporter-slow.R, R/reporter-timing.R +\name{SlowReporter} +\alias{SlowReporter} +\title{Test reporter: show timings for slow tests} +\description{ +\code{SlowReporter} is designed to identify slow tests. It reports the +execution time for each test and can optionally filter out tests that +run faster than a specified threshold (default: 1 second). This reporter +is useful for performance optimization and identifying tests that may +benefit from optimization or parallelization. + +\code{SlowReporter} is designed to identify slow tests. It reports the +execution time for each test, ignoring tests faster than a specified +threshold (default: 0.5s). + +The easiest way to run it over your package is with +\code{devtools::test(reporter = "slow")}. +} +\seealso{ +Other reporters: +\code{\link{CheckReporter}}, +\code{\link{DebugReporter}}, +\code{\link{FailReporter}}, +\code{\link{JunitReporter}}, +\code{\link{ListReporter}}, +\code{\link{LocationReporter}}, +\code{\link{MinimalReporter}}, +\code{\link{MultiReporter}}, +\code{\link{ProgressReporter}}, +\code{\link{RStudioReporter}}, +\code{\link{Reporter}}, +\code{\link{SilentReporter}}, +\code{\link{StopReporter}}, +\code{\link{SummaryReporter}}, +\code{\link{TapReporter}}, +\code{\link{TeamcityReporter}} + +Other reporters: +\code{\link{CheckReporter}}, +\code{\link{DebugReporter}}, +\code{\link{FailReporter}}, +\code{\link{JunitReporter}}, +\code{\link{ListReporter}}, +\code{\link{LocationReporter}}, +\code{\link{MinimalReporter}}, +\code{\link{MultiReporter}}, +\code{\link{ProgressReporter}}, +\code{\link{RStudioReporter}}, +\code{\link{Reporter}}, +\code{\link{SilentReporter}}, +\code{\link{StopReporter}}, +\code{\link{SummaryReporter}}, +\code{\link{TapReporter}}, +\code{\link{TeamcityReporter}} +} +\concept{reporters} diff --git a/man/StopReporter.Rd b/man/StopReporter.Rd index 53d5f41f5..3d5850935 100644 --- a/man/StopReporter.Rd +++ b/man/StopReporter.Rd @@ -27,6 +27,7 @@ Other reporters: \code{\link{RStudioReporter}}, \code{\link{Reporter}}, \code{\link{SilentReporter}}, +\code{\link{SlowReporter}}, \code{\link{SummaryReporter}}, \code{\link{TapReporter}}, \code{\link{TeamcityReporter}} diff --git a/man/SummaryReporter.Rd b/man/SummaryReporter.Rd index 149182127..0ebbe2e66 100644 --- a/man/SummaryReporter.Rd +++ b/man/SummaryReporter.Rd @@ -30,6 +30,7 @@ Other reporters: \code{\link{RStudioReporter}}, \code{\link{Reporter}}, \code{\link{SilentReporter}}, +\code{\link{SlowReporter}}, \code{\link{StopReporter}}, \code{\link{TapReporter}}, \code{\link{TeamcityReporter}} diff --git a/man/TapReporter.Rd b/man/TapReporter.Rd index 6c8a680e0..1ac66f545 100644 --- a/man/TapReporter.Rd +++ b/man/TapReporter.Rd @@ -22,6 +22,7 @@ Other reporters: \code{\link{RStudioReporter}}, \code{\link{Reporter}}, \code{\link{SilentReporter}}, +\code{\link{SlowReporter}}, \code{\link{StopReporter}}, \code{\link{SummaryReporter}}, \code{\link{TeamcityReporter}} diff --git a/man/TeamcityReporter.Rd b/man/TeamcityReporter.Rd index f2b2b79de..088fcad79 100644 --- a/man/TeamcityReporter.Rd +++ b/man/TeamcityReporter.Rd @@ -22,6 +22,7 @@ Other reporters: \code{\link{RStudioReporter}}, \code{\link{Reporter}}, \code{\link{SilentReporter}}, +\code{\link{SlowReporter}}, \code{\link{StopReporter}}, \code{\link{SummaryReporter}}, \code{\link{TapReporter}} diff --git a/tests/testthat/_snaps/reporter-slow.md b/tests/testthat/_snaps/reporter-slow.md new file mode 100644 index 000000000..a4e171c45 --- /dev/null +++ b/tests/testthat/_snaps/reporter-slow.md @@ -0,0 +1,21 @@ +# multiplication works + + Code + show_all <- SlowReporter$new(min_time = 0) + with_reporter(show_all, n_tests(10)) + Output + [-.--s] : run 1 + [-.--s] : run 2 + [-.--s] : run 3 + [-.--s] : run 4 + [-.--s] : run 5 + [-.--s] : run 6 + [-.--s] : run 7 + [-.--s] : run 8 + [-.--s] : run 9 + [-.--s] : run 10 + + == Summary ===================================================================== + All tests: -.--s + Slow tests: -.--s + diff --git a/tests/testthat/test-reporter-slow.R b/tests/testthat/test-reporter-slow.R new file mode 100644 index 000000000..64e2f63ec --- /dev/null +++ b/tests/testthat/test-reporter-slow.R @@ -0,0 +1,16 @@ +test_that("multiplication works", { + n_tests <- function(n) { + for (i in 1:n) { + test_that(paste0("run ", i), { + suceed() + }) + } + } + expect_snapshot( + { + show_all <- SlowReporter$new(min_time = 0) + with_reporter(show_all, n_tests(10)) + }, + transform = \(x) gsub("\\d.\\d\\ds", "-.--s", x), + ) +})