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

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

Open Xiretza opened this issue 1 year ago • 10 comments

Description

We have just experienced a state reset in the newly upgraded #rust:matrix.org (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

{
    "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

{
  "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

{
    "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

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: <FrozenEventV3 event_id=$I4x3asUzJGjzdhCarvVwzgV3S7qboSYC0U_yYML8Roo, type=m.room.member, state_key=@kaplan:matrix.org, outlier=False>
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: [<FrozenEventV3 event_id=$43Qzc0IWd7svVtPb2g7kBB1TdLitBdwNANmZECGVxp0, type=m.room.member, state_key=@k900:0upti.me, outlier=False>]. 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 <FrozenEventV3 event_id=$I4x3asUzJGjzdhCarvVwzgV3S7qboSYC0U_yYML8Roo, type=m.room.member, state_key=@kaplan:matrix.org, outlier=False> against room state before the event: 403: @k900:0upti.me not in room !rmJmWEyNJNeBFfzLyh:xiretza.xyz.

The event $I4x3asUzJGjzdhCarvVwzgV3S7qboSYC0U_yYML8Roo:

{
    "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

Jan 17 '24 19:01 Xiretza

synapse synapse copied to clipboard

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

Description

Steps to reproduce

Homeserver

Synapse Version

Installation Method

Database

Workers

Platform

Configuration

Relevant log output

Anything else that would be useful to know?

synapse
synapse copied to clipboard