pak icon indicating copy to clipboard operation
pak copied to clipboard

Error in pak without message during `r-lib/actions/setup-r-dependencies@v2`

Open DanChaltiel opened this issue 1 year ago • 15 comments

Hi,

I'm using pkgdown.yaml to build the documentation website for a package of mine.

During the process, r-lib/actions/setup-r-dependencies@v2 uses pak to install dependencies and then build the package.

This very last step throws an error, but the error message is only "Failed to build the package", with no further information.

Here is some context of the error (see the run for the whole log):

  ✔ Installed ... (a lot of packages)
  ✔ Installed withr 3.0.0  (23ms)
  ℹ Packaging EDCimport 0.4.1.9011
  ✔ Packaged EDCimport 0.4.1.9011 (417ms)
  ℹ Building EDCimport 0.4.1.9011
  ✖ Failed to build EDCimport 0.4.1.9011 (1.1s)
  ##[debug]Skipping logging an issue for the matched line because the message is empty.
  Error: 
  ! error in pak subprocess
  Caused by error in `stop_task_build(state, worker)`:
  ! Failed to build source package EDCimport.
  ---
  Backtrace:
  1. pak::lockfile_install(".github/pkg.lock")
  2. pak:::remote(function(...) { …
  3. err$throw(res$error)
  ---
  Subprocess backtrace:
   1. base::withCallingHandlers(cli_message = function(msg) { …
   2. get("lockfile_install_internal", asNamespace("pak"))(...)
   3. plan$install()
   4. pkgdepends::install_package_plan(plan, lib = private$library, num_workers = nw, …
   5. base::withCallingHandlers({ …
   6. pkgdepends:::handle_events(state, events)
   7. pkgdepends:::handle_event(state, i)
   8. pkgdepends:::stop_task(state, worker)
   9. pkgdepends:::stop_task_build(state, worker)
  10. base::throw(pkg_error("Failed to build source package {.pkg {pkg}}.", …
  11. | base::signalCondition(cond)
  12. global (function (e) …
  Execution halted
  Error: Process completed with exit code 1.
  ##[debug]Finished: run
  ##[debug]Evaluating condition for step: 'run'
  ##[debug]Evaluating: success()
  ##[debug]Evaluating success:
  ##[debug]=> false
  ##[debug]Result: false
  ##[debug]Evaluating condition for step: 'run'
  ##[debug]Evaluating: (success() && (steps.check-pandoc.outputs.install == 'true'))
  ##[debug]Evaluating And:
  ##[debug]..Evaluating success:
  ##[debug]..=> false
  ##[debug]=> false
  ##[debug]Expanded: (false && (steps['check-pandoc']['outputs']['install'] == 'true'))
  ##[debug]Result: false
  ##[debug]Evaluating condition for step: 'run'
  ##[debug]Evaluating: success()
  ##[debug]Evaluating success:
  ##[debug]=> false
  ##[debug]Result: false
  ##[debug]Evaluating condition for step: 'run'
  ##[debug]Evaluating: (success() && (runner.os == 'Windows'))
  ##[debug]Evaluating And:
  ##[debug]..Evaluating success:
  ##[debug]..=> false
  ##[debug]=> false
  ##[debug]Expanded: (false && (runner['os'] == 'Windows'))
  ##[debug]Result: false
  ##[debug]Finishing: Run r-lib/actions/setup-r-dependencies@v2

If you look at the runs, you'll see this GHA failed a lot but it is only because I was lazy about _pkgdown.yml, up until "clinical utils (WIP)". Starting at "Update waterfall_plot.Rd", the error is the one above.

What is surprising is that the commit of "Update waterfall_plot.Rd" is very minor, so I don't think it could explain this error.

Thanks for your help!

DanChaltiel avatar Apr 15 '24 09:04 DanChaltiel

That's a EDCimport build failure, try adding

with:
	- pak-version: devel

to see the real error.

gaborcsardi avatar Apr 15 '24 09:04 gaborcsardi

Thanks Gabor, I'm always amazed how you always answer so quickly 💪

I re-ran with pak-version: devel, indeed, the error message is more informative (link to the run):

  ✖ Failed to build EDCimport 0.4.1.9012 (966ms)
  Error: 
  ! error in pak subprocess
  Caused by error in `stop_task_build(state, worker)`:
  ! Failed to build source package EDCimport.
  Full installation output:
  * installing *source* package ‘EDCimport’ ...
  staged installation is only possible with locking
  ** using non-staged installation
  ** R
  ** inst
  ** byte-compile and prepare package for lazy loading
  Error in loadNamespace(i, c(lib.loc, .libPaths()), versionCheck = vI[[i]]) : 
    there is no package called ‘xtable’
  Calls: <Anonymous> ... loadNamespace -> withRestarts -> withOneRestart -> doWithOneRestart
  Execution halted
  ERROR: lazy loading failed for package ‘EDCimport’

However, the reason being "there is no package called ‘xtable’" is surprising, as xtable seems available on CRAN.

DanChaltiel avatar Apr 15 '24 09:04 DanChaltiel

It is not a dependency of EDCimport:

❯ pak::pkg_deps_explain("EDCimport", "xtable")
✔ Updated metadata database: 2.65 MB in 6 files.
✔ Updating metadata database ... done
x xtable

gaborcsardi avatar Apr 15 '24 09:04 gaborcsardi

Sorry, I am not sure I understand your point.

I agree with the output of pkg_deps_explain() here. Indeed, xtable appears in neither NAMESPACE nor DESCRIPTION, it is only a "Suggests" dependency of flextable which is itself a "Suggests" of EDCimport.

The only "special" thing I'm doing is S3method(flextable::as_flextable,ae_table_soc), but IIUC it is OK with flextable in Suggests since roxygen2 v7.2.0.

DanChaltiel avatar Apr 15 '24 10:04 DanChaltiel

Nevermind, I had some imports of flextable in NAMESPACE while flextable is only in Suggests! Sorry, that was totally my bad, I should have run "R CMD check" sooner.

Maybe the error message could have been a bit more helpful though. Not sure if it should be in pak or in r-lib/actions, but if the coherence is very important for the build, a simple check could stop the process earlier and with a better message. Note that devtools::build() works fine locally.

Don't hesitate to close this issue if you think this is out of pak scope.

DanChaltiel avatar Apr 15 '24 10:04 DanChaltiel

How would you implement a better error message if the error happens when building a dependency?

gaborcsardi avatar Apr 15 '24 10:04 gaborcsardi

I was thinking about a function that would check that every package engaged in NAMESPACE (import, importFrom, etc) is mentioned in Imports in DESCRIPTION. This is what R CMD CHECK does somehow, but it is very long to run as a whole. A cheaper check would catch problems like this one. The more I think about it, the less it relates to pak though.

DanChaltiel avatar Apr 15 '24 15:04 DanChaltiel

It makes sense to make installation more resilient.

But there are a lot of things that have higher priority than checking if the packages we are installing are broken.

gaborcsardi avatar Apr 15 '24 15:04 gaborcsardi

I have a confusingly similar issue.

ℹ Building imager 0.45.8
  ✔ Built openxlsx 4.2.5.2 (1m 8.8s)
  ✔ Installed openxlsx 4.2.5.2  (153ms)
  ✖ Failed to build imager 0.45.8 (4m 56.1s)
  Error: 
  ! error in pak subprocess
  Caused by error in `stop_task_build(state, worker)`:
  ! Failed to build source package imager.
  ---
  Backtrace:
  1. pak::lockfile_install(".github/pkg.lock")
  2. pak:::remote(function(...) { …
  3. err$throw(res$error)
  ---
  Subprocess backtrace:
   1. base::withCallingHandlers(cli_message = function(msg) { …
   2. get("lockfile_install_internal", asNamespace("pak"))(...)
   3. plan$install()
   4. pkgdepends::install_package_plan(plan, lib = private$library, num_workers = nw, …
   5. base::withCallingHandlers({ …
   6. pkgdepends:::handle_events(state, events)
   7. pkgdepends:::handle_event(state, i)
   8. pkgdepends:::stop_task(state, worker)
   9. pkgdepends:::stop_task_build(state, worker)
  10. base::throw(pkg_error("Failed to build source package {.pkg {pkg}}.", …
  11. | base::signalCondition(cond)
  12. global (function (e) …
  Execution halted
  Error: Process completed with exit code 1.

I am now bit by bit retesting old action runs, and now even merges which passed checks successfully before fail now. I don't know why, and I have basically no idea how to resolve this. I have tagged all commits which merge to dev which are currently failing, which is a surprisingly tedious process.

There are a variety of things that confuse me here:

  • The action only breaks on windows, linux runners are not afflicted.
    • Mac is not tested
  • This package duflor.gui directly depend on imager, importing from it directly via various @ImportFrom-directives. However, the underlying package duflor (to which duflor.gui provides a shiny-frontend) does also import from imager. Unlike duflor.gui, this package passes GHA-executed R CMD CHECK-workflows on both windows and linux.

What confuses me most is that most of these tagged commits did pass at one point or another. And most of them have never been tested since, up until today - where they all fail. The state of the package did not change on most of these commits (some branches were force-pushed over again to rectify sudden bugs. However, this problem also manifests in commits prior to any force-pushing.)

For ref: R CMD CHECK Overview. Any "failed" workflow-run beyond the first one (https://github.com/Claudius-Appel/duflor.gui/commit/966d728781810de94c102bfa82249b2ca813f320) were retested. However, not all merges to dev were tested. The first merge which set up GHA was tested, but given that everything I am retesting right now fails, even literally the first one that could leads me to believe that there is little to be learned by me waiting another 8*20 minutes for the same message 8 times.


All of this is to say that I have very little clues as to what is actually going on, going wrong, or how to rectify this.

Could someone help me figure out what the frick is going on here?

Thank you. Sincerely, ~CA

Claudius-Appel avatar Apr 25 '24 17:04 Claudius-Appel

@Claudius-Appel imager does not work on Windows, on R 4.4.0: https://cran.rstudio.com/web/checks/check_results_imager.html

gaborcsardi avatar Apr 25 '24 17:04 gaborcsardi

@gaborcsardi

Huh, that is weird, for several reasons. For one, I can compile my stuff flawlessly on my local machine. But that's only circumstantially relevant, I think. However, as outlined above, the backend package duflor succeeds its GHA-checks as of ~~a couple hours~~ 8 minutes ago. And both duflor and duflor.gui import heavily from imager - so I wouldn't understand how one package can succeed, while the other does not.

non-failing ref-workflow on duflor failing ref-workflow on duflor.gui (most others as well. This is the most-recent execution of the action that has failed).

Claudius-Appel avatar Apr 25 '24 18:04 Claudius-Appel

You use a different repo setup for the two builds, CRAN has a binary for imager, PPPM does not. https://github.com/Claudius-Appel/duflor/actions/runs/8814859980/job/24265181052#step:5:974 https://github.com/Claudius-Appel/duflor.gui/actions/runs/8783424821/job/24264034763#step:5:2020

gaborcsardi avatar Apr 25 '24 18:04 gaborcsardi

@gaborcsardi Well, thank you. I don't think I would have nailed that down ._. I don't even know how I managed to change that, particularly because renv::config$rspm.enabled() returns true for both packages, and the config files under root/renv/settings.json are similar for both:

duflor.gui: grafik

duflor: grafik

Which means that in both cases renv should default to system config, which as above states renv::config$rspm.enabled()==TRUE on both projects. This is to say - I don't know why/how the lockfiles ended up pointing to different remotes, and currently I don't even know how to resolve this (beyond manually modifying renv.lock - which I'd rather not).

Claudius-Appel avatar Apr 25 '24 18:04 Claudius-Appel

https://github.com/Claudius-Appel/duflor/blob/7a43ff7936737eb8ebc0f9609dd95bed01fa860e/renv.lock#L27 https://github.com/Claudius-Appel/duflor.gui/blob/67e8eefa501aefe40b8f1e765d690aac9420f06a/renv.lock#L7

gaborcsardi avatar Apr 25 '24 18:04 gaborcsardi

I feel silly for not noticing that. However, it works now. Again, thank you for your support on this.

Claudius-Appel avatar Apr 25 '24 19:04 Claudius-Appel

AFAICT there is nothing for me to do here, but please reopen if you think otherwise. Thanks!

gaborcsardi avatar May 09 '25 11:05 gaborcsardi