jerry/buzz
1
0
Fork 0
mirror of https://github.com/block/buzz.git synced 2026-10-31 14:31:02 +00:00
Code Issues Packages Projects Releases Wiki Activity

refactor(desktop): drop the switch tracer, keep the perf harness

Browse Source 
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 <maxwell@squareup.com>
This commit is contained in:
Max Lampert
2026-08-26 20:31:48 -07:00
parent be26be0181
commit 8a8e01cfb0
14 changed files with 12 additions and 1348 deletions
Download Patch File Download Diff File Expand all files Collapse all files

1
desktop/playwright.config.ts
View File

@@ -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",

177
desktop/src/app/navigation/commitGuardedNavigation.test.mjs
View File

@@ -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);

26
desktop/src/app/navigation/commitGuardedNavigation.ts
View File

@@ -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<unknown>;
},
deps: {
allow?: typeof allowNavigation;
beginTrace?: typeof beginChannelSwitchTrace;
dropActiveTrace?: typeof dropActiveChannelSwitchTrace;
} = {},
): Promise<boolean> {
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;
}

7
desktop/src/app/navigation/navigationGuard.ts
View File

@@ -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;
}

20
desktop/src/app/navigation/useAppNavigation.ts
View File

@@ -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(

116
desktop/src/features/channels/useChannelSwitchTraceMarks.test.mjs
View File

@@ -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(
"<!doctype html><html><body><div id='root'></div></body></html>",
);
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();
});

43
desktop/src/features/channels/useChannelSwitchTraceMarks.ts
View File

@@ -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]);
}

12
desktop/src/features/channels/useChannelTimelineLoading.ts
View File

@@ -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;
}

5
desktop/src/features/communities/useCommunityInit.ts
View File

@@ -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<void> {
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();

52
desktop/src/features/messages/hooks.ts
View File

@@ -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<RelayEvent[]>(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,

91
desktop/src/features/messages/lib/projectChannelWindow.test.mjs
View File

@@ -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;
}
});

324
desktop/src/shared/lib/channelSwitchPerf.test.mjs
View File

@@ -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);
});
});

338
desktop/src/shared/lib/channelSwitchPerf.ts
View File

@@ -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<object>();
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);
}

148
desktop/tests/e2e/switch-settle-after-paint.spec.ts
View File

@@ -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<void>((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);
});