element-hq / element-hq/synapse

Federation sender worker not federating messages when using multiple stream writers

Open
#14,928 0 comments 0 reactions 0 assignees View on GitHub
A-Workers O-Uncommon S-Major T-Defect
Dominant language
Python
Stars
4.6k
Forks
600
Avg merge
5d 22h
Merged PRs (30d)
51

Description

This issue has been migrated from [#14928](https://github.com/matrix-org/synapse/issues/14928).

---

### Description

My federation sender worker hasn't been federating outgoing messages since updating to 1.76.0rc1. Even messages sent before doing the first faster join haven't gone through. Presence and typing notifications do seem to go through. Incoming messages are being received normally.

This only happens when multiple event stream writers are configured.

### Steps to reproduce

- set up at least one federation sender
- add multiple generic workers as event stream writers
- try to send messages

### Homeserver

tonkku.me

### Synapse Version

1.76.0rc1

### Installation Method

Docker (matrixdotorg/synapse)

### Database

single postgresql database

### Workers

Multiple workers

### Platform

Running in docker containers on a server with Ubuntu 20.04.5, AMD Ryzen 5 3600, 64GB RAM.

### Configuration

Using a worker setup with one main synapse instance, 4 generic workers and 1 federation sender. Presence is enabled.
Experimental features enabled:
```
msc3026_enabled: true
msc2815_enabled: true
msc3773_enabled: true
msc3882_enabled: true
msc3886_endpoint: 'https://rendezvous.lab.element.dev'
msc3912_enabled: true
```
worker configuration:
```
send_federation: false
federation_sender_instances:
- federation_sender1
instance_map:
generic_worker1:
host: generic-worker1
port: 9111
generic_worker2:
host: generic-worker2
port: 9112
generic_worker3:
host: generic-worker3
port: 9113
generic_worker4:
host: generic-worker4
port: 9114
stream_writers:
events:
- generic_worker1
- generic_worker2
- generic_worker3
- generic_worker4
redis:
enabled: true
host: redis
```
```
worker_app: synapse.app.federation_sender
worker_name: federation_sender1

worker_replication_host: synapse
worker_replication_http_port: 9100

worker_log_config: "/data/tonkku.me.log.config"
```

### Relevant log output

```shell
tonkku-matrix-server-generic-worker-4 | 2023-01-27 07:50:29,215 - synapse.replication.http.send_events - 147 - INFO - POST-31712 - Got batch of events to send, last ID of batch is: $1Kq2JWRsQNYq3BdNb_D1vUPeJciH7j39-l7dFyDqhWE, sending into room: !KibRmKHfMtoXfmIqBP:tonkku.me
tonkku-matrix-server-generic-worker-4 | 2023-01-27 07:50:29,232 - synapse.access.http.9114 - 460 - INFO - POST-31712 - ::ffff:192.168.240.6 - 9114 - {None} Processed request: 0.017sec/0.001sec (0.000sec, 0.000sec) (0.000sec/0.000sec/0) 149B 200 "POST /_synapse/replication/send_events/frDXoxQLuc HTTP/1.1" "Synapse/1.76.0rc1" [0 dbevts]
tonkku-matrix-server-generic-worker-2 | 2023-01-27 07:50:29,233 - synapse.http.client - 460 - INFO - PUT-10818 - Received response to POST http://generic-worker4:9114/_synapse/replication/send_events/frDXoxQLuc: 200
tonkku-matrix-server-generic-worker-2 | 2023-01-27 07:50:29,233 - synapse.replication.tcp.client - 372 - INFO - PUT-10818 - Waiting for repl stream 'events' to reach 817572 (generic_worker4)
tonkku-matrix-server-generic-worker-4 | 2023-01-27 07:50:29,237 - synapse.replication.tcp.resource - 193 - INFO - replication_notifier-725 - Streaming: events -> 817572
tonkku-matrix-server-generic-worker-2 | 2023-01-27 07:50:29,239 - synapse.replication.tcp.client - 384 - INFO - PUT-10818 - Finished waiting for repl stream 'events' to reach 817572 (generic_worker4)
tonkku-matrix-server-generic-worker-2 | 2023-01-27 07:50:29,240 - synapse.access.http.9102 - 460 - INFO - PUT-10818 - [redacted IP] - 9102 - {@tonkku:tonkku.me} Processed request: 0.049sec/0.000sec (0.005sec, 0.001sec) (0.003sec/0.013sec/15) 59B 200 "PUT /_matrix/client/r0/rooms/!KibRmKHfMtoXfmIqBP%3Atonkku.me/send/m.room.encrypted/m1674805828912.7 HTTP/1.0" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Element/1.11.20 Chrome/108.0.5359.179 Electron/22.0.3 Safari/537.36" [3 dbevts]
tonkku-matrix-server-generic-worker-1 | 2023-01-27 07:50:29,259 - synapse.access.http.9101 - 460 - INFO - GET-12340 - [redacted IP] - 9101 - {@tonkku:tonkku.me} Processed request: 4.449sec/0.000sec (0.007sec, 0.002sec) (0.024sec/0.045sec/18) 1272B 200 "GET /_matrix/client/r0/sync?filter=6&timeout=30000&since=m788039%7E3.817456%7E1.817571%7E2.817568_20566155_2601_2123712_33123_30_7014_2345778_0_3 HTTP/1.0" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Element/1.11.20 Chrome/108.0.5359.179 Electron/22.0.3 Safari/537.36" [1 dbevts]
tonkku-matrix-server | 2023-01-27 07:50:29,452 - synapse.access.http.9100 - 460 - INFO - POST-64485 - ::ffff:192.168.240.7 - 9100 - {None} Processed request: 0.000sec/0.001sec (0.000sec, 0.000sec) (0.000sec/0.000sec/0) 279B 200 "POST /_synapse/replication/presence_set_state/%40tonkku%3Atonkku.me HTTP/1.1" "Synapse/1.76.0rc1" [0 dbevts]
tonkku-matrix-server-generic-worker-1 | 2023-01-27 07:50:29,453 - synapse.http.client - 460 - INFO - GET-12342 - Received response to POST http://synapse:9100/_synapse/replication/presence_set_state/%40tonkku%3Atonkku.me: 200
tonkku-matrix-server | 2023-01-27 07:50:29,463 - synapse.access.http.8008 - 460 - INFO - POST-64484 - [redacted IP] - 8008 - {@tonkku:tonkku.me} Processed request: 0.012sec/0.001sec (0.000sec, 0.001sec) (0.001sec/0.008sec/4) 2B 200 "POST /_matrix/client/r0/rooms/!KibRmKHfMtoXfmIqBP%3Atonkku.me/read_markers HTTP/1.0" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Element/1.11.20 Chrome/108.0.5359.179 Electron/22.0.3 Safari/537.36" [0 dbevts]
tonkku-matrix-server | 2023-01-27 07:50:29,464 - synapse.replication.tcp.resource - 193 - INFO - replication_notifier-109167 - Streaming: account_data -> 33124
tonkku-matrix-server-generic-worker-1 | 2023-01-27 07:50:29,471 - synapse.access.http.9101 - 460 - INFO - GET-12342 - [redacted IP] - 9101 - {@tonkku:tonkku.me} Processed request: 0.021sec/0.000sec (0.001sec, 0.000sec) (0.001sec/0.003sec/4) 729B 200 "GET /_matrix/client/r0/sync?filter=6&timeout=30000&since=m788039%7E3.817456%7E1.817572%7E2.817568_20566155_2601_2123712_33123_30_7014_2345778_0_3 HTTP/1.0" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Element/1.11.20 Chrome/108.0.5359.179 Electron/22.0.3 Safari/537.36" [0 dbevts]
tonkku-matrix-server | 2023-01-27 07:50:29,590 - synapse.access.http.9100 - 460 - INFO - POST-64486 - ::ffff:192.168.240.7 - 9100 - {None} Processed request: 0.000sec/0.000sec (0.000sec, 0.000sec) (0.000sec/0.000sec/0) 279B 200 "POST /_synapse/replication/presence_set_state/%40tonkku%3Atonkku.me HTTP/1.1" "Synapse/1.76.0rc1" [0 dbevts]
tonkku-matrix-server-generic-worker-1 | 2023-01-27 07:50:29,591 - synapse.http.client - 460 - INFO - GET-12344 - Received response to POST http://synapse:9100/_synapse/replication/presence_set_state/%40tonkku%3Atonkku.me: 200
tonkku-matrix-server-generic-worker-1 | 2023-01-27 07:50:29,892 - synapse.federation.transport.server.federation - 103 - INFO - PUT-12345 - Received txn 1673813262285 from matrix.hadallen.ca. (PDUs: 0, EDUs: 1)
tonkku-matrix-server | 2023-01-27 07:50:29,896 - synapse.replication.http.federation - 186 - INFO - POST-64487 - Got 'm.presence' edu from matrix.hadallen.ca
tonkku-matrix-server | 2023-01-27 07:50:29,897 - synapse.access.http.9100 - 460 - INFO - POST-64487 - ::ffff:192.168.240.7 - 9100 - {None} Processed request: 0.001sec/0.000sec (0.001sec, 0.000sec) (0.000sec/0.000sec/0) 279B 200 "POST /_synapse/replication/fed_send_edu/m.presence/jtnpiXDrUe HTTP/1.1" "Synapse/1.76.0rc1" [0 dbevts]
tonkku-matrix-server-generic-worker-1 | 2023-01-27 07:50:29,897 - synapse.http.client - 460 - INFO - PUT-12345 - Received response to POST http://synapse:9100/_synapse/replication/fed_send_edu/m.presence/jtnpiXDrUe: 200
tonkku-matrix-server-generic-worker-1 | 2023-01-27 07:50:29,907 - synapse.access.http.9101 - 460 - INFO - PUT-12345 - 24.68.83.130 - 9101 - {matrix.hadallen.ca} Processed request: 0.015sec/0.000sec (0.001sec, 0.000sec) (0.001sec/0.009sec/2) 11B 200 "PUT /_matrix/federation/v1/send/1673813262285 HTTP/1.0" "Synapse/1.73.0" [0 dbevts]
tonkku-matrix-server-federation-sender-1 | 2023-01-27 07:50:30,172 - synapse.http.matrixfederationclient - 672 - INFO - federation_transaction_transmission_loop-393797 - {PUT-O-181577} [bancino.net] Request failed: PUT matrix://bancino.net/_matrix/federation/v1/send/1674746060146: ResponseNeverReceived:[CancelledError()]
tonkku-matrix-server-generic-worker-3 | 2023-01-27 07:50:30,760 - synapse.federation.transport.server.federation - 103 - INFO - PUT-14201 - Received txn 1674755342297 from matrix.org. (PDUs: 0, EDUs: 4)
tonkku-matrix-server | 2023-01-27 07:50:30,764 - synapse.replication.http.federation - 186 - INFO - POST-64488 - Got 'm.device_list_update' edu from matrix.org
tonkku-matrix-server | 2023-01-27 07:50:30,765 - synapse.replication.http.federation - 186 - INFO - POST-64489 - Got 'm.device_list_update' edu from matrix.org
tonkku-matrix-server | 2023-01-27 07:50:30,766 - synapse.replication.http.federation - 186 - INFO - POST-64490 - Got 'm.device_list_update' edu from matrix.org
tonkku-matrix-server | 2023-01-27 07:50:30,767 - synapse.replication.http.federation - 186 - INFO - POST-64491 - Got 'm.receipt' edu from matrix.org
tonkku-matrix-server | 2023-01-27 07:50:30,769 - synapse.handlers.device - 1111 - INFO - POST-64488 - Received device list update for @hannahbarbarian:matrix.org, requiring resync: True. Devices: HMJZNAGOZS
tonkku-matrix-server | 2023-01-27 07:50:30,770 - synapse.handlers.device - 1111 - INFO - POST-64489 - Received device list update for @lr7:matrix.org, requiring resync: True. Devices: WVPPLBOOFW
tonkku-matrix-server | 2023-01-27 07:50:30,783 - synapse.replication.tcp.resource - 193 - INFO - replication_notifier-109168 - Streaming: receipts -> 2123713
tonkku-matrix-server | 2023-01-27 07:50:30,788 - synapse.access.http.9100 - 460 - INFO - POST-64491 - ::ffff:192.168.240.5 - 9100 - {None} Processed request: 0.021sec/0.000sec (0.001sec, 0.001sec) (0.002sec/0.015sec/5) 279B 200 "POST /_synapse/replication/fed_send_edu/m.receipt/TtOesxZXle HTTP/1.1" "Synapse/1.76.0rc1" [0 dbevts]
tonkku-matrix-server-generic-worker-3 | 2023-01-27 07:50:30,789 - synapse.http.client - 460 - INFO - PUT-14201 - Received response to POST http://synapse:9100/_synapse/replication/fed_send_edu/m.receipt/TtOesxZXle: 200
tonkku-matrix-server-generic-worker-1 | 2023-01-27 07:50:30,794 - synapse.access.http.9101 - 460 - INFO - GET-12344 - [redacted IP] - 9101 - {@tonkku:tonkku.me} Processed request: 1.205sec/0.000sec (0.003sec, 0.000sec) (0.001sec/0.006sec/4) 780B 200 "GET /_matrix/client/r0/sync?filter=6&timeout=30000&since=m788039%7E3.817456%7E1.817572%7E2.817568_20566155_2601_2123712_33124_30_7014_2345778_0_3 HTTP/1.0" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Element/1.11.20 Chrome/108.0.5359.179 Electron/22.0.3 Safari/537.36" [0 dbevts]
tonkku-matrix-server-federation-sender-1 | 2023-01-27 07:50:30,864 - synapse.http.matrixfederationclient - 672 - INFO - federation_transaction_transmission_loop-392140 - {PUT-O-180948} [synapsis.nadir.org] Request failed: PUT matrix://synapsis.nadir.org/_matrix/federation/v1/send/1674746059517: ResponseNeverReceived:[CancelledError()]
tonkku-matrix-server | 2023-01-27 07:50:30,939 - synapse.access.http.9100 - 460 - INFO - POST-64492 - ::ffff:192.168.240.7 - 9100 - {None} Processed request: 0.000sec/0.000sec (0.000sec, 0.000sec) (0.000sec/0.000sec/0) 279B 200 "POST /_synapse/replication/presence_set_state/%40tonkku%3Atonkku.me HTTP/1.1" "Synapse/1.76.0rc1" [0 dbevts]
tonkku-matrix-server-generic-worker-1 | 2023-01-27 07:50:30,940 - synapse.http.client - 460 - INFO - GET-12347 - Received response to POST http://synapse:9100/_synapse/replication/presence_set_state/%40tonkku%3Atonkku.me: 200
tonkku-matrix-server | 2023-01-27 07:50:31,086 - synapse.access.http.8008 - 460 - INFO - GET-64493 - 2a00:1098:84:1c8::158 - 8008 - {None} Processed request: 0.000sec/0.000sec (0.000sec, 0.000sec) (0.000sec/0.000sec/0) 301B 200 "GET /_matrix/key/v2/server HTTP/1.0" "Synapse/1.76.0rc1 (b=matrix-org-hotfixes,484db60cd6)" [0 dbevts]
tonkku-matrix-server | 2023-01-27 07:50:31,149 - synapse.http.matrixfederationclient - 299 - INFO - POST-64488 - {GET-O-141113} [matrix.org] Completed request: 200 OK in 0.38 secs, got 1892 bytes - GET matrix://matrix.org/_matrix/federation/v1/user/devices/%40hannahbarbarian%3Amatrix.org
tonkku-matrix-server | 2023-01-27 07:50:31,150 - root - 1352 - INFO - POST-64488 - Skipping device list resync for @hannahbarbarian:matrix.org, as our cache matches already
tonkku-matrix-server | 2023-01-27 07:50:31,151 - synapse.access.http.9100 - 460 - INFO - POST-64488 - ::ffff:192.168.240.5 - 9100 - {None} Processed request: 0.387sec/0.000sec (0.001sec, 0.001sec) (0.001sec/0.002sec/3) 279B 200 "POST /_synapse/replication/fed_send_edu/m.device_list_update/eIFEReVCkH HTTP/1.1" "Synapse/1.76.0rc1" [0 dbevts]
tonkku-matrix-server-generic-worker-3 | 2023-01-27 07:50:31,152 - synapse.http.client - 460 - INFO - PUT-14201 - Received response to POST http://synapse:9100/_synapse/replication/fed_send_edu/m.device_list_update/eIFEReVCkH: 200
tonkku-matrix-server-federation-sender-1 | 2023-01-27 07:50:31,312 - synapse.http.federation.matrix_federation_agent - 363 - INFO - federation_transaction_transmission_loop-396260 - Failed to connect to eggy.cc:8448: User timeout caused connection failure.
tonkku-matrix-server-federation-sender-1 | 2023-01-27 07:50:31,313 - synapse.http.matrixfederationclient - 672 - INFO - federation_transaction_transmission_loop-396260 - {PUT-O-182682} [eggy.cc] Request failed: PUT matrix://eggy.cc/_matrix/federation/v1/send/1674746061248: TimeoutError('')
tonkku-matrix-server-generic-worker-1 | 2023-01-27 07:50:31,967 - synapse.federation.transport.server.federation - 103 - INFO - PUT-12348 - Received txn 1673566981718 from gruenhage.xyz. (PDUs: 0, EDUs: 1)
tonkku-matrix-server | 2023-01-27 07:50:31,970 - synapse.replication.http.federation - 186 - INFO - POST-64494 - Got 'm.presence' edu from gruenhage.xyz
tonkku-matrix-server | 2023-01-27 07:50:31,971 - synapse.access.http.9100 - 460 - INFO - POST-64494 - ::ffff:192.168.240.7 - 9100 - {None} Processed request: 0.001sec/0.000sec (0.000sec, 0.000sec) (0.000sec/0.000sec/0) 279B 200 "POST /_synapse/replication/fed_send_edu/m.presence/mwocLhmkrK HTTP/1.1" "Synapse/1.76.0rc1" [0 dbevts]
tonkku-matrix-server-generic-worker-1 | 2023-01-27 07:50:31,971 - synapse.http.client - 460 - INFO - PUT-12348 - Received response to POST http://synapse:9100/_synapse/replication/fed_send_edu/m.presence/mwocLhmkrK: 200
tonkku-matrix-server-generic-worker-1 | 2023-01-27 07:50:31,985 - synapse.access.http.9101 - 460 - INFO - PUT-12348 - 109.250.36.91 - 9101 - {gruenhage.xyz} Processed request: 0.019sec/0.000sec (0.001sec, 0.000sec) (0.001sec/0.013sec/2) 11B 200 "PUT /_matrix/federation/v1/send/1673566981718 HTTP/1.0" "Synapse/1.74.0rc1" [0 dbevts]
tonkku-matrix-server-generic-worker-2 | 2023-01-27 07:50:32,695 - synapse.federation.transport.server.federation - 103 - INFO - PUT-10819 - Received txn 1674647102137 from strahlungsfrei.de. (PDUs: 0, EDUs: 1)
tonkku-matrix-server | 2023-01-27 07:50:32,698 - synapse.replication.http.federation - 186 - INFO - POST-64495 - Got 'm.presence' edu from strahlungsfrei.de
tonkku-matrix-server | 2023-01-27 07:50:32,710 - synapse.replication.tcp.resource - 193 - INFO - replication_notifier-109169 - Streaming: presence -> 20566156
tonkku-matrix-server | 2023-01-27 07:50:32,713 - synapse.access.http.9100 - 460 - INFO - POST-64495 - ::ffff:192.168.240.6 - 9100 - {None} Processed request: 0.015sec/0.000sec (0.001sec, 0.000sec) (0.001sec/0.011sec/3) 279B 200 "POST /_synapse/replication/fed_send_edu/m.presence/tAVsrPDqdu HTTP/1.1" "Synapse/1.76.0rc1" [0 dbevts]
tonkku-matrix-server-generic-worker-2 | 2023-01-27 07:50:32,714 - synapse.http.client - 460 - INFO - PUT-10819 - Received response to POST http://synapse:9100/_synapse/replication/fed_send_edu/m.presence/tAVsrPDqdu: 200
tonkku-matrix-server-generic-worker-1 | 2023-01-27 07:50:32,716 - synapse.access.http.9101 - 460 - INFO - GET-12347 - [redacted IP] - 9101 - {@tonkku:tonkku.me} Processed request: 1.779sec/0.000sec (0.002sec, 0.000sec) (0.001sec/0.002sec/3) 425B 200 "GET /_matrix/client/r0/sync?filter=6&timeout=30000&since=m788039%7E3.817456%7E1.817572%7E2.817568_20566155_2601_2123713_33124_30_7014_2345778_0_3 HTTP/1.0" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Element/1.11.20 Chrome/108.0.5359.179 Electron/22.0.3 Safari/537.36" [0 dbevts]
tonkku-matrix-server-generic-worker-2 | 2023-01-27 07:50:32,717 - synapse.access.http.9102 - 460 - INFO - PUT-10819 - 37.221.197.227 - 9102 - {strahlungsfrei.de} Processed request: 0.022sec/0.000sec (0.001sec, 0.000sec) (0.001sec/0.002sec/2) 11B 200 "PUT /_matrix/federation/v1/send/1674647102137 HTTP/1.0" "Synapse/1.75.0" [0 dbevts]
tonkku-matrix-server | 2023-01-27 07:50:32,952 - synapse.access.http.9100 - 460 - INFO - POST-64496 - ::ffff:192.168.240.7 - 9100 - {None} Processed request: 0.000sec/0.000sec (0.000sec, 0.000sec) (0.000sec/0.000sec/0) 279B 200 "POST /_synapse/replication/presence_set_state/%40tonkku%3Atonkku.me HTTP/1.1" "Synapse/1.76.0rc1" [0 dbevts]
tonkku-matrix-server-generic-worker-1 | 2023-01-27 07:50:32,952 - synapse.http.client - 460 - INFO - GET-12350 - Received response to POST http://synapse:9100/_synapse/replication/presence_set_state/%40tonkku%3Atonkku.me: 200
tonkku-matrix-server-generic-worker-2 | 2023-01-27 07:50:33,864 - synapse.federation.transport.server.federation - 103 - INFO - PUT-10820 - Received txn 1674646692320 from roastburry.com. (PDUs: 0, EDUs: 1)
tonkku-matrix-server | 2023-01-27 07:50:33,867 - synapse.replication.http.federation - 186 - INFO - POST-64497 - Got 'm.presence' edu from roastburry.com
tonkku-matrix-server | 2023-01-27 07:50:33,868 - synapse.access.http.9100 - 460 - INFO - POST-64497 - ::ffff:192.168.240.6 - 9100 - {None} Processed request: 0.001sec/0.000sec (0.001sec, 0.000sec) (0.000sec/0.000sec/0) 279B 200 "POST /_synapse/replication/fed_send_edu/m.presence/LBeYTSWDXP HTTP/1.1" "Synapse/1.76.0rc1" [0 dbevts]
tonkku-matrix-server-generic-worker-2 | 2023-01-27 07:50:33,869 - synapse.http.client - 460 - INFO - PUT-10820 - Received response to POST http://synapse:9100/_synapse/replication/fed_send_edu/m.presence/LBeYTSWDXP: 200
tonkku-matrix-server-generic-worker-2 | 2023-01-27 07:50:33,875 - synapse.access.http.9102 - 460 - INFO - PUT-10820 - 99.46.147.41 - 9102 - {roastburry.com} Processed request: 0.012sec/0.000sec (0.002sec, 0.000sec) (0.001sec/0.006sec/2) 11B 200 "PUT /_matrix/federation/v1/send/1674646692320 HTTP/1.0" "Synapse/1.74.0" [0 dbevts]tonkku-matrix-server-generic-worker-4 | 2023-01-27 07:50:29,215 - synapse.replication.http.send_events - 147 - INFO - POST-31712 - Got batch of events to send, last ID of batch is: $1Kq2JWRsQNYq3BdNb_D1vUPeJciH7j39-l7dFyDqhWE, sending into room: !KibRmKHfMtoXfmIqBP:tonkku.me
tonkku-matrix-server-generic-worker-4 | 2023-01-27 07:50:29,232 - synapse.access.http.9114 - 460 - INFO - POST-31712 - ::ffff:192.168.240.6 - 9114 - {None} Processed request: 0.017sec/0.001sec (0.000sec, 0.000sec) (0.000sec/0.000sec/0) 149B 200 "POST /_synapse/replication/send_events/frDXoxQLuc HTTP/1.1" "Synapse/1.76.0rc1" [0 dbevts]
tonkku-matrix-server-generic-worker-2 | 2023-01-27 07:50:29,233 - synapse.http.client - 460 - INFO - PUT-10818 - Received response to POST http://generic-worker4:9114/_synapse/replication/send_events/frDXoxQLuc: 200
tonkku-matrix-server-generic-worker-2 | 2023-01-27 07:50:29,233 - synapse.replication.tcp.client - 372 - INFO - PUT-10818 - Waiting for repl stream 'events' to reach 817572 (generic_worker4)
tonkku-matrix-server-generic-worker-4 | 2023-01-27 07:50:29,237 - synapse.replication.tcp.resource - 193 - INFO - replication_notifier-725 - Streaming: events -> 817572
tonkku-matrix-server-generic-worker-2 | 2023-01-27 07:50:29,239 - synapse.replication.tcp.client - 384 - INFO - PUT-10818 - Finished waiting for repl stream 'events' to reach 817572 (generic_worker4)
tonkku-matrix-server-generic-worker-2 | 2023-01-27 07:50:29,240 - synapse.access.http.9102 - 460 - INFO - PUT-10818 - [redacted IP] - 9102 - {@tonkku:tonkku.me} Processed request: 0.049sec/0.000sec (0.005sec, 0.001sec) (0.003sec/0.013sec/15) 59B 200 "PUT /_matrix/client/r0/rooms/!KibRmKHfMtoXfmIqBP%3Atonkku.me/send/m.room.encrypted/m1674805828912.7 HTTP/1.0" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Element/1.11.20 Chrome/108.0.5359.179 Electron/22.0.3 Safari/537.36" [3 dbevts]
tonkku-matrix-server-generic-worker-1 | 2023-01-27 07:50:29,259 - synapse.access.http.9101 - 460 - INFO - GET-12340 - [redacted IP] - 9101 - {@tonkku:tonkku.me} Processed request: 4.449sec/0.000sec (0.007sec, 0.002sec) (0.024sec/0.045sec/18) 1272B 200 "GET /_matrix/client/r0/sync?filter=6&timeout=30000&since=m788039%7E3.817456%7E1.817571%7E2.817568_20566155_2601_2123712_33123_30_7014_2345778_0_3 HTTP/1.0" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Element/1.11.20 Chrome/108.0.5359.179 Electron/22.0.3 Safari/537.36" [1 dbevts]
tonkku-matrix-server | 2023-01-27 07:50:29,452 - synapse.access.http.9100 - 460 - INFO - POST-64485 - ::ffff:192.168.240.7 - 9100 - {None} Processed request: 0.000sec/0.001sec (0.000sec, 0.000sec) (0.000sec/0.000sec/0) 279B 200 "POST /_synapse/replication/presence_set_state/%40tonkku%3Atonkku.me HTTP/1.1" "Synapse/1.76.0rc1" [0 dbevts]
tonkku-matrix-server-generic-worker-1 | 2023-01-27 07:50:29,453 - synapse.http.client - 460 - INFO - GET-12342 - Received response to POST http://synapse:9100/_synapse/replication/presence_set_state/%40tonkku%3Atonkku.me: 200
tonkku-matrix-server | 2023-01-27 07:50:29,463 - synapse.access.http.8008 - 460 - INFO - POST-64484 - [redacted IP] - 8008 - {@tonkku:tonkku.me} Processed request: 0.012sec/0.001sec (0.000sec, 0.001sec) (0.001sec/0.008sec/4) 2B 200 "POST /_matrix/client/r0/rooms/!KibRmKHfMtoXfmIqBP%3Atonkku.me/read_markers HTTP/1.0" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Element/1.11.20 Chrome/108.0.5359.179 Electron/22.0.3 Safari/537.36" [0 dbevts]
tonkku-matrix-server | 2023-01-27 07:50:29,464 - synapse.replication.tcp.resource - 193 - INFO - replication_notifier-109167 - Streaming: account_data -> 33124
tonkku-matrix-server-generic-worker-1 | 2023-01-27 07:50:29,471 - synapse.access.http.9101 - 460 - INFO - GET-12342 - [redacted IP] - 9101 - {@tonkku:tonkku.me} Processed request: 0.021sec/0.000sec (0.001sec, 0.000sec) (0.001sec/0.003sec/4) 729B 200 "GET /_matrix/client/r0/sync?filter=6&timeout=30000&since=m788039%7E3.817456%7E1.817572%7E2.817568_20566155_2601_2123712_33123_30_7014_2345778_0_3 HTTP/1.0" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Element/1.11.20 Chrome/108.0.5359.179 Electron/22.0.3 Safari/537.36" [0 dbevts]
tonkku-matrix-server | 2023-01-27 07:50:29,590 - synapse.access.http.9100 - 460 - INFO - POST-64486 - ::ffff:192.168.240.7 - 9100 - {None} Processed request: 0.000sec/0.000sec (0.000sec, 0.000sec) (0.000sec/0.000sec/0) 279B 200 "POST /_synapse/replication/presence_set_state/%40tonkku%3Atonkku.me HTTP/1.1" "Synapse/1.76.0rc1" [0 dbevts]
tonkku-matrix-server-generic-worker-1 | 2023-01-27 07:50:29,591 - synapse.http.client - 460 - INFO - GET-12344 - Received response to POST http://synapse:9100/_synapse/replication/presence_set_state/%40tonkku%3Atonkku.me: 200
tonkku-matrix-server-generic-worker-1 | 2023-01-27 07:50:29,892 - synapse.federation.transport.server.federation - 103 - INFO - PUT-12345 - Received txn 1673813262285 from matrix.hadallen.ca. (PDUs: 0, EDUs: 1)
tonkku-matrix-server | 2023-01-27 07:50:29,896 - synapse.replication.http.federation - 186 - INFO - POST-64487 - Got 'm.presence' edu from matrix.hadallen.ca
tonkku-matrix-server | 2023-01-27 07:50:29,897 - synapse.access.http.9100 - 460 - INFO - POST-64487 - ::ffff:192.168.240.7 - 9100 - {None} Processed request: 0.001sec/0.000sec (0.001sec, 0.000sec) (0.000sec/0.000sec/0) 279B 200 "POST /_synapse/replication/fed_send_edu/m.presence/jtnpiXDrUe HTTP/1.1" "Synapse/1.76.0rc1" [0 dbevts]
tonkku-matrix-server-generic-worker-1 | 2023-01-27 07:50:29,897 - synapse.http.client - 460 - INFO - PUT-12345 - Received response to POST http://synapse:9100/_synapse/replication/fed_send_edu/m.presence/jtnpiXDrUe: 200
tonkku-matrix-server-generic-worker-1 | 2023-01-27 07:50:29,907 - synapse.access.http.9101 - 460 - INFO - PUT-12345 - 24.68.83.130 - 9101 - {matrix.hadallen.ca} Processed request: 0.015sec/0.000sec (0.001sec, 0.000sec) (0.001sec/0.009sec/2) 11B 200 "PUT /_matrix/federation/v1/send/1673813262285 HTTP/1.0" "Synapse/1.73.0" [0 dbevts]
tonkku-matrix-server-federation-sender-1 | 2023-01-27 07:50:30,172 - synapse.http.matrixfederationclient - 672 - INFO - federation_transaction_transmission_loop-393797 - {PUT-O-181577} [bancino.net] Request failed: PUT matrix://bancino.net/_matrix/federation/v1/send/1674746060146: ResponseNeverReceived:[CancelledError()]
tonkku-matrix-server-generic-worker-3 | 2023-01-27 07:50:30,760 - synapse.federation.transport.server.federation - 103 - INFO - PUT-14201 - Received txn 1674755342297 from matrix.org. (PDUs: 0, EDUs: 4)
tonkku-matrix-server | 2023-01-27 07:50:30,764 - synapse.replication.http.federation - 186 - INFO - POST-64488 - Got 'm.device_list_update' edu from matrix.org
tonkku-matrix-server | 2023-01-27 07:50:30,765 - synapse.replication.http.federation - 186 - INFO - POST-64489 - Got 'm.device_list_update' edu from matrix.org
tonkku-matrix-server | 2023-01-27 07:50:30,766 - synapse.replication.http.federation - 186 - INFO - POST-64490 - Got 'm.device_list_update' edu from matrix.org
tonkku-matrix-server | 2023-01-27 07:50:30,767 - synapse.replication.http.federation - 186 - INFO - POST-64491 - Got 'm.receipt' edu from matrix.org
tonkku-matrix-server | 2023-01-27 07:50:30,769 - synapse.handlers.device - 1111 - INFO - POST-64488 - Received device list update for @hannahbarbarian:matrix.org, requiring resync: True. Devices: HMJZNAGOZS
tonkku-matrix-server | 2023-01-27 07:50:30,770 - synapse.handlers.device - 1111 - INFO - POST-64489 - Received device list update for @lr7:matrix.org, requiring resync: True. Devices: WVPPLBOOFW
tonkku-matrix-server | 2023-01-27 07:50:30,783 - synapse.replication.tcp.resource - 193 - INFO - replication_notifier-109168 - Streaming: receipts -> 2123713
tonkku-matrix-server | 2023-01-27 07:50:30,788 - synapse.access.http.9100 - 460 - INFO - POST-64491 - ::ffff:192.168.240.5 - 9100 - {None} Processed request: 0.021sec/0.000sec (0.001sec, 0.001sec) (0.002sec/0.015sec/5) 279B 200 "POST /_synapse/replication/fed_send_edu/m.receipt/TtOesxZXle HTTP/1.1" "Synapse/1.76.0rc1" [0 dbevts]
tonkku-matrix-server-generic-worker-3 | 2023-01-27 07:50:30,789 - synapse.http.client - 460 - INFO - PUT-14201 - Received response to POST http://synapse:9100/_synapse/replication/fed_send_edu/m.receipt/TtOesxZXle: 200
tonkku-matrix-server-generic-worker-1 | 2023-01-27 07:50:30,794 - synapse.access.http.9101 - 460 - INFO - GET-12344 - [redacted IP] - 9101 - {@tonkku:tonkku.me} Processed request: 1.205sec/0.000sec (0.003sec, 0.000sec) (0.001sec/0.006sec/4) 780B 200 "GET /_matrix/client/r0/sync?filter=6&timeout=30000&since=m788039%7E3.817456%7E1.817572%7E2.817568_20566155_2601_2123712_33124_30_7014_2345778_0_3 HTTP/1.0" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Element/1.11.20 Chrome/108.0.5359.179 Electron/22.0.3 Safari/537.36" [0 dbevts]
tonkku-matrix-server-federation-sender-1 | 2023-01-27 07:50:30,864 - synapse.http.matrixfederationclient - 672 - INFO - federation_transaction_transmission_loop-392140 - {PUT-O-180948} [synapsis.nadir.org] Request failed: PUT matrix://synapsis.nadir.org/_matrix/federation/v1/send/1674746059517: ResponseNeverReceived:[CancelledError()]
tonkku-matrix-server | 2023-01-27 07:50:30,939 - synapse.access.http.9100 - 460 - INFO - POST-64492 - ::ffff:192.168.240.7 - 9100 - {None} Processed request: 0.000sec/0.000sec (0.000sec, 0.000sec) (0.000sec/0.000sec/0) 279B 200 "POST /_synapse/replication/presence_set_state/%40tonkku%3Atonkku.me HTTP/1.1" "Synapse/1.76.0rc1" [0 dbevts]
tonkku-matrix-server-generic-worker-1 | 2023-01-27 07:50:30,940 - synapse.http.client - 460 - INFO - GET-12347 - Received response to POST http://synapse:9100/_synapse/replication/presence_set_state/%40tonkku%3Atonkku.me: 200
tonkku-matrix-server | 2023-01-27 07:50:31,086 - synapse.access.http.8008 - 460 - INFO - GET-64493 - 2a00:1098:84:1c8::158 - 8008 - {None} Processed request: 0.000sec/0.000sec (0.000sec, 0.000sec) (0.000sec/0.000sec/0) 301B 200 "GET /_matrix/key/v2/server HTTP/1.0" "Synapse/1.76.0rc1 (b=matrix-org-hotfixes,484db60cd6)" [0 dbevts]
tonkku-matrix-server | 2023-01-27 07:50:31,149 - synapse.http.matrixfederationclient - 299 - INFO - POST-64488 - {GET-O-141113} [matrix.org] Completed request: 200 OK in 0.38 secs, got 1892 bytes - GET matrix://matrix.org/_matrix/federation/v1/user/devices/%40hannahbarbarian%3Amatrix.org
tonkku-matrix-server | 2023-01-27 07:50:31,150 - root - 1352 - INFO - POST-64488 - Skipping device list resync for @hannahbarbarian:matrix.org, as our cache matches already
tonkku-matrix-server | 2023-01-27 07:50:31,151 - synapse.access.http.9100 - 460 - INFO - POST-64488 - ::ffff:192.168.240.5 - 9100 - {None} Processed request: 0.387sec/0.000sec (0.001sec, 0.001sec) (0.001sec/0.002sec/3) 279B 200 "POST /_synapse/replication/fed_send_edu/m.device_list_update/eIFEReVCkH HTTP/1.1" "Synapse/1.76.0rc1" [0 dbevts]
tonkku-matrix-server-generic-worker-3 | 2023-01-27 07:50:31,152 - synapse.http.client - 460 - INFO - PUT-14201 - Received response to POST http://synapse:9100/_synapse/replication/fed_send_edu/m.device_list_update/eIFEReVCkH: 200
tonkku-matrix-server-federation-sender-1 | 2023-01-27 07:50:31,312 - synapse.http.federation.matrix_federation_agent - 363 - INFO - federation_transaction_transmission_loop-396260 - Failed to connect to eggy.cc:8448: User timeout caused connection failure.
tonkku-matrix-server-federation-sender-1 | 2023-01-27 07:50:31,313 - synapse.http.matrixfederationclient - 672 - INFO - federation_transaction_transmission_loop-396260 - {PUT-O-182682} [eggy.cc] Request failed: PUT matrix://eggy.cc/_matrix/federation/v1/send/1674746061248: TimeoutError('')
tonkku-matrix-server-generic-worker-1 | 2023-01-27 07:50:31,967 - synapse.federation.transport.server.federation - 103 - INFO - PUT-12348 - Received txn 1673566981718 from gruenhage.xyz. (PDUs: 0, EDUs: 1)
tonkku-matrix-server | 2023-01-27 07:50:31,970 - synapse.replication.http.federation - 186 - INFO - POST-64494 - Got 'm.presence' edu from gruenhage.xyz
tonkku-matrix-server | 2023-01-27 07:50:31,971 - synapse.access.http.9100 - 460 - INFO - POST-64494 - ::ffff:192.168.240.7 - 9100 - {None} Processed request: 0.001sec/0.000sec (0.000sec, 0.000sec) (0.000sec/0.000sec/0) 279B 200 "POST /_synapse/replication/fed_send_edu/m.presence/mwocLhmkrK HTTP/1.1" "Synapse/1.76.0rc1" [0 dbevts]
tonkku-matrix-server-generic-worker-1 | 2023-01-27 07:50:31,971 - synapse.http.client - 460 - INFO - PUT-12348 - Received response to POST http://synapse:9100/_synapse/replication/fed_send_edu/m.presence/mwocLhmkrK: 200
tonkku-matrix-server-generic-worker-1 | 2023-01-27 07:50:31,985 - synapse.access.http.9101 - 460 - INFO - PUT-12348 - 109.250.36.91 - 9101 - {gruenhage.xyz} Processed request: 0.019sec/0.000sec (0.001sec, 0.000sec) (0.001sec/0.013sec/2) 11B 200 "PUT /_matrix/federation/v1/send/1673566981718 HTTP/1.0" "Synapse/1.74.0rc1" [0 dbevts]
tonkku-matrix-server-generic-worker-2 | 2023-01-27 07:50:32,695 - synapse.federation.transport.server.federation - 103 - INFO - PUT-10819 - Received txn 1674647102137 from strahlungsfrei.de. (PDUs: 0, EDUs: 1)
tonkku-matrix-server | 2023-01-27 07:50:32,698 - synapse.replication.http.federation - 186 - INFO - POST-64495 - Got 'm.presence' edu from strahlungsfrei.de
tonkku-matrix-server | 2023-01-27 07:50:32,710 - synapse.replication.tcp.resource - 193 - INFO - replication_notifier-109169 - Streaming: presence -> 20566156
tonkku-matrix-server | 2023-01-27 07:50:32,713 - synapse.access.http.9100 - 460 - INFO - POST-64495 - ::ffff:192.168.240.6 - 9100 - {None} Processed request: 0.015sec/0.000sec (0.001sec, 0.000sec) (0.001sec/0.011sec/3) 279B 200 "POST /_synapse/replication/fed_send_edu/m.presence/tAVsrPDqdu HTTP/1.1" "Synapse/1.76.0rc1" [0 dbevts]
tonkku-matrix-server-generic-worker-2 | 2023-01-27 07:50:32,714 - synapse.http.client - 460 - INFO - PUT-10819 - Received response to POST http://synapse:9100/_synapse/replication/fed_send_edu/m.presence/tAVsrPDqdu: 200
tonkku-matrix-server-generic-worker-1 | 2023-01-27 07:50:32,716 - synapse.access.http.9101 - 460 - INFO - GET-12347 - [redacted IP] - 9101 - {@tonkku:tonkku.me} Processed request: 1.779sec/0.000sec (0.002sec, 0.000sec) (0.001sec/0.002sec/3) 425B 200 "GET /_matrix/client/r0/sync?filter=6&timeout=30000&since=m788039%7E3.817456%7E1.817572%7E2.817568_20566155_2601_2123713_33124_30_7014_2345778_0_3 HTTP/1.0" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Element/1.11.20 Chrome/108.0.5359.179 Electron/22.0.3 Safari/537.36" [0 dbevts]
tonkku-matrix-server-generic-worker-2 | 2023-01-27 07:50:32,717 - synapse.access.http.9102 - 460 - INFO - PUT-10819 - 37.221.197.227 - 9102 - {strahlungsfrei.de} Processed request: 0.022sec/0.000sec (0.001sec, 0.000sec) (0.001sec/0.002sec/2) 11B 200 "PUT /_matrix/federation/v1/send/1674647102137 HTTP/1.0" "Synapse/1.75.0" [0 dbevts]
tonkku-matrix-server | 2023-01-27 07:50:32,952 - synapse.access.http.9100 - 460 - INFO - POST-64496 - ::ffff:192.168.240.7 - 9100 - {None} Processed request: 0.000sec/0.000sec (0.000sec, 0.000sec) (0.000sec/0.000sec/0) 279B 200 "POST /_synapse/replication/presence_set_state/%40tonkku%3Atonkku.me HTTP/1.1" "Synapse/1.76.0rc1" [0 dbevts]
tonkku-matrix-server-generic-worker-1 | 2023-01-27 07:50:32,952 - synapse.http.client - 460 - INFO - GET-12350 - Received response to POST http://synapse:9100/_synapse/replication/presence_set_state/%40tonkku%3Atonkku.me: 200
tonkku-matrix-server-generic-worker-2 | 2023-01-27 07:50:33,864 - synapse.federation.transport.server.federation - 103 - INFO - PUT-10820 - Received txn 1674646692320 from roastburry.com. (PDUs: 0, EDUs: 1)
tonkku-matrix-server | 2023-01-27 07:50:33,867 - synapse.replication.http.federation - 186 - INFO - POST-64497 - Got 'm.presence' edu from roastburry.com
tonkku-matrix-server | 2023-01-27 07:50:33,868 - synapse.access.http.9100 - 460 - INFO - POST-64497 - ::ffff:192.168.240.6 - 9100 - {None} Processed request: 0.001sec/0.000sec (0.001sec, 0.000sec) (0.000sec/0.000sec/0) 279B 200 "POST /_synapse/replication/fed_send_edu/m.presence/LBeYTSWDXP HTTP/1.1" "Synapse/1.76.0rc1" [0 dbevts]
tonkku-matrix-server-generic-worker-2 | 2023-01-27 07:50:33,869 - synapse.http.client - 460 - INFO - PUT-10820 - Received response to POST http://synapse:9100/_synapse/replication/fed_send_edu/m.presence/LBeYTSWDXP: 200
tonkku-matrix-server-generic-worker-2 | 2023-01-27 07:50:33,875 - synapse.access.http.9102 - 460 - INFO - PUT-10820 - 99.46.147.41 - 9102 - {roastburry.com} Processed request: 0.012sec/0.000sec (0.002sec, 0.000sec) (0.001sec/0.006sec/2) 11B 200 "PUT /_matrix/federation/v1/send/1674646692320 HTTP/1.0" "Synapse/1.74.0" [0 dbevts]
```

### Anything else that would be useful to know?

The logs are a snippet of a few seconds starting from sending a message to a room with members from matrix.org and kde.org. You can see that an outgoing federation request is never even attempted to either of those servers

Contributor guide

Open the contributing guide

Assessment

This issue has not been assessed yet.

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.