Rejected event made it into current_state_events, leading to errors such as 404: Could not find event

[matrixbot]

This issue has been migrated from #6867.

---

I'm not seeing any inbound federation to #irc:matrix.org (!BAXLHOFjvDKUeLafmO:matrix.org), and my logs are full of:

2020-02-06 17:42:19,652 - synapse.federation.transport.server - 161 - INFO - PUT-81436- Request from raim.ist
2020-02-06 17:42:19,653 - synapse.federation.transport.server - 406 - INFO - PUT-81436- Received txn 1580999134839 from raim.ist. (PDUs: 1, EDUs: 1)
2020-02-06 17:42:19,673 - synapse.http.client - 284 - INFO - PUT-81436- Sending request POST http://127.0.0.1:9593/_synapse/replication/fed_send_edu/m.receipt/BIetiYxCmo
2020-02-06 17:42:19,754 - synapse.federation.transport.server - 427 - ERROR - PUT-81436- on_incoming_transaction failed
Traceback (most recent call last):
  File "/opt/synapse/lib/python3.7/site-packages/twisted/internet/defer.py", line 1418, in _inlineCallbacks
    result = g.send(result)
StopIteration: {'$NVI5AZqJdV7KyJPF3XFlxzRiiD0G86IBbWi7JxxUr0g': {'event_id': '$NVI5AZqJdV7KyJPF3XFlxzRiiD0G86IBbWi7JxxUr0g', 'internal_metadata': '{"outlier": false, "stream_ordering": -150956}', 'json': '{"auth_events": ["$fgAiL9F7RRbilPAfTVYhaOPl7sunZZVhtUCPvphGDL4", "$S38/aRG4Qz8eIdrTyzJuQdH3Ieus1Y1dhczoFKnOB7M", "$AQfAndymjyEmF3BjyHxwK9wIBZxMq0i8APoWoPIubNM"], "content": {"allow": ["*"], "allow_ip_literals": false, "deny": ["calamari.space", "*.200acres.org", "*.glowers.club", "*.gossip.love", "*.matrix.kiwifarms.net", "*.nerdsin.space", "*.ordoevangelistarum.com", "*.zemos.net", "200acres.org", "ardaxi.com", "c-24-11-108-182.hsd1.ut.comcast.net", "glowers.club", "gossip.love", "matrix.kiwifarms.net", "nerdsin.space", "ordoevangelistarum.com", "zemos.net"]}, "depth": 18623, "hashes": {"sha256": "jD2Wrs+hrdFRZOkpO63fGdxu4ku05dYXmDM61pneUgQ"}, "origin": "matrix.org", "origin_server_ts": 1579737097568, "prev_events": ["$+80N8tyd9FlDbCsIdBQqY5+7vv5Be2bJdIcT95JS2YM"], "prev_state": [], "room_id": "!BAXLHOFjvDKUeLafmO:matrix.org", "sender": "@abuse:matrix.org", "state_key": "", "type": "m.room.server_acl", "signatures": {"matrix.org": {"ed25519:a_RXGa": "s+o7wIY57ea0FZBZC2CjhWgU7FRKxl9E9HNQizL+USvQEfF0C9AaVYYxBaqoySNvPUfE5jPWrFVoS5yOtJ/0Dg"}}, "unsigned": {"age": 31784513, "replaces_state": "$+80N8tyd9FlDbCsIdBQqY5+7vv5Be2bJdIcT95JS2YM"}}', 'format_version': 2, 'rejected_reason': 'auth_error', 'redactions': []}}

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/synapse/lib/python3.7/site-packages/twisted/internet/defer.py", line 1418, in _inlineCallbacks
    result = g.send(result)
StopIteration: {}

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/synapse/lib/python3.7/site-packages/twisted/internet/defer.py", line 1418, in _inlineCallbacks
    result = g.send(result)
StopIteration: {}

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/synapse/lib/python3.7/site-packages/twisted/internet/defer.py", line 1418, in _inlineCallbacks
    result = g.send(result)
StopIteration: []

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/synapse/lib/python3.7/site-packages/synapse/federation/transport/server.py", line 424, in on_PUT
    origin, transaction_data
  File "/opt/synapse/lib/python3.7/site-packages/synapse/federation/federation_server.py", line 129, in on_incoming_transaction
    origin, transaction, request_time
  File "/opt/synapse/lib/python3.7/site-packages/synapse/federation/federation_server.py", line 181, in _handle_incoming_transaction
    ).addErrback(unwrapFirstError)
  File "/opt/synapse/lib/python3.7/site-packages/twisted/internet/defer.py", line 1416, in _inlineCallbacks
    result = result.throwExceptionIntoGenerator(g)
  File "/opt/synapse/lib/python3.7/site-packages/twisted/python/failure.py", line 512, in throwExceptionIntoGenerator
    return g.throw(self.type, self.value, self.tb)
  File "/opt/synapse/lib/python3.7/site-packages/synapse/federation/federation_server.py", line 293, in _handle_pdus_in_txn
    process_pdus_for_room, pdus_by_room.keys(), TRANSACTION_CONCURRENCY_LIMIT
  File "/opt/synapse/lib/python3.7/site-packages/twisted/internet/defer.py", line 1416, in _inlineCallbacks
    result = result.throwExceptionIntoGenerator(g)
  File "/opt/synapse/lib/python3.7/site-packages/twisted/python/failure.py", line 512, in throwExceptionIntoGenerator
    return g.throw(self.type, self.value, self.tb)
  File "/opt/synapse/lib/python3.7/site-packages/synapse/util/async_helpers.py", line 155, in _concurrently_execute_inner
    await maybe_awaitable(func(next(it)))
  File "/opt/synapse/lib/python3.7/site-packages/synapse/federation/federation_server.py", line 266, in process_pdus_for_room
    await self.check_server_matches_acl(origin_host, room_id)
  File "/opt/synapse/lib/python3.7/site-packages/synapse/federation/federation_server.py", line 710, in check_server_matches_acl
    acl_event = await self.store.get_event(acl_event_id)
  File "/opt/synapse/lib/python3.7/site-packages/twisted/internet/defer.py", line 1418, in _inlineCallbacks
    result = g.send(result)
  File "/opt/synapse/lib/python3.7/site-packages/synapse/storage/data_stores/main/events_worker.py", line 190, in get_event
    raise NotFoundError("Could not find event %s" % (event_id,))
synapse.api.errors.NotFoundError: 404: Could not find event $NVI5AZqJdV7KyJPF3XFlxzRiiD0G86IBbWi7JxxUr0g
2020-02-06 17:42:19,755 - synapse.http.server - 81 - INFO - PUT-81436- <XForwardedForRequest at 0x7f47ea9f94e0 method='PUT' uri='/_matrix/federation/v1/send/1580999134839' clientproto='HTTP/1.0' site=8053> SynapseError: 404 - Could not find event $NVI5AZqJdV7KyJPF3XFlxzRiiD0G86IBbWi7JxxUr0g
2020-02-06 17:42:19,756 - synapse.access.http.8053 - 302 - INFO - PUT-81436- - - 8053 - {raim.ist} Processed request: 0.105sec/0.000sec (0.010sec, 0.000sec) (0.001sec/0.073sec/2) 101B 404 "PUT /_matrix/federation/v1/send/1580999134839 HTTP/1.0" "Synapse/1.10.0rc2" [1 dbevts]