Two small Wireguard frustrations on Mac & Apple iOS

Fri Sep 11 03:08:15 CEST 2020

Hi,

Sorry if this message comes out of thread, I wasn't subscribed when the messages below were sent (I did click on the web link containing "in-reply-to").

I'm also seeing the same on iOS (an iPhone and an iPad) after I put them to flight mode (overnight or for more than a few hours).
It seems to recover after a minute and a half but looking at the logs I also saw that handshakes are being attempted while in flight mode every ~ 10 minutes.
This doesn't seem to affect battery life (significantly)

sample log:
--
2020-09-11 00:35:06.972422: [NET] peer(YhQB…Lcm8) - Handshake did not complete after 5 seconds, retrying (try 3)
2020-09-11 00:35:06.972897: [NET] peer(YhQB…Lcm8) - Sending handshake initiation
2020-09-11 00:35:06.975534: [NET] peer(CHzf…1U30) - Handshake did not complete after 5 seconds, retrying (try 6)
2020-09-11 00:35:06.978000: [NET] peer(CHzf…1U30) - Sending handshake initiation
2020-09-11 00:35:06.980886: [NET] peer(YhQB…Lcm8) - Failed to send handshake initiation write udp4 0.0.0.0:56035->redacted_peer_1:44455: sendto: no route to host
2020-09-11 00:35:06.981306: [NET] peer(YhQB…Lcm8) - Removing all keys, since we haven't received a new one in 540 seconds
2020-09-11 00:35:06.985392: [NET] peer(CHzf…1U30) - Failed to send handshake initiation write udp4 0.0.0.0:56035->redacted_peer_2:44455: sendto: no route to host
2020-09-11 00:35:06.985751: [NET] peer(CHzf…1U30) - Removing all keys, since we haven't received a new one in 540 seconds
2020-09-11 00:35:06.987170: [NET] peer(YhQB…Lcm8) - Awaiting keypair
2020-09-11 00:35:06.994062: [NET] peer(CHzf…1U30) - Awaiting keypair
2020-09-11 00:35:12.160213: [NET] peer(CHzf…1U30) - Handshake did not complete after 5 seconds, retrying (try 2)
2020-09-11 00:35:12.160762: [NET] peer(CHzf…1U30) - Sending handshake initiation
2020-09-11 00:35:12.168432: [NET] peer(CHzf…1U30) - Failed to send handshake initiation write udp4 0.0.0.0:56035->redacted_peer_2:44455: sendto: no route to host
2020-09-11 00:35:12.232323: [NET] peer(YhQB…Lcm8) - Handshake did not complete after 5 seconds, retrying (try 2)
2020-09-11 00:35:12.232701: [NET] peer(YhQB…Lcm8) - Sending handshake initiation
[a few more]
2020-09-11 00:55:13.793554: [NET] peer(CHzf…1U30) - Failed to send handshake initiation write udp4 0.0.0.0:56035->redacted_peer_2:44455: sendto: no route to host
2020-09-11 00:55:13.823302: [NET] peer(YhQB…Lcm8) - Handshake did not complete after 5 seconds, retrying (try 19)
2020-09-11 00:55:13.823679: [NET] peer(YhQB…Lcm8) - Sending handshake initiation
2020-09-11 00:55:13.830352: [NET] peer(YhQB…Lcm8) - Failed to send handshake initiation write udp4 0.0.0.0:56035->redacted_peer_1:44455: sendto: no route to host
2020-09-11 00:55:18.961279: [NET] peer(CHzf…1U30) - Handshake did not complete after 5 seconds, retrying (try 20)
2020-09-11 00:55:18.961761: [NET] peer(CHzf…1U30) - Sending handshake initiation
2020-09-11 00:55:18.969481: [NET] peer(CHzf…1U30) - Failed to send handshake initiation write udp4 0.0.0.0:56035->redacted_peer_2:44455: sendto: no route to host
2020-09-11 00:55:19.013912: [NET] peer(YhQB…Lcm8) - Handshake did not complete after 5 seconds, retrying (try 20)
2020-09-11 00:55:19.014284: [NET] peer(YhQB…Lcm8) - Sending handshake initiation
2020-09-11 00:55:19.021406: [NET] peer(YhQB…Lcm8) - Failed to send handshake initiation write udp4 0.0.0.0:56035->redacted_peer_1:44455: sendto: no route to host
2020-09-11 00:55:24.071094: [NET] peer(YhQB…Lcm8) - Handshake did not complete after 20 attempts, giving up
2020-09-11 00:55:24.072152: [NET] peer(YhQB…Lcm8) - Sending handshake initiation
2020-09-11 00:55:24.079339: [NET] peer(YhQB…Lcm8) - Failed to send handshake initiation write udp4 0.0.0.0:56035->redacted_peer_1:44455: sendto: no route to host
2020-09-11 00:55:24.079992: [NET] peer(YhQB…Lcm8) - Awaiting keypair
2020-09-11 00:55:24.083542: [NET] peer(CHzf…1U30) - Sending handshake initiation
2020-09-11 00:55:24.088956: [NET] peer(CHzf…1U30) - Failed to send handshake initiation write udp4 0.0.0.0:56035->redacted_peer_2:44455: sendto: no route to host
2020-09-11 00:55:29.187685: [NET] peer(CHzf…1U30) - Handshake did not complete after 5 seconds, retrying (try 2)
2020-09-11 00:55:29.188175: [NET] peer(CHzf…1U30) - Sending handshake initiation
2020-09-11 00:55:29.195769: [NET] peer(CHzf…1U30) - Failed to send handshake initiation write udp4 0.0.0.0:56035->redacted_peer_2:44455: sendto: no route to host

Log for when I woke up in the morning:
2020-09-11 07:30:33.963812: [NET] Network change detected with unsatisfied route and interface order [utun2, en0]
2020-09-11 07:30:33.964685: [NET] DNS64: mapped redacted_peer_1 to itself.
2020-09-11 07:30:33.970653: [NET] DNS64: mapped redacted_peer_2 to itself.
2020-09-11 07:30:33.971174: [NET] DNS64: mapped wg_endpoint to itself.
2020-09-11 07:30:33.972489: [NET] DNS64: mapped wg_endpoint to itself.
2020-09-11 07:30:33.974145: [NET] UAPI: Transition to peer configuration
2020-09-11 07:30:33.976164: [NET] peer(YhQB…Lcm8) - UAPI: Updating endpoint
2020-09-11 07:30:33.978041: [NET] peer(CHzf…1U30) - UAPI: Updating endpoint
2020-09-11 07:30:33.978884: [NET] peer(gk0t…AyAc) - UAPI: Updating endpoint
2020-09-11 07:30:33.981027: [NET] peer(xmkD…IMho) - UAPI: Updating endpoint
2020-09-11 07:30:33.983182: [NET] Routine: receive incoming IPv4 - stopped
2020-09-11 07:30:33.985043: [NET] Routine: receive incoming IPv6 - stopped
2020-09-11 07:30:33.987112: [NET] peer(YhQB…Lcm8) - Sending handshake initiation
2020-09-11 07:30:33.989163: [NET] Routine: receive incoming IPv6 - started
2020-09-11 07:30:33.991036: [NET] Routine: receive incoming IPv4 - started
2020-09-11 07:30:33.993164: [NET] UDP bind has been updated
2020-09-11 07:30:34.522914: [NET] Network change detected with satisfied route and interface order [en0, utun2]
2020-09-11 07:30:34.543799: [NET] DNS64: mapped redacted_peer_1 to itself.
2020-09-11 07:30:34.546818: [NET] DNS64: mapped redacted_peer_2 to itself.
2020-09-11 07:30:34.547362: [NET] DNS64: mapped wg_endpoint to itself.
2020-09-11 07:30:34.548670: [NET] DNS64: mapped wg_endpoint to itself.
2020-09-11 07:30:34.550471: [NET] UAPI: Transition to peer configuration
2020-09-11 07:30:34.552311: [NET] peer(YhQB…Lcm8) - UAPI: Updating endpoint
2020-09-11 07:30:34.555128: [NET] peer(CHzf…1U30) - UAPI: Updating endpoint
2020-09-11 07:30:34.555231: [NET] peer(gk0t…AyAc) - UAPI: Updating endpoint
2020-09-11 07:30:34.557314: [NET] peer(xmkD…IMho) - UAPI: Updating endpoint
2020-09-11 07:30:34.559804: [NET] Routine: receive incoming IPv6 - stopped
2020-09-11 07:30:34.561226: [NET] Routine: receive incoming IPv4 - stopped
2020-09-11 07:30:34.563905: [NET] Routine: receive incoming IPv6 - started
2020-09-11 07:30:34.565256: [NET] Routine: receive incoming IPv4 - started
2020-09-11 07:30:34.567279: [NET] UDP bind has been updated
2020-09-11 07:30:37.309301: [APP] App version: 0.0.20200127 (17); Go backend version: 0.0.20200121
2020-09-11 07:30:39.013248: [NET] peer(YhQB…Lcm8) - Handshake did not complete after 5 seconds, retrying (try 2)
2020-09-11 07:30:39.013410: [NET] peer(YhQB…Lcm8) - Sending handshake initiation
2020-09-11 07:32:00.302471: [NET] peer(YhQB…Lcm8) - Removing all keys, since we haven't received a new one in 540 seconds
2020-09-11 07:32:00.303803: [NET] peer(YhQB…Lcm8) - Handshake did not complete after 5 seconds, retrying (try 3)
2020-09-11 07:32:00.304892: [NET] Received invalid response message from redacted_peer_1:44455
2020-09-11 07:32:00.305435: [NET] peer(YhQB…Lcm8) - Sending handshake initiation
2020-09-11 07:32:00.308002: [NET] peer(YhQB…Lcm8) - Awaiting keypair
2020-09-11 07:32:00.309891: [NET] peer(CHzf…1U30) - Handshake did not complete after 5 seconds, retrying (try 14)
2020-09-11 07:32:00.311963: [NET] peer(CHzf…1U30) - Sending handshake initiation
2020-09-11 07:32:00.372409: [NET] peer(YhQB…Lcm8) - Received handshake response
2020-09-11 07:32:00.372697: [NET] peer(YhQB…Lcm8) - Obtained awaited keypair
2020-09-11 07:32:00.529186: [NET] peer(CHzf…1U30) - Received handshake response

I normally try to toggle wireguard connection but it seems to hang so I try to turn off/on wifi but
it appears that after about 1:30 min it fixes itself - this time I just let it alone (I was actually looking at the logs)

Would there anything I can do on my end or is a code update in the App required?

Thank you.

In reply to:
---

Alexander Burke alex at alexburke.ca
Thu Aug 27 10:29:10 CEST 2020

I can’t speak for the Mac side, but I’ve been seeing the same on iOS for months now.

>/El 23 ag 2020, a les 20:34, Laura Smith <n5d9xq3ti233xiyif2vp at 
protonmail.ch <https://lists.zx2c4.com/mailman/listinfo/wireguard>> va 
escriure: />//>/Hi, />//>/These aren't show-stoppers per-se, but it would be nice to see them 
fixed and new clients pushed out via the App Store: />//>/(1) MacOS (10.15.6 but also observed on 10.15.5, not tested on anything 
older) />//>/- Start with WG client in an operational state />/- Disconnect network (e.g. if on WiFI, turn off the WiFi in the menu bar) />/- Sleep the machine />/- Wait- Wake the machine />/- Turn on Wifi />/- Note that WG client fails to re-establish connectivity (shows 
connected, but no traffic flows until you deactivate/reactivate WG) /