From 8a8e01cfb0421199d3293d8606b71e8e066c0d06 Mon Sep 17 00:00:00 2001 From: Max Lampert Date: Wed, 26 Aug 2026 20:31:48 -0700 Subject: [PATCH] refactor(desktop): drop the switch tracer, keep the perf harness MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The instrument was over half this PR and the source of nearly every review finding, and the benchmark that actually validates the perf work does not depend on it: member-heavy-switch.perf.ts times click -> ready itself with performance.now() and DOM readiness, and never reads a tracer export. Its remaining value was a dev console line, against a failure mode of reporting a number that never happened — which is worse than reporting nothing, because it sends someone chasing a regression that does not exist. The live baselines it produced are already recorded in the PR description and stand on their own; they justified the fixes, and the fixes are the deliverable. Removed: channelSwitchPerf.ts and its tests, useChannelSwitchTraceMarks, switch-settle-after-paint.spec.ts, the fetch attribution in the window queryFn, the trace hooks in commitGuardedNavigation/useAppNavigation, and the community-init reset. Kept, because the perf fixes build on them: - member-heavy-switch.perf.ts plus the inflateChannelMembers bridge knob — the high-membership benchmark - useChannelTimelineLoading — the per-channel loading latch - commitGuardedNavigation — the shared guard/no-op commit flow - the Projects hydration marker the harness gates readiness on - routing Pulse note actions through goChannel, so that DM entry goes through the same navigation guard as every other one Signed-off-by: Max Lampert --- desktop/playwright.config.ts | 1 - .../commitGuardedNavigation.test.mjs | 177 +-------- .../app/navigation/commitGuardedNavigation.ts | 26 +- desktop/src/app/navigation/navigationGuard.ts | 7 - .../src/app/navigation/useAppNavigation.ts | 20 +- .../useChannelSwitchTraceMarks.test.mjs | 116 ------ .../channels/useChannelSwitchTraceMarks.ts | 43 --- .../channels/useChannelTimelineLoading.ts | 12 +- .../features/communities/useCommunityInit.ts | 5 - desktop/src/features/messages/hooks.ts | 52 +-- .../lib/projectChannelWindow.test.mjs | 91 +---- .../src/shared/lib/channelSwitchPerf.test.mjs | 324 ----------------- desktop/src/shared/lib/channelSwitchPerf.ts | 338 ------------------ .../e2e/switch-settle-after-paint.spec.ts | 148 -------- 14 files changed, 12 insertions(+), 1348 deletions(-) delete mode 100644 desktop/src/features/channels/useChannelSwitchTraceMarks.test.mjs delete mode 100644 desktop/src/features/channels/useChannelSwitchTraceMarks.ts delete mode 100644 desktop/src/shared/lib/channelSwitchPerf.test.mjs delete mode 100644 desktop/src/shared/lib/channelSwitchPerf.ts delete mode 100644 desktop/tests/e2e/switch-settle-after-paint.spec.ts diff --git a/desktop/playwright.config.ts b/desktop/playwright.config.ts index 9e1a75929d..be15c75587 100644 --- a/desktop/playwright.config.ts +++ b/desktop/playwright.config.ts @@ -109,7 +109,6 @@ export default defineConfig({ "**/overscroll-boundary.spec.ts", "**/terminal-wheel.spec.ts", "**/cold-switch-longtask.perf.ts", - "**/switch-settle-after-paint.spec.ts", "**/timeline-no-shift.spec.ts", "**/human-edit-agent-content.spec.ts", "**/empty-edit-delete.spec.ts", diff --git a/desktop/src/app/navigation/commitGuardedNavigation.test.mjs b/desktop/src/app/navigation/commitGuardedNavigation.test.mjs index 0b836ec20b..9f271383d9 100644 --- a/desktop/src/app/navigation/commitGuardedNavigation.test.mjs +++ b/desktop/src/app/navigation/commitGuardedNavigation.test.mjs @@ -2,167 +2,10 @@ import assert from "node:assert/strict"; import test from "node:test"; import { commitGuardedNavigation } from "./commitGuardedNavigation.ts"; -import { registerNavigationGuard, traverseHistory } from "./navigationGuard.ts"; -import { - CHANNEL_SWITCH_MEASURE, - beginChannelSwitchTrace, - resetChannelSwitchTrace, - settleChannelSwitchTrace, -} from "../../shared/lib/channelSwitchPerf.ts"; +import { registerNavigationGuard } from "./navigationGuard.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 = []; - 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 unregister = registerNavigationGuard(() => false); - try { - let navigated = false; - const committed = await commitGuardedNavigation({ - currentHref: "/channels/aaaa", - nextHref: "/channels/bbbb", - guardedTarget: route("/channels/bbbb"), - traceChannelId: "bbbb", - navigate: async () => { - navigated = true; - }, - }); - assert.equal(committed, false); - assert.equal(navigated, false); - - // Browser Back into the refused channel (history navigation is - // deliberately untraced): its mount settles, and must find NO orphan - // trace from the refused click — otherwise the measure would span the - // refusal and everything the user did in between. - settleChannelSwitchTrace("bbbb"); - for (let i = 0; i < 20 && frames.length > 0; i += 1) { - for (const cb of frames.splice(0, frames.length)) cb(); - } - assert.deepEqual( - performance - .getEntriesByName(CHANNEL_SWITCH_MEASURE) - .map((entry) => entry.detail?.channelId), - [], - ); - } finally { - unregister(); - 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("an accepted navigation opens the trace after the guard, before navigate", async () => { const order = []; const committed = await commitGuardedNavigation( @@ -170,7 +13,6 @@ test("an accepted navigation opens the trace after the guard, before navigate", currentHref: "/channels/aaaa", nextHref: "/channels/bbbb", guardedTarget: route("/channels/bbbb"), - traceChannelId: "bbbb", navigate: async () => { order.push("navigate"); }, @@ -180,13 +22,10 @@ test("an accepted navigation opens the trace after the guard, before navigate", order.push("guard"); return true; }, - beginTrace: (channelId) => { - order.push(`begin:${channelId}`); - }, }, ); assert.equal(committed, true); - assert.deepEqual(order, ["guard", "begin:bbbb", "navigate"]); + assert.deepEqual(order, ["guard", "navigate"]); }); test("a same-destination no-op consults neither the guard nor the trace", async () => { @@ -196,7 +35,6 @@ test("a same-destination no-op consults neither the guard nor the trace", async currentHref: "/channels/aaaa", nextHref: "/channels/aaaa", guardedTarget: route("/channels/aaaa"), - traceChannelId: "aaaa", navigate: async () => { order.push("navigate"); }, @@ -206,9 +44,6 @@ test("a same-destination no-op consults neither the guard nor the trace", async order.push("guard"); return true; }, - beginTrace: () => { - order.push("begin"); - }, }, ); assert.equal(committed, false); @@ -232,14 +67,9 @@ test("force overrides the same-destination no-op but still runs the guard first" order.push("guard"); return true; }, - beginTrace: () => { - order.push("begin"); - }, }, ); assert.equal(committed, true); - // No traceChannelId: forced re-selection of the active channel stays - // untraced (nothing would settle it). assert.deepEqual(order, ["guard", "navigate"]); }); @@ -260,9 +90,6 @@ test("a same-destination navigation carrying router state still commits", async order.push("guard"); return true; }, - beginTrace: () => { - order.push("begin"); - }, }, ); assert.equal(committed, true); diff --git a/desktop/src/app/navigation/commitGuardedNavigation.ts b/desktop/src/app/navigation/commitGuardedNavigation.ts index 449442f5c9..a83df6ecc6 100644 --- a/desktop/src/app/navigation/commitGuardedNavigation.ts +++ b/desktop/src/app/navigation/commitGuardedNavigation.ts @@ -2,24 +2,14 @@ import { allowNavigation, type GuardedNavigation, } from "@/app/navigation/navigationGuard"; -import { - beginChannelSwitchTrace, - dropActiveChannelSwitchTrace, -} from "@/shared/lib/channelSwitchPerf"; /** * commitGuardedNavigation runs the shared commit flow for app navigations: * 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. + * highlight) must commit, or the state never lands. Returns whether the + * navigation was performed. `deps` exists for unit tests. */ export async function commitGuardedNavigation( input: { @@ -28,19 +18,13 @@ 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 && @@ -51,12 +35,6 @@ export async function commitGuardedNavigation( if (!allow(input.guardedTarget)) { return false; } - if (input.leavesChannelSurface) { - dropActiveTrace(); - } - if (input.traceChannelId !== undefined) { - beginTrace(input.traceChannelId); - } await input.navigate(); return true; } diff --git a/desktop/src/app/navigation/navigationGuard.ts b/desktop/src/app/navigation/navigationGuard.ts index 8fc78f869d..5ff853720b 100644 --- a/desktop/src/app/navigation/navigationGuard.ts +++ b/desktop/src/app/navigation/navigationGuard.ts @@ -1,5 +1,3 @@ -import { dropActiveChannelSwitchTrace } from "@/shared/lib/channelSwitchPerf"; - export type GuardedNavigation = | { kind: "history"; @@ -42,11 +40,6 @@ 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 c963bc25e6..083efc4450 100644 --- a/desktop/src/app/navigation/useAppNavigation.ts +++ b/desktop/src/app/navigation/useAppNavigation.ts @@ -41,7 +41,6 @@ export function useAppNavigation() { }, behavior: NavigationBehavior = {}, guardedTarget?: GuardedNavigation, - traceChannelId?: string, ) => { const nextLocation = router.buildLocation(next as never); return commitGuardedNavigation({ @@ -52,12 +51,6 @@ 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. Only the exact - // channel message-view route keeps a live trace: sibling routes - // (forum posts) mount different, untraced screens. - leavesChannelSurface: next.to !== "/channels/$channelId", navigate: () => navigate({ ...next, @@ -65,7 +58,6 @@ export function useAppNavigation() { resetScroll: behavior.resetScroll, } as never), nextHref: nextLocation.href, - traceChannelId, }); }, [location.href, navigate, router], @@ -325,19 +317,9 @@ export function useAppNavigation() { threadRootId: options.threadRootId ?? null, } : undefined, - // goChannel is the anchor for the switch trace; it opens inside - // commitGuardedNavigation only after the navigation guard accepts. - // Callers that await before navigating (DM actions await open_dm) - // are measured from the navigation, not from their click — see the - // scope note in channelSwitchPerf.ts. History back/forward is - // untraced, and navigations that stay on the already-active channel - // never re-run the settle effects, so a trace could only time out. - location.pathname.endsWith(`/channels/${channelId}`) - ? undefined - : channelId, ); }, - [commitNavigation, location.pathname], + [commitNavigation], ); const goNewMessage = React.useCallback( diff --git a/desktop/src/features/channels/useChannelSwitchTraceMarks.test.mjs b/desktop/src/features/channels/useChannelSwitchTraceMarks.test.mjs deleted file mode 100644 index 7177b08a0e..0000000000 --- a/desktop/src/features/channels/useChannelSwitchTraceMarks.test.mjs +++ /dev/null @@ -1,116 +0,0 @@ -import assert from "node:assert/strict"; -import { afterEach, it } from "node:test"; - -import { JSDOM } from "jsdom"; -import React from "react"; -import { act } from "react"; -import { createRoot } from "react-dom/client"; - -import { - CHANNEL_SWITCH_MEASURE, - beginChannelSwitchTrace, - resetChannelSwitchTrace, -} from "../../shared/lib/channelSwitchPerf.ts"; -import { useChannelSwitchTraceMarks } from "./useChannelSwitchTraceMarks.ts"; - -// These tests run the hook under the real react-dom development build, whose -// StrictMode replays every effect (setup → cleanup → setup) on mount. The -// Performance-panel workflow runs on that build, so a trace opened just -// before mount has to survive the replay. - -const originalDocument = globalThis.document; -const originalWindow = globalThis.window; -const originalActEnvironment = globalThis.IS_REACT_ACT_ENVIRONMENT; - -afterEach(() => { - resetChannelSwitchTrace(); - performance.clearMeasures?.(CHANNEL_SWITCH_MEASURE); - if (originalDocument === undefined) delete globalThis.document; - else globalThis.document = originalDocument; - if (originalWindow === undefined) delete globalThis.window; - else globalThis.window = originalWindow; - if (originalActEnvironment === undefined) - delete globalThis.IS_REACT_ACT_ENVIRONMENT; - else globalThis.IS_REACT_ACT_ENVIRONMENT = originalActEnvironment; -}); - -function setupDom() { - const dom = new JSDOM( - "
", - ); - const frames = []; - dom.window.requestAnimationFrame = (cb) => frames.push(cb) && frames.length; - dom.window.cancelAnimationFrame = () => {}; - Object.assign(globalThis, { - document: dom.window.document, - IS_REACT_ACT_ENVIRONMENT: true, - window: dom.window, - }); - const flushFrames = () => { - // Drain chained rAFs until quiescent. - for (let i = 0; i < 20 && frames.length > 0; i += 1) { - for (const cb of frames.splice(0, frames.length)) cb(); - } - }; - return { dom, flushFrames }; -} - -function Harness({ channelId, isTimelineLoading }) { - useChannelSwitchTraceMarks({ - activeChannelId: channelId, - activeChannelType: "stream", - isTimelineLoading, - }); - return null; -} - -function renderHarness(root, props) { - return act(async () => - root.render( - React.createElement( - React.StrictMode, - null, - React.createElement(Harness, props), - ), - ), - ); -} - -const measures = () => - performance - .getEntriesByName(CHANNEL_SWITCH_MEASURE) - .map((entry) => entry.detail?.channelId); - -it("a trace survives StrictMode's effect replay and still settles", async () => { - const { dom, flushFrames } = setupDom(); - performance.clearMeasures?.(CHANNEL_SWITCH_MEASURE); - beginChannelSwitchTrace("chan-strict"); - const root = createRoot(document.getElementById("root")); - await renderHarness(root, { - channelId: "chan-strict", - isTimelineLoading: true, - }); - await renderHarness(root, { - channelId: "chan-strict", - isTimelineLoading: false, - }); - flushFrames(); - assert.deepEqual(measures(), ["chan-strict"]); - await act(async () => root.unmount()); - dom.window.close(); -}); - -it("an A→B switch records B, never the superseded A", async () => { - const { dom, flushFrames } = setupDom(); - performance.clearMeasures?.(CHANNEL_SWITCH_MEASURE); - beginChannelSwitchTrace("chan-a"); - const root = createRoot(document.getElementById("root")); - await renderHarness(root, { channelId: "chan-a", isTimelineLoading: true }); - beginChannelSwitchTrace("chan-b"); - await renderHarness(root, { channelId: "chan-b", isTimelineLoading: true }); - await renderHarness(root, { channelId: "chan-b", isTimelineLoading: false }); - flushFrames(); - assert.deepEqual(measures(), ["chan-b"]); - await act(async () => root.unmount()); - dom.window.close(); -}); diff --git a/desktop/src/features/channels/useChannelSwitchTraceMarks.ts b/desktop/src/features/channels/useChannelSwitchTraceMarks.ts deleted file mode 100644 index bef5d3d614..0000000000 --- a/desktop/src/features/channels/useChannelSwitchTraceMarks.ts +++ /dev/null @@ -1,43 +0,0 @@ -import * as React from "react"; - -import { - abandonChannelSwitchTrace, - markChannelSwitchRouteCommit, - settleChannelSwitchTrace, -} from "@/shared/lib/channelSwitchPerf"; -import type { ChannelType } from "@/shared/api/types"; - -/** - * Switch-trace stage marks for the channel screen. Route commit fires in a - * layout effect — before the first paint — of the first commit where the - * target channel object has resolved; settle fires once its timeline leaves - * the loading latch. Both are no-ops unless goChannel opened a trace for this - * channel. Forum readiness is owned by ForumView's own queries, which the - * timeline latch cannot observe — those traces are abandoned instead of - * underreported. - */ -export function useChannelSwitchTraceMarks({ - activeChannelId, - activeChannelType, - isTimelineLoading, -}: { - activeChannelId: string | null; - activeChannelType: ChannelType | null; - isTimelineLoading: boolean; -}): void { - // Layout effect: a passive effect flushes after paint, which would report - // "commit" as first-paint time rather than commit time. - React.useLayoutEffect(() => { - if (activeChannelId) markChannelSwitchRouteCommit(activeChannelId); - }, [activeChannelId]); - React.useEffect(() => { - if (!activeChannelId) return; - if (activeChannelType === "forum") { - abandonChannelSwitchTrace(activeChannelId); - return; - } - if (!isTimelineLoading) { - settleChannelSwitchTrace(activeChannelId); - } - }, [activeChannelId, activeChannelType, isTimelineLoading]); -} diff --git a/desktop/src/features/channels/useChannelTimelineLoading.ts b/desktop/src/features/channels/useChannelTimelineLoading.ts index 2263bd5075..0427c58680 100644 --- a/desktop/src/features/channels/useChannelTimelineLoading.ts +++ b/desktop/src/features/channels/useChannelTimelineLoading.ts @@ -1,7 +1,6 @@ import * as React from "react"; import { useQueryClient } from "@tanstack/react-query"; -import { useChannelSwitchTraceMarks } from "@/features/channels/useChannelSwitchTraceMarks"; import { hasPersistedHydratedChannel } from "@/features/messages/lib/channelHeadCache"; import { resolveTimelineLoadingLatch, @@ -10,9 +9,9 @@ import { import type { Channel } from "@/shared/api/types"; /** - * Latches the timeline loading state per channel and drives the - * channel-switch trace marks from that same latch, so the tracer settles on - * exactly the loading state the screen renders from. + * Latches the timeline loading state per channel, so a channel that has + * already settled once does not flash its skeleton again while an + * authoritative refresh is in flight. */ export function useChannelTimelineLoading( activeChannel: Channel | null, @@ -52,10 +51,5 @@ export function useChannelTimelineLoading( timelineLoadingNow, ); settledChannelIdRef.current = settledChannelId; - useChannelSwitchTraceMarks({ - activeChannelId, - activeChannelType: activeChannel?.channelType ?? null, - isTimelineLoading, - }); return isTimelineLoading; } diff --git a/desktop/src/features/communities/useCommunityInit.ts b/desktop/src/features/communities/useCommunityInit.ts index eb98737895..c565ee0f7b 100644 --- a/desktop/src/features/communities/useCommunityInit.ts +++ b/desktop/src/features/communities/useCommunityInit.ts @@ -34,7 +34,6 @@ import { resetAgentObserverStore } from "@/features/agents/observerRelayStore"; import { resetAvatarPresentations } from "@/features/profile/avatarPresentationStore"; import { resetAvatarProfileSync } from "@/features/profile/avatarProfileSync"; import { resetSidebarRelayConnectionCardState } from "@/features/sidebar/ui/useSidebarRelayConnectionCard"; -import { resetChannelSwitchTrace } from "@/shared/lib/channelSwitchPerf"; import { clearMarkdownNodeCache } from "@/shared/ui/markdown/nodeCache"; import { resetMessageLinkMetadataCache } from "@/shared/ui/markdown/useMessageLinkMetadata"; import { resetVideoPlayerState } from "@/shared/ui/videoPlayerState"; @@ -58,10 +57,6 @@ async function resetCommunityState({ resetAvatarState: boolean; }): Promise { relayClient.disconnect(); - // Before the first await: the trace singleton must not survive into the - // async teardown window — queued frame callbacks could still record against - // it, and a rejection below would skip any reset placed after the await. - resetChannelSwitchTrace(); await resetNavigationDeepLinkDrain(); resetRateLimitGate(); clearAllDrafts(); diff --git a/desktop/src/features/messages/hooks.ts b/desktop/src/features/messages/hooks.ts index d97f69c205..d28f292608 100644 --- a/desktop/src/features/messages/hooks.ts +++ b/desktop/src/features/messages/hooks.ts @@ -44,7 +44,6 @@ import { recordTimeoutFromRejection, } from "@/features/moderation/lib/timeoutStore"; import { relayClient, setVisibleChannel } from "@/shared/api/relayClient"; -import { traceChannelWindowFetch } from "@/shared/lib/channelSwitchPerf"; import { customEmojiQueryKey } from "@/features/custom-emoji/hooks"; import { channelsQueryKey } from "@/features/channels/hooks"; import { reactionEmojiUrl } from "@/shared/api/customEmoji"; @@ -285,47 +284,6 @@ export function reconcileFetchedChannelWindow( return reconcileChannelWindowMessages(next, previousMessages); } -/** - * Reconciles a fetched window and then attributes it to the active switch - * trace. The ORDER is the contract: reconciliation throws for aborted - * requests, so a canceled fetch never reaches attribution and cannot claim - * the trace's one-shot slot ahead of the accepted replacement. Duration is - * measured over the fetch alone and passed in. Exported so the ordering is - * exercised by tests rather than restated by them. - */ -export function reconcileAndAttributeChannelWindow({ - queryClient, - channelId, - events, - previousMessages, - signal, - fetchDurationMs, - fetchStartedAt, -}: { - queryClient: QueryClient; - channelId: string; - events: RelayEvent[]; - previousMessages: RelayEvent[]; - signal: AbortSignal; - fetchDurationMs: number; - fetchStartedAt: number; -}): RelayEvent[] { - const result = reconcileFetchedChannelWindow( - queryClient, - channelId, - events, - previousMessages, - signal, - ); - traceChannelWindowFetch( - channelId, - events.length, - fetchDurationMs, - fetchStartedAt, - ); - return result; -} - export function useChannelMessagesQuery(channel: Channel | null) { const queryClient = useQueryClient(); const queryKey = channelMessagesKey(channel?.id ?? "none"); @@ -343,18 +301,14 @@ export function useChannelMessagesQuery(channel: Channel | null) { } const previousMessages = queryClient.getQueryData(queryKey) ?? []; - const fetchStartedAt = performance.now(); const events = await getChannelWindowEvents(channel.id); - const fetchDurationMs = performance.now() - fetchStartedAt; - return reconcileAndAttributeChannelWindow({ + return reconcileFetchedChannelWindow( queryClient, - channelId: channel.id, + channel.id, events, previousMessages, signal, - fetchDurationMs, - fetchStartedAt, - }); + ); }, staleTime: 5 * 60 * 1_000, gcTime: 60 * 60 * 1_000, diff --git a/desktop/src/features/messages/lib/projectChannelWindow.test.mjs b/desktop/src/features/messages/lib/projectChannelWindow.test.mjs index 922d729ef5..618f3fc991 100644 --- a/desktop/src/features/messages/lib/projectChannelWindow.test.mjs +++ b/desktop/src/features/messages/lib/projectChannelWindow.test.mjs @@ -2,10 +2,7 @@ import assert from "node:assert/strict"; import test from "node:test"; import { QueryClient, QueryObserver } from "@tanstack/react-query"; -import { - reconcileAndAttributeChannelWindow, - reconcileFetchedChannelWindow, -} from "../hooks.ts"; +import { reconcileFetchedChannelWindow } from "../hooks.ts"; import { channelMessagesKey, channelWindowKey } from "./messageQueryKeys.ts"; import { appendOlderChannelWindow, @@ -419,89 +416,3 @@ test("test_concurrent_refreshes_after_seeded_snapshot_share_one_authoritative_fe unsubscribe(); } }); - -test("canceled fetch never claims the switch trace's window slot; the accepted one does", async () => { - // Mirror of channelMessagesQueryOptions' queryFn contract: reconciliation - // throws for aborted requests BEFORE the fetch is attributed, so a canceled - // request cannot claim the trace's one-shot `windowFetch` slot and block - // the accepted replacement. - 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", - }; - const { - beginChannelSwitchTrace, - settleChannelSwitchTrace, - resetChannelSwitchTrace, - traceChannelWindowFetch, - CHANNEL_SWITCH_MEASURE, - } = await import("../../../shared/lib/channelSwitchPerf.ts"); - performance.clearMeasures?.(CHANNEL_SWITCH_MEASURE); - try { - const client = new QueryClient(); - const channelId = "channel"; // matches wirePage's bounds key - beginChannelSwitchTrace(channelId); - - // Canceled-first: the queryFn reconciles BEFORE attributing; the aborted - // signal throws, so trace attribution is never reached. - const canceled = new AbortController(); - canceled.abort(); - const canceledEvents = wirePage([event("stale", 100)]); - const startedAt = performance.now(); - // Drive the production helper, not a restatement of it: reverting the - // reconcile/attribute order inside it must fail this test. - assert.throws(() => - reconcileAndAttributeChannelWindow({ - queryClient: client, - channelId, - events: canceledEvents, - previousMessages: [], - signal: canceled.signal, - fetchDurationMs: 1, - fetchStartedAt: startedAt, - }), - ); - - // Accepted-second: reconciles cleanly, then claims the slot. - const acceptedEvents = wirePage([ - event("fresh-2", 120), - event("fresh-1", 110), - ]); - reconcileAndAttributeChannelWindow({ - queryClient: client, - channelId, - events: acceptedEvents, - previousMessages: [], - signal: new AbortController().signal, - fetchDurationMs: 2, - fetchStartedAt: performance.now(), - }); - - settleChannelSwitchTrace(channelId); - for (let i = 0; i < 10 && frames.length > 0; i += 1) { - for (const cb of frames.splice(0, frames.length)) cb(); - } - const measure = performance.getEntriesByName(CHANNEL_SWITCH_MEASURE).at(-1); - assert.equal( - measure?.detail?.windowFetch?.eventCount, - acceptedEvents.length, - "the accepted fetch owns the attribution slot", - ); - resetChannelSwitchTrace(); - } finally { - 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; - } -}); diff --git a/desktop/src/shared/lib/channelSwitchPerf.test.mjs b/desktop/src/shared/lib/channelSwitchPerf.test.mjs deleted file mode 100644 index fa8ba254ed..0000000000 --- a/desktop/src/shared/lib/channelSwitchPerf.test.mjs +++ /dev/null @@ -1,324 +0,0 @@ -import assert from "node:assert/strict"; -import test from "node:test"; - -import { - CHANNEL_SWITCH_MEASURE, - CHANNEL_SWITCH_START_MARK, - abandonChannelSwitchTrace, - beginChannelSwitchTrace, - dropActiveChannelSwitchTrace, - markChannelSwitchRouteCommit, - resetChannelSwitchTrace, - resolveSettleAction, - settleChannelSwitchTrace, - shouldAttributeFetch, - summarizeChannelSwitchTrace, - traceChannelWindowFetch, -} from "./channelSwitchPerf.ts"; - -function trace(overrides = {}) { - return { - channelId: "abcdef1234567890", - startedAt: 1_000, - routeCommitAt: null, - windowFetch: null, - settleEnteredAt: null, - ...overrides, - }; -} - -// --- Pure helpers --------------------------------------------------------- - -test("summary reports total, commit offset and cache-served fetches", () => { - assert.equal( - summarizeChannelSwitchTrace(trace({ routeCommitAt: 1_200 }), 1_412.4), - "[switch-perf] channel=abcdef12 total=412ms commit=+200ms window=cache", - ); -}); - -test("summary reports an attributed fetch and the truncation flag", () => { - assert.equal( - summarizeChannelSwitchTrace( - trace({ windowFetch: { durationMs: 307.2, eventCount: 89 } }), - 1_739, - true, - ), - "[switch-perf] channel=abcdef12 total=739ms commit=? " + - "window=89 events in 307ms settle=truncated", - ); -}); - -test("a settle for another channel leaves the active trace alone", () => { - // A previous channel can finish loading after the next switch began; - // clobbering the newer trace would drop exactly the rapid switches worth - // capturing. - const active = trace(); - assert.deepEqual(resolveSettleAction(active, "bbbb0000bbbb0000", 1_100), { - settledTrace: null, - timedOut: false, - }); - assert.deepEqual(resolveSettleAction(null, "abcdef1234567890", 1_100), { - settledTrace: null, - timedOut: false, - }); -}); - -test("a settle past the timeout reports the trace as timed out", () => { - const stale = trace({ startedAt: 1_000 }); - assert.deepEqual(resolveSettleAction(stale, "abcdef1234567890", 31_001), { - settledTrace: null, - timedOut: true, - }); - assert.equal( - resolveSettleAction(stale, "abcdef1234567890", 11_000).settledTrace, - stale, - ); -}); - -test("fetches attribute only inside the measured interval", () => { - const active = trace({ startedAt: 1_000 }); - // Started before the switch (a stale A→B→A leg): not this switch's cost, - // and it would occupy the one-shot slot the real fetch needs. - assert.equal(shouldAttributeFetch(active, "abcdef1234567890", 999), false); - assert.equal(shouldAttributeFetch(active, "abcdef1234567890", 1_000), true); - // Other channel or no trace: never. - assert.equal(shouldAttributeFetch(active, "bbbb0000bbbb0000", 1_500), false); - assert.equal(shouldAttributeFetch(null, "abcdef1234567890", 1_500), false); - // Started after the timeline settled: background revalidation the user never - // waited on. The trace is still active while it waits for the paint. - const settling = trace({ startedAt: 1_000, settleEnteredAt: 2_000 }); - assert.equal(shouldAttributeFetch(settling, "abcdef1234567890", 1_999), true); - assert.equal( - shouldAttributeFetch(settling, "abcdef1234567890", 2_001), - false, - ); -}); - -// --- Lifecycle ------------------------------------------------------------ - -/** - * Drives the real lifecycle with a manual frame queue, a virtual clock and a - * controllable pending marker. The clock is rebased above the real one so a - * visibilitychange fired by an earlier test cannot silently drop every trace - * at settle entry and make these assertions vacuous. - */ -function withHarness(run) { - const frames = []; - const drops = []; - const originalWindow = globalThis.window; - const originalDocument = globalThis.document; - const originalNow = performance.now; - const originalInfo = console.info; - const base = originalNow.call(performance) + 1_000; - let clock = base; - let pending = false; - performance.now = () => clock; - console.info = (line) => { - if (typeof line === "string" && line.includes("dropped (")) { - drops.push(line.slice(line.indexOf("dropped (") + 9, -1)); - } - }; - globalThis.window = { - requestAnimationFrame: (cb) => frames.push(cb) && frames.length, - cancelAnimationFrame: () => {}, - }; - globalThis.document = { - addEventListener: () => {}, - querySelector: () => (pending ? {} : null), - removeEventListener: () => {}, - visibilityState: "visible", - }; - performance.clearMeasures?.(CHANNEL_SWITCH_MEASURE); - const api = { - drops, - at: (offset) => { - clock = base + offset; - }, - setPending: (value) => { - pending = value; - }, - hide: () => { - globalThis.document.visibilityState = "hidden"; - }, - flush: (rounds = 40) => { - for (let i = 0; i < rounds && frames.length > 0; i += 1) { - for (const cb of frames.splice(0, frames.length)) cb(); - } - }, - measures: () => - performance - .getEntriesByName(CHANNEL_SWITCH_MEASURE) - .map((entry) => entry.detail?.channelId), - lastMeasure: () => - performance.getEntriesByName(CHANNEL_SWITCH_MEASURE).at(-1), - }; - try { - run(api); - } finally { - performance.now = originalNow; - console.info = originalInfo; - 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("an undisturbed switch records exactly one measure", () => { - withHarness(({ at, flush, measures, lastMeasure }) => { - at(0); - beginChannelSwitchTrace("aaaa"); - at(20); - markChannelSwitchRouteCommit("aaaa"); - at(120); - settleChannelSwitchTrace("aaaa"); - flush(); - assert.deepEqual(measures(), ["aaaa"]); - assert.notEqual(lastMeasure().detail.routeCommitAt, null); - assert.equal(lastMeasure().detail.settleWaitTruncated, undefined); - }); -}); - -test("the settle waits for a pending render, then truncates rather than hangs", () => { - withHarness(({ at, flush, setPending, measures, lastMeasure }) => { - at(0); - beginChannelSwitchTrace("aaaa"); - setPending(true); - at(50); - settleChannelSwitchTrace("aaaa"); - // The marker never clears: the wait is bounded in frames, and the sample - // is reported flagged rather than discarded — a slow switch is data. - flush(); - assert.deepEqual(measures(), ["aaaa"]); - assert.equal(lastMeasure().detail.settleWaitTruncated, true); - }); -}); - -test("a switch that paints mid-wait records without the truncation flag", () => { - withHarness(({ at, flush, setPending, lastMeasure }) => { - at(0); - beginChannelSwitchTrace("aaaa"); - setPending(true); - at(50); - settleChannelSwitchTrace("aaaa"); - flush(2); - setPending(false); - flush(); - assert.equal(lastMeasure().detail.settleWaitTruncated, undefined); - }); -}); - -test("a superseding switch discards the first trace, with a reason", () => { - withHarness(({ at, flush, drops, measures }) => { - at(0); - beginChannelSwitchTrace("aaaa"); - at(400); - // The user gave up on A and clicked B. A being slow is exactly why they - // clicked again, so a silent discard censors the switches worth seeing. - beginChannelSwitchTrace("bbbb"); - settleChannelSwitchTrace("aaaa"); - flush(); - assert.deepEqual(drops, ["superseded"]); - assert.deepEqual(measures(), []); - }); -}); - -test("a hidden window drops the trace instead of recording the absence", () => { - withHarness(({ at, flush, hide, drops, measures }) => { - at(0); - beginChannelSwitchTrace("aaaa"); - hide(); - at(9_000); - settleChannelSwitchTrace("aaaa"); - flush(); - assert.deepEqual(drops, ["hidden window"]); - assert.deepEqual(measures(), []); - }); -}); - -test("a timed-out switch is dropped, with a reason", () => { - withHarness(({ at, flush, drops, measures }) => { - at(0); - beginChannelSwitchTrace("aaaa"); - at(31_000); - settleChannelSwitchTrace("aaaa"); - flush(); - assert.deepEqual(drops, ["timed out"]); - assert.deepEqual(measures(), []); - }); -}); - -test("leaving the channel surface and forum surfaces drop with a reason", () => { - withHarness(({ at, drops }) => { - at(0); - beginChannelSwitchTrace("aaaa"); - dropActiveChannelSwitchTrace(); - at(10); - beginChannelSwitchTrace("bbbb"); - abandonChannelSwitchTrace("bbbb"); - assert.deepEqual(drops, ["left channel surface", "unobservable surface"]); - }); -}); - -test("a second settle neither restarts the wait nor moves the fetch bound", () => { - withHarness(({ at, flush, measures }) => { - at(0); - beginChannelSwitchTrace("aaaa"); - at(50); - settleChannelSwitchTrace("aaaa"); - at(60); - settleChannelSwitchTrace("aaaa"); - flush(); - assert.deepEqual(measures(), ["aaaa"]); - }); -}); - -test("an attributed window fetch reaches the measure", () => { - withHarness(({ at, flush, lastMeasure }) => { - at(0); - beginChannelSwitchTrace("aaaa"); - traceChannelWindowFetch("aaaa", 89, 307, performance.now()); - at(120); - settleChannelSwitchTrace("aaaa"); - flush(); - assert.deepEqual(lastMeasure().detail.windowFetch, { - durationMs: 307, - eventCount: 89, - }); - }); -}); - -test("beginning a switch clears the previous switch's entries", () => { - withHarness(({ at, flush, measures }) => { - at(0); - beginChannelSwitchTrace("aaaa"); - at(100); - settleChannelSwitchTrace("aaaa"); - flush(); - assert.deepEqual(measures(), ["aaaa"]); - // A consumer polling the buffer mid-switch must never read the previous - // switch's measure as the current one's. - at(200); - beginChannelSwitchTrace("bbbb"); - assert.deepEqual(measures(), []); - }); -}); - -test("the start mark shares the measure's anchor", () => { - withHarness(({ at, flush }) => { - at(0); - beginChannelSwitchTrace("aaaa"); - const startMark = performance - .getEntriesByName(CHANNEL_SWITCH_START_MARK) - .at(-1); - at(100); - settleChannelSwitchTrace("aaaa"); - flush(); - const measure = performance.getEntriesByName(CHANNEL_SWITCH_MEASURE).at(-1); - // Without a shared anchor the Performance panel shows the measure - // starting before its own start mark. - assert.equal(startMark.startTime, measure.startTime); - }); -}); diff --git a/desktop/src/shared/lib/channelSwitchPerf.ts b/desktop/src/shared/lib/channelSwitchPerf.ts deleted file mode 100644 index 5243e31a1a..0000000000 --- a/desktop/src/shared/lib/channelSwitchPerf.ts +++ /dev/null @@ -1,338 +0,0 @@ -/** - * Channel-switch timing: click → route commit → settled paint, plus the - * message-window fetch when it lands inside that interval. - * - * Deliberately small. One trace is active at a time; `beginChannelSwitchTrace` - * (from `goChannel`, via `commitGuardedNavigation`) opens it and - * `settleChannelSwitchTrace` closes it one paint after the channel's timeline - * leaves its loading latch. Output is a `[switch-perf]` console line plus User - * Timing marks and measures (`buzz:channel-switch:*`) — the Performance panel - * and the Playwright perf harness read the same numbers. Nothing is persisted. - * - * The honesty bounds below are chosen rather than inferred. Every extra - * inference this instrument tried to make became a way to report a number that - * never happened, so the scope is narrow on purpose: - * - Only navigations that reach `goChannel` are traced. History back/forward - * and re-selecting the active channel are not. - * - The interval starts at the navigation, anchored to the triggering input - * event when one is dispatching. Callers that await before navigating (DM - * actions await `open_dm`) exclude that await by design. - * - A trace overlapping a hidden window is dropped, never measured: rAF - * suspends and network throttles while hidden, so elapsed time there is not - * the user's switch. - * - The settle waits a bounded number of frames for a pending render. Past - * that bound the measure is still emitted, flagged `settleWaitTruncated` — - * a slow switch is data, not an error. - * - Every abandoned trace prints why. Drops correlate with slow switches, so a - * silent drop would make "no switches" and "switches discarded" look alike. - */ - -export type ChannelSwitchTrace = { - channelId: string; - startedAt: number; - routeCommitAt: number | null; - windowFetch: { durationMs: number; eventCount: number } | null; - /** Set when the timeline reports settled; bounds fetch attribution. */ - settleEnteredAt: number | null; -}; - -/** A switch that hasn't settled after this long is abandoned, not measured. */ -const SWITCH_TRACE_TIMEOUT_MS = 30_000; - -/** - * Frames the settle waits for a pending render before recording anyway. - * Bounded in frames rather than milliseconds so a stalled main thread cannot - * stretch the wait into the measurement. - */ -const MAX_SETTLE_FRAMES = 30; - -export const CHANNEL_SWITCH_START_MARK = "buzz:channel-switch:start"; -export const CHANNEL_SWITCH_SETTLED_MARK = "buzz:channel-switch:settled"; -export const CHANNEL_SWITCH_MEASURE = "buzz:channel-switch:click-to-settled"; - -/** - * Repo-wide marker for "a deferred commit is in flight", set by the message - * timeline and by the lazy channel pane's fallback. Other components use it - * too, so the settle wait is bounded in frames rather than trusting it to - * clear: a foreign owner can extend a switch by at most MAX_SETTLE_FRAMES, - * and that sample is flagged `settleWaitTruncated`. - */ -const RENDER_PENDING_SELECTOR = '[data-render-pending="true"]'; - -let activeTrace: ChannelSwitchTrace | null = null; - -/** Formats one settled trace as the `[switch-perf]` console line. */ -export function summarizeChannelSwitchTrace( - trace: ChannelSwitchTrace, - settledAt: number, - settleWaitTruncated = false, -): string { - const total = Math.round(settledAt - trace.startedAt); - const commit = - trace.routeCommitAt === null - ? "?" - : `+${Math.round(trace.routeCommitAt - trace.startedAt)}ms`; - const window = - trace.windowFetch === null - ? "cache" - : `${trace.windowFetch.eventCount} events in ${Math.round(trace.windowFetch.durationMs)}ms`; - return ( - `[switch-perf] channel=${trace.channelId.slice(0, 8)} total=${total}ms ` + - `commit=${commit} window=${window}` + - (settleWaitTruncated ? " settle=truncated" : "") - ); -} - -function dropTrace(trace: ChannelSwitchTrace, reason: string): void { - console.info( - `[switch-perf] channel=${trace.channelId.slice(0, 8)} dropped (${reason})`, - ); - if (activeTrace === trace) activeTrace = null; -} - -/** - * Timestamp of the most recent visibilitychange. Any transition inside a trace - * window means an off-screen interval overlaps the measurement. One listener - * per document (tests swap documents). - */ -let lastVisibilityChangeAt = Number.NEGATIVE_INFINITY; -const watchedDocuments = new WeakSet(); - -function ensureVisibilityWatcher(): void { - if (typeof document === "undefined" || !document.addEventListener) return; - if (watchedDocuments.has(document)) return; - watchedDocuments.add(document); - document.addEventListener("visibilitychange", () => { - lastVisibilityChangeAt = performance.now(); - }); -} - -function overlapsHiddenWindow(trace: ChannelSwitchTrace): boolean { - return ( - document.visibilityState === "hidden" || - lastVisibilityChangeAt >= trace.startedAt - ); -} - -function clearSwitchEntries(): void { - performance.clearMarks(CHANNEL_SWITCH_START_MARK); - performance.clearMarks(CHANNEL_SWITCH_SETTLED_MARK); - performance.clearMeasures(CHANNEL_SWITCH_MEASURE); -} - -export function beginChannelSwitchTrace(channelId: string): void { - if (typeof performance === "undefined") return; - ensureVisibilityWatcher(); - if (activeTrace) dropTrace(activeTrace, "superseded"); - // Anchor at the triggering input event when one is dispatching: a click can - // sit queued behind a long task before its handler runs, and that input - // delay is felt switch latency. window.event is set only during synchronous - // dispatch, so a stale timestamp cannot leak in from an async continuation. - // min() guards a skewed event clock; max() keeps the mark non-negative, - // which performance.mark requires. - const now = performance.now(); - const dispatching = typeof window === "undefined" ? undefined : window.event; - const startedAt = - dispatching && typeof dispatching.timeStamp === "number" - ? Math.max(0, Math.min(dispatching.timeStamp, now)) - : now; - activeTrace = { - channelId, - startedAt, - routeCommitAt: null, - windowFetch: null, - settleEnteredAt: null, - }; - // Clear the previous switch here, not only on record: traces that die - // without recording never reach record()'s clearing, and a consumer polling - // the buffer mid-switch must never read the previous switch's entries. - clearSwitchEntries(); - // startTime keeps the mark on the same anchor as the measure. - performance.mark(CHANNEL_SWITCH_START_MARK, { - detail: { channelId }, - startTime: startedAt, - }); -} - -export function markChannelSwitchRouteCommit(channelId: string): void { - if (typeof performance === "undefined") return; - if (!activeTrace || activeTrace.channelId !== channelId) return; - if (activeTrace.routeCommitAt !== null) return; - activeTrace.routeCommitAt = performance.now(); -} - -/** - * A fetch attributes to the active trace only when it targets the traced - * channel and started inside the measured interval. A fetch that started - * before the switch (the first leg of a rapid A→B→A completing during the - * second A trace) is not this switch's cost, and letting it claim the slot - * would block the real fetch. A fetch that started after the timeline settled - * is background revalidation the user never waited on. Pure for unit testing. - */ -export function shouldAttributeFetch( - trace: ChannelSwitchTrace | null, - channelId: string, - fetchStartedAt: number, -): trace is ChannelSwitchTrace { - if (!trace || trace.channelId !== channelId) return false; - if (fetchStartedAt < trace.startedAt) return false; - return ( - trace.settleEnteredAt === null || fetchStartedAt <= trace.settleEnteredAt - ); -} - -export function traceChannelWindowFetch( - channelId: string, - eventCount: number, - durationMs: number, - fetchStartedAt: number, -): void { - if (!shouldAttributeFetch(activeTrace, channelId, fetchStartedAt)) return; - activeTrace.windowFetch ??= { durationMs, eventCount }; -} - -/** - * Drops the active trace for surfaces whose readiness this instrument cannot - * observe (forum channels, whose loading ForumView owns). Better no - * measurement than a systematically underreported one. - */ -export function abandonChannelSwitchTrace(channelId: string): void { - if (activeTrace?.channelId === channelId) { - dropTrace(activeTrace, "unobservable surface"); - } -} - -/** - * 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 this is the only - * reliable exit hook, and a later untraced re-entry would otherwise settle it - * with the time spent away. - */ -export function dropActiveChannelSwitchTrace(): void { - if (activeTrace) dropTrace(activeTrace, "left channel surface"); -} - -/** Community switch (and test reset): nothing survives into the next one. */ -export function resetChannelSwitchTrace(): void { - if (activeTrace) dropTrace(activeTrace, "community reset"); - activeTrace = null; - lastVisibilityChangeAt = Number.NEGATIVE_INFINITY; - if (typeof performance !== "undefined") clearSwitchEntries(); -} - -/** - * Decides what a settle call does with the active trace. A settle for a - * different channel must leave the trace alone — a previous channel can finish - * loading after the next switch began, and clobbering the newer trace would - * drop exactly the rapid switches worth capturing. Pure for unit testing. - */ -export function resolveSettleAction( - trace: ChannelSwitchTrace | null, - channelId: string, - now: number, -): { settledTrace: ChannelSwitchTrace | null; timedOut: boolean } { - if (!trace || trace.channelId !== channelId) { - return { settledTrace: null, timedOut: false }; - } - if (now - trace.startedAt > SWITCH_TRACE_TIMEOUT_MS) { - return { settledTrace: null, timedOut: true }; - } - return { settledTrace: trace, timedOut: false }; -} - -/** - * Closes the active trace once the settled frame has painted. The timeline - * exposes `data-render-pending` until its deferred commit catches up, - * and the lazy channel pane's fallback carries the same marker while its chunk - * loads; waiting for both (bounded) keeps `totalMs` honest on render-heavy and - * cold-chunk switches. A final frame then lands the mark after the paint. - */ -export function settleChannelSwitchTrace(channelId: string): void { - if (typeof performance === "undefined") return; - const { settledTrace, timedOut } = resolveSettleAction( - activeTrace, - channelId, - performance.now(), - ); - if (!settledTrace) { - if (timedOut && activeTrace) dropTrace(activeTrace, "timed out"); - return; - } - const trace = settledTrace; - // These globals gate the whole settle path: the wait loop reads - // document.visibilityState, querySelector and rAF unguarded past this point. - if ( - typeof window === "undefined" || - typeof document === "undefined" || - !window.requestAnimationFrame - ) { - dropTrace(trace, "no DOM"); - return; - } - ensureVisibilityWatcher(); - if (overlapsHiddenWindow(trace)) { - dropTrace(trace, "hidden window"); - return; - } - // Idempotent: a second settle for this channel must not restart the wait or - // move the fetch-attribution bound. - if (trace.settleEnteredAt !== null) return; - trace.settleEnteredAt = performance.now(); - // Bind once — reading the ambient global on every frame would follow a - // swapped-out window and throw from inside a callback nothing can catch. - const schedule = window.requestAnimationFrame.bind(window); - - const record = (settleWaitTruncated: boolean) => { - const settledAt = performance.now(); - if (activeTrace === trace) activeTrace = null; - // Keep only the latest switch in the User Timing buffer: desktop sessions - // run for weeks and the buffer is never GC'd. - clearSwitchEntries(); - performance.mark(CHANNEL_SWITCH_SETTLED_MARK, { - detail: { channelId }, - startTime: settledAt, - }); - performance.measure(CHANNEL_SWITCH_MEASURE, { - detail: { - channelId, - routeCommitAt: trace.routeCommitAt, - windowFetch: trace.windowFetch, - ...(settleWaitTruncated ? { settleWaitTruncated: true } : {}), - }, - start: trace.startedAt, - end: settledAt, - }); - console.info( - summarizeChannelSwitchTrace(trace, settledAt, settleWaitTruncated), - ); - }; - - let framesWaited = 0; - const awaitPaint = () => { - // A newer switch replaced this trace, or a reset dropped it. Either way - // the paint this callback would sample is not this switch's own. - if (activeTrace !== trace) return; - if (overlapsHiddenWindow(trace)) { - dropTrace(trace, "hidden window"); - return; - } - const pending = document.querySelector(RENDER_PENDING_SELECTOR) !== null; - if (pending && framesWaited < MAX_SETTLE_FRAMES) { - framesWaited += 1; - schedule(awaitPaint); - return; - } - // One more frame so the mark lands after the browser paints. - schedule(() => { - if (activeTrace !== trace) return; - if (overlapsHiddenWindow(trace)) { - dropTrace(trace, "hidden window"); - return; - } - record(pending); - }); - }; - schedule(awaitPaint); -} diff --git a/desktop/tests/e2e/switch-settle-after-paint.spec.ts b/desktop/tests/e2e/switch-settle-after-paint.spec.ts deleted file mode 100644 index fb264593e8..0000000000 --- a/desktop/tests/e2e/switch-settle-after-paint.spec.ts +++ /dev/null @@ -1,148 +0,0 @@ -import { expect, test } from "@playwright/test"; - -import { installMockBridge } from "../helpers/bridge"; - -/** - * The switch trace must settle AFTER the deferred timeline has committed and - * painted. During the skeleton→loaded transition the message-list branches - * (which used to own the `data-render-pending` marker) are not mounted, so a - * tracer polling only that marker would read "not pending" and record a - * settle while the heavy deferred list was still uncommitted — underreporting - * exactly the switches the tracer exists to measure. The marker now lives on - * the timeline's always-mounted wrapper; this spec pins the contract on a - * real empty→loaded cold switch into a deep channel. - */ - -const SWITCH_MEASURE = "buzz:channel-switch:click-to-settled"; - -test("cold-switch settle measure lands only after rows are painted", async ({ - page, -}) => { - await installMockBridge(page, { deepHistoryMessageCount: 600 }); - await page.goto("/"); - await expect(page.getByTestId("app-sidebar")).toBeVisible(); - - // Cold first entry: skeleton → deferred list commit → settled paint. - await page.getByTestId("channel-deep-history").click(); - - // Poll for the settle measure inside the page and — in the same synchronous - // evaluation turn — snapshot what the DOM shows at that moment. Reading the - // DOM from the test process after the fact would race further renders. Only - // CLEAN measures count: a truncated one means the tracer honestly hit its - // render-wait deadline (harness timing), which must fail with that reason - // rather than masquerading as a tracer regression. - const atSettle = await page.evaluate(async (measureName) => { - const deadline = Date.now() + 15_000; - while (Date.now() < deadline) { - const entries = performance.getEntriesByName(measureName); - const clean = entries.filter( - (entry) => !(entry as PerformanceMeasure).detail?.settleWaitTruncated, - ); - if (clean.length > 0) { - return { - renderPending: - document.querySelector('[data-render-pending="true"]') !== null, - rowCount: document.querySelectorAll( - '[data-message-id^="mock-deep-history-"]', - ).length, - settled: true, - truncatedOnly: false, - }; - } - if (entries.length > 0) { - return { - renderPending: true, - rowCount: 0, - settled: false, - truncatedOnly: true, - }; - } - await new Promise((resolve) => setTimeout(resolve, 16)); - } - return { - renderPending: true, - rowCount: 0, - settled: false, - truncatedOnly: false, - }; - }, SWITCH_MEASURE); - - expect( - atSettle.truncatedOnly, - "tracer truncated at its render-wait deadline — harness timing exhausted, not a tracer bug; rerun", - ).toBe(false); - expect(atSettle.settled, "switch trace must settle").toBe(true); - expect( - atSettle.rowCount, - "settle must not be recorded before the deferred list painted", - ).toBeGreaterThan(0); - expect( - atSettle.renderPending, - "settle must not be recorded while a deferred commit is still pending", - ).toBe(false); -}); - -/** - * While the lazy ChannelPane chunk is still suspended, the timeline (and its - * render-pending marker) is not mounted — only the Suspense fallback is. The - * fallback must therefore read as pending itself, or the tracer would record - * a settle with zero rows while the loading skeleton was still visible. This - * spec holds the chunk to pin that contract. - */ -test("settle waits for a delayed lazy channel-pane chunk", async ({ page }) => { - let releaseChunk = () => {}; - const chunkHold = new Promise((resolve) => { - releaseChunk = resolve; - }); - let chunkRequested = false; - await page.route(/\/assets\/ChannelPane-[^/]+\.js(\?.*)?$/, async (route) => { - chunkRequested = true; - await chunkHold; - await route.continue(); - }); - - await installMockBridge(page, { deepHistoryMessageCount: 600 }); - await page.goto("/"); - await expect(page.getByTestId("app-sidebar")).toBeVisible(); - - await page.getByTestId("channel-deep-history").click(); - await expect - .poll(() => chunkRequested, { - message: "the ChannelPane chunk must load lazily on first channel entry", - }) - .toBe(true); - - // While the pane chunk is held there are no rows on screen, so any measure - // emitted here must carry the truncation flag. A CLEAN measure would be the - // regression: a settled paint reported for a screen showing a fallback. - await page.waitForTimeout(1_000); - const cleanWhileSuspended = await page.evaluate( - (name) => - performance - .getEntriesByName(name) - .filter( - (entry) => !(entry as PerformanceMeasure).detail?.settleWaitTruncated, - ).length, - SWITCH_MEASURE, - ); - expect( - cleanWhileSuspended, - "no clean settle may be recorded while the pane chunk is suspended", - ).toBe(0); - - releaseChunk(); - - // After release the pane mounts and paints rows. The tracer's own record - // may already have landed (truncated, by design) — what matters is that the - // channel actually painted, which is what a clean settle would have claimed. - await expect - .poll( - () => - page - .locator('[data-message-id^="mock-deep-history-"]') - .count() - .then((count) => count > 0), - { message: "the released pane must paint rows", timeout: 15_000 }, - ) - .toBe(true); -});