Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Better output for multiple (failing) tests with --as-cran #162

Merged
merged 2 commits into from
Sep 21, 2021
Merged

Better output for multiple (failing) tests with --as-cran #162

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
2 commits
Select commit Hold shift + click to select a range
1aecf69
Better output for multiple (failing) tests with --as-cran
gaborcsardi Sep 21, 2021
42d299e
Test case for output of multiple test files
gaborcsardi Sep 21, 2021
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
52 changes: 25 additions & 27 deletions R/callback.R
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -7,7 +7,10 @@
#' @importFrom utils head tail
#' @importFrom prettyunits pretty_dt

block_callback <- function(top_line = TRUE, sys_time = NULL) {
block_callback <- function(
top_line = TRUE,
sys_time = NULL,
as_cran = NA) {

sys_time <- sys_time %||% Sys.time
partial_line <- ""
Expand Down Expand Up @@ -99,26 +102,6 @@ block_callback <- function(top_line = TRUE, sys_time = NULL) {
}
}

## The output from the tests is a bit messed up, especially if we
## want to process it line by line.
## The tests start with '* checking test ...\n' and then when a test
## file starts running we see sg like ' Running 'testthat.R''
## This is without the newline character.
##
## The first test file that errors out will stop the tests entirely.
##
## When a test file is done, we get a '\n', and then either the next one
## is started with another ' Running ...' line (without \n), or they are
## done completely, and we get a '\n' and ' ERROR\n' / ' OK\n' depending
## on the result.
##
## So the tricky thing is, we can only update a 'Running ' line after
## we already know what is in the next line. If the next line is ' ERROR',
## then the test file failed, otherwise succeeded. So we also do the actual
## updating based on the ' Running' partial lines.
##
## As usually, prev_line contains the previous line.

do_test_mode <- function(x) {
## Maybe we just learned the result of the current test file
if (test_running) {
Expand All @@ -132,7 +115,14 @@ block_callback <- function(top_line = TRUE, sys_time = NULL) {
## Tests are over, error
state <<- "ERROR"
test_running <<- FALSE
xx <- style(err = "E", pale = no(prev_line))
if (isTRUE(as_cran)) {
xp <- style(pale = symbol$line, pale = no(prev_line))
xp <- style(xp, timing = time_if_long())
cat(xp, "\n", sep = "")
xx <- style(err = "E", pale = " Some test files failed")
} else {
xx <- style(err = "E", pale = no(prev_line))
}
xx <- style(xx, timing = time_if_long())
} else if (grepl("^\\s+Comparing", x)) {
## Comparison
Expand All @@ -141,7 +131,11 @@ block_callback <- function(top_line = TRUE, sys_time = NULL) {
xx <- style(xx, timing = time_if_long())
} else if (grepl("^\\s+Running", x)) {
## Next test is running now, state unchanged
xx <- style(ok = symbol$tick, pale = no(prev_line))
if (isTRUE(as_cran)) {
xx <- style(pale = symbol$line, pale = no(prev_line))
} else {
xx <- style(ok = symbol$tick, pale = no(prev_line))
}
xx <- style(xx, timing = time_if_long())
now <<- sys_time()
} else {
Expand Down Expand Up @@ -190,7 +184,11 @@ block_callback <- function(top_line = TRUE, sys_time = NULL) {
if (grepl("^\\s+Running ", x) || grepl("^\\s+Comparing", x)) {
test_running <<- FALSE
if (grepl("^\\s+Running ", x)) {
xx <- style(ok = symbol$tick, pale = no(prev_line))
if (isTRUE(as_cran)) {
xx <- style(pale = symbol$line, pale = no(prev_line))
} else {
xx <- style(ok = symbol$tick, pale = no(prev_line))
}
xx <- style(xx, timing = time_if_long())
} else {
xx <- style(ok = symbol$tick, pale = prev_line)
Expand Down Expand Up @@ -224,14 +222,14 @@ is_new_check <- function(x) {
grepl("^\\*\\*? ", x)
}

simple_callback <- function(top_line = TRUE, sys_time = NULL) {
simple_callback <- function(top_line = TRUE, sys_time = NULL, ...) {
function(x) cat(gsub("[\r\n]+", "\n", x, useBytes = TRUE))
}

#' @importFrom cli is_dynamic_tty

detect_callback <- function() {
if (cli::is_dynamic_tty()) block_callback() else simple_callback()
detect_callback <- function(...) {
if (cli::is_dynamic_tty()) block_callback(...) else simple_callback(...)
}

should_add_spinner <- function() {
Expand Down
2 changes: 1 addition & 1 deletion R/package.R
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -208,7 +208,7 @@ do_check <- function(targz, package, args, libpath, repos,
user_profile = TRUE,
repos = repos,
stderr = "2>&1",
block_callback = if (!quiet) detect_callback(),
block_callback = if (!quiet) detect_callback(as_cran = "--as-cran" %in% args),
spinner = !quiet && should_add_spinner(),
timeout = timeout,
fail_on_status = FALSE
Expand Down
38 changes: 38 additions & 0 deletions tests/testthat/_snaps/callback.md
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -532,3 +532,41 @@
[71] ""
[72] "Status: OK"

# multiple tests

Code
out
Output
[1] " \r- checking examples ... NONE"
[2] "\r \rv checking for unstated dependencies in ‘tests’"
[3] "\r \r- checking tests"
[4] "\r \r\r \r- Running ‘a.R’"
[5] "\r \r- Running ‘b.R’"
[6] "\r \r- Running ‘c.R’"
[7] "E Some test files failed"
[8] "\r \r Running the tests in ‘tests/b.R’ failed."
[9] "\r \r Complete output:"
[10] "\r \r > stop(\"error\")"
[11] "\r \r Error: error"
[12] "\r \r Execution halted"
[13] "\r \rv checking PDF version of manual"
[14] "\r"

---

Code
out
Output
[1] " \r- checking examples ... NONE"
[2] "\r \rv checking for unstated dependencies in ‘tests’"
[3] "\r \r- checking tests"
[4] "\r \r\r \rv Running ‘a.R’"
[5] "\r \rE Running ‘b.R’"
[6] "\r \r Running the tests in ‘tests/b.R’ failed."
[7] "\r \r Complete output:"
[8] "\r \r > stop(\"error\")"
[9] "\r \r Error: error"
[10] "\r \r Execution halted"
[11] "\r \rv checking PDF version of manual"
[12] "\r"

13 changes: 13 additions & 0 deletions tests/testthat/fixtures/tests-as-cran.txt
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -0,0 +1,13 @@
* checking examples ... NONE
* checking for unstated dependencies in ‘tests’ ... OK
* checking tests ...
Running ‘a.R’
Running ‘b.R’
Running ‘c.R’
ERROR
Running the tests in ‘tests/b.R’ failed.
Complete output:
> stop("error")
Error: error
Execution halted
* checking PDF version of manual ... OK
12 changes: 12 additions & 0 deletions tests/testthat/fixtures/tests-not-as-cran.txt
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -0,0 +1,12 @@
* checking examples ... NONE
* checking for unstated dependencies in ‘tests’ ... OK
* checking tests ...
Running ‘a.R’
Running ‘b.R’
ERROR
Running the tests in ‘tests/b.R’ failed.
Complete output:
> stop("error")
Error: error
Execution halted
* checking PDF version of manual ... OK
21 changes: 17 additions & 4 deletions tests/testthat/test-callback.R
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -127,7 +127,7 @@ test_that("multiple test file run times are measured properly", {

test_that("multi-arch test cases", {
txt <- list(
list("* using log directory 'C:/Users/csard/works/ps.Rcheck'\n", 0.01),
list("* using log directory 'C:/Users/csard/works/ps.Rcheck'\n", 0.01),
list("* using R version 4.1.1 (2021-08-10)\n", 0.01),
list("* using platform: x86_64-w64-mingw32 (64-bit)\n", 0.01),
list("* using session charset: ISO8859-1\n", 0.01),
Expand Down Expand Up @@ -173,7 +173,7 @@ test_that("partial comparing line", {
list(" Comparing ‘test-2.Rout’ to ‘test-2.Rout.save’ ... OK\n", 0),
list(" OK\n", 0.01),
list("* checking PDF version of manual ... OK\n", 0.01),
list("* DONE\n", 0.01)
list("* DONE\n", 0.01)
)

out <- capture.output(replay(lines))
Expand All @@ -184,7 +184,7 @@ test_that("multiple comparing blocks", {
txt <- readLines(test_path("fixtures", "checks", "comparing2.txt"))[53:88]
lines <- lapply(txt, function(x) list(paste0(x, "\n"), 0.001))
out <- capture.output(replay(lines))
expect_snapshot(out)
expect_snapshot(out)
})

test_that("simple_callback", {
Expand All @@ -200,7 +200,7 @@ test_that("detect_callback", {

withr::local_options(cli.dynamic = TRUE)
expect_equal(detect_callback(), "block")

withr::local_options(cli.dynamic = FALSE)
expect_equal(detect_callback(), "simple")
})
Expand All @@ -211,3 +211,16 @@ test_that("should_add_spinner", {
withr::local_options(cli.dynamic = FALSE)
expect_false(should_add_spinner())
})

test_that("multiple tests", {
txt <- readLines(test_path("fixtures", "tests-as-cran.txt"))
lines <- lapply(txt, function(x) list(paste0(x, "\n"), 0.001))
cb <- function(...) block_callback(as_cran = TRUE, ...)
out <- capture.output(replay(lines, callback = cb))
expect_snapshot(out)

txt <- readLines(test_path("fixtures", "tests-not-as-cran.txt"))
lines <- lapply(txt, function(x) list(paste0(x, "\n"), 0.001))
out <- capture.output(replay(lines))
expect_snapshot(out)
})