mirror of
https://github.com/block/buzz.git
synced 2026-11-03 16:01:35 +00:00
refactor(desktop): cut the switch tracer to a simple, honest metric
The instrument was accumulating defects faster than it was answering questions. Nearly every review finding lived in a seam that existed only because the tracer inferred more than it could observe: a starvation heartbeat, a per-seam guard matrix, DOM-attribute sniffing with a commit generation, click anchors threaded by hand through nine async call sites, and an on-disk JSONL sink with rotation and byte caps. Each fix added a seam, and the next review found the guard that seam was missing. The perf work these numbers support matters more than the numbers, so the instrument is now scoped to what it can measure without inference: - click (or navigation) -> route commit -> settled paint, as a console line plus User Timing marks/measures. That is what the Performance panel and the perf harness read. - the message-window fetch when it starts inside that interval. - one drop rule per unmeasurable condition (hidden window, timeout, superseded, left the surface), each printing why. Removed: the Rust perf-log sink and its git-revision baking, the click-anchor threading and every call site that existed only to carry it, the starvation heartbeat, the roster-fetch attribution and its sequence machinery, and the commit-generation burst gate. Scope bounds are now stated in the module doc rather than inferred: callers that await before navigating are measured from the navigation, a bounded frame wait replaces the 5s render deadline, and a sample past that bound is flagged rather than dropped. Net: 2231 lines removed, 462 added. Signed-off-by: Max Lampert <maxwell@squareup.com>
This commit is contained in:
@@ -8,34 +8,6 @@ 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");
|
||||
|
||||
@@ -44,7 +44,6 @@ mod notifications;
|
||||
mod observer_archive;
|
||||
mod os_idle;
|
||||
pub mod pairing;
|
||||
mod perf_log;
|
||||
mod personas;
|
||||
mod prevent_sleep;
|
||||
mod profile;
|
||||
@@ -106,7 +105,6 @@ 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::*;
|
||||
|
||||
@@ -1,416 +0,0 @@
|
||||
//! 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. Enforced on the input
|
||||
/// record and again on the final serialized line, so folded-in metadata can
|
||||
/// never defeat it.
|
||||
const MAX_RECORD_BYTES: usize = 4 * 1024;
|
||||
|
||||
/// Upper bound on the operator-supplied `BUZZ_PERF_LOG_LABEL` run label.
|
||||
/// Truncating (rather than erroring) keeps a fat-fingered label from
|
||||
/// silently dropping every trace for the whole run — the frontend swallows
|
||||
/// sink errors by design.
|
||||
const MAX_LABEL_BYTES: usize = 128;
|
||||
|
||||
/// Truncates to the last char boundary at or below `max_bytes`.
|
||||
fn truncate_at_char_boundary(text: &str, max_bytes: usize) -> &str {
|
||||
if text.len() <= max_bytes {
|
||||
return text;
|
||||
}
|
||||
let mut end = max_bytes;
|
||||
while !text.is_char_boundary(end) {
|
||||
end -= 1;
|
||||
}
|
||||
&text[..end]
|
||||
}
|
||||
|
||||
/// 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<String, String> {
|
||||
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(
|
||||
truncate_at_char_boundary(label, MAX_LABEL_BYTES).to_string(),
|
||||
),
|
||||
);
|
||||
}
|
||||
let line = serde_json::to_string(&value).map_err(|e| e.to_string())?;
|
||||
// The cap must hold for what actually reaches the disk: gitSha and label
|
||||
// are folded in after the record-size check above, and writeln! appends
|
||||
// a newline terminator — reserve one byte for it.
|
||||
if line.len() + 1 > MAX_RECORD_BYTES {
|
||||
return Err("perf log line too large".to_string());
|
||||
}
|
||||
Ok(line)
|
||||
}
|
||||
|
||||
/// 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 `<name>.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. Same
|
||||
// platform rule as managed_agents::storage::start_install_log_session.
|
||||
//
|
||||
// Rotation itself is best-effort: an AV/EDR or editor holding a
|
||||
// transient lock (again, chiefly Windows) would otherwise fail
|
||||
// EVERY append until the lock clears — the frontend deliberately
|
||||
// swallows sink errors, so records would vanish silently.
|
||||
// Degrade to an unrotated append; the size cap re-applies once
|
||||
// rotation succeeds on a later write.
|
||||
let rotation = (|| -> std::io::Result<()> {
|
||||
if rotated.exists() {
|
||||
std::fs::remove_file(&rotated)?;
|
||||
}
|
||||
std::fs::rename(path, &rotated)
|
||||
})();
|
||||
if let Err(e) = rotation {
|
||||
eprintln!("buzz-desktop: perf-log rotation failed, appending unrotated: {e}");
|
||||
}
|
||||
}
|
||||
}
|
||||
let mut file = std::fs::OpenOptions::new()
|
||||
.create(true)
|
||||
.append(true)
|
||||
.open(path)
|
||||
.map_err(|e| e.to_string())?;
|
||||
// One write_all, not writeln!: writeln! issues two write syscalls (line,
|
||||
// then newline), and PERF_LOG_LOCK is process-local while the path is
|
||||
// not — a second Buzz process sharing the log dir could interleave
|
||||
// between them. A single O_APPEND write keeps lines atomic.
|
||||
file.write_all(format!("{line}\n").as_bytes())
|
||||
.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<String, String> {
|
||||
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::<String, String>(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 shape_truncates_an_unbounded_label_and_keeps_the_line_capped() {
|
||||
// BUZZ_PERF_LOG_LABEL is operator-supplied; a runaway value must not
|
||||
// defeat the record cap by being folded in after the size check.
|
||||
let label = "l".repeat(1024 * 1024);
|
||||
let line =
|
||||
shape_perf_log_line(r#"{"totalMs":13}"#, Some("abc123"), Some(&label)).expect("shape");
|
||||
assert!(line.len() <= MAX_RECORD_BYTES, "line stays under the cap");
|
||||
let value: serde_json::Value = serde_json::from_str(&line).expect("parse");
|
||||
assert_eq!(
|
||||
value["label"].as_str().expect("label").len(),
|
||||
MAX_LABEL_BYTES
|
||||
);
|
||||
assert_eq!(value["totalMs"], 13);
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn label_truncation_cuts_at_a_char_boundary() {
|
||||
// '€' is 3 bytes; MAX_LABEL_BYTES (128) is not a multiple of 3, so a
|
||||
// byte-index cut would split a char and panic (or emit invalid UTF-8).
|
||||
let label = "€".repeat(MAX_LABEL_BYTES);
|
||||
let line = shape_perf_log_line(r#"{"totalMs":1}"#, None, Some(&label)).expect("shape");
|
||||
let value: serde_json::Value = serde_json::from_str(&line).expect("parse");
|
||||
let stored = value["label"].as_str().expect("label");
|
||||
assert_eq!(stored.len(), MAX_LABEL_BYTES - (MAX_LABEL_BYTES % 3));
|
||||
assert!(stored.chars().all(|c| c == '€'));
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn shape_rejects_a_line_that_outgrows_the_cap_after_metadata() {
|
||||
// The record alone passes the input check; the folded-in git sha
|
||||
// pushes the serialized line over the cap.
|
||||
let pad = "x".repeat(MAX_RECORD_BYTES - 20);
|
||||
let record = format!(r#"{{"pad":"{pad}"}}"#);
|
||||
assert!(record.len() <= MAX_RECORD_BYTES);
|
||||
assert!(shape_perf_log_line(&record, Some(&"s".repeat(64)), None).is_err());
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn the_cap_bounds_bytes_on_disk_including_the_newline() {
|
||||
// Shaped line = {"pad":"…","gitSha":null} → pad length + 24 bytes.
|
||||
// The largest accepted line is MAX_RECORD_BYTES - 1: writeln! appends
|
||||
// a newline, and the cap bounds what reaches the disk.
|
||||
let fits = format!(r#"{{"pad":"{}"}}"#, "x".repeat(MAX_RECORD_BYTES - 25));
|
||||
let line = shape_perf_log_line(&fits, None, None).expect("one byte reserved for newline");
|
||||
assert_eq!(line.len(), MAX_RECORD_BYTES - 1);
|
||||
|
||||
let dir = std::env::temp_dir().join(format!(
|
||||
"perf-log-newline-{}-{:?}",
|
||||
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);
|
||||
append_line_rotating(&path, &line, MAX_LOG_BYTES).expect("append");
|
||||
assert_eq!(
|
||||
std::fs::metadata(&path).expect("metadata").len(),
|
||||
MAX_RECORD_BYTES as u64,
|
||||
"on-disk record must not exceed the cap"
|
||||
);
|
||||
std::fs::remove_dir_all(&dir).ok();
|
||||
|
||||
// One pad byte more serializes to exactly MAX_RECORD_BYTES, which
|
||||
// would write MAX_RECORD_BYTES + 1 bytes — rejected.
|
||||
let over = format!(r#"{{"pad":"{}"}}"#, "x".repeat(MAX_RECORD_BYTES - 24));
|
||||
assert!(shape_perf_log_line(&over, 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 a_failed_rotation_degrades_to_an_unrotated_append() {
|
||||
let dir = std::env::temp_dir().join(format!(
|
||||
"perf-log-degrade-{}-{:?}",
|
||||
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");
|
||||
std::fs::write(&path, "oversized-live\n").expect("seed live");
|
||||
// A non-empty DIRECTORY at the rotated path defeats remove_file and
|
||||
// rename on every platform — including for root, where permission
|
||||
// tricks no-op (containers often run tests as uid 0). It stands in
|
||||
// for a transient AV/EDR hold: the append must degrade to the
|
||||
// unrotated file, not drop records until the lock clears.
|
||||
std::fs::create_dir_all(rotated.join("hold")).expect("seed blocker");
|
||||
|
||||
append_line_rotating(&path, "must-survive", 8)
|
||||
.expect("append must survive a failed rotation");
|
||||
|
||||
assert_eq!(
|
||||
std::fs::read_to_string(&path).expect("read live"),
|
||||
"oversized-live\nmust-survive\n"
|
||||
);
|
||||
assert!(rotated.join("hold").exists(), "blocker untouched");
|
||||
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 18 bytes on disk (17 chars + newline) = 576
|
||||
// bytes against a 384-byte cap: rotation triggers before the 23rd
|
||||
// append (22 lines = 396 bytes ≥ 384) and the ≤10 lines that follow
|
||||
// (≤180 bytes) cannot re-trigger it, so the boundary is crossed
|
||||
// exactly once and 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<String> = std::fs::read_to_string(&path)
|
||||
.expect("read live")
|
||||
.lines()
|
||||
.map(str::to_string)
|
||||
.collect();
|
||||
// Unconditional: if rotation never fired under contention, the size
|
||||
// cap is inoperative and this test must fail, not silently pass with
|
||||
// all 32 lines in the live file.
|
||||
let rotated = std::fs::read_to_string(dir.join("switch-perf.jsonl.1"))
|
||||
.expect("rotation must have occurred under contention");
|
||||
lines.extend(rotated.lines().map(str::to_string));
|
||||
lines.sort();
|
||||
let expected: Vec<String> = (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();
|
||||
}
|
||||
}
|
||||
@@ -591,7 +591,6 @@ 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,
|
||||
|
||||
@@ -13,7 +13,6 @@ import {
|
||||
TerminalContextOverrideProvider,
|
||||
} from "@/app/TerminalContextOverrideContext";
|
||||
import { useAppNavigation } from "@/app/navigation/useAppNavigation";
|
||||
import { captureSwitchTraceAnchor } from "@/shared/lib/channelSwitchPerf";
|
||||
import { useBackForwardControls } from "@/app/navigation/useBackForwardControls";
|
||||
import { useCommunityNavigationTransitions } from "@/app/useCommunityNavigationTransitions";
|
||||
import { useLiveHomeFeedActions } from "@/app/useLiveHomeFeedActions";
|
||||
@@ -866,16 +865,11 @@ export function AppShell() {
|
||||
onMarkChannelUnread={markChannelUnread}
|
||||
onBrowseChannels={handleOpenBrowseChannels}
|
||||
onOpenDm={async ({ pubkeys }) => {
|
||||
// Anchor before awaiting open_dm; see
|
||||
// captureSwitchTraceAnchor.
|
||||
const traceStartedAt = captureSwitchTraceAnchor();
|
||||
const directMessage =
|
||||
await openDmMutation.mutateAsync({
|
||||
pubkeys,
|
||||
});
|
||||
await goChannel(directMessage.id, {
|
||||
traceStartedAt,
|
||||
});
|
||||
await goChannel(directMessage.id);
|
||||
}}
|
||||
onSelectAgents={() => void goAgents()}
|
||||
onSelectChannel={handleSidebarChannelSelect}
|
||||
|
||||
@@ -268,89 +268,3 @@ test("a same-destination navigation carrying router state still commits", async
|
||||
assert.equal(committed, true);
|
||||
assert.deepEqual(order, ["guard", "navigate"]);
|
||||
});
|
||||
|
||||
test("a rejected navigate cancels the trace it opened", async () => {
|
||||
await withTraceHarness(async ({ flush, measures }) => {
|
||||
// Router/loader rejection: no destination committed, so the trace must
|
||||
// not survive for a later untraced re-entry to settle with the failed
|
||||
// attempt plus everything in between.
|
||||
await assert.rejects(
|
||||
commitGuardedNavigation({
|
||||
currentHref: "/channels/aaaa",
|
||||
nextHref: "/channels/bbbb",
|
||||
guardedTarget: route("/channels/bbbb"),
|
||||
traceChannelId: "bbbb",
|
||||
navigate: async () => {
|
||||
throw new Error("loader failed");
|
||||
},
|
||||
}),
|
||||
/loader failed/,
|
||||
);
|
||||
settleChannelSwitchTrace("bbbb");
|
||||
flush();
|
||||
assert.deepEqual(measures(), []);
|
||||
});
|
||||
});
|
||||
|
||||
test("a rejected navigate never cancels a newer same-channel trace", async () => {
|
||||
await withTraceHarness(async ({ flush, measures }) => {
|
||||
// Cancel by identity, not by channel: the retry's trace is a different
|
||||
// object and must keep its measurement when the first attempt rejects.
|
||||
let releaseFirst;
|
||||
const firstGate = new Promise((resolve) => {
|
||||
releaseFirst = resolve;
|
||||
});
|
||||
const failing = assert.rejects(
|
||||
commitGuardedNavigation({
|
||||
currentHref: "/channels/aaaa",
|
||||
nextHref: "/channels/bbbb",
|
||||
guardedTarget: route("/channels/bbbb"),
|
||||
traceChannelId: "bbbb",
|
||||
navigate: async () => {
|
||||
await firstGate;
|
||||
throw new Error("loader failed");
|
||||
},
|
||||
}),
|
||||
/loader failed/,
|
||||
);
|
||||
// Retry lands while the first attempt is still in flight.
|
||||
await commitGuardedNavigation({
|
||||
currentHref: "/channels/aaaa",
|
||||
nextHref: "/channels/bbbb",
|
||||
guardedTarget: route("/channels/bbbb"),
|
||||
force: true,
|
||||
traceChannelId: "bbbb",
|
||||
navigate: async () => {},
|
||||
});
|
||||
releaseFirst();
|
||||
await failing;
|
||||
settleChannelSwitchTrace("bbbb");
|
||||
flush();
|
||||
assert.deepEqual(measures(), ["bbbb"]);
|
||||
});
|
||||
});
|
||||
|
||||
test("a DM caller's click anchor is carried into the trace", async () => {
|
||||
await withTraceHarness(async () => {
|
||||
const anchors = [];
|
||||
await commitGuardedNavigation(
|
||||
{
|
||||
currentHref: "/",
|
||||
nextHref: "/channels/bbbb",
|
||||
guardedTarget: route("/channels/bbbb"),
|
||||
traceChannelId: "bbbb",
|
||||
traceStartedAt: 1234,
|
||||
navigate: async () => {},
|
||||
},
|
||||
{
|
||||
allow: () => true,
|
||||
beginTrace: (channelId, anchoredAt) => {
|
||||
anchors.push([channelId, anchoredAt]);
|
||||
return null;
|
||||
},
|
||||
},
|
||||
);
|
||||
// Without this the open_dm round-trip would sit outside the measurement.
|
||||
assert.deepEqual(anchors, [["bbbb", 1234]]);
|
||||
});
|
||||
});
|
||||
|
||||
@@ -4,7 +4,6 @@ import {
|
||||
} from "@/app/navigation/navigationGuard";
|
||||
import {
|
||||
beginChannelSwitchTrace,
|
||||
cancelChannelSwitchTrace,
|
||||
dropActiveChannelSwitchTrace,
|
||||
} from "@/shared/lib/channelSwitchPerf";
|
||||
|
||||
@@ -19,12 +18,8 @@ import {
|
||||
* navigation (deliberately untraced) would settle with the refused click's
|
||||
* inflated wall time. When `leavesChannelSurface` is set, any active trace is
|
||||
* dropped instead: the trace may be live with no channel screen mounted
|
||||
* (route still resolving), so this is the only reliable exit hook. A
|
||||
* `navigate()` rejection cancels the trace this call opened — by identity, so
|
||||
* a newer same-channel attempt is never erased — because no destination
|
||||
* committed and an untraced re-entry would otherwise settle the failed
|
||||
* attempt. Returns whether the navigation was performed. `deps` exists for
|
||||
* unit tests.
|
||||
* (route still resolving), so this is the only reliable exit hook. Returns
|
||||
* whether the navigation was performed. `deps` exists for unit tests.
|
||||
*/
|
||||
export async function commitGuardedNavigation(
|
||||
input: {
|
||||
@@ -35,20 +30,16 @@ export async function commitGuardedNavigation(
|
||||
hasStateUpdate?: boolean;
|
||||
leavesChannelSurface?: boolean;
|
||||
traceChannelId?: string;
|
||||
/** Click-time anchor for callers that await before `goChannel`. */
|
||||
traceStartedAt?: number;
|
||||
navigate: () => Promise<unknown>;
|
||||
},
|
||||
deps: {
|
||||
allow?: typeof allowNavigation;
|
||||
beginTrace?: typeof beginChannelSwitchTrace;
|
||||
cancelTrace?: typeof cancelChannelSwitchTrace;
|
||||
dropActiveTrace?: typeof dropActiveChannelSwitchTrace;
|
||||
} = {},
|
||||
): Promise<boolean> {
|
||||
const allow = deps.allow ?? allowNavigation;
|
||||
const beginTrace = deps.beginTrace ?? beginChannelSwitchTrace;
|
||||
const cancelTrace = deps.cancelTrace ?? cancelChannelSwitchTrace;
|
||||
const dropActiveTrace = deps.dropActiveTrace ?? dropActiveChannelSwitchTrace;
|
||||
if (
|
||||
input.currentHref === input.nextHref &&
|
||||
@@ -63,15 +54,9 @@ export async function commitGuardedNavigation(
|
||||
if (input.leavesChannelSurface) {
|
||||
dropActiveTrace();
|
||||
}
|
||||
let handle = null;
|
||||
if (input.traceChannelId !== undefined) {
|
||||
handle = beginTrace(input.traceChannelId, input.traceStartedAt) ?? null;
|
||||
}
|
||||
try {
|
||||
await input.navigate();
|
||||
} catch (error) {
|
||||
cancelTrace(handle);
|
||||
throw error;
|
||||
beginTrace(input.traceChannelId);
|
||||
}
|
||||
await input.navigate();
|
||||
return true;
|
||||
}
|
||||
|
||||
@@ -42,7 +42,6 @@ export function useAppNavigation() {
|
||||
behavior: NavigationBehavior = {},
|
||||
guardedTarget?: GuardedNavigation,
|
||||
traceChannelId?: string,
|
||||
traceStartedAt?: number,
|
||||
) => {
|
||||
const nextLocation = router.buildLocation(next as never);
|
||||
return commitGuardedNavigation({
|
||||
@@ -67,7 +66,6 @@ export function useAppNavigation() {
|
||||
} as never),
|
||||
nextHref: nextLocation.href,
|
||||
traceChannelId,
|
||||
traceStartedAt,
|
||||
});
|
||||
},
|
||||
[location.href, navigate, router],
|
||||
@@ -283,13 +281,6 @@ export function useAppNavigation() {
|
||||
preserveSearchHighlight?: boolean;
|
||||
searchHighlight?: SearchHighlightNavigation;
|
||||
replace?: boolean;
|
||||
/**
|
||||
* Click-time anchor from `captureSwitchTraceAnchor()`, for callers
|
||||
* that must await before they know the channel id (DM actions await
|
||||
* `open_dm`). Without it the trace would start after that relay
|
||||
* round-trip and exclude felt click latency.
|
||||
*/
|
||||
traceStartedAt?: number;
|
||||
/** Open this thread panel directly without waiting for a timeline row. */
|
||||
thread?: string;
|
||||
threadRootId?: string | null;
|
||||
@@ -334,20 +325,16 @@ export function useAppNavigation() {
|
||||
threadRootId: options.threadRootId ?? null,
|
||||
}
|
||||
: undefined,
|
||||
// goChannel is the click-time anchor for the switch trace; it opens
|
||||
// inside commitGuardedNavigation only after the navigation guard
|
||||
// accepts. Coverage: sidebar, search, notification, and DM-open
|
||||
// navigations all funnel through here; DM callers pass traceStartedAt
|
||||
// so the open_dm round-trip stays inside the measurement. History
|
||||
// back/forward is deliberately untraced. Navigations that stay on the
|
||||
// already-active channel (exact re-click only rewrites router state;
|
||||
// jump-to-message/autoSend/force change only search params) never
|
||||
// re-run the channel's settle effects, so a trace could only time out
|
||||
// — also untraced.
|
||||
// goChannel is the anchor for the switch trace; it opens inside
|
||||
// commitGuardedNavigation only after the navigation guard accepts.
|
||||
// Callers that await before navigating (DM actions await open_dm)
|
||||
// are measured from the navigation, not from their click — see the
|
||||
// scope note in channelSwitchPerf.ts. History back/forward is
|
||||
// untraced, and navigations that stay on the already-active channel
|
||||
// never re-run the settle effects, so a trace could only time out.
|
||||
location.pathname.endsWith(`/channels/${channelId}`)
|
||||
? undefined
|
||||
: channelId,
|
||||
options?.traceStartedAt,
|
||||
);
|
||||
},
|
||||
[commitNavigation, location.pathname],
|
||||
|
||||
@@ -1,7 +1,6 @@
|
||||
import * as React from "react";
|
||||
|
||||
import { useAppNavigation } from "@/app/navigation/useAppNavigation";
|
||||
import { captureSwitchTraceAnchor } from "@/shared/lib/channelSwitchPerf";
|
||||
import { usePersonasQuery } from "@/features/agents/hooks";
|
||||
import { useOpenDmMutation } from "@/features/channels/hooks";
|
||||
import {
|
||||
@@ -111,10 +110,8 @@ export function AgentsScreen() {
|
||||
|
||||
const handleOpenDm = React.useCallback(
|
||||
async (pubkeys: string[]) => {
|
||||
// Anchor before awaiting open_dm; see captureSwitchTraceAnchor.
|
||||
const traceStartedAt = captureSwitchTraceAnchor();
|
||||
const dm = await openDmMutation.mutateAsync({ pubkeys });
|
||||
await goChannel(dm.id, { traceStartedAt });
|
||||
await goChannel(dm.id);
|
||||
},
|
||||
[goChannel, openDmMutation],
|
||||
);
|
||||
|
||||
@@ -42,10 +42,6 @@ import type {
|
||||
} from "@/shared/api/tauriChannels";
|
||||
import { mergeConcurrentChannelRecency } from "@/features/channels/lib/channelRecencyMerge";
|
||||
import { useIdentityQuery } from "@/shared/api/hooks";
|
||||
import {
|
||||
openChannelMembersFetch,
|
||||
traceChannelMembersFetch,
|
||||
} from "@/shared/lib/channelSwitchPerf";
|
||||
import { useFocusedRefetchInterval } from "@/shared/lib/useDocumentVisible";
|
||||
import { useCommunities } from "@/features/communities/useCommunities";
|
||||
import {
|
||||
@@ -53,10 +49,6 @@ import {
|
||||
type ChannelSnapshot,
|
||||
writeChannelSnapshot,
|
||||
} from "@/features/channels/channelSnapshot";
|
||||
import {
|
||||
markSnapshotDiagnostic,
|
||||
measureFullSidebarPaint,
|
||||
} from "@/features/channels/sidebarPerf";
|
||||
import {
|
||||
CHANNEL_MEMBERS_STALE_TIME_MS,
|
||||
channelMembersQueryKey,
|
||||
@@ -105,6 +97,73 @@ 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<string>();
|
||||
const measuredSidebarKeys = new Set<string>();
|
||||
const scheduledSidebarKeys = new Set<string>();
|
||||
|
||||
function sidebarMeasurementKey(relayUrl: string, ownerPubkey: string): string {
|
||||
return `${relayUrl}\u0000${ownerPubkey.toLowerCase()}`;
|
||||
}
|
||||
|
||||
function markSnapshotDiagnostic(
|
||||
relayUrl: string,
|
||||
ownerPubkey: string,
|
||||
diagnostics: ReturnType<typeof inspectChannelSnapshot>["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;
|
||||
@@ -568,22 +627,7 @@ export function useChannelMembersQuery(
|
||||
throw new Error("No channel selected.");
|
||||
}
|
||||
|
||||
// Supersession token, NOT the query's AbortSignal: reading the signal
|
||||
// getter flips React Query to cancel-and-revert when the last observer
|
||||
// unsubscribes mid-fetch, which would discard warm rosters on
|
||||
// interrupted switches. The token keeps stale fetches (replaced by a
|
||||
// live join/leave invalidation) out of the trace's one-shot slot.
|
||||
const fetchAttempt = openChannelMembersFetch(channelId);
|
||||
const fetchStartedAt = performance.now();
|
||||
const members = await getChannelMembers(channelId);
|
||||
traceChannelMembersFetch(
|
||||
channelId,
|
||||
members.length,
|
||||
performance.now() - fetchStartedAt,
|
||||
fetchStartedAt,
|
||||
fetchAttempt,
|
||||
);
|
||||
return members;
|
||||
return getChannelMembers(channelId);
|
||||
},
|
||||
staleTime: CHANNEL_MEMBERS_STALE_TIME_MS,
|
||||
});
|
||||
|
||||
@@ -1,74 +0,0 @@
|
||||
/**
|
||||
* 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<string>();
|
||||
const measuredSidebarKeys = new Set<string>();
|
||||
const scheduledSidebarKeys = new Set<string>();
|
||||
|
||||
function sidebarMeasurementKey(relayUrl: string, ownerPubkey: string): string {
|
||||
return `${relayUrl}\u0000${ownerPubkey.toLowerCase()}`;
|
||||
}
|
||||
|
||||
export function markSnapshotDiagnostic(
|
||||
relayUrl: string,
|
||||
ownerPubkey: string,
|
||||
diagnostics: ReturnType<typeof inspectChannelSnapshot>["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,
|
||||
});
|
||||
});
|
||||
});
|
||||
}
|
||||
@@ -1,7 +1,6 @@
|
||||
import * as React from "react";
|
||||
|
||||
import { useAppNavigation } from "@/app/navigation/useAppNavigation";
|
||||
import { captureSwitchTraceAnchor } from "@/shared/lib/channelSwitchPerf";
|
||||
import { useOpenDmMutation } from "@/features/channels/hooks";
|
||||
import type { ProfilePanelOpenOptions } from "@/shared/context/ProfilePanelContext";
|
||||
|
||||
@@ -61,10 +60,8 @@ export function useChannelProfilePanel({
|
||||
const openDmMutateAsync = openDmMutation.mutateAsync;
|
||||
const handleOpenDm = React.useCallback(
|
||||
async (pubkeys: string[]) => {
|
||||
// Anchor before awaiting open_dm; see captureSwitchTraceAnchor.
|
||||
const traceStartedAt = captureSwitchTraceAnchor();
|
||||
const dm = await openDmMutateAsync({ pubkeys });
|
||||
await goChannel(dm.id, { traceStartedAt });
|
||||
await goChannel(dm.id);
|
||||
},
|
||||
[goChannel, openDmMutateAsync],
|
||||
);
|
||||
|
||||
@@ -101,26 +101,6 @@ it("a trace survives StrictMode's effect replay and still settles", async () =>
|
||||
dom.window.close();
|
||||
});
|
||||
|
||||
it("a real route exit still abandons: a history-back settle records nothing", async () => {
|
||||
const { dom, flushFrames } = setupDom();
|
||||
performance.clearMeasures?.(CHANNEL_SWITCH_MEASURE);
|
||||
beginChannelSwitchTrace("chan-exit");
|
||||
const root = createRoot(document.getElementById("root"));
|
||||
await renderHarness(root, {
|
||||
channelId: "chan-exit",
|
||||
isTimelineLoading: true,
|
||||
});
|
||||
// Leaving the channel surface unmounts the hook; with no re-setup to
|
||||
// cancel it, the scheduled abandon must fire.
|
||||
await act(async () => root.unmount());
|
||||
await new Promise((resolve) => setImmediate(resolve));
|
||||
// History-back re-enters without goChannel; its settle must find no trace.
|
||||
settleChannelSwitchTrace("chan-exit");
|
||||
flushFrames();
|
||||
assert.deepEqual(measures(), []);
|
||||
dom.window.close();
|
||||
});
|
||||
|
||||
it("an A→B switch's deferred abandon of A never kills B's trace", async () => {
|
||||
const { dom, flushFrames } = setupDom();
|
||||
performance.clearMeasures?.(CHANNEL_SWITCH_MEASURE);
|
||||
|
||||
@@ -2,9 +2,7 @@ import * as React from "react";
|
||||
|
||||
import {
|
||||
abandonChannelSwitchTrace,
|
||||
cancelRouteExitAbandon,
|
||||
markChannelSwitchRouteCommit,
|
||||
scheduleRouteExitAbandon,
|
||||
settleChannelSwitchTrace,
|
||||
} from "@/shared/lib/channelSwitchPerf";
|
||||
import type { ChannelType } from "@/shared/api/types";
|
||||
@@ -32,24 +30,6 @@ export function useChannelSwitchTraceMarks({
|
||||
React.useLayoutEffect(() => {
|
||||
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. The abandon is scheduled (one microtask) rather
|
||||
// than immediate so StrictMode's dev-only effect replay — whose re-setup
|
||||
// runs synchronously right after this cleanup — cancels it instead of
|
||||
// killing the just-opened trace.
|
||||
React.useEffect(() => {
|
||||
if (!activeChannelId) return;
|
||||
const channelId = activeChannelId;
|
||||
cancelRouteExitAbandon(channelId);
|
||||
return () => {
|
||||
scheduleRouteExitAbandon(channelId);
|
||||
};
|
||||
}, [activeChannelId]);
|
||||
React.useEffect(() => {
|
||||
if (!activeChannelId) return;
|
||||
if (activeChannelType === "forum") {
|
||||
|
||||
@@ -3,7 +3,6 @@ import { RefreshCcw } from "lucide-react";
|
||||
|
||||
import { useAppShell } from "@/app/AppShellContext";
|
||||
import { useAppNavigation } from "@/app/navigation/useAppNavigation";
|
||||
import { captureSwitchTraceAnchor } from "@/shared/lib/channelSwitchPerf";
|
||||
import { useKnownAgentPubkeys } from "@/features/agents/useKnownAgentPubkeys";
|
||||
import { useChannelsQuery, useOpenDmMutation } from "@/features/channels/hooks";
|
||||
import { RightAuxiliaryPane } from "@/features/channels/ui/RightAuxiliaryPane";
|
||||
@@ -222,10 +221,8 @@ export function HomeView({
|
||||
const [isSendingReply, setIsSendingReply] = React.useState(false);
|
||||
const handleOpenDm = React.useCallback(
|
||||
async (pubkeys: string[]) => {
|
||||
// Anchor before awaiting open_dm; see captureSwitchTraceAnchor.
|
||||
const traceStartedAt = captureSwitchTraceAnchor();
|
||||
const dm = await openDm({ pubkeys });
|
||||
await goChannel(dm.id, { traceStartedAt });
|
||||
await goChannel(dm.id);
|
||||
},
|
||||
[goChannel, openDm],
|
||||
);
|
||||
|
||||
@@ -144,22 +144,12 @@ type TimelineSnapshot = {
|
||||
* finally land (the pass-1 tear, ledgered 2026-07-11).
|
||||
*/
|
||||
historyExhausted: boolean;
|
||||
/**
|
||||
* Monotonic id of this snapshot. Rendered as `data-timeline-commit` from
|
||||
* the DEFERRED snapshot, so the switch tracer can tell "the commit I was
|
||||
* waiting for has painted" from "new live traffic re-latched the pending
|
||||
* marker after my rows painted" — the two are indistinguishable from
|
||||
* `data-render-pending` alone, and the second one used to inflate the
|
||||
* recorded switch by the whole burst.
|
||||
*/
|
||||
generation: number;
|
||||
};
|
||||
|
||||
const EMPTY_TIMELINE_SNAPSHOT: TimelineSnapshot = {
|
||||
channelId: null,
|
||||
messages: EMPTY_MESSAGES,
|
||||
historyExhausted: false,
|
||||
generation: 0,
|
||||
};
|
||||
|
||||
const MessageTimelineBase = React.forwardRef<
|
||||
@@ -256,18 +246,10 @@ const MessageTimelineBase = React.forwardRef<
|
||||
// Channel id travels with the deferred message snapshot. Without that guard, a
|
||||
// route change can paint the previous channel's deferred rows for a frame even
|
||||
// though the sidebar/header already moved to the new channel.
|
||||
const snapshotGenerationRef = React.useRef(0);
|
||||
const liveSnapshot = React.useMemo<TimelineSnapshot>(() => {
|
||||
// Monotonic only — StrictMode's double-invoke may skip a number, which
|
||||
// the tracer's `>` comparison tolerates.
|
||||
snapshotGenerationRef.current += 1;
|
||||
return {
|
||||
channelId: channelId ?? null,
|
||||
messages,
|
||||
historyExhausted,
|
||||
generation: snapshotGenerationRef.current,
|
||||
};
|
||||
}, [channelId, historyExhausted, messages]);
|
||||
const liveSnapshot = React.useMemo<TimelineSnapshot>(
|
||||
() => ({ channelId: channelId ?? null, messages, historyExhausted }),
|
||||
[channelId, historyExhausted, messages],
|
||||
);
|
||||
const deferredSnapshot = React.useDeferredValue(
|
||||
liveSnapshot,
|
||||
EMPTY_TIMELINE_SNAPSHOT,
|
||||
@@ -719,7 +701,6 @@ const MessageTimelineBase = React.forwardRef<
|
||||
<div
|
||||
className="relative flex min-h-0 min-w-0 flex-1 flex-col overflow-hidden"
|
||||
data-render-pending={isRenderPending ? "true" : undefined}
|
||||
data-timeline-commit={deferredSnapshot.generation}
|
||||
>
|
||||
{showUnreadPill ? (
|
||||
<div
|
||||
|
||||
@@ -285,9 +285,6 @@ export function NewMessageScreen() {
|
||||
if (!isMountedRef.current) {
|
||||
return;
|
||||
}
|
||||
// No click anchor here: the switch begins at navigation. Back-dating to
|
||||
// the Send click would report the whole publish round-trip as switch
|
||||
// latency.
|
||||
await goChannel(directMessage.id, { replace: true });
|
||||
},
|
||||
[
|
||||
|
||||
@@ -3,7 +3,6 @@ import * as React from "react";
|
||||
import { toast } from "sonner";
|
||||
|
||||
import { useAppNavigation } from "@/app/navigation/useAppNavigation";
|
||||
import { captureSwitchTraceAnchor } from "@/shared/lib/channelSwitchPerf";
|
||||
import {
|
||||
channelsQueryKey,
|
||||
useChannelsQuery,
|
||||
@@ -153,12 +152,9 @@ export function useProfileInteractionActions({
|
||||
return;
|
||||
}
|
||||
|
||||
// Anchor before awaiting open_dm: that relay round-trip is felt click
|
||||
// latency and belongs inside the switch measurement.
|
||||
const traceStartedAt = captureSwitchTraceAnchor();
|
||||
void runAction("message", async (targetPubkey) => {
|
||||
const dm = await openDm({ pubkeys: [targetPubkey] });
|
||||
await goChannel(dm.id, { traceStartedAt });
|
||||
await goChannel(dm.id);
|
||||
if (isMountedRef.current) {
|
||||
onClose();
|
||||
}
|
||||
@@ -170,10 +166,9 @@ export function useProfileInteractionActions({
|
||||
return;
|
||||
}
|
||||
|
||||
const traceStartedAt = captureSwitchTraceAnchor();
|
||||
void runAction("huddle", async (targetPubkey) => {
|
||||
const dm = await openDm({ pubkeys: [targetPubkey] });
|
||||
await goChannel(dm.id, { traceStartedAt });
|
||||
await goChannel(dm.id);
|
||||
await startHuddle(dm.id, isBot ? [targetPubkey] : []);
|
||||
await queryClient.invalidateQueries({ queryKey: channelsQueryKey });
|
||||
if (isMountedRef.current) {
|
||||
@@ -197,7 +192,6 @@ export function useProfileInteractionActions({
|
||||
return;
|
||||
}
|
||||
|
||||
const traceStartedAt = captureSwitchTraceAnchor();
|
||||
void runAction("wave", async (targetPubkey) => {
|
||||
const identity = identityQuery.data;
|
||||
if (!identity) {
|
||||
@@ -233,7 +227,7 @@ export function useProfileInteractionActions({
|
||||
);
|
||||
|
||||
try {
|
||||
await goChannel(dm.id, { traceStartedAt });
|
||||
await goChannel(dm.id);
|
||||
if (isMountedRef.current) {
|
||||
onClose();
|
||||
}
|
||||
|
||||
@@ -1,7 +1,6 @@
|
||||
import * as React from "react";
|
||||
|
||||
import { useAppNavigation } from "@/app/navigation/useAppNavigation";
|
||||
import { captureSwitchTraceAnchor } from "@/shared/lib/channelSwitchPerf";
|
||||
import { useOpenDmMutation } from "@/features/channels/hooks";
|
||||
import type {
|
||||
ProfilePanelTab,
|
||||
@@ -52,10 +51,8 @@ export function useProjectProfilePanel() {
|
||||
),
|
||||
handleOpenDm: React.useCallback(
|
||||
async (pubkeys: string[]) => {
|
||||
// Anchor before awaiting open_dm; see captureSwitchTraceAnchor.
|
||||
const traceStartedAt = captureSwitchTraceAnchor();
|
||||
const dm = await openDmMutation.mutateAsync({ pubkeys });
|
||||
await goChannel(dm.id, { traceStartedAt });
|
||||
await goChannel(dm.id);
|
||||
},
|
||||
[goChannel, openDmMutation],
|
||||
),
|
||||
|
||||
@@ -1,6 +1,5 @@
|
||||
import * as React from "react";
|
||||
import { useAppNavigation } from "@/app/navigation/useAppNavigation";
|
||||
import { captureSwitchTraceAnchor } from "@/shared/lib/channelSwitchPerf";
|
||||
import { useQueryClient } from "@tanstack/react-query";
|
||||
import { toast } from "sonner";
|
||||
|
||||
@@ -156,14 +155,12 @@ export function usePulseNoteActions({
|
||||
const startDm = React.useCallback(
|
||||
async (pubkey: string) => {
|
||||
// goChannel, not raw navigate: this is a first-class channel entry and
|
||||
// must produce a switch measurement like every other one. Anchor before
|
||||
// awaiting open_dm; see captureSwitchTraceAnchor.
|
||||
const traceStartedAt = captureSwitchTraceAnchor();
|
||||
// must go through the same navigation guard as every other one.
|
||||
try {
|
||||
const directMessage = await openDmMutation.mutateAsync({
|
||||
pubkeys: [pubkey],
|
||||
});
|
||||
await goChannel(directMessage.id, { traceStartedAt });
|
||||
await goChannel(directMessage.id);
|
||||
} catch (error) {
|
||||
toast.error(
|
||||
error instanceof Error ? error.message : "Failed to open DM",
|
||||
|
||||
@@ -1,7 +1,6 @@
|
||||
import * as React from "react";
|
||||
|
||||
import { useAppNavigation } from "@/app/navigation/useAppNavigation";
|
||||
import { captureSwitchTraceAnchor } from "@/shared/lib/channelSwitchPerf";
|
||||
import { useOpenDmMutation } from "@/features/channels/hooks";
|
||||
import {
|
||||
type ProfilePanelTab,
|
||||
@@ -54,10 +53,8 @@ export function PulseScreen() {
|
||||
const { goChannel } = useAppNavigation();
|
||||
const handleOpenDm = React.useCallback(
|
||||
async (pubkeys: string[]) => {
|
||||
// Anchor before awaiting open_dm; see captureSwitchTraceAnchor.
|
||||
const traceStartedAt = captureSwitchTraceAnchor();
|
||||
const dm = await openDmMutation.mutateAsync({ pubkeys });
|
||||
await goChannel(dm.id, { traceStartedAt });
|
||||
await goChannel(dm.id);
|
||||
},
|
||||
[goChannel, openDmMutation],
|
||||
);
|
||||
|
||||
File diff suppressed because it is too large
Load Diff
File diff suppressed because it is too large
Load Diff
@@ -112,77 +112,37 @@ test("settle waits for a delayed lazy channel-pane chunk", async ({ page }) => {
|
||||
})
|
||||
.toBe(true);
|
||||
|
||||
// Give the tracer ample frames to (incorrectly) settle behind the held
|
||||
// chunk. The tracer's 5s render-wait deadline runs from settle entry
|
||||
// (query readiness — immediate in mock mode), after which it honestly
|
||||
// emits a TRUNCATED measure even while suspended; the contract under test
|
||||
// is that no CLEAN measure appears. Guard the timing assumption
|
||||
// explicitly so a slow CI box fails with the real reason.
|
||||
await page.waitForTimeout(1_500);
|
||||
const early = await page.evaluate((name) => {
|
||||
const start = performance.getEntriesByName("buzz:channel-switch:start")[0];
|
||||
return {
|
||||
cleanMeasures: performance
|
||||
// While the pane chunk is held there are no rows on screen, so any measure
|
||||
// emitted here must carry the truncation flag. A CLEAN measure would be the
|
||||
// regression: a settled paint reported for a screen showing a fallback.
|
||||
await page.waitForTimeout(1_000);
|
||||
const cleanWhileSuspended = await page.evaluate(
|
||||
(name) =>
|
||||
performance
|
||||
.getEntriesByName(name)
|
||||
.filter(
|
||||
(entry) => !(entry as PerformanceMeasure).detail?.settleWaitTruncated,
|
||||
).length,
|
||||
elapsedSinceClick: start ? performance.now() - start.startTime : null,
|
||||
};
|
||||
}, SWITCH_MEASURE);
|
||||
// Order matters: a clean measure recorded behind the held chunk — the
|
||||
// regression under test — clears the start mark, nulling elapsedSinceClick.
|
||||
// Asserting the budget first would then fail with a "rerun, not a tracer
|
||||
// bug" message that states the opposite of the truth.
|
||||
SWITCH_MEASURE,
|
||||
);
|
||||
expect(
|
||||
early.cleanMeasures,
|
||||
cleanWhileSuspended,
|
||||
"no clean settle may be recorded while the pane chunk is suspended",
|
||||
).toBe(0);
|
||||
// Boolean form: a truncated record already landing clears the start mark
|
||||
// and nulls elapsedSinceClick — that too is budget exhaustion, and must
|
||||
// fail with this message rather than a raw matcher error.
|
||||
expect(
|
||||
early.elapsedSinceClick !== null && early.elapsedSinceClick < 4_500,
|
||||
"harness overhead consumed the tracer's settle deadline — timing, not a tracer bug",
|
||||
).toBe(true);
|
||||
|
||||
releaseChunk();
|
||||
|
||||
// Same in-page polling as above: snapshot the DOM in the evaluation turn
|
||||
// where the first CLEAN measure exists. A truncated measure here means the
|
||||
// released chunk's mount outran the remaining render-wait budget — a
|
||||
// harness timing exhaustion, and it must fail with that reason.
|
||||
const atSettle = await page.evaluate(async (measureName) => {
|
||||
const deadline = Date.now() + 15_000;
|
||||
while (Date.now() < deadline) {
|
||||
const entries = performance.getEntriesByName(measureName);
|
||||
const clean = entries.filter(
|
||||
(entry) => !(entry as PerformanceMeasure).detail?.settleWaitTruncated,
|
||||
);
|
||||
if (clean.length > 0) {
|
||||
return {
|
||||
rowCount: document.querySelectorAll(
|
||||
'[data-message-id^="mock-deep-history-"]',
|
||||
).length,
|
||||
settled: true,
|
||||
truncatedOnly: false,
|
||||
};
|
||||
}
|
||||
if (entries.length > 0) {
|
||||
return { rowCount: 0, settled: false, truncatedOnly: true };
|
||||
}
|
||||
await new Promise((resolve) => setTimeout(resolve, 16));
|
||||
}
|
||||
return { rowCount: 0, settled: false, truncatedOnly: false };
|
||||
}, SWITCH_MEASURE);
|
||||
|
||||
expect(
|
||||
atSettle.truncatedOnly,
|
||||
"tracer truncated before the released chunk painted — harness timing exhausted, not a tracer bug; rerun",
|
||||
).toBe(false);
|
||||
expect(atSettle.settled, "switch trace must settle after release").toBe(true);
|
||||
expect(
|
||||
atSettle.rowCount,
|
||||
"the settle must land only after the released pane painted rows",
|
||||
).toBeGreaterThan(0);
|
||||
// After release the pane mounts and paints rows. The tracer's own record
|
||||
// may already have landed (truncated, by design) — what matters is that the
|
||||
// channel actually painted, which is what a clean settle would have claimed.
|
||||
await expect
|
||||
.poll(
|
||||
() =>
|
||||
page
|
||||
.locator('[data-message-id^="mock-deep-history-"]')
|
||||
.count()
|
||||
.then((count) => count > 0),
|
||||
{ message: "the released pane must paint rows", timeout: 15_000 },
|
||||
)
|
||||
.toBe(true);
|
||||
});
|
||||
|
||||
Reference in New Issue
Block a user