server keeps trying to handle device list update on a server that doesn't exists anymore (301: Moved Permanently)

[thomasesr]

Description

2020-12-22 13:01:10,115 - root - 319 - WARNING - None - ***** STARTING SERVER *****,
2020-12-22 13:01:10,118 - root - 320 - WARNING - None - Server /usr/local/lib/python3.8/site-packages/synapse/app/homeserver.py version 1.24.0,
2020-12-22 13:01:28,935 - synapse.http.matrixfederationclient - 577 - WARNING - federation_transaction_transmission_loop-0 - {PUT-O-1} [tyjgr.com] Request failed: PUT matrix://tyjgr.com/_matrix/federation/v1/send/1608652870402: HttpResponseException('302: Found'),
2020-12-22 13:01:28,941 - synapse.federation.sender.transaction_manager - 177 - WARNING - federation_transaction_transmission_loop-0 - TX [tyjgr.com] {1608652870402} Failed to send event $misioIClpmW5V_1KW1sExYKDY_idMmB1yx-Lleiyekg,
2020-12-22 13:01:41,490 - synapse.http.matrixfederationclient - 577 - WARNING - _maybe_retry_device_resync-0 - {GET-O-24} [orthool.com] Request failed: GET matrix://orthool.com/_matrix/federation/v1/user/devices/%40lucasmendes%3Aorthool.com: HttpResponseException('301: Moved Permanently'),
2020-12-22 13:01:41,494 - synapse.handlers.device - 857 - WARNING - _maybe_retry_device_resync-0 - Failed to handle device list update for @lucasmendes:orthool.com: 301: Moved Permanently,
2020-12-22 13:02:10,600 - synapse.http.matrixfederationclient - 577 - WARNING - _maybe_retry_device_resync-1 - {GET-O-56} [orthool.com] Request failed: GET matrix://orthool.com/_matrix/federation/v1/user/devices/%40lucasmendes%3Aorthool.com: HttpResponseException('301: Moved Permanently'),
2020-12-22 13:02:10,605 - synapse.handlers.device - 857 - WARNING - _maybe_retry_device_resync-1 - Failed to handle device list update for @lucasmendes:orthool.com: 301: Moved Permanently,
2020-12-22 13:02:40,618 - synapse.http.matrixfederationclient - 577 - WARNING - _maybe_retry_device_resync-2 - {GET-O-87} [orthool.com] Request failed: GET matrix://orthool.com/_matrix/federation/v1/user/devices/%40lucasmendes%3Aorthool.com: HttpResponseException('301: Moved Permanently'),
2020-12-22 13:02:40,624 - synapse.handlers.device - 857 - WARNING - _maybe_retry_device_resync-2 - Failed to handle device list update for @lucasmendes:orthool.com: 301: Moved Permanently,
2020-12-22 13:03:10,611 - synapse.http.matrixfederationclient - 577 - WARNING - _maybe_retry_device_resync-3 - {GET-O-121} [orthool.com] Request failed: GET matrix://orthool.com/_matrix/federation/v1/user/devices/%40lucasmendes%3Aorthool.com: HttpResponseException('301: Moved Permanently'),
2020-12-22 13:03:10,617 - synapse.handlers.device - 857 - WARNING - _maybe_retry_device_resync-3 - Failed to handle device list update for @lucasmendes:orthool.com: 301: Moved Permanently,
2020-12-22 13:03:40,582 - synapse.http.matrixfederationclient - 577 - WARNING - _maybe_retry_device_resync-4 - {GET-O-153} [orthool.com] Request failed: GET matrix://orthool.com/_matrix/federation/v1/user/devices/%40lucasmendes%3Aorthool.com: HttpResponseException('301: Moved Permanently'),
2020-12-22 13:03:40,587 - synapse.handlers.device - 857 - WARNING - _maybe_retry_device_resync-4 - Failed to handle device list update for @lucasmendes:orthool.com: 301: Moved Permanently,
2020-12-22 13:04:10,589 - synapse.http.matrixfederationclient - 577 - WARNING - _maybe_retry_device_resync-5 - {GET-O-187} [orthool.com] Request failed: GET matrix://orthool.com/_matrix/federation/v1/user/devices/%40lucasmendes%3Aorthool.com: HttpResponseException('301: Moved Permanently'),
2020-12-22 13:04:10,593 - synapse.handlers.device - 857 - WARNING - _maybe_retry_device_resync-5 - Failed to handle device list update for @lucasmendes:orthool.com: 301: Moved Permanently,
2020-12-22 13:04:40,580 - synapse.http.matrixfederationclient - 577 - WARNING - _maybe_retry_device_resync-6 - {GET-O-220} [orthool.com] Request failed: GET matrix://orthool.com/_matrix/federation/v1/user/devices/%40lucasmendes%3Aorthool.com: HttpResponseException('301: Moved Permanently'),
2020-12-22 13:04:40,584 - synapse.handlers.device - 857 - WARNING - _maybe_retry_device_resync-6 - Failed to handle device list update for @lucasmendes:orthool.com: 301: Moved Permanently,
2020-12-22 13:05:10,576 - synapse.http.matrixfederationclient - 577 - WARNING - _maybe_retry_device_resync-7 - {GET-O-252} [orthool.com] Request failed: GET matrix://orthool.com/_matrix/federation/v1/user/devices/%40lucasmendes%3Aorthool.com: HttpResponseException('301: Moved Permanently'),
2020-12-22 13:05:10,580 - synapse.handlers.device - 857 - WARNING - _maybe_retry_device_resync-7 - Failed to handle device list update for @lucasmendes:orthool.com: 301: Moved Permanently,
2020-12-22 13:05:40,600 - synapse.http.matrixfederationclient - 577 - WARNING - _maybe_retry_device_resync-8 - {GET-O-284} [orthool.com] Request failed: GET matrix://orthool.com/_matrix/federation/v1/user/devices/%40lucasmendes%3Aorthool.com: HttpResponseException('301: Moved Permanently'),
2020-12-22 13:05:40,604 - synapse.handlers.device - 857 - WARNING - _maybe_retry_device_resync-8 - Failed to handle device list update for @lucasmendes:orthool.com: 301: Moved Permanently,
2020-12-22 13:06:10,590 - synapse.http.matrixfederationclient - 577 - WARNING - _maybe_retry_device_resync-9 - {GET-O-317} [orthool.com] Request failed: GET matrix://orthool.com/_matrix/federation/v1/user/devices/%40lucasmendes%3Aorthool.com: HttpResponseException('301: Moved Permanently'),
2020-12-22 13:06:10,595 - synapse.handlers.device - 857 - WARNING - _maybe_retry_device_resync-9 - Failed to handle device list update for @lucasmendes:orthool.com: 301: Moved Permanently,
2020-12-22 13:06:40,587 - synapse.http.matrixfederationclient - 577 - WARNING - _maybe_retry_device_resync-10 - {GET-O-348} [orthool.com] Request failed: GET matrix://orthool.com/_matrix/federation/v1/user/devices/%40lucasmendes%3Aorthool.com: HttpResponseException('301: Moved Permanently'),
2020-12-22 13:06:40,595 - synapse.handlers.device - 857 - WARNING - _maybe_retry_device_resync-10 - Failed to handle device list update for @lucasmendes:orthool.com: 301: Moved Permanently,
2020-12-22 13:07:10,616 - synapse.http.matrixfederationclient - 577 - WARNING - _maybe_retry_device_resync-11 - {GET-O-380} [orthool.com] Request failed: GET matrix://orthool.com/_matrix/federation/v1/user/devices/%40lucasmendes%3Aorthool.com: HttpResponseException('301: Moved Permanently'),
2020-12-22 13:07:10,620 - synapse.handlers.device - 857 - WARNING - _maybe_retry_device_resync-11 - Failed to handle device list update for @lucasmendes:orthool.com: 301: Moved Permanently,
2020-12-22 13:07:40,574 - synapse.http.matrixfederationclient - 577 - WARNING - _maybe_retry_device_resync-12 - {GET-O-412} [orthool.com] Request failed: GET matrix://orthool.com/_matrix/federation/v1/user/devices/%40lucasmendes%3Aorthool.com: HttpResponseException('301: Moved Permanently'),
2020-12-22 13:07:40,577 - synapse.handlers.device - 857 - WARNING - _maybe_retry_device_resync-12 - Failed to handle device list update for @lucasmendes:orthool.com: 301: Moved Permanently,
2020-12-22 13:07:43,925 - synapse.http.matrixfederationclient - 577 - WARNING - _maybe_retry_device_resync-12 - {GET-O-417} [sascha-fuchs.com] Request failed: GET matrix://sascha-fuchs.com/_matrix/federation/v1/user/devices/%40palerius%3Asascha-fuchs.com: HttpResponseException('401: Unauthorized'),
2020-12-22 13:07:43,931 - synapse.handlers.device - 857 - WARNING - _maybe_retry_device_resync-12 - Failed to handle device list update for @palerius:sascha-fuchs.com: 401: Unauthorized,
2020-12-22 13:07:43,938 - synapse.logging.context - 70 - WARNING - _maybe_retry_device_resync-12 - Re-starting finished log context _maybe_retry_device_resync-12,

Steps to reproduce

• during normal server operation, everything works but log gets filled up with retry messages:
  Failed to handle device list update for @lucasmendes:orthool.com: 301: Moved Permanently,

Version information

• Homeserver:

smartceva.com

• Version:
  1.24.0
• Install method:

portainer

• Platform:

docker

[thomasesr]

also, my homeserver has only me using it (@thomas:smartceva.com) I have no idea who @lucasmendes:orthool.com is or why the log is asking me to do a device resync on this random user.

[clokep]

I have no idea who @lucasmendes:orthool.com is or why the log is asking me to do a device resync on this random user.

You likely share an encrypted room with this person.

[clokep]

Looks like that user's server might be broken, https://orthool.com/.well-known/matrix/server points to matrix.orthool.com, but that https://matrix.orthool.com and all other endpoints there are returning a 301.

[thomasesr]

I have no idea who @lucasmendes:orthool.com is or why the log is asking me to do a device resync on this random user.

You likely share an encrypted room with this person.

How can I find out which room it is?

[Adrien-Luxey]

@thomasesr My Synapse logs are filled with synapse.http.matrixfederationclient warnings as well. They are fairly normal once you enable federation, since you (or any other user of your server) are going to join public rooms eventually. And public rooms are filled with members of a faulty instance, causing this warning.

I do have a question for the community though: Is there a way to stop the log-spamming? Maybe these messages should be Notices, given how frequent they are? It's really not informative to me, I have a hard time reading my logs.

[Adrien-Luxey]

Considering your logs: why _maybe_retry_device_resync when 301: Moved Permanently anyway? ^^

[richvdh]

Related: #5442, #8917

[periish]

Hello, my homeserver is completely nonfunctional (as in, for clients connecting) and these are the only error messages that show up in any log output (homeserver.log, stdout and stderr). Whenever my client attempts to send a message, the log fills up with errors such as this one, despite there being no members from the homeservers mentioned present in the room that the messages are sent in.

[vikanezrimaya]

I have recently moved my homeserver and used delegation (and 301 redirects, because some clients don't seem to get the message) to update its location, and now another homeserver which I'm using to debug is spamming these messages and can't seem to send messages to the moved homeserver properly. Hopefully it all clears up when the other server will refetch the /.well-known/matrix/server — it will, right?...

[xundeenergie]

This still filles up my log with MANY entries...

2023-09-11 11:19:42,285 - synapse.handlers.device - 1312 - WARNING - _maybe_retry_device_resync-2 - Failed to handle device list update for @some_user:some_server.tld: 301: Moved Permanently
2023-09-11 11:20:21,585 - synapse.handlers.device - 1312 - WARNING - _maybe_retry_device_resync-12 - Failed to handle device list update for @some_user:some_server.tld: 301: Moved Permanently
2023-09-11 11:20:50,128 - synapse.handlers.device - 1312 - WARNING - _maybe_retry_device_resync-14 - Failed to handle device list update for @some_user:some_server.tld: 301: Moved Permanently
2023-09-11 11:21:20,488 - synapse.handlers.device - 1312 - WARNING - _maybe_retry_device_resync-15 - Failed to handle device list update for @some_user:some_server.tld: 301: Moved Permanently
2023-09-11 11:21:50,796 - synapse.handlers.device - 1312 - WARNING - _maybe_retry_device_resync-16 - Failed to handle device list update for @some_user:some_server.tld: 301: Moved Permanently
2023-09-11 11:22:21,317 - synapse.handlers.device - 1312 - WARNING - _maybe_retry_device_resync-18 - Failed to handle device list update for @some_user:some_server.tld: 301: Moved Permanently
2023-09-11 11:22:51,226 - synapse.handlers.device - 1312 - WARNING - _maybe_retry_device_resync-19 - Failed to handle device list update for @some_user:some_server.tld: 301: Moved Permanently
2023-09-11 11:23:21,014 - synapse.handlers.device - 1312 - WARNING - _maybe_retry_device_resync-20 - Failed to handle device list update for @some_user:some_server.tld: 301: Moved Permanently
2023-09-11 11:23:50,128 - synapse.handlers.device - 1312 - WARNING - _maybe_retry_device_resync-22 - Failed to handle device list update for @some_user:some_server.tld: 301: Moved Permanently
2023-09-11 11:24:20,449 - synapse.handlers.device - 1312 - WARNING - _maybe_retry_device_resync-25 - Failed to handle device list update for @some_user:some_server.tld: 301: Moved Permanently
2023-09-11 11:24:50,258 - synapse.handlers.device - 1312 - WARNING - _maybe_retry_device_resync-26 - Failed to handle device list update for @some_user:some_server.tld: 301: Moved Permanently
2023-09-11 11:25:24,352 - synapse.handlers.device - 1312 - WARNING - _maybe_retry_device_resync-27 - Failed to handle device list update for @some_user:some_server.tld: 301: Moved Permanently
2023-09-11 11:25:50,343 - synapse.handlers.device - 1312 - WARNING - _maybe_retry_device_resync-28 - Failed to handle device list update for @some_user:some_server.tld: 301: Moved Permanently
2023-09-11 11:26:20,502 - synapse.handlers.device - 1312 - WARNING - _maybe_retry_device_resync-29 - Failed to handle device list update for @some_user:some_server.tld: 301: Moved Permanently
2023-09-11 11:26:50,266 - synapse.handlers.device - 1312 - WARNING - _maybe_retry_device_resync-30 - Failed to handle device list update for @some_user:some_server.tld: 301: Moved Permanently
2023-09-11 11:27:20,789 - synapse.handlers.device - 1312 - WARNING - _maybe_retry_device_resync-31 - Failed to handle device list update for @some_user:some_server.tld: 301: Moved Permanently
2023-09-11 11:27:51,150 - synapse.handlers.device - 1312 - WARNING - _maybe_retry_device_resync-32 - Failed to handle device list update for @some_user:some_server.tld: 301: Moved Permanently
2023-09-11 11:28:20,914 - synapse.handlers.device - 1312 - WARNING - _maybe_retry_device_resync-33 - Failed to handle device list update for @some_user:some_server.tld: 301: Moved Permanently
2023-09-11 11:28:51,553 - synapse.handlers.device - 1312 - WARNING - _maybe_retry_device_resync-34 - Failed to handle device list update for @some_user:some_server.tld: 301: Moved Permanently
2023-09-11 11:29:24,069 - synapse.handlers.device - 1312 - WARNING - _maybe_retry_device_resync-35 - Failed to handle device list update for @some_user:some_server.tld: 301: Moved Permanently
2023-09-11 11:30:14,854 - synapse.handlers.device - 1312 - WARNING - _maybe_retry_device_resync-36 - Failed to handle device list update for @some_user:some_server.tld: 301: Moved Permanently
2023-09-11 11:30:50,376 - synapse.handlers.device - 1312 - WARNING - _maybe_retry_device_resync-37 - Failed to handle device list update for @some_user:some_server.tld: 301: Moved Permanently
2023-09-11 11:31:20,685 - synapse.handlers.device - 1312 - WARNING - _maybe_retry_device_resync-38 - Failed to handle device list update for @some_user:some_server.tld: 301: Moved Permanently
2023-09-11 11:31:50,173 - synapse.handlers.device - 1312 - WARNING - _maybe_retry_device_resync-39 - Failed to handle device list update for @some_user:some_server.tld: 301: Moved Permanently
2023-09-11 11:32:20,114 - synapse.handlers.device - 1312 - WARNING - _maybe_retry_device_resync-40 - Failed to handle device list update for @some_user:some_server.tld: 301: Moved Permanently
2023-09-11 11:32:50,447 - synapse.handlers.device - 1312 - WARNING - _maybe_retry_device_resync-42 - Failed to handle device list update for @some_user:some_server.tld: 301: Moved Permanently
2023-09-11 11:33:21,756 - synapse.handlers.device - 1312 - WARNING - _maybe_retry_device_resync-43 - Failed to handle device list update for @some_user:some_server.tld: 301: Moved Permanently
2023-09-11 11:33:53,746 - synapse.handlers.device - 1312 - WARNING - _maybe_retry_device_resync-44 - Failed to handle device list update for @some_user:some_server.tld: 301: Moved Permanently
2023-09-11 11:34:20,790 - synapse.handlers.device - 1312 - WARNING - _maybe_retry_device_resync-45 - Failed to handle device list update for @some_user:some_server.tld: 301: Moved Permanently
2023-09-11 11:34:50,107 - synapse.handlers.device - 1312 - WARNING - _maybe_retry_device_resync-46 - Failed to handle device list update for @some_user:some_server.tld: 301: Moved Permanently
2023-09-11 11:35:20,302 - synapse.handlers.device - 1312 - WARNING - _maybe_retry_device_resync-47 - Failed to handle device list update for @some_user:some_server.tld: 301: Moved Permanently
2023-09-11 11:35:50,759 - synapse.handlers.device - 1312 - WARNING - _maybe_retry_device_resync-48 - Failed to handle device list update for @some_user:some_server.tld: 301: Moved Permanently
2023-09-11 11:36:27,715 - synapse.handlers.device - 1312 - WARNING - _maybe_retry_device_resync-49 - Failed to handle device list update for @some_user:some_server.tld: 301: Moved Permanently
2023-09-11 11:36:50,435 - synapse.handlers.device - 1312 - WARNING - _maybe_retry_device_resync-50 - Failed to handle device list update for @some_user:some_server.tld: 301: Moved Permanently
2023-09-11 11:37:20,484 - synapse.handlers.device - 1312 - WARNING - _maybe_retry_device_resync-52 - Failed to handle device list update for @some_user:some_server.tld: 301: Moved Permanently
2023-09-11 11:38:20,487 - synapse.handlers.device - 1312 - WARNING - _maybe_retry_device_resync-55 - Failed to handle device list update for @some_user:some_server.tld: 301: Moved Permanently
2023-09-11 11:39:23,206 - synapse.handlers.device - 1312 - WARNING - _maybe_retry_device_resync-58 - Failed to handle device list update for @some_user:some_server.tld: 301: Moved Permanently
2023-09-11 11:39:53,991 - synapse.handlers.device - 1312 - WARNING - _maybe_retry_device_resync-59 - Failed to handle device list update for @some_user:some_server.tld: 301: Moved Permanently
2023-09-11 11:40:20,670 - synapse.handlers.device - 1312 - WARNING - _maybe_retry_device_resync-60 - Failed to handle device list update for @some_user:some_server.tld: 301: Moved Permanently
2023-09-11 11:40:50,261 - synapse.handlers.device - 1312 - WARNING - _maybe_retry_device_resync-61 - Failed to handle device list update for @some_user:some_server.tld: 301: Moved Permanently
2023-09-11 11:41:20,358 - synapse.handlers.device - 1312 - WARNING - _maybe_retry_device_resync-62 - Failed to handle device list update for @some_user:some_server.tld: 301: Moved Permanently
2023-09-11 11:41:50,598 - synapse.handlers.device - 1312 - WARNING - _maybe_retry_device_resync-63 - Failed to handle device list update for @some_user:some_server.tld: 301: Moved Permanently
2023-09-11 11:42:20,248 - synapse.handlers.device - 1312 - WARNING - _maybe_retry_device_resync-64 - Failed to handle device list update for @some_user:some_server.tld: 301: Moved Permanently
2023-09-11 11:42:50,891 - synapse.handlers.device - 1312 - WARNING - _maybe_retry_device_resync-65 - Failed to handle device list update for @some_user:some_server.tld: 301: Moved Permanently
2023-09-11 11:43:20,116 - synapse.handlers.device - 1312 - WARNING - _maybe_retry_device_resync-66 - Failed to handle device list update for @some_user:some_server.tld: 301: Moved Permanently
2023-09-11 11:43:52,320 - synapse.handlers.device - 1312 - WARNING - _maybe_retry_device_resync-68 - Failed to handle device list update for @some_user:some_server.tld: 301: Moved Permanently

and this is only one user of MANY users...

[erikjohnston]

I think #16298 will mitigate this a bunch