Comments (11)
msherman13
commented on July 17, 2024
anyone able to help here?
from boringtun.
csepulveda
commented on July 17, 2024
Same issue here:
2023-09-20T18:00:24.128Z DEBUG boringtun::noise::timers: KEEPALIVE(PERSISTENT_KEEPALIVE)
2023-09-20T18:00:48.298Z DEBUG boringtun::noise::timers: KEEPALIVE(PERSISTENT_KEEPALIVE)
2023-09-20T18:01:12.487Z DEBUG boringtun::noise::timers: KEEPALIVE(PERSISTENT_KEEPALIVE)
2023-09-20T18:01:36.691Z DEBUG boringtun::noise::timers: KEEPALIVE(PERSISTENT_KEEPALIVE)
2023-09-20T18:02:00.870Z DEBUG boringtun::noise::timers: KEEPALIVE(PERSISTENT_KEEPALIVE)
2023-09-20T18:02:25.090Z DEBUG boringtun::noise::timers: KEEPALIVE(PERSISTENT_KEEPALIVE)
2023-09-20T18:02:35.978Z DEBUG boringtun::noise::timers: SESSION_EXPIRED(REJECT_AFTER_TIME) session=4124895233
2023-09-20T18:02:49.299Z DEBUG boringtun::noise::timers: KEEPALIVE(PERSISTENT_KEEPALIVE)
2023-09-20T18:03:13.498Z DEBUG boringtun::noise::timers: KEEPALIVE(PERSISTENT_KEEPALIVE)
2023-09-20T18:03:17.427Z DEBUG boringtun::noise::timers: SESSION_EXPIRED(REJECT_AFTER_TIME) session=4124895234
2023-09-20T18:03:37.708Z DEBUG boringtun::noise::timers: KEEPALIVE(PERSISTENT_KEEPALIVE)
2023-09-20T18:03:37.708Z DEBUG boringtun::noise: Sending handshake_initiation
2023-09-20T18:03:42.838Z WARN boringtun::noise::timers: HANDSHAKE(REKEY_TIMEOUT)
2023-09-20T18:03:42.839Z DEBUG boringtun::noise: Sending handshake_initiation
2023-09-20T18:03:47.992Z WARN boringtun::noise::timers: HANDSHAKE(REKEY_TIMEOUT)
2023-09-20T18:03:47.993Z DEBUG boringtun::noise: Sending handshake_initiation
2023-09-20T18:03:53.125Z WARN boringtun::noise::timers: HANDSHAKE(REKEY_TIMEOUT)
2023-09-20T18:03:53.126Z DEBUG boringtun::noise: Sending handshake_initiation
2023-09-20T18:03:58.255Z WARN boringtun::noise::timers: HANDSHAKE(REKEY_TIMEOUT)
2023-09-20T18:03:58.255Z DEBUG boringtun::noise: Sending handshake_initiation
2023-09-20T18:04:03.392Z WARN boringtun::noise::timers: HANDSHAKE(REKEY_TIMEOUT)
2023-09-20T18:04:03.392Z DEBUG boringtun::noise: Sending handshake_initiation
2023-09-20T18:04:08.540Z WARN boringtun::noise::timers: HANDSHAKE(REKEY_TIMEOUT)
2023-09-20T18:04:08.541Z DEBUG boringtun::noise: Sending handshake_initiation
2023-09-20T18:04:13.695Z WARN boringtun::noise::timers: HANDSHAKE(REKEY_TIMEOUT)
2023-09-20T18:04:13.695Z DEBUG boringtun::noise: Sending handshake_initiation
2023-09-20T18:04:18.841Z WARN boringtun::noise::timers: HANDSHAKE(REKEY_TIMEOUT)
2023-09-20T18:04:18.841Z DEBUG boringtun::noise: Sending handshake_initiation
2023-09-20T18:04:23.986Z WARN boringtun::noise::timers: HANDSHAKE(REKEY_TIMEOUT)
2023-09-20T18:04:23.989Z DEBUG boringtun::noise: Sending handshake_initiation
2023-09-20T18:04:29.193Z WARN boringtun::noise::timers: HANDSHAKE(REKEY_TIMEOUT)
2023-09-20T18:04:29.193Z DEBUG boringtun::noise: Sending handshake_initiation
2023-09-20T18:04:34.348Z WARN boringtun::noise::timers: HANDSHAKE(REKEY_TIMEOUT)
2023-09-20T18:04:34.349Z DEBUG boringtun::noise: Sending handshake_initiation
2023-09-20T18:04:39.479Z WARN boringtun::noise::timers: HANDSHAKE(REKEY_TIMEOUT)
2023-09-20T18:04:39.480Z DEBUG boringtun::noise: Sending handshake_initiation
2023-09-20T18:04:44.667Z WARN boringtun::noise::timers: HANDSHAKE(REKEY_TIMEOUT)
2023-09-20T18:04:44.668Z DEBUG boringtun::noise: Sending handshake_initiation
2023-09-20T18:04:49.805Z WARN boringtun::noise::timers: HANDSHAKE(REKEY_TIMEOUT)
2023-09-20T18:04:49.805Z DEBUG boringtun::noise: Sending handshake_initiation
2023-09-20T18:04:54.935Z WARN boringtun::noise::timers: HANDSHAKE(REKEY_TIMEOUT)
2023-09-20T18:04:54.936Z DEBUG boringtun::noise: Sending handshake_initiation
2023-09-20T18:05:00.078Z WARN boringtun::noise::timers: HANDSHAKE(REKEY_TIMEOUT)
2023-09-20T18:05:00.079Z DEBUG boringtun::noise: Sending handshake_initiation
2023-09-20T18:05:05.224Z WARN boringtun::noise::timers: HANDSHAKE(REKEY_TIMEOUT)
2023-09-20T18:05:05.224Z DEBUG boringtun::noise: Sending handshake_initiation
2023-09-20T18:05:07.938Z ERROR boringtun::noise::timers: CONNECTION_EXPIRED(REKEY_ATTEMPT_TIME)
2023-09-20T18:05:08.061Z DEBUG boringtun::noise: Sending handshake_initiation
2023-09-20T18:05:08.072Z DEBUG boringtun::noise: Received handshake_response local_idx=2722392065 remote_idx=1259440
2023-09-20T18:05:08.072Z DEBUG boringtun::noise: New session session=2722392065
2023-09-20T18:05:08.072Z DEBUG boringtun::noise: Sending keepalive
any ideas what could be? do you need any other info?
from boringtun.
msherman13
commented on July 17, 2024
I tried on fedora 36 and it’s even worse. Connection freezes after 5 seconds every time. Guess I’ll use tailscale
from boringtun.
JonathonFS
commented on July 17, 2024
Similar issue, except on Windows 10. Traffic drops for 1-2 minutes at a time, every 5-10 minutes or so. I can consistently ping google (8.8.8.8) and the cloudflare VPN endpoint this client is using (172.68.168.79), so doesn't seem like an issue with the internet connection. There are 4 other remote clients in this organization that have the same setting applied, but they don't experience the issue. However, those 4 clients are connecting from different locations and are connecting to different cloudflare VPN endpoints.
- Mode: Gateway with WARP
- Split Tunnel: Include IPs and Domains
- WARP v23.11.6.0
- Cloudfared v2023.10.0
cfwarp_service_boring.txt shows:
2023-12-01T11:02:33.556Z DEBUG boringtun::noise::timers: KEEPALIVE(PERSISTENT_KEEPALIVE)
2023-12-01T11:02:57.679Z DEBUG boringtun::noise::timers: KEEPALIVE(PERSISTENT_KEEPALIVE)
2023-12-01T11:03:21.912Z DEBUG boringtun::noise::timers: KEEPALIVE(PERSISTENT_KEEPALIVE)
2023-12-01T11:03:46.128Z DEBUG boringtun::noise::timers: KEEPALIVE(PERSISTENT_KEEPALIVE)
2023-12-01T11:03:50.169Z DEBUG boringtun::noise::timers: SESSION_EXPIRED(REJECT_AFTER_TIME) session=10645661 index=41584
2023-12-01T11:04:10.334Z DEBUG boringtun::noise::timers: KEEPALIVE(PERSISTENT_KEEPALIVE)
2023-12-01T11:04:24.301Z WARN boringtun::noise::timers: HANDSHAKE(KEEPALIVE + REKEY_TIMEOUT)
2023-12-01T11:04:24.301Z DEBUG boringtun::noise: Sending handshake_initiation
2023-12-01T11:04:29.540Z WARN boringtun::noise::timers: HANDSHAKE(REKEY_TIMEOUT)
2023-12-01T11:04:29.540Z DEBUG boringtun::noise: Sending handshake_initiation
2023-12-01T11:04:34.824Z WARN boringtun::noise::timers: HANDSHAKE(REKEY_TIMEOUT)
2023-12-01T11:04:34.824Z DEBUG boringtun::noise: Sending handshake_initiation
2023-12-01T11:04:40.084Z WARN boringtun::noise::timers: HANDSHAKE(REKEY_TIMEOUT)
2023-12-01T11:04:40.085Z DEBUG boringtun::noise: Sending handshake_initiation
2023-12-01T11:04:45.349Z WARN boringtun::noise::timers: HANDSHAKE(REKEY_TIMEOUT)
2023-12-01T11:04:45.349Z DEBUG boringtun::noise: Sending handshake_initiation
2023-12-01T11:04:50.627Z WARN boringtun::noise::timers: HANDSHAKE(REKEY_TIMEOUT)
2023-12-01T11:04:50.627Z DEBUG boringtun::noise: Sending handshake_initiation
2023-12-01T11:04:55.917Z WARN boringtun::noise::timers: HANDSHAKE(REKEY_TIMEOUT)
2023-12-01T11:04:55.918Z DEBUG boringtun::noise: Sending handshake_initiation
2023-12-01T11:05:01.191Z WARN boringtun::noise::timers: HANDSHAKE(REKEY_TIMEOUT)
2023-12-01T11:05:01.191Z DEBUG boringtun::noise: Sending handshake_initiation
2023-12-01T11:05:06.463Z WARN boringtun::noise::timers: HANDSHAKE(REKEY_TIMEOUT)
2023-12-01T11:05:06.463Z DEBUG boringtun::noise: Sending handshake_initiation
2023-12-01T11:05:11.733Z WARN boringtun::noise::timers: HANDSHAKE(REKEY_TIMEOUT)
2023-12-01T11:05:11.733Z DEBUG boringtun::noise: Sending handshake_initiation
2023-12-01T11:05:11.754Z DEBUG boringtun::noise: Received handshake_response local_idx=10645681 remote_idx=16685579
2023-12-01T11:05:11.755Z DEBUG boringtun::noise: New session session=10645681 index=41584
2023-12-01T11:05:11.755Z DEBUG boringtun::noise: Sending keepalive
2023-12-01T11:05:12.045Z DEBUG boringtun::noise::timers: KEEPALIVE(PERSISTENT_KEEPALIVE)
About 30-50% of the time I also get an Incorrect sender index for responder gone packet error. But this message doesn't show up consistently when I experience the problem.
2023-12-01T11:00:04.824Z DEBUG boringtun::noise::timers: KEEPALIVE(PERSISTENT_KEEPALIVE)
2023-12-01T11:00:29.020Z DEBUG boringtun::noise::timers: KEEPALIVE(PERSISTENT_KEEPALIVE)
2023-12-01T11:00:50.141Z DEBUG boringtun::noise::timers: HANDSHAKE(REKEY_AFTER_TIME (on send))
2023-12-01T11:00:50.141Z DEBUG boringtun::noise: Sending handshake_initiation
2023-12-01T11:00:50.166Z DEBUG boringtun::noise: Received handshake_response local_idx=10645661 remote_idx=8409149
2023-12-01T11:00:50.166Z DEBUG boringtun::noise: New session session=10645661 index=41584
2023-12-01T11:00:50.166Z DEBUG boringtun::noise: Sending keepalive
2023-12-01T11:00:53.244Z DEBUG boringtun::noise::timers: KEEPALIVE(PERSISTENT_KEEPALIVE)
2023-12-01T11:01:17.495Z DEBUG boringtun::noise::timers: KEEPALIVE(PERSISTENT_KEEPALIVE)
2023-12-01T11:01:17.520Z DEBUG boringtun::noise: Incorrect sender index for responder gone packet packet_index=8409088 session_index=8409149
2023-12-01T11:01:17.607Z DEBUG boringtun::noise: Incorrect sender index for responder gone packet packet_index=8409088 session_index=8409149
2023-12-01T11:01:17.838Z DEBUG boringtun::noise: Incorrect sender index for responder gone packet packet_index=8409088 session_index=8409149
2023-12-01T11:01:18.002Z DEBUG boringtun::noise: Incorrect sender index for responder gone packet packet_index=8409088 session_index=8409149
2023-12-01T11:01:18.109Z DEBUG boringtun::noise: Incorrect sender index for responder gone packet packet_index=8409088 session_index=8409149
2023-12-01T11:01:18.309Z DEBUG boringtun::noise: Incorrect sender index for responder gone packet packet_index=8409088 session_index=8409149
2023-12-01T11:01:18.670Z DEBUG boringtun::noise: Incorrect sender index for responder gone packet packet_index=8409088 session_index=8409149
2023-12-01T11:01:18.919Z DEBUG boringtun::noise: Incorrect sender index for responder gone packet packet_index=8409088 session_index=8409149
2023-12-01T11:01:19.757Z DEBUG boringtun::noise: Incorrect sender index for responder gone packet packet_index=8409088 session_index=8409149
2023-12-01T11:01:20.131Z DEBUG boringtun::noise: Incorrect sender index for responder gone packet packet_index=8409088 session_index=8409149
2023-12-01T11:01:21.938Z DEBUG boringtun::noise: Incorrect sender index for responder gone packet packet_index=8409088 session_index=8409149
2023-12-01T11:01:22.532Z DEBUG boringtun::noise: Incorrect sender index for responder gone packet packet_index=8409088 session_index=8409149
2023-12-01T11:01:22.927Z DEBUG boringtun::noise: Incorrect sender index for responder gone packet packet_index=8409088 session_index=8409149
2023-12-01T11:01:41.699Z DEBUG boringtun::noise::timers: KEEPALIVE(PERSISTENT_KEEPALIVE)
2023-12-01T11:01:45.749Z WARN boringtun::noise::timers: HANDSHAKE(KEEPALIVE + REKEY_TIMEOUT)
2023-12-01T11:01:45.750Z DEBUG boringtun::noise: Sending handshake_initiation
2023-12-01T11:01:50.416Z DEBUG boringtun::noise::timers: SESSION_EXPIRED(REJECT_AFTER_TIME) session=10645660 index=41584
2023-12-01T11:01:51.040Z WARN boringtun::noise::timers: HANDSHAKE(REKEY_TIMEOUT)
2023-12-01T11:01:51.041Z DEBUG boringtun::noise: Sending handshake_initiation
2023-12-01T11:01:56.335Z WARN boringtun::noise::timers: HANDSHAKE(REKEY_TIMEOUT)
2023-12-01T11:01:56.335Z DEBUG boringtun::noise: Sending handshake_initiation
2023-12-01T11:02:01.622Z WARN boringtun::noise::timers: HANDSHAKE(REKEY_TIMEOUT)
2023-12-01T11:02:01.622Z DEBUG boringtun::noise: Sending handshake_initiation
2023-12-01T11:02:06.891Z WARN boringtun::noise::timers: HANDSHAKE(REKEY_TIMEOUT)
2023-12-01T11:02:06.891Z DEBUG boringtun::noise: Sending handshake_initiation
2023-12-01T11:02:12.158Z WARN boringtun::noise::timers: HANDSHAKE(REKEY_TIMEOUT)
2023-12-01T11:02:12.158Z DEBUG boringtun::noise: Sending handshake_initiation
2023-12-01T11:02:17.427Z WARN boringtun::noise::timers: HANDSHAKE(REKEY_TIMEOUT)
2023-12-01T11:02:17.427Z DEBUG boringtun::noise: Sending handshake_initiation
2023-12-01T11:02:22.696Z WARN boringtun::noise::timers: HANDSHAKE(REKEY_TIMEOUT)
2023-12-01T11:02:22.696Z DEBUG boringtun::noise: Sending handshake_initiation
2023-12-01T11:02:27.949Z WARN boringtun::noise::timers: HANDSHAKE(REKEY_TIMEOUT)
2023-12-01T11:02:27.949Z DEBUG boringtun::noise: Sending handshake_initiation
2023-12-01T11:02:31.916Z DEBUG boringtun::noise: Incorrect sender index for responder gone packet packet_index=8409088 session_index=8409149
2023-12-01T11:02:32.101Z DEBUG boringtun::noise: Incorrect sender index for responder gone packet packet_index=8409088 session_index=8409149
2023-12-01T11:02:32.486Z DEBUG boringtun::noise: Incorrect sender index for responder gone packet packet_index=8409088 session_index=8409149
2023-12-01T11:02:32.933Z DEBUG boringtun::noise: Incorrect sender index for responder gone packet packet_index=8409088 session_index=8409149
2023-12-01T11:02:33.035Z DEBUG boringtun::noise: Incorrect sender index for responder gone packet packet_index=8409088 session_index=8409149
2023-12-01T11:02:33.249Z WARN boringtun::noise::timers: HANDSHAKE(REKEY_TIMEOUT)
2023-12-01T11:02:33.249Z DEBUG boringtun::noise: Sending handshake_initiation
2023-12-01T11:02:33.270Z DEBUG boringtun::noise: Received handshake_response local_idx=10645671 remote_idx=16685569
2023-12-01T11:02:33.271Z DEBUG boringtun::noise: New session session=10645671 index=41584
2023-12-01T11:02:33.271Z DEBUG boringtun::noise: Sending keepalive
2023-12-01T11:02:33.556Z DEBUG boringtun::noise::timers: KEEPALIVE(PERSISTENT_KEEPALIVE)
2023-12-01T11:02:57.679Z DEBUG boringtun::noise::timers: KEEPALIVE(PERSISTENT_KEEPALIVE)
2023-12-01T11:03:21.912Z DEBUG boringtun::noise::timers: KEEPALIVE(PERSISTENT_KEEPALIVE)
I'm currently trying to find a good way to re-home clients to different cloudflare VPN endpoints. Maybe this client's VPN endpoint (172.68.168.79) is just having a bad day?
from boringtun.
JonathonFS
commented on July 17, 2024
EDIT: This didn't actually assign a different "VPN endpoint". It just caused a change in the internal VPN routing, which was observable when running tracert to a tunneled subnet. See post on 12/11/2023 for a real way to change the VPN endpoint.
I was able to get the client shifted over to another VPN endpoint by revoking access, restarting the warp service, and re-authorizing the device (not sure if both were necessary). After that the system was solid for about an hour. Then it started dropping out again with the same error.
2023-12-01T20:55:25.094Z DEBUG boringtun::noise::timers: KEEPALIVE(PERSISTENT_KEEPALIVE)
2023-12-01T20:55:49.309Z DEBUG boringtun::noise::timers: KEEPALIVE(PERSISTENT_KEEPALIVE)
2023-12-01T20:56:09.793Z DEBUG boringtun::noise::timers: SESSION_EXPIRED(REJECT_AFTER_TIME) session=11520023 index=45000
2023-12-01T20:56:13.526Z DEBUG boringtun::noise::timers: KEEPALIVE(PERSISTENT_KEEPALIVE)
2023-12-01T20:56:37.752Z DEBUG boringtun::noise::timers: KEEPALIVE(PERSISTENT_KEEPALIVE)
2023-12-01T20:57:01.948Z DEBUG boringtun::noise::timers: KEEPALIVE(PERSISTENT_KEEPALIVE)
2023-12-01T20:57:09.980Z DEBUG boringtun::noise::timers: HANDSHAKE(REKEY_AFTER_TIME (on send))
2023-12-01T20:57:09.981Z DEBUG boringtun::noise: Sending handshake_initiation
2023-12-01T20:57:10.000Z DEBUG boringtun::noise: Received handshake_response local_idx=11520025 remote_idx=13113367
2023-12-01T20:57:10.000Z DEBUG boringtun::noise: New session session=11520025 index=45000
2023-12-01T20:57:10.000Z DEBUG boringtun::noise: Sending keepalive
2023-12-01T20:57:26.099Z DEBUG boringtun::noise::timers: KEEPALIVE(PERSISTENT_KEEPALIVE)
2023-12-01T20:57:50.278Z DEBUG boringtun::noise::timers: KEEPALIVE(PERSISTENT_KEEPALIVE)
2023-12-01T20:58:09.859Z DEBUG boringtun::noise::timers: SESSION_EXPIRED(REJECT_AFTER_TIME) session=11520024 index=45000
2023-12-01T20:58:14.481Z DEBUG boringtun::noise::timers: KEEPALIVE(PERSISTENT_KEEPALIVE)
2023-12-01T20:58:38.680Z DEBUG boringtun::noise::timers: KEEPALIVE(PERSISTENT_KEEPALIVE)
2023-12-01T20:59:02.918Z DEBUG boringtun::noise::timers: KEEPALIVE(PERSISTENT_KEEPALIVE)
2023-12-01T20:59:10.063Z DEBUG boringtun::noise::timers: HANDSHAKE(REKEY_AFTER_TIME (on send))
2023-12-01T20:59:10.063Z DEBUG boringtun::noise: Sending handshake_initiation
2023-12-01T20:59:10.082Z DEBUG boringtun::noise: Received handshake_response local_idx=11520026 remote_idx=13113368
2023-12-01T20:59:10.082Z DEBUG boringtun::noise: New session session=11520026 index=45000
2023-12-01T20:59:10.082Z DEBUG boringtun::noise: Sending keepalive
2023-12-01T20:59:27.150Z DEBUG boringtun::noise::timers: KEEPALIVE(PERSISTENT_KEEPALIVE)
2023-12-01T20:59:51.352Z DEBUG boringtun::noise::timers: KEEPALIVE(PERSISTENT_KEEPALIVE)
2023-12-01T21:00:10.180Z DEBUG boringtun::noise::timers: SESSION_EXPIRED(REJECT_AFTER_TIME) session=11520025 index=45000
2023-12-01T21:00:15.420Z DEBUG boringtun::noise::timers: KEEPALIVE(PERSISTENT_KEEPALIVE)
2023-12-01T21:00:25.670Z WARN boringtun::noise::timers: HANDSHAKE(KEEPALIVE + REKEY_TIMEOUT)
2023-12-01T21:00:25.670Z DEBUG boringtun::noise: Sending handshake_initiation
2023-12-01T21:00:30.950Z WARN boringtun::noise::timers: HANDSHAKE(REKEY_TIMEOUT)
2023-12-01T21:00:30.950Z DEBUG boringtun::noise: Sending handshake_initiation
2023-12-01T21:00:36.216Z WARN boringtun::noise::timers: HANDSHAKE(REKEY_TIMEOUT)
2023-12-01T21:00:36.216Z DEBUG boringtun::noise: Sending handshake_initiation
2023-12-01T21:00:41.511Z WARN boringtun::noise::timers: HANDSHAKE(REKEY_TIMEOUT)
2023-12-01T21:00:41.511Z DEBUG boringtun::noise: Sending handshake_initiation
2023-12-01T21:00:46.800Z WARN boringtun::noise::timers: HANDSHAKE(REKEY_TIMEOUT)
2023-12-01T21:00:46.800Z DEBUG boringtun::noise: Sending handshake_initiation
2023-12-01T21:00:52.090Z WARN boringtun::noise::timers: HANDSHAKE(REKEY_TIMEOUT)
2023-12-01T21:00:52.090Z DEBUG boringtun::noise: Sending handshake_initiation
2023-12-01T21:00:57.346Z WARN boringtun::noise::timers: HANDSHAKE(REKEY_TIMEOUT)
2023-12-01T21:00:57.346Z DEBUG boringtun::noise: Sending handshake_initiation
2023-12-01T21:01:02.620Z WARN boringtun::noise::timers: HANDSHAKE(REKEY_TIMEOUT)
2023-12-01T21:01:02.620Z DEBUG boringtun::noise: Sending handshake_initiation
2023-12-01T21:01:07.905Z WARN boringtun::noise::timers: HANDSHAKE(REKEY_TIMEOUT)
2023-12-01T21:01:07.906Z DEBUG boringtun::noise: Sending handshake_initiation
2023-12-01T21:01:13.188Z WARN boringtun::noise::timers: HANDSHAKE(REKEY_TIMEOUT)
2023-12-01T21:01:13.188Z DEBUG boringtun::noise: Sending handshake_initiation
2023-12-01T21:01:18.289Z WARN boringtun::noise::timers: HANDSHAKE(REKEY_TIMEOUT)
2023-12-01T21:01:18.290Z DEBUG boringtun::noise: Sending handshake_initiation
2023-12-01T21:01:18.310Z DEBUG boringtun::noise: Received handshake_response local_idx=11520037 remote_idx=13113369
2023-12-01T21:01:18.311Z DEBUG boringtun::noise: New session session=11520037 index=45000
2023-12-01T21:01:18.311Z DEBUG boringtun::noise: Sending keepalive
2023-12-01T21:01:18.589Z DEBUG boringtun::noise::timers: KEEPALIVE(PERSISTENT_KEEPALIVE)
Back to the drawing boarding...
from boringtun.
JonathonFS
commented on July 17, 2024
I setup ping monitors on the workstation. The problem seems to come and go. Sometimes the problem will occur every 5-10 minutes, other times there won't be any issues for a few hours.
I took a closer look at the logs using Excel. Seems the protocol alternates between two overlapping sessions, which I'm calling Session A and Session B. Each session lasts 3 minutes, then waits 1 minute before re-keying a new session.
Everything looks peachy in the logs below, until we get to line 55. We should expect to see the first keepalive for Session A, which would look something like this:
DEBUG boringtun::noise::timers: KEEPALIVE(PERSISTENT_KEEPALIVE)
Instead we get this around the same time we'd expect to get the keepalive:
WARN boringtun::noise::timers: HANDSHAKE(KEEPALIVE + REKEY_TIMEOUT)
I'm not exactly sure if this REKEY_TIMEOUT is for session A or B. Session B is already 12 seconds into it's rekey cool-down period. But I put the rekey failures in the session B column anyways, since we still get a SESSION_EXPIRED log later on for session A.
So the problem seems to be that this KEEPALIVE + REKEY_TIMEOUT timer is forcing boringtun to rekey session A while session B is in it's 1 minute rekey cool down period. For whatever reason, boringtun can't seem to rekey session A during the 1 minute cool-down. Maybe the server won't allow it to rekey early? Doesn't really matter, since this seems to be a symptom of the root problem.... which is what causes the KEEPALIVE + REKEY_TIMEOUT timer to trigger at an in-opportune time?
from boringtun.
JonathonFS
commented on July 17, 2024
In the Zero Trust admin center, under Settings > Authentication, I tried changing the Global session timeout to 1 Month. This had no effect, so I changed it back to Same as application session timeout.
Been doing some more reading on the subject, and WireGuard states:
A handshake initiation is retried after REKEY_TIMEOUT + jitter ms, if a response has not been received, where jitter is some random value between 0 and 333 ms.
Looking at the log's timestamps, I believe REKEY_TIMEOUT = 5 seconds and KEEPALIVE = 25 seconds. WireGuard goes on to say:
If we have sent a packet to a given peer but have not received a packet after from that peer for KEEPALIVE + REKEY_TIMEOUT ms, we initiate a new handshake.
This means we should expect to see the KEEPALIVE + REKEY_TIMEOUT timer go off if it's been 30+ seconds since we sent a packet and have had no response. So now the question becomes, why aren't we getting a response in that 30 second window?
- Is a response package being sent?
- The connection works intermittently, so I'm pretty sure cloudflare is sending a response.
- Is there a delay?
- Could the cloudflare VPN gateway be too busy? (I doubt it.)
- Could the workstation's ISP be throttling UDP?
- Possible Solution: Increase REKEY_TIMEOUT to 10 or 15 seconds
- Is the response getting blocked/dropped?
- The response isn't being blocked, since it works intermittently.
- If the ISP is using CGNAT, and the dynamic IP bounces around frequently, an inbound UDP packet might get lost.
- Possible Solution: Decrease the KEEPALIVE to 20 or 15 seconds? The ISP must have some mechanism in place to preserve active UDP streams as they're migrated within the CGNAT. Decreasing the keepalive could help ensure the UDP session is preserved.
Does anyone know how to tweak the REKEY_TIMEOUT and KEEPALIVE parameters? I don't see this anywhere in the Windows registry or config files.
from boringtun.
JonathonFS
commented on July 17, 2024
I've implemented some monitoring that allows me to see the number of KEEPALIVE + REKEY_TIMEOUT (KART) and standalone REKEY_TIMEOUT (RKTO) events. The workstation at issue has improved over the past week, but still experiences a significantly higher number of KART events from our other workstations... with the exception one other. This other PC (bottom of image) has 18x the number of KART events, but almost zero RKTO events and no network dropouts.
This is interesting, because it shows the KART event can be handled gracefully, and doesn't need to cause packet loss. So now the question becomes, why can one workstation recover from a KART event in under 100ms, while another workstation is forced to wait until the aforementioned 1 minute cool-down expires? I tried shifting the workstation at issue over to the working PC's VPN endpoint. Maybe the original VPN endpoint doesn't like early rekeys?
warp-cli tunnel endpoint set 162.159.193.8:2408
If that doesn't work, I'll try one of the alternative ports. Maybe the ISP will handle traffic on UDP 500, 1701, or 4500 better.
from boringtun.
JonathonFS
commented on July 17, 2024
It's been a week, and we've had no more traffic dropouts. Changing the VPN endpoint seems to have done the trick. KEEPALIVE + REKEY_TIMEOUT (KART) events are down from 11.34/day to 1.16/day. More importantly, REKEY_TIMEOUT (RKTO) events are down from 147.1/day to 0/day.
So maybe the issue wasn't with boringtun after all... Could be something on the Cloudflare VPN endpoint side.
from boringtun.
Related Issues (20)
- Error doesn't implement StdError or Display
- Crate no longer compiles HOT 15
- How does warp use same allowedIP(172.16.0.2/32) for all of their clients ? HOT 3
- [ server_mode ] Cannot connect , 1970-01-01 Timestamp for latest handshake, no data sent to client
- Is this crate still "undergoing a restructuring"? HOT 1
- Usage documentation or samples for Android and iOS HOT 1
- `wg set private-key` does not give any output with `wg show`
- Example to test functionality
- Failed to initialize tunnel HOT 1
- Slow work during testing on VM HOT 17
- The wireguard_write encryption result is different from the official one HOT 5
- libboringtun.so shared lib
- Decapsulate error InvalidCounter (not a huge problem, just curious why it happens and whether I should worry) HOT 2
- Tag 0.6.0?
- Add support for mips(el) with ring 0.17.0
- Failed to initialize tunnel, error: Socket kind: NotFound
- any benchmarks against Wireguard? HOT 5
- Apple Silicon Support? HOT 2
- i found it's hard to compile this project to shared lib for android, lets share it here HOT 1
Recommend Projects
-
React
A declarative, efficient, and flexible JavaScript library for building user interfaces.
-
Vue.js
🖖 Vue.js is a progressive, incrementally-adoptable JavaScript framework for building UI on the web.
-
Typescript
TypeScript is a superset of JavaScript that compiles to clean JavaScript output.
-
TensorFlow
An Open Source Machine Learning Framework for Everyone
-
Django
The Web framework for perfectionists with deadlines.
-
Laravel
A PHP framework for web artisans
-
D3
Bring data to life with SVG, Canvas and HTML. 📊📈🎉
-
Recommend Topics
-
javascript
JavaScript (JS) is a lightweight interpreted programming language with first-class functions.
-
web
Some thing interesting about web. New door for the world.
-
server
A server is a program made to process requests and deliver data to clients.
-
Machine learning
Machine learning is a way of modeling and interpreting data that allows a piece of software to respond intelligently.
-
Visualization
Some thing interesting about visualization, use data art
-
Game
Some thing interesting about game, make everyone happy.
Recommend Org
-
Facebook
We are working to build community through open source technology. NB: members must have two-factor auth.
-
Microsoft
Open source projects and samples from Microsoft.
-
Google
Google ❤️ Open Source for everyone.
-
Alibaba
Alibaba Open Source for everyone
-
D3
Data-Driven Documents codes.
-
Tencent
China tencent open source team.
from boringtun.