Handshake failed: Raspberry Pi 1 + OSX Client

[Davide Lupo]

Hi All,

I've compiled and setup Wireguard for my Raspberry Pi 1 from latest TAG
WireGuard-0.0.20190227.tar.xz
<https://git.zx2c4.com/WireGuard/snapshot/WireGuard-0.0.20190227.tar.xz>

I've also installed the iOS and OSX clients.

Initially (after a couple of minutes of trials) the iOS client successfully
connected to the Server and it worked for a while until I disconnected it.

I'm trying to connect with OSX but without success.
It connects to the Wireguard server but no host are reachable on the server
network.
I can't ping the Wireguard server.

Reading the logs it seems that the client is trying to redo the handshake
every 30 seconds c.a.

Can anyone help me?

Here a small log:

2019-03-18 15:27:40.893871: [APP] startActivation: Entering (tunnel: Home)
2019-03-18 15:27:40.895666: [APP] startActivation: Starting tunnel
2019-03-18 15:27:40.899432: [APP] startActivation: Success
2019-03-18 15:27:40.905189: [APP] Tunnel 'Home' connection status changed
to 'connecting'
2019-03-18 15:27:41.057518: [NET] App version: 0.0.20190207 (3); Go backend
version: 0.0.20181222
2019-03-18 15:27:41.057881: [NET] Starting tunnel from the app
2019-03-18 15:27:45.899794: [APP] Status update notification timeout for
tunnel 'Home'. Tunnel status is now 'connecting'.
2019-03-18 15:27:46.088950: [APP] Tunnel 'Home' connection status changed
to 'connected'
2019-03-18 15:27:46.081345: [NET] Tunnel interface is utun1
2019-03-18 15:27:46.082065: [NET] Attaching to interface
2019-03-18 15:27:46.082844: [NET] Routine: encryption worker - started
2019-03-18 15:27:46.082936: [NET] Routine: decryption worker - started
2019-03-18 15:27:46.083137: [NET] Routine: decryption worker - started
2019-03-18 15:27:46.083187: [NET] Routine: handshake worker - started
2019-03-18 15:27:46.083368: [NET] Routine: encryption worker - started
2019-03-18 15:27:46.083438: [NET] Routine: decryption worker - started
2019-03-18 15:27:46.083499: [NET] Routine: handshake worker - started
2019-03-18 15:27:46.083546: [NET] Routine: encryption worker - started
2019-03-18 15:27:46.083594: [NET] Routine: decryption worker - started
2019-03-18 15:27:46.083788: [NET] Routine: handshake worker - started
2019-03-18 15:27:46.083839: [NET] Routine: encryption worker - started
2019-03-18 15:27:46.084133: [NET] Routine: handshake worker - started
2019-03-18 15:27:46.084182: [NET] Routine: TUN reader - started
2019-03-18 15:27:46.084374: [NET] Routine: event worker - started
2019-03-18 15:27:46.084490: [NET] UAPI: Updating private key
2019-03-18 15:27:46.084667: [NET] UAPI: Removing all peers
2019-03-18 15:27:46.084722: [NET] UAPI: Transition to peer configuration
2019-03-18 15:27:46.084900: [NET] peer(Jn7u…NMyQ) - UAPI: Created
2019-03-18 15:27:46.084957: [NET] peer(Jn7u…NMyQ) - UAPI: Updating endpoint
2019-03-18 15:27:46.085208: [NET] peer(Jn7u…NMyQ) - UAPI: Updating
persistent keepalive interval
2019-03-18 15:27:46.085259: [NET] peer(Jn7u…NMyQ) - UAPI: Removing all
allowedips
2019-03-18 15:27:46.085360: [NET] peer(Jn7u…NMyQ) - UAPI: Adding allowedip
2019-03-18 15:27:46.085411: [NET] peer(Jn7u…NMyQ) - UAPI: Adding allowedip
2019-03-18 15:27:46.085773: [NET] Routine: receive incoming IPv4 - started
2019-03-18 15:27:46.085871: [NET] Routine: receive incoming IPv6 - started
2019-03-18 15:27:46.086048: [NET] UDP bind has been updated
2019-03-18 15:27:46.086112: [NET] peer(Jn7u…NMyQ) - Starting...
2019-03-18 15:27:46.086347: [NET] peer(Jn7u…NMyQ) - Routine: nonce worker -
started
2019-03-18 15:27:46.086442: [NET] peer(Jn7u…NMyQ) - Routine: sequential
receiver - started
2019-03-18 15:27:46.087540: [NET] peer(Jn7u…NMyQ) - Routine: sequential
sender - started
2019-03-18 15:27:46.087781: [NET] Device started
2019-03-18 15:27:46.090861: [NET] UAPI: Processing get operation
2019-03-18 15:27:47.090178: [NET] UAPI: Processing get operation
2019-03-18 15:27:48.091227: [NET] UAPI: Processing get operation
2019-03-18 15:27:49.091311: [NET] UAPI: Processing get operation
2019-03-18 15:27:50.900640: [APP] Status update notification timeout for
tunnel 'Home'. Tunnel status is now 'connected'.
2019-03-18 15:27:50.089938: [NET] UAPI: Processing get operation
2019-03-18 15:27:50.901547: [NET] UAPI: Processing get operation
2019-03-18 15:27:51.901880: [NET] UAPI: Processing get operation
2019-03-18 15:27:52.903340: [NET] UAPI: Processing get operation
2019-03-18 15:27:53.903403: [NET] UAPI: Processing get operation
2019-03-18 15:27:54.903083: [NET] UAPI: Processing get operation
2019-03-18 15:27:55.902612: [NET] UAPI: Processing get operation
2019-03-18 15:27:56.903235: [NET] UAPI: Processing get operation
2019-03-18 15:27:57.903151: [NET] UAPI: Processing get operation
2019-03-18 15:27:58.903223: [NET] UAPI: Processing get operation
2019-03-18 15:27:59.903015: [NET] UAPI: Processing get operation
2019-03-18 15:28:00.903116: [NET] UAPI: Processing get operation
2019-03-18 15:28:01.902682: [NET] UAPI: Processing get operation
2019-03-18 15:28:02.903294: [NET] UAPI: Processing get operation
2019-03-18 15:28:03.903295: [NET] UAPI: Processing get operation
2019-03-18 15:28:04.901842: [NET] UAPI: Processing get operation
2019-03-18 15:28:05.902565: [NET] UAPI: Processing get operation
2019-03-18 15:28:06.902002: [NET] UAPI: Processing get operation
2019-03-18 15:28:07.903479: [NET] UAPI: Processing get operation
2019-03-18 15:28:08.903427: [NET] UAPI: Processing get operation
2019-03-18 15:28:09.903452: [NET] UAPI: Processing get operation
2019-03-18 15:28:10.903482: [NET] UAPI: Processing get operation
2019-03-18 15:28:11.903483: [NET] UAPI: Processing get operation
2019-03-18 15:28:12.902855: [NET] UAPI: Processing get operation
2019-03-18 15:28:13.903404: [NET] UAPI: Processing get operation
2019-03-18 15:28:14.174687: [NET] peer(Jn7u…NMyQ) - Sending handshake
initiation
2019-03-18 15:28:14.175233: [NET] peer(Jn7u…NMyQ) - Awaiting keypair
2019-03-18 15:28:14.238603: [NET] peer(Jn7u…NMyQ) - Received handshake
response
2019-03-18 15:28:14.238827: [NET] peer(Jn7u…NMyQ) - Obtained awaited keypair
2019-03-18 15:28:14.903711: [NET] UAPI: Processing get operation
2019-03-18 15:28:15.903451: [NET] UAPI: Processing get operation
2019-03-18 15:28:16.903560: [NET] UAPI: Processing get operation
2019-03-18 15:28:17.902894: [NET] UAPI: Processing get operation
2019-03-18 15:28:18.903461: [NET] UAPI: Processing get operation
2019-03-18 15:28:19.903558: [NET] UAPI: Processing get operation
2019-03-18 15:28:20.902740: [NET] UAPI: Processing get operation
2019-03-18 15:28:21.903553: [NET] UAPI: Processing get operation
2019-03-18 15:28:22.903405: [NET] UAPI: Processing get operation
2019-03-18 15:28:23.902719: [NET] UAPI: Processing get operation
2019-03-18 15:28:24.903233: [NET] UAPI: Processing get operation
2019-03-18 15:28:25.903590: [NET] UAPI: Processing get operation
2019-03-18 15:28:26.903620: [NET] UAPI: Processing get operation
2019-03-18 15:28:27.903584: [NET] UAPI: Processing get operation
2019-03-18 15:28:28.903317: [NET] UAPI: Processing get operation
2019-03-18 15:28:29.242282: [NET] peer(Jn7u…NMyQ) - Retrying handshake
because we stopped hearing back after 15 seconds
2019-03-18 15:28:29.242595: [NET] peer(Jn7u…NMyQ) - Sending handshake
initiation
2019-03-18 15:28:29.304797: [NET] peer(Jn7u…NMyQ) - Received handshake
response
2019-03-18 15:28:29.305025: [NET] peer(Jn7u…NMyQ) - Sending keepalive packet
2019-03-18 15:28:29.903738: [NET] UAPI: Processing get operation
2019-03-18 15:28:30.903984: [NET] UAPI: Processing get operation
2019-03-18 15:28:31.903052: [NET] UAPI: Processing get operation
2019-03-18 15:28:32.903007: [NET] UAPI: Processing get operation
2019-03-18 15:28:33.903678: [NET] UAPI: Processing get operation
2019-03-18 15:28:34.903702: [NET] UAPI: Processing get operation
2019-03-18 15:28:35.902359: [NET] UAPI: Processing get operation
2019-03-18 15:28:36.903832: [NET] UAPI: Processing get operation
2019-03-18 15:28:37.903858: [NET] UAPI: Processing get operation
2019-03-18 15:28:38.903328: [NET] UAPI: Processing get operation
2019-03-18 15:28:39.903808: [NET] UAPI: Processing get operation
2019-03-18 15:28:40.902469: [NET] UAPI: Processing get operation
2019-03-18 15:28:41.903885: [NET] UAPI: Processing get operation
2019-03-18 15:28:42.903813: [NET] UAPI: Processing get operation
2019-03-18 15:28:43.904000: [NET] UAPI: Processing get operation
2019-03-18 15:28:44.530191: [NET] peer(Jn7u…NMyQ) - Retrying handshake
because we stopped hearing back after 15 seconds
2019-03-18 15:28:44.530393: [NET] peer(Jn7u…NMyQ) - Sending handshake
initiation
2019-03-18 15:28:44.638109: [NET] peer(Jn7u…NMyQ) - Received handshake
response
2019-03-18 15:28:44.638385: [NET] peer(Jn7u…NMyQ) - Sending keepalive packet
2019-03-18 15:28:44.904022: [NET] UAPI: Processing get operation
2019-03-18 15:28:45.903517: [NET] UAPI: Processing get operation
2019-03-18 15:28:46.902685: [NET] UAPI: Processing get operation
2019-03-18 15:28:47.903926: [NET] UAPI: Processing get operation
2019-03-18 15:28:48.904012: [NET] UAPI: Processing get operation
2019-03-18 15:28:49.903955: [NET] UAPI: Processing get operation
2019-03-18 15:28:50.903954: [NET] UAPI: Processing get operation
2019-03-18 15:28:51.903501: [NET] UAPI: Processing get operation
2019-03-18 15:28:52.904089: [NET] UAPI: Processing get operation
2019-03-18 15:28:53.903264: [NET] UAPI: Processing get operation
2019-03-18 15:28:54.903677: [NET] UAPI: Processing get operation
2019-03-18 15:28:55.904018: [NET] UAPI: Processing get operation
2019-03-18 15:28:56.904046: [NET] UAPI: Processing get operation
2019-03-18 15:28:57.903917: [NET] UAPI: Processing get operation
2019-03-18 15:28:58.904210: [NET] UAPI: Processing get operation
2019-03-18 15:28:59.904100: [NET] UAPI: Processing get operation
2019-03-18 15:29:00.903223: [NET] UAPI: Processing get operation
2019-03-18 15:29:01.904237: [NET] UAPI: Processing get operation
2019-03-18 15:29:02.904200: [NET] UAPI: Processing get operation
2019-03-18 15:29:03.903027: [NET] UAPI: Processing get operation
2019-03-18 15:29:04.904611: [NET] UAPI: Processing get operation
2019-03-18 15:29:05.904266: [NET] UAPI: Processing get operation
2019-03-18 15:29:06.904536: [NET] UAPI: Processing get operation
2019-03-18 15:29:07.904704: [NET] UAPI: Processing get operation
2019-03-18 15:29:08.904274: [NET] UAPI: Processing get operation
2019-03-18 15:29:09.904260: [NET] UAPI: Processing get operation
2019-03-18 15:29:10.904390: [NET] UAPI: Processing get operation
2019-03-18 15:29:11.904284: [NET] UAPI: Processing get operation
2019-03-18 15:29:12.576313: [NET] peer(Jn7u…NMyQ) - Retrying handshake
because we stopped hearing back after 15 seconds
2019-03-18 15:29:12.576571: [NET] peer(Jn7u…NMyQ) - Sending handshake
initiation
2019-03-18 15:29:12.641026: [NET] peer(Jn7u…NMyQ) - Received handshake
response
2019-03-18 15:29:12.641247: [NET] peer(Jn7u…NMyQ) - Sending keepalive packet
2019-03-18 15:29:12.903576: [NET] UAPI: Processing get operation
2019-03-18 15:29:13.904330: [NET] UAPI: Processing get operation
2019-03-18 15:29:14.904637: [NET] UAPI: Processing get operation
2019-03-18 15:29:15.904786: [NET] UAPI: Processing get operation
2019-03-18 15:29:16.904425: [NET] UAPI: Processing get operation
2019-03-18 15:29:17.904134: [NET] UAPI: Processing get operation
2019-03-18 15:29:18.903013: [NET] UAPI: Processing get operation
2019-03-18 15:29:19.904375: [NET] UAPI: Processing get operation
2019-03-18 15:29:20.904409: [NET] UAPI: Processing get operation
2019-03-18 15:29:21.903868: [NET] UAPI: Processing get operation
2019-03-18 15:29:22.904661: [NET] UAPI: Processing get operation
2019-03-18 15:29:23.904433: [NET] UAPI: Processing get operation
2019-03-18 15:29:24.904902: [NET] UAPI: Processing get operation
2019-03-18 15:29:25.904439: [NET] UAPI: Processing get operation
2019-03-18 15:29:26.904510: [NET] UAPI: Processing get operation
2019-03-18 15:29:27.904106: [NET] UAPI: Processing get operation
2019-03-18 15:29:28.904306: [NET] UAPI: Processing get operation
2019-03-18 15:29:29.408556: [NET] peer(Jn7u…NMyQ) - Received handshake
initiation
2019-03-18 15:29:29.408640: [NET] peer(Jn7u…NMyQ) - Sending handshake
response
2019-03-18 15:29:29.957942: [NET] UAPI: Processing get operation
2019-03-18 15:29:30.903840: [NET] UAPI: Processing get operation
2019-03-18 15:29:31.903158: [NET] UAPI: Processing get operation
2019-03-18 15:29:32.904597: [NET] UAPI: Processing get operation
2019-03-18 15:29:33.904647: [NET] UAPI: Processing get operation
2019-03-18 15:29:34.904590: [NET] UAPI: Processing get operation
2019-03-18 15:29:35.904163: [NET] UAPI: Processing get operation
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.zx2c4.com/pipermail/wireguard/attachments/20190318/3239ade7/attachment-0001.html>