From 553bfa455866b50f24bb3c2971a00ffe93cb96c8 Mon Sep 17 00:00:00 2001 From: Erik Johnston Date: Tue, 13 Oct 2026 11:23:30 +0000 Subject: [PATCH] Report the time spent building events in Rust state res stats Loading an event means parsing its JSON and recomputing its event ID, which the Python event cache usually saves. parse_time shows how much that costs, to decide whether the Rust side needs an event cache. Co-Authored-By: Claude Opus 5.5 Claude-Session: https://claude.ai/code/session_01ULdieJyQoHNzeHq42H2M1p --- rust/src/state/mod.rs | 3 +++ rust/src/state/store.rs | 9 +++++++++ synapse/synapse_rust/state.pyi | 1 + 3 files changed, 13 insertions(+) diff --git a/rust/src/state/mod.rs b/rust/src/state/mod.rs index d6d0ac6c56..9d2978d8c0 100644 --- a/rust/src/state/mod.rs +++ b/rust/src/state/mod.rs @@ -346,6 +346,8 @@ pub struct StateResStats { pub total_time: f64, /// Time waiting on the database. pub db_time: f64, + /// Time building events from database rows. + pub parse_time: f64, /// Time in the algorithm (sorts and auth checks). pub cpu_time: f64, pub sort_time: f64, @@ -498,6 +500,7 @@ impl StateResolutionHandler { let stats = StateResStats { total_time: start.elapsed().as_secs_f64(), db_time: db.db_time.as_secs_f64(), + parse_time: db.parse_time.as_secs_f64(), cpu_time: (core.sort_time + core.auth_time + core.mainline_time).as_secs_f64(), sort_time: core.sort_time.as_secs_f64(), auth_time: core.auth_time.as_secs_f64(), diff --git a/rust/src/state/store.rs b/rust/src/state/store.rs index cd40b7e424..a304409761 100644 --- a/rust/src/state/store.rs +++ b/rust/src/state/store.rs @@ -100,6 +100,9 @@ pub struct DbStats { pub events_fetched: u64, /// Time spent waiting on statements. pub db_time: Duration, + /// Time spent building events from rows: parsing the JSON and computing + /// the event IDs. + pub parse_time: Duration, } /// A [`StateResStore`] reading Postgres through the native driver. @@ -119,6 +122,7 @@ pub struct PostgresStateResStore { rows: AtomicU64, events_fetched: AtomicU64, db_nanos: AtomicU64, + parse_nanos: AtomicU64, } /// How many event IDs to send per event-loading statement. @@ -148,6 +152,7 @@ impl PostgresStateResStore { rows: AtomicU64::new(0), events_fetched: AtomicU64::new(0), db_nanos: AtomicU64::new(0), + parse_nanos: AtomicU64::new(0), }; // If this fails, dropping the store sends a ROLLBACK, which is // harmless outside a transaction. @@ -176,6 +181,7 @@ impl PostgresStateResStore { rows: self.rows.load(Ordering::Relaxed), events_fetched: self.events_fetched.load(Ordering::Relaxed), db_time: Duration::from_nanos(self.db_nanos.load(Ordering::Relaxed)), + parse_time: Duration::from_nanos(self.parse_nanos.load(Ordering::Relaxed)), } } @@ -233,11 +239,14 @@ impl StateResStore for PostgresStateResStore { for batch in ids.chunks(EVENT_BATCH_SIZE) { let batch: Vec<&str> = batch.iter().map(|id| &**id).collect(); let rows = self.query(LOAD_EVENTS_SQL, &[&batch]).await?; + let start = Instant::now(); for row in rows { if let Some((event_id, event)) = event_from_row(&row)? { events.insert(event_id, StateResEvent::from_rust(event)?); } } + self.parse_nanos + .fetch_add(start.elapsed().as_nanos() as u64, Ordering::Relaxed); } self.events_fetched .fetch_add(events.len() as u64, Ordering::Relaxed); diff --git a/synapse/synapse_rust/state.pyi b/synapse/synapse_rust/state.pyi index 7b1b3f7c2f..1ecd8eaf01 100644 --- a/synapse/synapse_rust/state.pyi +++ b/synapse/synapse_rust/state.pyi @@ -27,6 +27,7 @@ class StateResStats: total_time: float db_time: float + parse_time: float cpu_time: float sort_time: float auth_time: float