element-hq / element-hq/synapse

State reset in #rust:matrix.org (room version 10)

Open
#16,825 17 comments 6 reactions 0 assignees View on GitHub
A-State-Resolution O-Occasional S-Major T-Defect
Dominant language
Python
Stars
4.6k
Forks
600
Avg merge
5d 22h
Merged PRs (30d)
51

Description

### Description

We have just experienced a state reset in the newly upgraded [#rust:matrix.org](https://matrix.to/#/!rmJmWEyNJNeBFfzLyh:xiretza.xyz?via=computer.surgery&via=matrix.org&via=xiretza.xyz) (room version 10). These are all the `m.room.join_rules` events in the room:

```
synapse=# SELECT * FROM events WHERE room_id = '!rmJmWEyNJNeBFfzLyh:xiretza.xyz' AND type = 'm.room.join_rules' ORDER BY depth;
topological_ordering | event_id | type | room_id | content | unrecognized_keys | processed | outlier | depth | origin_server_ts | received_ts | sender | contains_url | instance_name | stream_ordering | state_key | rejection_reason
----------------------+----------------------------------------------+-------------------+---------------------------------+---------+-------------------+-----------+---------+-------+------------------+---------------+-----------------------+--------------+---------------+-----------------+-----------+------------------
10 | $pkIC9wCS-hb8wcDJWqoAmrZDr0bQULaqGvNDwtWjhws | m.room.join_rules | !rmJmWEyNJNeBFfzLyh:xiretza.xyz | | | t | f | 10 | 1705313193913 | 1705313194290 | @xiretza:xiretza.xyz | f | master | 5523323 | |
562 | $yRR415bJULHyipJnf1KIyVFvgX0TtDA0_G3NoYHP6p4 | m.room.join_rules | !rmJmWEyNJNeBFfzLyh:xiretza.xyz | | | t | f | 562 | 1705315776319 | 1705315777172 | @ruma_mod:flipdot.org | f | master | 5524042 | |
565 | $N4ca1QfFRzW5T2r207Dc1RbmfE-KNFWl3RfRGbWlOPI | m.room.join_rules | !rmJmWEyNJNeBFfzLyh:xiretza.xyz | | | t | f | 565 | 1705316369263 | 1705316369330 | @xiretza:xiretza.xyz | f | master | 5524086 | |
567 | $wZf26aec3qefZJTf88ggSS9nxEDY3V1pZeWhfrSzMF8 | m.room.join_rules | !rmJmWEyNJNeBFfzLyh:xiretza.xyz | | | t | f | 567 | 1705316380899 | 1705316381730 | @ruma_mod:flipdot.org | f | master | 5524092 | |
571 | $Wr-cCbrzPfxhd5KEx6EpK2Xr9UlKawMjxn-VK2U-tHY | m.room.join_rules | !rmJmWEyNJNeBFfzLyh:xiretza.xyz | | | t | f | 571 | 1705316419468 | 1705316419629 | @xiretza:xiretza.xyz | f | master | 5524105 | |
(5 rows)
```

- It was initially created as `public`

$pkIC9wCS-hb8wcDJWqoAmrZDr0bQULaqGvNDwtWjhws

```json
{
"type": "m.room.join_rules",
"depth": 10,
"hashes": {
"sha256": "czinN/Fu7oD/rY5kz5I7oVEpBqPxKfYAgEZTw0t+d+Y"
},
"origin": "xiretza.xyz",
"sender": "@xiretza:xiretza.xyz",
"content": {
"join_rule": "public"
},
"room_id": "!rmJmWEyNJNeBFfzLyh:xiretza.xyz",
"unsigned": {
"age_ts": 1705313193913
},
"state_key": "",
"signatures": {
"xiretza.xyz": {
"ed25519:a_xHzI": "py1E8KgeOx0HXSAqxqfMa1cb0k0axHnaqGhBkLlDlmwdRde+1FPKArrCJ7PRTwKT9un8AcziOQCb21r3GiFmDw"
}
},
"auth_events": [
"$44zEG_KubJAQt2i3dmEuyuLFwOTWLtzsSEZ4j9DCORw",
"$L29_VSvHx5ub38vFMKEH5rm992icCBeSqn6HoxGkJ00",
"$dpON2f4sQQdkBZsUgCoK0-qXGqgnSU_lC5hD7ypLtRU"
],
"prev_events": [
"$AgSJx8nwGtevC3zCSu6XuY_s_SbefGUktxVKq1cfBOg"
],
"origin_server_ts": 1705313193913
}
```

- It was then set private by the overeager moderation bot `@ruma_mod:flipdot.org` (`$yRR415bJULHyipJnf1KIyVFvgX0TtDA0_G3NoYHP6p4`) and immediately made public again (`$N4ca1QfFRzW5T2r207Dc1RbmfE-KNFWl3RfRGbWlOPI`)
- The bot hadn't had enough and made it private *again*:

$wZf26aec3qefZJTf88ggSS9nxEDY3V1pZeWhfrSzMF8

```json
{
"type": "m.room.join_rules",
"depth": 567,
"hashes": {
"sha256": "gUC4IsLZ7+mTdkJsznIBtEY2CaPq933ve39Te7TOr/E"
},
"origin": "flipdot.org",
"sender": "@ruma_mod:flipdot.org",
"content": {
"join_rule": "invite"
},
"room_id": "!rmJmWEyNJNeBFfzLyh:xiretza.xyz",
"unsigned": {
"replaces_state": "$N4ca1QfFRzW5T2r207Dc1RbmfE-KNFWl3RfRGbWlOPI"
},
"state_key": "",
"signatures": {
"flipdot.org": {
"ed25519:a_gJzK": "CbZhADyF3EksrCv11k2YDJM2kn25P/5ZRXXSQyi0UIEsVvSNzB6FgSNbyvgYnZ3auEAfittla3+b2PzmJqDjCA"
}
},
"auth_events": [
"$L29_VSvHx5ub38vFMKEH5rm992icCBeSqn6HoxGkJ00",
"$MMT8cHk32dWVtcfpT_wuODNeodIDkjx7ipUSGDvKyVU",
"$sLcf5E0Jdk8htF2LVXAIRFy849ViT5E1b_Ai-g1OlG4"
],
"prev_events": [
"$QUlbCxG_-UrNZLfzEa6Q_Bve-BcpLaCSu1VmW-S6oHQ"
],
"origin_server_ts": 1705316380899
}
```

- The bot was tamed and the room was made public again:

$Wr-cCbrzPfxhd5KEx6EpK2Xr9UlKawMjxn-VK2U-tHY

```json
{
"type": "m.room.join_rules",
"depth": 571,
"hashes": {
"sha256": "z8JTidXIVtdNz+i8q45NGbsku5C8fSiU3JLiJ4pXOWg"
},
"origin": "xiretza.xyz",
"sender": "@xiretza:xiretza.xyz",
"content": {
"join_rule": "public"
},
"room_id": "!rmJmWEyNJNeBFfzLyh:xiretza.xyz",
"unsigned": {
"age_ts": 1705316419468,
"replaces_state": "$wZf26aec3qefZJTf88ggSS9nxEDY3V1pZeWhfrSzMF8"
},
"state_key": "",
"signatures": {
"xiretza.xyz": {
"ed25519:a_xHzI": "rFgSIbG/1Ma+fHMhzLFae8A3fQp3B/7eeRWEZ7pff8m+vcZq1wMMQIlyj9t+3tEwhNxLR53z9FWi+x+BesqeDA"
}
},
"auth_events": [
"$44zEG_KubJAQt2i3dmEuyuLFwOTWLtzsSEZ4j9DCORw",
"$L29_VSvHx5ub38vFMKEH5rm992icCBeSqn6HoxGkJ00",
"$MMT8cHk32dWVtcfpT_wuODNeodIDkjx7ipUSGDvKyVU"
],
"prev_events": [
"$Kx2u0YC1neFX7hK-2mzv2qp_yJuNzZtFBEChlbkzXjE"
],
"origin_server_ts": 1705316419468
}
```

The problem is that the very last state event (`$Wr-cCbrzPfxhd5KEx6EpK2Xr9UlKawMjxn-VK2U-tHY`) was first accepted, then reset back to `$wZf26aec3qefZJTf88ggSS9nxEDY3V1pZeWhfrSzMF8`:

```
synapse=# SELECT * FROM current_state_delta_stream WHERE room_id = '!rmJmWEyNJNeBFfzLyh:xiretza.xyz' AND type = 'm.room.join_rules' ORDER BY stream_id ASC;
stream_id | room_id | type | state_key | event_id | prev_event_id | instance_name
-----------+---------------------------------+-------------------+-----------+----------------------------------------------+----------------------------------------------+---------------
5523316 | !rmJmWEyNJNeBFfzLyh:xiretza.xyz | m.room.join_rules | | $pkIC9wCS-hb8wcDJWqoAmrZDr0bQULaqGvNDwtWjhws | | master
5524042 | !rmJmWEyNJNeBFfzLyh:xiretza.xyz | m.room.join_rules | | $yRR415bJULHyipJnf1KIyVFvgX0TtDA0_G3NoYHP6p4 | $pkIC9wCS-hb8wcDJWqoAmrZDr0bQULaqGvNDwtWjhws | master
5524086 | !rmJmWEyNJNeBFfzLyh:xiretza.xyz | m.room.join_rules | | $N4ca1QfFRzW5T2r207Dc1RbmfE-KNFWl3RfRGbWlOPI | $yRR415bJULHyipJnf1KIyVFvgX0TtDA0_G3NoYHP6p4 | master
5524092 | !rmJmWEyNJNeBFfzLyh:xiretza.xyz | m.room.join_rules | | $wZf26aec3qefZJTf88ggSS9nxEDY3V1pZeWhfrSzMF8 | $N4ca1QfFRzW5T2r207Dc1RbmfE-KNFWl3RfRGbWlOPI | master
5524105 | !rmJmWEyNJNeBFfzLyh:xiretza.xyz | m.room.join_rules | | $Wr-cCbrzPfxhd5KEx6EpK2Xr9UlKawMjxn-VK2U-tHY | $wZf26aec3qefZJTf88ggSS9nxEDY3V1pZeWhfrSzMF8 | master
5534237 | !rmJmWEyNJNeBFfzLyh:xiretza.xyz | m.room.join_rules | | $wZf26aec3qefZJTf88ggSS9nxEDY3V1pZeWhfrSzMF8 | $Wr-cCbrzPfxhd5KEx6EpK2Xr9UlKawMjxn-VK2U-tHY | master
(6 rows)

synapse=# SELECT * FROM current_state_events WHERE room_id = '!rmJmWEyNJNeBFfzLyh:xiretza.xyz' AND type = 'm.room.join_rules';
event_id | room_id | type | state_key | membership | event_stream_ordering
----------------------------------------------+---------------------------------+-------------------+-----------+------------+-----------------------
$wZf26aec3qefZJTf88ggSS9nxEDY3V1pZeWhfrSzMF8 | !rmJmWEyNJNeBFfzLyh:xiretza.xyz | m.room.join_rules | | | 5524092
(1 row)
```

How can this happen? Why was it first accepted, then reset again?

### Steps to reproduce

Unknown. It was fine for a while, then everything fell apart.

### Homeserver

xiretza.xyz

### Synapse Version

1.98.0

### Installation Method

Other (please mention below)

### Database

single PostgreSQL server, migrated long ago (before this room existed), no backup restore

### Workers

Single process

### Platform

Arch Linux x86_64, Hetzner VM

### Configuration

Nothing out of the ordinary except for an unrelated appservice (https://github.com/mautrix/telegram)

### Relevant log output

```shell
Unfortunately it's been rotated out, the only thing I caught was this (an invite that was considered invalid by my HS because the inviting user's join was invalidated by the state reset):

Jan 17 08:38:05 matrix synapse[866918]: synapse.federation.federation_server: [_process_incoming_pdus_in_room_inner-60668] handling received PDU in room !rmJmWEyNJNeBFfzLyh:xiretza.xyz:
Jan 17 08:38:05 matrix synapse[866918]: synapse.handlers.federation_event: [_process_incoming_pdus_in_room_inner-60668-$I4x3asUzJGjzdhCarvVwzgV3S7qboSYC0U_yYML8Roo] event's auth_events are different to our calculated auth_events. Claimed but not calculated: []. Calculated but not claimed: []
Jan 17 08:38:05 matrix synapse[866918]: synapse.handlers.federation_event: [_process_incoming_pdus_in_room_inner-60668-$I4x3asUzJGjzdhCarvVwzgV3S7qboSYC0U_yYML8Roo] While checking auth of against room state before the event: 403: @k900:0upti.me not in room !rmJmWEyNJNeBFfzLyh:xiretza.xyz.
```

The event `$I4x3asUzJGjzdhCarvVwzgV3S7qboSYC0U_yYML8Roo`:

```json
{
"type": "m.room.member",
"depth": 1497,
"hashes": {
"sha256": "ooRpsb1zy/s0gIMbZRYOn91rzpMezeg8MVqQJUaZxbw"
},
"origin": "0upti.me",
"sender": "@k900:0upti.me",
"content": {
"is_direct": false,
"membership": "invite"
},
"room_id": "!rmJmWEyNJNeBFfzLyh:xiretza.xyz",
"unsigned": {
},
"state_key": "@kaplan:matrix.org",
"signatures": {
"0upti.me": {
"ed25519:qTw53QCu": "kUPI+Enir37bq5mDxEGiVpcOXSucAvB5r14cLKBW4ucWv6o8bbrX87WcscDHeutn00xLFu4DFxfIKs1t/IoaCw"
},
"matrix.org": {
"ed25519:a_RXGa": "6sfhtQSolw369A27VChah0SahTh6kD4xRL1j+alIQeI4QOiCjY0w/DHlEp/TuDlA5hiCrFz1ZrWKICPMRraoCg"
}
},
"auth_events": [
"$43Qzc0IWd7svVtPb2g7kBB1TdLitBdwNANmZECGVxp0",
"$MMT8cHk32dWVtcfpT_wuODNeodIDkjx7ipUSGDvKyVU",
"$L29_VSvHx5ub38vFMKEH5rm992icCBeSqn6HoxGkJ00",
"$wZf26aec3qefZJTf88ggSS9nxEDY3V1pZeWhfrSzMF8"
],
"prev_events": [
"$3AcINsCNEvEW6TEgbIa8kdVIRorNItfJnW-iEnsHwWw"
],
"origin_server_ts": 1705480685022
}
```

### Anything else that would be useful to know?

_No response_

Contributor guide

Open the contributing guide

Research direction

Start by tracing the federation.federation_server and handlers.federation_event paths mentioned in the logs, then compare the current_state_delta_stream and current_state_events records for the affected room. Determine why the final join-rules event was later replaced and identify a reproducible cause or required correction; the issue currently provides no reproduction steps or named test.

Written by the indexing model from the issue text.

Assessment

Tech stack
python
Domain
backend, databases, distributed-systems
Issue type
Bug
Difficulty
4/5
Estimated time
3-5 days
Activity status
Quiet
Clarity
Needs clarification
Newbie friendliness
35/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.