element-hq / element-hq/synapse
Performance regression since 1.147.0: Tight loop in `_get_new_state_after_events` causes ~5× CPU increase via race condition during event de-outliering
- Dominant language
- Python
- Stars
- 4.6k
- Forks
- 600
- Avg merge
- 5d 22h
- Merged PRs (30d)
- 51
Description
## Summary
Since upgrading from **1.146.x** to **1.147.0**, CPU usage has risen from **~5%** to **~25%** on a 4-core server. The root cause is a race condition in `_get_new_state_after_events` that triggers a tight event-persistence retry loop affecting any large federated room that receives events with missing `prev_events`.
---
## Symptoms
- **CPU load:** 5% → 25% (4 cores) after upgrade to 1.147.0
- **PostgreSQL** `pg_stat_user_tables` shows `state_groups_persisting` being seq-scanned **12.6 times/second** with **0 live rows** — a clear tight-loop signature
- **418 tracebacks** in `homeserver.log` since last stats reset (4 days)
- `federation_transaction_transmission_loop` counter reaches **378,000+ iterations**
- Constant `_process_new_pulled_events_with_failed_pull_attempts` background process exceptions
---
## Stack Trace
```
File "synapse/storage/controllers/persist_events.py", line 435, in persist_events
File "...", line 430, in enqueue
File "...", line 251, in add_to_queue
File "...", line 294, in handle_queue_loop
File "...", line 376, in _process_event_persist_queue_task
File "...", line 637, in _persist_event_batch
File "...", line 746, in _calculate_new_forward_extremities_and_state_delta
File "...", line 940, in _get_new_state_after_events
event_id_to_state_group[evid] for evid in old_latest_event_ids
KeyError: '$CUUA3u0Bi52j-5EV74WCyBD2vgFOmei9K79XgZbiHGU'
The above exception was the direct cause of the following exception:
Exception: Error fetching missing prev_events for $zHaFKG9...
```
---
## Root Cause Analysis
In `_get_new_state_after_events` (`persist_events.py`):
```python
missing_event_ids = set(old_latest_event_ids) # ← all old extremities go here
# ... fetch new extremities from context or DB ...
if missing_event_ids:
event_to_groups = await self.main_store._get_state_group_for_events(
missing_event_ids
)
event_id_to_state_group.update(event_to_groups)
old_state_groups = {
event_id_to_state_group[evid] # ← KeyError if evid missing!
for evid in old_latest_event_ids
}
```
### Race Condition Step-by-Step
1. Event X arrives via federation with missing `prev_events`
2. Synapse fetches and stores the missing events as **outliers**
3. During de-outliering, event Y becomes a new **forward extremity**
4. A concurrent persistence attempt queries `event_to_state_groups` for event Y
5. The `INSERT INTO event_to_state_groups` for event Y has **not committed yet** (it is being written as part of the de-outlier transaction)
6. `_get_state_group_for_events` returns an incomplete mapping (in 1.147.0) or raises `RuntimeError` (in 1.147.1 after the hardening fix)
7. Either way, **persistence fails** for the room
8. The failed event is re-queued in `failed_pull_attempts`
9. `_process_new_pulled_events_with_failed_pull_attempts` retries → same failure
10. **→ Tight retry loop** that continuously scans `state_groups_persisting`
> **Note:** The affected event `$CUUA3u0Bi52j...` is *not* an outlier in the DB (`outlier=false`, `state_group=1182141`), confirming the state group was eventually written — but too late for the concurrent persistence attempt.
---
## Database Evidence
`state_groups_persisting`: **4.3M seq_scans** in 4 days on a table with **0 live rows** = 12.62 scans/second → tight polling loop.
```sql
SELECT relname, seq_scan, n_live_tup,
round(seq_scan::numeric / 345600, 2) AS scans_per_sec
FROM pg_stat_user_tables
WHERE relname = 'state_groups_persisting';
-- state_groups_persisting | 4361559 | 0 | 12.62
```
---
## Suggested Fix
### Option A – Guard against missing state groups
```python
event_to_groups = await self.main_store._get_state_group_for_events(
missing_event_ids, allow_missing=True # new parameter
)
event_id_to_state_group.update(event_to_groups)
# Only include old extremities that have a known state group
old_state_groups = {
event_id_to_state_group[evid]
for evid in old_latest_event_ids
if evid in event_id_to_state_group # ← guard
}
```
### Option B – Ensure commit ordering
Ensure that a de-outliered event's `event_to_state_groups` row is committed (via `RETURNING` or a separate read-after-write) **before** the event is added to the room's forward extremities.
---
## Workaround
**None confirmed.** Restarting Synapse provides temporary relief if the retry queue empties, but the problem recurs on the next batch of federation events with missing `prev_events` in the affected room.
---
## Related Issues
- [[#9260](https://github.com/element-hq/synapse/issues/9260)](https://github.com/element-hq/synapse/issues/9260) – *"Unable to leave a certain room (KeyError)"*
### Steps to reproduce
1. Run Synapse 1.147.0 or 1.147.1 as a single-process homeserver
2. Join a large federated room with many servers and members
3. Wait for federation events with missing `prev_events` to arrive
4. Observe `KeyError` tracebacks in `homeserver.log` and rising CPU usage
### Homeserver
matrix.yourdevice.ch
### Synapse Version
1.147.1
### Installation Method
Debian packages from packages.matrix.org
### Database
Single PostgreSQL 14 on the same host, never migrated
### Workers
Single process
### Platform
Ubuntu 24.04 Server
### Configuration
_No response_
### Relevant log output
```shell
File "synapse/storage/controllers/persist_events.py", line 940, in _get_new_state_after_events
event_id_to_state_group[evid] for evid in old_latest_event_ids
KeyError: '$CUUA3u0Bi52j-5EV74WCyBD2vgFOmei9K79XgZbiHGU'
```
### Anything else that would be useful to know?
_No response_
Contributor guide
Assessment
This issue has not been assessed yet.