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

[Xiretza]

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

[Xiretza]

Since we haven't found any way to debug this, and opening an issue here is probably akin to shouting into the void, we've tombstoned the room yet again and made a new one. The old one is still there and still broken, if anyone has any suggestions for debugging, I'm all ears (ping @xiretza:xiretza.xyz).

[reivilibre]

we've tombstoned the room yet again and made a new one

I'm afraid this was probably the right/pragmatic move, but sorry for the trouble all the same.
Staffing is very tricky at the moment.