diff --git a/desktop/playwright.config.ts b/desktop/playwright.config.ts index ff8a0e7703b..e2b05e2433b 100644 --- a/desktop/playwright.config.ts +++ b/desktop/playwright.config.ts @@ -104,7 +104,9 @@ 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", + "**/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-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..48b83b27d83 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"; @@ -260,28 +261,78 @@ 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) ?? []; + 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, + 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 14ec110addf..e2b63a02150 100644 --- a/desktop/src/features/messages/lib/projectChannelWindow.test.mjs +++ b/desktop/src/features/messages/lib/projectChannelWindow.test.mjs @@ -363,3 +363,124 @@ 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; + } +}); + +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/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/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/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..4b879f4e901 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.`); @@ -5547,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 { @@ -11981,6 +12026,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/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/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); +}); 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); +}); 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. */