Issue joining rooms

This issue has been migrated from [#15863](https://github.com/matrix-org/synapse/issues/15863).

---

### Description

Joining rooms (issue happening on `#synapse:matrix.org`) results in an 500 internal server error.

### Steps to reproduce

- Attempt to jon `#synapse:matrix.org`
- Element will output "`MatrixError: [500] Internal server error (https://matrix.plus.st/_matrix/client/r0/join/!ehXvUhWNASUkSLvAGP%3Amatrix.org)`"

### Homeserver

plus.st

### Synapse Version

1.87.0rc1 (b=develop,13fc89148)

### Installation Method

Other (please mention below)

### Database

PostgreSQL

### Workers

Single process

### Platform

Arch Linux
It is not running in a container or a vm

### Configuration

Presence is enabled
`mjolnir.AntiSpam` module is enabled

### Relevant log output

```shell
Jul 02 22:20:21 plus.st matrix-synapse[2388194]: Traceback (most recent call last):
Jul 02 22:20:21 plus.st matrix-synapse[2388194]: File "/opt/matrix-synapse/synapse/http/server.py", line 319, in _async_render_wrapper
Jul 02 22:20:21 plus.st matrix-synapse[2388194]: callback_return = await self._async_render(request)
Jul 02 22:20:21 plus.st matrix-synapse[2388194]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Jul 02 22:20:21 plus.st matrix-synapse[2388194]: File "/opt/matrix-synapse/synapse/http/server.py", line 529, in _async_render
Jul 02 22:20:21 plus.st matrix-synapse[2388194]: callback_return = await raw_callback_return
Jul 02 22:20:21 plus.st matrix-synapse[2388194]: ^^^^^^^^^^^^^^^^^^^^^^^^^
Jul 02 22:20:21 plus.st matrix-synapse[2388194]: File "/opt/matrix-synapse/synapse/rest/client/room.py", line 453, in on_POST
Jul 02 22:20:21 plus.st matrix-synapse[2388194]: return await self._do(request, requester, room_identifier, None)
Jul 02 22:20:21 plus.st matrix-synapse[2388194]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Jul 02 22:20:21 plus.st matrix-synapse[2388194]: File "/opt/matrix-synapse/synapse/rest/client/room.py", line 434, in _do
Jul 02 22:20:21 plus.st matrix-synapse[2388194]: await self.room_member_handler.update_membership(
Jul 02 22:20:21 plus.st matrix-synapse[2388194]: File "/opt/matrix-synapse/synapse/handlers/room_member.py", line 642, in update_membership
Jul 02 22:20:21 plus.st matrix-synapse[2388194]: result = await self.update_membership_locked(
Jul 02 22:20:21 plus.st matrix-synapse[2388194]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Jul 02 22:20:21 plus.st matrix-synapse[2388194]: File "/opt/matrix-synapse/synapse/handlers/room_member.py", line 1103, in update_membership_locked
Jul 02 22:20:21 plus.st matrix-synapse[2388194]: return await self._local_membership_update(
Jul 02 22:20:21 plus.st matrix-synapse[2388194]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Jul 02 22:20:21 plus.st matrix-synapse[2388194]: File "/opt/matrix-synapse/synapse/handlers/room_member.py", line 500, in _local_membership_update
Jul 02 22:20:21 plus.st matrix-synapse[2388194]: await self.event_creation_handler.handle_new_client_event(
Jul 02 22:20:21 plus.st matrix-synapse[2388194]: File "/opt/matrix-synapse/synapse/util/metrics.py", line 113, in measured_func
Jul 02 22:20:21 plus.st matrix-synapse[2388194]: r = await func(self, *args, **kwargs)
Jul 02 22:20:21 plus.st matrix-synapse[2388194]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Jul 02 22:20:21 plus.st matrix-synapse[2388194]: File "/opt/matrix-synapse/synapse/handlers/message.py", line 1424, in handle_new_client_event
Jul 02 22:20:21 plus.st matrix-synapse[2388194]: result, _ = await make_deferred_yieldable(
Jul 02 22:20:21 plus.st matrix-synapse[2388194]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Jul 02 22:20:21 plus.st matrix-synapse[2388194]: File "/opt/matrix-synapse/lib/python3.11/site-packages/twisted/internet/defer.py", line 1697, in _inlineCallbacks
Jul 02 22:20:21 plus.st matrix-synapse[2388194]: result = context.run(gen.send, result)
Jul 02 22:20:21 plus.st matrix-synapse[2388194]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Jul 02 22:20:21 plus.st matrix-synapse[2388194]: File "/opt/matrix-synapse/synapse/handlers/message.py", line 1503, in _persist_events
Jul 02 22:20:21 plus.st matrix-synapse[2388194]: event = await self.persist_and_notify_client_events(
Jul 02 22:20:21 plus.st matrix-synapse[2388194]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Jul 02 22:20:21 plus.st matrix-synapse[2388194]: File "/opt/matrix-synapse/synapse/handlers/message.py", line 1852, in persist_and_notify_client_events
Jul 02 22:20:21 plus.st matrix-synapse[2388194]: ) = await self._storage_controllers.persistence.persist_events(
Jul 02 22:20:21 plus.st matrix-synapse[2388194]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Jul 02 22:20:21 plus.st matrix-synapse[2388194]: File "/opt/matrix-synapse/synapse/logging/opentracing.py", line 916, in _wrapper
Jul 02 22:20:21 plus.st matrix-synapse[2388194]: return await func(*args, **kwargs) # type: ignore[misc]
Jul 02 22:20:21 plus.st matrix-synapse[2388194]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^
Jul 02 22:20:21 plus.st matrix-synapse[2388194]: File "/opt/matrix-synapse/synapse/storage/controllers/persist_events.py", line 413, in persist_events
Jul 02 22:20:21 plus.st matrix-synapse[2388194]: ret_vals = await yieldable_gather_results(enqueue, partitioned.items())
Jul 02 22:20:21 plus.st matrix-synapse[2388194]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Jul 02 22:20:21 plus.st matrix-synapse[2388194]: File "/opt/matrix-synapse/synapse/util/async_helpers.py", line 304, in yieldable_gather_results
Jul 02 22:20:21 plus.st matrix-synapse[2388194]: raise dfe.subFailure.value from None
Jul 02 22:20:21 plus.st matrix-synapse[2388194]: File "/opt/matrix-synapse/lib/python3.11/site-packages/twisted/internet/defer.py", line 1693, in _inlineCallbacks
Jul 02 22:20:21 plus.st matrix-synapse[2388194]: result = context.run(
Jul 02 22:20:21 plus.st matrix-synapse[2388194]: ^^^^^^^^^^^^
Jul 02 22:20:21 plus.st matrix-synapse[2388194]: File "/opt/matrix-synapse/lib/python3.11/site-packages/twisted/python/failure.py", line 518, in throwExceptionIntoGenerator
Jul 02 22:20:21 plus.st matrix-synapse[2388194]: return g.throw(self.type, self.value, self.tb)
Jul 02 22:20:21 plus.st matrix-synapse[2388194]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Jul 02 22:20:21 plus.st matrix-synapse[2388194]: File "/opt/matrix-synapse/synapse/storage/controllers/persist_events.py", line 408, in enqueue
Jul 02 22:20:21 plus.st matrix-synapse[2388194]: return await self._event_persist_queue.add_to_queue(
Jul 02 22:20:21 plus.st matrix-synapse[2388194]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Jul 02 22:20:21 plus.st matrix-synapse[2388194]: File "/opt/matrix-synapse/synapse/storage/controllers/persist_events.py", line 239, in add_to_queue
Jul 02 22:20:21 plus.st matrix-synapse[2388194]: res = await make_deferred_yieldable(end_item.deferred.observe())
Jul 02 22:20:21 plus.st matrix-synapse[2388194]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Jul 02 22:20:21 plus.st matrix-synapse[2388194]: File "/opt/matrix-synapse/synapse/storage/controllers/persist_events.py", line 282, in handle_queue_loop
Jul 02 22:20:21 plus.st matrix-synapse[2388194]: ret = await self._per_item_callback(room_id, item.task)
Jul 02 22:20:21 plus.st matrix-synapse[2388194]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Jul 02 22:20:21 plus.st matrix-synapse[2388194]: File "/opt/matrix-synapse/synapse/storage/controllers/persist_events.py", line 354, in _process_event_persist_queue_task
Jul 02 22:20:21 plus.st matrix-synapse[2388194]: return await self._persist_event_batch(room_id, task)
Jul 02 22:20:21 plus.st matrix-synapse[2388194]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Jul 02 22:20:21 plus.st matrix-synapse[2388194]: File "/opt/matrix-synapse/synapse/storage/controllers/persist_events.py", line 672, in _persist_event_batch
Jul 02 22:20:21 plus.st matrix-synapse[2388194]: res = await self._get_new_state_after_events(
Jul 02 22:20:21 plus.st matrix-synapse[2388194]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Jul 02 22:20:21 plus.st matrix-synapse[2388194]: File "/opt/matrix-synapse/synapse/storage/controllers/persist_events.py", line 874, in _get_new_state_after_events
Jul 02 22:20:21 plus.st matrix-synapse[2388194]: old_state_groups = {
Jul 02 22:20:21 plus.st matrix-synapse[2388194]: ^
Jul 02 22:20:21 plus.st matrix-synapse[2388194]: File "/opt/matrix-synapse/synapse/storage/controllers/persist_events.py", line 875, in
Jul 02 22:20:21 plus.st matrix-synapse[2388194]: event_id_to_state_group[evid] for evid in old_latest_event_ids
Jul 02 22:20:21 plus.st matrix-synapse[2388194]: ~~~~~~~~~~~~~~~~~~~~~~~^^^^^^
Jul 02 22:20:21 plus.st matrix-synapse[2388194]: KeyError: '$8luWWJ3YZiu7yJ0I4E39-Go6x-MYJP2dEaiFajsGDqQ'
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: 2023-07-02 22:20:22,555 - synapse.federation.federation_server - 1249 - ERROR - _process_incoming_pdus_in_room_inner-0 - Failed to handle PDU $vDYyedJ6b0H9ZB2H4FdOUtg8htWYWA2nQPInOImEazc
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: Traceback (most recent call last):
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: File "/opt/matrix-synapse/synapse/handlers/federation_event.py", line 285, in on_receive_pdu
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: await self._get_missing_events_for_pdu(
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: File "/opt/matrix-synapse/synapse/logging/opentracing.py", line 916, in _wrapper
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: return await func(*args, **kwargs) # type: ignore[misc]
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: File "/opt/matrix-synapse/synapse/handlers/federation_event.py", line 805, in _get_missing_events_for_pdu
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: await self._process_pulled_events(origin, missing_events, backfilled=False)
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: File "/opt/matrix-synapse/synapse/logging/opentracing.py", line 916, in _wrapper
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: return await func(*args, **kwargs) # type: ignore[misc]
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: File "/opt/matrix-synapse/synapse/handlers/federation_event.py", line 938, in _process_pulled_events
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: await _process_new_pulled_events(fresh_events)
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: File "/opt/matrix-synapse/synapse/handlers/federation_event.py", line 895, in _process_new_pulled_events
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: await self._process_pulled_event(origin, ev, backfilled=backfilled)
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: File "/opt/matrix-synapse/synapse/logging/opentracing.py", line 916, in _wrapper
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: return await func(*args, **kwargs) # type: ignore[misc]
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: File "/opt/matrix-synapse/synapse/logging/opentracing.py", line 916, in _wrapper
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: return await func(*args, **kwargs) # type: ignore[misc]
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: File "/opt/matrix-synapse/synapse/handlers/federation_event.py", line 1001, in _process_pulled_event
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: await self._process_received_pdu(
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: File "/opt/matrix-synapse/synapse/logging/opentracing.py", line 916, in _wrapper
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: return await func(*args, **kwargs) # type: ignore[misc]
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: File "/opt/matrix-synapse/synapse/handlers/federation_event.py", line 1442, in _process_received_pdu
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: await self._run_push_actions_and_persist_event(event, context, backfilled)
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: File "/opt/matrix-synapse/synapse/logging/opentracing.py", line 916, in _wrapper
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: return await func(*args, **kwargs) # type: ignore[misc]
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: File "/opt/matrix-synapse/synapse/handlers/federation_event.py", line 2217, in _run_push_actions_and_persist_event
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: await self.persist_events_and_notify(
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: File "/opt/matrix-synapse/synapse/handlers/federation_event.py", line 2278, in persist_events_and_notify
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: ) = await self._storage_controllers.persistence.persist_events(
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: File "/opt/matrix-synapse/synapse/logging/opentracing.py", line 916, in _wrapper
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: return await func(*args, **kwargs) # type: ignore[misc]
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: File "/opt/matrix-synapse/synapse/storage/controllers/persist_events.py", line 413, in persist_events
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: ret_vals = await yieldable_gather_results(enqueue, partitioned.items())
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: File "/opt/matrix-synapse/synapse/util/async_helpers.py", line 304, in yieldable_gather_results
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: raise dfe.subFailure.value from None
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: File "/opt/matrix-synapse/lib/python3.11/site-packages/twisted/internet/defer.py", line 1693, in _inlineCallbacks
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: result = context.run(
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: ^^^^^^^^^^^^
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: File "/opt/matrix-synapse/lib/python3.11/site-packages/twisted/python/failure.py", line 518, in throwExceptionIntoGenerator
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: return g.throw(self.type, self.value, self.tb)
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: File "/opt/matrix-synapse/synapse/storage/controllers/persist_events.py", line 408, in enqueue
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: return await self._event_persist_queue.add_to_queue(
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: File "/opt/matrix-synapse/synapse/storage/controllers/persist_events.py", line 239, in add_to_queue
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: res = await make_deferred_yieldable(end_item.deferred.observe())
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: File "/opt/matrix-synapse/synapse/storage/controllers/persist_events.py", line 282, in handle_queue_loop
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: ret = await self._per_item_callback(room_id, item.task)
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: File "/opt/matrix-synapse/synapse/storage/controllers/persist_events.py", line 354, in _process_event_persist_queue_task
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: return await self._persist_event_batch(room_id, task)
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: File "/opt/matrix-synapse/synapse/storage/controllers/persist_events.py", line 672, in _persist_event_batch
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: res = await self._get_new_state_after_events(
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: File "/opt/matrix-synapse/synapse/storage/controllers/persist_events.py", line 874, in _get_new_state_after_events
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: old_state_groups = {
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: ^
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: File "/opt/matrix-synapse/synapse/storage/controllers/persist_events.py", line 875, in
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: event_id_to_state_group[evid] for evid in old_latest_event_ids
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: ~~~~~~~~~~~~~~~~~~~~~~~^^^^^^
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: KeyError: '$KJHrE0qR921NxDf92eUjIIxSxu7tFbtzJ6AvzaE0p4I'
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: The above exception was the direct cause of the following exception:
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: Traceback (most recent call last):
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: File "/opt/matrix-synapse/synapse/federation/federation_server.py", line 1239, in _process_incoming_pdus_in_room_inner
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: await self._federation_event_handler.on_receive_pdu(
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: File "/opt/matrix-synapse/synapse/handlers/federation_event.py", line 289, in on_receive_pdu
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: raise Exception(
Jul 02 22:20:22 plus.st matrix-synapse[2388194]: Exception: Error fetching missing prev_events for $vDYyedJ6b0H9ZB2H4FdOUtg8htWYWA2nQPInOImEazc: '$KJHrE0qR921NxDf92eUjIIxSxu7tFbtzJ6AvzaE0p4I'
```
```

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

This synapse installation was installed using poetry which was installed using pipx.

The traceback points through synapse/rest/client/room.py, synapse/handlers/room_member.py, synapse/handlers/message.py, and synapse/storage/controllers/persist_events.py, ending in a KeyError during state persistence. Start by reproducing the join against #synapse:matrix.org on the reported setup and trace the missing event ID; done means joining no longer returns HTTP 500 and the persistence path handles the case without the logged exception.

Written by the indexing model from the issue text.