setup-lesson-deps can fail for bioconductor lessons when PPM not up-to-date

[zkamvar]

I ran into a situation where a package (data.table) was up-to-date on CRAN, but not yet added to the posit package manager.

Interestingly, the process was able to find the data.table on the first pass:

2023-02-20T11:42:17.5410934Z 
2023-02-20T11:42:17.5459127Z trying URL 'https://cran.rstudio.com/src/contrib/data.table_1.14.8.tar.gz'
2023-02-20T11:42:17.7308532Z Content type 'application/x-gzip' length 5338582 bytes (5.1 MB)
2023-02-20T11:42:17.7850243Z ==================================================
2023-02-20T11:42:17.7850917Z downloaded 5.1 MB

and it was successfully installed:

2023-02-20T11:42:48.0428900Z * installing *source* package ‘data.table’ ...
2023-02-20T11:42:48.0898250Z ** package ‘data.table’ successfully unpacked and MD5 sums checked
2023-02-20T11:42:48.0899805Z ** using staged installation
2023-02-20T11:42:48.2097305Z gcc 11.3.0
2023-02-20T11:42:48.2262890Z zlib 1.2.11 is available ok
2023-02-20T11:42:48.4464474Z R CMD SHLIB supports OpenMP without any extra hint
2023-02-20T11:42:48.5229112Z ** libs
2023-02-20T11:42:48.5311236Z gcc -I"/usr/share/R/include" -DNDEBUG     -fopenmp  -fpic  -g -O2 -ffile-prefix-map=/build/r-base-Faorqz/r-base-4.2.2.20221110=. -fstack-protector-strong -Wformat -Werror=format-security -Wdate-time -D_FORTIFY_SOURCE=2  -c assign.c -o assign.o
2023-02-20T11:42:50.0127876Z gcc -I"/usr/share/R/include" -DNDEBUG     -fopenmp  -fpic  -g -O2 -ffile-prefix-map=/build/r-base-Faorqz/r-base-4.2.2.20221110=. -fstack-protector-strong -Wformat -Werror=format-security -Wdate-time -D_FORTIFY_SOURCE=2  -c between.c -o between.o
2023-02-20T11:42:50.3624417Z gcc -I"/usr/share/R/include" -DNDEBUG     -fopenmp  -fpic  -g -O2 -ffile-prefix-map=/build/r-base-Faorqz/r-base-4.2.2.20221110=. -fstack-protector-strong -Wformat -Werror=format-security -Wdate-time -D_FORTIFY_SOURCE=2  -c bmerge.c -o bmerge.o
2023-02-20T11:42:51.0267729Z gcc -I"/usr/share/R/include" -DNDEBUG     -fopenmp  -fpic  -g -O2 -ffile-prefix-map=/build/r-base-Faorqz/r-base-4.2.2.20221110=. -fstack-protector-strong -Wformat -Werror=format-security -Wdate-time -D_FORTIFY_SOURCE=2  -c chmatch.c -o chmatch.o
2023-02-20T11:42:51.1812171Z gcc -I"/usr/share/R/include" -DNDEBUG     -fopenmp  -fpic  -g -O2 -ffile-prefix-map=/build/r-base-Faorqz/r-base-4.2.2.20221110=. -fstack-protector-strong -Wformat -Werror=format-security -Wdate-time -D_FORTIFY_SOURCE=2  -c cj.c -o cj.o
2023-02-20T11:42:51.3586435Z gcc -I"/usr/share/R/include" -DNDEBUG     -fopenmp  -fpic  -g -O2 -ffile-prefix-map=/build/r-base-Faorqz/r-base-4.2.2.20221110=. -fstack-protector-strong -Wformat -Werror=format-security -Wdate-time -D_FORTIFY_SOURCE=2  -c coalesce.c -o coalesce.o
2023-02-20T11:42:51.5685114Z gcc -I"/usr/share/R/include" -DNDEBUG     -fopenmp  -fpic  -g -O2 -ffile-prefix-map=/build/r-base-Faorqz/r-base-4.2.2.20221110=. -fstack-protector-strong -Wformat -Werror=format-security -Wdate-time -D_FORTIFY_SOURCE=2  -c dogroups.c -o dogroups.o
2023-02-20T11:42:52.0413491Z gcc -I"/usr/share/R/include" -DNDEBUG     -fopenmp  -fpic  -g -O2 -ffile-prefix-map=/build/r-base-Faorqz/r-base-4.2.2.20221110=. -fstack-protector-strong -Wformat -Werror=format-security -Wdate-time -D_FORTIFY_SOURCE=2  -c fastmean.c -o fastmean.o
2023-02-20T11:42:52.1487881Z gcc -I"/usr/share/R/include" -DNDEBUG     -fopenmp  -fpic  -g -O2 -ffile-prefix-map=/build/r-base-Faorqz/r-base-4.2.2.20221110=. -fstack-protector-strong -Wformat -Werror=format-security -Wdate-time -D_FORTIFY_SOURCE=2  -c fcast.c -o fcast.o
2023-02-20T11:42:52.2685351Z gcc -I"/usr/share/R/include" -DNDEBUG     -fopenmp  -fpic  -g -O2 -ffile-prefix-map=/build/r-base-Faorqz/r-base-4.2.2.20221110=. -fstack-protector-strong -Wformat -Werror=format-security -Wdate-time -D_FORTIFY_SOURCE=2  -c fifelse.c -o fifelse.o
2023-02-20T11:42:52.5597062Z gcc -I"/usr/share/R/include" -DNDEBUG     -fopenmp  -fpic  -g -O2 -ffile-prefix-map=/build/r-base-Faorqz/r-base-4.2.2.20221110=. -fstack-protector-strong -Wformat -Werror=format-security -Wdate-time -D_FORTIFY_SOURCE=2  -c fmelt.c -o fmelt.o
2023-02-20T11:42:53.1152588Z gcc -I"/usr/share/R/include" -DNDEBUG     -fopenmp  -fpic  -g -O2 -ffile-prefix-map=/build/r-base-Faorqz/r-base-4.2.2.20221110=. -fstack-protector-strong -Wformat -Werror=format-security -Wdate-time -D_FORTIFY_SOURCE=2  -c forder.c -o forder.o
2023-02-20T11:42:54.2141231Z gcc -I"/usr/share/R/include" -DNDEBUG     -fopenmp  -fpic  -g -O2 -ffile-prefix-map=/build/r-base-Faorqz/r-base-4.2.2.20221110=. -fstack-protector-strong -Wformat -Werror=format-security -Wdate-time -D_FORTIFY_SOURCE=2  -c frank.c -o frank.o
2023-02-20T11:42:54.4176427Z gcc -I"/usr/share/R/include" -DNDEBUG     -fopenmp  -fpic  -g -O2 -ffile-prefix-map=/build/r-base-Faorqz/r-base-4.2.2.20221110=. -fstack-protector-strong -Wformat -Werror=format-security -Wdate-time -D_FORTIFY_SOURCE=2  -c fread.c -o fread.o
2023-02-20T11:42:56.2771632Z gcc -I"/usr/share/R/include" -DNDEBUG     -fopenmp  -fpic  -g -O2 -ffile-prefix-map=/build/r-base-Faorqz/r-base-4.2.2.20221110=. -fstack-protector-strong -Wformat -Werror=format-security -Wdate-time -D_FORTIFY_SOURCE=2  -c freadR.c -o freadR.o
2023-02-20T11:42:56.7310865Z gcc -I"/usr/share/R/include" -DNDEBUG     -fopenmp  -fpic  -g -O2 -ffile-prefix-map=/build/r-base-Faorqz/r-base-4.2.2.20221110=. -fstack-protector-strong -Wformat -Werror=format-security -Wdate-time -D_FORTIFY_SOURCE=2  -c froll.c -o froll.o
2023-02-20T11:42:57.1188166Z gcc -I"/usr/share/R/include" -DNDEBUG     -fopenmp  -fpic  -g -O2 -ffile-prefix-map=/build/r-base-Faorqz/r-base-4.2.2.20221110=. -fstack-protector-strong -Wformat -Werror=format-security -Wdate-time -D_FORTIFY_SOURCE=2  -c frollR.c -o frollR.o
2023-02-20T11:42:57.3795436Z gcc -I"/usr/share/R/include" -DNDEBUG     -fopenmp  -fpic  -g -O2 -ffile-prefix-map=/build/r-base-Faorqz/r-base-4.2.2.20221110=. -fstack-protector-strong -Wformat -Werror=format-security -Wdate-time -D_FORTIFY_SOURCE=2  -c frolladaptive.c -o frolladaptive.o
2023-02-20T11:42:57.7142569Z gcc -I"/usr/share/R/include" -DNDEBUG     -fopenmp  -fpic  -g -O2 -ffile-prefix-map=/build/r-base-Faorqz/r-base-4.2.2.20221110=. -fstack-protector-strong -Wformat -Werror=format-security -Wdate-time -D_FORTIFY_SOURCE=2  -c fsort.c -o fsort.o
2023-02-20T11:42:57.9652392Z gcc -I"/usr/share/R/include" -DNDEBUG     -fopenmp  -fpic  -g -O2 -ffile-prefix-map=/build/r-base-Faorqz/r-base-4.2.2.20221110=. -fstack-protector-strong -Wformat -Werror=format-security -Wdate-time -D_FORTIFY_SOURCE=2  -c fwrite.c -o fwrite.o
2023-02-20T11:42:58.5507174Z gcc -I"/usr/share/R/include" -DNDEBUG     -fopenmp  -fpic  -g -O2 -ffile-prefix-map=/build/r-base-Faorqz/r-base-4.2.2.20221110=. -fstack-protector-strong -Wformat -Werror=format-security -Wdate-time -D_FORTIFY_SOURCE=2  -c fwriteR.c -o fwriteR.o
2023-02-20T11:42:58.7334376Z gcc -I"/usr/share/R/include" -DNDEBUG     -fopenmp  -fpic  -g -O2 -ffile-prefix-map=/build/r-base-Faorqz/r-base-4.2.2.20221110=. -fstack-protector-strong -Wformat -Werror=format-security -Wdate-time -D_FORTIFY_SOURCE=2  -c gsumm.c -o gsumm.o
2023-02-20T11:43:00.0103771Z gcc -I"/usr/share/R/include" -DNDEBUG     -fopenmp  -fpic  -g -O2 -ffile-prefix-map=/build/r-base-Faorqz/r-base-4.2.2.20221110=. -fstack-protector-strong -Wformat -Werror=format-security -Wdate-time -D_FORTIFY_SOURCE=2  -c ijoin.c -o ijoin.o
2023-02-20T11:43:00.5296393Z gcc -I"/usr/share/R/include" -DNDEBUG     -fopenmp  -fpic  -g -O2 -ffile-prefix-map=/build/r-base-Faorqz/r-base-4.2.2.20221110=. -fstack-protector-strong -Wformat -Werror=format-security -Wdate-time -D_FORTIFY_SOURCE=2  -c init.c -o init.o
2023-02-20T11:43:00.6381559Z gcc -I"/usr/share/R/include" -DNDEBUG     -fopenmp  -fpic  -g -O2 -ffile-prefix-map=/build/r-base-Faorqz/r-base-4.2.2.20221110=. -fstack-protector-strong -Wformat -Werror=format-security -Wdate-time -D_FORTIFY_SOURCE=2  -c inrange.c -o inrange.o
2023-02-20T11:43:00.7032707Z gcc -I"/usr/share/R/include" -DNDEBUG     -fopenmp  -fpic  -g -O2 -ffile-prefix-map=/build/r-base-Faorqz/r-base-4.2.2.20221110=. -fstack-protector-strong -Wformat -Werror=format-security -Wdate-time -D_FORTIFY_SOURCE=2  -c nafill.c -o nafill.o
2023-02-20T11:43:00.9292154Z gcc -I"/usr/share/R/include" -DNDEBUG     -fopenmp  -fpic  -g -O2 -ffile-prefix-map=/build/r-base-Faorqz/r-base-4.2.2.20221110=. -fstack-protector-strong -Wformat -Werror=format-security -Wdate-time -D_FORTIFY_SOURCE=2  -c nqrecreateindices.c -o nqrecreateindices.o
2023-02-20T11:43:01.0012765Z gcc -I"/usr/share/R/include" -DNDEBUG     -fopenmp  -fpic  -g -O2 -ffile-prefix-map=/build/r-base-Faorqz/r-base-4.2.2.20221110=. -fstack-protector-strong -Wformat -Werror=format-security -Wdate-time -D_FORTIFY_SOURCE=2  -c openmp-utils.c -o openmp-utils.o
2023-02-20T11:43:01.1331547Z gcc -I"/usr/share/R/include" -DNDEBUG     -fopenmp  -fpic  -g -O2 -ffile-prefix-map=/build/r-base-Faorqz/r-base-4.2.2.20221110=. -fstack-protector-strong -Wformat -Werror=format-security -Wdate-time -D_FORTIFY_SOURCE=2  -c quickselect.c -o quickselect.o
2023-02-20T11:43:01.2716667Z gcc -I"/usr/share/R/include" -DNDEBUG     -fopenmp  -fpic  -g -O2 -ffile-prefix-map=/build/r-base-Faorqz/r-base-4.2.2.20221110=. -fstack-protector-strong -Wformat -Werror=format-security -Wdate-time -D_FORTIFY_SOURCE=2  -c rbindlist.c -o rbindlist.o
2023-02-20T11:43:01.7972231Z gcc -I"/usr/share/R/include" -DNDEBUG     -fopenmp  -fpic  -g -O2 -ffile-prefix-map=/build/r-base-Faorqz/r-base-4.2.2.20221110=. -fstack-protector-strong -Wformat -Werror=format-security -Wdate-time -D_FORTIFY_SOURCE=2  -c reorder.c -o reorder.o
2023-02-20T11:43:01.9580669Z gcc -I"/usr/share/R/include" -DNDEBUG     -fopenmp  -fpic  -g -O2 -ffile-prefix-map=/build/r-base-Faorqz/r-base-4.2.2.20221110=. -fstack-protector-strong -Wformat -Werror=format-security -Wdate-time -D_FORTIFY_SOURCE=2  -c shift.c -o shift.o
2023-02-20T11:43:02.1703156Z gcc -I"/usr/share/R/include" -DNDEBUG     -fopenmp  -fpic  -g -O2 -ffile-prefix-map=/build/r-base-Faorqz/r-base-4.2.2.20221110=. -fstack-protector-strong -Wformat -Werror=format-security -Wdate-time -D_FORTIFY_SOURCE=2  -c snprintf.c -o snprintf.o
2023-02-20T11:43:02.3287870Z gcc -I"/usr/share/R/include" -DNDEBUG     -fopenmp  -fpic  -g -O2 -ffile-prefix-map=/build/r-base-Faorqz/r-base-4.2.2.20221110=. -fstack-protector-strong -Wformat -Werror=format-security -Wdate-time -D_FORTIFY_SOURCE=2  -c subset.c -o subset.o
2023-02-20T11:43:02.7030798Z gcc -I"/usr/share/R/include" -DNDEBUG     -fopenmp  -fpic  -g -O2 -ffile-prefix-map=/build/r-base-Faorqz/r-base-4.2.2.20221110=. -fstack-protector-strong -Wformat -Werror=format-security -Wdate-time -D_FORTIFY_SOURCE=2  -c transpose.c -o transpose.o
2023-02-20T11:43:02.8237564Z gcc -I"/usr/share/R/include" -DNDEBUG     -fopenmp  -fpic  -g -O2 -ffile-prefix-map=/build/r-base-Faorqz/r-base-4.2.2.20221110=. -fstack-protector-strong -Wformat -Werror=format-security -Wdate-time -D_FORTIFY_SOURCE=2  -c types.c -o types.o
2023-02-20T11:43:02.9391304Z gcc -I"/usr/share/R/include" -DNDEBUG     -fopenmp  -fpic  -g -O2 -ffile-prefix-map=/build/r-base-Faorqz/r-base-4.2.2.20221110=. -fstack-protector-strong -Wformat -Werror=format-security -Wdate-time -D_FORTIFY_SOURCE=2  -c uniqlist.c -o uniqlist.o
2023-02-20T11:43:03.3234653Z gcc -I"/usr/share/R/include" -DNDEBUG     -fopenmp  -fpic  -g -O2 -ffile-prefix-map=/build/r-base-Faorqz/r-base-4.2.2.20221110=. -fstack-protector-strong -Wformat -Werror=format-security -Wdate-time -D_FORTIFY_SOURCE=2  -c utils.c -o utils.o
2023-02-20T11:43:03.5883632Z gcc -I"/usr/share/R/include" -DNDEBUG     -fopenmp  -fpic  -g -O2 -ffile-prefix-map=/build/r-base-Faorqz/r-base-4.2.2.20221110=. -fstack-protector-strong -Wformat -Werror=format-security -Wdate-time -D_FORTIFY_SOURCE=2  -c vecseq.c -o vecseq.o
2023-02-20T11:43:03.6711753Z gcc -I"/usr/share/R/include" -DNDEBUG     -fopenmp  -fpic  -g -O2 -ffile-prefix-map=/build/r-base-Faorqz/r-base-4.2.2.20221110=. -fstack-protector-strong -Wformat -Werror=format-security -Wdate-time -D_FORTIFY_SOURCE=2  -c wrappers.c -o wrappers.o
2023-02-20T11:43:03.7834029Z gcc -shared -L/usr/lib/R/lib -Wl,-Bsymbolic-functions -flto=auto -ffat-lto-objects -flto=auto -Wl,-z,relro -o data.table.so assign.o between.o bmerge.o chmatch.o cj.o coalesce.o dogroups.o fastmean.o fcast.o fifelse.o fmelt.o forder.o frank.o fread.o freadR.o froll.o frollR.o frolladaptive.o fsort.o fwrite.o fwriteR.o gsumm.o ijoin.o init.o inrange.o nafill.o nqrecreateindices.o openmp-utils.o quickselect.o rbindlist.o reorder.o shift.o snprintf.o subset.o transpose.o types.o uniqlist.o utils.o vecseq.o wrappers.o -fopenmp -lz -L/usr/lib/R/lib -lR
2023-02-20T11:43:03.8554926Z PKG_CFLAGS = -fopenmp
2023-02-20T11:43:03.8575884Z PKG_LIBS = -fopenmp -lz
2023-02-20T11:43:03.8579104Z if [ "data.table.so" != "data_table.so" ]; then mv data.table.so data_table.so; fi
2023-02-20T11:43:03.8617729Z if [ "" != "Windows_NT" ] && [ `uname -s` = 'Darwin' ]; then install_name_tool -id data_table.so data_table.so; fi
2023-02-20T11:43:03.8665130Z installing to /home/runner/work/_temp/Library/00LOCK-data.table/00new/data.table/libs
2023-02-20T11:43:03.8695240Z ** R
2023-02-20T11:43:03.9024096Z ** inst
2023-02-20T11:43:03.9119432Z ** byte-compile and prepare package for lazy loading
2023-02-20T11:43:10.1182837Z ** help
2023-02-20T11:43:10.4805368Z *** installing help indices
2023-02-20T11:43:10.7122365Z ** building package indices
2023-02-20T11:43:11.1009830Z ** installing vignettes
2023-02-20T11:43:11.1111311Z ** testing if installed package can be loaded from temporary location
2023-02-20T11:43:11.4243464Z ** checking absolute paths in shared objects and dynamic libraries
2023-02-20T11:43:11.5941898Z ** testing if installed package can be loaded from final location
2023-02-20T11:43:12.1180361Z ** testing if installed package keeps a record of temporary installation path
2023-02-20T11:43:12.1241059Z * DONE (data.table)

However, upon the second phase discovery for BioConductor lessons, it searches the posit package manager and that is installed into the cache:

2023-02-20T11:46:15.4010963Z Retrieving 'https://packagemanager.posit.co/cran/__linux__/jammy/latest/src/contrib/data.table_1.14.6.tar.gz' ...
2023-02-20T11:46:16.3074820Z 	OK [downloaded 2 Mb in 0.9 secs]

[snip]

2023-02-20T11:54:39.0919530Z Installing data.table [1.14.6] ...
2023-02-20T11:54:39.6095541Z 	OK [installed binary]
2023-02-20T11:54:39.6118804Z Moving data.table [1.14.6] into the cache ...

And then the snapshot downgrades the package cache:

2023-02-20T11:58:33.8238395Z → Restoring any dependency versions
2023-02-20T11:58:34.2091149Z The following package(s) will be updated:
2023-02-20T11:58:34.2091657Z 
2023-02-20T11:58:34.2091985Z # CRAN ===============================
2023-02-20T11:58:34.2093277Z - Matrix       [1.5-1 -> 1.5-3]
2023-02-20T11:58:34.2094377Z - RSQLite      [repo: RSPM -> CRAN; ver: 2.2.20 -> 2.3.0]
2023-02-20T11:58:34.2095313Z - data.table   [repo: RSPM -> CRAN; ver: 1.14.6 -> 1.14.8]
2023-02-20T11:58:34.2096214Z - fs           [repo: RSPM -> CRAN; ver: 1.6.1 -> 1.6.0]
2023-02-20T11:58:34.2097097Z - ggplot2      [repo: RSPM -> CRAN; ver: 3.4.1 -> 3.4.0]
2023-02-20T11:58:34.2097807Z - nlme         [3.1-162 -> 3.1-161]
2023-02-20T11:58:34.2098429Z - cluster      [* -> 2.1.4]
2023-02-20T11:58:34.2099038Z - renv         [* -> 0.16.0]
2023-02-20T11:58:34.2099310Z 
2023-02-20T11:58:34.2099608Z # RSPM ===============================
2023-02-20T11:58:34.2100441Z - codetools    [* -> 0.2-19]
2023-02-20T11:58:34.2100739Z 
2023-02-20T11:58:37.2334893Z Warning message:
2023-02-20T11:58:37.2335517Z curl: (22) The requested URL returned error: 404 
2023-02-20T11:58:37.7106112Z Error: 
2023-02-20T11:58:37.7106930Z ! in callr subprocess.
2023-02-20T11:58:37.7107342Z Caused by error: 
2023-02-20T11:58:37.7108198Z ! failed to find source for 'data.table 1.14.8' in package repositories
2023-02-20T11:58:37.7108647Z ---

Full log: bioc-rnaseq-failed-datatable.txt

[zkamvar]

This might actually be a problem with the renv::install() in {sandpaper}, which was implemented in carpentries/sandpaper#397