"Failed to send_join via any server" with "'coroutine' object has no attribute 'event_id'"

[richvdh]

On synapse 1.11.0, when you try to join #synapse:matrix.org, you get:

2020-02-24 14:00:07,320 - synapse.federation.federation_base - 196 - WARNING - POST-1957- Signature check failed for $zTjQbxV26Zs_Jan_Km9kbq7YScafrGYhYMT0rKtJP7o: 403: event id $zTjQbxV26Zs_Jan_Km9kbq7YScafrGYhYMT0rKtJP7o: unable to verify signature for sender matrix.org: 401: Invalid signature for server matrix.org with key ed25519:auto: Unable to verify signature for matrix.org: <class 'nacl.exceptions.BadSignatureError'> Signature was forged or corrupt

and later:

2020-02-24 14:00:10,088 - synapse.federation.federation_client - 421 - WARNING - POST-1957- Failed to send_join via matrix.org
...
Traceback (most recent call last):
  File "/home/synapse/matrixtest/synapse/federation/federation_client.py", line 402, in _try_destination_list
    res = await callback(destination)
  File "/home/synapse/matrixtest/synapse/federation/federation_client.py", line 589, in send_request
    valid_pdus_map = {p.event_id: p for p in valid_pdus}
  File "/home/synapse/matrixtest/synapse/federation/federation_client.py", line 589, in <dictcomp>
    valid_pdus_map = {p.event_id: p for p in valid_pdus}
AttributeError: 'coroutine' object has no attribute 'event_id'
2020-02-24 14:00:10,154 - synapse.http.server - 81 - INFO - POST-1957- <SynapseRequest at 0x7ff1bf3efd30 method='POST' uri='/_matrix/client/r0/join/%23synapse%3Amatrix.org' clientproto='HTTP/1.1' site=8447> SynapseError: 502 - Failed to send_join via any server

[richvdh]

I think there are two problems here:

• $zTjQbxV26Zs_Jan_Km9kbq7YScafrGYhYMT0rKtJP7o has a bad signature; it shouldn't have been accepted by matrix.org.
• something has recently broken the code that is meant to handle the above situation, causing the AttributeError: 'coroutine' object has no attribute 'event_id' error.

[sbug-1bit]

I'm getting this for other rooms.

[MrCustomizer]

This seems also to be reproducible with Fractal's room #fractal-gtk:matrix.org. At least I'm getting the "Failed to send_join via any server"-message when trying to join the room with two different accounts from two different servers.

[sbug-1bit]

#fractal-gtk:matrix.org is one the rooms that don't work for me too.
But also #gridepo:kamax.io and #rust:matrix.org (the rust room I was in, left and tried to rejoin and got that message)

[MrCustomizer]

I just tried the two rooms with one of my accounts and I can't join them either. Always fails with "Failed to send_join via any server".

[clokep]

The attribute error ('coroutine' object has no attribute 'event_id') should be fixed by #6996. @richvdh is this worth keeping open for the signature issue or is that something else?

[richvdh]

I think we should consider the signature warning a separate problem.

[ZLima12]

Currently having this issue. It seems like it was fixed (since it was moved to Done)? If so, would I have to wait until the next release to correct this issue? Or would temporarily running synapse off of master be enough to correct the issue, which would let me go back to stable?

[ZLima12]

After checking my logs, it seems that each time I get this error, I get something like this right before it:
2020-03-07 02:31:17,108 - synapse.federation.federation_base - 193 - WARNING - POST-224769 - Signature check failed for $144234967914LjkGt:oddvar.org: 403: event id $144234967914LjkGt:oddvar.org: unable to verify signature for sender oddvar.org: 401: No key for oddvar.org with ids in ['ed25519:auto'] (min_validity 0)

This particular error happened when trying to join #Python:matrix.org. Is this related? The error is a bit different.

[richvdh]

the warning is saying that there is an incorrectly-signed event in the room. This bug (fixed in synapse 1.11.1) meant that, instead of recovering gracefully after the warning, the entire join would fail.

It is not the only thing that can cause a room join to fail: if you still see "Failed to send_join...", it suggests there is another unrelated problem.

There may be additional problems specific to #Python: see #5599.

[melroy89]

I see the same happening at my synapse sever (version v1.20.1):

2020-10-07 16:17:57,145 - synapse.logging.context - 396 - WARNING - federation_transaction_transmission_loop-6663 - Re-starting finished log context federation_transaction_transmission_loop-6663
2020-10-07 16:30:08,807 - synapse.logging.context - 396 - WARNING - federation_transaction_transmission_loop-6711 - Re-starting finished log context federation_transaction_transmission_loop-6711
2020-10-07 16:44:38,197 - synapse.federation.federation_base - 124 - WARNING - POST-18107 - Signature check failed for $zTjQbxV26Zs_Jan_Km9kbq7YScafrGYhYMT0rKtJP7o: 403: event id $zTjQbxV26Zs_Jan_Km9kbq7YScafrGYhYMT0rKtJP7o: unable to verify signature for sender matrix.org: 401: Invalid signature for server matrix.org with key ed25519:auto: Unable to verify signature for matrix.org: <class 'nacl.exceptions.BadSignatureError'> Signature was forged or corrupt
2020-10-07 16:44:43,860 - synapse.federation.federation_client - 402 - WARNING - POST-18107 - Failed to find copy of $zTjQbxV26Zs_Jan_Km9kbq7YScafrGYhYMT0rKtJP7o with valid signature
2020-10-07 16:45:22,463 - synapse.federation.federation_base - 124 - WARNING - POST-18107 - Signature check failed for $xcIMpNALSvYeTV-zvCiCg9P8NUYv0KTDvRRbxWQBXA4: 403: event id $xcIMpNALSvYeTV-zvCiCg9P8NUYv0KTDvRRbxWQBXA4: unable to verify signature for sender letsrulethe.world: 401: Invalid signature for server letsrulethe.world with key ed25519:a_GsOc: Unable to verify signature for letsrulethe.world: <class 'nacl.exceptions.BadSignatureError'> Signature was forged or corrupt
2020-10-07 16:45:23,141 - synapse.federation.federation_base - 124 - WARNING - POST-18107 - Signature check failed for $i67nreWgP2lbgB6WPnLx4x2idL6Bah-peTqmt55OLtI: 403: event id $i67nreWgP2lbgB6WPnLx4x2idL6Bah-peTqmt55OLtI: unable to verify signature for sender c.a2sc.eu: 401: Invalid signature for server c.a2sc.eu with key ed25519:a_wIti: Unable to verify signature for c.a2sc.eu: <class 'nacl.exceptions.BadSignatureError'> Signature was forged or corrupt
2020-10-07 16:45:28,751 - synapse.http.server - 616 - WARNING - PUT-18300 - Not sending response to request <XForwardedForRequest at 0x7f75fb091f50 method='PUT' uri='/_matrix/federation/v1/send/1601343900336' clientproto='HTTP/1.0' site=8008>, already disconnected.
2020-10-07 16:45:28,756 - synapse.http.server - 616 - WARNING - PUT-18309 - Not sending response to request <XForwardedForRequest at 0x7f75fb15fe10 method='PUT' uri='/_matrix/federation/v1/send/1601278347539' clientproto='HTTP/1.0' site=8008>, already disconnected.
2020-10-07 16:45:28,773 - synapse.http.server - 616 - WARNING - PUT-18310 - Not sending response to request <XForwardedForRequest at 0x7f75fa678c50 method='PUT' uri='/_matrix/federation/v1/send/1601319897844' clientproto='HTTP/1.0' site=8008>, already disconnected.
2020-10-07 16:45:28,788 - synapse.http.server - 616 - WARNING - PUT-18298 - Not sending response to request <XForwardedForRequest at 0x7f75fb704a10 method='PUT' uri='/_matrix/federation/v1/send/1600265066401' clientproto='HTTP/1.0' site=8008>, already disconnected.
2020-10-07 16:45:28,801 - synapse.http.server - 616 - WARNING - PUT-18292 - Not sending response to request <XForwardedForRequest at 0x7f75fb39c190 method='PUT' uri='/_matrix/federation/v1/send/1602077392534' clientproto='HTTP/1.0' site=8008>, already disconnected.
2020-10-07 16:45:28,809 - synapse.http.server - 616 - WARNING - PUT-18325 - Not sending response to request <XForwardedForRequest at 0x7f75f9d2ee10 method='PUT' uri='/_matrix/federation/v1/send/1601865778124' clientproto='HTTP/1.0' site=8008>, already disconnected.
2020-10-07 16:45:28,811 - synapse.http.server - 616 - WARNING - PUT-18294 - Not sending response to request <XForwardedForRequest at 0x7f75f37937d0 method='PUT' uri='/_matrix/federation/v1/send/1600233039698' clientproto='HTTP/1.0' site=8008>, already disconnected.
2020-10-07 16:45:28,817 - synapse.http.server - 616 - WARNING - PUT-18303 - Not sending response to request <XForwardedForRequest at 0x7f75fb3e2350 method='PUT' uri='/_matrix/federation/v1/send/1602086843566' clientproto='HTTP/1.0' site=8008>, already disconnected.
2020-10-07 16:45:28,821 - synapse.http.server - 616 - WARNING - PUT-18305 - Not sending response to request <XForwardedForRequest at 0x7f75fba05e10 method='PUT' uri='/_matrix/federation/v1/send/1600795353690' clientproto='HTTP/1.0' site=8008>, already disconnected.
2020-10-07 16:45:28,831 - synapse.http.server - 616 - WARNING - PUT-18293 - Not sending response to request <XForwardedForRequest at 0x7f75f3767850 method='PUT' uri='/_matrix/federation/v1/send/1602070484976' clientproto='HTTP/1.0' site=8008>, already disconnected.
2020-10-07 16:45:28,836 - synapse.http.server - 616 - WARNING - PUT-18304 - Not sending response to request <XForwardedForRequest at 0x7f75fa2cf0d0 method='PUT' uri='/_matrix/federation/v1/send/1600266679533' clientproto='HTTP/1.0' site=8008>, already disconnected.
2020-10-07 16:45:28,856 - synapse.http.server - 616 - WARNING - PUT-18306 - Not sending response to request <XForwardedForRequest at 0x7f75fb7cc650 method='PUT' uri='/_matrix/federation/v1/send/1602086415453' clientproto='HTTP/1.0' site=8008>, already disconnected.
2020-10-07 16:45:28,858 - synapse.http.server - 616 - WARNING - PUT-18324 - Not sending response to request <XForwardedForRequest at 0x7f75fa805550 method='PUT' uri='/_matrix/federation/v1/send/1601994692130' clientproto='HTTP/1.0' site=8008>, already disconnected.
2020-10-07 16:45:28,863 - synapse.http.server - 616 - WARNING - PUT-18299 - Not sending response to request <XForwardedForRequest at 0x7f75facdf9d0 method='PUT' uri='/_matrix/federation/v1/send/1602003285697' clientproto='HTTP/1.0' site=8008>, already disconnected.
2020-10-07 16:45:28,867 - synapse.http.server - 616 - WARNING - PUT-18290 - Not sending response to request <XForwardedForRequest at 0x7f7603cc60d0 method='PUT' uri='/_matrix/federation/v1/send/1602044209736' clientproto='HTTP/1.0' site=8008>, already disconnected.
2020-10-07 16:45:28,922 - synapse.http.server - 616 - WARNING - PUT-18313 - Not sending response to request <XForwardedForRequest at 0x7f75fae53350 method='PUT' uri='/_matrix/federation/v1/send/1600974075477' clientproto='HTTP/1.0' site=8008>, already disconnected.
2020-10-07 16:45:28,934 - synapse.http.server - 616 - WARNING - PUT-18308 - Not sending response to request <XForwardedForRequest at 0x7f75fb147910 method='PUT' uri='/_matrix/federation/v1/send/1601232786340' clientproto='HTTP/1.0' site=8008>, already disconnected.
2020-10-07 16:45:28,938 - synapse.http.server - 616 - WARNING - PUT-18316 - Not sending response to request <XForwardedForRequest at 0x7f75fb88f410 method='PUT' uri='/_matrix/federation/v1/send/1601984684973' clientproto='HTTP/1.0' site=8008>, already disconnected.
2020-10-07 16:45:28,950 - synapse.http.server - 616 - WARNING - PUT-18307 - Not sending response to request <XForwardedForRequest at 0x7f75f9ba51d0 method='PUT' uri='/_matrix/federation/v1/send/1601853860965' clientproto='HTTP/1.0' site=8008>, already disconnected.
2020-10-07 16:45:28,958 - synapse.http.server - 616 - WARNING - PUT-18444 - Not sending response to request <XForwardedForRequest at 0x7f75ed70aa50 method='PUT' uri='/_matrix/federation/v1/send/1601681193729' clientproto='HTTP/1.0' site=8008>, already disconnected.
2020-10-07 16:45:28,961 - synapse.http.server - 616 - WARNING - PUT-18291 - Not sending response to request <XForwardedForRequest at 0x7f7603b608d0 method='PUT' uri='/_matrix/federation/v1/send/1601741288086' clientproto='HTTP/1.0' site=8008>, already disconnected.
2020-10-07 16:45:28,964 - synapse.http.server - 616 - WARNING - PUT-18311 - Not sending response to request <XForwardedForRequest at 0x7f75fb39c9d0 method='PUT' uri='/_matrix/federation/v1/send/1601320341719' clientproto='HTTP/1.0' site=8008>, already disconnected.
2020-10-07 16:45:28,986 - synapse.http.matrixfederationclient - 581 - WARNING - POST-18107 - {GET-O-11599} [letsrulethe.world] Request failed: GET matrix://letsrulethe.world/_matrix/federation/v1/event/%24xcIMpNALSvYeTV-zvCiCg9P8NUYv0KTDvRRbxWQBXA4: HttpResponseException('404: Not Found')
2020-10-07 16:45:28,986 - synapse.federation.federation_client - 402 - WARNING - POST-18107 - Failed to find copy of $xcIMpNALSvYeTV-zvCiCg9P8NUYv0KTDvRRbxWQBXA4 with valid signature
2020-10-07 16:45:28,988 - synapse.http.server - 616 - WARNING - PUT-18301 - Not sending response to request <XForwardedForRequest at 0x7f75fa5c6290 method='PUT' uri='/_matrix/federation/v1/send/1601858565751' clientproto='HTTP/1.0' site=8008>, already disconnected.
2020-10-07 16:45:28,989 - synapse.http.server - 616 - WARNING - PUT-18295 - Not sending response to request <XForwardedForRequest at 0x7f75f3738d50 method='PUT' uri='/_matrix/federation/v1/send/1602082625388' clientproto='HTTP/1.0' site=8008>, already disconnected.
2020-10-07 16:45:28,991 - synapse.http.server - 616 - WARNING - PUT-18321 - Not sending response to request <XForwardedForRequest at 0x7f75fb576490 method='PUT' uri='/_matrix/federation/v1/send/1601754467874' clientproto='HTTP/1.0' site=8008>, already disconnected.
2020-10-07 16:45:28,993 - synapse.http.server - 616 - WARNING - PUT-18302 - Not sending response to request <XForwardedForRequest at 0x7f75f9ea5850 method='PUT' uri='/_matrix/federation/v1/send/1602087545142' clientproto='HTTP/1.0' site=8008>, already disconnected.
2020-10-07 16:45:28,999 - synapse.http.server - 616 - WARNING - PUT-18297 - Not sending response to request <XForwardedForRequest at 0x7f75fa206f90 method='PUT' uri='/_matrix/federation/v1/send/1601854646894' clientproto='HTTP/1.0' site=8008>, already disconnected.
2020-10-07 16:45:29,024 - synapse.http.matrixfederationclient - 581 - WARNING - POST-18107 - {GET-O-11600} [c.a2sc.eu] Request failed: GET matrix://c.a2sc.eu/_matrix/federation/v1/event/%24i67nreWgP2lbgB6WPnLx4x2idL6Bah-peTqmt55OLtI: HttpResponseException('404: Not Found')
2020-10-07 16:45:29,025 - synapse.federation.federation_client - 402 - WARNING - POST-18107 - Failed to find copy of $i67nreWgP2lbgB6WPnLx4x2idL6Bah-peTqmt55OLtI with valid signature
2020-10-07 16:45:29,859 - synapse.http.server - 616 - WARNING - PUT-18296 - Not sending response to request <XForwardedForRequest at 0x7f75f376ef90 method='PUT' uri='/_matrix/federation/v1/send/1601798398153' clientproto='HTTP/1.0' site=8008>, already disconnected.
2020-10-07 16:45:32,156 - synapse.federation.federation_base - 124 - WARNING - POST-18107 - Signature check failed for $zTjQbxV26Zs_Jan_Km9kbq7YScafrGYhYMT0rKtJP7o: 403: event id $zTjQbxV26Zs_Jan_Km9kbq7YScafrGYhYMT0rKtJP7o: unable to verify signature for sender matrix.org: 401: Invalid signature for server matrix.org with key ed25519:auto: Unable to verify signature for matrix.org: <class 'nacl.exceptions.BadSignatureError'> Signature was forged or corrupt
2020-10-07 16:45:32,417 - synapse.federation.federation_base - 124 - WARNING - POST-18107 - Signature check failed for $i67nreWgP2lbgB6WPnLx4x2idL6Bah-peTqmt55OLtI: 403: event id $i67nreWgP2lbgB6WPnLx4x2idL6Bah-peTqmt55OLtI: unable to verify signature for sender c.a2sc.eu: 401: Invalid signature for server c.a2sc.eu with key ed25519:a_wIti: Unable to verify signature for c.a2sc.eu: <class 'nacl.exceptions.BadSignatureError'> Signature was forged or corrupt
2020-10-07 16:45:33,628 - synapse.federation.federation_base - 124 - WARNING - POST-18107 - Signature check failed for $xcIMpNALSvYeTV-zvCiCg9P8NUYv0KTDvRRbxWQBXA4: 403: event id $xcIMpNALSvYeTV-zvCiCg9P8NUYv0KTDvRRbxWQBXA4: unable to verify signature for sender letsrulethe.world: 401: Invalid signature for server letsrulethe.world with key ed25519:a_GsOc: Unable to verify signature for letsrulethe.world: <class 'nacl.exceptions.BadSignatureError'> Signature was forged or corrupt

I got the error message that I couldn't join the room. But it still tries eventually... (I was trying to join the Synapse Admins room from my Synapse homeserver).