My server takes up a lot of CPU and RAM after a database restore #17138
Description
Description
Since I restored a backup of my database, I've been unable to connect to synapse matrix. It simply takes up all the RAM and CPU available on the server.
I've talked about it on the matrix channel, but we haven't managed to solve the problem.
I tried REINDEX and VACUUM FULL. I also disabled presence and changed some federation parameters in homeserver.yaml :
federation:
destination_min_retry_interval: 1m
destination_retry_multiplier: 5
destination_max_retry_interval: 365d
but after reboot, the same problems occur
Steps to reproduce
- Drop database
- Install the backup
- Launch synapse matrix
Homeserver
matrix.cocamserverguild.com
Synapse Version
1.105.1
Installation Method
Debian packages from packages.matrix.org
Database
PostgreSQL (single one, restored from a backup)
Workers
Single process
Platform
It's running on a Debian machine on a VPS.
2 CPU, 4 Go RAM
Configuration
No response
Relevant log output
2024-04-30 18:21:38,774 - synapse.app.homeserver - 356 - INFO - main - Setting up server
2024-04-30 18:21:38,775 - synapse.server - 345 - INFO - main - Setting up.
2024-04-30 18:21:38,832 - synapse.storage.databases - 73 - INFO - main - [database config 'master']: Checking database server
2024-04-30 18:21:38,870 - synapse.storage.databases - 76 - INFO - main - [database config 'master']: Preparing for databases ['main', 'state']
2024-04-30 18:21:38,870 - synapse.storage.prepare_database - 135 - INFO - main - ['main', 'state']: Checking existing schema version
2024-04-30 18:21:38,896 - synapse.storage.prepare_database - 139 - INFO - main - ['main', 'state']: Existing schema is 84 (+4 deltas)
2024-04-30 18:21:38,896 - synapse.storage.databases.main - 391 - INFO - main - Checking database for consistency with configuration...
2024-04-30 18:21:38,904 - synapse.storage.prepare_database - 433 - INFO - main - Applying schema deltas for v84
2024-04-30 18:21:38,916 - synapse.storage.prepare_database - 568 - INFO - main - Schema now up to date
2024-04-30 18:21:38,920 - synapse.storage.databases - 91 - INFO - main - [database config 'master']: Starting 'main' database
2024-04-30 18:21:42,990 - synapse.storage.util.id_generators - 99 - INFO - main - Initialising stream generator for pushers(id): 3770
2024-04-30 18:21:42,994 - synapse.storage.util.id_generators - 99 - INFO - main - Initialising stream generator for deleted_pushers(stream_id): 3733
2024-04-30 18:21:42,999 - synapse.storage.util.id_generators - 99 - INFO - main - Initialising stream generator for push_rules_stream(stream_id): 176
2024-04-30 18:21:43,010 - synapse.storage.util.id_generators - 99 - INFO - main - Initialising stream generator for push_rules(id): 37
2024-04-30 18:21:43,014 - synapse.storage.util.id_generators - 99 - INFO - main - Initialising stream generator for push_rules_enable(id): 63
2024-04-30 18:21:43,049 - synapse.storage.util.id_generators - 99 - INFO - main - Initialising stream generator for e2e_cross_signing_keys(stream_id): 51451
2024-04-30 18:21:43,050 - synapse.storage.databases.main.event_push_actions - 1247 - INFO - main - Searching for stream ordering 1 month ago
2024-04-30 18:21:43,073 - synapse.storage.databases.main.event_push_actions - 1251 - INFO - main - Found stream ordering 1 month ago: it's 522175
2024-04-30 18:21:43,073 - synapse.storage.databases.main.event_push_actions - 1254 - INFO - main - Searching for stream ordering 1 day ago
2024-04-30 18:21:43,085 - synapse.storage.databases.main.event_push_actions - 1258 - INFO - main - Found stream ordering 1 day ago: it's 611265
2024-04-30 18:21:43,392 - synapse.storage.util.id_generators - 99 - INFO - main - Initialising stream generator for access_tokens(id): 213
2024-04-30 18:21:43,396 - synapse.storage.util.id_generators - 99 - INFO - main - Initialising stream generator for refresh_tokens(id): 1
2024-04-30 18:21:43,408 - synapse.storage.util.id_generators - 99 - INFO - main - Initialising stream generator for event_reports(id): 2
2024-04-30 18:21:43,415 - synapse.storage.util.id_generators - 99 - INFO - main - Initialising stream generator for device_lists_stream(stream_id): 1472508
2024-04-30 18:21:43,417 - synapse.storage.util.id_generators - 99 - INFO - main - Initialising stream generator for user_signature_stream(stream_id): 1
2024-04-30 18:21:43,427 - synapse.storage.util.id_generators - 99 - INFO - main - Initialising stream generator for device_lists_outbound_pokes(stream_id): 1454833
2024-04-30 18:21:43,436 - synapse.storage.util.id_generators - 99 - INFO - main - Initialising stream generator for device_lists_changes_in_room(stream_id): 1472508
2024-04-30 18:21:43,440 - synapse.storage.util.id_generators - 99 - INFO - main - Initialising stream generator for device_lists_remote_pending(stream_id): 1472510
2024-04-30 18:21:43,448 - synapse.storage.util.id_generators - 99 - INFO - main - Initialising stream generator for device_lists_changes_converted_stream_position(stream_id): 1472510
2024-04-30 18:21:43,755 - synapse.storage.databases - 108 - INFO - main - [database config 'master']: Starting 'state' database
2024-04-30 18:21:43,764 - synapse.storage.databases - 123 - INFO - main - [database config 'master']: prepared
2024-04-30 18:21:43,770 - synapse.server - 348 - INFO - main - Finished setting up.
2024-04-30 18:21:43,819 - synapse.push.pusher - 45 - INFO - main - email enable notifs: False
2024-04-30 18:21:43,822 - synapse.federation.federation_server - 1379 - INFO - main - Registering federation EDU handler for 'm.device_list_update'
2024-04-30 18:21:43,823 - synapse.federation.federation_server - 1399 - INFO - main - Registering federation query handler for 'profile'
2024-04-30 18:21:43,824 - synapse.federation.federation_server - 1379 - INFO - main - Registering federation EDU handler for 'm.presence'
2024-04-30 18:21:43,830 - synapse.federation.federation_server - 1379 - INFO - main - Registering federation EDU handler for 'm.typing'
2024-04-30 18:21:43,831 - synapse.federation.federation_server - 1399 - INFO - main - Registering federation query handler for 'directory'
2024-04-30 18:21:43,832 - twisted - 282 - INFO - main - Redirected stdout/stderr to logs
2024-04-30 18:21:43,833 - synapse.app.homeserver - 179 - INFO - sentinel - Running
2024-04-30 18:21:43,836 - synapse.app.homeserver - 36 - INFO - sentinel - Set file limit to: 524288
2024-04-30 18:21:43,842 - synapse.handlers.deactivate_account - 245 - INFO - user_parter_loop-0 - Starting user parter
2024-04-30 18:21:43,933 - synapse.util.caches.lrucache - 231 - INFO - sentinel - Expiring LRU caches after 1800 seconds
2024-04-30 18:21:43,942 - synapse.push.mailer - 138 - INFO - sentinel - Created Mailer for app_name Cocamserverguild
2024-04-30 18:21:43,943 - synapse.push.mailer - 138 - INFO - sentinel - Created Mailer for app_name Cocamserverguild
2024-04-30 18:21:43,944 - synapse.push.mailer - 138 - INFO - sentinel - Created Mailer for app_name Cocamserverguild
2024-04-30 18:21:43,944 - synapse.federation.federation_server - 1379 - INFO - sentinel - Registering federation EDU handler for 'm.receipt'
2024-04-30 18:21:43,945 - synapse.federation.federation_server - 1379 - INFO - sentinel - Registering federation EDU handler for 'm.signing_key_update'
2024-04-30 18:21:43,945 - synapse.federation.federation_server - 1379 - INFO - sentinel - Registering federation EDU handler for 'org.matrix.signing_key_update'
2024-04-30 18:21:43,945 - synapse.federation.federation_server - 1399 - INFO - sentinel - Registering federation query handler for 'client_keys'
2024-04-30 18:21:43,945 - synapse.federation.federation_server - 1379 - INFO - sentinel - Registering federation EDU handler for 'm.direct_to_device'
2024-04-30 18:21:43,964 - synapse.util.httpresourcetree - 56 - INFO - sentinel - Attaching <synapse.rest.health.HealthResource object at 0x7f4c9829d100> to path b'/health'
2024-04-30 18:21:43,964 - synapse.util.httpresourcetree - 56 - INFO - sentinel - Attaching <synapse.rest.ClientRestResource object at 0x7f4c9829d220> to path b'/_matrix/client'
2024-04-30 18:21:43,964 - synapse.util.httpresourcetree - 56 - INFO - sentinel - Attaching <twisted.web.resource.Resource object at 0x7f4c9825cca0> to path b'/.well-known'
2024-04-30 18:21:43,964 - synapse.util.httpresourcetree - 56 - INFO - sentinel - Attaching <synapse.rest.admin.AdminRestResource object at 0x7f4c9825ceb0> to path b'/_synapse/admin'
2024-04-30 18:21:43,964 - synapse.util.httpresourcetree - 56 - INFO - sentinel - Attaching <synapse.rest.synapse.client.pick_idp.PickIdpResource object at 0x7f4c981f4910> to path b'/_synapse/client/pick_idp'
2024-04-30 18:21:43,964 - synapse.util.httpresourcetree - 56 - INFO - sentinel - Attaching <twisted.web.resource.Resource object at 0x7f4c981f49d0> to path b'/_synapse/client/pick_username'
2024-04-30 18:21:43,964 - synapse.util.httpresourcetree - 56 - INFO - sentinel - Attaching <synapse.rest.synapse.client.new_user_consent.NewUserConsentResource object at 0x7f4c981f4d00> to path b'/_synapse/client/new_user_consent'
2024-04-30 18:21:43,964 - synapse.util.httpresourcetree - 56 - INFO - sentinel - Attaching <synapse.rest.synapse.client.sso_register.SsoRegisterResource object at 0x7f4c981f4d30> to path b'/_synapse/client/sso_register'
2024-04-30 18:21:43,964 - synapse.util.httpresourcetree - 56 - INFO - sentinel - Attaching <synapse.rest.synapse.client.unsubscribe.UnsubscribeResource object at 0x7f4c981f4fa0> to path b'/_synapse/client/unsubscribe'
2024-04-30 18:21:43,965 - synapse.util.httpresourcetree - 56 - INFO - sentinel - Attaching <synapse.rest.synapse.client.password_reset.PasswordResetSubmitTokenResource object at 0x7f4c981f4fd0> to path b'/_synapse/client/password_reset/email/submit_token'
2024-04-30 18:21:43,965 - synapse.util.httpresourcetree - 56 - INFO - sentinel - Attaching FilePath('/opt/venvs/matrix-synapse/lib/python3.9/site-packages/synapse/static') to path b'/_matrix/static'
2024-04-30 18:21:43,965 - synapse.util.httpresourcetree - 56 - INFO - sentinel - Attaching <synapse.rest.media.media_repository_resource.MediaRepositoryResource object at 0x7f4c981fb040> to path b'/_matrix/media/r0'
2024-04-30 18:21:43,965 - synapse.util.httpresourcetree - 56 - INFO - sentinel - Attaching <synapse.rest.media.media_repository_resource.MediaRepositoryResource object at 0x7f4c981fb040> to path b'/_matrix/media/v3'
2024-04-30 18:21:43,965 - synapse.util.httpresourcetree - 56 - INFO - sentinel - Attaching <synapse.rest.media.media_repository_resource.MediaRepositoryResource object at 0x7f4c981fb040> to path b'/_matrix/media/v1'
2024-04-30 18:21:43,965 - synapse.util.httpresourcetree - 56 - INFO - sentinel - Attaching <synapse.federation.transport.server.TransportLayerServer object at 0x7f4c981fb6a0> to path b'/_matrix/federation'
2024-04-30 18:21:43,965 - synapse.util.httpresourcetree - 56 - INFO - sentinel - Attaching <synapse.rest.key.v2.KeyResource object at 0x7f4c981fb760> to path b'/_matrix/key'
2024-04-30 18:21:43,965 - synapse.util.httpresourcetree - 56 - INFO - sentinel - Attaching <synapse.rest.consent.consent_resource.ConsentResource object at 0x7f4c9820d790> to path b'/_matrix/consent'
2024-04-30 18:21:43,966 - twisted - 282 - INFO - sentinel - SynapseSite starting on 8008
2024-04-30 18:21:43,966 - twisted - 282 - INFO - sentinel - SynapseSite starting on 8008
2024-04-30 18:21:43,967 - synapse.app._base - 438 - INFO - sentinel - Synapse now listening on TCP port 8008
2024-04-30 18:21:44,108 - synapse.storage.background_updates - 415 - INFO - background_updates-0 - Starting background schema updates for database master
2024-04-30 18:21:44,110 - synapse.handlers.deactivate_account - 255 - INFO - user_parter_loop-0 - User parter finished: stopping
2024-04-30 18:21:44,111 - synapse.federation.sender - 1019 - INFO - wake_destinations_needing_catchup-0 - Destination xmr.se has outstanding catch-up, waking up.
2024-04-30 18:21:44,147 - synapse.storage.background_updates - 433 - INFO - background_updates-0 - No more background updates to do. Unscheduling background update task.
2024-04-30 18:21:44,148 - synapse.push.pusherpool - 424 - INFO - start_pushers-0 - Starting pusher @misaki:matrix.cocamserverguild.com / im.vector.app.android:eYzsIrKgTlCTZXLArVex2h:APA91bGh_09iiotAPpBNsga2fprmVqfoNmdtdzE7SgkOFKsDu-FxDXhIGCGlrHdpNiGRs772rH_0G4H8azbYpsa-IayBV_XxBsfxKQTTfa7F3eCr-Tvp7OUEr3iScRBUV9W2w1Sol9xK
2024-04-30 18:21:44,149 - synapse.push.pusherpool - 424 - INFO - start_pushers-0 - Starting pusher @deathlock666:matrix.cocamserverguild.com / im.vector.app.ios.prod:ftea9GWaL/oXoGmCnYHI52q6qXk35dG3IMFAKJJUjwc=
2024-04-30 18:21:44,150 - synapse.push.pusherpool - 424 - INFO - start_pushers-0 - Starting pusher @bruneau:matrix.cocamserverguild.com / im.vector.app.android:d3sBZXREQn-fg4lOle6HYR:APA91bGNlu8NeyorDyX87mT51hggxbtWmJNTw_4pN5DE0Wf5vy8hcXgavdxSOqXVlrQ_VD1rXW3MX9MKUQGw0fV692AgZyWV3zjAPYzE4niYlpLVCY6evuZmfJW7lk4jZPcIjm1_RFwm
2024-04-30 18:21:44,152 - synapse.push.pusherpool - 424 - INFO - start_pushers-0 - Starting pusher @sandra:matrix.cocamserverguild.com / im.vector.app.android:fTx6LibkSvqUte3EK663_k:APA91bGAfyrCb0b6loApJDOw5dFFnok5BAXX0LeakDzZloDOQUVE1PXTo93UxgejyhUB6WcP_Ba0csfrmDd5zIkWML3biPjt5yfergkC4ZklYk7OSXO8iNabsoy5xeGjBdE22km4Su-o
2024-04-30 18:21:44,155 - synapse.push.pusherpool - 424 - INFO - start_pushers-0 - Starting pusher @vert_of_leanbox:matrix.cocamserverguild.com / im.vector.app.android:dyzYTAvdRQ-SuMus1uzZDo:APA91bGWhYk_3YSeruWMogXYxnVZ7aJxW1zw5799ZeJFgFwVrs6Vsajl0vqw70olRQ5mesX3EC5w65lwxmGNe4PIvBIWfBAB7o4WPPc6AWTGpn-1h22J0Sozt-zO8w4naSIH-dkYBHqz
2024-04-30 18:21:44,155 - synapse.push.pusherpool - 424 - INFO - start_pushers-0 - Starting pusher @alexisauvinet1999:matrix.cocamserverguild.com / im.vector.app.android:fLp0WSl3TDyPu1OrDJCE8D:APA91bG7QCEte0kZMuUo4v5WqBvUwsx8aYo6BIjIYHon0jSjOkPJ-j4ri9Abu9KFXgzIUYOZ0tWvBAu73r2P9TVZCdH12CHRpJTXEXdQ3RJK9lfX9mL2oQ776mEaE5qe8zRMyZ62BS9Z
2024-04-30 18:21:44,158 - synapse.push.pusherpool - 424 - INFO - start_pushers-0 - Starting pusher @seiso_san:matrix.cocamserverguild.com / im.vector.app.ios.prod:kmbOMwOS2gAi8RBiEpYe/BVZA6EeVRcXqH3J1brFuyw=
2024-04-30 18:21:44,170 - synapse.push.pusherpool - 424 - INFO - start_pushers-0 - Starting pusher @ahykono:matrix.cocamserverguild.com / im.vector.app.android:fSY6IGsQRFug9Hzd0u1Z0X:APA91bEfr-ziSCQZWM3HWAg20bzt2xsGhvLvDXmUO5gdkUMPPSIc4a-h3a3LGxPnkExC3AHW_V6MQbJHam6Fntj_SuBukLwrsT47Wz9vfwiqikHRBrXNC5LuZaAVuPtxxIQs9dFSf7Eq
2024-04-30 18:21:44,171 - synapse.push.pusherpool - 424 - INFO - start_pushers-0 - Starting pusher @dragonwielder200:matrix.cocamserverguild.com / im.vector.app.ios.prod:mMaEMxcZ4geHI7T+RD4dbPNl9vFyb/mamaqZPBPvEJg=
2024-04-30 18:21:44,172 - synapse.push.pusherpool - 424 - INFO - start_pushers-0 - Starting pusher @jaymel120:matrix.cocamserverguild.com / im.vector.app.ios.prod:Eo4Whj7Lu9OkMsUoAIQqmnRk6wNDqLWWyp0MxoMN4i8=
2024-04-30 18:21:44,205 - synapse.push.pusherpool - 372 - INFO - start_pushers-0 - Started pushers
2024-04-30 18:21:44,235 - synapse.federation.sender.transaction_manager - 127 - INFO - federation_transaction_transmission_loop-0 - TX [xmr.se] {1714501303820} Sending transaction [1714501303820], (PDUs: 0, EDUs: 3)
2024-04-30 18:21:44,237 - synapse.http.federation.well_known_resolver - 260 - INFO - federation_transaction_transmission_loop-0 - Fetching https://xmr.se/.well-known/matrix/server
2024-04-30 18:21:44,247 - synapse.http.client - 200 - INFO - sentinel - Blocked 45.154.252.164 from DNS resolution to xmr.se
2024-04-30 18:21:44,247 - synapse.http.federation.well_known_resolver - 291 - INFO - federation_transaction_transmission_loop-0 - Error fetching https://xmr.se/.well-known/matrix/server: DNS lookup failed: no results for hostname lookup: xmr.se.
2024-04-30 18:21:44,249 - twisted - 282 - INFO - federation_transaction_transmission_loop-0 - b'/etc/resolv.conf' changed, reparsing
2024-04-30 18:21:44,250 - twisted - 282 - INFO - federation_transaction_transmission_loop-0 - Resolver added ('8.8.8.8', 53) to server list
2024-04-30 18:21:44,250 - twisted - 282 - INFO - federation_transaction_transmission_loop-0 - Resolver added ('8.8.4.4', 53) to server list
2024-04-30 18:21:44,309 - synapse.http.client - 200 - INFO - sentinel - Blocked 45.154.252.164 from DNS resolution to xmr.se
2024-04-30 18:21:44,309 - synapse.http.federation.matrix_federation_agent - 371 - INFO - federation_transaction_transmission_loop-0 - Failed to connect to xmr.se:443: DNS lookup failed: no results for hostname lookup: xmr.se.
2024-04-30 18:21:44,310 - synapse.http.matrixfederationclient - 799 - INFO - federation_transaction_transmission_loop-0 - {PUT-O-1} [xmr.se] Request failed: PUT matrix-federation://xmr.se/_matrix/federation/v1/send/1714501303820: DNSLookupError('no results for hostname lookup: xmr.se')
2024-04-30 18:21:44,423 - synapse.crypto.keyring - 677 - INFO - PerspectivesKeyFetcher-0 - Requesting keys [_FetchKeyRequest(server_name='reboot.fi', minimum_valid_until_ts=1714501304410, key_ids=['ed25519:a_vsul'])] from notary server matrix.org
2024-04-30 18:21:44,424 - synapse.crypto.keyring - 677 - INFO - PerspectivesKeyFetcher-0 - Requesting keys [_FetchKeyRequest(server_name='reboot.fi', minimum_valid_until_ts=1714501304410, key_ids=['ed25519:a_vsul'])] from notary server cocamserverguild.com
2024-04-30 18:21:44,429 - synapse.http.federation.well_known_resolver - 260 - INFO - PerspectivesKeyFetcher-0 - Fetching https://matrix.org/.well-known/matrix/server
2024-04-30 18:21:44,431 - synapse.crypto.keyring - 632 - WARNING - PerspectivesKeyFetcher-0 - Key lookup failed from 'cocamserverguild.com': Not retrying server cocamserverguild.com because we tried it recently retry_last_ts=1714500351439 and we won't check for another retry_interval=12990479ms.
2024-04-30 18:21:44,498 - synapse.http.federation.well_known_resolver - 197 - INFO - PerspectivesKeyFetcher-0 - Response from .well-known: {'m.server': 'matrix-federation.matrix.org:443'}
2024-04-30 18:21:44,650 - synapse.http.matrixfederationclient - 362 - INFO - PerspectivesKeyFetcher-0 - {POST-O-2} [matrix.org] Completed request: 200 OK in 0.23 secs, got 438 bytes - POST matrix-federation://matrix.org/_matrix/key/v2/query
2024-04-30 18:21:44,688 - synapse.federation.transport.server.federation - 112 - INFO - PUT-0 - Received txn 1713943604393 from reboot.fi. (PDUs: 0, EDUs: 1)
2024-04-30 18:21:44,755 - synapse.access.http.8008 - 472 - INFO - PUT-0 - 81.6.39.188 - 8008 - {reboot.fi} Processed request: 0.344sec/0.001sec (0.008sec, 0.002sec) (0.004sec/0.050sec/8) 11B 200 "PUT /_matrix/federation/v1/send/1713943604393 HTTP/1.1" "Synapse/1.105.1" [0 dbevts]
2024-04-30 18:21:49,634 - synapse.crypto.keyring - 677 - INFO - PerspectivesKeyFetcher-1 - Requesting keys [_FetchKeyRequest(server_name='roguesrepast.cafe', minimum_valid_until_ts=1714501309628, key_ids=['ed25519:a_OHzH'])] from notary server matrix.org
2024-04-30 18:21:49,637 - synapse.crypto.keyring - 677 - INFO - PerspectivesKeyFetcher-1 - Requesting keys [_FetchKeyRequest(server_name='roguesrepast.cafe', minimum_valid_until_ts=1714501309628, key_ids=['ed25519:a_OHzH'])] from notary server cocamserverguild.com
2024-04-30 18:21:49,637 - synapse.crypto.keyring - 632 - WARNING - PerspectivesKeyFetcher-1 - Key lookup failed from 'cocamserverguild.com': Not retrying server cocamserverguild.com because we tried it recently retry_last_ts=1714500351439 and we won't check for another retry_interval=12990479ms.
2024-04-30 18:21:49,857 - synapse.http.client - 200 - INFO - sentinel - Blocked 45.154.252.164 from DNS resolution to xmr.se
2024-04-30 18:21:49,857 - synapse.http.federation.matrix_federation_agent - 371 - INFO - federation_transaction_transmission_loop-0 - Failed to connect to xmr.se:443: DNS lookup failed: no results for hostname lookup: xmr.se.
2024-04-30 18:21:49,857 - synapse.http.matrixfederationclient - 799 - INFO - federation_transaction_transmission_loop-0 - {PUT-O-1} [xmr.se] Request failed: PUT matrix-federation://xmr.se/_matrix/federation/v1/send/1714501303820: DNSLookupError('no results for hostname lookup: xmr.se')
2024-04-30 18:21:50,264 - synapse.http.matrixfederationclient - 362 - INFO - PerspectivesKeyFetcher-1 - {POST-O-4} [matrix.org] Completed request: 200 OK in 0.63 secs, got 454 bytes - POST matrix-federation://matrix.org/_matrix/key/v2/query
2024-04-30 18:21:50,281 - synapse.federation.transport.server.federation - 112 - INFO - PUT-1 - Received txn 1714181631145 from roguesrepast.cafe. (PDUs: 0, EDUs: 1)
2024-04-30 18:21:50,282 - synapse.federation.transport.server.federation - 112 - INFO - PUT-2 - Received txn 1714181631145 from roguesrepast.cafe. (PDUs: 0, EDUs: 1)
2024-04-30 18:21:50,282 - synapse.util.caches.response_cache - 275 - INFO - PUT-2 - [fed_txn_handler]: using incomplete cached result for [('roguesrepast.cafe', '1714181631145')]
2024-04-30 18:21:50,282 - synapse.federation.transport.server.federation - 112 - INFO - PUT-3 - Received txn 1714181631145 from roguesrepast.cafe. (PDUs: 0, EDUs: 1)
2024-04-30 18:21:50,282 - synapse.util.caches.response_cache - 275 - INFO - PUT-3 - [fed_txn_handler]: using incomplete cached result for [('roguesrepast.cafe', '1714181631145')]
2024-04-30 18:21:50,282 - synapse.federation.transport.server.federation - 112 - INFO - PUT-4 - Received txn 1714181631145 from roguesrepast.cafe. (PDUs: 0, EDUs: 1)
2024-04-30 18:21:50,284 - synapse.util.caches.response_cache - 275 - INFO - PUT-4 - [fed_txn_handler]: using incomplete cached result for [('roguesrepast.cafe', '1714181631145')]
2024-04-30 18:21:50,284 - synapse.federation.transport.server.federation - 112 - INFO - PUT-5 - Received txn 1714181631145 from roguesrepast.cafe. (PDUs: 0, EDUs: 1)
2024-04-30 18:21:50,284 - synapse.util.caches.response_cache - 275 - INFO - PUT-5 - [fed_txn_handler]: using incomplete cached result for [('roguesrepast.cafe', '1714181631145')]
2024-04-30 18:21:50,284 - synapse.federation.transport.server.federation - 112 - INFO - PUT-6 - Received txn 1714181631145 from roguesrepast.cafe. (PDUs: 0, EDUs: 1)
2024-04-30 18:21:50,284 - synapse.util.caches.response_cache - 275 - INFO - PUT-6 - [fed_txn_handler]: using incomplete cached result for [('roguesrepast.cafe', '1714181631145')]
2024-04-30 18:21:50,330 - synapse.access.http.8008 - 472 - INFO - PUT-1 - 154.38.186.98 - 8008 - {roguesrepast.cafe} Processed request: 0.696sec/0.006sec (0.011sec, 0.003sec) (0.006sec/0.031sec/8) 11B 200 "PUT /_matrix/federation/v1/send/1714181631145 HTTP/1.1" "Synapse/1.105.1" [0 dbevts]
2024-04-30 18:21:50,331 - synapse.access.http.8008 - 472 - INFO - PUT-2 - 154.38.186.98 - 8008 - {roguesrepast.cafe} Processed request: 0.694sec/0.006sec (0.002sec, 0.000sec) (0.000sec/0.000sec/0) 11B 200 "PUT /_matrix/federation/v1/send/1714181631145 HTTP/1.1" "Synapse/1.105.1" [0 dbevts]
2024-04-30 18:21:50,332 - synapse.access.http.8008 - 472 - INFO - PUT-3 - 154.38.186.98 - 8008 - {roguesrepast.cafe} Processed request: 0.694sec/0.006sec (0.000sec, 0.000sec) (0.000sec/0.000sec/0) 11B 200 "PUT /_matrix/federation/v1/send/1714181631145 HTTP/1.1" "Synapse/1.105.1" [0 dbevts]
2024-04-30 18:21:50,333 - synapse.access.http.8008 - 472 - INFO - PUT-4 - 154.38.186.98 - 8008 - {roguesrepast.cafe} Processed request: 0.604sec/0.006sec (0.001sec, 0.000sec) (0.000sec/0.000sec/0) 11B 200 "PUT /_matrix/federation/v1/send/1714181631145 HTTP/1.1" "Synapse/1.105.1" [0 dbevts]
2024-04-30 18:21:50,333 - synapse.access.http.8008 - 472 - INFO - PUT-5 - 154.38.186.98 - 8008 - {roguesrepast.cafe} Processed request: 0.599sec/0.006sec (0.001sec, 0.000sec) (0.000sec/0.000sec/0) 11B 200 "PUT /_matrix/federation/v1/send/1714181631145 HTTP/1.1" "Synapse/1.105.1" [0 dbevts]
2024-04-30 18:21:50,335 - synapse.access.http.8008 - 472 - INFO - PUT-6 - 154.38.186.98 - 8008 - {roguesrepast.cafe} Processed request: 0.297sec/0.007sec (0.001sec, 0.000sec) (0.000sec/0.000sec/0) 11B 200 "PUT /_matrix/federation/v1/send/1714181631145 HTTP/1.1" "Synapse/1.105.1" [0 dbevts]
2024-04-30 18:21:54,406 - synapse.crypto.keyring - 677 - INFO - PerspectivesKeyFetcher-2 - Requesting keys [_FetchKeyRequest(server_name='nope.chat', minimum_valid_until_ts=1714501314402, key_ids=['ed25519:a_UVsC'])] from notary server matrix.org
2024-04-30 18:21:54,408 - synapse.crypto.keyring - 677 - INFO - PerspectivesKeyFetcher-2 - Requesting keys [_FetchKeyRequest(server_name='nope.chat', minimum_valid_until_ts=1714501314402, key_ids=['ed25519:a_UVsC'])] from notary server cocamserverguild.com
2024-04-30 18:21:54,408 - synapse.crypto.keyring - 632 - WARNING - PerspectivesKeyFetcher-2 - Key lookup failed from 'cocamserverguild.com': Not retrying server cocamserverguild.com because we tried it recently retry_last_ts=1714500351439 and we won't check for another retry_interval=12990479ms.
2024-04-30 18:21:54,603 - synapse.http.matrixfederationclient - 362 - INFO - PerspectivesKeyFetcher-2 - {POST-O-6} [matrix.org] Completed request: 200 OK in 0.20 secs, got 438 bytes - POST matrix-federation://matrix.org/_matrix/key/v2/query
2024-04-30 18:21:54,628 - synapse.federation.transport.server.federation - 112 - INFO - PUT-7 - Received txn 1713964796668 from nope.chat. (PDUs: 0, EDUs: 1)
2024-04-30 18:21:54,666 - synapse.access.http.8008 - 472 - INFO - PUT-7 - 88.198.7.62 - 8008 - {nope.chat} Processed request: 0.263sec/0.001sec (0.009sec, 0.005sec) (0.004sec/0.024sec/8) 11B 200 "PUT /_matrix/federation/v1/send/1713964796668 HTTP/1.1" "Synapse/1.105.1" [0 dbevts]
2024-04-30 18:21:54,699 - synapse.federation.transport.server.federation - 112 - INFO - PUT-8 - Received txn 1713964799102 from nope.chat. (PDUs: 0, EDUs: 1)
2024-04-30 18:21:54,736 - synapse.access.http.8008 - 472 - INFO - PUT-8 - 88.198.7.62 - 8008 - {nope.chat} Processed request: 0.043sec/0.001sec (0.009sec, 0.003sec) (0.004sec/0.023sec/9) 11B 200 "PUT /_matrix/federation/v1/send/1713964799102 HTTP/1.1" "Synapse/1.105.1" [0 dbevts]
2024-04-30 18:21:55,714 - synapse.crypto.keyring - 677 - INFO - PerspectivesKeyFetcher-3 - Requesting keys [_FetchKeyRequest(server_name='josh.tel', minimum_valid_until_ts=1714501315708, key_ids=['ed25519:KUIETc'])] from notary server matrix.org
2024-04-30 18:21:55,717 - synapse.crypto.keyring - 677 - INFO - PerspectivesKeyFetcher-3 - Requesting keys [_FetchKeyRequest(server_name='josh.tel', minimum_valid_until_ts=1714501315708, key_ids=['ed25519:KUIETc'])] from notary server cocamserverguild.com
2024-04-30 18:21:55,717 - synapse.crypto.keyring - 632 - WARNING - PerspectivesKeyFetcher-3 - Key lookup failed from 'cocamserverguild.com': Not retrying server cocamserverguild.com because we tried it recently retry_last_ts=1714500351439 and we won't check for another retry_interval=12990479ms.
2024-04-30 18:21:55,890 - synapse.http.matrixfederationclient - 362 - INFO - PerspectivesKeyFetcher-3 - {POST-O-8} [matrix.org] Completed request: 200 OK in 0.18 secs, got 436 bytes - POST matrix-federation://matrix.org/_matrix/key/v2/query
2024-04-30 18:21:55,919 - synapse.federation.transport.server.federation - 112 - INFO - PUT-9 - Received txn 1714194892016 from josh.tel. (PDUs: 5, EDUs: 0)
2024-04-30 18:21:55,985 - synapse.federation.federation_server - 1241 - INFO - _process_incoming_pdus_in_room_inner-0 - handling received PDU in room !KlacjKWnARbprTLuRM:nova.chat: <FrozenEventV3 event_id=$i4Wz0YCL0cz_fyTXuASbXKX1i-b0Gssd0RNgyyRyTdA, type=m.room.member, state_key=@josh:josh.tel, outlier=False>
2024-04-30 18:21:56,001 - synapse.federation.federation_server - 1241 - INFO - _process_incoming_pdus_in_room_inner-1 - handling received PDU in room !ZVIOUxtbNRapDHyAQK:etke.cc: <FrozenEventV3 event_id=$nO4ZCosi8hTqP2I_r7YrhphtcMZLXoStbueUeDx04To, type=m.room.member, state_key=@josh:josh.tel, outlier=False>
2024-04-30 18:21:56,051 - synapse.access.http.8008 - 472 - INFO - PUT-9 - 143.110.144.192 - 8008 - {josh.tel} Processed request: 0.343sec/0.001sec (0.027sec, 0.004sec) (0.045sec/0.076sec/17) 260B 200 "PUT /_matrix/federation/v1/send/1714194892016 HTTP/1.1" "Synapse/1.105.1" [0 dbevts]
2024-04-30 18:21:56,074 - synapse.handlers.federation_event - 261 - INFO - _process_incoming_pdus_in_room_inner-0-$i4Wz0YCL0cz_fyTXuASbXKX1i-b0Gssd0RNgyyRyTdA - Ignoring PDU from josh.tel as we're not in the room
2024-04-30 18:21:56,075 - synapse.handlers.federation_event - 261 - INFO - _process_incoming_pdus_in_room_inner-1-$nO4ZCosi8hTqP2I_r7YrhphtcMZLXoStbueUeDx04To - Ignoring PDU from josh.tel as we're not in the room
2024-04-30 18:21:56,121 - synapse.federation.federation_server - 1241 - INFO - _process_incoming_pdus_in_room_inner-1 - handling received PDU in room !ZVIOUxtbNRapDHyAQK:etke.cc: <FrozenEventV3 event_id=$yLQvimPFbD3Yulb6MBrXO4xkdDOeAYLYpVw18xI044U, type=m.room.member, state_key=@josh:josh.tel, outlier=False>
2024-04-30 18:21:56,123 - synapse.federation.federation_server - 1241 - INFO - _process_incoming_pdus_in_room_inner-0 - handling received PDU in room !KlacjKWnARbprTLuRM:nova.chat: <FrozenEventV3 event_id=$H2kRjlsKLgUXbu1nYSV9yhWNbbx9ZGnSoVPPhf9F_d0, type=m.room.member, state_key=@josh:josh.tel, outlier=False>
2024-04-30 18:21:56,132 - synapse.handlers.federation_event - 261 - INFO - _process_incoming_pdus_in_room_inner-0-$H2kRjlsKLgUXbu1nYSV9yhWNbbx9ZGnSoVPPhf9F_d0 - Ignoring PDU from josh.tel as we're not in the roomAnything else that would be useful to know?
No response