mirror of
https://github.com/pnpm/pnpm.git
synced 2026-06-29 18:35:18 -04:00
feat(deps-installer): announce reused lockfile-verification verdicts (#12326)
When the lockfile-verification gate short-circuits on a cached verdict, it used to stay completely silent, which made it look like the supply-chain policy gate never ran (pnpm/pnpm#12324). Emit a new `cached` status on the pnpm:lockfile-verification channel carrying the reused record's verifiedAt timestamp, and render it in the default reporter as "Lockfile passes supply-chain policies (verified 2h ago)" (falling back to "previously verified" for records that predate the timestamp). The event fires only when policy verifiers are active, so the shape-only check every install performs stays quiet. Ported to pacquet in the same change: a `Cached` variant on the reporter's LockfileVerificationMessage with the matching camelCase wire shape, emitted from the same cache-hit point in verify_lockfile_resolutions.
This commit is contained in:
8
.changeset/lockfile-verification-cached-message.md
Normal file
8
.changeset/lockfile-verification-cached-message.md
Normal file
@@ -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).
|
||||
@@ -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 <path>` 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
|
||||
|
||||
@@ -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'] },
|
||||
|
||||
@@ -6,7 +6,7 @@ import {
|
||||
export const lockfileVerificationLogger = logger<LockfileVerificationMessage>('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' }
|
||||
|
||||
@@ -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.
|
||||
|
||||
@@ -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 {
|
||||
|
||||
@@ -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 {
|
||||
|
||||
@@ -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<String>,
|
||||
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) },
|
||||
}
|
||||
}
|
||||
|
||||
@@ -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<Reporter: self::Reporter>(
|
||||
lockfile: &Lockfile,
|
||||
verifiers: &[Arc<dyn ResolutionVerifier>],
|
||||
@@ -109,6 +111,8 @@ pub async fn verify_lockfile_resolutions<Reporter: self::Reporter>(
|
||||
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<Reporter: self::Reporter>(
|
||||
&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::<Reporter>(
|
||||
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<Reporter: self::Reporter>(
|
||||
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
|
||||
|
||||
@@ -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<Vec<LogEvent>> = 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<dyn ResolutionVerifier>;
|
||||
let opts = VerifyLockfileResolutionsOptions {
|
||||
lockfile_path: Some(&lockfile_path),
|
||||
cache_dir: Some(&cache_dir),
|
||||
..Default::default()
|
||||
};
|
||||
|
||||
verify_lockfile_resolutions::<SilentReporter>(
|
||||
&lockfile,
|
||||
std::slice::from_ref(&verifier),
|
||||
&opts,
|
||||
)
|
||||
.await
|
||||
.expect("first run");
|
||||
verify_lockfile_resolutions::<RecordingReporter>(
|
||||
&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<Vec<LogEvent>> = 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<dyn ResolutionVerifier>;
|
||||
let opts = VerifyLockfileResolutionsOptions {
|
||||
lockfile_path: Some(&lockfile_path),
|
||||
cache_dir: Some(&cache_dir),
|
||||
..Default::default()
|
||||
};
|
||||
|
||||
verify_lockfile_resolutions::<SilentReporter>(
|
||||
&lockfile,
|
||||
std::slice::from_ref(&verifier),
|
||||
&opts,
|
||||
)
|
||||
.await
|
||||
.expect("first run");
|
||||
verify_lockfile_resolutions::<RecordingReporter>(&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]
|
||||
|
||||
@@ -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);
|
||||
|
||||
@@ -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<String>,
|
||||
},
|
||||
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<String>,
|
||||
#[serde(rename = "lockfilePath", skip_serializing_if = "Option::is_none")]
|
||||
lockfile_path: Option<String>,
|
||||
},
|
||||
}
|
||||
|
||||
/// Generic-channel (`name: "pnpm"`) payload, used for `logger.info`-style
|
||||
|
||||
@@ -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
|
||||
|
||||
Reference in New Issue
Block a user