diff --git a/.changeset/lockfile-verification-cached-message.md b/.changeset/lockfile-verification-cached-message.md new file mode 100644 index 0000000000..ed498ceee2 --- /dev/null +++ b/.changeset/lockfile-verification-cached-message.md @@ -0,0 +1,8 @@ +--- +"@pnpm/core-loggers": minor +"@pnpm/cli.default-reporter": minor +"@pnpm/installing.deps-installer": patch +"pnpm": patch +--- + +Print a "Lockfile passes supply-chain policies (verified 2h ago)" message when lockfile verification is skipped because a cached verdict for the same lockfile content and policy is reused. Previously the cached short-circuit was completely silent, which made it look like the policy gate never ran [#12324](https://github.com/pnpm/pnpm/issues/12324). diff --git a/cli/default-reporter/src/reporterForClient/reportLockfileVerification.ts b/cli/default-reporter/src/reporterForClient/reportLockfileVerification.ts index c6d771032d..545954580d 100644 --- a/cli/default-reporter/src/reporterForClient/reportLockfileVerification.ts +++ b/cli/default-reporter/src/reporterForClient/reportLockfileVerification.ts @@ -29,6 +29,11 @@ export function reportLockfileVerification ( return Rx.of(lockfileVerification$.pipe( map((log) => { const path_ = formatLockfilePath(log.lockfilePath, opts.cwd, expectedDir) + if (log.status === 'cached') { + return { + msg: `${chalk.green('✓')} Lockfile${path_} passes supply-chain policies (${formatCachedVerdict(log.verifiedAt)})`, + } + } const entries = `${log.entries} ${log.entries === 1 ? 'entry' : 'entries'}` switch (log.status) { case 'started': @@ -51,6 +56,17 @@ export function reportLockfileVerification ( )) } +// Relative "verified 2h ago" when the cached record carries a parseable +// timestamp; the timeless "previously verified" otherwise. The elapsed +// time is clamped at zero so a clock that moved backwards between the +// verification run and this install doesn't render a negative age. +function formatCachedVerdict (verifiedAt: string | undefined): string { + if (verifiedAt == null) return 'previously verified' + const elapsedMs = Date.now() - Date.parse(verifiedAt) + if (Number.isNaN(elapsedMs)) return 'previously verified' + return `verified ${prettyMs(Math.max(elapsedMs, 0), { compact: true })} ago` +} + // Returns a leading-space-prefixed `at ` suffix only when the // lockfile sits outside the obvious project/workspace root — otherwise // the path is implied and printing it would just add noise to every diff --git a/cli/default-reporter/test/reportingLockfileVerification.ts b/cli/default-reporter/test/reportingLockfileVerification.ts index 60d1339bd9..15854f90b9 100644 --- a/cli/default-reporter/test/reportingLockfileVerification.ts +++ b/cli/default-reporter/test/reportingLockfileVerification.ts @@ -129,6 +129,42 @@ test('suppresses path when workspaceDir has a trailing separator', async () => { expect(stripAnsi(started)).toBe('? Verifying lockfile against supply-chain policies (3 entries)...') }) +test('prints a previously-verified line when the cached verdict is reused', async () => { + const cwd = '/repo' + const output$ = toOutput$({ + context: { + argv: ['install'], + config: { dir: cwd } as Config & ConfigContext, + }, + streamParser: createStreamParser(), + }) + + const frames = firstValueFrom(output$.pipe(take(1), toArray())) + + lockfileVerificationLogger.debug({ + status: 'cached', + verifiedAt: new Date(Date.now() - 2 * 60 * 60 * 1000).toISOString(), + lockfilePath: path.join(cwd, 'pnpm-lock.yaml'), + }) + + const [cached] = await frames + expect(stripAnsi(cached)).toBe('✓ Lockfile passes supply-chain policies (verified 2h ago)') +}) + +test('falls back to a timeless cached message when the record has no timestamp', async () => { + const output$ = toOutput$({ + context: { argv: ['install'] }, + streamParser: createStreamParser(), + }) + + const frames = firstValueFrom(output$.pipe(take(1), toArray())) + + lockfileVerificationLogger.debug({ status: 'cached' }) + + const [cached] = await frames + expect(stripAnsi(cached)).toBe('✓ Lockfile passes supply-chain policies (previously verified)') +}) + test('emits a brief failure line on failed status', async () => { const output$ = toOutput$({ context: { argv: ['install'] }, diff --git a/core/core-loggers/src/lockfileVerificationLogger.ts b/core/core-loggers/src/lockfileVerificationLogger.ts index 3383771e56..ba93335872 100644 --- a/core/core-loggers/src/lockfileVerificationLogger.ts +++ b/core/core-loggers/src/lockfileVerificationLogger.ts @@ -6,7 +6,7 @@ import { export const lockfileVerificationLogger = logger('lockfile-verification') export interface LockfileVerificationMessageBase { - status: 'started' | 'done' | 'failed' + status: 'started' | 'done' | 'failed' | 'cached' /** * Absolute path of the lockfile being verified. Omitted only when * the verifier is invoked without a path (today only in unit tests @@ -45,10 +45,27 @@ export interface LockfileVerificationFailedMessage extends LockfileVerificationM elapsedMs: number } +/** + * Emitted instead of a `started`/`done` pair when the verification + * cache already holds a passing verdict for this lockfile content + * under the same (or stricter) policy, so the gate short-circuited + * without contacting the registry. Carries no `entries` count — the + * short-circuit happens before candidates are collected. + */ +export interface LockfileVerificationCachedMessage extends LockfileVerificationMessageBase { + status: 'cached' + /** + * ISO-8601 timestamp of the verification run the cached verdict was + * recorded by. Omitted when the cache record predates the field. + */ + verifiedAt?: string +} + export type LockfileVerificationMessage = | LockfileVerificationStartedMessage | LockfileVerificationDoneMessage | LockfileVerificationFailedMessage + | LockfileVerificationCachedMessage export type LockfileVerificationLog = & { name: 'pnpm:lockfile-verification' } diff --git a/installing/deps-installer/src/install/verifyLockfileResolutions.ts b/installing/deps-installer/src/install/verifyLockfileResolutions.ts index a3f18cd92b..c601211fcb 100644 --- a/installing/deps-installer/src/install/verifyLockfileResolutions.ts +++ b/installing/deps-installer/src/install/verifyLockfileResolutions.ts @@ -130,14 +130,28 @@ export async function verifyLockfileResolutions ( verifiers: cacheVerifiers, hashLockfile, }) - if (result.hit) return + if (result.hit) { + // A silent short-circuit looks like the policy gate never ran + // (pnpm/pnpm#12324), so surface the reused verdict — but only + // when policy verifiers are active; the shape-only run that + // every install performs stays quiet. + if (verifiers.length > 0) { + lockfileVerificationLogger.debug({ + status: 'cached', + verifiedAt: result.verifiedAt, + lockfilePath: options?.lockfilePath, + }) + } + return + } cachePrecomputed = result.precomputed } // Emit started/done around the actual verification pass — the // round-trip can be slow on a cold registry cache, and the cached - // short-circuit above doesn't reach this branch, so a user only - // sees these messages on installs that are doing real work. + // short-circuit above announces itself with its own `cached` event, + // so a user only sees these messages on installs that are doing + // real work. // A degenerate lockfile where every snapshot fails the // name/version extraction (so candidates is empty) skips emission // entirely — no work, no noise. diff --git a/installing/deps-installer/src/install/verifyLockfileResolutionsCache.ts b/installing/deps-installer/src/install/verifyLockfileResolutionsCache.ts index b1315577fb..3112a7ef75 100644 --- a/installing/deps-installer/src/install/verifyLockfileResolutionsCache.ts +++ b/installing/deps-installer/src/install/verifyLockfileResolutionsCache.ts @@ -106,6 +106,13 @@ interface CacheRecord { export interface CacheLookupResult { hit: boolean + /** + * ISO-8601 timestamp of the verification run the hit is reusing. + * Set only on a hit, and only when the record carries a usable + * timestamp (records written before the field existed normalize to + * an empty string and surface as `undefined` here). + */ + verifiedAt?: string /** * stat + hash already computed during the lookup. When the caller * follows up with {@link recordVerification} after running the gate, @@ -254,8 +261,10 @@ export function tryLockfileVerificationCache ( // hash without reading the file. Microseconds. const byPathRecord = indexes.byPath.get(key.lockfilePath) if (byPathRecord && statMatches(stat, byPathRecord.lockfile)) { + const hit = everyVerifierTrustsCachedRun(byPathRecord, key.verifiers) return { - hit: everyVerifierTrustsCachedRun(byPathRecord, key.verifiers), + hit, + verifiedAt: hit ? byPathRecord.verifiedAt || undefined : undefined, // The stat-match implies the file content is unchanged since the // cached record was written, so its hash is still correct. Pass // it through to skip hashing on the miss-then-record path. @@ -285,7 +294,7 @@ export function tryLockfileVerificationCache ( ...byHashRecord, lockfile: { ...byHashRecord.lockfile, path: key.lockfilePath, size: stat.size, mtimeNs: stat.mtimeNs, inode: stat.inode }, }) - return { hit: true, precomputed: { stat, hash } } + return { hit: true, verifiedAt: byHashRecord.verifiedAt || undefined, precomputed: { stat, hash } } } function everyVerifierTrustsCachedRun (record: CacheRecord, verifiers: readonly VerifierCacheIdentity[]): boolean { diff --git a/installing/deps-installer/test/install/verifyLockfileResolutions.ts b/installing/deps-installer/test/install/verifyLockfileResolutions.ts index 5be290ea96..4ab07628dc 100644 --- a/installing/deps-installer/test/install/verifyLockfileResolutions.ts +++ b/installing/deps-installer/test/install/verifyLockfileResolutions.ts @@ -2,7 +2,8 @@ import fs from 'node:fs' import os from 'node:os' import path from 'node:path' -import { expect, test } from '@jest/globals' +import { expect, jest, test } from '@jest/globals' +import { lockfileVerificationLogger } from '@pnpm/core-loggers' import type { LockfileObject } from '@pnpm/lockfile.fs' import type { ResolutionVerifier } from '@pnpm/resolving.resolver-base' @@ -262,6 +263,63 @@ test('skips the verifier when the cache holds an unchanged lockfile + matching p } }) +test('emits a cached event when the cache short-circuits verification', async () => { + const tmpDir = await fs.promises.mkdtemp(path.join(os.tmpdir(), 'pnpm-vlr-')) + try { + const cacheDir = path.join(tmpDir, 'cache') + const lockfilePath = path.join(tmpDir, 'pnpm-lock.yaml') + await fs.promises.writeFile(lockfilePath, 'lockfileVersion: \'9.0\'\n') + const lockfile = makeLockfile({ + 'a@1.0.0': { resolution: tarballResolution('sha512-a') }, + }) + const verifier = wrap(async () => ({ ok: true }), exampleSlot(60)) + + await verifyLockfileResolutions(lockfile, [verifier], { cacheDir, lockfilePath }) + + const debugSpy = jest.spyOn(lockfileVerificationLogger, 'debug') + try { + await verifyLockfileResolutions(lockfile, [verifier], { cacheDir, lockfilePath }) + expect(debugSpy.mock.calls.map(([message]) => message)).toEqual([ + { + status: 'cached', + verifiedAt: expect.stringMatching(/^\d{4}-\d{2}-\d{2}T/), + lockfilePath, + }, + ]) + } finally { + debugSpy.mockRestore() + } + } finally { + await fs.promises.rm(tmpDir, { recursive: true, force: true }) + } +}) + +test('reuses the cached verdict silently when no policy verifiers are active', async () => { + const tmpDir = await fs.promises.mkdtemp(path.join(os.tmpdir(), 'pnpm-vlr-')) + try { + const cacheDir = path.join(tmpDir, 'cache') + const lockfilePath = path.join(tmpDir, 'pnpm-lock.yaml') + await fs.promises.writeFile(lockfilePath, 'lockfileVersion: \'9.0\'\n') + const lockfile = makeLockfile({ + 'a@1.0.0': { resolution: tarballResolution('sha512-a') }, + }) + + await verifyLockfileResolutions(lockfile, [wrap(async () => ({ ok: true }), exampleSlot(60))], { + cacheDir, lockfilePath, + }) + + const debugSpy = jest.spyOn(lockfileVerificationLogger, 'debug') + try { + await verifyLockfileResolutions(lockfile, [], { cacheDir, lockfilePath }) + expect(debugSpy).not.toHaveBeenCalled() + } finally { + debugSpy.mockRestore() + } + } finally { + await fs.promises.rm(tmpDir, { recursive: true, force: true }) + } +}) + test('does not write a cache record when verification rejects', async () => { const tmpDir = await fs.promises.mkdtemp(path.join(os.tmpdir(), 'pnpm-vlr-')) try { diff --git a/pacquet/crates/lockfile-verification/src/cache.rs b/pacquet/crates/lockfile-verification/src/cache.rs index 31d3ebc7da..75ed9193fb 100644 --- a/pacquet/crates/lockfile-verification/src/cache.rs +++ b/pacquet/crates/lockfile-verification/src/cache.rs @@ -106,6 +106,10 @@ pub struct CacheLockfile { #[derive(Debug, Default, Clone)] pub struct CacheLookupResult { pub hit: bool, + /// ISO-8601 timestamp of the verification run the hit is reusing. + /// `Some` only on a hit, and only when the record carries a + /// non-empty timestamp. + pub verified_at: Option, pub precomputed: CachePrecomputed, } @@ -171,8 +175,11 @@ pub fn try_lockfile_verification_cache( if let Some(record) = indexes.by_path.get(&path_key) && stat_matches(&stat, &record.lockfile) { + let hit = every_verifier_trusts_cached_run(record, verifiers); return CacheLookupResult { - hit: every_verifier_trusts_cached_run(record, verifiers), + hit, + verified_at: (hit && !record.verified_at.is_empty()) + .then(|| record.verified_at.clone()), precomputed: CachePrecomputed { stat: Some(stat), hash: Some(record.lockfile.hash.clone()), @@ -184,12 +191,14 @@ pub fn try_lockfile_verification_cache( let Some(record) = indexes.by_hash.get(&hash) else { return CacheLookupResult { hit: false, + verified_at: None, precomputed: CachePrecomputed { stat: Some(stat), hash: Some(hash) }, }; }; if !every_verifier_trusts_cached_run(record, verifiers) { return CacheLookupResult { hit: false, + verified_at: None, precomputed: CachePrecomputed { stat: Some(stat), hash: Some(hash) }, }; } @@ -213,6 +222,7 @@ pub fn try_lockfile_verification_cache( CacheLookupResult { hit: true, + verified_at: (!refreshed.verified_at.is_empty()).then(|| refreshed.verified_at.clone()), precomputed: CachePrecomputed { stat: Some(stat), hash: Some(hash) }, } } diff --git a/pacquet/crates/lockfile-verification/src/verify_lockfile_resolutions.rs b/pacquet/crates/lockfile-verification/src/verify_lockfile_resolutions.rs index 55c95d4bf1..42ec5361e7 100644 --- a/pacquet/crates/lockfile-verification/src/verify_lockfile_resolutions.rs +++ b/pacquet/crates/lockfile-verification/src/verify_lockfile_resolutions.rs @@ -76,7 +76,9 @@ pub struct VerifyLockfileResolutionsOptions<'a> { /// terminal `Done` (success) or `Failed` (rejection), even if the /// fan-out panics; the failure variant of the emit is fired from the /// drop guard so the reporter never leaves a hanging "Verifying..." -/// frame. +/// frame. When the verification cache short-circuits the gate and +/// policy verifiers are active, a single `Cached` event fires +/// instead of the `Started`/`Done` pair. pub async fn verify_lockfile_resolutions( lockfile: &Lockfile, verifiers: &[Arc], @@ -109,6 +111,8 @@ pub async fn verify_lockfile_resolutions( hash }; + let lockfile_path_str = opts.lockfile_path.map(|path| path.to_string_lossy().into_owned()); + let mut cache_precomputed: CachePrecomputed = CachePrecomputed::default(); if let Some((cache_dir, lockfile_path)) = cache_inputs { let result = try_lockfile_verification_cache( @@ -118,6 +122,19 @@ pub async fn verify_lockfile_resolutions( &mut hash_once, ); if result.hit { + // A silent short-circuit looks like the policy gate never + // ran (pnpm/pnpm#12324), so surface the reused verdict — + // but only when policy verifiers are active; the + // shape-only run that every install performs stays quiet. + if !verifiers.is_empty() { + emit::( + LogLevel::Debug, + LockfileVerificationMessage::Cached { + verified_at: result.verified_at, + lockfile_path: lockfile_path_str, + }, + ); + } return Ok(()); } cache_precomputed = result.precomputed; @@ -130,7 +147,6 @@ pub async fn verify_lockfile_resolutions( if verifiers.is_empty() { return Ok(()); } - let lockfile_path_str = opts.lockfile_path.map(|path| path.to_string_lossy().into_owned()); if candidates.is_empty() { // Persist the success so the next install can stat-only the // lockfile. Matches upstream's behavior at diff --git a/pacquet/crates/lockfile-verification/src/verify_lockfile_resolutions/tests.rs b/pacquet/crates/lockfile-verification/src/verify_lockfile_resolutions/tests.rs index f391d68e09..94ba891cfc 100644 --- a/pacquet/crates/lockfile-verification/src/verify_lockfile_resolutions/tests.rs +++ b/pacquet/crates/lockfile-verification/src/verify_lockfile_resolutions/tests.rs @@ -513,6 +513,106 @@ async fn second_run_with_cache_skips_fan_out() { assert_eq!(CALLS.load(Ordering::SeqCst), 1, "second run skipped via cache"); } +/// A cache hit with active policy verifiers announces itself with a +/// single `Cached` event instead of the `Started`/`Done` pair, so the +/// short-circuit doesn't look like the policy gate never ran +/// (pnpm/pnpm#12324). +#[tokio::test] +async fn cache_hit_emits_cached_event() { + static EVENTS: Mutex> = Mutex::new(Vec::new()); + EVENTS.lock().unwrap().clear(); + struct RecordingReporter; + impl Reporter for RecordingReporter { + fn emit(event: &LogEvent) { + EVENTS.lock().unwrap().push(event.clone()); + } + } + + let dir = TempDir::new().expect("tempdir"); + let lockfile_path = dir.path().join("pnpm-lock.yaml"); + std::fs::write(&lockfile_path, SINGLE_PKG_LOCKFILE).expect("write lockfile"); + let lockfile = parse(SINGLE_PKG_LOCKFILE); + let cache_dir = dir.path().join("cache"); + let verifier = FailFor::new("UNUSED", "n/a", vec![]) as Arc; + let opts = VerifyLockfileResolutionsOptions { + lockfile_path: Some(&lockfile_path), + cache_dir: Some(&cache_dir), + ..Default::default() + }; + + verify_lockfile_resolutions::( + &lockfile, + std::slice::from_ref(&verifier), + &opts, + ) + .await + .expect("first run"); + verify_lockfile_resolutions::( + &lockfile, + std::slice::from_ref(&verifier), + &opts, + ) + .await + .expect("second run"); + + let captured = EVENTS.lock().unwrap(); + assert_eq!(captured.len(), 1, "expected a single Cached event, got: {captured:?}"); + match &captured[0] { + LogEvent::LockfileVerification(log) => match &log.message { + LockfileVerificationMessage::Cached { verified_at, lockfile_path: emitted } => { + assert_eq!(emitted.as_deref(), Some(&*lockfile_path.to_string_lossy())); + assert!( + verified_at.is_some(), + "the reused record carries the first run's timestamp", + ); + } + other => panic!("expected Cached, got {other:?}"), + }, + other => panic!("expected LockfileVerification, got {other:?}"), + } +} + +/// A cache hit with no policy verifiers stays silent — the shape-only +/// run that every install performs must not announce supply-chain +/// policies the user never configured. +#[tokio::test] +async fn cache_hit_with_no_policy_verifiers_stays_silent() { + static EVENTS: Mutex> = Mutex::new(Vec::new()); + EVENTS.lock().unwrap().clear(); + struct RecordingReporter; + impl Reporter for RecordingReporter { + fn emit(event: &LogEvent) { + EVENTS.lock().unwrap().push(event.clone()); + } + } + + let dir = TempDir::new().expect("tempdir"); + let lockfile_path = dir.path().join("pnpm-lock.yaml"); + std::fs::write(&lockfile_path, SINGLE_PKG_LOCKFILE).expect("write lockfile"); + let lockfile = parse(SINGLE_PKG_LOCKFILE); + let cache_dir = dir.path().join("cache"); + let verifier = FailFor::new("UNUSED", "n/a", vec![]) as Arc; + let opts = VerifyLockfileResolutionsOptions { + lockfile_path: Some(&lockfile_path), + cache_dir: Some(&cache_dir), + ..Default::default() + }; + + verify_lockfile_resolutions::( + &lockfile, + std::slice::from_ref(&verifier), + &opts, + ) + .await + .expect("first run"); + verify_lockfile_resolutions::(&lockfile, &[], &opts) + .await + .expect("second run"); + + let captured = EVENTS.lock().unwrap(); + assert!(captured.is_empty(), "shape-only cache hit must not emit, got: {captured:?}"); +} + /// Catches a regression where `PkgName` would be passed into the /// ctx as a borrow whose lifetime didn't outlive the future. #[tokio::test] diff --git a/pacquet/crates/package-manager/src/install/tests.rs b/pacquet/crates/package-manager/src/install/tests.rs index d94774cb5b..11f9b5b348 100644 --- a/pacquet/crates/package-manager/src/install/tests.rs +++ b/pacquet/crates/package-manager/src/install/tests.rs @@ -12,9 +12,9 @@ use pacquet_modules_yaml::{ }; use pacquet_package_manifest::{DependencyGroup, PackageManifest}; use pacquet_reporter::{ - BrokenModulesLog, ContextLog, HookLog, IgnoredScriptsLog, LogEvent, PackageManifestLog, - PackageManifestMessage, ProgressLog, ProgressMessage, Reporter, SilentReporter, Stage, - StageLog, StatsLog, StatsMessage, SummaryLog, + BrokenModulesLog, ContextLog, HookLog, IgnoredScriptsLog, LockfileVerificationMessage, + LogEvent, PackageManifestLog, PackageManifestMessage, ProgressLog, ProgressMessage, Reporter, + SilentReporter, Stage, StageLog, StatsLog, StatsMessage, SummaryLog, }; use pacquet_store_dir::STORE_VERSION; use pacquet_testing_utils::{ @@ -6106,9 +6106,16 @@ async fn fresh_install_records_lockfile_verification_for_mtime_bypassed_noop() { )), "second install must reach the modules/current-lockfile no-op path; got {captured:#?}", ); + let verification_messages: Vec<_> = captured + .iter() + .filter_map(|event| match event { + LogEvent::LockfileVerification(log) => Some(&log.message), + _ => None, + }) + .collect(); assert!( - !captured.iter().any(|event| matches!(event, LogEvent::LockfileVerification(_))), - "verification cache hit must skip the lockfile-verification fan-out; got {captured:#?}", + matches!(verification_messages.as_slice(), [LockfileVerificationMessage::Cached { .. }]), + "verification cache hit must skip the fan-out and announce the reused verdict; got {captured:#?}", ); drop(dir); diff --git a/pacquet/crates/reporter/src/lib.rs b/pacquet/crates/reporter/src/lib.rs index d599b31eb4..b8e1fdca2d 100644 --- a/pacquet/crates/reporter/src/lib.rs +++ b/pacquet/crates/reporter/src/lib.rs @@ -740,7 +740,10 @@ pub struct LockfileVerificationLog { /// `pnpm:lockfile-verification` discriminated payload. `Started` /// fires once before the per-candidate fan-out begins; exactly one /// terminal `Done` or `Failed` fires after, with `elapsed_ms` -/// measured against the matching `Started`. +/// measured against the matching `Started`. `Cached` fires instead +/// of the pair when the verification cache short-circuits the gate; +/// it carries no `entries` count because the short-circuit happens +/// before candidates are collected. /// /// `lockfile_path` is the absolute path of the lockfile being /// verified. It's `Option` because the runner is invoked without a @@ -769,6 +772,15 @@ pub enum LockfileVerificationMessage { #[serde(rename = "lockfilePath", skip_serializing_if = "Option::is_none")] lockfile_path: Option, }, + Cached { + /// ISO-8601 timestamp of the verification run the cached + /// verdict was recorded by. Omitted when the cache record + /// predates the field. + #[serde(rename = "verifiedAt", skip_serializing_if = "Option::is_none")] + verified_at: Option, + #[serde(rename = "lockfilePath", skip_serializing_if = "Option::is_none")] + lockfile_path: Option, + }, } /// Generic-channel (`name: "pnpm"`) payload, used for `logger.info`-style diff --git a/pacquet/crates/reporter/src/tests.rs b/pacquet/crates/reporter/src/tests.rs index caf5d836a5..6b41a86369 100644 --- a/pacquet/crates/reporter/src/tests.rs +++ b/pacquet/crates/reporter/src/tests.rs @@ -936,6 +936,55 @@ fn lockfile_verification_failed_event_matches_pnpm_wire_shape() { assert_eq!(json["lockfilePath"], "/proj/pnpm-lock.yaml"); } +/// `pnpm:lockfile-verification` `cached` carries the discriminator, +/// the camelCase `verifiedAt` of the reused verdict, and the optional +/// camelCase `lockfilePath` — no `entries` or `elapsedMs`, because +/// the cache short-circuit happens before candidates are collected. +#[test] +fn lockfile_verification_cached_event_matches_pnpm_wire_shape() { + let event = LogEvent::LockfileVerification(LockfileVerificationLog { + level: LogLevel::Debug, + message: LockfileVerificationMessage::Cached { + verified_at: Some("2026-06-11T10:00:00.000Z".to_string()), + lockfile_path: Some("/proj/pnpm-lock.yaml".to_string()), + }, + }); + let envelope = Envelope { time: 1_700_000_000_000, hostname: "host", pid: 4242, event: &event }; + let json: Value = envelope + .pipe_ref(serde_json::to_string) + .expect("serialize envelope") + .pipe_as_ref(serde_json::from_str) + .expect("parse JSON"); + assert_eq!(json["name"], "pnpm:lockfile-verification"); + assert_eq!(json["status"], "cached"); + assert_eq!(json["verifiedAt"], "2026-06-11T10:00:00.000Z"); + assert_eq!(json["lockfilePath"], "/proj/pnpm-lock.yaml"); + assert!(json.get("entries").is_none(), "entries must be absent on cached"); + assert!(json.get("elapsedMs").is_none(), "elapsedMs must be absent on cached"); +} + +/// A cached record written before `verifiedAt` existed surfaces as +/// `None` and must be omitted from the wire rather than rendered as +/// `null` — pnpm's reporter falls back to a timeless message on +/// absence. +#[test] +fn lockfile_verification_cached_omits_absent_verified_at() { + let event = LogEvent::LockfileVerification(LockfileVerificationLog { + level: LogLevel::Debug, + message: LockfileVerificationMessage::Cached { verified_at: None, lockfile_path: None }, + }); + let envelope = Envelope { time: 1_700_000_000_000, hostname: "host", pid: 4242, event: &event }; + let json: Value = envelope + .pipe_ref(serde_json::to_string) + .expect("serialize envelope") + .pipe_as_ref(serde_json::from_str) + .expect("parse JSON"); + assert!( + json.get("verifiedAt").is_none(), + "verifiedAt must be omitted when absent, got {json:?}", + ); +} + /// `lockfilePath` is upstream-optional (undefined in test paths that /// skip the cache wiring). When `None`, the field must be omitted /// rather than rendered as `null` — pnpm's reporter dispatches on