Introduced in: #19473
Noticed in:
https://github.com/element-hq/synapse/pull/19556#discussion_r3505783541
I have not experienced the bug in the real world, it's just something I
noticed by reading.
--
Fix bug in `_prune_device_lists_changes_in_room` when transaction is
retried
The `nonlocal` variable is a footgun as it increments the counter even
though the transaction did not commit yet and may still be retried.
---------
Signed-off-by: Olivier 'reivilibre <oliverw@matrix.org>
If presence is disabled after having been enabled, the presence states
in the database (and hence on clients) are frozen at whatever they were
when presence was last enabled: nothing writes to the presence stream
any more and /sync omits the presence section entirely, so clients show
the old presence states forever.
Fix this in two parts:
1. At startup, if presence is disabled but the database still contains
non-offline presence states, the presence writer sends out one final
round of updates marking those users as offline.
2. /sync no longer unconditionally omits presence when presence is
disabled: incremental syncs whose since token is behind the presence
stream still get the straggling updates. As the stream doesn't advance
while presence is disabled, clients catch up once and the check then
short-circuits to a token comparison.
Remote servers already handle this themselves by timing out our users
([`FEDERATION_TIMEOUT`](https://github.com/element-hq/synapse/blob/4d8905a15a417ed0054ec2533d243932d890bbbd/synapse/handlers/presence.py#L194-L198)),
so no federation changes are needed.
Note that this only fixes the issue if presence is fully disabled. If
set to `untracked` we still have the same issue, however since modules
would still write to presence we can't just clobber everything like we
do in this patch.
This does two things, first it adds a config flag to ignore rooms for
the purposes of presence routing.
Secondly, it changes the caching behaviour to try and improve the cache
hit ratio. Previously, the size of the `do_users_share_a_room` cache
(which stores pairs of users) needs to `O(n²)` for the number of online
users, which is infeasible for large servers.
Instead, we call `get_users_in_room` for both the syncing and updated
users. This sounds more expensive, but a) we will already have cached
the syncing user's rooms, and b) we will only calculate the updated
user's rooms once (rather than once per syncing user).
---------
Co-authored-by: Claude Fable 5 <noreply@anthropic.com>
- Impose limit of scheduled delayed events
- Update error codes to match latest draft of MSC4140
---------
Co-authored-by: Eric Eastwood <madlittlemods@gmail.com>
Sync workers proxied a full `ReplicationPresenceSetState` call to the
presence writer on every sync request with `affect_presence=True` (via
`user_syncing`), and a `ReplicationBumpPresenceActiveTime` call on every
user action, even though the writer's presence timers only need feeding
every `SYNC_ONLINE_TIMEOUT` / `LAST_ACTIVE_GRANULARITY`. On busy clients
this amounts to tens of no-op replication calls per user per minute, and
the resulting per-update work is the dominant CPU cost on saturated
presence writers.
Track the last relayed `(state, timestamp)` per `(user, device)` on the
worker and suppress unchanged sync-driven repeats within a 25s relay
interval - deliberately below `SYNC_ONLINE_TIMEOUT` (30s) so the
writer's device `last_sync_ts`/`last_active_ts` timers stay fed and
users neither flap offline nor bounce `currently_active`. Genuine state
changes are relayed immediately, explicit (non-sync) set_state calls
always go through and reset the throttle, bumps that might un-idle a
device bypass it, and entries are evicted when a `USER_SYNC` stop is
sent so reconnecting devices are relayed afresh.
This gives the writer-CPU benefit that deployments currently obtain by
tightening `rc_presence` to ~1/29s, without dropping real presence
transitions.
---------
Co-authored-by: Claude Fable 5 <noreply@anthropic.com>
Co-authored-by: Quentin Gliech <quenting@element.io>
A handful of places in the storage layer bound a value whose Python type
didn't match the declared column type — an `int` into a `TEXT` column,
or a `str` into a `BIGINT` column — and relied on psycopg2's loose
coercion to paper over the mismatch. These are latent correctness bugs:
they only work because the driver silently converts, and a stricter
driver that binds typed parameters rejects them outright.
Found during a Rust port of the database pool where the driver does not
coerce automatically.
Each fix binds the value with the type the column actually declares,
rather than depending on driver-specific coercion. All changes are
behaviour-preserving on psycopg2 and sqlite.
There is also a fix to the multi-writer id-gen tests where we forgot to
commit. This is tangential, but was found during the same effort.
### Changes
- **`device_lists_remote_extremeties.stream_id (TEXT)`** —
`_update_remote_device_list_cache_txn` (typed `stream_id: int`) bound an
int; store it as a string, matching the column and the sibling
`_update_remote_device_list_cache_entry_txn` (typed `stream_id: str`).
The old mismatch, when rejected, was swallowed inside the device-list
resync and hung `query_devices`.
- **`user_filters.filter_id (BIGINT)`** — `get_user_filter` bound the
raw `int | str` (a string, from sync requests). It already validates via
`int(filter_id)`; bind that int so it matches the column.
- **`rejections.last_check (TEXT)`** — both writers stored
`clock.time_msec()` (an int); store the timestamp as a string.
- **user-directory temp position** — the `populate_user_directory`
background update's staging column
`_temp_populate_user_directory_position.position` was `TEXT` but held an
int (read back into a `BIGINT` column). Declare it `BIGINT`. The temp
table is created and dropped within the background update, so there's no
migration.
- **`test_batched_state_group_storing`** — selected from
`state_group_edges` with a stringified `state_group`; bind the int
directly (the column is an integer).
- **Multi-writer id-generator tests** — constructing a
`MultiWriterIdGenerator` prunes stale `stream_positions` rows, but the
harness never committed, so the cleanup only survived because adbapi
keeps one connection per thread with its transaction open. Commit after
construction so it persists regardless of pool semantics (the delete is
legitimate work that should be committed anyway).
This speeds up the cascading delete from
`sliding_sync_connection_positions`, which without an index on
`connection_position` requires a sequential scan of the whole table for
each deleted position.
Co-authored-by: Claude Opus 4.8 <noreply@anthropic.com>
Adds `last_active_granularity`, `sync_online_timeout` and `idle_timeout`
options to the `presence` config section, controlling the previously
hard-coded `LAST_ACTIVE_GRANULARITY`, `SYNC_ONLINE_TIMEOUT` and
`IDLE_TIMER` constants (which remain as the defaults).
This is mainly useful on deployments that ratelimit how often syncs can
affect presence (`rc_presence`): the sync timeout must exceed the
ratelimit interval or users flap offline between syncs, so tuning down
presence traffic currently requires squeezing under the fixed 30s limit.
---------
Co-authored-by: Claude Fable 5 <noreply@anthropic.com>
Fix https://github.com/element-hq/synapse/issues/19907
The flake manifested as a failure pointing at
`TestMessagesOverFederation/Backfill_from_nearby_backward_extremities_past_token`
but was actually caused by some cross-test pollution from an earlier
test (`TestOIDCProviderUnavailable`) causing some workers to be
temporarily unavailable.
As explained in
https://github.com/element-hq/synapse/issues/19907#issuecomment-4917362461,
> ### Cross-test pollution
>
> When I point an LLM at the logs, it points to
`TestOIDCProviderUnavailable` being the culprit because of the server
restarts polluting this test. When this flake happens, we can indeed see
that `TestOIDCProviderUnavailable` runs before
`TestMessagesOverFederation`.
>
> ```
> PASS TestEventBetweenMakeJoinAndSendJoinIsNotLost 15.08s
> PASS TestFederation/parallel/HS2_->_HS1 1.5s
> PASS TestFederation/parallel/HS1_->_HS2 1.51s
> PASS TestFederation/parallel 0s
> PASS TestFederation 15.12s
> PASS TestOIDCProviderUnavailable//login/sso/redirect_shows_HTML_error
0.02s
> PASS TestOIDCProviderUnavailable 8.62s
> FAIL
TestMessagesOverFederation/Backfill_from_nearby_backward_extremities_past_token
0.89s
> FAIL TestMessagesOverFederation 1.1s
> PASS TestSynapseVersion/Synapse_version_matches_current_git_checkout
0.97s
> PASS TestSynapseVersion 0.97s
> ```
>
> The pollution happens because we enable
[`COMPLEMENT_ENABLE_DIRTY_RUNS`](https://github.com/element-hq/synapse/blob/c63d77a79d7157f26f849684520ba9e99f4d07c0/scripts-dev/complement.sh#L309-L311)
([docs](https://github.com/matrix-org/complement/blob/0e6f8552ff0c99fddb97222399efed3e1f0cb91a/ENVIRONMENT.md#complement_enable_dirty_runs))
which means Complement will reuse deployments (shares homeservers
between tests).
>
> During the `TestOIDCProviderUnavailable` test, there are some stray
federation requests that hit the homeserver while it's still booting
which marks the nginx upstream as unavailable for 10 seconds. nginx has
a default of
[`max_fails=1`](https://nginx.org/en/docs/http/ngx_http_upstream_module.html#max_fails)
and
[`fail_timeout=10s`](https://nginx.org/en/docs/http/ngx_http_upstream_module.html#fail_timeout).
Then when `TestMessagesOverFederation` starts, we're still in the 10
second unavailable window and nginx doesn't even try to connect at all.
>
> <details>
> <summary>LLM summary of the logs and how this happens in
practice</summary>
>
> 1. **19:52:10–11** — the previous federation test finishes:
`user-3:hs2` does a faster-join (`send_join?omit_members=true`) to
`!YnyCRpCLIpimppIreR:hs1`, so `hs2` kicks off a
`sync_partial_state_room` background resync that is still running when
the test ends.
> 2. **19:52:11.6** — `TestOIDCProviderUnavailable` starts and calls
`deployment.StopServer(t, "hs1")` / `StartServer`
(`complement/tests/oidc_test.go:78-80`) to apply an OIDC config
fragment. `hs1` gets `SIGTERM`; new supervisord at 19:52:13.3. `hs2` is
not restarted and keeps retrying its unfinished work.
> 3. **19:52:14** — `hs1`'s nginx is up, but the Synapse workers aren't:
`federation_inbound` only listens on `18015` at 19:52:18.7,
`federation_reader` on `18016` at 19:52:19.0.
> 4. **19:52:15–16** — `hs2`'s retries arrive in that gap: `PUT
/_matrix/federation/v1/send/…` → `18015` refused; `GET
/state_ids/!YnyCRpCLIpimppIreR:hs1` → `18016` refused. With nginx
defaults (`max_fails=1`, `fail_timeout=10s`) and only one server per
upstream block, both upstreams are now marked down until ~19:52:25/26.
(Side casualty: `hs2`'s partial-state resync gives up — "We can't get
valid state history" — and puts `hs1` on a 10-minute federation
backoff.)
> 5. **19:52:21.5** — the failing test's `make_join` for
`@user-5-bob:hs2` reaches `hs1`'s nginx → `no live upstreams` → `502` →
the join fails, even though the worker has been listening for 2.5
seconds by then.
> 6. **19:52:22** — `TestSynapseVersion`'s `GET
/_matrix/federation/v1/version` hits the same dead upstream → `502` → it
fails too.
>
> So it's a flake caused by a race between the OIDC test's container
restart, hs2's background federation retries, and nginx's passive
health-check — not anything wrong with the backfill logic under test.
>
> </details>
>
>
> We can indeed confirm this suspicion with these logs
>
> ❌https://github.com/element-hq/synapse/actions/runs/28888070856/job/85701936736
(archive:
[85701936736.log](https://github.com/user-attachments/files/29809986/85701936736.log)):
> ```
> Error: 2026/07/07 19:52:20 [error] 34#34: *1 no live upstreams while
connecting to upstream, client: 172.18.0.3, server: localhost, request:
"PUT /_matrix/federation/v1/send/1783453927718 HTTP/1.1", upstream:
"http://federation_inbound/_matrix/federation/v1/send/1783453927718",
host: "hs1"
> ...
>
> Error: 2026/07/07 19:52:21 [error] 33#33: *4 no live upstreams while
connecting to upstream, client: 172.18.0.3, server: localhost, request:
"GET
/_matrix/federation/v1/make_join/%21scAbyTQDdaauGYicpU%3Ahs1/%40user-5-bob%3Ahs2?ver=1&ver=2&ver=3&ver=4&ver=5&ver=6&ver=7&ver=8&ver=9&ver=10&ver=11&ver=12&ver=org.matrix.msc3757.10&ver=org.matrix.msc3757.11&ver=org.matrix.hydra.11
HTTP/1.1", upstream:
"http://federation_reader/_matrix/federation/v1/make_join/%21scAbyTQDdaauGYicpU%3Ahs1/%40user-5-bob%3Ahs2?ver=1&ver=2&ver=3&ver=4&ver=5&ver=6&ver=7&ver=8&ver=9&ver=10&ver=11&ver=12&ver=org.matrix.msc3757.10&ver=org.matrix.msc3757.11&ver=org.matrix.hydra.11",
host: "hs1"
> ```
>
> The fix here would be to disable nginx's unavailable upstream behavior
by configuring `max_fails=0` in the upstream block:
https://github.com/element-hq/synapse/blob/c63d77a79d7157f26f849684520ba9e99f4d07c0/docker/configure_workers_and_start.py#L374-L378
`test_lock_contention` is a performance-regression canary (#16840): the
pathological behaviour it guards against spent ~30s spinning the CPU, vs
~0.5s when healthy. The 5s wall-clock alarm it used was calibrated on
SQLite, but against PostgreSQL a healthy run already takes 3-4s of
wall-clock time (500 sequential acquire/release cycles, each a real
database round-trip), so any CI load pushed it over the limit.
Add a `cpu_time` mode to `tests/utils.py`'s test_timeout, implemented
with
[`setitimer(ITIMER_PROF)`](https://docs.python.org/3/library/signal.html#signal.setitimer),
which budgets process CPU time instead of wall-clock time. Time spent
blocked on the database or lost to a loaded CI runner no longer counts,
while a regression to CPU-spinning still trips the alarm mid-spin. A
healthy run costs <1s of CPU on either database engine; the budget is
10s.
This also subsumes the RISC-V wall-clock carve-out from #18430, which is
removed.
---------
Co-authored-by: Claude Fable 5 <noreply@anthropic.com>
This is a stepping stone before we can go full Rust everywhere. We're
providing a generic interface as we want database access to work in
Synapse and `synapse-rust-apps`. In `synapse-rust-apps`, we will use a
`tokio-postgres` based database connection pool so it's full Rust.
We want to avoid the situation where we have two database connection
pools (one for Python, one for Rust) as we've run into connection
exhaustion problems on Matrix.org before.
As an example of using it and sanity check for all this work (including
tests), I've also ported over the `/versions` handler to the Rust side
with database access. The `/versions` endpoint is the simplest endpoint
I could find that still had some database access. Hopefully the refactor
on `/versions` isn't that controversial as it's not really the point of
this PR. We can always remove it from this PR but it's just here as a
sanity check that all of this works.
### Why `runInteraction(...)`?
Using the same `runInteraction` pattern that we already have in Synapse
means we can port over existing Synapse code/endpoints without much
thought. But this pattern also makes sense because we want[^1]
transactions to have repeatable-read isolation (easy to think about,
less foot-guns). Having everything thappen in a function callback means
we can do retries for serialization/deadlock errors.
[^1]: To note: Ideally, we'd want the least isolation possible but the
problem is that there is no tooling to yell at you when your
queries/logic is wrong so repeatable-read isolation is a great balance.
> When an application receives this error message, it should abort the
current transaction and retry the whole transaction from the beginning.
The second time through, the transaction will see the
previously-committed change as part of its initial view of the database,
so there is no logical conflict in using the new version of the row as
the starting point for the new transaction's update.
>
> Note that only updating transactions might need to be retried;
read-only transactions will never have serialization conflicts.
>
> *--
https://www.postgresql.org/docs/current/transaction-iso.html#XACT-REPEATABLE-READ*
As a note, this strategy is less of an impedance mismatch (aligns more
closely) with Synapse so the glue code for the `python_db_pool` should
also be simpler.
### How does this interact with logcontext (`LoggingContext`)?
See [docs on log
contexts](https://github.com/element-hq/synapse/blob/4e9f7757f17ba81b8747b7f8f9646d17df145aa3/docs/log_contexts.md)
for more background.
We already support normal logging from Rust -> Python with `pyo3-log`
and `log` but as soon as we pass a thread boundary, everything is logged
against the `sentinel` log context. Normally, we want logs and CPU/DB
usage correlated with the request that spawned the work.
You can see how I took a stab at fixing this in
https://github.com/element-hq/synapse/pull/19846 by capturing the
logcontext in a Tokio task local and re-activating as necessary. For
example, in that PR, I reactivated the logcontext in
`run_python_awaitable(...)` which we use to call `runInteraction(...)`
from the Rust side which means all of the database usage is correlated
with the request as expected. It also means any `log:info!(...)` done in
`run_interaction(...)` is correlated correctly. But there needs to be a
better story for when you want to log everywhere else.
I haven't explored tracking CPU usage on the Rust side.
I've left all of this out of this PR as I think it will be better to
tackle this as a dedicated follow-up. For example, I'm thinking about
instead creating a new `LoggingContext` with the `parent_context` set to
the calling context and try to avoid needing to call
`set_current_context(...)` on the Python side where possible (like
tracking CPU).
### Testing strategy
Added some tests that exercise some `async` Rust handlers for the
`/versions` endpoint:
```
SYNAPSE_TEST_LOG_LEVEL=INFO poetry run trial tests.rest.client.test_versions.VersionsTestCase
```
Real-world:
1. `poetry run synapse_homeserver --config-path homeserver.yaml`
1. `GET http://localhost:8008/_matrix/client/versions`
The port of event serialization to Rust (#19837) removed
`format_event_raw`, `format_event_for_client_v1`,
`format_event_for_client_v2` and
`format_event_for_client_v2_without_room_id` from
`synapse.events.utils`, but there are modules in the wild that import
them from there.
Reimplement them as standalone pyfunctions in Rust, operating directly
on the Python dict so the original semantics are preserved exactly
(in-place mutation, returning the same dict, arbitrary non-JSON values
passing through, KeyError on a missing `unsigned` in the v1 format), and
re-export them from `synapse.events.utils`.
---------
Co-authored-by: Claude Fable 5 <noreply@anthropic.com>
### Summary
This moves the synchronous core of client event serialization out of
`synapse/events/utils.py` and into Rust
(`rust/src/events/serialize.rs`).
Event serialization is on the hot path for `/sync`, `/messages`, and
most client-facing endpoints. Previously it was a recursive pure-Python
routine (`_serialize_event` / `_inject_bundled_aggregations` /
`only_fields`) that interleaved
CPU-bound formatting with `async` DB/IO. This PR separates those two
concerns and moves the CPU-bound half to Rust:
- **Async prep stays in Python.**
`EventClientSerializer._prepare_serialization` does all DB/IO up front:
batch-fetching redaction events and running the registered module
`unsigned`-callback hooks, for the top-level events *and* every bundled
sub-event (edits and thread latest events, which are themselves
serialized). The admin/MSC4354 config is resolved once via
`_update_config`, rather than re-checked on every recursive call as the
old code did.
- **The synchronous core moves to Rust.** Given an event plus the
pre-fetched `redaction_map`, `unsigned_additions`, and
`bundle_aggregations`, the Rust code produces the client JSON entirely
in Rust — including the v1/v2 format transforms, `only_event_fields`
filtering, redaction handling, and recursive bundled aggregations.
### Details
- The Rust entry point is a single batch function, `serialize_events`,
taking a list of `(event, membership)` pairs. The three lookup maps are
shared across the whole batch, so they're read out of Python and
converted to Rust
structures **once** per batch rather than once per event.
`EventClientSerializer.serialize_event` (singular) is a thin wrapper
that calls it with a one-element list.
- `SerializeEventConfig` is now a Rust `pyclass`, and the old
`event_format` callable is replaced by the `EventFormat` enum (`Raw` /
`ClientV1` / `ClientV2` / `ClientV2WithoutRoomId`). Call sites in
`rest/admin/events.py` and
`rest/client/{notifications,room,sync}.py` are updated to pass the enum.
`make_config_for_admin` and MSC4354 enablement now go through
`SerializeEventConfig.for_admin()` / `with_msc4354()`.
- New accessors on `EventInternalMetadata` (`redacted_by`, `txn_id`,
`device_id`, `token_id`, `delay_id`, `soft_failed`,
`policy_server_spammy`) expose to Rust the fields the serializer reads.
- The `_split_field` unit tests move from `tests/events/test_utils.py`
to a Rust test in `serialize.rs`, since the implementation moved.
### Behaviour
This is intended to be a behaviour-preserving refactor — the Rust core
mirrors the previous Python output (field ordering, v1 key promotion,
redaction placement per room version, null-`redacts` handling,
transaction-ID gating).
Existing serialization, relations, and sync tests pass unchanged.
---------
Co-authored-by: Claude Opus 4.8 <noreply@anthropic.com>
Co-authored-by: Eric Eastwood <madlittlemods@gmail.com>
Co-authored-by: Eric Eastwood <erice@element.io>
Speeds up finding and deleting expired sliding sync connections in
`delete_old_sliding_sync_connections`, which previously required a
sequential scan.
On matrix.org I have a suspicion that this might end up blocking some
SSS connections during the delete, which can take minutes. Specifically,
I think the deletion blocks this delete:
https://github.com/element-hq/synapse/blob/ff19c034d300869e64878a15aed9a97f1cec59e4/synapse/storage/databases/main/sliding_sync.py#L233-L241
We didn't previously have an index because we wanted the postgres HOT
updates, however we also limit the update frequency to once every 5
minutes, so hopefully this is fine.
---------
Co-authored-by: Claude Opus 4.8 <noreply@anthropic.com>
