Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Do not recover from network outage #929

Open
Knud3 opened this issue Sep 2, 2023 · 1 comment
Open

Do not recover from network outage #929

Knud3 opened this issue Sep 2, 2023 · 1 comment

Comments

@Knud3
Copy link

Knud3 commented Sep 2, 2023

If network outage occur, users won't receive new messages even network is up again.

Matrix itself and e.g. mautrix-signal will continue to work even after network outage.

Workaround is to send message to any Telegram room to get every new message to every rooms.

Everything is running in Docker containers with latest versions.

Here is log lines. 3am network outage:

[2023-08-28 03:00:41,269] [[email protected]] Getting difference for account updates (seq: 687, pts: 91593, qts: 0, date: 2023-08-28 02:45:41+00:00)
[2023-08-28 03:01:21,283] [[email protected]] Closing current connection to begin reconnect...
[2023-08-28 03:01:21,284] [[email protected]] Connecting to 149.154.167.91:443/TcpFull...
[2023-08-28 03:01:21,484] [[email protected]] Closing current connection to begin reconnect...
[2023-08-28 03:01:21,485] [[email protected]] Connecting to 149.154.167.91:443/TcpFull...
[2023-08-28 03:01:23,578] [[email protected]] Attempt 1 at connecting failed: OSError: [Errno 113] Connect call failed ('149.154.167.91', 443)
[2023-08-28 03:01:23,578] [[email protected]] Attempt 1 at connecting failed: OSError: [Errno 113] Connect call failed ('149.154.167.91', 443)
[2023-08-28 03:01:26,650] [[email protected]] Attempt 2 at connecting failed: OSError: [Errno 113] Connect call failed ('149.154.167.91', 443)
[2023-08-28 03:01:29,722] [[email protected]] Attempt 2 at connecting failed: OSError: [Errno 113] Connect call failed ('149.154.167.91', 443)
[2023-08-28 03:01:29,722] [[email protected]] Attempt 3 at connecting failed: OSError: [Errno 113] Connect call failed ('149.154.167.91', 443)
[2023-08-28 03:01:32,794] [[email protected]] Attempt 3 at connecting failed: OSError: [Errno 113] Connect call failed ('149.154.167.91', 443)
[2023-08-28 03:01:32,794] [[email protected]] Attempt 4 at connecting failed: OSError: [Errno 113] Connect call failed ('149.154.167.91', 443)
[2023-08-28 03:01:35,866] [[email protected]] Attempt 4 at connecting failed: OSError: [Errno 113] Connect call failed ('149.154.167.91', 443)
[2023-08-28 03:01:35,866] [[email protected]] Attempt 5 at connecting failed: OSError: [Errno 113] Connect call failed ('149.154.167.91', 443)
[2023-08-28 03:01:38,938] [[email protected]] Attempt 5 at connecting failed: OSError: [Errno 113] Connect call failed ('149.154.167.91', 443)
[2023-08-28 03:01:38,938] [[email protected]] Attempt 6 at connecting failed: OSError: [Errno 113] Connect call failed ('149.154.167.91', 443)
[2023-08-28 03:01:39,940] [[email protected]] Failed reconnection attempt 1 with ConnectionError
[2023-08-28 03:01:40,942] [[email protected]] Connecting to 149.154.167.91:443/TcpFull...
[2023-08-28 03:01:42,010] [[email protected]] Attempt 6 at connecting failed: OSError: [Errno 113] Connect call failed ('149.154.167.91', 443)
[2023-08-28 03:01:42,010] [[email protected]] Attempt 1 at connecting failed: OSError: [Errno 113] Connect call failed ('149.154.167.91', 443)
[2023-08-28 03:01:43,012] [[email protected]] Failed reconnection attempt 1 with ConnectionError
[2023-08-28 03:01:44,014] [[email protected]] Connecting to 149.154.167.91:443/TcpFull...
[2023-08-28 03:01:45,082] [[email protected]] Attempt 2 at connecting failed: OSError: [Errno 113] Connect call failed ('149.154.167.91', 443)
[2023-08-28 03:01:45,082] [[email protected]] Attempt 1 at connecting failed: OSError: [Errno 113] Connect call failed ('149.154.167.91', 443)
[2023-08-28 03:01:48,154] [[email protected]] Attempt 3 at connecting failed: OSError: [Errno 113] Connect call failed ('149.154.167.91', 443)
[2023-08-28 03:01:48,154] [[email protected]] Attempt 2 at connecting failed: OSError: [Errno 113] Connect call failed ('149.154.167.91', 443)
[2023-08-28 03:01:51,226] [[email protected]] Attempt 4 at connecting failed: OSError: [Errno 113] Connect call failed ('149.154.167.91', 443)
[2023-08-28 03:01:51,226] [[email protected]] Attempt 3 at connecting failed: OSError: [Errno 113] Connect call failed ('149.154.167.91', 443)
[2023-08-28 03:01:54,298] [[email protected]] Attempt 5 at connecting failed: OSError: [Errno 113] Connect call failed ('149.154.167.91', 443)
[2023-08-28 03:01:54,298] [[email protected]] Attempt 4 at connecting failed: OSError: [Errno 113] Connect call failed ('149.154.167.91', 443)
[2023-08-28 03:01:57,370] [[email protected]] Attempt 6 at connecting failed: OSError: [Errno 113] Connect call failed ('149.154.167.91', 443)
[2023-08-28 03:01:57,370] [[email protected]] Attempt 5 at connecting failed: OSError: [Errno 113] Connect call failed ('149.154.167.91', 443)
[2023-08-28 03:01:58,372] [[email protected]] Failed reconnection attempt 2 with ConnectionError
[2023-08-28 03:01:59,374] [[email protected]] Connecting to 149.154.167.91:443/TcpFull...
[2023-08-28 03:02:00,442] [[email protected]] Attempt 6 at connecting failed: OSError: [Errno 113] Connect call failed ('149.154.167.91', 443)
[2023-08-28 03:02:00,442] [[email protected]] Attempt 1 at connecting failed: OSError: [Errno 113] Connect call failed ('149.154.167.91', 443)
[2023-08-28 03:02:01,444] [[email protected]] Failed reconnection attempt 2 with ConnectionError
[2023-08-28 03:02:02,445] [[email protected]] Connecting to 149.154.167.91:443/TcpFull...
[2023-08-28 03:02:03,514] [[email protected]] Attempt 2 at connecting failed: OSError: [Errno 113] Connect call failed ('149.154.167.91', 443)
[2023-08-28 03:02:03,514] [[email protected]] Attempt 1 at connecting failed: OSError: [Errno 113] Connect call failed ('149.154.167.91', 443)
[2023-08-28 03:02:06,586] [[email protected]] Attempt 3 at connecting failed: OSError: [Errno 113] Connect call failed ('149.154.167.91', 443)
[2023-08-28 03:02:06,586] [[email protected]] Attempt 2 at connecting failed: OSError: [Errno 113] Connect call failed ('149.154.167.91', 443)
[2023-08-28 03:02:09,658] [[email protected]] Attempt 4 at connecting failed: OSError: [Errno 113] Connect call failed ('149.154.167.91', 443)
[2023-08-28 03:02:09,658] [[email protected]] Attempt 3 at connecting failed: OSError: [Errno 113] Connect call failed ('149.154.167.91', 443)
[2023-08-28 03:02:12,730] [[email protected]] Attempt 5 at connecting failed: OSError: [Errno 113] Connect call failed ('149.154.167.91', 443)
[2023-08-28 03:02:12,730] [[email protected]] Attempt 4 at connecting failed: OSError: [Errno 113] Connect call failed ('149.154.167.91', 443)
[2023-08-28 03:02:15,802] [[email protected]] Attempt 6 at connecting failed: OSError: [Errno 113] Connect call failed ('149.154.167.91', 443)
[2023-08-28 03:02:15,802] [[email protected]] Attempt 5 at connecting failed: OSError: [Errno 113] Connect call failed ('149.154.167.91', 443)
[2023-08-28 03:02:16,804] [[email protected]] Failed reconnection attempt 3 with ConnectionError
[2023-08-28 03:02:17,806] [[email protected]] Connecting to 149.154.167.91:443/TcpFull...
[2023-08-28 03:02:18,874] [[email protected]] Attempt 6 at connecting failed: OSError: [Errno 113] Connect call failed ('149.154.167.91', 443)
[2023-08-28 03:02:18,874] [[email protected]] Attempt 1 at connecting failed: OSError: [Errno 113] Connect call failed ('149.154.167.91', 443)
[2023-08-28 03:02:19,876] [[email protected]] Failed reconnection attempt 3 with ConnectionError
[2023-08-28 03:02:20,879] [[email protected]] Connecting to 149.154.167.91:443/TcpFull...
[2023-08-28 03:02:21,946] [[email protected]] Attempt 2 at connecting failed: OSError: [Errno 113] Connect call failed ('149.154.167.91', 443)
[2023-08-28 03:02:21,946] [[email protected]] Attempt 1 at connecting failed: OSError: [Errno 113] Connect call failed ('149.154.167.91', 443)
[2023-08-28 03:02:25,018] [[email protected]] Attempt 3 at connecting failed: OSError: [Errno 113] Connect call failed ('149.154.167.91', 443)
[2023-08-28 03:02:25,018] [[email protected]] Attempt 2 at connecting failed: OSError: [Errno 113] Connect call failed ('149.154.167.91', 443)
[2023-08-28 03:02:28,090] [[email protected]] Attempt 4 at connecting failed: OSError: [Errno 113] Connect call failed ('149.154.167.91', 443)
[2023-08-28 03:02:28,090] [[email protected]] Attempt 3 at connecting failed: OSError: [Errno 113] Connect call failed ('149.154.167.91', 443)
[2023-08-28 03:02:31,161] [[email protected]] Attempt 5 at connecting failed: OSError: [Errno 113] Connect call failed ('149.154.167.91', 443)
[2023-08-28 03:02:31,161] [[email protected]] Attempt 4 at connecting failed: OSError: [Errno 113] Connect call failed ('149.154.167.91', 443)
[2023-08-28 03:02:34,234] [[email protected]] Attempt 6 at connecting failed: OSError: [Errno 113] Connect call failed ('149.154.167.91', 443)
[2023-08-28 03:02:34,234] [[email protected]] Attempt 5 at connecting failed: OSError: [Errno 113] Connect call failed ('149.154.167.91', 443)
[2023-08-28 03:02:35,236] [[email protected]] Failed reconnection attempt 4 with ConnectionError
[2023-08-28 03:02:36,238] [[email protected]] Connecting to 149.154.167.91:443/TcpFull...
[2023-08-28 03:02:37,306] [[email protected]] Attempt 6 at connecting failed: OSError: [Errno 113] Connect call failed ('149.154.167.91', 443)
[2023-08-28 03:02:37,306] [[email protected]] Attempt 1 at connecting failed: OSError: [Errno 113] Connect call failed ('149.154.167.91', 443)
[2023-08-28 03:02:38,308] [[email protected]] Failed reconnection attempt 4 with ConnectionError
[2023-08-28 03:02:39,311] [[email protected]] Connecting to 149.154.167.91:443/TcpFull...
[2023-08-28 03:02:40,378] [[email protected]] Attempt 2 at connecting failed: OSError: [Errno 113] Connect call failed ('149.154.167.91', 443)
[2023-08-28 03:02:40,378] [[email protected]] Attempt 1 at connecting failed: OSError: [Errno 113] Connect call failed ('149.154.167.91', 443)
[2023-08-28 03:02:41,271] [[email protected]] Cannot get difference since the network is down: TimeoutError:
[2023-08-28 03:02:43,450] [[email protected]] Attempt 3 at connecting failed: OSError: [Errno 113] Connect call failed ('149.154.167.91', 443)
[2023-08-28 03:02:43,450] [[email protected]] Attempt 2 at connecting failed: OSError: [Errno 113] Connect call failed ('149.154.167.91', 443)
[2023-08-28 03:02:46,273] [[email protected]] Getting difference for account updates (seq: 687, pts: 91593, qts: 0, date: 2023-08-28 02:45:41+00:00)
[2023-08-28 03:02:46,522] [[email protected]] Attempt 4 at connecting failed: OSError: [Errno 113] Connect call failed ('149.154.167.91', 443)
[2023-08-28 03:02:46,522] [[email protected]] Attempt 3 at connecting failed: OSError: [Errno 113] Connect call failed ('149.154.167.91', 443)
[2023-08-28 03:02:49,594] [[email protected]] Attempt 5 at connecting failed: OSError: [Errno 113] Connect call failed ('149.154.167.91', 443)
[2023-08-28 03:02:49,594] [[email protected]] Attempt 4 at connecting failed: OSError: [Errno 113] Connect call failed ('149.154.167.91', 443)
[2023-08-28 03:02:52,665] [[email protected]] Attempt 6 at connecting failed: OSError: [Errno 113] Connect call failed ('149.154.167.91', 443)
[2023-08-28 03:02:52,666] [[email protected]] Attempt 5 at connecting failed: OSError: [Errno 113] Connect call failed ('149.154.167.91', 443)
[2023-08-28 03:02:53,667] [[email protected]] Failed reconnection attempt 5 with ConnectionError
[2023-08-28 03:02:54,670] [[email protected]] Automatic reconnection failed 5 time(s)
[2023-08-28 03:02:54,670] [[email protected]] Disconnecting from 149.154.167.91:443/TcpFull...
[2023-08-28 03:02:54,670] [[email protected]] Disconnection from 149.154.167.91:443/TcpFull complete!
[2023-08-28 03:02:55,738] [[email protected]] Attempt 6 at connecting failed: OSError: [Errno 113] Connect call failed ('149.154.167.91', 443)
[2023-08-28 03:02:56,738] [[email protected]] Failed reconnection attempt 5 with ConnectionError
[2023-08-28 03:02:57,740] [[email protected]] Automatic reconnection failed 5 time(s)
[2023-08-28 03:02:57,741] [[email protected]] Disconnecting from 149.154.167.91:443/TcpFull...
[2023-08-28 03:02:57,741] [[email protected]] Disconnection from 149.154.167.91:443/TcpFull complete!
[2023-08-28 03:04:46,285] [[email protected]] Cannot get difference since the network is down: TimeoutError:
[2023-08-28 03:04:51,291] [[email protected]] Update loop finished
[2023-08-28 03:14:08,458] [[email protected]] Update loop finished
[2023-08-28 06:02:04,600] [[email protected]] Handling transaction 87935 with 4 EDUs
[2023-08-28 06:02:04,601] [[email protected]] Finished handling transaction 87935
[2023-08-28 06:02:04,602] [[email protected]] 172.18.0.4 [28/Aug/2023:06:02:04 +0000] "PUT /_matrix/app/v1/transactions/87935 HTTP/1.1" 200 159 "-" "Synapse/1.90.0"
[2023-08-28 06:22:03,147] [[email protected]] Handling transaction 87939 with 4 EDUs
[2023-08-28 06:22:03,147] [[email protected]] Finished handling transaction 87939
[2023-08-28 06:22:03,148] [[email protected]] 172.18.0.4 [28/Aug/2023:06:22:03 +0000] "PUT /_matrix/app/v1/transactions/87939 HTTP/1.1" 200 159 "-" "Synapse/1.90.0"
[2023-08-28 06:22:03,181] [[email protected]] Handling transaction 87942 with 1 EDUs
[2023-08-28 06:22:03,182] [[email protected]] Finished handling transaction 87942
[2023-08-28 06:22:03,182] [[email protected]] 172.18.0.4 [28/Aug/2023:06:22:03 +0000] "PUT /_matrix/app/v1/transactions/87942 HTTP/1.1" 200 159 "-" "Synapse/1.90.0"
[2023-08-28 06:32:49,151] [[email protected]] Handling transaction 87945 with 4 EDUs
[2023-08-28 06:32:49,152] [[email protected]] Finished handling transaction 87945
[2023-08-28 06:32:49,152] [[email protected]] 172.18.0.4 [28/Aug/2023:06:32:49 +0000] "PUT /_matrix/app/v1/transactions/87945 HTTP/1.1" 200 159 "-" "Synapse/1.90.0"
[2023-08-28 06:32:49,180] [[email protected]] Handling transaction 87948 with 1 EDUs
[2023-08-28 06:32:49,180] [[email protected]] Finished handling transaction 87948
[2023-08-28 06:32:49,180] [[email protected]] 172.18.0.4 [28/Aug/2023:06:32:49 +0000] "PUT /_matrix/app/v1/transactions/87948 HTTP/1.1" 200 159 "-" "Synapse/1.90.0"
[2023-08-28 06:37:40,233] [[email protected]] Handling transaction 87951 with 5 EDUs
[2023-08-28 06:37:40,234] [[email protected]] Finished handling transaction 87951
[2023-08-28 06:37:40,235] [[email protected]] 172.18.0.4 [28/Aug/2023:06:37:40 +0000] "PUT /_matrix/app/v1/transactions/87951 HTTP/1.1" 200 159 "-" "Synapse/1.90.0"
[2023-08-28 07:29:49,311] [[email protected]] Handling transaction 87959 with 1 EDUs
[2023-08-28 07:29:49,311] [[email protected]] Finished handling transaction 87959
[2023-08-28 07:29:49,312] [[email protected]] 172.18.0.4 [28/Aug/2023:07:29:49 +0000] "PUT /_matrix/app/v1/transactions/87959 HTTP/1.1" 200 159 "-" "Synapse/1.90.0"
[2023-08-28 07:29:53,021] [[email protected]] Handling transaction 87960 with 1 EDUs
[2023-08-28 07:29:53,021] [[email protected]] Finished handling transaction 87960
[2023-08-28 07:29:53,022] [[email protected]] 172.18.0.4 [28/Aug/2023:07:29:53 +0000] "PUT /_matrix/app/v1/transactions/87960 HTTP/1.1" 200 159 "-" "Synapse/1.90.0"
[2023-08-28 07:29:53,207] [[email protected]] Handling transaction 87961 with 1 PDUs
[2023-08-28 07:29:53,208] [[email protected]] Finished handling transaction 87961
[2023-08-28 07:29:53,208] [[email protected]] 172.18.0.4 [28/Aug/2023:07:29:53 +0000] "PUT /_matrix/app/v1/transactions/87961 HTTP/1.1" 200 159 "-" "Synapse/1.90.0"
[2023-08-28 07:29:53,230] [[email protected]] Ratchet safety info for *SNIP*: RatchetSafety(next_index=5, missed_indices=[], lost_indices=[]), ratchet_target_index=5
[2023-08-28 07:29:53,252] [[email protected].@user2:example.com] Starting client due to ensure_started(even_if_no_session=False, session_exists=True)
[2023-08-28 07:29:53,252] [[email protected]] Connecting to 149.154.167.91:443/TcpFull...
[2023-08-28 07:29:53,284] [[email protected]] Connection to 149.154.167.91:443/TcpFull complete!
[2023-08-28 07:29:53,544] [[email protected]] Ensuring user is still in *SNIP*
[2023-08-28 07:29:53,590] [[email protected]] Ensuring user is still in *SNIP*
[2023-08-28 07:29:53,630] [[email protected].@user2:example.com] @user2:example.com connected: True
[2023-08-28 07:29:53,630] [[email protected]] Update loop starting
[2023-08-28 07:29:53,631] [[email protected]] Getting difference for account updates (seq: 984, pts: 46501, qts: 0, date: 2023-08-28 02:59:08+00:00)
[2023-08-28 07:29:53,668] [[email protected].@user2:example.com] Ensuring post_login() for @user2:example.com
[2023-08-28 07:29:53,668] [[email protected]] Received Matrix event *SNOP* from @user2:example.com in *SNIP*:example.com
[2023-08-28 07:29:53,669] [[email protected]] New account state after applying difference (DifferenceEmpty): seq: 984, pts: 46501, qts: 0, date: 2023-08-28 07:29:53+00:00
[2023-08-28 07:29:53,822] [[email protected]<->0000000002] Handled Matrix message *SNIP* -> 29207 (edit index 0)
[2023-08-28 07:30:53,639] [[email protected]] Closing current connection to begin reconnect...
[2023-08-28 07:30:53,640] [[email protected]] Connecting to 149.154.167.91:443/TcpFull...
[2023-08-28 07:30:53,671] [[email protected]] Connection to 149.154.167.91:443/TcpFull complete!
[2023-08-28 07:31:53,676] [[email protected]] Closing current connection to begin reconnect...
[2023-08-28 07:31:53,677] [[email protected]] Connecting to 149.154.167.91:443/TcpFull...
[2023-08-28 07:31:53,709] [[email protected]] Connection to 149.154.167.91:443/TcpFull complete!
[2023-08-28 07:32:53,720] [[email protected]] Closing current connection to begin reconnect...
[2023-08-28 07:32:53,721] [[email protected]] Connecting to 149.154.167.91:443/TcpFull...
[2023-08-28 07:32:53,753] [[email protected]] Connection to 149.154.167.91:443/TcpFull complete!
[2023-08-28 07:33:19,229] [[email protected]] Handling transaction 87964 with 5 EDUs
[2023-08-28 07:33:19,230] [[email protected]] Finished handling transaction 87964
[2023-08-28 07:33:19,231] [[email protected]] 172.18.0.4 [28/Aug/2023:07:33:19 +0000] "PUT /_matrix/app/v1/transactions/87964 HTTP/1.1" 200 159 "-" "Synapse/1.90.0"
[2023-08-28 07:33:19,242] [[email protected]] Handling transaction 87967 with 1 EDUs
[2023-08-28 07:33:19,243] [[email protected]] Finished handling transaction 87967
[2023-08-28 07:33:19,243] [[email protected]] 172.18.0.4 [28/Aug/2023:07:33:19 +0000] "PUT /_matrix/app/v1/transactions/87967 HTTP/1.1" 200 159 "-" "Synapse/1.90.0"
[2023-08-28 07:33:53,762] [[email protected]] Closing current connection to begin reconnect...
[2023-08-28 07:33:53,762] [[email protected]] Connecting to 149.154.167.91:443/TcpFull...
[2023-08-28 07:33:53,798] [[email protected]] Connection to 149.154.167.91:443/TcpFull complete!
[2023-08-28 07:34:53,789] [[email protected]] Closing current connection to begin reconnect...
[2023-08-28 07:34:53,791] [[email protected]] Connecting to 149.154.167.91:443/TcpFull...
[2023-08-28 07:34:53,827] [[email protected]] Connection to 149.154.167.91:443/TcpFull complete!
[2023-08-28 07:35:53,835] [[email protected]] Closing current connection to begin reconnect...
[2023-08-28 07:35:53,835] [[email protected]] Connecting to 149.154.167.91:443/TcpFull...
[2023-08-28 07:35:53,870] [[email protected]] Connection to 149.154.167.91:443/TcpFull complete!
[2023-08-28 07:36:53,861] [[email protected]] Closing current connection to begin reconnect...
[2023-08-28 07:36:53,862] [[email protected]] Connecting to 149.154.167.91:443/TcpFull...
[2023-08-28 07:36:53,896] [[email protected]] Connection to 149.154.167.91:443/TcpFull complete!
[2023-08-28 07:37:10,626] [[email protected]] Handling transaction 87971 with 5 EDUs
[2023-08-28 07:37:10,626] [[email protected]] Finished handling transaction 87971
[2023-08-28 07:37:10,627] [[email protected]] 172.18.0.4 [28/Aug/2023:07:37:10 +0000] "PUT /_matrix/app/v1/transactions/87971 HTTP/1.1" 200 159 "-" "Synapse/1.90.0"
[2023-08-28 07:37:10,638] [[email protected]] Handling transaction 87973 with 1 EDUs
[2023-08-28 07:37:10,638] [[email protected]] Finished handling transaction 87973
[2023-08-28 07:37:10,638] [[email protected]] 172.18.0.4 [28/Aug/2023:07:37:10 +0000] "PUT /_matrix/app/v1/transactions/87973 HTTP/1.1" 200 159 "-" "Synapse/1.90.0"
[2023-08-28 07:37:53,893] [[email protected]] Closing current connection to begin reconnect...
[2023-08-28 07:37:53,894] [[email protected]] Connecting to 149.154.167.91:443/TcpFull...
[2023-08-28 07:37:53,925] [[email protected]] Connection to 149.154.167.91:443/TcpFull complete!
[2023-08-28 07:38:53,934] [[email protected]] Closing current connection to begin reconnect...
[2023-08-28 07:38:53,935] [[email protected]] Connecting to 149.154.167.91:443/TcpFull...
[2023-08-28 07:38:53,966] [[email protected]] Connection to 149.154.167.91:443/TcpFull complete!
[2023-08-28 07:38:54,170] [[email protected]] Handling transaction 87976 with 5 EDUs
[2023-08-28 07:38:54,170] [[email protected]] Finished handling transaction 87976
[2023-08-28 07:38:54,171] [[email protected]] 172.18.0.4 [28/Aug/2023:07:38:54 +0000] "PUT /_matrix/app/v1/transactions/87976 HTTP/1.1" 200 159 "-" "Synapse/1.90.0"
[2023-08-28 07:38:56,419] [[email protected]] Handling transaction 87979 with 1 EDUs
[2023-08-28 07:38:56,419] [[email protected]] Finished handling transaction 87979
[2023-08-28 07:38:56,420] [[email protected]] 172.18.0.4 [28/Aug/2023:07:38:56 +0000] "PUT /_matrix/app/v1/transactions/87979 HTTP/1.1" 200 159 "-" "Synapse/1.90.0"
[2023-08-28 07:39:53,970] [[email protected]] Closing current connection to begin reconnect...
[2023-08-28 07:39:53,972] [[email protected]] Connecting to 149.154.167.91:443/TcpFull...
[2023-08-28 07:39:54,008] [[email protected]] Connection to 149.154.167.91:443/TcpFull complete!
[2023-08-28 07:40:54,002] [[email protected]] Closing current connection to begin reconnect...
[2023-08-28 07:40:54,003] [[email protected]] Connecting to 149.154.167.91:443/TcpFull...
[2023-08-28 07:40:54,034] [[email protected]] Connection to 149.154.167.91:443/TcpFull complete!
[2023-08-28 07:41:54,042] [[email protected]] Closing current connection to begin reconnect...
[2023-08-28 07:41:54,043] [[email protected]] Connecting to 149.154.167.91:443/TcpFull...
[2023-08-28 07:41:54,074] [[email protected]] Connection to 149.154.167.91:443/TcpFull complete!
[2023-08-28 07:42:05,557] [[email protected]] Handling transaction 87980 with 1 PDUs
[2023-08-28 07:42:05,557] [[email protected]] Finished handling transaction 87980

User send message to Telegram room and all received messages appear:

[2023-08-28 07:42:05,558] [[email protected]] 172.18.0.4 [28/Aug/2023:07:42:05 +0000] "PUT /_matrix/app/v1/transactions/87980 HTTP/1.1" 200 159 "-" "Synapse/1.90.0"
[2023-08-28 07:42:05,564] [[email protected]] Ratchet safety info for *SNIP*: RatchetSafety(next_index=25, missed_indices=[], lost_indices=[]), ratchet_target_index=25
[2023-08-28 07:42:05,573] [[email protected].@user1:example.com] Starting client due to ensure_started(even_if_no_session=False, session_exists=True)
[2023-08-28 07:42:05,573] [[email protected]] Connecting to 149.154.167.91:443/TcpFull...
[2023-08-28 07:42:05,608] [[email protected]] Connection to 149.154.167.91:443/TcpFull complete!
[2023-08-28 07:42:05,697] [[email protected]] Ensuring user is still in *SNIP*
[2023-08-28 07:42:05,750] [[email protected].@user1:example.com] @user1:example.com connected: True
[2023-08-28 07:42:05,751] [[email protected]] Update loop starting
[2023-08-28 07:42:05,751] [[email protected]] Getting difference for account updates (seq: 687, pts: 91593, qts: 0, date: 2023-08-28 02:45:41+00:00)
[2023-08-28 07:42:05,792] [[email protected].@user1:example.com] Ensuring post_login() for @user1:example.com
[2023-08-28 07:42:05,792] [[email protected]] Received Matrix event *SNIP* from @user1:example.com in *SNIP*:example.com
[2023-08-28 07:42:05,805] [[email protected]] New account state after applying difference (Difference): seq: 787, pts: 91595, qts: 0, date: 2023-08-28 07:42:05+00:00
[2023-08-28 07:42:05,877] [[email protected]<->0000000001] Handling Telegram message 54332@0000000002 from 0000000001 (ts: 2023-08-28 07:28:08+00:00)
[2023-08-28 07:42:05,948] [[email protected]<->0000000003] Handled Matrix message *SNIP* -> 54334 (edit index 0)
[2023-08-28 07:42:05,961] [[email protected]<->0000000002] Handling Telegram message 29208@0000000003 from 0000000002 (ts: 2023-08-28 07:42:05+00:00)
[2023-08-28 07:42:06,051] [[email protected].@telegram_0000000001:example.com] req #1342: PUT http://synapse:8008/_matrix/client/v3/rooms/*SNIP*example.com/typing/%40telegram_0000000001%3Aexample.com?user_id=@telegram_0000000001:example.com {"typing": false}
[2023-08-28 07:42:06,079] [[email protected].@telegram_0000000001:example.com] req #1342 (/v3/rooms/*SNIP*example.com/typing/%40telegram_0000000001%3Aexample.com) completed in 27.2ms with status 200
[2023-08-28 07:42:06,079] [[email protected]] Encrypting event of type m.room.message for *SNIP*:example.com
[2023-08-28 07:42:06,081] [[email protected]] Got EncryptionError, sharing group session and trying again
[2023-08-28 07:42:06,107] [[email protected].@telegram_0000000002:example.com] req #1343: PUT http://synapse:8008/_matrix/client/v3/rooms/*SNIP*example.com/typing/%40telegram_0000000002%3Aexample.com?user_id=@telegram_0000000002:example.com {"typing": false}
[2023-08-28 07:42:06,139] [[email protected].@telegram_0000000002:example.com] req #1343 (/v3/rooms/*SNIP*example.com/typing/%40telegram_0000000002%3Aexample.com) completed in 32.6ms with status 200
[2023-08-28 07:42:06,140] [[email protected]] Encrypting event of type m.room.message for *SNIP*:example.com
[2023-08-28 07:42:06,142] [[email protected]] Got EncryptionError, sharing group session and trying again
[2023-08-28 07:42:06,146] [[email protected]] Handling transaction 87981 with 4 EDUs
[2023-08-28 07:42:06,146] [[email protected]] Finished handling transaction 87981
[2023-08-28 07:42:06,147] [[email protected]] 172.18.0.4 [28/Aug/2023:07:42:06 +0000] "PUT /_matrix/app/v1/transactions/87981 HTTP/1.1" 200 159 "-" "Synapse/1.90.0"
[2023-08-28 07:42:06,167] [[email protected]] Handling transaction 87982 with 1 EDUs
[2023-08-28 07:42:06,168] [[email protected]] Finished handling transaction 87982
[2023-08-28 07:42:06,168] [[email protected]] 172.18.0.4 [28/Aug/2023:07:42:06 +0000] "PUT /_matrix/app/v1/transactions/87982 HTTP/1.1" 200 159 "-" "Synapse/1.90.0"
[2023-08-28 07:42:06,243] [[email protected]] Got stored encryption state event and configured session to rotate after 100 messages or 7 days, 0:00:00
[2023-08-28 07:42:06,248] [[email protected]] Created inbound group session *SNIP*:example.com/*SNIP* (max 7 days, 0:00:00 / 100 messages, is_scheduled=False)
[2023-08-28 07:42:06,248] [[email protected]] Sharing group session *SNIP* for room *SNIP*:example.com with ['@user1:example.com']
[2023-08-28 07:42:06,252] [[email protected]] Trying to encrypt group session *SNIP* for @user1:example.com
[2023-08-28 07:42:06,286] [[email protected]] Sending to-device events to 5 devices of 1 users to share *SNIP*
[2023-08-28 07:42:06,287] [[email protected]] req #1344: PUT http://synapse:8008/_matrix/client/v3/sendToDevice/m.room.encrypted/mautrix-python_*SNIP* {"messages": {"@user1:example.com": {"*SNIP*": {"ciphertext": {"*SNIP*": {"body": "*SNIP*", "type": 1}}, "sender_key": "*SNIP*", "algorithm": "m.olm.v1.curve25519-aes-sha2"}, "*SNIP*": {"ciphertext": {"*SNIP*": {"body": "*SNIP*", "type": 1}}, "sender_key": "*SNIP*", "algorithm": "m.olm.v1.curve25519-aes-sha2"}, "*SNIP*": {"ciphertext": {"*SNIP*": {"body": "*SNIP*", "type": 1}}, "sender_key": "*SNIP*", "algorithm": "m.olm.v1.curve25519-aes-sha2"}, "*SNIP*": {"ciphertext": {"*SNIP*": {"body": "*SNIP*", "type": 1}}, "sender_key": "*SNIP*", "algorithm": "m.olm.v1.curve25519-aes-sha2"}, "*SNIP*": {"ciphertext": {"*SNIP*": {"body": "*SNIP*", "type": 1}}, "sender_key": "*SNIP*", "algorithm": "m.olm.v1.curve25519-aes-sha2"}}}}
[2023-08-28 07:42:06,297] [[email protected]] Got stored encryption state event and configured session to rotate after 100 messages or 7 days, 0:00:00
[2023-08-28 07:42:06,303] [[email protected]] Created inbound group session *SNIP*:example.com/*SNIP*/*SNIP* (max 7 days, 0:00:00 / 100 messages, is_scheduled=False)
[2023-08-28 07:42:06,303] [[email protected]] Sharing group session *SNIP* for room *SNIP*:example.com with ['@user2:example.com']
[2023-08-28 07:42:06,305] [[email protected]] Trying to encrypt group session *SNIP* for @user2:example.com
[2023-08-28 07:42:06,307] [[email protected]] req #1344 (/v3/sendToDevice/m.room.encrypted/mautrix-python_*SNIP*) completed in 20.6ms with status 200
[2023-08-28 07:42:06,308] [[email protected]] Group session *SNIP* for *SNIP*:example.com successfully shared
[2023-08-28 07:42:06,312] [[email protected]] Encrypting event of type m.room.message for *SNIP*:example.com
[2023-08-28 07:42:06,318] [[email protected]] Sending to-device events to 1 devices of 1 users to share *SNIP*
[2023-08-28 07:42:06,318] [[email protected]] req #1345: PUT http://synapse:8008/_matrix/client/v3/sendToDevice/m.room.encrypted/mautrix-python_*SNIP* {"messages": {"@user2:example.com": {"*SNIP*": {"ciphertext": {"*SNIP*": {"body": "*SNIP*", "type": 1}}, "sender_key": "*SNIP*", "algorithm": "m.olm.v1.curve25519-aes-sha2"}}}}
[2023-08-28 07:42:06,323] [[email protected].@telegram_0000000001:example.com] req #1346: PUT http://synapse:8008/_matrix/client/v3/rooms/*SNIP*example.com/send/m.room.encrypted/mautrix-python_*SNIP*?ts=*SNIP*&user_id=@telegram_0000000001:example.com {"ciphertext": "*SNIP*", "session_id": "*SNIP*", "algorithm": "m.megolm.v1.aes-sha2", "sender_key": "*SNIP*", "device_id": "*SNIP*"}
[2023-08-28 07:42:06,331] [[email protected]] req #1345 (/v3/sendToDevice/m.room.encrypted/mautrix-python_*SNIP*) completed in 12.0ms with status 200
[2023-08-28 07:42:06,331] [[email protected]] Group session *SNIP* for *SNIP*:example.com successfully shared
[2023-08-28 07:42:06,338] [[email protected]] Encrypting event of type m.room.message for *SNIP*:example.com
[2023-08-28 07:42:06,344] [[email protected].@telegram_0000000002:example.com] req #1347: PUT http://synapse:8008/_matrix/client/v3/rooms/*SNIP*example.com/send/m.room.encrypted/mautrix-python_*SNIP*?ts=*SNIP*&user_id=@telegram_0000000002:example.com {"ciphertext": "*SNIP*", "session_id": "*SNIP*", "algorithm": "m.megolm.v1.aes-sha2", "sender_key": "*SNIP*", "device_id": "*SNIP*"}
@ClemensElflein
Copy link

I have the same issue. Noticed it after updating to the latest version.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Development

No branches or pull requests

2 participants