From 087d9b7b903fcfd8415147986ec0a3c4d4ba5217 Mon Sep 17 00:00:00 2001 From: Max Lampert Date: Mon, 24 Aug 2026 22:25:28 -0700 Subject: [PATCH] fix(desktop): drop live traces on any exit from the channel surface Blind-review round 7 (Opus medium) findings: - P2: a trace begun while the channel route was still resolving never mounted ChannelScreen, so no route-exit cleanup existed; leaving for Home and history-backing into the channel within 30s settled the stale trace with the time spent away. Any committed non-channel navigation and any history traversal now drop the active trace at the navigation layer (dropActiveChannelSwitchTrace), which covers traces no component ever owned. Same-channel navigations keep the live trace. - The delayed-chunk spec now asserts no CLEAN measure while the chunk is held (the tracer honestly emits a truncated one if its 5s deadline passes) and guards its own timing budget explicitly so a slow CI box fails with the real reason. - The rotation-degradation test blocks rotation with a non-empty directory instead of chmod, so it also holds when tests run as root (containers), and now runs on Windows too. Co-Authored-By: Claude Fable 5 Signed-off-by: Max Lampert --- desktop/src-tauri/src/commands/perf_log.rs | 24 ++--- .../commitGuardedNavigation.test.mjs | 98 ++++++++++++++++++- .../app/navigation/commitGuardedNavigation.ts | 31 ++++-- desktop/src/app/navigation/navigationGuard.ts | 7 ++ .../src/app/navigation/useAppNavigation.ts | 4 + desktop/src/shared/lib/channelSwitchPerf.ts | 12 +++ .../e2e/switch-settle-after-paint.spec.ts | 29 ++++-- 7 files changed, 172 insertions(+), 33 deletions(-) diff --git a/desktop/src-tauri/src/commands/perf_log.rs b/desktop/src-tauri/src/commands/perf_log.rs index a2c8ce21a8..4ffbf81ef2 100644 --- a/desktop/src-tauri/src/commands/perf_log.rs +++ b/desktop/src-tauri/src/commands/perf_log.rs @@ -326,10 +326,8 @@ mod tests { std::fs::remove_dir_all(&dir).ok(); } - #[cfg(unix)] #[test] fn a_failed_rotation_degrades_to_an_unrotated_append() { - use std::os::unix::fs::PermissionsExt; let dir = std::env::temp_dir().join(format!( "perf-log-degrade-{}-{:?}", std::process::id(), @@ -339,25 +337,21 @@ mod tests { let path = dir.join("switch-perf.jsonl"); let rotated = dir.join("switch-perf.jsonl.1"); std::fs::write(&path, "oversized-live\n").expect("seed live"); - std::fs::write(&rotated, "old-generation\n").expect("seed rotated"); + // A non-empty DIRECTORY at the rotated path defeats remove_file and + // rename on every platform — including for root, where permission + // tricks no-op (containers often run tests as uid 0). It stands in + // for a transient AV/EDR hold: the append must degrade to the + // unrotated file, not drop records until the lock clears. + std::fs::create_dir_all(rotated.join("hold")).expect("seed blocker"); - // A read-only directory makes remove/rename fail, like a transient - // AV/EDR hold would. The append must degrade to the unrotated file — - // dropping every record until an external lock clears would violate - // the sink's no-silent-loss contract. - std::fs::set_permissions(&dir, std::fs::Permissions::from_mode(0o555)).expect("lock dir"); - let result = append_line_rotating(&path, "must-survive", 8); - std::fs::set_permissions(&dir, std::fs::Permissions::from_mode(0o755)).expect("unlock dir"); - result.expect("append must survive a failed rotation"); + append_line_rotating(&path, "must-survive", 8) + .expect("append must survive a failed rotation"); assert_eq!( std::fs::read_to_string(&path).expect("read live"), "oversized-live\nmust-survive\n" ); - assert_eq!( - std::fs::read_to_string(&rotated).expect("read rotated"), - "old-generation\n" - ); + assert!(rotated.join("hold").exists(), "blocker untouched"); std::fs::remove_dir_all(&dir).ok(); } diff --git a/desktop/src/app/navigation/commitGuardedNavigation.test.mjs b/desktop/src/app/navigation/commitGuardedNavigation.test.mjs index 9ed897949d..0b836ec20b 100644 --- a/desktop/src/app/navigation/commitGuardedNavigation.test.mjs +++ b/desktop/src/app/navigation/commitGuardedNavigation.test.mjs @@ -2,15 +2,111 @@ import assert from "node:assert/strict"; import test from "node:test"; import { commitGuardedNavigation } from "./commitGuardedNavigation.ts"; -import { registerNavigationGuard } from "./navigationGuard.ts"; +import { registerNavigationGuard, traverseHistory } from "./navigationGuard.ts"; import { CHANNEL_SWITCH_MEASURE, + beginChannelSwitchTrace, resetChannelSwitchTrace, settleChannelSwitchTrace, } from "../../shared/lib/channelSwitchPerf.ts"; const route = (href) => ({ kind: "route", href }); +// Frame/document stubs so settle's rAF chain can be driven synchronously. +function withTraceHarness(run) { + const frames = []; + const originalWindow = globalThis.window; + const originalDocument = globalThis.document; + globalThis.window = { + requestAnimationFrame: (cb) => frames.push(cb) && frames.length, + cancelAnimationFrame: () => {}, + }; + globalThis.document = { + addEventListener: () => {}, + querySelector: () => null, + removeEventListener: () => {}, + visibilityState: "visible", + }; + performance.clearMeasures?.(CHANNEL_SWITCH_MEASURE); + const flush = () => { + for (let i = 0; i < 20 && frames.length > 0; i += 1) { + for (const cb of frames.splice(0, frames.length)) cb(); + } + }; + const measures = () => + performance + .getEntriesByName(CHANNEL_SWITCH_MEASURE) + .map((entry) => entry.detail?.channelId); + return (async () => { + try { + await run({ flush, measures }); + } finally { + resetChannelSwitchTrace(); + performance.clearMeasures?.(CHANNEL_SWITCH_MEASURE); + if (originalWindow === undefined) delete globalThis.window; + else globalThis.window = originalWindow; + if (originalDocument === undefined) delete globalThis.document; + else globalThis.document = originalDocument; + } + })(); +} + +test("a committed non-channel navigation drops the active trace", async () => { + await withTraceHarness(async ({ flush, measures }) => { + // A trace can be live with no channel screen mounted at all (the route + // still resolving), so no route-exit cleanup exists to abandon it — the + // navigation layer must drop it, or a history-back re-entry within the + // 30s timeout would settle it with the time spent away. + beginChannelSwitchTrace("bbbb"); + const committed = await commitGuardedNavigation({ + currentHref: "/channels/bbbb", + nextHref: "/", + guardedTarget: route("/"), + leavesChannelSurface: true, + navigate: async () => {}, + }); + assert.equal(committed, true); + settleChannelSwitchTrace("bbbb"); + flush(); + assert.deepEqual(measures(), []); + }); +}); + +test("a same-channel navigation never drops the channel's live trace", async () => { + await withTraceHarness(async ({ flush, measures }) => { + beginChannelSwitchTrace("bbbb"); + // Jump-to-message within the active channel: untraced, but must not + // kill the in-flight trace either. + await commitGuardedNavigation({ + currentHref: "/channels/bbbb", + nextHref: "/channels/bbbb?messageId=m1", + guardedTarget: route("/channels/bbbb?messageId=m1"), + leavesChannelSurface: false, + navigate: async () => {}, + }); + settleChannelSwitchTrace("bbbb"); + flush(); + assert.deepEqual(measures(), ["bbbb"]); + }); +}); + +test("history traversal drops the active trace", async () => { + await withTraceHarness(async ({ flush, measures }) => { + beginChannelSwitchTrace("bbbb"); + const calls = []; + // History navigation is deliberately untraced and its destination is + // unknowable here — a live trace must not survive into it. + traverseHistory( + { back: () => calls.push("back"), forward: () => {} }, + "back", + ); + assert.deepEqual(calls, ["back"]); + settleChannelSwitchTrace("bbbb"); + flush(); + assert.deepEqual(measures(), []); + }); +}); + test("a refused navigation opens no trace; a later history settle records nothing", async () => { // Frame-queue stub so the settle's rAF chain can be drained synchronously. const frames = []; diff --git a/desktop/src/app/navigation/commitGuardedNavigation.ts b/desktop/src/app/navigation/commitGuardedNavigation.ts index 9b9f69d6a2..449442f5c9 100644 --- a/desktop/src/app/navigation/commitGuardedNavigation.ts +++ b/desktop/src/app/navigation/commitGuardedNavigation.ts @@ -2,19 +2,24 @@ import { allowNavigation, type GuardedNavigation, } from "@/app/navigation/navigationGuard"; -import { beginChannelSwitchTrace } from "@/shared/lib/channelSwitchPerf"; +import { + beginChannelSwitchTrace, + dropActiveChannelSwitchTrace, +} from "@/shared/lib/channelSwitchPerf"; /** * commitGuardedNavigation runs the shared commit flow for app navigations: - * skip same-destination no-ops (unless forced or carrying a router-state - * update), consult the navigation guard, then navigate. A same-href - * navigation that writes state — e.g. setting or clearing the search - * highlight — must still commit, or the state never lands. When - * `traceChannelId` is set, the channel-switch - * trace opens only after the guard accepts — a refused click must not leave - * an orphan trace that a later history navigation (deliberately untraced) - * would settle with the refused click's inflated wall time. Returns whether - * the navigation was performed. `deps` exists for unit tests. + * skip same-destination no-ops, consult the navigation guard, then navigate. + * `force` and `hasStateUpdate` both defeat the no-op skip — a same-href + * navigation that writes router state (setting or clearing the search + * highlight) must commit, or the state never lands. When `traceChannelId` is + * set, the channel-switch trace opens only after the guard accepts — a + * refused click must not leave an orphan trace that a later history + * navigation (deliberately untraced) would settle with the refused click's + * inflated wall time. When `leavesChannelSurface` is set, any active trace is + * dropped instead: the trace may be live with no channel screen mounted + * (route still resolving), so this is the only reliable exit hook. Returns + * whether the navigation was performed. `deps` exists for unit tests. */ export async function commitGuardedNavigation( input: { @@ -23,16 +28,19 @@ export async function commitGuardedNavigation( force?: boolean; guardedTarget: GuardedNavigation; hasStateUpdate?: boolean; + leavesChannelSurface?: boolean; traceChannelId?: string; navigate: () => Promise; }, deps: { allow?: typeof allowNavigation; beginTrace?: typeof beginChannelSwitchTrace; + dropActiveTrace?: typeof dropActiveChannelSwitchTrace; } = {}, ): Promise { const allow = deps.allow ?? allowNavigation; const beginTrace = deps.beginTrace ?? beginChannelSwitchTrace; + const dropActiveTrace = deps.dropActiveTrace ?? dropActiveChannelSwitchTrace; if ( input.currentHref === input.nextHref && !input.force && @@ -43,6 +51,9 @@ export async function commitGuardedNavigation( if (!allow(input.guardedTarget)) { return false; } + if (input.leavesChannelSurface) { + dropActiveTrace(); + } if (input.traceChannelId !== undefined) { beginTrace(input.traceChannelId); } diff --git a/desktop/src/app/navigation/navigationGuard.ts b/desktop/src/app/navigation/navigationGuard.ts index 5ff853720b..8fc78f869d 100644 --- a/desktop/src/app/navigation/navigationGuard.ts +++ b/desktop/src/app/navigation/navigationGuard.ts @@ -1,3 +1,5 @@ +import { dropActiveChannelSwitchTrace } from "@/shared/lib/channelSwitchPerf"; + export type GuardedNavigation = | { kind: "history"; @@ -40,6 +42,11 @@ export function traverseHistory( return false; } + // History navigation is deliberately untraced and its destination is + // unknowable here: a live switch trace must not survive into it, or an + // untraced re-entry into the traced channel would settle it with the time + // spent away. + dropActiveChannelSwitchTrace(); history[direction](); return true; } diff --git a/desktop/src/app/navigation/useAppNavigation.ts b/desktop/src/app/navigation/useAppNavigation.ts index 913f51a2de..03b9b1aaf3 100644 --- a/desktop/src/app/navigation/useAppNavigation.ts +++ b/desktop/src/app/navigation/useAppNavigation.ts @@ -52,6 +52,10 @@ export function useAppNavigation() { href: nextLocation.href, }, hasStateUpdate: next.state !== undefined, + // Leaving the channel surface must drop any active switch trace — + // including one whose channel screen never mounted (route still + // resolving), which no component cleanup can cover. + leavesChannelSurface: !next.to.startsWith("/channels/"), navigate: () => navigate({ ...next, diff --git a/desktop/src/shared/lib/channelSwitchPerf.ts b/desktop/src/shared/lib/channelSwitchPerf.ts index a5fa935a90..78f9a52a78 100644 --- a/desktop/src/shared/lib/channelSwitchPerf.ts +++ b/desktop/src/shared/lib/channelSwitchPerf.ts @@ -161,6 +161,18 @@ export function abandonChannelSwitchTrace(channelId: string): void { } } +/** + * dropActiveChannelSwitchTrace abandons whatever trace is active, regardless + * of channel. Called when navigation leaves the channel surface (any + * committed non-channel destination, any history traversal): a trace can be + * live with no channel screen mounted at all — the route still resolving — + * so no route-exit cleanup exists to abandon it, and a later untraced + * re-entry within the timeout would settle it with the time spent away. + */ +export function dropActiveChannelSwitchTrace(): void { + activeTrace = null; +} + // Route-exit abandons currently deferred; see scheduleRouteExitAbandon. const pendingRouteExitAbandons = new Set(); diff --git a/desktop/tests/e2e/switch-settle-after-paint.spec.ts b/desktop/tests/e2e/switch-settle-after-paint.spec.ts index a74826dfc9..192c171e16 100644 --- a/desktop/tests/e2e/switch-settle-after-paint.spec.ts +++ b/desktop/tests/e2e/switch-settle-after-paint.spec.ts @@ -88,15 +88,30 @@ test("settle waits for a delayed lazy channel-pane chunk", async ({ page }) => { .toBe(true); // Give the tracer ample frames to (incorrectly) settle behind the held - // chunk. This wait must stay well under the tracer's 5s settle deadline. + // chunk. The tracer's 5s render-wait deadline runs from settle entry + // (query readiness — immediate in mock mode), after which it honestly + // emits a TRUNCATED measure even while suspended; the contract under test + // is that no CLEAN measure appears. Guard the timing assumption + // explicitly so a slow CI box fails with the real reason. await page.waitForTimeout(1_500); - const early = await page.evaluate( - (name) => performance.getEntriesByName(name).length, - SWITCH_MEASURE, - ); + const early = await page.evaluate((name) => { + const start = performance.getEntriesByName("buzz:channel-switch:start")[0]; + return { + cleanMeasures: performance + .getEntriesByName(name) + .filter( + (entry) => !(entry as PerformanceMeasure).detail?.settleWaitTruncated, + ).length, + elapsedSinceClick: start ? performance.now() - start.startTime : null, + }; + }, SWITCH_MEASURE); expect( - early, - "no settle may be recorded while the pane chunk is suspended", + early.elapsedSinceClick, + "harness overhead consumed the tracer's settle deadline — timing, not a tracer bug", + ).toBeLessThan(4_500); + expect( + early.cleanMeasures, + "no clean settle may be recorded while the pane chunk is suspended", ).toBe(0); releaseChunk();