From 8f2e058b27477fdf3c499002e9281cf9f6f3faba Mon Sep 17 00:00:00 2001 From: Tom Rochette Date: Sun, 28 Jun 2026 17:23:27 -0400 Subject: [PATCH] fix(sync): stop watchdog redundant resyncs on healthy event stream (#1829) The stale-event check excluded heartbeats from lastActiveEventAt, so a quiet-but-connected session (only receiving heartbeats) tripped the 20s stale timer and triggered a full resync every ~15s. This re-fetched listPendingQuestions, listPendingPermissions, session.get, and session.messages despite the event stream being healthy. Track all stream activity (including heartbeats) in a global lastStreamActivityAt ref. The stale check now only fires when no events at all arrive for 20s, meaning the stream is genuinely dead. Resyncs still fire correctly on genuine reconnects, transport switches, and status-poll escalation when a real discrepancy is detected. Fixes #1656 --- .../__tests__/session-status-snapshot.test.ts | 53 +++++++++++++++++++ packages/ui/src/sync/sync-context.tsx | 49 ++++++++++------- 2 files changed, 83 insertions(+), 19 deletions(-) diff --git a/packages/ui/src/sync/__tests__/session-status-snapshot.test.ts b/packages/ui/src/sync/__tests__/session-status-snapshot.test.ts index b6b02477..67d030c5 100644 --- a/packages/ui/src/sync/__tests__/session-status-snapshot.test.ts +++ b/packages/ui/src/sync/__tests__/session-status-snapshot.test.ts @@ -7,6 +7,7 @@ import type { DirectoryStore } from "../child-store" import { applySessionStatusSnapshot, needsSnapshotAfterStatusPoll, + shouldTriggerStaleResync, } from "../sync-context" type StatusSnapshot = Record @@ -115,3 +116,55 @@ describe("needsSnapshotAfterStatusPoll", () => { expect(needsSnapshotAfterStatusPoll(store.getState(), "ses_a", undefined)).toBe(false) }) }) + +describe("shouldTriggerStaleResync", () => { + const STALE_MS = 20_000 + const COOLDOWN_MS = 15_000 + + test("does NOT trigger when heartbeats are recent (quiet-but-connected session)", () => { + // 5s ago a heartbeat arrived — stream is alive even though no meaningful + // events came through. This is the core fix for issue #1656. + const now = 100_000 + const lastStreamActivityAt = now - 5_000 + expect(shouldTriggerStaleResync(lastStreamActivityAt, 0, now, STALE_MS, COOLDOWN_MS)).toBe(false) + }) + + test("does NOT trigger when a non-heartbeat event is recent", () => { + const now = 100_000 + const lastStreamActivityAt = now - 3_000 + expect(shouldTriggerStaleResync(lastStreamActivityAt, 0, now, STALE_MS, COOLDOWN_MS)).toBe(false) + }) + + test("triggers when no events at all (including heartbeats) for the stale threshold", () => { + const now = 100_000 + const lastStreamActivityAt = now - STALE_MS - 1 + expect(shouldTriggerStaleResync(lastStreamActivityAt, 0, now, STALE_MS, COOLDOWN_MS)).toBe(true) + }) + + test("does NOT trigger when within the resync cooldown even if stream is stale", () => { + const now = 100_000 + const lastStreamActivityAt = now - STALE_MS - 1 + const lastFullResyncAt = now - 5_000 // only 5s ago, cooldown is 15s + expect(shouldTriggerStaleResync(lastStreamActivityAt, lastFullResyncAt, now, STALE_MS, COOLDOWN_MS)).toBe(false) + }) + + test("triggers when stream is stale AND cooldown has elapsed", () => { + const now = 100_000 + const lastStreamActivityAt = now - STALE_MS - 1 + const lastFullResyncAt = now - COOLDOWN_MS - 1 + expect(shouldTriggerStaleResync(lastStreamActivityAt, lastFullResyncAt, now, STALE_MS, COOLDOWN_MS)).toBe(true) + }) + + test("does NOT trigger when no events have been received yet (lastStreamActivityAt is 0)", () => { + // Prevents firing before the first heartbeat arrives + expect(shouldTriggerStaleResync(0, 0, 100_000, STALE_MS, COOLDOWN_MS)).toBe(false) + }) + + test("uses default thresholds when omitted", () => { + const now = 100_000 + // 25s since last activity (> 20s default), 20s since last resync (> 15s default) + expect(shouldTriggerStaleResync(now - 25_000, now - 20_000, now)).toBe(true) + // 10s since last activity (< 20s default) + expect(shouldTriggerStaleResync(now - 10_000, 0, now)).toBe(false) + }) +}) diff --git a/packages/ui/src/sync/sync-context.tsx b/packages/ui/src/sync/sync-context.tsx index 8c27fbaa..9387eaf7 100644 --- a/packages/ui/src/sync/sync-context.tsx +++ b/packages/ui/src/sync/sync-context.tsx @@ -418,11 +418,6 @@ function toSessionStatus(status: Awaited messageSessionById: Map @@ -1575,7 +1591,7 @@ export function SyncProvider(props: { const routingIndexRef = useRef(null) if (!routingIndexRef.current) routingIndexRef.current = createEventRoutingIndex() const routingIndex = routingIndexRef.current - const lastActiveEventAtByDirectoryRef = useRef(new Map()) + const lastStreamActivityAtRef = useRef(0) const lastStatusPollAtByDirectoryRef = useRef(new Map()) const lastFullResyncAtByDirectoryRef = useRef(new Map()) const lastChildDiscoveryAtByDirectoryRef = useRef(new Map()) @@ -1759,9 +1775,13 @@ export function SyncProvider(props: { return resolveDirectoryFromRoutingIndex(routingIndex, directory, payload, childStores) }, onEvent: (directory, payload) => { - if (!isStreamHeartbeatEvent(payload)) { - lastActiveEventAtByDirectoryRef.current.set(directory, Date.now()) - } + // Track ALL stream activity (including heartbeats) as proof of + // connection health. The watchdog stale check uses this to distinguish + // a genuinely dead stream (no heartbeats for 20s) from a quiet-but- + // connected session that is only receiving heartbeats. Excluding + // heartbeats here caused issue #1656: the stale timer fired for any + // quiet session, triggering redundant full resyncs every ~15s. + lastStreamActivityAtRef.current = Date.now() dispatchVSCodeRuntimeNotificationEvent(directory, payload) if (payload.type === "installation.update-available") { const version = typeof (payload.properties as { version?: unknown })?.version === "string" @@ -1901,28 +1921,19 @@ export function SyncProvider(props: { const state = store.getState() const candidateSessionIds = getActiveSessionCandidateIds(directory, state) if (candidateSessionIds.length === 0) { - lastActiveEventAtByDirectoryRef.current.delete(directory) lastStatusPollAtByDirectoryRef.current.delete(directory) lastFullResyncAtByDirectoryRef.current.delete(directory) continue } - if (!lastActiveEventAtByDirectoryRef.current.has(directory)) { - lastActiveEventAtByDirectoryRef.current.set(directory, now) - } - const lastStatusPollAt = lastStatusPollAtByDirectoryRef.current.get(directory) ?? 0 if (now - lastStatusPollAt >= ACTIVE_SESSION_STATUS_POLL_INTERVAL_MS) { lastStatusPollAtByDirectoryRef.current.set(directory, now) void pollDirectoryStatuses(directory, store, candidateSessionIds).catch(() => undefined) } - const lastActiveEventAt = lastActiveEventAtByDirectoryRef.current.get(directory) ?? now const lastFullResyncAt = lastFullResyncAtByDirectoryRef.current.get(directory) ?? 0 - if ( - now - lastActiveEventAt >= ACTIVE_SESSION_STALE_EVENT_MS - && now - lastFullResyncAt >= ACTIVE_SESSION_FULL_RESYNC_COOLDOWN_MS - ) { + if (shouldTriggerStaleResync(lastStreamActivityAtRef.current, lastFullResyncAt, now)) { pipelineReconnectRef.current?.("active_stream_stale") triggerDirectoryResync(directory) }