Log val.pipeline version + install path at the top of every val_build() run (#179) - #180
Conversation
…() run (#179) The val_build() banner in val_pipeline.log used to read === val_build() @ 2026-09-14 ... (R 4.5.2, metric_pkg=riskmetric, ...) === which recorded the R version but NOT which val.pipeline version was actually loaded, nor which library slot it came from. That made it impossible to retrospectively answer "which val.pipeline built this?" from the log alone -- an operator only found out by cross-referencing `qual_metadata.rds$val_pipeline_ver` after the run completed. That gap showed up in practice recently: an operator installed 0.1.59 into their user library, tested it interactively, and launched a workbench job that they believed picked up 0.1.59. The log looked recent (contained the `Pandoc discovery:` and `HOME is unset ... overriding HOME = ...` messages that were added in #167 and #173/174) so they assumed it was 0.1.59, but the job actually resolved 0.1.57 from a different `.libPaths()` slot than the interactive session. Both of those "recent" log messages shipped in 0.1.57, so their presence alone doesn't distinguish 0.1.57 from 0.1.59. The banner now does: === val_build() @ 2026-09-14 ... (val.pipeline 0.1.60, R 4.5.2, ...) === --> val.pipeline 0.1.60 loaded from '/home/aclark02/R/.../val.pipeline' (`.libPaths()` slot 2 of 3). The library slot is expressed as "N of M" of `.libPaths()` so a stale rv / renv library at slot 1 is visible without a second command. Falls back gracefully to the plain "loaded from '<dir>'" form when find.package() lands outside .libPaths() (typical of `devtools::load_all()` sessions -- the source-dir path is not a real library slot). Version bump 0.1.59 -> 0.1.60 + NEWS entry. No test churn: the change is purely a `val_msg()` add + a header string extension. Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
Diagnostic scaffolding for the covr_coverage delta reported on 2026-09-14:
val_build(pkg_names="logrx", ...) in a workbench job returns >90%,
val_pipeline(...) in the SAME workbench job (same hard-pinned 2026-08-15
CRAN snapshot, same logrx 0.4.0 tarball) returns 62%. Since the tarball
is identical, the delta must live in what val_prep_pipeline() /
val_pipeline() do to the session state BEFORE val_build() runs.
The script captures a probe_run_context() bundle immediately before each
call:
* .libPaths() and installed.packages() key/version snapshot
* Sys.getenv() for all covr-relevant vars (PATH, HOME, R_LIBS_*,
RSTUDIO_PANDOC, NOT_CRAN, TESTTHAT, locale, ...)
* options() slots (repos, pkgType, val.pipeline.config_path,
val.pipeline.capture_covr_skip_report, ...)
* val.pipeline unexported helpers (pull_covr_env_vars,
pull_covr_path_env, pull_covr_home_env, resolve_covr_pandoc_dir)
guarded with tryCatch() in case internal shape shifts
* rmarkdown::pandoc_available() live check
Operator runs it once with MODE = "val_build" and once with MODE =
"val_pipeline" as separate workbench jobs, then sources the DIFF ONLY
block (waldo::compare on the scalar/vector context + a merge on
installed.packages()) to identify the delta without paying for a second
40-minute pipeline invocation.
Not exported / not built into the pkg -- dev/*.R is .Rbuildignore'd.
Kept off main in favor of shipping with the #180 branch since the two
addresses the same "make effective run context loud" theme.
Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
Aaron flagged that firing val_pipeline() against a ~1.5k pkg universe would take days. The whole point of the probe is to capture the session-state delta val_prep_pipeline() introduces before val_build() fires -- we never needed the covr work to complete. The script now snapshots twice in a single job: once before val_prep_pipeline() (bare val_build() state) and once after (val_pipeline() pre-val_build state), then diffs the two in-process via waldo::compare() plus an installed.packages() merge and .libPaths() dump. Runs in minutes on the ~1.5k pkg universe -- the prep step only touches remote_reduce metadata + dep tree, never covr. Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
There was a problem hiding this comment.
🟡 Changes recommended
Quiet logging omits the promised path, the diagnostic comparison can report false changes, and regression tests are missing.
Get a fresh assessment by requesting another Copilot review.
Pull request overview
Adds val.pipeline version and library-location diagnostics to each val_build() run.
Changes:
- Logs the loaded package version, path, and library slot.
- Adds a diagnostic script for comparing pipeline state.
- Bumps version to 0.1.60 and updates NEWS.
File summaries
| File | Description |
|---|---|
R/val_build.R |
Adds version and installation-path logging. |
dev/dev_diagnose_val_build_vs_val_pipeline.R |
Adds state-comparison diagnostics. |
DESCRIPTION |
Bumps package version. |
NEWS.md |
Documents the new logging behavior. |
Review details
- Files reviewed: 4/4 changed files
- Comments generated: 3
- Review effort level: Balanced
💡 Add a code-review agent skill or configure MCP servers for context-aware, tailored reviews. Learn more in the docs.
| val_msg(paste0("--> val.pipeline ", vp_ver, | ||
| " loaded from '", vp_lib, "'", vp_lib_slot, ".\n"), | ||
| min_level = "minimal") |
| ai <- before$installed[, c("Package", "Version")] | ||
| bi <- after$installed[, c("Package", "Version")] | ||
| names(ai)[2] <- "Version.before" | ||
| names(bi)[2] <- "Version.after" | ||
| diff_pkgs <- merge(ai, bi, by = "Package", all = TRUE) | ||
| diff_pkgs <- diff_pkgs[with(diff_pkgs, | ||
| is.na(Version.before) | is.na(Version.after) | | ||
| Version.before != Version.after), ] | ||
| diff_pkgs <- diff_pkgs[order(diff_pkgs$Package), ] |
| vp_lib_slot <- if (!is.na(vp_lib)) { | ||
| # `find.package()` returns the package dir; its parent is the | ||
| # library. Match against `.libPaths()` by normalised path. | ||
| lib_dir <- dirname(vp_lib) | ||
| idx <- which(normalizePath(vp_libpaths, mustWork = FALSE) == |
Adopt two Copilot review suggestions on #179 log-vp-version work: 1. R/val_build.R: move the val.pipeline install path + `.libPaths()` slot into the unconditional `init_val_log()` header rather than only emitting them via `val_msg(min_level = 'minimal')`. Under a `log_level = 'quiet'` run the `val_msg()` line was filtered from the log, defeating the whole 'retrospectively answer which val.pipeline built this' goal. The header writes unconditionally regardless of log level, so the origin now survives quiet. Console-side echo is kept via the same `val_msg()` line so interactive users still see the confirmation surfaced. 2. dev/dev_diagnose_val_build_vs_val_pipeline.R: fix Cartesian merge of before/after `installed.packages()` snapshots. Merging on `Package` alone Cartesian-products any package that appears in more than one library slot (e.g. base pkgs present in both an rv library and the site library), producing dozens of phantom 'before != after' rows that were just row-reordering artifacts. Now merge on `(Package, LibPath)` and carry LibPath in the snapshot select. Refs #179. Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
|
Adopted 2 of 3 Copilot review suggestions in 65d666c: Adopted
Skipped
Tests: |
Closes #179.
What
Bake the loaded `val.pipeline` version + its resolved library slot
into the `val_build()` banner in `val_pipeline.log`, so an
operator can retrospectively answer "which val.pipeline built this?"
from the log alone.
Before:
```
=== val_build() @ 2026-09-14 06:00:00 PDT (R 4.5.2, metric_pkg=riskmetric, ref=source, workers=2) ===
```
After:
```
=== val_build() @ 2026-09-14 06:00:00 PDT (val.pipeline 0.1.60, R 4.5.2, metric_pkg=riskmetric, ref=source, workers=2) ===
--> val.pipeline 0.1.60 loaded from '/home/aclark02/R/x86_64-pc-linux-gnu-library/4.5/val.pipeline' (`.libPaths()` slot 2 of 3).
```
Why
An operator recently ran what they thought was 0.1.59 and got a
suspiciously low logrx coverage number. The log looked recent
because it contained `Pandoc discovery:` and `HOME is unset ...
overriding HOME = ...` lines. Those messages, however, shipped in
0.1.57 (#167 and #173/174 respectively), so their presence
doesn't distinguish 0.1.57 from 0.1.59. The job actually resolved
0.1.57 from a different `.libPaths()` slot than the operator's
interactive session had -- a classic "stale rv snapshot at slot 1"
issue -- and the mismatch was only detectable by opening
`qual_metadata.rds$val_pipeline_ver` after the fact.
Verification
Smoke test in a `devtools::load_all()` session against an empty'" form because the source dir is not a real
package list confirmed the banner + follow-up line render correctly
(the load_all() case correctly falls back to the plain "loaded from
'
`.libPaths()` slot). `devtools::test()`: 1071 pass / 0 fail /
1 skip (unchanged).
Version / NEWS