revdepcheck
revdepcheck copied to clipboard
r-lib
revdep_check should fail gracefully when it times out & tell the user to increase `timeout`
When doing reverse dependency checks of my gratia package, revdep_check() times out as soon as the installation of all packages needed to check the dependencies and gratia is completed. This is what I see:
> revdepcheck::revdep_check(num_workers = 4)
── INIT ───────────────────────────────────────────────────────────────── Computing revdeps ──
── INSTALL ───────────────────────────────────────────────────────────────────── 2 versions ──
Installing CRAN version of gratia
Installing DEV version of gratia
Installing 8 packages: Rcpp, colorspace, fansi, vctrs, isoband, BH, stringr, tidyr
── CHECK ─────────────────────────────────────────────────────────────────────── 2 packages ──
[0/2] 00:10:29 | ETA: ?s | (1) dsfa [I]OK: 2
BROKEN: 0
Total time: 11 min
── REPORT ────────────────────────────────────────────────────────────────────────────────────
Writing summary to 'revdep/README.md'
Writing problems to 'revdep/problems.md'
Writing failures to 'revdep/failures.md'
Writing CRAN report to 'revdep/cran.md'
Warning message:
call dbDisconnect() when finished working with a connection
There's nothing there to indicate it timed out and actually didn't do any checks.
I would be nice for the user if revdep_check() mentioned it timed out and didn't proceed as if it had actually done something.
Also, revdep_check() isn't cleaning up after itself when it times out, as evidenced by the warning message.
This is with
─ Session info ─────────────────────────────────────────────────────────────────────────────
setting value
version R version 4.2.2 Patched (2022-11-10 r83330)
os Ubuntu 20.04.5 LTS
system x86_64, linux-gnu
ui X11
language en_GB:en
collate en_GB.UTF-8
ctype en_GB.UTF-8
tz Europe/Copenhagen
date 2023-01-28
pandoc 2.5 @ /usr/bin/pandoc
─ Packages ─────────────────────────────────────────────────────────────────────────────────
package * version date (UTC) lib source
assertthat 0.2.1 2019-03-21 [1] RSPM (R 4.2.0)
base64enc 0.1-3 2015-07-28 [1] RSPM (R 4.2.0)
bit 4.0.5 2022-11-15 [1] RSPM (R 4.2.2)
bit64 4.0.5 2020-08-30 [1] RSPM (R 4.2.0)
blob 1.2.3 2022-04-10 [1] RSPM (R 4.2.0)
cachem 1.0.6 2021-08-19 [1] RSPM (R 4.2.0)
callr 3.7.3 2022-11-02 [1] RSPM (R 4.2.2)
cli 3.6.0 2023-01-09 [1] RSPM (R 4.2.2)
clisymbols 1.2.0 2017-05-21 [1] RSPM (R 4.2.0)
crancache 0.0.0.9001 2021-11-04 [1] Github (r-lib/crancache@7ea4e47)
cranlike 1.0.2 2018-11-26 [1] RSPM (R 4.2.0)
crayon 1.5.2 2022-09-29 [1] RSPM (R 4.2.1)
curl 5.0.0 2023-01-12 [1] RSPM (R 4.2.2)
DBI 1.1.3 2022-06-18 [1] RSPM (R 4.2.0)
debugme 1.1.0 2017-10-22 [1] RSPM (R 4.2.0)
desc 1.4.2 2022-09-08 [1] RSPM (R 4.2.1)
digest 0.6.31 2022-12-11 [1] RSPM (R 4.2.2)
ellipsis 0.3.2 2021-04-29 [1] RSPM (R 4.2.0)
fansi 1.0.4 2023-01-22 [1] RSPM (R 4.2.2)
fastmap 1.1.0 2021-01-25 [1] RSPM (R 4.2.0)
fs 1.6.0 2023-01-23 [1] RSPM (R 4.2.2)
gargle 1.2.1 2022-09-08 [1] RSPM (R 4.2.1)
glue 1.6.2 2022-02-24 [1] RSPM (R 4.2.0)
gmailr 1.0.1 2021-11-30 [1] RSPM (R 4.2.0)
hms 1.1.2 2022-08-19 [1] RSPM (R 4.2.1)
httr 1.4.4 2022-08-17 [1] RSPM (R 4.2.1)
jsonlite 1.8.4 2022-12-06 [1] RSPM (R 4.2.2)
knitr 1.42 2023-01-25 [1] CRAN (R 4.2.2)
lifecycle 1.0.3 2022-10-07 [1] CRAN (R 4.2.1)
magrittr 2.0.3 2022-03-30 [1] RSPM (R 4.2.0)
memoise 2.0.1 2021-11-26 [1] RSPM (R 4.2.0)
parsedate 1.3.1 2022-10-27 [1] RSPM (R 4.2.2)
pillar 1.8.1 2022-08-19 [1] RSPM (R 4.2.1)
pkgbuild 1.4.0 2022-11-27 [1] RSPM (R 4.2.2)
pkgconfig 2.0.3 2019-09-22 [1] RSPM (R 4.2.0)
prettyunits 1.1.1 2020-01-24 [1] RSPM (R 4.2.0)
processx 3.8.0 2022-10-26 [1] RSPM (R 4.2.2)
progress 1.2.2 2019-05-16 [1] RSPM (R 4.2.0)
ps 1.7.2 2022-10-26 [1] RSPM (R 4.2.2)
R6 2.5.1 2021-08-19 [1] RSPM (R 4.2.0)
rappdirs 0.3.3 2021-01-31 [1] RSPM (R 4.2.0)
rcmdcheck 1.4.0 2021-09-27 [1] RSPM (R 4.2.0)
Rcpp 1.0.10 2023-01-22 [1] RSPM (R 4.2.2)
rematch2 2.1.2 2020-05-01 [1] RSPM (R 4.2.0)
remotes 2.4.2 2021-11-30 [1] RSPM (R 4.2.0)
revdepcheck * 1.0.0.9001 2022-01-23 [1] Github (r-lib/revdepcheck@b855323)
rlang 1.0.6 2022-09-24 [1] RSPM (R 4.2.1)
rprojroot 2.0.3 2022-04-02 [1] RSPM (R 4.2.0)
RSQLite 2.2.20 2022-12-22 [1] RSPM (R 4.2.2)
sessioninfo 1.2.2 2021-12-06 [1] RSPM (R 4.2.0)
tibble 3.1.8 2022-07-22 [1] RSPM (R 4.2.1)
utf8 1.2.2 2021-07-24 [1] RSPM (R 4.2.0)
vctrs 0.5.2 2023-01-23 [1] RSPM (R 4.2.2)
whoami 1.3.0 2019-03-19 [1] RSPM (R 4.2.0)
withr 2.5.0 2022-03-03 [1] RSPM (R 4.2.0)
xfun 0.36 2022-12-21 [1] RSPM (R 4.2.2)
xopen 1.0.0 2018-09-17 [1] RSPM (R 4.2.0)
yaml 2.3.7 2023-01-23 [1] RSPM (R 4.2.2)
[1] /home/au690221/R/x86_64-pc-linux-gnu-library/4.2
[2] /usr/local/lib/R/site-library
[3] /usr/lib/R/site-library
[4] /usr/lib/R/library
────────────────────────────────────────────────────────────────────────────────────────────
I'd like to escalate this issue, as after looking through the code base some parts of this functionality look buggy and/or contradictory to what the documentation says.
Let's start with the timeout, in general, this is what the documentation says:
https://github.com/r-lib/revdepcheck/blob/a52c7cb136e230f3cd3d55a905dbe76d62aa82f3/R/revdepcheck.R#L39-L40
it clearly says that timeout is applied to the R CMD check only, however currently by how run_event_loop function is designed (https://github.com/r-lib/revdepcheck/blob/main/R/event-loop.R#L62) timeout is applied to all revdepcheck steps (executed during revdepcheck:::revdep_run), in particular, it also could be applied to the deps_installing step. It should either be clearly stated that timeout is applied to all steps, not only R CMD Check or review the code base and exclude other steps than "checking" from timeout.
However, it is not the only issue with the timeout I've identified. Let's take a look at the event loop fragment and check_for_timeouts function
https://github.com/r-lib/revdepcheck/blob/a52c7cb136e230f3cd3d55a905dbe76d62aa82f3/R/event-loop.R#L60-L64
https://github.com/r-lib/revdepcheck/blob/a52c7cb136e230f3cd3d55a905dbe76d62aa82f3/R/event-loop.R#L83-L93
We see thatcheck_for_timeouts does not return anything, and even if it did, it is not assigned in the event loop, meaning information that the worker was killed (https://github.com/r-lib/revdepcheck/blob/main/R/event-loop.R#L89) is completely lost as in this case assignment happens to the copy of the state list. This creates a nightmare to debug because later in the deps_install_done timeout cannot be gracefully handled:
https://github.com/r-lib/revdepcheck/blob/a52c7cb136e230f3cd3d55a905dbe76d62aa82f3/R/deps-install.R#L115-L124
as value worker$killed does not exist so we end up with "PREPERROR" what clearly indicated timeout was not an issue (as got to the else statement) and additionally leaves {"class":["list"],"object":{"stdout":[""],"stderr":[""],"errormsg":["! callr subprocess failed: could not start R, exited with non-zero status, has crashed or was killed"]}} as error message in the sqlite db which also does not help as the same error would be shown for other problems like potential memory issues for instance.
The bug is easy to fix. The only thing required is to make check_for_timeouts return an altered state object and in the event loop assign that to the state variable.
That being said I fully support the previous suggestion to not mark timed-out packages as DONE. It creates a false positive assumption that everything was all right and the only indicator that potentially none of the packages run is README.md or raw sql results.
I'm happy to help with MR to address this issue if you agree with my findings.
