From ff5be7f7b68dd09167355ddf723ec85a62151bf2 Mon Sep 17 00:00:00 2001 From: OrcaWin Date: Sun, 11 Oct 2026 03:55:21 -0700 Subject: [PATCH] fix(runtime): reuse cached worktree rows when the admin probe cannot answer (#27445) * fix(runtime): reuse cached worktree rows when the admin probe cannot answer * test(runtime): wait for the fingerprint probe to settle instead of a fixed delay --------- Co-authored-by: m4air --- ...orca-runtime-refresh-repo-worktree-scan.ts | 78 ++++++++++++++++--- .../worktree-scan-cache-ttl.spec.ts | 13 +++- ...rktree-scan-admin-fingerprint-gate.test.ts | 51 +++++++++--- 3 files changed, 119 insertions(+), 23 deletions(-) diff --git a/src/main/runtime/orca-runtime-refresh-repo-worktree-scan.ts b/src/main/runtime/orca-runtime-refresh-repo-worktree-scan.ts index b4853ba70f1..afe0c752a10 100644 --- a/src/main/runtime/orca-runtime-refresh-repo-worktree-scan.ts +++ b/src/main/runtime/orca-runtime-refresh-repo-worktree-scan.ts @@ -20,6 +20,25 @@ import { listStoredWorktreeRowsForRepo } from './repo-worktree-row-resolution' import type { ResolvedWorktree } from './runtime-worktree-path-identity' import { getRepoExecutionHostId, getRepoSshConnectionId } from '../../shared/execution-host' +const lastFingerprintUnknownWarnAt = new Map() + +// Why once per reconcile window: a wedged mount answers "unknown" on every poll. +function warnFingerprintUnknownOnce(repoId: string, reason: string): void { + const now = Date.now() + const last = lastFingerprintUnknownWarnAt.get(repoId) + if (last !== undefined && now - last < WORKTREE_SCAN_ADMIN_RECONCILE_INTERVAL_MS) { + return + } + lastFingerprintUnknownWarnAt.set(repoId, now) + console.warn( + '[worktree-scan] admin fingerprint unknown; reusing cached rows until the reconcile ceiling', + { + repoId, + reason + } + ) +} + export class OrcaRuntimeWithRefreshRepoWorktreeScan extends OrcaRuntimeWithListKnownResolvedWorktreesForExplicitTarget { /** * Refresh one repo's worktree rows, skipping the `git worktree list` subprocess when a cheap @@ -48,28 +67,61 @@ export class OrcaRuntimeWithRefreshRepoWorktreeScan extends OrcaRuntimeWithListK scannedAt - cached.scannedAt < WORKTREE_SCAN_ADMIN_RECONCILE_INTERVAL_MS ? cached : null - if (probe && reusable) { + // Why reuse on "cannot tell": a probe that is still pending or timed out says nothing about + // the repo, and turning that into a full scan is the feedback loop of #19312 (slow mount → + // timeouts → scans → more load). The original `scannedAt` is kept, so the reconcile ceiling + // still forces a real scan on schedule. + const reuseCached = (): RuntimeWorktreeScanRefresh | null => + reusable + ? { + result: reusable.result, + adminFingerprint: reusable.adminFingerprint, + adminFingerprintProbe: null, + scannedAt: reusable.scannedAt + } + : null + if (probe === 'in-flight') { + const reused = reuseCached() + if (reused) { + warnFingerprintUnknownOnce(repo.id, 'previous probe still pending') + return reused + } + } else if (probe && reusable) { // Why await only here: this is the one branch whose decision needs the probe. A scan-bound // caller must never wait on it, or every cold read pays filesystem latency it cannot use. const probed = await withTimeoutResult(probe, WORKTREE_SCAN_ADMIN_FINGERPRINT_TIMEOUT_MS) if (!probed.ok) { - // Why log: expiry and "fingerprint unavailable" both surface as `null`, so a wedged mount is - // otherwise indistinguishable from a repo that simply cannot be fingerprinted. - console.warn('[worktree-scan] admin fingerprint probe expired; running a full scan', { - repoId: repo.id, - timeoutMs: WORKTREE_SCAN_ADMIN_FINGERPRINT_TIMEOUT_MS - }) + warnFingerprintUnknownOnce(repo.id, 'probe expired') + return ( + reuseCached() ?? + (await this.scanRepoWorktreesForRefresh(repo, projectRuntime, null, scannedAt)) + ) } - const current = probed.ok ? probed.value : null - if (current !== null && current === reusable.adminFingerprint) { + // A known fingerprint that matches proves nothing changed; null means the repo cannot be + // fingerprinted, which (like a mismatch) needs a real scan. + if (probed.value !== null && probed.value === reusable.adminFingerprint) { return { result: reusable.result, - adminFingerprint: current, + adminFingerprint: probed.value, adminFingerprintProbe: null, scannedAt: reusable.scannedAt } } } + return await this.scanRepoWorktreesForRefresh( + repo, + projectRuntime, + probe === 'in-flight' ? null : probe, + scannedAt + ) + } + + private async scanRepoWorktreesForRefresh( + repo: Repo, + projectRuntime: ProjectExecutionRuntimeResolution | undefined, + probe: Promise | null, + scannedAt: number + ): Promise { const result = dropRepeatedWorktreeRows( await this.listRepoWorktreesForResolutionUncached(repo, projectRuntime) ) @@ -81,9 +133,11 @@ export class OrcaRuntimeWithRefreshRepoWorktreeScan extends OrcaRuntimeWithListK * Why the gate: `withTimeout` abandons a probe without cancelling it, and readdir/stat take no * AbortSignal — on a wedged mount a fresh probe per refresh would pin every libuv fs thread. */ - protected startRepoWorktreeAdminFingerprintProbe(repo: Repo): Promise | null { + protected startRepoWorktreeAdminFingerprintProbe( + repo: Repo + ): Promise | 'in-flight' { if (this.worktreeAdminFingerprintProbes.has(repo.id)) { - return null + return 'in-flight' } this.worktreeAdminFingerprintProbes.add(repo.id) return readRepoWorktreeAdminFingerprint(repo.path) diff --git a/src/main/runtime/orca-runtime-tests/worktree-scan-cache-ttl.spec.ts b/src/main/runtime/orca-runtime-tests/worktree-scan-cache-ttl.spec.ts index f8ec37f7c2c..fd614e0eeb0 100644 --- a/src/main/runtime/orca-runtime-tests/worktree-scan-cache-ttl.spec.ts +++ b/src/main/runtime/orca-runtime-tests/worktree-scan-cache-ttl.spec.ts @@ -46,7 +46,15 @@ describe('resolveWorktreeScanCacheTtlMs', () => { it('keeps a scratch repo scan cached past the base TTL while normal repos rescan', async () => { // Why: the whole fix lives in the cache-stamp call site; pin the wiring so // a revert to the flat TTL fails CI, not just the pure-function tests. - vi.useFakeTimers() + // Why only Date: each refresh starts a real admin-fingerprint read, which must settle on the + // real event loop; a probe still pending at the next refresh reuses the cache by design. + vi.useFakeTimers({ toFake: ['Date'] }) + let runtimeProbes: { size: number } = { size: 0 } + const settleFingerprintProbes = async (): Promise => { + for (let attempt = 0; attempt < 400 && runtimeProbes.size > 0; attempt += 1) { + await new Promise((resolve) => setTimeout(resolve, 5)) + } + } // Why: the shared listWorktrees stub keeps call history across this file's // tests; absolute counts need a clean baseline. vi.mocked(listWorktrees).mockClear() @@ -66,10 +74,13 @@ describe('resolveWorktreeScanCacheTtlMs', () => { ] } as never) const internals = runtime as unknown as { listResolvedWorktrees: () => Promise } + // Why bracket access: the probe set is protected runtime state this test only reads. + runtimeProbes = runtime['worktreeAdminFingerprintProbes'] const scanCallsFor = (path: string): number => vi.mocked(listWorktrees).mock.calls.filter((call) => call[0] === path).length await internals.listResolvedWorktrees() + await settleFingerprintProbes() expect(scanCallsFor('/tmp/repo')).toBe(1) expect(scanCallsFor(scratchPath)).toBe(1) diff --git a/src/main/runtime/worktree-scan-admin-fingerprint-gate.test.ts b/src/main/runtime/worktree-scan-admin-fingerprint-gate.test.ts index 7dfe0144406..05412275168 100644 --- a/src/main/runtime/worktree-scan-admin-fingerprint-gate.test.ts +++ b/src/main/runtime/worktree-scan-admin-fingerprint-gate.test.ts @@ -403,8 +403,9 @@ describe('worktree scan admin-fingerprint gate', () => { const secondSettled = trackSettled(second) await drainMicrotasks() expect(secondSettled()).toBe(true) - await second - expect(scanCount()).toBe(2) + // #19312: a pending probe says nothing, so it reuses the scanned rows instead of rescanning. + expect(heads(await second)).toEqual(['abc', 'def']) + expect(scanCount()).toBe(1) vi.advanceTimersByTime(SCAN_TTL_MS + 1_000) const third = list() @@ -412,7 +413,7 @@ describe('worktree scan admin-fingerprint gate', () => { await drainMicrotasks() expect(thirdSettled()).toBe(true) await third - expect(scanCount()).toBe(3) + expect(scanCount()).toBe(1) } finally { vi.useRealTimers() } @@ -427,6 +428,7 @@ describe('worktree scan admin-fingerprint gate', () => { await list() expect(readRepoWorktreeAdminFingerprintMock).toHaveBeenCalledTimes(1) + const startedAt = Date.now() for (let refresh = 0; refresh < 20; refresh += 1) { vi.advanceTimersByTime(SCAN_TTL_MS + 1_000) await list() @@ -434,7 +436,12 @@ describe('worktree scan admin-fingerprint gate', () => { // Each abandoned probe pins an fs work item on the 4-slot libuv pool forever. expect(readRepoWorktreeAdminFingerprintMock).toHaveBeenCalledTimes(1) - expect(scanCount()).toBe(21) + // Only the reconcile ceiling rescans while the probe stays pending, never every refresh. + const elapsed = Date.now() - startedAt + expect(scanCount()).toBeGreaterThan(1) + expect(scanCount()).toBeLessThanOrEqual( + 1 + Math.ceil(elapsed / WORKTREE_SCAN_ADMIN_RECONCILE_INTERVAL_MS) + ) } finally { vi.useRealTimers() } @@ -449,24 +456,24 @@ describe('worktree scan admin-fingerprint gate', () => { await list() vi.advanceTimersByTime(SCAN_TTL_MS + 1_000) await list() - expect(scanCount()).toBe(2) + expect(scanCount()).toBe(1) // The mount unwedges; its stale answer must not gate anything, but the repo must probe again. releaseStalledProbe('fp-stale') await drainMicrotasks() vi.advanceTimersByTime(SCAN_TTL_MS + 1_000) await list() - expect(scanCount()).toBe(3) + expect(scanCount()).toBe(2) vi.advanceTimersByTime(SCAN_TTL_MS + 1_000) await list() - expect(scanCount()).toBe(3) + expect(scanCount()).toBe(2) } finally { vi.useRealTimers() } }) - it('scans when the awaited probe outlives its deadline', async () => { + it('reuses the scanned rows when the awaited probe outlives its deadline', async () => { vi.useFakeTimers() try { const { list } = makeRuntime() @@ -485,8 +492,32 @@ describe('worktree scan admin-fingerprint gate', () => { await vi.advanceTimersByTimeAsync(WORKTREE_SCAN_ADMIN_FINGERPRINT_TIMEOUT_MS) await drainMicrotasks() + // #19312: a timeout is "unknown", never a mismatch, so it must not start a full scan. + expect(scanCount()).toBe(1) + expect(heads(await second)).toEqual(['abc', 'def']) + } finally { + vi.useRealTimers() + } + }) + + it('still reconciles on schedule while every probe times out', async () => { + vi.useFakeTimers() + try { + readRepoWorktreeAdminFingerprintMock.mockImplementation(() => new Promise(() => {})) + const { list } = makeRuntime() + const scannedAt = Date.now() + await list() + expect(scanCount()).toBe(1) + + while (Date.now() - scannedAt < WORKTREE_SCAN_ADMIN_RECONCILE_INTERVAL_MS - SCAN_TTL_MS) { + vi.advanceTimersByTime(SCAN_TTL_MS + 1_000) + await list() + } + expect(scanCount()).toBe(1) + + vi.advanceTimersByTime(2 * SCAN_TTL_MS) + await list() expect(scanCount()).toBe(2) - await second } finally { vi.useRealTimers() } @@ -537,7 +568,7 @@ describe('worktree scan admin-fingerprint gate', () => { await vi.advanceTimersByTimeAsync(WORKTREE_SCAN_ADMIN_FINGERPRINT_TIMEOUT_MS) await drainMicrotasks() expect(secondSettled()).toBe(true) - expect(scanCount()).toBe(2) + expect(scanCount()).toBe(1) expect(heads(await second)).toEqual(['abc', 'def']) } finally { vi.useRealTimers()