search

pufferffish / wireproxy

Wireguard client that exposes itself as a socks5 proxy
ISC License
4.1k stars 235 forks source link

Stops receiving handshake responses #84

Open Winand opened 10 months ago

Winand commented 10 months ago
System details 
Windows 10 Pro 19045.3031, wireproxy 1.0.6
config.ini:
  WGConfig = "C:\Users\<.....>\wireguard.conf"
  [Socks5]
  BindAddress = 127.0.0.1:25344
  [http]
  BindAddress = 127.0.0.1:25345

Wireproxy stops receiving handshake responses after some time of inactivity, so I have to restart it.

DEBUG: 2023/08/17 11:45:00 Routine: encryption worker 1 - started
DEBUG: 2023/08/17 11:45:00 Routine: encryption worker 2 - started
DEBUG: 2023/08/17 11:45:00 Routine: decryption worker 1 - started
DEBUG: 2023/08/17 11:45:00 Routine: handshake worker 1 - started
DEBUG: 2023/08/17 11:45:00 Routine: decryption worker 4 - started
DEBUG: 2023/08/17 11:45:00 Routine: decryption worker 2 - started
DEBUG: 2023/08/17 11:45:00 Routine: handshake worker 2 - started
DEBUG: 2023/08/17 11:45:00 Routine: encryption worker 3 - started
DEBUG: 2023/08/17 11:45:00 Routine: decryption worker 3 - started
DEBUG: 2023/08/17 11:45:00 Routine: handshake worker 3 - started
DEBUG: 2023/08/17 11:45:00 Routine: encryption worker 4 - started
DEBUG: 2023/08/17 11:45:00 Routine: handshake worker 5 - started
DEBUG: 2023/08/17 11:45:00 Routine: handshake worker 4 - started
DEBUG: 2023/08/17 11:45:00 Routine: encryption worker 5 - started
DEBUG: 2023/08/17 11:45:00 UAPI: Updating private key
DEBUG: 2023/08/17 11:45:00 Routine: event worker - started
DEBUG: 2023/08/17 11:45:00 Interface up requested
DEBUG: 2023/08/17 11:45:00 Routine: encryption worker 6 - started
DEBUG: 2023/08/17 11:45:00 Routine: decryption worker 5 - started
DEBUG: 2023/08/17 11:45:00 Routine: decryption worker 6 - started
DEBUG: 2023/08/17 11:45:00 Routine: handshake worker 6 - started
DEBUG: 2023/08/17 11:45:00 Routine: TUN reader - started
DEBUG: 2023/08/17 11:45:00 peer(scoh…CnU0) - UAPI: Created
DEBUG: 2023/08/17 11:45:00 peer(scoh…CnU0) - UAPI: Updating endpoint
DEBUG: 2023/08/17 11:45:00 peer(scoh…CnU0) - UAPI: Updating persistent keepalive interval
DEBUG: 2023/08/17 11:45:00 peer(scoh…CnU0) - UAPI: Updating preshared key
DEBUG: 2023/08/17 11:45:00 peer(scoh…CnU0) - UAPI: Adding allowedip
DEBUG: 2023/08/17 11:45:00 peer(scoh…CnU0) - Starting
DEBUG: 2023/08/17 11:45:00 peer(scoh…CnU0) - Routine: sequential receiver - started
DEBUG: 2023/08/17 11:45:00 peer(scoh…CnU0) - Routine: sequential sender - started
DEBUG: 2023/08/17 11:45:00 peer(scoh…CnU0) - Sending keepalive packet
DEBUG: 2023/08/17 11:45:00 peer(scoh…CnU0) - Sending handshake initiation
DEBUG: 2023/08/17 11:45:00 UDP bind has been updated
DEBUG: 2023/08/17 11:45:00 Routine: receive incoming v4 - started
DEBUG: 2023/08/17 11:45:00 Routine: receive incoming v6 - started
DEBUG: 2023/08/17 11:45:00 Interface state was Down, requested Up, now Up
DEBUG: 2023/08/17 11:45:00 peer(scoh…CnU0) - Received handshake response
DEBUG: 2023/08/17 11:45:25 peer(scoh…CnU0) - Sending keepalive packet
DEBUG: 2023/08/17 11:45:50 peer(scoh…CnU0) - Sending keepalive packet
DEBUG: 2023/08/17 11:46:15 peer(scoh…CnU0) - Sending keepalive packet
DEBUG: 2023/08/17 11:46:41 peer(scoh…CnU0) - Sending keepalive packet
DEBUG: 2023/08/17 11:47:06 peer(scoh…CnU0) - Sending keepalive packet
DEBUG: 2023/08/17 11:47:06 peer(scoh…CnU0) - Sending handshake initiation
DEBUG: 2023/08/17 11:47:11 peer(scoh…CnU0) - Handshake did not complete after 5 seconds, retrying (try 2)
DEBUG: 2023/08/17 11:47:11 peer(scoh…CnU0) - Sending handshake initiation
DEBUG: 2023/08/17 11:47:16 peer(scoh…CnU0) - Handshake did not complete after 5 seconds, retrying (try 3)
DEBUG: 2023/08/17 11:47:16 peer(scoh…CnU0) - Sending handshake initiation
DEBUG: 2023/08/17 11:47:21 peer(scoh…CnU0) - Handshake did not complete after 5 seconds, retrying (try 4)
DEBUG: 2023/08/17 11:47:21 peer(scoh…CnU0) - Sending handshake initiation
DEBUG: 2023/08/17 11:47:26 peer(scoh…CnU0) - Handshake did not complete after 5 seconds, retrying (try 5)
DEBUG: 2023/08/17 11:47:26 peer(scoh…CnU0) - Sending handshake initiation
DEBUG: 2023/08/17 11:47:32 peer(scoh…CnU0) - Handshake did not complete after 5 seconds, retrying (try 6)
DEBUG: 2023/08/17 11:47:32 peer(scoh…CnU0) - Sending handshake initiation
DEBUG: 2023/08/17 11:47:37 peer(scoh…CnU0) - Handshake did not complete after 5 seconds, retrying (try 7)
DEBUG: 2023/08/17 11:47:37 peer(scoh…CnU0) - Sending handshake initiation
DEBUG: 2023/08/17 11:47:42 peer(scoh…CnU0) - Handshake did not complete after 5 seconds, retrying (try 8)
DEBUG: 2023/08/17 11:47:42 peer(scoh…CnU0) - Sending handshake initiation
DEBUG: 2023/08/17 11:47:47 peer(scoh…CnU0) - Handshake did not complete after 5 seconds, retrying (try 9)
DEBUG: 2023/08/17 11:47:47 peer(scoh…CnU0) - Sending handshake initiation
DEBUG: 2023/08/17 11:47:53 peer(scoh…CnU0) - Handshake did not complete after 5 seconds, retrying (try 10)
DEBUG: 2023/08/17 11:47:53 peer(scoh…CnU0) - Sending handshake initiation
DEBUG: 2023/08/17 11:47:58 peer(scoh…CnU0) - Handshake did not complete after 5 seconds, retrying (try 11)
DEBUG: 2023/08/17 11:47:58 peer(scoh…CnU0) - Sending handshake initiation
DEBUG: 2023/08/17 11:48:03 peer(scoh…CnU0) - Handshake did not complete after 5 seconds, retrying (try 12)
DEBUG: 2023/08/17 11:48:03 peer(scoh…CnU0) - Sending handshake initiation
DEBUG: 2023/08/17 11:48:09 peer(scoh…CnU0) - Handshake did not complete after 5 seconds, retrying (try 13)
DEBUG: 2023/08/17 11:48:09 peer(scoh…CnU0) - Sending handshake initiation
DEBUG: 2023/08/17 11:48:14 peer(scoh…CnU0) - Handshake did not complete after 5 seconds, retrying (try 14)
DEBUG: 2023/08/17 11:48:14 peer(scoh…CnU0) - Sending handshake initiation
DEBUG: 2023/08/17 11:48:19 peer(scoh…CnU0) - Handshake did not complete after 5 seconds, retrying (try 15)
DEBUG: 2023/08/17 11:48:19 peer(scoh…CnU0) - Sending handshake initiation
DEBUG: 2023/08/17 11:48:24 peer(scoh…CnU0) - Handshake did not complete after 5 seconds, retrying (try 16)
DEBUG: 2023/08/17 11:48:24 peer(scoh…CnU0) - Sending handshake initiation
DEBUG: 2023/08/17 11:48:29 peer(scoh…CnU0) - Handshake did not complete after 5 seconds, retrying (try 17)
DEBUG: 2023/08/17 11:48:29 peer(scoh…CnU0) - Sending handshake initiation
DEBUG: 2023/08/17 11:48:34 peer(scoh…CnU0) - Handshake did not complete after 5 seconds, retrying (try 18)
DEBUG: 2023/08/17 11:48:34 peer(scoh…CnU0) - Sending handshake initiation
DEBUG: 2023/08/17 11:48:40 peer(scoh…CnU0) - Handshake did not complete after 5 seconds, retrying (try 19)
DEBUG: 2023/08/17 11:48:40 peer(scoh…CnU0) - Sending handshake initiation
DEBUG: 2023/08/17 11:48:45 peer(scoh…CnU0) - Handshake did not complete after 5 seconds, retrying (try 20)
DEBUG: 2023/08/17 11:48:45 peer(scoh…CnU0) - Sending handshake initiation
DEBUG: 2023/08/17 11:48:50 peer(scoh…CnU0) - Handshake did not complete after 20 attempts, giving up

If I make requests periodically everything is ok:

while (1) {Write-Host -NoNewLine "Request..."; curl -proxy http://127.0.0.1:25345 https://www.google.com > $null; echo "$(Get-Date)"; sleep 30}

But if the interval between requests is ≥90s it stops working.

kubrickfr commented 10 months ago

Try adding PersistentKeepalive = 25 to the Peer section of your wireguard configuration on the server?

Winand commented 10 months ago

Try adding PersistentKeepalive = 25 to the Peer section of your wireguard configuration on the server?

But from the log we can see that it keeps sending keepalive packets every 25s until handshake fails at 2023/08/17 11:47:11. I use Firezone ~0.7.26~ 0.7.33 server and it sets [peer] PersistentKeepalive = 25 in client configurations by default. Config looks like this:

[Interface]
PrivateKey = *******************
Address = ***.***.***.***/32
MTU = 1280
DNS = 1.1.1.1,1.0.0.1

[Peer]
PresharedKey = *******************
PublicKey = *******************
AllowedIPs = 0.0.0.0/0
Endpoint = *******************:51820
PersistentKeepalive = 25
kubrickfr commented 10 months ago

Yes, but that's from the client. It should not matter, I know, but NAT can be unpredictable, especially CGNAT.

Winand commented 10 months ago

Ok, I see now that it's a network issue. I've copied wireproxy app with my config to a different machine located in a different place and it works as expected.

wireguard configuration on the server

I don't know where to edit server config in Firezone (Docker deployment)🤔 Cannot find that in docs.

kubrickfr commented 10 months ago

That would be covered by the configuration file reference. Specifically default['firezone']['wireguard']['persistent_keepalive']