search

YunoHost-Apps / synapse_ynh

Matrix server (synapse) package for YunoHost
https://matrix.org/
GNU General Public License v3.0
79 stars 42 forks source link

on 1.31.0 Login fails ... syncing forever ... many rooms #257

Open rocky-III opened 3 years ago

rocky-III commented 3 years ago

synapse 1.31.0 is running with my old database from 1.23.--- but now i have problems which are described also here:

Login fails after update from 1.25.0 to 1.26.0 - syncing forever ... many rooms https://github.com/matrix-org/synapse/issues/9264 https://github.com/matrix-org/synapse/issues/9352

tried the fix of @greinick 


Maybe noone needs to revert back to older server versions - I had the same problem and it was solved by correcting a misconfigured homeserver.yaml configuration.

    My configuration is debian but I either had server_name uncommented by accident or the update uncommented this line.
    Line above says: # This is set in /etc/matrix-synapse/conf.d/server_name.yaml for Debian installations.

    public_baseurl was https://servername but had to be https://servername:8448.

After I changed these two settings, logging in on new element devices (including nextcloud client) worked again.

Hope this helps anyone...

Kind regards

Simon

but that did not work also this should been fixed already in 1.31... but even for new accounts without any rooms synapse tries syncing forever... and says: many rooms...

what could I try? Thanks

rocky-III commented 3 years ago

still wondering what is going on...

do this logs help?

journalctl -- Logs begin at Sun 2021-04-18 13:50:59 CEST, end at Mon 2021-04-19 14:03:35 CEST. -- Apr 19 13:54:29 python[3938]: 2021-04-19 13:54:29,650 - synapse.http.matrixfederationclient - 588 - WARNING - _maybe_retry_device_resync-6- {GET-O-395} [matrix.daumiller.eu] Request failed: GET matrix://matrix.daumiller.eu/_matrix/federation/v1/user/devices/%40dorian%3Amatrix.daumiller.eu: HttpResponseException('302: Found') Apr 19 13:54:29 python[3938]: 2021-04-19 13:54:29,651 - synapse.handlers.device - 866 - WARNING - _maybe_retry_device_resync-6- Failed to handle device list update for @dorian:matrix.daumiller.eu: 302: Found Apr 19 13:54:59 python[3938]: 2021-04-19 13:54:59,643 - synapse.http.matrixfederationclient - 588 - WARNING - _maybe_retry_device_resync-7- {GET-O-457} [matrix.daumiller.eu] Request failed: GET matrix://matrix.daumiller.eu/_matrix/federation/v1/user/devices/%40dorian%3Amatrix.daumiller.eu: HttpResponseException('302: Found') Apr 19 13:54:59 python[3938]: 2021-04-19 13:54:59,643 - synapse.handlers.device - 866 - WARNING - _maybe_retry_device_resync-7- Failed to handle device list update for @dorian:matrix.daumiller.eu: 302: Found Apr 19 13:55:29 python[3938]: 2021-04-19 13:55:29,645 - synapse.http.matrixfederationclient - 588 - WARNING - _maybe_retry_device_resync-8- {GET-O-519} [matrix.daumiller.eu] Request failed: GET matrix://matrix.daumiller.eu/_matrix/federation/v1/user/devices/%40dorian%3Amatrix.daumiller.eu: HttpResponseException('302: Found') Apr 19 13:55:29 python[3938]: 2021-04-19 13:55:29,645 - synapse.handlers.device - 866 - WARNING - _maybe_retry_device_resync-8- Failed to handle device list update for @dorian:matrix.daumiller.eu: 302: Found Apr 19 13:55:59 python[3938]: 2021-04-19 13:55:59,641 - synapse.http.matrixfederationclient - 588 - WARNING - _maybe_retry_device_resync-9- {GET-O-581} [matrix.daumiller.eu] Request failed: GET matrix://matrix.daumiller.eu/_matrix/federation/v1/user/devices/%40dorian%3Amatrix.daumiller.eu: HttpResponseException('302: Found') Apr 19 13:55:59 python[3938]: 2021-04-19 13:55:59,642 - synapse.handlers.device - 866 - WARNING - _maybe_retry_device_resync-9- Failed to handle device list update for @dorian:matrix.daumiller.eu: 302: Found Apr 19 13:56:29 python[3938]: 2021-04-19 13:56:29,649 - synapse.http.matrixfederationclient - 588 - WARNING - _maybe_retry_device_resync-10- {GET-O-643} [matrix.daumiller.eu] Request failed: GET matrix://matrix.daumiller.eu/_matrix/federation/v1/user/devices/%40dorian%3Amatrix.daumiller.eu: HttpResponseException('302: Found') Apr 19 13:56:29 python[3938]: 2021-04-19 13:56:29,649 - synapse.handlers.device - 866 - WARNING - _maybe_retry_device_resync-10- Failed to handle device list update for @dorian:matrix.daumiller.eu: 302: Found Apr 19 13:56:31 python[3938]: 2021-04-19 13:56:31,427 - synapse.federation.federation_server - 190 - WARNING - PUT-146- Received another txn 1618331234599 from mozilla.org while still processing 1618331232189 Apr 19 13:56:35 python[3938]: 2021-04-19 13:56:35,792 - synapse.federation.federation_server - 190 - WARNING - PUT-151- Received another txn 1618331234599 from mozilla.org while still processing 1618331232189 Apr 19 13:56:52 python[3938]: 2021-04-19 13:56:52,670 - synapse.federation.federation_server - 190 - WARNING - PUT-155- Received another txn 1618331234599 from mozilla.org while still processing 1618331232189 Apr 19 13:57:01 python[3938]: 2021-04-19 13:57:01,488 - synapse.http.matrixfederationclient - 588 - WARNING - _maybe_retry_device_resync-11- {GET-O-705} [matrix.daumiller.eu] Request failed: GET matrix://matrix.daumiller.eu/_matrix/federation/v1/user/devices/%40dorian%3Amatrix.daumiller.eu: HttpResponseException('302: Found') Apr 19 13:57:01 python[3938]: 2021-04-19 13:57:01,489 - synapse.handlers.device - 866 - WARNING - _maybe_retry_device_resync-11- Failed to handle device list update for @dorian:matrix.daumiller.eu: 302: Found Apr 19 13:57:29 python[3938]: 2021-04-19 13:57:29,654 - synapse.http.matrixfederationclient - 588 - WARNING - _maybe_retry_device_resync-12- {GET-O-767} [matrix.daumiller.eu] Request failed: GET matrix://matrix.daumiller.eu/_matrix/federation/v1/user/devices/%40dorian%3Amatrix.daumiller.eu: HttpResponseException('302: Found') Apr 19 13:57:29 python[3938]: 2021-04-19 13:57:29,654 - synapse.handlers.device - 866 - WARNING - _maybe_retry_device_resync-12- Failed to handle device list update for @dorian:matrix.daumiller.eu: 302: Found Apr 19 13:57:54 python[3938]: 2021-04-19 13:57:54,882 - synapse.federation.federation_server - 190 - WARNING - PUT-167- Received another txn 1618331234599 from mozilla.org while still processing 1618331232189 Apr 19 13:57:59 python[3938]: 2021-04-19 13:57:59,645 - synapse.http.matrixfederationclient - 588 - WARNING - _maybe_retry_device_resync-13- {GET-O-829} [matrix.daumiller.eu] Request failed: GET matrix://matrix.daumiller.eu/_matrix/federation/v1/user/devices/%40dorian%3Amatrix.daumiller.eu: HttpResponseException('302: Found') Apr 19 13:57:59 python[3938]: 2021-04-19 13:57:59,645 - synapse.handlers.device - 866 - WARNING - _maybe_retry_device_resync-13- Failed to handle device list update for @dorian:matrix.daumiller.eu: 302: Found Apr 19 13:58:29 python[3938]: 2021-04-19 13:58:29,642 - synapse.http.matrixfederationclient - 588 - WARNING - _maybe_retry_device_resync-14- {GET-O-891} [matrix.daumiller.eu] Request failed: GET matrix://matrix.daumiller.eu/_matrix/federation/v1/user/devices/%40dorian%3Amatrix.daumiller.eu: HttpResponseException('302: Found') Apr 19 13:58:29 python[3938]: 2021-04-19 13:58:29,642 - synapse.handlers.device - 866 - WARNING - _maybe_retry_device_resync-14- Failed to handle device list update for @dorian:matrix.daumiller.eu: 302: Found Apr 19 13:58:45 python[3938]: 2021-04-19 13:58:45,288 - synapse.federation.federation_server - 190 - WARNING - PUT-181- Received another txn 1618331234599 from mozilla.org while still processing 1618331232189 Apr 19 13:58:59 python[3938]: 2021-04-19 13:58:59,649 - synapse.http.matrixfederationclient - 588 - WARNING - _maybe_retry_device_resync-15- {GET-O-953} [matrix.daumiller.eu] Request failed: GET matrix://matrix.daumiller.eu/_matrix/federation/v1/user/devices/%40dorian%3Amatrix.daumiller.eu: HttpResponseException('302: Found') Apr 19 13:58:59 python[3938]: 2021-04-19 13:58:59,650 - synapse.handlers.device - 866 - WARNING - _maybe_retry_device_resync-15- Failed to handle device list update for @dorian:matrix.daumiller.eu: 302: Found Apr 19 13:59:29 python[3938]: 2021-04-19 13:59:29,640 - synapse.http.matrixfederationclient - 588 - WARNING - _maybe_retry_device_resync-16- {GET-O-1015} [matrix.daumiller.eu] Request failed: GET matrix://matrix.daumiller.eu/_matrix/federation/v1/user/devices/%40dorian%3Amatrix.daumiller.eu: HttpResponseException('302: Found') Apr 19 13:59:29 python[3938]: 2021-04-19 13:59:29,640 - synapse.handlers.device - 866 - WARNING - _maybe_retry_device_resync-16- Failed to handle device list update for @dorian:matrix.daumiller.eu: 302: Found Apr 19 13:59:38 python[3938]: 2021-04-19 13:59:38,160 - synapse.federation.federation_server - 190 - WARNING - PUT-185- Received another txn 1618331234599 from mozilla.org while still processing 1618331232189 Apr 19 14:00:03 python[3938]: 2021-04-19 14:00:03,193 - synapse.http.matrixfederationclient - 588 - WARNING - _maybe_retry_device_resync-17- {GET-O-1078} [matrix.daumiller.eu] Request failed: GET matrix://matrix.daumiller.eu/_matrix/federation/v1/user/devices/%40dorian%3Amatrix.daumiller.eu: HttpResponseException('302: Found') Apr 19 14:00:03 python[3938]: 2021-04-19 14:00:03,194 - synapse.handlers.device - 866 - WARNING - _maybe_retry_device_resync-17- Failed to handle device list update for @dorian:matrix.daumiller.eu: 302: Found Apr 19 14:00:29 python[3938]: 2021-04-19 14:00:29,648 - synapse.http.matrixfederationclient - 588 - WARNING - _maybe_retry_device_resync-18- {GET-O-1140} [matrix.daumiller.eu] Request failed: GET matrix://matrix.daumiller.eu/_matrix/federation/v1/user/devices/%40dorian%3Amatrix.daumiller.eu: HttpResponseException('302: Found') Apr 19 14:00:29 python[3938]: 2021-04-19 14:00:29,649 - synapse.handlers.device - 866 - WARNING - _maybe_retry_device_resync-18- Failed to handle device list update for @dorian:matrix.daumiller.eu: 302: Found Apr 19 14:00:58 systemd[1]: Stopping Synapse Matrix homeserver... Apr 19 14:02:28 systemd[1]: matrix-synapse.service: State 'stop-sigterm' timed out. Killing. Apr 19 14:02:28 systemd[1]: matrix-synapse.service: Killing process 3938 (python) with signal SIGKILL. Apr 19 14:02:28 systemd[1]: matrix-synapse.service: Main process exited, code=killed, status=9/KILL Apr 19 14:02:28 systemd[1]: matrix-synapse.service: Failed with result 'timeout'. Apr 19 14:02:28 systemd[1]: Stopped Synapse Matrix homeserver. Apr 19 14:02:28 systemd[1]: Starting Synapse Matrix homeserver... Apr 19 14:03:23 systemd[1]: Started Synapse Matrix homeserver. Apr 19 14:03:26 python[5549]: This server is configured to use 'matrix.org' as its trusted key server via the Apr 19 14:03:26 python[5549]: 'trusted_key_servers' config option. 'matrix.org' is a good choice for a key Apr 19 14:03:26 python[5549]: server since it is long-lived, stable and trusted. However, some admins may Apr 19 14:03:26 python[5549]: wish to use another server for this purpose. Apr 19 14:03:26 python[5549]: To suppress this warning and continue using 'matrix.org', admins should set Apr 19 14:03:26 python[5549]: 'suppress_key_server_warning' to 'true' in homeserver.yaml. Apr 19 14:03:26 python[5549]: -------------------------------------------------------------------------------- Apr 19 14:03:27 python[5549]: 2021-04-19 14:03:27,008 - root - 325 - WARNING - None- ***** STARTING SERVER ***** Apr 19 14:03:27 python[5549]: 2021-04-19 14:03:27,008 - root - 326 - WARNING - None- Server /opt/yunohost/matrix-synapse/lib/python3.7/site-packages/synapse/app/homeserver.py version 1.31.0 Apr 19 14:03:35 python[5549]: 2021-04-19 14:03:35,090 - synapse.config.appservice - 56 - WARNING - None- Expected None to be a list of AS config files.

/var/log/matrix-synapse/homeserver.log 2021-04-19 14:00:50,957 - synapse.federation.transport.server - 412 - INFO - PUT-201- Received txn 1617795837568 from rwgmobile.ems.host. (PDUs: 0, EDUs: 1) 2021-04-19 14:00:53,920 - synapse.access.http.8008 - 329 - INFO - GET-205- 2.244.29.133 - 8008 - {None} Processed request: 0.001sec/-0.000sec (0.002sec, 0.000sec) (0.000sec/0.000sec/0) 394B 200 "GET /_matrix/client/versions HTTP/1.0" "Mozilla/5.0 (Windows NT 6.1; Win64; x64; rv:87.0) Gecko/20100101 Firefox/87.0" [0 dbevts] 2021-04-19 14:00:54,868 - twisted - 260 - INFO - None- Timing out client: IPv6Address(type='TCP', host='::ffff:76.181.63.141', port=10246, flowInfo=0, scopeID=0) 2021-04-19 14:00:54,870 - synapse.access.https.8448 - 329 - INFO - PUT-198- ::ffff:185.92.68.76 - 8448 - {agilit.nl} Processed request: 4.441sec/-0.000sec (0.007sec, 0.000sec) (0.003sec/4.429sec/3) 11B 200 "PUT /_matrix/federation/v1/send/1617870733042 HTTP/1.1" "Synapse/1.30.1" [0 dbevts] 2021-04-19 14:00:54,886 - synapse.federation.transport.server - 412 - INFO - PUT-206- Received txn 1617870735011 from agilit.nl. (PDUs: 0, EDUs: 1) 2021-04-19 14:00:54,954 - synapse.util.caches.response_cache - 160 - INFO - GET-208- [sync]: using incomplete cached result for [(@chris2:lokal.social, 0, None, '0', False, 'SSEWPNTLIQ')] 2021-04-19 14:00:55,035 - synapse.access.https.8448 - 329 - INFO - PUT-200- ::ffff:168.62.7.95 - 8448 - {superkazuya.com} Processed request: 4.318sec/-0.000sec (0.003sec, 0.002sec) (0.067sec/3.509sec/4) 11B 200 "PUT /_matrix/federation/v1/send/1617825002549 HTTP/1.1" "Synapse/1.30.0" [0 dbevts] 2021-04-19 14:00:55,049 - synapse.access.http.8008 - 329 - INFO - POST-203- 95.216.145.65 - 8008 - {None} Processed request: 4.036sec/-0.000sec (0.004sec, 0.001sec) (0.018sec/4.013sec/2) 212B 401 "POST /_matrix/client/r0/register HTTP/1.0" "python/federation/0.20.0-dev" [0 dbevts] 2021-04-19 14:00:55,051 - synapse.federation.transport.server - 412 - INFO - PUT-204- Received txn 1614950740461 from germanzero.org. (PDUs: 0, EDUs: 1) 2021-04-19 14:00:55,062 - synapse.access.https.8448 - 329 - INFO - PUT-206- ::ffff:185.92.68.76 - 8448 - {agilit.nl} Processed request: 0.178sec/-0.000sec (0.002sec, 0.001sec) (0.143sec/0.029sec/2) 11B 200 "PUT /_matrix/federation/v1/send/1617870735011 HTTP/1.1" "Synapse/1.30.1" [0 dbevts] 2021-04-19 14:00:55,114 - synapse.access.https.8448 - 329 - INFO - PUT-201- ::ffff:52.57.205.175 - 8448 - {rwgmobile.ems.host} Processed request: 4.314sec/-0.000sec (0.002sec, 0.005sec) (3.124sec/1.178sec/7) 11B 200 "PUT /_matrix/federation/v1/send/1617795837568 HTTP/1.1" "Synapse/1.31.0" [0 dbevts] 2021-04-19 14:00:55,509 - synapse.federation.transport.server - 412 - INFO - PUT-209- Received txn 1618686758867 from lightnovel-dungeon.de. (PDUs: 0, EDUs: 1) 2021-04-19 14:00:57,294 - synapse.access.https.8448 - 329 - INFO - PUT-209- 2003:e4:870d:8035:aa5f:d627:53a:473c - 8448 - {lightnovel-dungeon.de} Processed request: 1.794sec/-0.000sec (0.003sec, 0.001sec) (0.002sec/1.785sec/4) 11B 200 "PUT /_matrix/federation/v1/send/1618686758867 HTTP/1.1" "Synapse/1.28.0" [0 dbevts] 2021-04-19 14:00:58,035 - twisted - 260 - INFO - None- Received SIGTERM, shutting down. 2021-04-19 14:00:58,036 - synapse.handlers.presence - 331 - INFO - presence.on_shutdown-0- Performing _on_shutdown. Persisting 75 unpersisted changes 2021-04-19 14:00:58,037 - synapse.app._base - 497 - INFO - None- Shutting down... 2021-04-19 14:00:58,049 - synapse.handlers.presence - 342 - INFO - presence.on_shutdown-0- Finished _on_shutdown 2021-04-19 14:00:58,052 - synapse.http.site - 232 - INFO - PUT-199- Connection from client lost before response was sent 2021-04-19 14:00:58,053 - twisted - 260 - INFO - None- (TCP Port 8008 Closed) 2021-04-19 14:00:58,054 - twisted - 260 - INFO - None- (TCP Port 8008 Closed) 2021-04-19 14:00:58,055 - synapse.http.site - 232 - INFO - GET-208- Connection from client lost before response was sent 2021-04-19 14:00:58,057 - synapse.http.site - 232 - INFO - PUT-204- Connection from client lost before response was sent 2021-04-19 14:00:58,058 - twisted - 260 - INFO - None- (TLS Port 8448 Closed) 2021-04-19 14:03:26,997 - twisted - 260 - INFO - None- Redirected stdout/stderr to logs 2021-04-19 14:03:27,008 - root - 325 - WARNING - None- ***** STARTING SERVER ***** 2021-04-19 14:03:27,008 - root - 326 - WARNING - None- Server /opt/yunohost/matrix-synapse/lib/python3.7/site-packages/synapse/app/homeserver.py version 1.31.0 2021-04-19 14:03:27,009 - root - 327 - INFO - None- Server hostname: lokal.social 2021-04-19 14:03:27,009 - root - 328 - INFO - None- Instance name: master 2021-04-19 14:03:27,009 - synapse.app.homeserver - 352 - INFO - None- Setting up server 2021-04-19 14:03:27,009 - synapse.server - 274 - INFO - None- Setting up. 2021-04-19 14:03:27,156 - synapse.storage.databases - 50 - INFO - None- [database config 'master']: Checking database server 2021-04-19 14:03:30,857 - synapse.storage.databases - 56 - INFO - None- [database config 'master']: Preparing for databases ['main', 'state'] 2021-04-19 14:03:30,858 - synapse.storage.prepare_database - 100 - INFO - None- ['main', 'state']: Checking existing schema version 2021-04-19 14:03:30,941 - synapse.storage.prepare_database - 109 - INFO - None- ['main', 'state']: Existing schema is 59 (+15 deltas) 2021-04-19 14:03:30,943 - synapse.storage.databases.main - 379 - INFO - None- Checking database for consistency with configuration... 2021-04-19 14:03:30,945 - synapse.storage.prepare_database - 376 - INFO - None- Applying schema deltas for v59 2021-04-19 14:03:30,988 - synapse.storage.prepare_database - 501 - INFO - None- Schema now up to date 2021-04-19 14:03:33,947 - synapse.storage.databases - 69 - INFO - None- [database config 'master']: Starting 'main' database 2021-04-19 14:03:33,948 - synapse.storage.util.id_generators - 56 - INFO - None- initialising stream generator for presence_stream(stream_id) 2021-04-19 14:03:34,396 - synapse.storage.util.id_generators - 56 - INFO - None- initialising stream generator for public_room_list_stream(stream_id) 2021-04-19 14:03:34,588 - synapse.storage.util.id_generators - 56 - INFO - None- initialising stream generator for device_lists_stream(stream_id) 2021-04-19 14:03:34,679 - synapse.storage.util.id_generators - 56 - INFO - None- initialising stream generator for user_signature_stream(stream_id) 2021-04-19 14:03:34,693 - synapse.storage.util.id_generators - 56 - INFO - None- initialising stream generator for device_lists_outbound_pokes(stream_id) 2021-04-19 14:03:34,745 - synapse.storage.util.id_generators - 56 - INFO - None- initialising stream generator for e2e_cross_signing_keys(stream_id) 2021-04-19 14:03:34,957 - synapse.storage.util.id_generators - 56 - INFO - None- initialising stream generator for event_reports(id) 2021-04-19 14:03:34,971 - synapse.storage.util.id_generators - 56 - INFO - None- initialising stream generator for push_rules(id) 2021-04-19 14:03:34,977 - synapse.storage.util.id_generators - 56 - INFO - None- initialising stream generator for push_rules_enable(id) 2021-04-19 14:03:34,983 - synapse.storage.util.id_generators - 56 - INFO - None- initialising stream generator for local_group_updates(stream_id) 2021-04-19 14:03:35,090 - synapse.config.appservice - 56 - WARNING - None- Expected None to be a list of AS config files. 2021-04-19 14:03:35,252 - synapse.storage.databases.main.event_push_actions - 538 - INFO - None- Searching for stream ordering 1 month ago

MayeulC commented 2 years ago

Maybe sync_response_cache_duration can help you? Edit: I thought I was on the upstream synapse repo, which was in another tab. I'm proposing to change the default in #321