can't e2ee send messages to matrix.org users

[lephisto]

Description

Hi,

i have the issue that since a few days or a small number of weeks i can't send messages to matrix.org users. They eventually get:

{
"type": "m.room.message",
"content": {
"msgtype": "m.bad.encrypted",
"body": "** Unable to decrypt: DecryptionError: The sender's device has not sent us the keys for this message. **"
}
}

What I see in my homeserver.log:

2025-08-12 10:29:31,378 - synapse.federation.sender.per_destination_queue - 414 - WARNING - federation_transaction_transmission_loop-8 - TX [matrix.org] Failed to send transaction: Failed to send request: HttpResponseException: 520:
2025-08-12 10:39:11,547 - synapse.federation.sender.per_destination_queue - 414 - WARNING - federation_transaction_transmission_loop-3677 - TX [matrix.org] Failed to send transaction: Failed to send request: HttpResponseException: 520:
2025-08-12 10:49:31,052 - synapse.federation.sender.per_destination_queue - 414 - WARNING - federation_transaction_transmission_loop-15873 - TX [matrix.org] Failed to send transaction: Failed to send request: HttpResponseException: 520:
2025-08-12 10:58:31,053 - synapse.federation.sender.per_destination_queue - 414 - WARNING - federation_transaction_transmission_loop-27382 - TX [matrix.org] Failed to send transaction: Failed to send request: HttpResponseException: 520:
2025-08-12 11:09:35,620 - synapse.federation.sender.per_destination_queue - 414 - WARNING - federation_transaction_transmission_loop-33571 - TX [matrix.org] Failed to send transaction: Failed to send request: HttpResponseException: 520:
2025-08-12 11:18:57,357 - synapse.federation.sender.per_destination_queue - 414 - WARNING - federation_transaction_transmission_loop-41634 - TX [matrix.org] Failed to send transaction: Failed to send request: HttpResponseException: 520:
2025-08-12 11:28:04,699 - synapse.federation.sender.per_destination_queue - 414 - WARNING - federation_transaction_transmission_loop-50819 - TX [matrix.org] Failed to send transaction: Failed to send request: HttpResponseException: 520:
2025-08-12 11:38:30,454 - synapse.federation.sender.per_destination_queue - 414 - WARNING - federation_transaction_transmission_loop-62888 - TX [matrix.org] Failed to send transaction: Failed to send request: HttpResponseException: 520:

Steps to reproduce

• Open Query to matrix.org user
• Write a message
• matrix.org user gets nothing or in the best case "Unable to decrypt"

Homeserver

mephis.to

Synapse Version

1.135.2

Installation Method

Debian packages from packages.matrix.org

Database

postgres

Workers

Single process

Platform

ubuntu 22.04, install from debian packages, apache as ingress proxy.

Configuration

No response

Relevant log output

2025-08-12 10:29:31,378 - synapse.federation.sender.per_destination_queue - 414 - WARNING - federation_transaction_transmission_loop-8 - TX [matrix.org] Failed to send transaction: Failed to send request: HttpResponseException: 520: 
2025-08-12 10:39:11,547 - synapse.federation.sender.per_destination_queue - 414 - WARNING - federation_transaction_transmission_loop-3677 - TX [matrix.org] Failed to send transaction: Failed to send request: HttpResponseException: 520: 
2025-08-12 10:49:31,052 - synapse.federation.sender.per_destination_queue - 414 - WARNING - federation_transaction_transmission_loop-15873 - TX [matrix.org] Failed to send transaction: Failed to send request: HttpResponseException: 520: 
2025-08-12 10:58:31,053 - synapse.federation.sender.per_destination_queue - 414 - WARNING - federation_transaction_transmission_loop-27382 - TX [matrix.org] Failed to send transaction: Failed to send request: HttpResponseException: 520: 
2025-08-12 11:09:35,620 - synapse.federation.sender.per_destination_queue - 414 - WARNING - federation_transaction_transmission_loop-33571 - TX [matrix.org] Failed to send transaction: Failed to send request: HttpResponseException: 520: 
2025-08-12 11:18:57,357 - synapse.federation.sender.per_destination_queue - 414 - WARNING - federation_transaction_transmission_loop-41634 - TX [matrix.org] Failed to send transaction: Failed to send request: HttpResponseException: 520: 
2025-08-12 11:28:04,699 - synapse.federation.sender.per_destination_queue - 414 - WARNING - federation_transaction_transmission_loop-50819 - TX [matrix.org] Failed to send transaction: Failed to send request: HttpResponseException: 520: 
2025-08-12 11:38:30,454 - synapse.federation.sender.per_destination_queue - 414 - WARNING - federation_transaction_transmission_loop-62888 - TX [matrix.org] Failed to send transaction: Failed to send request: HttpResponseException: 520:

Anything else that would be useful to know?

No response

[anoadragon453]

matrix.org appears to be occasionally rate-limited by mephis.to, and thus will mark the homeserver as down:

var/federation_inbound1.log-20250812.gz:2025-08-12 14:43:03,626 - synapse.http.matrixfederationclient - 783 - INFO - _process_incoming_pdus_in_room_inner-5741-$JsWJi1Zl9g7WMBSh-fDjQiUO5t8fv_n0NJlkVz8KPYg-----$QobLa2Q-XfV03tTCHDYVjE21xiLj623qkuKZZUUCPSo---$k-cGhgPuh2LDqDtomfpzGFOwI5CrKPyiuhe3keqKVSU---$gZHmRKzUnF3U28EE5hk76bTzAuG8PWCqKo23yKR3V3w-- - {GET-O-3815} [mephis.to] Got response headers: 429 Unknown Status
var/federation_inbound1.log-20250812.gz:2025-08-12 14:43:03,627 - synapse.http.matrixfederationclient - 826 - INFO - _process_incoming_pdus_in_room_inner-5741-$JsWJi1Zl9g7WMBSh-fDjQiUO5t8fv_n0NJlkVz8KPYg-----$QobLa2Q-XfV03tTCHDYVjE21xiLj623qkuKZZUUCPSo---$k-cGhgPuh2LDqDtomfpzGFOwI5CrKPyiuhe3keqKVSU---$gZHmRKzUnF3U28EE5hk76bTzAuG8PWCqKo23yKR3V3w-- - {GET-O-3815} [mephis.to] Request failed: GET matrix-federation://mephis.to/_matrix/federation/v1/event/%24gZHmRKzUnF3U28EE5hk76bTzAuG8PWCqKo23yKR3V3w: HttpResponseException('429: Unknown Status')
var/federation_inbound1.log-20250812.gz:2025-08-12 14:43:03,631 - synapse.http.matrixfederationclient - 783 - INFO - _process_incoming_pdus_in_room_inner-5888-$uhgp9uup16zv1k7Sm0wbC6lHACxUiwW9E9XZviCv0VY--- - {POST-O-3825} [mephis.to] Got response headers: 429 Unknown Status
var/federation_inbound1.log-20250812.gz:2025-08-12 14:43:03,632 - synapse.http.matrixfederationclient - 826 - INFO - _process_incoming_pdus_in_room_inner-5888-$uhgp9uup16zv1k7Sm0wbC6lHACxUiwW9E9XZviCv0VY--- - {POST-O-3825} [mephis.to] Request failed: POST matrix-federation://mephis.to/_matrix/federation/v1/get_missing_events/%21lBdWAgtYTazVSpADJT%3Ainsa.lol: HttpResponseException('429: Unknown Status')
var/federation_inbound1.log-20250812.gz:2025-08-12 14:43:03,632 - synapse.util.retryutils - 296 - INFO - _process_incoming_pdus_in_room_inner-5888-$uhgp9uup16zv1k7Sm0wbC6lHACxUiwW9E9XZviCv0VY-- - Connection to mephis.to was unsuccessful (<class 'synapse.api.errors.RequestSendFailed'>(Failed to send request: HttpResponseException: 429: Unknown Status)); backoff now 600000

then, when mephis.to tries to send an event that references several prev_events that matrix.org does not have, matrix.org refuses to contact mephis.to. Thus, validation of incoming events returns an error:

var/federation_inbound1.log-20250812.gz:2025-08-12 14:48:10,496 - synapse.federation.federation_server - 1296 - INFO - _process_incoming_pdus_in_room_inner-6420 - handling received PDU in room !pLRUplKxKbyzWKpNJH:nitro.chat: <FrozenEventV3 event_id=$Fc8WV_xLPlg1gDeVMtqOvxgggVLgQ2UFeqMnPYySE9g, type=m.room.member, state_key=@mynumber1:mephis.to, membership=join, outlier=False>
...
var/federation_inbound1.log-20250812.gz:2025-08-12 14:48:33,419 - synapse.handlers.federation_event - 1724 - WARNING - _process_incoming_pdus_in_room_inner-6420-$Fc8WV_xLPlg1gDeVMtqOvxgggVLgQ2UFeqMnPYySE9g-----$zJYJZnfJipADhzA4Cmn_xQ-dhJBTs3R0Iyht_ckzj4Q---$ese_eIDvHjD2t754RRl0zed6RlaqMXvqYz2HH5eUv9s---$SrqwcgiB9nQKM3ZMQQqUgVEmHoEj9FXhNdk4BUuBJY8 - Server mephis.to didn't return event $SrqwcgiB9nQKM3ZMQQqUgVEmHoEj9FXhNdk4BUuBJY8
var/federation_inbound1.log-20250812.gz:2025-08-12 14:48:33,419 - synapse.federation.federation_client - 580 - INFO - _process_incoming_pdus_in_room_inner-6420-$Fc8WV_xLPlg1gDeVMtqOvxgggVLgQ2UFeqMnPYySE9g-----$zJYJZnfJipADhzA4Cmn_xQ-dhJBTs3R0Iyht_ckzj4Q---$ese_eIDvHjD2t754RRl0zed6RlaqMXvqYz2HH5eUv9s---$ese_eIDvHjD2t754RRl0zed6RlaqMXvqYz2HH5eUv9s- - get_pdu(event_id=$ese_eIDvHjD2t754RRl0zed6RlaqMXvqYz2HH5eUv9s): Not retrying server mephis.to because we tried it recently retry_last_ts=1755010112141 and we won't check for another retry_interval=600000ms.
var/federation_inbound1.log-20250812.gz:2025-08-12 14:48:33,419 - synapse.handlers.federation_event - 1724 - WARNING - _process_incoming_pdus_in_room_inner-6420-$Fc8WV_xLPlg1gDeVMtqOvxgggVLgQ2UFeqMnPYySE9g-----$zJYJZnfJipADhzA4Cmn_xQ-dhJBTs3R0Iyht_ckzj4Q---$ese_eIDvHjD2t754RRl0zed6RlaqMXvqYz2HH5eUv9s---$ese_eIDvHjD2t754RRl0zed6RlaqMXvqYz2HH5eUv9s - Server mephis.to didn't return event $ese_eIDvHjD2t754RRl0zed6RlaqMXvqYz2HH5eUv9s
var/federation_inbound1.log-20250812.gz:2025-08-12 14:48:33,420 - synapse.federation.federation_client - 580 - INFO - _process_incoming_pdus_in_room_inner-6420-$Fc8WV_xLPlg1gDeVMtqOvxgggVLgQ2UFeqMnPYySE9g-----$zJYJZnfJipADhzA4Cmn_xQ-dhJBTs3R0Iyht_ckzj4Q---$ese_eIDvHjD2t754RRl0zed6RlaqMXvqYz2HH5eUv9s---$fPvZZqPGRdqseTEu4j8fA_LoKlON8soPN9iQRPTPZMc- - get_pdu(event_id=$fPvZZqPGRdqseTEu4j8fA_LoKlON8soPN9iQRPTPZMc): Not retrying server mephis.to because we tried it recently retry_last_ts=1755010112141 and we won't check for another retry_interval=600000ms.
...

I think this is a duplicate of matrix-org/synapse#1729 (now #1729), and I'm sorry it's been a known failure mode for so long.

Some more info here:

synapse/synapse/handlers/federation_event.py

Lines 745 to 791 in e8c6cb3

	# XXX: we set timeout to 10s to help workaround
	# https://github.com/matrix-org/synapse/issues/1733.
	# The reason is to avoid holding the linearizer lock
	# whilst processing inbound /send transactions, causing
	# FDs to stack up and block other inbound transactions
	# which empirically can currently take up to 30 minutes.
	#
	# N.B. this explicitly disables retry attempts.
	#
	# N.B. this also increases our chances of falling back to
	# fetching fresh state for the room if the missing event
	# can't be found, which slightly reduces our security.
	# it may also increase our DAG extremity count for the room,
	# causing additional state resolution? See https://github.com/matrix-org/synapse/issues/1760.
	# However, fetching state doesn't hold the linearizer lock
	# apparently.
	#
	# see https://github.com/matrix-org/synapse/pull/1744
	#
	# ----
	#
	# Update richvdh 2018/09/18: There are a number of problems with timing this
	# request out aggressively on the client side:
	#
	# - it plays badly with the server-side rate-limiter, which starts tarpitting you
	# if you send too many requests at once, so you end up with the server carefully
	# working through the backlog of your requests, which you have already timed
	# out.
	#
	# - for this request in particular, we now (as of
	# https://github.com/matrix-org/synapse/pull/3456) reject any PDUs where the
	# server can't produce a plausible-looking set of prev_events - so we becone
	# much more likely to reject the event.
	#
	# - contrary to what it says above, we do *not* fall back to fetching fresh state
	# for the room if get_missing_events times out. Rather, we give up processing
	# the PDU whose prevs we are missing, which then makes it much more likely that
	# we'll end up back here for the *next* PDU in the list, which exacerbates the
	# problem.
	#
	# - the aggressive 10s timeout was introduced to deal with incoming federation
	# requests taking 8 hours to process. It's not entirely clear why that was going
	# on; certainly there were other issues causing traffic storms which are now
	# resolved, and I think in any case we may be more sensible about our locking
	# now. We're *certainly* more sensible about our logging.
	#
	# All that said: Let's try increasing the timeout to 60s and see what happens.

To workaround it for now, I'd raise rate-limits on /_matrix/federation/v1/get_missing_events/{eventId} and /_matrix/federation/v1/event/{eventId} endpoints to stop matrix.org from receiving 429's and marking mephis.to as down.