Catch tests reported multiple times

[hsloot]

Catch test results are (sometimes) reported multiple times. The aggregated number of passed tests seems correct, though.

For reasons, I could not identify, the reprex output was different that the interactive output. For completeness the ProgressReporter output in interactive mode was:

#> Loading testcatch
#> Testing testcatch
#> ✓ |  OK F W S | Context
#> ✓ |   1       | Sample unit tests (copy)                                                                                        
#> ✓ |   1       | Sample unit tests                                                                                               
#> ✓ |   1       | Sample unit tests
#> 
#> ══ Results ═════════════════════════════════════════════════════════════════════════════════════════════════════════════════════
#> [ FAIL 0 | WARN 0 | SKIP 0 | PASS 2 ]
#> 
#> 😀

I also used the ListReporter which did not have the same behaviour and contained the correct number of tests.

Reprex

tmp <- tempdir()
setwd(tmp)
usethis::create_package("testcatch", open=FALSE)
#> ✓ Creating 'testcatch/'
#> ✓ Setting active project to '/private/var/folders/29/_qzzdhnn75780wtf8805n85w0000gn/T/Rtmpj1Yw5H/testcatch'
#> ✓ Creating 'R/'
#> ✓ Writing 'DESCRIPTION'
#> Package: testcatch
#> Title: What the Package Does (One Line, Title Case)
#> Version: 0.0.0.9000
#> Authors@R (parsed):
#>     * First Last <first.last@example.com> [aut, cre] (YOUR-ORCID-ID)
#> Description: What the package does (one paragraph).
#> License: `use_mit_license()`, `use_gpl3_license()` or friends to pick a
#>     license
#> Encoding: UTF-8
#> LazyData: true
#> Roxygen: list(markdown = TRUE)
#> RoxygenNote: 7.1.1
#> ✓ Writing 'NAMESPACE'
#> ✓ Setting active project to '<no active project>'
setwd("testcatch")

usethis::use_rcpp()
#> ✓ Setting active project to '/private/var/folders/29/_qzzdhnn75780wtf8805n85w0000gn/T/Rtmpj1Yw5H/testcatch'
#> ✓ Creating 'src/'
#> ✓ Adding '*.o', '*.so', '*.dll' to 'src/.gitignore'
#> ● Copy and paste the following lines into '/private/var/folders/29/_qzzdhnn75780wtf8805n85w0000gn/T/Rtmpj1Yw5H/testcatch/R/testcatch-package.R':
#>   ## usethis namespace: start
#>   #' @useDynLib testcatch, .registration = TRUE
#>   ## usethis namespace: end
#>   NULL
#> ✓ Adding 'Rcpp' to LinkingTo field in DESCRIPTION
#> ✓ Adding 'Rcpp' to Imports field in DESCRIPTION
#> ● Copy and paste the following lines into '/private/var/folders/29/_qzzdhnn75780wtf8805n85w0000gn/T/Rtmpj1Yw5H/testcatch/R/testcatch-package.R':
#>   ## usethis namespace: start
#>   #' @importFrom Rcpp sourceCpp
#>   ## usethis namespace: end
#>   NULL
#> ✓ Writing 'src/code.cpp'
usethis::use_testthat()
#> ✓ Adding 'testthat' to Suggests field in DESCRIPTION
#> ✓ Creating 'tests/testthat/'
#> ✓ Writing 'tests/testthat.R'
#> ● Call `use_test()` to initialize a basic test file and open it for editing.
testthat::use_catch()
#> > Added C++ unit testing infrastructure.
#> > Please ensure you have 'LinkingTo: testthat' in your DESCRIPTION.
#> > Please ensure you have 'useDynLib(testcatch, .registration = TRUE)' in your NAMESPACE.
writeLines("## usethis namespace: start\n#' @useDynLib testcatch, .registration = TRUE\n#' @importFrom Rcpp sourceCpp\n## usethis namespace: end\nNULL", con = "R/testcatch-package.R")
usethis::use_package("testthat", type = "LinkingTo")
#> ✓ Adding 'testthat' to LinkingTo field in DESCRIPTION
#> ● Possible includes are:
#>   #include <testthat.h>
usethis::use_package("xml2", type = "Suggests")
#> ✓ Adding 'xml2' to Suggests field in DESCRIPTION
#> ● Use `requireNamespace("xml2", quietly = TRUE)` to test if package is installed
#> ● Then directly refer to functons like `xml2::fun()` (replacing `fun()`).

# Copy and slightly modify test-example
invisible(file.copy("src/test-example.cpp", "src/test-example-copy.cpp"))
file_content <- readLines("src/test-example-copy.cpp")
file_content <- gsub("Sample unit tests", "Sample unit tests (copy)", file_content)
file_content <- gsub("twoPlusTwo", "twoPlusTwoCopy", file_content)
file_content <- gsub("two plus two equals four", "two plus two equals four (copy)", file_content)
cat(file_content, file="src/test-example-copy.cpp", sep ="\n")

devtools::document()
#> Updating testcatch documentation
#> Loading testcatch
#> Re-compiling testcatch
#>   ─  installing *source* package ‘testcatch’ ... (619ms)
#>      ** using staged installation
#>      ** libs
#>      clang++ -std=gnu++11 -I"/usr/local/Cellar/r/4.0.3/lib/R/include" -DNDEBUG  -I'/usr/local/lib/R/4.0/site-library/Rcpp/include' -I'/usr/local/lib/R/4.0/site-library/testthat/include' -I/usr/local/opt/gettext/include -I/usr/local/opt/readline/include -I/usr/local/include  -O3 -Wall -pedantic -pipe -Weffc++ -fPIC  -g -O2  -c code.cpp -o code.o
#>      clang++ -std=gnu++11 -I"/usr/local/Cellar/r/4.0.3/lib/R/include" -DNDEBUG  -I'/usr/local/lib/R/4.0/site-library/Rcpp/include' -I'/usr/local/lib/R/4.0/site-library/testthat/include' -I/usr/local/opt/gettext/include -I/usr/local/opt/readline/include -I/usr/local/include  -O3 -Wall -pedantic -pipe -Weffc++ -fPIC  -g -O2  -c test-example-copy.cpp -o test-example-copy.o
#>      clang++ -std=gnu++11 -I"/usr/local/Cellar/r/4.0.3/lib/R/include" -DNDEBUG  -I'/usr/local/lib/R/4.0/site-library/Rcpp/include' -I'/usr/local/lib/R/4.0/site-library/testthat/include' -I/usr/local/opt/gettext/include -I/usr/local/opt/readline/include -I/usr/local/include  -O3 -Wall -pedantic -pipe -Weffc++ -fPIC  -g -O2  -c test-example.cpp -o test-example.o
#>      clang++ -std=gnu++11 -I"/usr/local/Cellar/r/4.0.3/lib/R/include" -DNDEBUG  -I'/usr/local/lib/R/4.0/site-library/Rcpp/include' -I'/usr/local/lib/R/4.0/site-library/testthat/include' -I/usr/local/opt/gettext/include -I/usr/local/opt/readline/include -I/usr/local/include  -O3 -Wall -pedantic -pipe -Weffc++ -fPIC  -g -O2  -c test-runner.cpp -o test-runner.o
#>      clang++ -std=gnu++11 -dynamiclib -Wl,-headerpad_max_install_names -undefined dynamic_lookup -single_module -multiply_defined suppress -L/usr/local/Cellar/r/4.0.3/lib/R/lib -L/usr/local/opt/gettext/lib -L/usr/local/opt/readline/lib -L/usr/local/lib -o testcatch.so code.o test-example-copy.o test-example.o test-runner.o -L/usr/local/Cellar/r/4.0.3/lib/R/lib -lR -lintl -Wl,-framework -Wl,CoreFoundation
#>      installing to /private/var/folders/29/_qzzdhnn75780wtf8805n85w0000gn/T/Rtmpj1Yw5H/devtools_install_636d240ae2be/00LOCK-testcatch/00new/testcatch/libs
#>      ** checking absolute paths in shared objects and dynamic libraries
#>   ─  DONE (testcatch) (672ms)
#> Writing NAMESPACE
devtools::test(reporter=testthat::ProgressReporter)
#> Loading testcatch
#> Testing testcatch
#> ✓ |  OK F W S | Context
#> ⠏ |   0       | cpp                                                             ✓ |   1       | Sample unit tests (copy)
#> ⠏ |   0       | Sample unit tests                                               ✓ |   1       | Sample unit tests
#> ✓ |   1       | Sample unit tests
#> 
#> ══ Results ═════════════════════════════════════════════════════════════════════
#> [ FAIL 0 | WARN 0 | SKIP 0 | PASS 2 ]

^{Created on 2020-11-17 by the reprex package (v0.3.0)}

Session info

devtools::session_info()
#> ─ Session info ───────────────────────────────────────────────────────────────
#>  setting  value                       
#>  version  R version 4.0.3 (2020-10-10)
#>  os       macOS Catalina 10.15.7      
#>  system   x86_64, darwin19.6.0        
#>  ui       unknown                     
#>  language (EN)                        
#>  collate  de_DE.UTF-8                 
#>  ctype    de_DE.UTF-8                 
#>  tz       Europe/Berlin               
#>  date     2020-11-17                  
#> 
#> ─ Packages ───────────────────────────────────────────────────────────────────
#>  ! package     * version    date       lib source        
#>    assertthat    0.2.1      2019-03-21 [1] CRAN (R 4.0.0)
#>    callr         3.5.1      2020-10-13 [1] CRAN (R 4.0.3)
#>    cli           2.1.0      2020-10-12 [1] CRAN (R 4.0.3)
#>    crayon        1.3.4      2017-09-16 [1] CRAN (R 4.0.0)
#>    desc          1.2.0      2018-05-01 [1] CRAN (R 4.0.0)
#>    devtools      2.3.2      2020-09-18 [1] CRAN (R 4.0.2)
#>    digest        0.6.27     2020-10-24 [1] CRAN (R 4.0.3)
#>    ellipsis      0.3.1      2020-05-15 [1] CRAN (R 4.0.0)
#>    evaluate      0.14       2019-05-28 [1] CRAN (R 4.0.0)
#>    fansi         0.4.1      2020-01-08 [1] CRAN (R 4.0.0)
#>    fs            1.5.0      2020-07-31 [1] CRAN (R 4.0.2)
#>    git2r         0.27.1     2020-05-03 [1] CRAN (R 4.0.0)
#>    glue          1.4.2      2020-08-27 [1] CRAN (R 4.0.2)
#>    highr         0.8        2019-03-20 [1] CRAN (R 4.0.0)
#>    htmltools     0.5.0      2020-06-16 [1] CRAN (R 4.0.2)
#>    knitr         1.30       2020-09-22 [1] CRAN (R 4.0.3)
#>    lifecycle     0.2.0      2020-03-06 [1] CRAN (R 4.0.0)
#>    magrittr      1.5        2014-11-22 [1] CRAN (R 4.0.0)
#>    memoise       1.1.0      2017-04-21 [1] CRAN (R 4.0.0)
#>    pillar        1.4.6      2020-07-10 [1] CRAN (R 4.0.2)
#>    pkgbuild      1.1.0      2020-07-13 [1] CRAN (R 4.0.2)
#>    pkgconfig     2.0.3      2019-09-22 [1] CRAN (R 4.0.0)
#>    pkgload       1.1.0      2020-05-29 [1] CRAN (R 4.0.1)
#>    prettyunits   1.1.1      2020-01-24 [1] CRAN (R 4.0.0)
#>    processx      3.4.4      2020-09-03 [1] CRAN (R 4.0.2)
#>    ps            1.4.0      2020-10-07 [1] CRAN (R 4.0.3)
#>    purrr         0.3.4      2020-04-17 [1] CRAN (R 4.0.0)
#>    R6            2.5.0      2020-10-28 [1] CRAN (R 4.0.3)
#>    Rcpp          1.0.5      2020-07-06 [1] CRAN (R 4.0.2)
#>    remotes       2.2.0      2020-07-21 [1] CRAN (R 4.0.2)
#>    rlang         0.4.8      2020-10-08 [1] CRAN (R 4.0.3)
#>    rmarkdown     2.5        2020-10-21 [1] CRAN (R 4.0.3)
#>    roxygen2      7.1.1      2020-06-27 [1] CRAN (R 4.0.2)
#>    rprojroot     2.0.2      2020-11-15 [1] CRAN (R 4.0.3)
#>    rstudioapi    0.13       2020-11-12 [1] CRAN (R 4.0.3)
#>    sessioninfo   1.1.1      2018-11-05 [1] CRAN (R 4.0.0)
#>    stringi       1.5.3      2020-09-09 [1] CRAN (R 4.0.2)
#>    stringr       1.4.0      2019-02-10 [1] CRAN (R 4.0.0)
#>  R testcatch   * 0.0.0.9000 <NA>       [?] <NA>          
#>    testthat    * 3.0.0      2020-10-31 [1] CRAN (R 4.0.3)
#>    tibble        3.0.4      2020-10-12 [1] CRAN (R 4.0.3)
#>    usethis       1.6.3      2020-09-17 [1] CRAN (R 4.0.2)
#>    vctrs         0.3.5      2020-11-17 [1] CRAN (R 4.0.3)
#>    whisker       0.4        2019-08-28 [1] CRAN (R 4.0.0)
#>    withr         2.3.0      2020-09-22 [1] CRAN (R 4.0.3)
#>    xfun          0.19       2020-10-30 [1] CRAN (R 4.0.3)
#>    xml2          1.3.2      2020-04-23 [1] CRAN (R 4.0.3)
#>    yaml          2.2.1      2020-02-01 [1] CRAN (R 4.0.0)
#> 
#> [1] /usr/local/lib/R/4.0/site-library
#> [2] /usr/local/Cellar/r/4.0.3/lib/R/library
#> 
#>  R ── Package was removed from disk.

[hsloot]

The cause of this behaviour for ProgressReporter seems to be that end_context does not properly clean up the internal state of the reporter and assumes that it is not called another time before start_context is called again (which resets the internal values). Thus when end_context_if_started is called, end_context invokes again show_status with complete=TRUE which prints the last line one more time.

I am not familiar enough with the internals to see if that breaks something else, but the following solved it for me:

start_context = function(context) {
+      ## conditionally end context 
+      if (!("" == self$ctxt_name)) {
+        self$end_context(self$ctxt_name)
+      }
      self$ctxt_name <- context
      self$ctxt_issues <- Stack$new()

-      self$ctxt_n <- 0L
-      self$ctxt_n_ok <- 0L
-      self$ctxt_n_fail <- 0L
-      self$ctxt_n_warn <- 0L
-      self$ctxt_n_skip <- 0L
...
}

...

end_context = function(context) {
      time <- proc.time() - self$ctxt_start_time
      self$last_update <- NULL

      # context with no expectation = automatic file context in file
      # that also has manual contexts
      if (self$ctxt_n == 0) {
        return()
      }

      self$show_status(complete = TRUE, time = time[[3]])

+      ## cleanup after we leave context
+      self$ctxt_name <- ""
+      self$ctxt_n <- 0L
+      self$ctxt_n_ok <- 0L
+      self$ctxt_n_fail <- 0L
+      self$ctxt_n_warn <- 0L
+      self$ctxt_n_skip <- 0L

...
}

[hadley]

@jimhester could you take a look please?

[hadley]

run_tests_rcpp() probably needs to call context_start()