Usual Suspects for specific failure modes

[jennybc]

Tests that pass during devtools::test() but then fail during devtools::check()

One cause: files present in source package but that match one of the criteria for auto-Rbuildignore and, therefore, aren't present when tests run at the end of R CMD check.

In addition, directories from source control systems or from eclipse, directories with names ending .Rcheck or Old or old and files GNUMakefile, Read-and-delete-me or with base names starting with ‘.#’, or starting and ending with ‘#’, or ending in ‘~’, ‘.bak’ or ‘.swp’, are excluded by default.

from https://cran.r-project.org/doc/manuals/r-release/R-exts.html#Building-package-tarballs

[topepo]

I had some errors that occurred via devtools::check() that passed when the tests are run in a fresh R session. I found that using the command line R CMD build \ R CMD check sequence gave more accurate reports of the issue when I looked at the leftover files in the "check" directory.

The issue was that there was an object created outside of the tests that was used inside the tests. The object was found in some test cases but could not be found for others. The test code was something link this:

form <- mpg ~ .

test_that('lm fit', {
  fit <- lm(form, data = mtcars)
  # ...
})

# other tests

# fails here
test_that('glm fit', {
  fit <- glm(form, data = mtcars)
  # ...
})

[jennybc]

@topepo Can you say anymore about the lesson learned / how you fixed? Is all of the above in a single test file / context?

[topepo]

I have no idea why the error was occurring. Here are the changes that I made that fixed it. Instead of referencing the formula object, I just added the formula to each call. I think it was the last test case that used iris_form that was failing (not the previous invocations).

To figure it out, I ran R CMD check parsnip and looked at the resulting testthat.Rout file in the parsnip.Rcheck directory. That had more specific information and error messages than the top-level output.

Also, oddly, other errors are surfacing using devtools::check() that pass using R CMD check at the command line. This reference to a formula object throws an error using devtools but not otherwise. Previously, this had not caused an error. This is making me think that there is some other issue in the test files that is occurring when they executing sequentially.

[topepo]

As one more parsnip example, devtools::check() reports a test error:

2. Error: stan_glm prediction (@test_logistic_reg_stan.R#44) 

(this line) but R CMD check reports no errors. ¯_(ツ)_/¯

EDIT: This seems to be related to skip_on_cran(). A plain R CMD check seems to skip them despite the absence of --as-cran.

[topepo]

One other thing... it looks like some installed packages don't load in some situations:

via R CMD check --as-cran:

> library(testthat)
> library(parsnip)
> 
> test_check("parsnip")
`nnet` installed?  TRUE 
── 1. Error: (unknown) (@test_mlp_nnet.R#6)  ───────────────────────────────────
there is no package called 'nnet'
1: library(nnet) at testthat/test_mlp_nnet.R:6
2: stop(txt, domain = NA)

══ testthat results  ═══════════════════════════════════════════════════════════
OK: 21 SKIPPED: 0 FAILED: 1
1. Error: (unknown) (@test_mlp_nnet.R#6) 

Error: testthat unit tests failed
Execution halted

via R CMD check:

> library(testthat)
> library(parsnip)
> 
> test_check("parsnip")
`nnet` installed?  TRUE 
══ testthat results  ═══════════════════════════════════════════════════════════
OK: 30 SKIPPED: 0 FAILED: 0

[jennybc]

@topepo Thank you! Some vague observations. It feels like the formula stuff might be worth pursuing, but would probably require @lionel- and/or @jimhester to sort it out. It seems like it must have to do with environments and I don't claim to understand how all of that is working inside testthat.

Re: the second case. This makes sense, though, yes? A plain R CMD check won't have the env var NOT_CRAN defined, so will be treated as if it is CRAN and, therefore, skipped. I think skip_on_cran() is sensitive only to the env var and not to command line options such as --as-cran.

[drmowinckels]

I've had two recent really annoyingly stupid reasons my checks have failed.

One recent was where a line-by-line run through the checks was completing just fine, but running devtools::check() was failing on said lines. This despite me having restarted my r-session several times. I was, though, apparently loading a previously working version of the package (I did something and broke it) by a call the the package by library in a side-script I had not noticed had ended up in my R/ folder and was wreaking havoc.

Another recent one was when I was rewriting something I had as data to the package, into a function in stead. And the checks were fine, but I had some really really odd issues during checks because of documentation being all wrong. I had forgotten to remove the documentation for the data of the same name as the function, which was overwriting the function documentation, and so the examples were bugging. This last thing is not really a test-thing really, just something that tok me way too much time to see, as I was obsessed by the tests.

[drmowinckels]

Experiencing a new one today. devtools::test works just fine, but is failing during build check. In this case I think perhaps the culprit is the sequence of packages loading. I need my package to be loaded after another one, as I need a function to mask a function in another package. I know there probably are reasons to not do it this way, but at the moment that is what I need.

I've fixed that in the test script by doing

library(Y)
devtools::load_all(".")

which works fine during test, fails during check.

[jennybc]

@athanasiamo is this package on github?

[drmowinckels]

yes, but I did realise my mistake in this!

I loaded the package in each specific test script, rather that just in the testthat.R script before the test_check command. Since test_check loads the package you are testing, any library loading prior to that is used in all subsequent tests. In my case, it meant that things were being masked as they should.

When I started loading the package in testthat.R instead, it is now passing both test and check.

[jennybc]

Thanks for the follow up. This is exactly what this thread is for. I've been a party to other conversations about how/whether to attach other packages in tests. This is something we should offer guidance on.

[drmowinckels]

I dont know if its me, my system or whatever, but I do some across some odd behaviour from test and check at times. In this case, the tests should be failing, because I did some alterations to the mother-package (ggseg), and am working on making sure this child-package (ggsegExtra) is up-to-date and works with the changes.

During test it fails because it is not loading the package needed (which is specified in the testthat.R script, this worked before. But during check the packages are loaded, and the tests are failing as expected.

==> devtools::test()

Loading ggsegExtra
Testing ggsegExtra
✔ | OK F W S | Context
✖ |  0 1     | test-adapt_scales
────────────────────────────────────────────────────────
test-adapt_scales.R:4: error: Check that adapt_scales is working
could not find function "ggseg"
1: expect_is(ggseg(atlas = yeo17, mapping = aes(fill = area), 
       adapt_scales = F) + scale_brain("yeo17"), c("gg", "ggplot")) at /Users/amowinckel/R-stuff/LCBC/ggseg_stuff/ggsegExtra/tests/testthat/test-adapt_scales.R:4
2: quasi_label(enquo(object), label)
3: eval_bare(get_expr(quo), get_env(quo))
──────────────────────────────────────────────────────

── Test failures ───────────────────────────────────────────────── testthat ────

> library(testthat)
> library(dplyr)

Attaching package: 'dplyr'

The following object is masked from 'package:testthat':

    matches

The following objects are masked from 'package:stats':

    filter, lag

The following objects are masked from 'package:base':

    intersect, setdiff, setequal, union

> library(ggseg)
Loading required package: ggplot2
> 
> test_check("ggsegExtra")
Loading required package: ggsegExtra

Attaching package: 'ggsegExtra'

The following object is masked from 'package:ggseg':

    brain_pals

── 1. Failure: Check that adapt_scales is working (@test-adapt_
mode(adapt_scales(yeo7)) not equal to "list".
1/1 mismatches
x[1]: "NULL"
y[1]: "list"

[jimhester]

@Athanasiamo test() does not run any code in testthat.R, if you need ggseg to be attached to run your tests put the library call in a test helper, e.g. tests/testthat/helper.R, which will be run for both test() and check(). As a general rule you should not put any additional code in testthat.R for this reason.

Alternatively if your functions in ggsegExtra don't work unless ggseg is attached, put ggseg in Depends so it is automatically attached.

[drmowinckels]

@jimhester, having the packages loaded in the testthat.R script worked for me before (i.e up until some days ago). how long has the helper.R thing been the preferred way? I have not read about it before.
If you see my post from early in march, this is how I got my tests working to begin with.

I loaded the package in each specific test script, rather that just in the testthat.R script before the test_check command. Since test_check loads the package you are testing, any library loading prior to that is used in all subsequent tests. In my case, it meant that things were being masked as they should.

When I started loading the package in testthat.R instead, it is now passing both test and check.

Originally posted by @Athanasiamo in #483 (comment)

And yes, ggsegExtra won't work without ggseg as it is really just a companion of datasets for plotting with ggseg. But I have not understood how to make a remote a dependency in a package.

[jennybc]

Example of a difference between results seen via test() and check() (though now designed away by devtools):

r-lib/devtools#2121 (comment)

[eliocamp]

One more for the compilation:
I had several test failing when running check() and test(), but passing when run as a script or with the "Run test" button in RStudio.

The culprit turned out to be the order of execution! The failing function had as.character(formula) somewhere in its body and the issue was that base R returns a vector of character, but {formula.tools} has its own as.character.formula() which returns a single string:

The problem is that some other functions used {formula.tools} and thus the package was loaded. This meant that for that point forward, as.character() returned a single string, which was not what the failing function was expecting. When run by itself, however, {formula.tools} had no opportunity to be loaded and as.character() returned the expected vector.

So the moral of the story is that one source of frustration can be side effects created by other tests!

All this shenanigans highlighted a potential error in my code since the issue could arise if the user loaded {formula.tools} before running my function. The fix was to check which version of as.character() was used and handle each case accordingly.

[hadley]

This reminds me of a problem I had yesterday — I forgot to export an S3 method. Unexported method are found when using devtools::test(), but not from inside of R CMD check.

[czeildi]

We recently had an issue related to different defaults of _R_CHECK_LENGTH_1_CONDITION and
_R_CHECK_LENGTH_1_LOGIC2 (I can work on a reproducible example if relevant)

[jennybc]

@czeildi Yes, I'd definitely love to hear specifics.

[czeildi]

We recently had an issue related to different defaults of _R_CHECK_LENGTH_1_CONDITION and
_R_CHECK_LENGTH_1_LOGIC2 (I can work on a reproducible example if relevant)

I created a reprex at https://github.com/czeildi/logiccheckdemo

Function:

check_equality <- function(x, y) {
  all.equal(x, y) == TRUE && TRUE
}

Test:

test_that("check_equality returns FALSE for non equal arguments", {
  expect_false(check_equality(data.frame(x = 3:6, y = 4), data.frame(x = 4:7, y = 5)))
})

What we experience: tests pass devtools::test() but devtools::check() fails due to unit test fail with the following message:

 --- value of length: 2 type: logical ---
[1] FALSE FALSE
 --- function from context --- 
function (x, y) 
{
    all.equal(x, y) == TRUE && TRUE
}
<bytecode: 0x55d8316041b8>
<environment: namespace:logiccheckdemo>
 --- function search by body ---
Function check_equality in namespace logiccheckdemo has this body.
 ----------- END OF FAILURE REPORT -------------- 
Fatal error: length > 1 in coercion to logical

1 error ✖ | 0 warnings ✔ | 0 notes ✔

I could not prove that it is related to the above env vars, but should be something similar, because changing x == TRUE to isTRUE(x) solves the problem and googling length > 1 in coercion to logical gives result about this. Related link: https://twitter.com/henrikbengtsson/status/1172155983935631360?s=20

It occurs under R 3.6.0 and 3.6.1, tested with latest devtools from CRAN as well. I could reproduce on my mac without Docker and inside a docker container as well for more reproducibility.

I realise this example is silly and it is not good practice to use all.equal() this way anyway, but we encountered this with a similarly structured code in real life. I feel we might learn something more general from this.

Code passing devtools::check():

check_equality <- function(x, y) {
  isTRUE(all.equal(x, y)) && TRUE
}

[jimhester]

Yes, you are correct, these environment variables are turned on by --as-cran, so it is true this will only happen during a full R CMD check. From R-internals

R_CHECK_LENGTH_1_LOGIC2
Optionally check if either argument of the binary operators && and || has length greater than one. The format is the same as for R_CHECK_LENGTH_1_CONDITION. Default: unset (nothing is reported, but ‘package:R_CHECK_PACKAGE_NAME,abort,verbose’ for the CRAN submission checks).

[hadley]

@jimhester we should probably add those to the env vars we set in check()

[jimhester]

They are set in check(), assuming you are using cran=TRUE, which is the default. Did you mean we should set them in test()?

[Aariq]

I had a situation where a test was passing when I ran devtools::test() in the console, but failing when I used the RStudio GUI "Build" > "Test Package" which runs devtools::test() in the Build tab in RStudio. It turns out the problem was some code that only ran if interactive()---the console is of course interactive, even when running test(), but the Build tab is not.

[maelle]

I should have known better but empty directories are deleted before tests are run in R CMD check so if you have fake empty folders that play a role in testing, tests will pass with devtools::test() but not devtools::check().

[jennybc]

@maelle I have basically come to the opinion that any file system work done in tests should happen below the temp directory anyway. So, if you need to stand up a directory, then do stuff to or in it, the affected test(s) should create such a directory explicitly, below tempdir, for themselves (and delete it when they're done). That, in some sense, designs this problem away. Am I generally getting the gist of what you're talking about?

[maelle]

@jennybc yes! It seems more work at first to do what you're saying but if one chooses laziness one will be punished 😉

[eliocamp]

Recently had a test that failed on devtools::check() but passed on devtools::test(). The issue was that the code called a function of {raster}, which was on Suggests, but that function needed {rgdal}, which was on Suggests of {raster}. I guess that devtools::check() tested the package as if {rgdal} was not installed, but devtools::test() tested it with it installed. I added {rgdal} to my package Suggests and it was resolved.

[maelle]

Another case of package loading order being important as noted by @Athanasiamo in #483 (comment) see jennahamlin/tinselR#17 (in test() as_tibble() was the correct one from tidytree, in check() it was the one from tibble).

[jennybc]

@maelle I poked around a little (but not extensively, so could still be wrong.) But that looks more like a user error, i.e. an explicit call to tibble::as_tibble() when tidytree::as_tibble() was desired/correct. And that caused an object to have the wrong class, which caused the wrong S3 method to get dispatched.

That is, this doesn't seem related to "package loading order" or anything subtle or implicit. Do you agree?

It does underscore that S3 generics/methods are an area where it's easy to make a mistake.

[maelle]

Edit: I got confused, user error indeed

[nealrichardson]

My experience on nealrichardson/httptest#51 was the opposite of what most of these reports are about--tests passed in check but failed interactively with devtools::test(). One issue I found that could be easy to get wrong is code (not test setup) that by design modifies global state, like setting options(). Some tests assumed a clean R process and didn't bother to track down all places they modified state and reset it, so they pass on check and pass the first time you run devtools::test() but would fail next time.

I added a GitHub Actions job to catch this: basically a regular workflow but calling devtools::test() twice instead of using rcmdcheck: https://github.com/nealrichardson/httptest/blob/be6d80f32b0bb51895f986d229a1c29aec3a9942/.github/workflows/devtools-test.yaml#L60-L70 It doesn't catch the interactive() differences but does catch any differences when the package is loaded with load_all() and when tests are run multiple times in the same process. Since this isn't my normal workflow (I guess I'm paranoid about the kinds of differences discussed in this thread so I've learned to run tests on the installed package), this workflow will help me not break things for others who test interactively.

[jennybc]

@nealrichardson Interesting. I recently did a very manual/cumbersome study of the usethis tests, where I wrote certain conditions (e.g. active usethis project, working directory, etc.) to file at the start and end of each tests to pinpoint sloppy tests that weren't leaving the world as they found it.

[njtierney]

Thanks for this thread! Very interesting stuff here.

I am currently stuck with devtools::test() returning no errors, and devtools::check() returning errors.

Following some of the advice here, I tried R CMD build greta, then R CMD check --as-cran greta_0.4.0.tar.gz

This revealed no errors! Which is great.

Another thing so far that I have found helpful was to use withr::defer and withr::local_envvar to help ensure environment variables and options get returned back to normal - doing this locally, I was able to remove 2 Errors (see this commit). I believe that things weren't getting cleaned up inside test_that(), despite our efforts there to clean up at the end.

A strange thing about all of this is that I can only get these errors locally, and not on GitHub Actions, which are running totally fine (well, pretty much)

I'm wondering if there a way for me to replicate the environment that devtools::check() is creating/using locally, so that I can step into that environment and work out what is going on and debug things?

My next step is to try and work out if there's a way to do something with withr to help isolate issues with Python being initialised - currently Python cannot be found in tests when doing them inside of devtools::check()

[njtierney]

I've now started the process of removing source(helper.R) calls inside of my test_that(... expressions, and it is proving to reveal some other bugs that were previously not there. Hopefully this is the right next step to take.

I'm trying to document (some of) my process here:

https://community.rstudio.com/t/devtools-test-passes-but-devtools-check-does-not/129885