search

r-lib / pak

A fresh approach to package installation
https://pak.r-lib.org
639 stars 56 forks source link

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

Open DanChaltiel opened 2 months ago

DanChaltiel commented 2 months ago

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!

gaborcsardi commented 2 months ago

That's a EDCimport build failure, try adding

with:
    - pak-version: devel

to see the real error.

DanChaltiel commented 2 months ago

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.

gaborcsardi commented 2 months ago

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
DanChaltiel commented 2 months ago

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 commented 2 months ago

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.

gaborcsardi commented 2 months ago

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

DanChaltiel commented 2 months ago

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.

gaborcsardi commented 2 months ago

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.

Claudius-Appel commented 2 months ago

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:

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

gaborcsardi commented 2 months ago

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

Claudius-Appel commented 2 months ago

@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).

gaborcsardi commented 2 months ago

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

Claudius-Appel commented 2 months ago

@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).

gaborcsardi commented 2 months ago

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

Claudius-Appel commented 2 months ago

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