From 5f7e56716a2e30ab7ab719b7826c2e78374c3269 Mon Sep 17 00:00:00 2001 From: Max Lampert Date: Thu, 20 Aug 2026 13:47:13 -0700 Subject: [PATCH 1/3] perf(desktop): trace channel switches from click to settled paint MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Add a single-active-trace instrument for channel navigation: goChannel opens the trace, ChannelScreen marks route commit and settles it after the timeline loading latch clears (double rAF so the frame painted). The two relay fetches that can sit on the switch path — the message window and the member roster — are attributed to the trace when they run during it; cache-served switches log "cache". Each switch emits one [switch-perf] console line plus User Timing marks/measures (buzz:channel-switch:*) so before/after comparisons work identically in a dev build, the Performance panel, and Playwright perf specs. Signed-off-by: Max Lampert --- desktop/playwright.config.ts | 1 + desktop/src-tauri/build.rs | 28 ++ desktop/src-tauri/src/commands/mod.rs | 2 + desktop/src-tauri/src/commands/perf_log.rs | 268 ++++++++++++++++ desktop/src-tauri/src/lib.rs | 1 + .../src/app/navigation/useAppNavigation.ts | 20 +- desktop/src/features/channels/hooks.ts | 82 +---- desktop/src/features/channels/sidebarPerf.ts | 74 +++++ .../features/channels/ui/ChannelScreen.tsx | 6 + .../channels/useChannelSwitchTraceMarks.ts | 54 ++++ .../features/communities/useCommunityInit.ts | 5 + desktop/src/features/messages/hooks.ts | 16 +- .../lib/projectChannelWindow.test.mjs | 82 +++++ .../features/messages/ui/MessageTimeline.tsx | 18 +- .../src/shared/lib/channelSwitchPerf.test.mjs | 216 +++++++++++++ desktop/src/shared/lib/channelSwitchPerf.ts | 297 ++++++++++++++++++ desktop/src/testing/e2eBridge.ts | 3 + .../e2e/switch-settle-after-paint.spec.ts | 58 ++++ 18 files changed, 1150 insertions(+), 81 deletions(-) create mode 100644 desktop/src-tauri/src/commands/perf_log.rs create mode 100644 desktop/src/features/channels/sidebarPerf.ts create mode 100644 desktop/src/features/channels/useChannelSwitchTraceMarks.ts create mode 100644 desktop/src/shared/lib/channelSwitchPerf.test.mjs create mode 100644 desktop/src/shared/lib/channelSwitchPerf.ts create mode 100644 desktop/tests/e2e/switch-settle-after-paint.spec.ts diff --git a/desktop/playwright.config.ts b/desktop/playwright.config.ts index ff8a0e7703b..86108bf6e50 100644 --- a/desktop/playwright.config.ts +++ b/desktop/playwright.config.ts @@ -104,6 +104,7 @@ 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-tauri/build.rs b/desktop/src-tauri/build.rs index 2cdd785c735..63dfa91dc6b 100644 --- a/desktop/src-tauri/build.rs +++ b/desktop/src-tauri/build.rs @@ -8,6 +8,34 @@ include!("src/managed_agents/reserved_env_keys.rs"); use base64::Engine as _; fn main() { + // Bake the source git revision into the binary so diagnostics (the + // switch-perf JSONL sink) can attribute records to the build that wrote + // them. Reruns key off the reflog, which updates on every checkout, + // commit, and rebase. `--dirty` marks uncommitted worktrees but is only + // as fresh as the last build-script run: plain source edits between + // builds do not re-stamp it. Checkout-based A/B flows (the intended use) + // always update the reflog and re-stamp. + if let Ok(git_dir) = std::process::Command::new("git") + .args(["rev-parse", "--absolute-git-dir"]) + .output() + { + if git_dir.status.success() { + let dir = String::from_utf8_lossy(&git_dir.stdout).trim().to_string(); + println!("cargo:rerun-if-changed={dir}/HEAD"); + println!("cargo:rerun-if-changed={dir}/logs/HEAD"); + } + } + if let Some(git_sha) = std::process::Command::new("git") + .args(["describe", "--always", "--dirty", "--abbrev=12"]) + .output() + .ok() + .filter(|output| output.status.success()) + .map(|output| String::from_utf8_lossy(&output.stdout).trim().to_string()) + .filter(|sha| !sha.is_empty()) + { + println!("cargo:rustc-env=BUZZ_DESKTOP_BUILD_GIT_SHA={git_sha}"); + } + println!("cargo:rerun-if-env-changed=BUZZ_RELAY_URL"); println!("cargo:rerun-if-env-changed=BUZZ_RELAY_HTTP"); println!("cargo:rerun-if-env-changed=BUZZ_UPDATER_PUBLIC_KEY"); diff --git a/desktop/src-tauri/src/commands/mod.rs b/desktop/src-tauri/src/commands/mod.rs index 7cb2d8e3b83..0389c20ecea 100644 --- a/desktop/src-tauri/src/commands/mod.rs +++ b/desktop/src-tauri/src/commands/mod.rs @@ -44,6 +44,7 @@ mod notifications; mod observer_archive; mod os_idle; pub mod pairing; +mod perf_log; mod personas; mod prevent_sleep; mod profile; @@ -105,6 +106,7 @@ pub use notifications::*; pub use observer_archive::*; pub use os_idle::*; pub use pairing::*; +pub use perf_log::*; pub use personas::*; pub use prevent_sleep::*; pub use profile::*; diff --git a/desktop/src-tauri/src/commands/perf_log.rs b/desktop/src-tauri/src/commands/perf_log.rs new file mode 100644 index 00000000000..ff493ac413e --- /dev/null +++ b/desktop/src-tauri/src/commands/perf_log.rs @@ -0,0 +1,268 @@ +//! Append-only JSONL sink for channel-switch perf traces. +//! +//! The desktop's `[switch-perf]` console traces vanish with the session; this +//! sink persists one JSON line per settled switch to +//! `{app_log_dir}/switch-perf.jsonl` so before/after builds can be compared +//! offline. Every line is stamped with the build's git revision (baked by +//! build.rs) and, when set at launch, the `BUZZ_PERF_LOG_LABEL` run label — +//! e.g. `BUZZ_PERF_LOG_LABEL=before just production`. + +use std::io::Write; + +use tauri::Manager; + +const PERF_LOG_FILENAME: &str = "switch-perf.jsonl"; + +/// Defensive cap: one record is a small trace object; anything larger is a +/// caller bug and must not grow the log unbounded. +const MAX_RECORD_BYTES: usize = 4 * 1024; + +/// Rotation threshold. The sink is always on, so without a cap the JSONL +/// grows for the life of the install; one rotated generation preserves +/// enough history for before/after comparisons. +const MAX_LOG_BYTES: u64 = 10 * 1024 * 1024; + +/// Validates and shapes one JSONL line: the record must be a JSON object +/// (which also guarantees the stored line is newline-free), then the build +/// revision and optional run label are folded in. Pure for unit testing. +fn shape_perf_log_line( + record_json: &str, + git_sha: Option<&str>, + label: Option<&str>, +) -> Result { + if record_json.len() > MAX_RECORD_BYTES { + return Err("perf log record too large".to_string()); + } + let mut value: serde_json::Value = + serde_json::from_str(record_json).map_err(|e| format!("invalid perf log record: {e}"))?; + let object = value + .as_object_mut() + .ok_or_else(|| "perf log record must be a JSON object".to_string())?; + object.insert( + "gitSha".to_string(), + match git_sha { + Some(sha) => serde_json::Value::String(sha.to_string()), + None => serde_json::Value::Null, + }, + ); + if let Some(label) = label { + object.insert( + "label".to_string(), + serde_json::Value::String(label.to_string()), + ); + } + serde_json::to_string(&value).map_err(|e| e.to_string()) +} + +/// Serializes the whole metadata→rename→append transaction. Appends run on +/// independent `spawn_blocking` threads; without this, two writers at the +/// rotation boundary can both decide to rotate — the loser's rename fails and +/// its record is dropped. One global lock suffices: the app writes a single +/// log path. +static PERF_LOG_LOCK: std::sync::Mutex<()> = std::sync::Mutex::new(()); + +/// Appends one line, rotating the file to `.1` (replacing the previous +/// generation) once it exceeds `max_bytes`. Factored for unit testing. +fn append_line_rotating(path: &std::path::Path, line: &str, max_bytes: u64) -> Result<(), String> { + let _guard = PERF_LOG_LOCK + .lock() + .unwrap_or_else(|poisoned| poisoned.into_inner()); + if let Ok(metadata) = std::fs::metadata(path) { + if metadata.len() >= max_bytes { + let mut rotated = path.as_os_str().to_owned(); + rotated.push(".1"); + let rotated = std::path::PathBuf::from(rotated); + // Remove the retained generation before renaming over it: on + // Windows, rename does not replace an existing destination, and a + // failed rotation here would silently drop every subsequent trace + // (the frontend deliberately swallows sink errors). Same platform + // rule as managed_agents::storage::start_install_log_session. + if rotated.exists() { + std::fs::remove_file(&rotated).map_err(|e| e.to_string())?; + } + std::fs::rename(path, &rotated).map_err(|e| e.to_string())?; + } + } + let mut file = std::fs::OpenOptions::new() + .create(true) + .append(true) + .open(path) + .map_err(|e| e.to_string())?; + writeln!(file, "{line}").map_err(|e| e.to_string()) +} + +/// Appends one switch-perf record to the app-log-dir JSONL file and returns +/// the file's path so the frontend can announce where the log lives. +/// +/// Async so Tauri runs it on the async runtime rather than the main thread: +/// a perf sink must not add main-thread filesystem stalls to the switches it +/// measures. +#[tauri::command] +pub async fn append_switch_perf_log( + app: tauri::AppHandle, + record_json: String, +) -> Result { + let label = std::env::var("BUZZ_PERF_LOG_LABEL").ok(); + let line = shape_perf_log_line( + &record_json, + option_env!("BUZZ_DESKTOP_BUILD_GIT_SHA"), + label.as_deref(), + )?; + let dir = app.path().app_log_dir().map_err(|e| e.to_string())?; + let path = dir.join(PERF_LOG_FILENAME); + let result = tauri::async_runtime::spawn_blocking(move || { + std::fs::create_dir_all(path.parent().unwrap_or(&path)).map_err(|e| e.to_string())?; + append_line_rotating(&path, &line, MAX_LOG_BYTES)?; + Ok::(path.display().to_string()) + }) + .await + .map_err(|e| e.to_string())?; + result +} + +#[cfg(test)] +mod tests { + use super::*; + + #[test] + fn shape_folds_in_git_sha_and_label() { + let line = shape_perf_log_line(r#"{"totalMs":412}"#, Some("abc123-dirty"), Some("before")) + .expect("shape"); + let value: serde_json::Value = serde_json::from_str(&line).expect("parse"); + assert_eq!(value["totalMs"], 412); + assert_eq!(value["gitSha"], "abc123-dirty"); + assert_eq!(value["label"], "before"); + assert!(!line.contains('\n')); + } + + #[test] + fn shape_without_label_or_sha_keeps_record_and_null_sha() { + let line = shape_perf_log_line(r#"{"totalMs":1}"#, None, None).expect("shape"); + let value: serde_json::Value = serde_json::from_str(&line).expect("parse"); + assert_eq!(value["gitSha"], serde_json::Value::Null); + assert!(value.get("label").is_none()); + } + + #[test] + fn shape_rejects_non_objects_and_oversized_records() { + assert!(shape_perf_log_line("[1,2]", None, None).is_err()); + assert!(shape_perf_log_line("not json", None, None).is_err()); + let oversized = format!(r#"{{"pad":"{}"}}"#, "x".repeat(MAX_RECORD_BYTES)); + assert!(shape_perf_log_line(&oversized, None, None).is_err()); + } + + #[test] + fn append_rotates_once_over_the_cap_and_keeps_one_generation() { + let dir = std::env::temp_dir().join(format!("perf-log-test-{}", std::process::id())); + std::fs::create_dir_all(&dir).expect("tempdir"); + let path = dir.join("switch-perf.jsonl"); + let _ = std::fs::remove_file(&path); + let _ = std::fs::remove_file(dir.join("switch-perf.jsonl.1")); + + append_line_rotating(&path, "first", 16).expect("append"); + append_line_rotating(&path, "second", 16).expect("append"); + // 12 bytes so far — under the cap, same file. + assert_eq!( + std::fs::read_to_string(&path).expect("read"), + "first\nsecond\n" + ); + + // Push past the cap; the next append must rotate. + append_line_rotating(&path, "third-is-long", 16).expect("append"); + append_line_rotating(&path, "fresh", 16).expect("append"); + assert_eq!(std::fs::read_to_string(&path).expect("read"), "fresh\n"); + assert_eq!( + std::fs::read_to_string(dir.join("switch-perf.jsonl.1")).expect("read rotated"), + "first\nsecond\nthird-is-long\n" + ); + + // A second rotation replaces the previous generation, never a third file. + append_line_rotating(&path, "overflow-the-cap!", 16).expect("append"); + append_line_rotating(&path, "newest", 16).expect("append"); + assert_eq!(std::fs::read_to_string(&path).expect("read"), "newest\n"); + assert_eq!( + std::fs::read_to_string(dir.join("switch-perf.jsonl.1")).expect("read rotated"), + "fresh\noverflow-the-cap!\n" + ); + std::fs::remove_dir_all(&dir).ok(); + } + + #[test] + fn rotation_replaces_an_existing_retained_generation() { + let dir = std::env::temp_dir().join(format!( + "perf-log-regen-{}-{:?}", + std::process::id(), + std::thread::current().id() + )); + std::fs::create_dir_all(&dir).expect("tempdir"); + let path = dir.join("switch-perf.jsonl"); + let rotated = dir.join("switch-perf.jsonl.1"); + // Seed BOTH generations, as after any prior rollover. On Windows a + // bare rename onto the existing `.1` fails, which used to kill every + // subsequent append. + std::fs::write(&path, "current-full\n").expect("seed current"); + std::fs::write(&rotated, "old-generation\n").expect("seed rotated"); + + append_line_rotating(&path, "fresh", 8).expect("rotation over existing .1 must succeed"); + + assert_eq!(std::fs::read_to_string(&path).expect("read"), "fresh\n"); + assert_eq!( + std::fs::read_to_string(&rotated).expect("read rotated"), + "current-full\n" + ); + std::fs::remove_dir_all(&dir).ok(); + } + + #[test] + fn concurrent_boundary_appends_lose_no_line_and_rotate_once() { + let dir = std::env::temp_dir().join(format!( + "perf-log-concurrent-{}-{:?}", + std::process::id(), + std::thread::current().id() + )); + std::fs::create_dir_all(&dir).expect("tempdir"); + let path = dir.join("switch-perf.jsonl"); + let _ = std::fs::remove_file(&path); + let _ = std::fs::remove_file(dir.join("switch-perf.jsonl.1")); + + // 8 writers × 4 lines of 16 bytes = 512 bytes against a 384-byte cap: + // exactly one rotation boundary is crossed, so every line must land in + // either the live file or the single rotated generation. Unserialized + // metadata→rename→append interleavings drop lines or fail renames. + let threads: Vec<_> = (0..8) + .map(|writer| { + let path = path.clone(); + std::thread::spawn(move || { + for line_index in 0..4 { + append_line_rotating( + &path, + &format!("writer-{writer:02}-line-{line_index:02}"), + 384, + ) + .expect("append"); + } + }) + }) + .collect(); + for thread in threads { + thread.join().expect("join"); + } + + let mut lines: Vec = std::fs::read_to_string(&path) + .expect("read live") + .lines() + .map(str::to_string) + .collect(); + if let Ok(rotated) = std::fs::read_to_string(dir.join("switch-perf.jsonl.1")) { + lines.extend(rotated.lines().map(str::to_string)); + } + lines.sort(); + let expected: Vec = (0..8) + .flat_map(|writer| { + (0..4).map(move |line_index| format!("writer-{writer:02}-line-{line_index:02}")) + }) + .collect(); + assert_eq!(lines, expected, "every append must survive the boundary"); + std::fs::remove_dir_all(&dir).ok(); + } +} diff --git a/desktop/src-tauri/src/lib.rs b/desktop/src-tauri/src/lib.rs index 71a5eb3806e..f0d88287d6c 100644 --- a/desktop/src-tauri/src/lib.rs +++ b/desktop/src-tauri/src/lib.rs @@ -589,6 +589,7 @@ pub fn run() { search_users, get_presence, get_os_idle_seconds, + append_switch_perf_log, get_default_relay_url, auto_connect_default_relay_enabled, get_legacy_workspace_storage, diff --git a/desktop/src/app/navigation/useAppNavigation.ts b/desktop/src/app/navigation/useAppNavigation.ts index c4776564e34..412120182c5 100644 --- a/desktop/src/app/navigation/useAppNavigation.ts +++ b/desktop/src/app/navigation/useAppNavigation.ts @@ -8,6 +8,7 @@ import { import { openSearchHitWithNavigation } from "@/app/navigation/searchHitNavigation"; import type { SearchHit } from "@/shared/api/types"; +import { beginChannelSwitchTrace } from "@/shared/lib/channelSwitchPerf"; type NavigationBehavior = { force?: boolean; @@ -256,8 +257,18 @@ export function useAppNavigation() { thread?: string; threadRootId?: string | null; }, - ) => - commitNavigation( + ) => { + // Every channel navigation entry point funnels through here, so this + // is the single click-time anchor for the switch trace. Re-selecting + // the already-active channel is a no-op navigation: the channel's + // effects never rerun, nothing would settle the trace, and it would + // squat on the singleton until timeout — so don't open one. (History + // back/forward bypasses goChannel entirely and is deliberately + // untraced.) + if (!location.pathname.endsWith(`/channels/${channelId}`)) { + beginChannelSwitchTrace(channelId); + } + return commitNavigation( { to: "/channels/$channelId", params: { @@ -282,8 +293,9 @@ export function useAppNavigation() { replace: options?.replace, resetScroll: options?.messageId ? true : undefined, }, - ), - [commitNavigation], + ); + }, + [commitNavigation, location.pathname], ); const goNewMessage = React.useCallback( diff --git a/desktop/src/features/channels/hooks.ts b/desktop/src/features/channels/hooks.ts index 9069b052da4..f08842355b4 100644 --- a/desktop/src/features/channels/hooks.ts +++ b/desktop/src/features/channels/hooks.ts @@ -42,6 +42,7 @@ import type { } from "@/shared/api/tauriChannels"; import { mergeConcurrentChannelRecency } from "@/features/channels/lib/channelRecencyMerge"; import { useIdentityQuery } from "@/shared/api/hooks"; +import { traceChannelMembersFetch } from "@/shared/lib/channelSwitchPerf"; import { useFocusedRefetchInterval } from "@/shared/lib/useDocumentVisible"; import { useCommunities } from "@/features/communities/useCommunities"; import { @@ -49,6 +50,10 @@ import { type ChannelSnapshot, writeChannelSnapshot, } from "@/features/channels/channelSnapshot"; +import { + markSnapshotDiagnostic, + measureFullSidebarPaint, +} from "@/features/channels/sidebarPerf"; import { CHANNEL_MEMBERS_STALE_TIME_MS, channelMembersQueryKey, @@ -97,73 +102,6 @@ export function sortChannels(channels: Channel[]) { }); } -export const CHANNELS_SNAPSHOT_DIAGNOSTIC_MARK = - "buzz:sidebar:snapshot-diagnostic"; -export const CHANNELS_FULL_SIDEBAR_PAINT_MARK = - "buzz:sidebar:full-list-painted"; -export const CHANNELS_BOOT_TO_FULL_SIDEBAR_MEASURE = - "buzz:sidebar:boot-to-full-list-painted"; - -const markedSnapshotKeys = new Set(); -const measuredSidebarKeys = new Set(); -const scheduledSidebarKeys = new Set(); - -function sidebarMeasurementKey(relayUrl: string, ownerPubkey: string): string { - return `${relayUrl}\u0000${ownerPubkey.toLowerCase()}`; -} - -function markSnapshotDiagnostic( - relayUrl: string, - ownerPubkey: string, - diagnostics: ReturnType["diagnostics"], -): void { - if (typeof performance === "undefined") return; - const key = sidebarMeasurementKey(relayUrl, ownerPubkey); - if (markedSnapshotKeys.has(key)) return; - markedSnapshotKeys.add(key); - performance.mark(CHANNELS_SNAPSHOT_DIAGNOSTIC_MARK, { - detail: { ...diagnostics, relayUrl }, - }); - console.info("[sidebar-perf] snapshot", { ...diagnostics, relayUrl }); -} - -function measureFullSidebarPaint( - relayUrl: string, - ownerPubkey: string, - channelCount: number, -): void { - if (typeof performance === "undefined") return; - const key = sidebarMeasurementKey(relayUrl, ownerPubkey); - if (measuredSidebarKeys.has(key) || scheduledSidebarKeys.has(key)) return; - scheduledSidebarKeys.add(key); - - // The channels have committed to the shared query cache; two animation frames - // put the mark after React's sidebar DOM commit and the browser's next paint. - window.requestAnimationFrame(() => { - window.requestAnimationFrame(() => { - scheduledSidebarKeys.delete(key); - if (measuredSidebarKeys.has(key)) return; - measuredSidebarKeys.add(key); - performance.mark(CHANNELS_FULL_SIDEBAR_PAINT_MARK, { - detail: { channelCount, relayUrl }, - }); - performance.measure(CHANNELS_BOOT_TO_FULL_SIDEBAR_MEASURE, { - detail: { channelCount, relayUrl }, - duration: performance.now(), - start: 0, - }); - const measure = performance - .getEntriesByName(CHANNELS_BOOT_TO_FULL_SIDEBAR_MEASURE) - .at(-1); - console.info("[sidebar-perf] full list painted", { - channelCount, - durationMs: measure?.duration, - relayUrl, - }); - }); - }); -} - export type CachedChannelMember = { membershipAdded: boolean; name: string; @@ -627,7 +565,15 @@ export function useChannelMembersQuery( throw new Error("No channel selected."); } - return getChannelMembers(channelId); + const fetchStartedAt = performance.now(); + const members = await getChannelMembers(channelId); + traceChannelMembersFetch( + channelId, + members.length, + performance.now() - fetchStartedAt, + fetchStartedAt, + ); + return members; }, staleTime: CHANNEL_MEMBERS_STALE_TIME_MS, }); diff --git a/desktop/src/features/channels/sidebarPerf.ts b/desktop/src/features/channels/sidebarPerf.ts new file mode 100644 index 00000000000..e2904fcd096 --- /dev/null +++ b/desktop/src/features/channels/sidebarPerf.ts @@ -0,0 +1,74 @@ +/** + * Sidebar boot-paint measurement: marks the persisted-snapshot read and the + * first fully-painted channel list per relay+identity. Split from hooks.ts to + * keep that file under the per-file line cap; behavior unchanged. + */ + +import type { inspectChannelSnapshot } from "@/features/channels/channelSnapshot"; + +export const CHANNELS_SNAPSHOT_DIAGNOSTIC_MARK = + "buzz:sidebar:snapshot-diagnostic"; +export const CHANNELS_FULL_SIDEBAR_PAINT_MARK = + "buzz:sidebar:full-list-painted"; +export const CHANNELS_BOOT_TO_FULL_SIDEBAR_MEASURE = + "buzz:sidebar:boot-to-full-list-painted"; + +const markedSnapshotKeys = new Set(); +const measuredSidebarKeys = new Set(); +const scheduledSidebarKeys = new Set(); + +function sidebarMeasurementKey(relayUrl: string, ownerPubkey: string): string { + return `${relayUrl}\u0000${ownerPubkey.toLowerCase()}`; +} + +export function markSnapshotDiagnostic( + relayUrl: string, + ownerPubkey: string, + diagnostics: ReturnType["diagnostics"], +): void { + if (typeof performance === "undefined") return; + const key = sidebarMeasurementKey(relayUrl, ownerPubkey); + if (markedSnapshotKeys.has(key)) return; + markedSnapshotKeys.add(key); + performance.mark(CHANNELS_SNAPSHOT_DIAGNOSTIC_MARK, { + detail: { ...diagnostics, relayUrl }, + }); + console.info("[sidebar-perf] snapshot", { ...diagnostics, relayUrl }); +} + +export function measureFullSidebarPaint( + relayUrl: string, + ownerPubkey: string, + channelCount: number, +): void { + if (typeof performance === "undefined") return; + const key = sidebarMeasurementKey(relayUrl, ownerPubkey); + if (measuredSidebarKeys.has(key) || scheduledSidebarKeys.has(key)) return; + scheduledSidebarKeys.add(key); + + // The channels have committed to the shared query cache; two animation frames + // put the mark after React's sidebar DOM commit and the browser's next paint. + window.requestAnimationFrame(() => { + window.requestAnimationFrame(() => { + scheduledSidebarKeys.delete(key); + if (measuredSidebarKeys.has(key)) return; + measuredSidebarKeys.add(key); + performance.mark(CHANNELS_FULL_SIDEBAR_PAINT_MARK, { + detail: { channelCount, relayUrl }, + }); + performance.measure(CHANNELS_BOOT_TO_FULL_SIDEBAR_MEASURE, { + detail: { channelCount, relayUrl }, + duration: performance.now(), + start: 0, + }); + const measure = performance + .getEntriesByName(CHANNELS_BOOT_TO_FULL_SIDEBAR_MEASURE) + .at(-1); + console.info("[sidebar-perf] full list painted", { + channelCount, + durationMs: measure?.duration, + relayUrl, + }); + }); + }); +} diff --git a/desktop/src/features/channels/ui/ChannelScreen.tsx b/desktop/src/features/channels/ui/ChannelScreen.tsx index 6254afd8c71..0d15b10cb01 100644 --- a/desktop/src/features/channels/ui/ChannelScreen.tsx +++ b/desktop/src/features/channels/ui/ChannelScreen.tsx @@ -66,6 +66,7 @@ import { useHuddleReadMarker } from "@/features/channels/ui/useHuddleReadMarker" import { useHuddleThreadIsolation } from "@/features/channels/ui/useHuddleThreadIsolation"; import { AgentSessionProvider } from "@/shared/context/AgentSessionContext"; import { ProfilePanelProvider } from "@/shared/context/ProfilePanelContext"; +import { useChannelSwitchTraceMarks } from "@/features/channels/useChannelSwitchTraceMarks"; import { useMainInsetRef } from "@/shared/layout/MainInsetContext"; import { channelContentTopPaddingMeasurement } from "@/shared/layout/chromeLayout"; import { useMeasuredCssVariable } from "@/shared/layout/useMeasuredCssVariable"; @@ -616,6 +617,11 @@ export function ChannelScreen({ timelineLoadingNow, ); settledChannelIdRef.current = settledChannelId; + useChannelSwitchTraceMarks({ + activeChannelId, + activeChannelType: activeChannel?.channelType ?? null, + isTimelineLoading, + }); const { welcomeKickoffStage, welcomeKickoffSettingUp } = useWelcomeKickoffStagePresence( activeChannel, diff --git a/desktop/src/features/channels/useChannelSwitchTraceMarks.ts b/desktop/src/features/channels/useChannelSwitchTraceMarks.ts new file mode 100644 index 00000000000..bc49f6d2d6e --- /dev/null +++ b/desktop/src/features/channels/useChannelSwitchTraceMarks.ts @@ -0,0 +1,54 @@ +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 on the + * first render for the target channel; 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 { + React.useEffect(() => { + if (activeChannelId) markChannelSwitchRouteCommit(activeChannelId); + }, [activeChannelId]); + // Route-exit cancellation: leaving the channel surface before the trace + // settles (Projects, Home, … — none of which call goChannel) must drop the + // trace. Otherwise a history-back into the same channel within the trace + // timeout matches the stale singleton and records the time spent away as + // switch latency. Keyed per channel id: on an A→B switch this cleanup runs + // with A's id after B's trace already began, so it only ever abandons its + // own channel's trace. + React.useEffect(() => { + if (!activeChannelId) return; + const channelId = activeChannelId; + return () => { + abandonChannelSwitchTrace(channelId); + }; + }, [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/communities/useCommunityInit.ts b/desktop/src/features/communities/useCommunityInit.ts index 5493a47b1e3..41555366399 100644 --- a/desktop/src/features/communities/useCommunityInit.ts +++ b/desktop/src/features/communities/useCommunityInit.ts @@ -34,6 +34,7 @@ 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"; @@ -57,6 +58,10 @@ 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 8b457a7adf8..76b6d5436a7 100644 --- a/desktop/src/features/messages/hooks.ts +++ b/desktop/src/features/messages/hooks.ts @@ -38,6 +38,7 @@ 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"; @@ -271,14 +272,27 @@ export function useChannelMessagesQuery(channel: Channel | null) { if (!channel) throw new Error("No channel selected."); const previousMessages = queryClient.getQueryData(queryKey) ?? []; + const fetchStartedAt = performance.now(); const events = await getChannelWindowEvents(channel.id); - return reconcileFetchedChannelWindow( + const fetchDurationMs = performance.now() - fetchStartedAt; + const result = reconcileFetchedChannelWindow( queryClient, channel.id, events, previousMessages, signal, ); + // Attribute only ACCEPTED fetches: reconciliation throws for aborted + // requests, and a canceled fetch that claimed the trace's one-shot + // attribution slot would block the accepted replacement from being + // recorded. Duration still measures the fetch alone, captured above. + traceChannelWindowFetch( + channel.id, + events.length, + fetchDurationMs, + fetchStartedAt, + ); + return result; }, 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 14ec110addf..4e5c2a01ae8 100644 --- a/desktop/src/features/messages/lib/projectChannelWindow.test.mjs +++ b/desktop/src/features/messages/lib/projectChannelWindow.test.mjs @@ -363,3 +363,85 @@ test("test_pageless_live_projection_preserves_cached_timeline", () => { assert.deepEqual(contents(harness), ["initial", "live"]); assert.equal(harness.client.getQueryData(harness.messagesKey)[0], cached[0]); }); + +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 = { querySelector: () => null }; + 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(); + assert.throws(() => { + reconcileFetchedChannelWindow( + client, + channelId, + canceledEvents, + [], + canceled.signal, + ); + traceChannelWindowFetch(channelId, canceledEvents.length, 1, startedAt); + }); + + // Accepted-second: reconciles cleanly, then claims the slot. + const acceptedEvents = wirePage([ + event("fresh-2", 120), + event("fresh-1", 110), + ]); + reconcileFetchedChannelWindow( + client, + channelId, + acceptedEvents, + [], + new AbortController().signal, + ); + traceChannelWindowFetch( + channelId, + acceptedEvents.length, + 2, + 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/features/messages/ui/MessageTimeline.tsx b/desktop/src/features/messages/ui/MessageTimeline.tsx index df9af09e674..27eeb0762c2 100644 --- a/desktop/src/features/messages/ui/MessageTimeline.tsx +++ b/desktop/src/features/messages/ui/MessageTimeline.tsx @@ -693,7 +693,15 @@ const MessageTimelineBase = React.forwardRef< return ( -
+ {/* The render-pending marker must live on this always-mounted wrapper: + during the skeleton→loaded transition the message-list branches (and + their own markers) are not mounted yet, and the switch tracer would + read "not pending" and record a settle before the heavy deferred + list ever committed or painted. */} +
{showUnreadPill ? (
{useTimelineVirtualizer && timelineList ? ( -
- {timelineList} -
+
{timelineList}
) : (
{timelineList}
diff --git a/desktop/src/shared/lib/channelSwitchPerf.test.mjs b/desktop/src/shared/lib/channelSwitchPerf.test.mjs new file mode 100644 index 00000000000..586ae70a324 --- /dev/null +++ b/desktop/src/shared/lib/channelSwitchPerf.test.mjs @@ -0,0 +1,216 @@ +import assert from "node:assert/strict"; +import test from "node:test"; + +import { + shouldAttributeFetch, + buildSwitchPerfLogRecord, + resolveSettleAction, + summarizeChannelSwitchTrace, +} from "./channelSwitchPerf.ts"; + +function trace(overrides = {}) { + return { + channelId: "abcdef1234567890", + startedAt: 1_000, + routeCommitAt: null, + windowFetch: null, + membersFetch: null, + ...overrides, + }; +} + +test("summary reports total and cache-served fetches", () => { + const summary = summarizeChannelSwitchTrace(trace(), 1_412.4); + assert.equal( + summary, + "[switch-perf] channel=abcdef12 total=412ms commit=? window=cache members=cache", + ); +}); + +test("summary includes route commit offset and fetch timings", () => { + const summary = summarizeChannelSwitchTrace( + trace({ + routeCommitAt: 1_038, + windowFetch: { durationMs: 180.6, eventCount: 250 }, + membersFetch: { durationMs: 320.2, memberCount: 10_000 }, + }), + 1_912, + ); + assert.equal( + summary, + "[switch-perf] channel=abcdef12 total=912ms commit=+38ms " + + "window=250 events in 181ms members=10000 members in 320ms", + ); +}); + +test("log record carries rounded stage timings and fetch attributions", () => { + const record = buildSwitchPerfLogRecord( + trace({ + routeCommitAt: 1_038.4, + windowFetch: { durationMs: 180.6, eventCount: 250 }, + membersFetch: { durationMs: 320.2, memberCount: 10_000 }, + }), + 1_912.3, + ); + assert.equal(record.channelId, "abcdef1234567890"); + assert.equal(record.totalMs, 912); + assert.equal(record.commitOffsetMs, 38); + assert.deepEqual(record.windowFetch, { durationMs: 181, eventCount: 250 }); + assert.deepEqual(record.membersFetch, { + durationMs: 320, + memberCount: 10_000, + }); + assert.equal(typeof record.ts, "string"); +}); + +test("log record marks cache-served fetches and missing commit as null", () => { + const record = buildSwitchPerfLogRecord(trace(), 1_412); + assert.equal(record.commitOffsetMs, null); + assert.equal(record.windowFetch, null); + assert.equal(record.membersFetch, null); +}); + +test("settle resolves only the trace for the settled channel", () => { + const active = trace(); + assert.deepEqual(resolveSettleAction(active, "abcdef1234567890", 2_000), { + settledTrace: active, + clearActive: true, + }); + assert.deepEqual(resolveSettleAction(null, "abcdef1234567890", 2_000), { + settledTrace: null, + clearActive: false, + }); +}); + +test("a mismatched settle never clobbers a newer switch's trace", () => { + // Channel A settles after the user already clicked channel B: B's trace + // must survive so B still gets measured. + const nextSwitch = trace({ channelId: "bbbb0000bbbb0000" }); + assert.deepEqual(resolveSettleAction(nextSwitch, "abcdef1234567890", 2_000), { + settledTrace: null, + clearActive: false, + }); +}); + +test("settle drops a trace that has timed out", () => { + const stale = trace({ startedAt: 1_000 }); + assert.deepEqual(resolveSettleAction(stale, "abcdef1234567890", 31_001), { + settledTrace: null, + clearActive: true, + }); + assert.deepEqual( + resolveSettleAction(stale, "abcdef1234567890", 11_000).settledTrace, + stale, + ); +}); + +test("fetches attribute only when started after the switch began", () => { + const active = trace({ channelId: "abcdef1234567890", startedAt: 1_000 }); + // Started before the switch (stale A→B→A leg): not attributable. + assert.equal(shouldAttributeFetch(active, "abcdef1234567890", 999), false); + // Started at/after the switch: attributable. + assert.equal(shouldAttributeFetch(active, "abcdef1234567890", 1_000), true); + assert.equal(shouldAttributeFetch(active, "abcdef1234567890", 1_500), true); + // Other channel or no trace: never. + assert.equal(shouldAttributeFetch(active, "bbbb0000bbbb0000", 1_500), false); + assert.equal(shouldAttributeFetch(null, "abcdef1234567890", 1_500), false); +}); + +// --- Settle lifecycle: rapid switches and community resets ---------------- + +async function withSettleHarness(run) { + const frames = []; + const originalWindow = globalThis.window; + const originalDocument = globalThis.document; + globalThis.window = { + requestAnimationFrame: (cb) => frames.push(cb) && frames.length, + cancelAnimationFrame: () => {}, + }; + globalThis.document = { querySelector: () => null }; + const { + abandonChannelSwitchTrace, + beginChannelSwitchTrace, + settleChannelSwitchTrace, + resetChannelSwitchTrace, + CHANNEL_SWITCH_MEASURE, + } = await import("./channelSwitchPerf.ts"); + performance.clearMeasures?.(CHANNEL_SWITCH_MEASURE); + const flush = () => { + // 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(); + } + }; + const measures = () => + performance + .getEntriesByName(CHANNEL_SWITCH_MEASURE) + .map((entry) => entry.detail?.channelId); + try { + await run({ + abandon: abandonChannelSwitchTrace, + begin: beginChannelSwitchTrace, + settle: settleChannelSwitchTrace, + reset: resetChannelSwitchTrace, + 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 switch begun during A's deferred wait drops A's record (no clock theft)", async () => { + await withSettleHarness(async ({ begin, settle, flush, measures }) => { + begin("aaaa1111aaaa1111"); + settle("aaaa1111aaaa1111"); // A's deferred-paint wait is now queued + begin("bbbb2222bbbb2222"); // rapid follow-up switch replaces the trace + flush(); + // A must NOT be recorded: its settledAt would be sampled from B's + // timeline, charging B's delay to A. + assert.deepEqual(measures(), []); + settle("bbbb2222bbbb2222"); + flush(); + assert.deepEqual(measures(), ["bbbb2222bbbb2222"]); + }); +}); + +test("a community reset during the deferred wait drops the record", async () => { + await withSettleHarness(async ({ begin, settle, reset, flush, measures }) => { + begin("aaaa1111aaaa1111"); + settle("aaaa1111aaaa1111"); + reset(); + flush(); + assert.deepEqual(measures(), []); + }); +}); + +test("an undisturbed settle records exactly one measure", async () => { + await withSettleHarness(async ({ begin, settle, flush, measures }) => { + begin("aaaa1111aaaa1111"); + settle("aaaa1111aaaa1111"); + flush(); + assert.deepEqual(measures(), ["aaaa1111aaaa1111"]); + }); +}); + +test("leaving the channel surface abandons the trace; history-back records nothing", async () => { + await withSettleHarness( + async ({ abandon, begin, settle, flush, measures }) => { + begin("aaaa1111aaaa1111"); + // Route exit (Projects/Home): the channel screen unmounts before the + // trace settled and abandons it. + abandon("aaaa1111aaaa1111"); + // History-back re-enters the channel without goChannel; its settle must + // find no trace — otherwise the time spent away would be recorded as + // switch latency. + settle("aaaa1111aaaa1111"); + flush(); + assert.deepEqual(measures(), []); + }, + ); +}); diff --git a/desktop/src/shared/lib/channelSwitchPerf.ts b/desktop/src/shared/lib/channelSwitchPerf.ts new file mode 100644 index 00000000000..015537179a0 --- /dev/null +++ b/desktop/src/shared/lib/channelSwitchPerf.ts @@ -0,0 +1,297 @@ +/** + * Channel-switch tracing: measures click → settled-paint for channel + * navigations, with the two relay fetches that can sit on that path + * (message window, member roster) attributed to the switch. + * + * One trace is active at a time; `beginChannelSwitchTrace` (called from + * `goChannel`) opens it and `settleChannelSwitchTrace` (called when the + * timeline settles for that channel) closes it after the next paint. Fetch + * traces and settles for non-active channels are ignored, so background + * refetches never pollute a switch measurement. + * + * Output per switch: a `[switch-perf]` console line plus User Timing + * marks/measures (`buzz:channel-switch:*`) so Playwright perf specs and the + * Performance panel can read the same numbers. + * + * Attribution window: fetches are credited to a switch only when they finish + * before the settled paint. A roster fetch that completes after settle is + * deliberately not part of the felt switch latency, so such switches report + * `members=cache` — by design, not omission. + */ + +export type ChannelSwitchFetchTrace = { + durationMs: number; + eventCount?: number; + memberCount?: number; +}; + +import { invoke, isTauri } from "@tauri-apps/api/core"; + +export type ChannelSwitchTrace = { + channelId: string; + startedAt: number; + routeCommitAt: number | null; + windowFetch: { durationMs: number; eventCount: number } | null; + membersFetch: { durationMs: number; memberCount: number } | null; +}; + +/** A switch that hasn't settled after this long is abandoned, not measured. */ +const SWITCH_TRACE_TIMEOUT_MS = 30_000; + +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"; + +let activeTrace: ChannelSwitchTrace | null = null; + +/** Formats one settled trace as the `[switch-perf]` console line. */ +export function summarizeChannelSwitchTrace( + trace: ChannelSwitchTrace, + settledAt: number, +): 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`; + const members = + trace.membersFetch === null + ? "cache" + : `${trace.membersFetch.memberCount} members in ${Math.round(trace.membersFetch.durationMs)}ms`; + return ( + `[switch-perf] channel=${trace.channelId.slice(0, 8)} total=${total}ms ` + + `commit=${commit} window=${window} members=${members}` + ); +} + +/** + * The JSONL record persisted per settled switch. The backend folds in the + * build's git revision and the optional BUZZ_PERF_LOG_LABEL run label, so + * before/after sessions are attributable offline. Pure for unit testing. + */ +export function buildSwitchPerfLogRecord( + trace: ChannelSwitchTrace, + settledAt: number, +): { + ts: string; + channelId: string; + totalMs: number; + commitOffsetMs: number | null; + windowFetch: { durationMs: number; eventCount: number } | null; + membersFetch: { durationMs: number; memberCount: number } | null; +} { + return { + ts: new Date().toISOString(), + channelId: trace.channelId, + totalMs: Math.round(settledAt - trace.startedAt), + commitOffsetMs: + trace.routeCommitAt === null + ? null + : Math.round(trace.routeCommitAt - trace.startedAt), + windowFetch: trace.windowFetch + ? { + durationMs: Math.round(trace.windowFetch.durationMs), + eventCount: trace.windowFetch.eventCount, + } + : null, + membersFetch: trace.membersFetch + ? { + durationMs: Math.round(trace.membersFetch.durationMs), + memberCount: trace.membersFetch.memberCount, + } + : null, + }; +} + +let hasAnnouncedLogPath = false; + +/** Fire-and-forget JSONL append; diagnostics must never surface failures. */ +function appendSwitchPerfLogRecord(record: Record): void { + if (!isTauri()) return; + void invoke("append_switch_perf_log", { + recordJson: JSON.stringify(record), + }) + .then((path) => { + if (!hasAnnouncedLogPath) { + hasAnnouncedLogPath = true; + console.info(`[switch-perf] logging to ${path}`); + } + }) + .catch(() => {}); +} + +/** + * 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 already began, and clobbering the + * newer trace would silently drop exactly the slow/rapid switches this + * instrumentation exists to capture. Only the settled channel's own trace is + * consumed (measured, or dropped when timed out). Pure so the attribution + * rules are unit-testable. + */ +export function resolveSettleAction( + trace: ChannelSwitchTrace | null, + channelId: string, + now: number, +): { settledTrace: ChannelSwitchTrace | null; clearActive: boolean } { + if (!trace || trace.channelId !== channelId) { + return { settledTrace: null, clearActive: false }; + } + if (now - trace.startedAt > SWITCH_TRACE_TIMEOUT_MS) { + return { settledTrace: null, clearActive: true }; + } + return { settledTrace: trace, clearActive: true }; +} + +/** + * Drops the active trace for surfaces whose readiness this instrument cannot + * observe (e.g. forum channels, whose loading is owned by ForumView's own + * queries). Better no measurement than a systematically underreported one. + */ +export function abandonChannelSwitchTrace(channelId: string): void { + if (activeTrace?.channelId === channelId) { + activeTrace = null; + } +} + +export function beginChannelSwitchTrace(channelId: string): void { + if (typeof performance === "undefined") return; + activeTrace = { + channelId, + startedAt: performance.now(), + routeCommitAt: null, + windowFetch: null, + membersFetch: null, + }; + performance.mark(CHANNEL_SWITCH_START_MARK, { detail: { channelId } }); +} + +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 after the switch began. A fetch that started before + * the switch (e.g. the first leg of a rapid A→B→A completing during the + * second A trace) is not this switch's cost; letting it claim the `??=` + * slot would also block the real fetch. Pure for unit testing. + */ +export function shouldAttributeFetch( + trace: ChannelSwitchTrace | null, + channelId: string, + fetchStartedAt: number, +): trace is ChannelSwitchTrace { + if (!trace || trace.channelId !== channelId) return false; + return fetchStartedAt >= trace.startedAt; +} + +export function traceChannelWindowFetch( + channelId: string, + eventCount: number, + durationMs: number, + fetchStartedAt: number, +): void { + if (!shouldAttributeFetch(activeTrace, channelId, fetchStartedAt)) return; + activeTrace.windowFetch ??= { durationMs, eventCount }; +} + +export function traceChannelMembersFetch( + channelId: string, + memberCount: number, + durationMs: number, + fetchStartedAt: number, +): void { + if (!shouldAttributeFetch(activeTrace, channelId, fetchStartedAt)) return; + activeTrace.membersFetch ??= { durationMs, memberCount }; +} + +/** + * Drops any active trace. Community switches remount the app shell but this + * module-level singleton survives; channel ids are community-scoped, so a + * stale trace could adopt the next community's fetches. Wired into + * resetCommunityState() like every community-scoped singleton. + */ +export function resetChannelSwitchTrace(): void { + activeTrace = null; +} + +/** Bound on waiting for the deferred timeline commit before recording. */ +const SETTLE_RENDER_WAIT_MS = 5_000; + +/** + * Closes the active trace once the settled frame has painted. The timeline + * renders rows through a deferred snapshot that exposes + * `data-render-pending` until the low-priority commit catches up — waiting + * for it (bounded) keeps `totalMs` honest on render-heavy switches; a final + * rAF pair then lands the mark after the browser paints. + */ +export function settleChannelSwitchTrace(channelId: string): void { + if (typeof performance === "undefined") return; + const { settledTrace, clearActive } = resolveSettleAction( + activeTrace, + channelId, + performance.now(), + ); + if (!settledTrace) { + if (clearActive) activeTrace = null; + return; + } + const trace = settledTrace; + if (typeof window === "undefined") { + activeTrace = null; + return; + } + // Keep the trace active through the deferred-commit wait so fetches that + // finish inside the measured window still attribute to it. It is released + // when the record lands; a newer switch's begin() simply replaces it. + const waitDeadline = performance.now() + SETTLE_RENDER_WAIT_MS; + const record = () => { + const settledAt = performance.now(); + if (activeTrace === trace) activeTrace = null; + performance.mark(CHANNEL_SWITCH_SETTLED_MARK, { + detail: { channelId }, + }); + performance.measure(CHANNEL_SWITCH_MEASURE, { + detail: { + channelId, + routeCommitAt: trace.routeCommitAt, + windowFetch: trace.windowFetch, + membersFetch: trace.membersFetch, + }, + start: trace.startedAt, + end: settledAt, + }); + console.info(summarizeChannelSwitchTrace(trace, settledAt)); + appendSwitchPerfLogRecord(buildSwitchPerfLogRecord(trace, settledAt)); + }; + const awaitDeferredCommit = () => { + if (activeTrace !== trace) { + // A newer switch replaced this trace, or a community reset dropped it. + // Either way the paint this callback would sample is not this switch's + // own — recording would charge the replacement's delay to the settled + // channel and could manufacture the very regression the tracer exists + // to diagnose. Better no measurement than a fabricated one. + return; + } + if ( + performance.now() < waitDeadline && + document.querySelector('[data-render-pending="true"]') !== null + ) { + window.requestAnimationFrame(awaitDeferredCommit); + return; + } + window.requestAnimationFrame(() => { + if (activeTrace !== trace) return; + record(); + }); + }; + window.requestAnimationFrame(awaitDeferredCommit); +} diff --git a/desktop/src/testing/e2eBridge.ts b/desktop/src/testing/e2eBridge.ts index e4028f01716..f0d0892ec7d 100644 --- a/desktop/src/testing/e2eBridge.ts +++ b/desktop/src/testing/e2eBridge.ts @@ -11981,6 +11981,9 @@ export function maybeInstallE2eTauriMocks() { }, activeConfig, ); + case "append_switch_perf_log": + // Perf-trace JSONL sink — a real file makes no sense in mock runs. + return "/mock/switch-perf.jsonl"; case "get_os_idle_seconds": // e2e runs headless with no OS idle API; the presence hook falls back // to in-app activity tracking. diff --git a/desktop/tests/e2e/switch-settle-after-paint.spec.ts b/desktop/tests/e2e/switch-settle-after-paint.spec.ts new file mode 100644 index 00000000000..ce8e223df65 --- /dev/null +++ b/desktop/tests/e2e/switch-settle-after-paint.spec.ts @@ -0,0 +1,58 @@ +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. + const atSettle = await page.evaluate(async (measureName) => { + const deadline = Date.now() + 15_000; + while (Date.now() < deadline) { + if (performance.getEntriesByName(measureName).length > 0) { + return { + renderPending: + document.querySelector('[data-render-pending="true"]') !== null, + rowCount: document.querySelectorAll( + '[data-message-id^="mock-deep-history-"]', + ).length, + settled: true, + }; + } + await new Promise((resolve) => setTimeout(resolve, 16)); + } + return { renderPending: true, rowCount: 0, settled: false }; + }, SWITCH_MEASURE); + + 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); +}); From 2a4d128a40b41c804f3c13966e60a08c4f0a8cad Mon Sep 17 00:00:00 2001 From: Max Lampert Date: Thu, 20 Aug 2026 13:59:09 -0700 Subject: [PATCH 2/3] test(desktop): high-membership channel-switch perf harness MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Add an inflateChannelMembers mock-bridge knob (channel name → target member count; synthetic hex-pubkey members appended once, on first channel read) and a member-heavy-switch perf spec that measures warm switch wall time and longtasks for channel↔channel and channel↔Projects at baseline / 2k / 10k members per channel, holding message volume constant at 150 rows. Method mirrors warm-switch-markdown.perf.ts: in-page click + rAF polling, 4x CPU throttle, medians over 16 switches after an untimed warmup round-trip. Run from desktop/: pnpm build:e2e npx playwright test --config=playwright.perf.config.ts member-heavy-switch.perf.ts Signed-off-by: Max Lampert --- desktop/src/testing/e2eBridge.ts | 32 ++ desktop/tests/e2e/member-heavy-switch.perf.ts | 290 ++++++++++++++++++ desktop/tests/helpers/bridge.ts | 2 + 3 files changed, 324 insertions(+) create mode 100644 desktop/tests/e2e/member-heavy-switch.perf.ts diff --git a/desktop/src/testing/e2eBridge.ts b/desktop/src/testing/e2eBridge.ts index f0d0892ec7d..2452b1ce12b 100644 --- a/desktop/src/testing/e2eBridge.ts +++ b/desktop/src/testing/e2eBridge.ts @@ -341,6 +341,10 @@ type E2eConfig = { honorChannelsKnownHash?: boolean; /** Number of seeded rows in the deep-history fixture. Defaults to 600. */ deepHistoryMessageCount?: number; + /** Channel name → target member count. Appends synthetic members until + * each named channel reaches its target; perf specs use this to model + * high-membership channels. Applied once, on first channel read. */ + inflateChannelMembers?: Record; feedReadError?: string; canvasReadError?: string; /** Delay (ms) for `apply_workspace` so e2e tests can observe the @@ -2611,11 +2615,39 @@ function listMockProfiles(): RawProfile[] { .filter((profile): profile is RawProfile => profile !== null); } +let memberInflationApplied = false; + +/** + * One-shot high-membership inflation for perf specs. Reads + * `mock.inflateChannelMembers` (channel name → target member count) and + * appends synthetic hex-pubkey members until each named channel reaches its + * target. Runs lazily on the first channel read so it sees the final config. + */ +function ensureInflatedChannelMembers(): void { + if (memberInflationApplied) return; + const inflation = getConfig()?.mock?.inflateChannelMembers; + if (!inflation) return; + memberInflationApplied = true; + for (const [name, targetCount] of Object.entries(inflation)) { + const channel = mockChannels.find((candidate) => candidate.name === name); + if (!channel) continue; + for (let index = channel.members.length; index < targetCount; index += 1) { + // "ab" prefix + zero-padded hex index: unique, hex-valid, and disjoint + // from every fixture pubkey. + const pubkey = `ab${index.toString(16).padStart(62, "0")}`; + channel.members.push(createMockMember(pubkey, "member", 500)); + } + syncMockChannel(channel); + } +} + function listMockChannels(config?: E2eConfig): RawChannelWithMembership[] { + ensureInflatedChannelMembers(); return mockChannels.map((channel) => toRawChannel(channel, config)); } function getMockChannel(channelId: string): MockChannel { + ensureInflatedChannelMembers(); const channel = mockChannels.find((candidate) => candidate.id === channelId); if (!channel) { throw new Error(`Channel ${channelId} not found.`); diff --git a/desktop/tests/e2e/member-heavy-switch.perf.ts b/desktop/tests/e2e/member-heavy-switch.perf.ts new file mode 100644 index 00000000000..a12720b2638 --- /dev/null +++ b/desktop/tests/e2e/member-heavy-switch.perf.ts @@ -0,0 +1,290 @@ +import { expect, test } from "@playwright/test"; + +import { installMockBridge } from "../helpers/bridge"; + +/** + * High-membership channel-switch benchmark. + * + * Isolates how channel MEMBERSHIP SIZE scales the warm-switch cost, holding + * message volume constant. Every channel object embeds its full + * member-pubkey array, so membership size inflates (a) the get_channels + * payload parsed on every poll, (b) the per-switch get_channel_members + * response, and (c) every render-path pass over `channel.memberPubkeys` and + * the member list (profile merges, agent-flag merges, mention candidates). + * This spec is the instrument for that scaling: same channels, same rows, + * member count is the only variable. + * + * Two scenarios per member count: + * channel<->channel — general <-> deep-history (150 fixed rows). + * channel<->projects — general <-> the Projects overview (preview + * feature). Projects mounts its own query fan + * (project enumeration, work items, repo snapshots, + * activity summaries) on top of the shell, so this + * axis captures the cross-surface switch the felt + * 1-2s report singled out. + * + * Method mirrors warm-switch-markdown.perf.ts: in-page click + rAF polling + * (CDP latency never pollutes samples), longtask capture per switch, 4x CPU + * throttle, medians over repeated switches, untimed warmup round-trip first. + * `deep-history` is pinned to 150 rows so the message-mount cost is fixed + * and comparable across member counts. + * + * Run it (from desktop/): + * pnpm build:e2e + * npx playwright test --config=playwright.perf.config.ts member-heavy-switch.perf.ts + * + * Compare the MEDIAN wall ms / longtask lines across the member-count + * scenarios; a superlinear jump is membership-scaling cost on the switch + * path. + */ + +const MEASURED_SWITCHES = 8; +const THROTTLE_RATE = 4; +const DEEP_HISTORY_ROWS = 150; +const MEMBER_COUNTS = [0, 2_000, 10_000] as const; + +type SwitchSample = { + ms: number; + longtaskTotal: number; + longtaskMax: number; + longtaskCount: number; +}; + +function median(values: number[]): number { + const sorted = [...values].sort((a, b) => a - b); + const mid = Math.floor(sorted.length / 2); + return sorted.length % 2 === 0 + ? (sorted[mid - 1] + sorted[mid]) / 2 + : sorted[mid]; +} + +/** Click the sidebar link and poll — all in-page — until the target channel's + * rows are committed, the deferred snapshot has caught up, and a frame + * painted. Returns wall-clock ms plus the longtasks observed in the window. */ +async function measureSwitch( + page: import("@playwright/test").Page, + input: { + targetTestId: string; + /** When set, chat-title must equal this before the switch counts. */ + targetTitle: string | null; + /** Selector that must be present before the switch counts. */ + readySelector: string; + }, +): Promise { + return page.evaluate(async (args) => { + const store = window as unknown as { __LONGTASKS__: number[] }; + store.__LONGTASKS__ = []; + const link = document.querySelector( + `[data-testid="${args.targetTestId}"]`, + ); + if (!link) throw new Error(`missing sidebar link ${args.targetTestId}`); + + const start = performance.now(); + link.click(); + + await new Promise((resolve, reject) => { + const deadline = start + 30_000; + const check = () => { + const titleReady = + args.targetTitle === null || + document.querySelector('[data-testid="chat-title"]')?.textContent === + args.targetTitle; + const ready = + titleReady && + document.querySelector(args.readySelector) !== null && + document.querySelector('[data-render-pending="true"]') === null; + if (ready) { + requestAnimationFrame(() => requestAnimationFrame(() => resolve())); + return; + } + if (performance.now() > deadline) { + reject(new Error(`switch to ${args.targetTitle} timed out`)); + return; + } + requestAnimationFrame(check); + }; + requestAnimationFrame(check); + }); + + const elapsed = performance.now() - start; + const tasks = store.__LONGTASKS__ ?? []; + return { + ms: elapsed, + longtaskTotal: tasks.reduce((sum, duration) => sum + duration, 0), + longtaskMax: tasks.length ? Math.max(...tasks) : 0, + longtaskCount: tasks.length, + }; + }, input); +} + +type SwitchTarget = { + targetTestId: string; + targetTitle: string | null; + readySelector: string; +}; + +const GENERAL_TARGET: SwitchTarget = { + targetTestId: "channel-general", + targetTitle: "general", + readySelector: "[data-message-id]", +}; + +const DEEP_HISTORY_TARGET: SwitchTarget = { + targetTestId: "channel-deep-history", + targetTitle: "deep-history", + readySelector: '[data-message-id^="mock-deep-history-"]', +}; + +const PROJECTS_TARGET: SwitchTarget = { + targetTestId: "open-projects-view", + targetTitle: null, + // Rendered by every Projects view mode (Activity intro or section header). + readySelector: '[data-testid="projects-page-header"]', +}; + +async function runScenario( + page: import("@playwright/test").Page, + label: string, + target: SwitchTarget, + back: SwitchTarget, +): Promise { + // Untimed warmup round-trip: caches both surfaces' queries and jits the + // switch code paths. + await measureSwitch(page, target); + await measureSwitch(page, back); + + const samples: SwitchSample[] = []; + for (let run = 0; run < MEASURED_SWITCHES; run += 1) { + samples.push(await measureSwitch(page, target)); + samples.push(await measureSwitch(page, back)); + } + + const times = samples.map((sample) => sample.ms); + const longtaskTotals = samples.map((sample) => sample.longtaskTotal); + /* eslint-disable no-console */ + console.log(`\n=== MEMBER-HEAVY WARM SWITCH: ${label} ===`); + console.log(`CPU throttle: ${THROTTLE_RATE}x`); + console.log( + `per-switch wall ms: [${times.map((v) => v.toFixed(1)).join(", ")}]`, + ); + console.log( + `per-switch longtask ms: [${longtaskTotals.map((v) => v.toFixed(1)).join(", ")}]`, + ); + console.log(`MEDIAN wall ms: ${median(times).toFixed(1)}`); + console.log( + `MEDIAN longtask total: ${median(longtaskTotals).toFixed(1)}ms`, + ); + console.log( + `worst single longtask: ${Math.max(...samples.map((sample) => sample.longtaskMax)).toFixed(1)}ms`, + ); + /* eslint-enable no-console */ + return samples; +} + +for (const memberCount of MEMBER_COUNTS) { + const label = + memberCount === 0 + ? "baseline fixture membership" + : `${memberCount.toLocaleString("en-US")} members per channel`; + + test(`MEASURE: warm switch general<->deep-history and general<->projects with ${label}`, async ({ + page, + }) => { + test.setTimeout(300_000); + // Projects is a preview feature; seed the override BEFORE the bridge + // installs so the shell mounts with it enabled. + await page.addInitScript(() => { + window.localStorage.setItem( + "buzz-feature-overrides-v1", + JSON.stringify({ projects: true }), + ); + }); + await installMockBridge(page, { + deepHistoryMessageCount: DEEP_HISTORY_ROWS, + ...(memberCount > 0 + ? { + inflateChannelMembers: { + general: memberCount, + "deep-history": memberCount, + }, + } + : {}), + }); + await page.goto("/"); + await page.waitForFunction( + () => typeof window.__BUZZ_E2E_EMIT_MOCK_MESSAGE__ === "function", + ); + + // Arm the longtask observer; addInitScript applies on next navigation. + await page.addInitScript(() => { + const store = window as unknown as { __LONGTASKS__?: number[] }; + store.__LONGTASKS__ = []; + new PerformanceObserver((list) => { + for (const entry of list.getEntries()) { + store.__LONGTASKS__?.push(entry.duration); + } + }).observe({ type: "longtask", buffered: true }); + }); + await page.reload(); + await page.waitForFunction( + () => + typeof window.__BUZZ_E2E_EMIT_MOCK_MESSAGE__ === "function" && + Array.isArray( + (window as unknown as { __LONGTASKS__?: number[] }).__LONGTASKS__, + ), + ); + + // Verify the inflation actually landed before measuring anything. + if (memberCount > 0) { + await expect + .poll(() => + page.evaluate(async () => { + const invoke = ( + window as unknown as { + __TAURI_INTERNALS__: { + invoke: ( + cmd: string, + args: unknown, + ) => Promise<{ members: unknown[] }>; + }; + } + ).__TAURI_INTERNALS__.invoke; + const response = await invoke("get_channel_members", { + channelId: "feedf00d-0000-4000-8000-000000000007", + }); + return response.members.length; + }), + ) + .toBeGreaterThanOrEqual(memberCount); + } + + await page.getByTestId("channel-general").click(); + await expect(page.getByTestId("chat-title")).toHaveText("general"); + + const client = await page.context().newCDPSession(page); + await client.send("Emulation.setCPUThrottlingRate", { + rate: THROTTLE_RATE, + }); + + const channelSamples = await runScenario( + page, + `channel<->channel, ${label}`, + DEEP_HISTORY_TARGET, + GENERAL_TARGET, + ); + const projectsSamples = await runScenario( + page, + `channel<->projects, ${label}`, + PROJECTS_TARGET, + GENERAL_TARGET, + ); + + await client.send("Emulation.setCPUThrottlingRate", { rate: 1 }); + + // Instrument, not a gate: assert the harness measured real work. + expect(channelSamples.length).toBe(MEASURED_SWITCHES * 2); + expect(channelSamples.every((sample) => sample.ms > 0)).toBe(true); + expect(projectsSamples.length).toBe(MEASURED_SWITCHES * 2); + expect(projectsSamples.every((sample) => sample.ms > 0)).toBe(true); + }); +} diff --git a/desktop/tests/helpers/bridge.ts b/desktop/tests/helpers/bridge.ts index ed94e6b1767..eab3b855d7f 100644 --- a/desktop/tests/helpers/bridge.ts +++ b/desktop/tests/helpers/bridge.ts @@ -277,6 +277,8 @@ type MockBridgeOptions = { honorChannelsKnownHash?: boolean; /** Number of seeded rows in the deep-history fixture. Defaults to 600. */ deepHistoryMessageCount?: number; + /** Channel name → target member count for high-membership perf specs. */ + inflateChannelMembers?: Record; feedReadError?: string; canvasReadError?: string; /** Delay (ms) for `apply_workspace`; see e2eBridge mock config. */ From d6aa87641160f60eb191490ef1fbb232fa404ff5 Mon Sep 17 00:00:00 2001 From: Max Lampert Date: Thu, 20 Aug 2026 17:52:04 -0700 Subject: [PATCH 3/3] perf(desktop): prefetch the channel window on sidebar hover intent A deliberate hover on a sidebar channel row (100ms dwell, so pointer scrubbing never fires) warms that channel's message window, making the subsequent click a cache hit instead of paying the relay fetch on the switch path. The window query options move into a shared factory so the prefetched entry is byte-identical to what the mounted query reads; the prefetch respects the window's staleTime, so hovering a fresh channel never refetches. The mock bridge gains a head-fetch probe (cursorless window reads) so the regression spec can assert dwell-fetches-once / scrub-fetches-never. Signed-off-by: Max Lampert --- desktop/playwright.config.ts | 1 + desktop/src/features/messages/hooks.ts | 53 +++++++++++-- .../lib/projectChannelWindow.test.mjs | 39 ++++++++++ .../messages/lib/projectChannelWindow.ts | 10 +++ .../features/sidebar/ui/SidebarSection.tsx | 13 ++++ .../src/shared/hooks/useHoverIntent.test.mjs | 59 ++++++++++++++ desktop/src/shared/hooks/useHoverIntent.ts | 68 ++++++++++++++++ desktop/src/testing/e2eBridge.ts | 15 +++- .../tests/e2e/sidebar-hover-prefetch.spec.ts | 78 +++++++++++++++++++ 9 files changed, 327 insertions(+), 9 deletions(-) create mode 100644 desktop/src/shared/hooks/useHoverIntent.test.mjs create mode 100644 desktop/src/shared/hooks/useHoverIntent.ts create mode 100644 desktop/tests/e2e/sidebar-hover-prefetch.spec.ts diff --git a/desktop/playwright.config.ts b/desktop/playwright.config.ts index 86108bf6e50..e2b05e2433b 100644 --- a/desktop/playwright.config.ts +++ b/desktop/playwright.config.ts @@ -106,6 +106,7 @@ export default defineConfig({ "**/cold-switch-longtask.perf.ts", "**/switch-settle-after-paint.spec.ts", "**/timeline-no-shift.spec.ts", + "**/sidebar-hover-prefetch.spec.ts", "**/human-edit-agent-content.spec.ts", "**/empty-edit-delete.spec.ts", "**/reaction-order.spec.ts", diff --git a/desktop/src/features/messages/hooks.ts b/desktop/src/features/messages/hooks.ts index 76b6d5436a7..48b83b27d83 100644 --- a/desktop/src/features/messages/hooks.ts +++ b/desktop/src/features/messages/hooks.ts @@ -261,14 +261,26 @@ export function reconcileFetchedChannelWindow( return reconcileChannelWindowMessages(next, previousMessages); } -export function useChannelMessagesQuery(channel: Channel | null) { - const queryClient = useQueryClient(); - const queryKey = channelMessagesKey(channel?.id ?? "none"); +export const CHANNEL_MESSAGES_STALE_TIME_MS = 5 * 60 * 1_000; +// Window-guarded like react-query's own server default (Infinity): an +// explicit finite gcTime schedules a real, non-unref'd timeout per cache +// entry, which keeps node test processes alive for the full hour. +export const CHANNEL_MESSAGES_GC_TIME_MS = + typeof window === "undefined" ? Number.POSITIVE_INFINITY : 60 * 60 * 1_000; - return useQuery({ - enabled: channel !== null && channel.channelType !== "forum", +/** + * Shared query options for a channel's message window — the single source + * for `useChannelMessagesQuery` and the sidebar hover prefetch, so a + * prefetched entry is a byte-identical cache hit for the mounted query. + */ +export function channelMessagesQueryOptions( + queryClient: QueryClient, + channel: Channel | null, +) { + const queryKey = channelMessagesKey(channel?.id ?? "none"); + return { queryKey, - queryFn: async ({ signal }) => { + queryFn: async ({ signal }: { signal: AbortSignal }) => { if (!channel) throw new Error("No channel selected."); const previousMessages = queryClient.getQueryData(queryKey) ?? []; @@ -294,8 +306,33 @@ export function useChannelMessagesQuery(channel: Channel | null) { ); return result; }, - staleTime: 5 * 60 * 1_000, - gcTime: 60 * 60 * 1_000, + staleTime: CHANNEL_MESSAGES_STALE_TIME_MS, + gcTime: CHANNEL_MESSAGES_GC_TIME_MS, + }; +} + +/** + * Warms a channel's message window ahead of navigation (sidebar hover + * intent). Respects staleTime — a fresh window is a no-op — and dedupes with + * any in-flight fetch. Forums own their data elsewhere; huddle/forum-less + * gating matches useChannelMessagesQuery's enabled condition. + */ +export function prefetchChannelMessages( + queryClient: QueryClient, + channel: Channel, +): void { + if (channel.channelType === "forum") return; + void queryClient.prefetchQuery( + channelMessagesQueryOptions(queryClient, channel), + ); +} + +export function useChannelMessagesQuery(channel: Channel | null) { + const queryClient = useQueryClient(); + + return useQuery({ + enabled: channel !== null && channel.channelType !== "forum", + ...channelMessagesQueryOptions(queryClient, channel), }); } diff --git a/desktop/src/features/messages/lib/projectChannelWindow.test.mjs b/desktop/src/features/messages/lib/projectChannelWindow.test.mjs index 4e5c2a01ae8..e2b63a02150 100644 --- a/desktop/src/features/messages/lib/projectChannelWindow.test.mjs +++ b/desktop/src/features/messages/lib/projectChannelWindow.test.mjs @@ -445,3 +445,42 @@ test("canceled fetch never claims the switch trace's window slot; the accepted o else globalThis.document = originalDocument; } }); + +test("gap refresh refetches after an in-flight prefetch settles (no dedupe)", async () => { + const client = new QueryClient(); + const channelId = "chan-prefetch-race"; + const queryKey = channelMessagesKey(channelId); + let calls = 0; + let releaseFirst; + const firstGate = new Promise((resolve) => { + releaseFirst = resolve; + }); + const options = { + queryKey, + queryFn: async () => { + calls += 1; + const n = calls; + if (n === 1) await firstGate; + return [event(`fetch-${n}`, 100 + n)]; + }, + staleTime: 300_000, + }; + + // Hover prefetch in flight; a mounted observer dedupes into it. + const prefetch = client.prefetchQuery(options); + const observer = new QueryObserver(client, options); + const unsubscribe = observer.subscribe(() => {}); + + // Live subscription established: the gap refresh MUST NOT adopt the + // prefetched snapshot (fetched before the subscription started). + const refresh = refreshChannelWindowMessages(client, channelId); + await new Promise((resolve) => setTimeout(resolve, 20)); + releaseFirst(); + await Promise.allSettled([prefetch, refresh]); + await new Promise((resolve) => setTimeout(resolve, 50)); + + assert.equal(calls, 2, "gap refresh must issue a second fetch"); + assert.equal(client.getQueryData(queryKey)[0].content, "fetch-2"); + unsubscribe(); + client.clear(); +}); diff --git a/desktop/src/features/messages/lib/projectChannelWindow.ts b/desktop/src/features/messages/lib/projectChannelWindow.ts index 81ef3de42d0..9b48596d3f9 100644 --- a/desktop/src/features/messages/lib/projectChannelWindow.ts +++ b/desktop/src/features/messages/lib/projectChannelWindow.ts @@ -26,6 +26,16 @@ export async function refreshChannelWindowMessages( queryClient: QueryClient, channelId: string, ) { + // A hover prefetch may still be in flight when the live subscription + // establishes. TanStack dedupes into an in-flight initial fetch, so + // invalidating alone can adopt a snapshot fetched BEFORE the subscription + // started and drop any event that landed in between. Cancel the in-flight + // fetch first — matching the canceled-stale-fetch contract — so the + // invalidate below always issues a fetch that starts after this refresh. + await queryClient.cancelQueries({ + queryKey: channelMessagesKey(channelId), + exact: true, + }); await queryClient.invalidateQueries({ queryKey: channelMessagesKey(channelId), exact: true, diff --git a/desktop/src/features/sidebar/ui/SidebarSection.tsx b/desktop/src/features/sidebar/ui/SidebarSection.tsx index 1a6403fb24d..62fdefa5951 100644 --- a/desktop/src/features/sidebar/ui/SidebarSection.tsx +++ b/desktop/src/features/sidebar/ui/SidebarSection.tsx @@ -25,7 +25,11 @@ import { ProfileAvatarWithStatus, scaleProfileAvatarStatusGeometry, } from "@/features/profile/ui/ProfileAvatarWithStatus"; +import { useQueryClient } from "@tanstack/react-query"; + +import { prefetchChannelMessages } from "@/features/messages/hooks"; import type { Channel, PresenceStatus } from "@/shared/api/types"; +import { useHoverIntent } from "@/shared/hooks/useHoverIntent"; import { cn } from "@/shared/lib/cn"; import { useNow } from "@/shared/lib/useNow"; import { @@ -274,6 +278,13 @@ export function ChannelMenuButton({ }) { const resolvedLabel = label ?? channel.name; const ephemeralDisplay = getEphemeralChannelDisplay(channel); + const queryClient = useQueryClient(); + // Hover intent warms the channel's message window so the click lands on a + // cache hit. Respects the window's staleTime — re-hovering a fresh channel + // never refetches. + const hoverPrefetch = useHoverIntent(() => + prefetchChannelMessages(queryClient, channel), + ); const { hasSidebarUnreadProjections, topLevelUnreadChannelIds, @@ -313,6 +324,8 @@ export function ChannelMenuButton({ data-testid={`channel-${channel.name}`} isActive={isActive} onClick={() => onSelectChannel(channel.id)} + onMouseEnter={hoverPrefetch.onMouseEnter} + onMouseLeave={hoverPrefetch.onMouseLeave} tooltip={resolvedLabel} type="button" > diff --git a/desktop/src/shared/hooks/useHoverIntent.test.mjs b/desktop/src/shared/hooks/useHoverIntent.test.mjs new file mode 100644 index 00000000000..a64ee2d484b --- /dev/null +++ b/desktop/src/shared/hooks/useHoverIntent.test.mjs @@ -0,0 +1,59 @@ +import assert from "node:assert/strict"; +import test from "node:test"; + +import { createHoverIntent } from "./useHoverIntent.ts"; + +function fakeTimers() { + const timers = new Map(); + let nextId = 1; + return { + setTimeout: (fn, _ms) => { + const id = nextId++; + timers.set(id, fn); + return id; + }, + clearTimeout: (id) => timers.delete(id), + fire: () => { + for (const [id, fn] of [...timers]) { + timers.delete(id); + fn(); + } + }, + pending: () => timers.size, + }; +} + +test("fires the callback only after the dwell elapses", () => { + const timers = fakeTimers(); + let fired = 0; + const intent = createHoverIntent(() => fired++, timers); + + intent.start(); + assert.equal(fired, 0); + timers.fire(); + assert.equal(fired, 1); +}); + +test("leaving before the dwell cancels the callback", () => { + const timers = fakeTimers(); + let fired = 0; + const intent = createHoverIntent(() => fired++, timers); + + intent.start(); + intent.cancel(); + timers.fire(); + assert.equal(fired, 0); + assert.equal(timers.pending(), 0); +}); + +test("re-entering restarts the dwell without stacking timers", () => { + const timers = fakeTimers(); + let fired = 0; + const intent = createHoverIntent(() => fired++, timers); + + intent.start(); + intent.start(); + assert.equal(timers.pending(), 1); + timers.fire(); + assert.equal(fired, 1); +}); diff --git a/desktop/src/shared/hooks/useHoverIntent.ts b/desktop/src/shared/hooks/useHoverIntent.ts new file mode 100644 index 00000000000..9e22a31e61b --- /dev/null +++ b/desktop/src/shared/hooks/useHoverIntent.ts @@ -0,0 +1,68 @@ +import * as React from "react"; + +/** + * Dwell before a hover counts as intent. Long enough that scrubbing the + * pointer across the sidebar never fires, short enough that a deliberate + * hover warms the destination well before the click lands. + */ +const HOVER_INTENT_DWELL_MS = 100; + +type TimerHost = { + setTimeout: (fn: () => void, ms: number) => number; + clearTimeout: (id: number) => void; +}; + +/** + * Pure dwell-timer core behind {@link useHoverIntent}; injectable timers for + * unit testing. `start` restarts the dwell; `cancel` drops it. + */ +export function createHoverIntent( + onIntent: () => void, + timers: TimerHost, + dwellMs: number = HOVER_INTENT_DWELL_MS, +): { start: () => void; cancel: () => void } { + let timerId: number | null = null; + const cancel = () => { + if (timerId !== null) { + timers.clearTimeout(timerId); + timerId = null; + } + }; + return { + start: () => { + cancel(); + timerId = timers.setTimeout(() => { + timerId = null; + onIntent(); + }, dwellMs); + }, + cancel, + }; +} + +/** + * Fires `onIntent` after the pointer dwells on an element. Returns stable + * mouse-enter/leave handlers; the latest callback is always used, and any + * pending dwell is dropped on unmount. + */ +export function useHoverIntent(onIntent: () => void): { + onMouseEnter: () => void; + onMouseLeave: () => void; +} { + const callbackRef = React.useRef(onIntent); + callbackRef.current = onIntent; + const intentRef = React.useRef | null>( + null, + ); + if (intentRef.current === null) { + intentRef.current = createHoverIntent(() => callbackRef.current(), { + setTimeout: (fn, ms) => window.setTimeout(fn, ms), + clearTimeout: (id) => window.clearTimeout(id), + }); + } + React.useEffect(() => () => intentRef.current?.cancel(), []); + return { + onMouseEnter: intentRef.current.start, + onMouseLeave: intentRef.current.cancel, + }; +} diff --git a/desktop/src/testing/e2eBridge.ts b/desktop/src/testing/e2eBridge.ts index 2452b1ce12b..4b879f4e901 100644 --- a/desktop/src/testing/e2eBridge.ts +++ b/desktop/src/testing/e2eBridge.ts @@ -5579,7 +5579,20 @@ async function handleGetChannelWindow( }; if (!args.cursor) { - return execute(); + // TEST-ONLY probe: head (cursorless) window fetches, keyed for specs that + // assert prefetch behavior. Continuations keep their own counter below. + const headProbe = window as unknown as { + __CHANNEL_WINDOW_HEAD_FETCH_COUNT__?: number; + __CHANNEL_WINDOW_HEAD_COMPLETE_COUNT__?: number; + }; + headProbe.__CHANNEL_WINDOW_HEAD_FETCH_COUNT__ = + (headProbe.__CHANNEL_WINDOW_HEAD_FETCH_COUNT__ ?? 0) + 1; + const result = await execute(); + // Completion counter: specs asserting a warmed cache must wait for this, + // not the start counter — a started-but-pending prefetch proves nothing. + headProbe.__CHANNEL_WINDOW_HEAD_COMPLETE_COUNT__ = + (headProbe.__CHANNEL_WINDOW_HEAD_COMPLETE_COUNT__ ?? 0) + 1; + return result; } const probe = window as unknown as { diff --git a/desktop/tests/e2e/sidebar-hover-prefetch.spec.ts b/desktop/tests/e2e/sidebar-hover-prefetch.spec.ts new file mode 100644 index 00000000000..b3a0392d662 --- /dev/null +++ b/desktop/tests/e2e/sidebar-hover-prefetch.spec.ts @@ -0,0 +1,78 @@ +import { expect, test } from "@playwright/test"; + +import { installMockBridge } from "../helpers/bridge"; + +/** + * Sidebar hover intent must warm the hovered channel's message window before + * the click: dwelling on an unvisited channel row triggers exactly one + * window fetch, so the subsequent click paints from cache instead of paying + * the fetch on the switch path. Scrubbing across the row (enter → quick + * leave) must NOT fetch. + */ + +declare global { + interface Window { + __CHANNEL_WINDOW_HEAD_FETCH_COUNT__?: number; + __CHANNEL_WINDOW_HEAD_COMPLETE_COUNT__?: number; + } +} + +async function windowFetchCount(page: import("@playwright/test").Page) { + return page.evaluate(() => window.__CHANNEL_WINDOW_HEAD_FETCH_COUNT__ ?? 0); +} + +async function windowCompleteCount(page: import("@playwright/test").Page) { + return page.evaluate( + () => window.__CHANNEL_WINDOW_HEAD_COMPLETE_COUNT__ ?? 0, + ); +} + +test("hover dwell prefetches the channel window; scrubbing does not", async ({ + page, +}) => { + await installMockBridge(page); + await page.goto("/"); + await expect(page.getByTestId("app-sidebar")).toBeVisible(); + // Seed #random (empty by default) so the warmed cache has a row to paint; + // recordMockMessage writes to the store without needing a subscription. + await page.evaluate(() => { + window.__BUZZ_E2E_EMIT_MOCK_MESSAGE__?.({ + channelName: "random", + content: "Prefetched row", + createdAt: Math.floor(Date.now() / 1000) - 300, + }); + }); + const baseline = await windowFetchCount(page); + + // Scrub: enter and leave immediately — under the dwell, no fetch. + const random = page.getByTestId("channel-random"); + await random.hover(); + await page.getByTestId("channel-general").hover({ force: true }); + await page.getByTestId("app-sidebar").hover({ position: { x: 4, y: 4 } }); + await page.waitForTimeout(300); + const afterScrub = await windowFetchCount(page); + + // Dwell: hover and stay past the intent threshold — exactly one fetch for + // the hovered channel, before any click. + const completedBeforeDwell = await windowCompleteCount(page); + await random.hover(); + await expect + .poll(() => windowFetchCount(page), { timeout: 2_000 }) + .toBe(afterScrub + 1); + + // The warmed cache only exists once the prefetch COMPLETES — a pending or + // failed prefetch must not pass this spec. + await expect + .poll(() => windowCompleteCount(page), { timeout: 2_000 }) + .toBeGreaterThan(completedBeforeDwell); + + // The click then paints the timeline from the warmed cache: rows are + // visible, not just the header. The subscription-gap refresh may add its + // own fetch after mount; the paint itself must not wait on one. + await random.click(); + await expect(page.getByTestId("chat-title")).toHaveText("random"); + await expect(page.getByTestId("message-row").first()).toBeVisible(); + + // Scrubbing earlier must not have fetched anything beyond the baseline. + expect(afterScrub).toBe(baseline); +});