Executing quarto render [target] randomly emits 'renv-snapshot dependency-discovery'-messages at random locations and intervals

[Gewerd-Strauss]

Description

Hello,

I am quite a bit confused.
Recently, I am encountering the following output during the execution of quarto render within a website-project:

$ quarto render experiments/ --to html
scripts/pre-render/isQuartoProject.R

NOTE: Dependency discovery took 11 seconds during snapshot.
Consider using .renvignore to ignore files, or switching to explicit snapshots.
See `?renv::dependencies` for more information.

This project uses renv; and during pre-render it will manually call renv::snapshot() iff the last render was 20+ minutes ago (scripts/pre-render/update_renv_lockfile.R):

cat("\014") ## clear console
library(stringr)
remove (list = ls()) ## clear environment variables
start <- Sys.time()
root <- fs::path_abs(".")
source(normalizePath(str_c(root, "\\scripts\\utility\\log.R")))
renv_path <- normalizePath(str_c(root,"\\renv.lock"))
commit_renv <- function(renv_path,message = "") {
    system(paste("git add renv.lock"))
    date_string <- format(Sys.time(), "%Y-%m-%d %H:%M")
    commit_message <- str_c(message," ",date_string)

    commit_command <- paste0("git commit -q -m", shQuote(commit_message))
    system(commit_command)
}
if (isFALSE(file.exists(renv_path))) {
    cli::cli_alert_danger(str_c("No renv-lockfile found. Package dependencies are not tracked for this project!"))
} else {
    current_branch <- system("git rev-parse --abbrev-ref HEAD", intern = TRUE)
    if (isFALSE(current_branch=="master")) {
        cli::cli_alert_warning("Current branch is not master. Lockfile will not be updated/committed.")
    } else {
        minutes <- 60
        threshold <- 60 * minutes # set update-threshold in minutes.
        current_time <- Sys.time()

        # make sure lockfile is only updated every X hours/minutes
        last_renv_update_file <- normalizePath(str_c(root,"\\scripts\\excludes\\logs\\lastrenvupdate.txt"))
        if (isFALSE(file.exists(last_renv_update_file))) {
            # If the file does not exist, create it and write the timestamp of the current time minus the threshold
            initial_time <- current_time - threshold
            write(as.character(initial_time), file = last_renv_update_file)
        }
        
        stored_time <- as.POSIXct(readLines(last_renv_update_file))
        time_difference <- difftime(Sys.time(), stored_time, units = "secs")
        # threshold in seconds: 20 minues
        if (time_difference>=threshold) {
            cli::cli_alert_info("Updating renv-lockfile.")
            renv::snapshot(confirm = FALSE)    
            cli::cli_alert_success("The renv-lockfile was updated.")
            cli::cli_alert_info("Committing renv-lockfile")
            commit_renv(renv_path = renv_path, message = "Chore: update renv-lockfile.")
            cli::cli_alert_success("Changes to renv-lockfile were committed.")
            write(as.character(current_time), file = last_renv_update_file)
        } else {
            cli::cli_alert_info(str_c("The renv-file was updated and committed within the last ", minutes, " minutes. Skipping updates."))
        }
    }
}

This script is executed second:

project:
  type: website
  output-dir: _site
  execute-dir: project
  render: # order in project.render is important; because documents are rendered in this order. a change that should suppress an update in 5 minutes
  - report/manuscript.qmd
  - "*.qmd"
  - "*.md"
  - "!__packages-citations.md"
  - "!excludes/*.md"
  - "!excludes/*.qmd"
  - "!private/*/*.md"
  - "!private/*/*.qmd"
  - "!private/*.md"
  - "!private/*.qmd"
  - "!assets/*/*.md"
  - "!assets/*/*.qmd"
  - "!report/parts/*introduction.md"
  - "!report/parts/*.qmd"
  - "!report/exp_analyses/*.qmd" # do not render parts which are only to be embedded into the report
  - "!README.md"
  pre-render: 
  - scripts/pre-render/isQuartoProject.R
  - scripts/pre-render/update_renv_lockfile.R
  - scripts/pre-render/run_OK_on_OKRequired.R
  - scripts/pre-render/rename_to_QMD.R
  - scripts/pre-render/updateCodeReferences.R

There are a couple things to note:

1. The position in the cli-output where the dependency-discovery-notice is placed is random. It can happen 0 times, 1 time, or multiple times. It is not restricted to the output emitted during pre-render-script execution and can pop up anywhere in the standard x/n: file: processing file-message outlined below:

[19/20] experiments\exp_image-resolution.qmd


processing file: exp_image-resolution.qmd
1/9
2/9 [tbl-overview-image-resolution-settings]
3/9
4/9 [fig-image-resolution-coordinate-system]
5/9
6/9 [instructions-image-resolution]
7/9
8/9 [tbl-variants-overview-image-resolution]
9/9
output file: exp_image-resolution.knit.md

2. The one script¹ which does call renv::snapshot() emits information via the cli-package before and after doing so. This does not add up, strings which would be emitted in this case are missing from output at these times.

---

At the bottom of this discussion I have attached parts of a quarto render-output which exhibits this issue in a project of mine.

I cannot currently reliably replicate this issue, I don't even know what triggers it.
I have not yet confirmed that the 'time taken' as displayed in the message is actually suffered - i.e. does it really take 11 seconds each time this message is emitted, or not?

I am posting this because I don't see how this message should be displaceable like this. No other message emitted by any other script so far has shown similar behaviour.

Does quarto interact with renv under the hood in any way that could reasonably lead to this super weird behaviour?

---

Thank you.
Sincerely
~Gw

---

---

quarto check:

Quarto 1.5.54
[>] Checking versions of quarto binary dependencies...
      Pandoc version 3.2.0: OK
      Dart Sass version 1.70.0: OK
      Deno version 1.41.0: OK
      Typst version 0.11.0: OK
[>] Checking versions of quarto dependencies......OK
[>] Checking Quarto installation......OK
      Version: 1.5.54
      Path: D:\CLI\quarto\bin
      CodePage: 1252

[>] Checking tools....................OK
      TinyTeX: v2024.02
      Chromium: 869685

[>] Checking LaTeX....................OK
      Using: TinyTex
      Path: C:\ProgramData\TinyTeX\bin\windows\
      Version: 2023

[>] Checking basic markdown render....OK

[>] Checking Python 3 installation....(None)

      Unable to locate an installed version of Python 3.
      Install Python 3 from https://www.python.org/downloads/

[>] Checking R installation...........OK
      Version: 4.4.0
      Path: D:/CLI/r/R-4.4.0
      LibPaths:
        - D:/Dokumente neu/Obsidian NoteTaking/BE31-Thesis-quarto/.renv/library/R-4.4/x86_64-w64-mingw32
        - C:/Users/Claudius Main/AppData/Local/R/cache/R/renv/sandbox/R-4.4/x86_64-w64-mingw32/501e432c
      knitr: 1.45
      rmarkdown: 2.25

[>] Checking Knitr engine render......OK

---

Partial output of quarto render ... which exhibits the described issue:

> quarto render 

...

scripts/pre-render/update_code_references.R

NOTE: Dependency discovery took 11 seconds during snapshot.
Consider using .renvignore to ignore files, or switching to explicit snapshots.
See `?renv::dependencies` for more information.


ℹ Updating R-package bibliography
✔ Updated R-package bibliography, taking ~'0.0703436493873596' mins

[ 1/26] experiments\experiments.md

...

[ 9/26] index.qmd


processing file: index.qmd
1/9
2/9 [knitr_default]
3/9
4/9 [d]
5/9
6/9 [quarto_input]
7/9
8/9 [quarto_project]
9/9
output file: index.knit.md


NOTE: Dependency discovery took 11 seconds during snapshot.
Consider using .renvignore to ignore files, or switching to explicit snapshots.
See `?renv::dependencies` for more information.



processing file: index.qmd
1/9
2/9 [knitr_default]
3/9
4/9 [d]
5/9
6/9 [quarto_input]
7/9
8/9 [quarto_project]
9/9
output file: index.knit.md


Rendering PDF
running xelatex - 1
  This is XeTeX, Version 3.141592653-2.6-0.999995 (TeX Live 2023) (preloaded format=xelatex)
   restricted \write18 enabled.
  entering extended mode

running xelatex - 2
  This is XeTeX, Version 3.141592653-2.6-0.999995 (TeX Live 2023) (preloaded format=xelatex)
   restricted \write18 enabled.
  entering extended mode


[10/26] experiments\exp_IDdot_size.qmd

Rendering PDF
running xelatex - 1
  This is XeTeX, Version 3.141592653-2.6-0.999995 (TeX Live 2023) (preloaded format=xelatex)
   restricted \write18 enabled.
  entering extended mode

running xelatex - 2
  This is XeTeX, Version 3.141592653-2.6-0.999995 (TeX Live 2023) (preloaded format=xelatex)
   restricted \write18 enabled.
  entering extended mode


[11/26] experiments\exp_camera-aperture.qmd

NOTE: Dependency discovery took 10 seconds during snapshot.
Consider using .renvignore to ignore files, or switching to explicit snapshots.
See `?renv::dependencies` for more information.



processing file: exp_camera-aperture.qmd
1/7
2/7 [instructions-camera-aperture-calculations]
3/7
4/7 [fig-camera-aperture-coordinate-system]
5/7
6/7 [tbl-variants-overview-camera-aperture]
7/7
output file: exp_camera-aperture.knit.md



processing file: exp_camera-aperture.qmd
1/7
2/7 [instructions-camera-aperture-calculations]
3/7
4/7 [fig-camera-aperture-coordinate-system]
5/7
6/7 [tbl-variants-overview-camera-aperture]
7/7
output file: exp_camera-aperture.knit.md

Footnotes

1. outlined above ↩

[mcanouil]

NOTE: Dependency discovery took 11 seconds during snapshot.
Consider using .renvignore to ignore files, or switching to explicit snapshots.
See ?renv::dependencies for more information.

This message comes from renv and is unrelated to Quarto or even knitr.
Each Quarto documents starts a new R process, thus loading the .Rprofile which in turn loads renv that displays the message.

[Gewerd-Strauss]

I am aware that this is a renv-message.

But if this is an artifact of each qmd-document being converted/each R-script being executed, why does this happen so irregularly?
I mean, I don't even get this on successive renderings with no modifation to any source doc. One time I get it, one time I don't.

I mean, is renv's dependency discovery so... inconsistent in its execution time?

It's this irregularity that I find odd.

[mcanouil]

You are asking in the wrong repository.
Quarto is only starting R process, everything else is not Quarto's doing.
If you want to understand renv dependencies discovery go to renv repository.