Open perry-mitchell opened 1 year ago
RTNETLINK answers: File exists
is just because the route already exists. It's logged as ERROR because openvpn sends it to stderr for whatever reason. Linux route add command failed: external program exited with error status: 2
is just more details on the previous error.
Now the healthcheck might fail if the vpn server or vpn connection or cloudflare server don't work. Usually it's the vpn server misbehaving. So this works as expected, see https://github.com/qdm12/gluetun/wiki/Healthcheck
Now regarding port forwarding not working after a restart, I'll have a look tomorrow, maybe it's related to #1086
Usually it's the vpn server misbehaving
It's weird that whenever the healthcheck fails, simply restarting the container fixes it. Not sure how this might be on the VPN side (I'm sure Torguard is quite popular) if it comes back after a clean restart.
I'm changing the healthcheck target now to see if it's something to do with Cloudflare (though I sincerely doubt it is).
Changing to say google:443
nets results like so, after a while:
2022-11-11T10:26:45+02:00 INFO [healthcheck] unhealthy: cannot dial: dial tcp4: lookup github.com: i/o timeout
2022-11-11T10:26:47+02:00 INFO [healthcheck] healthy!
2022-11-11T10:34:06+02:00 INFO [healthcheck] unhealthy: cannot dial: dial tcp4 140.82.121.4:443: i/o timeout
2022-11-11T10:34:07+02:00 INFO [healthcheck] healthy!
No idea where Github came from :thinking:
It's weird that whenever the healthcheck fails, simply restarting the container fixes it.
I'm not 100% sure how port forwarding works with Torguard, is it by VPN server IP address or for all VPN servers?
I checked the firewall and rules are set correctly (although I just fixed 5aa39be973fe8864944b01ad869edfcf0dbab225 which should had pretty much zero impact anyway, except duplicating accept rules on every internal vpn restart). You can check yourself with docker exec gluetun iptables -nvL
which lists all the rules. Also #1086 is related to a problem with PIA-specific code I think, not really firewall.
One more thing you can try is to run with FIREWALL=off
but really this isn't viable and will leak data outside the VPN. But worth a try to see if the port stays valid.
I also made additional commits 554a6cdb92d0c05f9e42a1e01d09ec81f86a728d to add a link to the FAQ when it gets unhealthy, and 7421dcb45f9ead04e0d0a7761a9933b31b2224ed to explain what RTNETLINK answers: File exists
means and changed it from error to warning, since it's not really critical and the vpn will still work fine. Although it may be why port forwarding then breaks, something to keep in mind :thinking:
Changing to say google:443 nets results like so, after a while:
I tried setting HEALTH_TARGET_ADDRESS=google.com:443
and it works fine for me :thinking: Maybe the Unraid template is outdated for that variable (see #550)? github.com:443
was the previous default value before cloudflare.com:443
, but it's really no longer there in the entire codebase: https://github.com/qdm12/gluetun/search?q=github.com%3A443 and it was changed in https://github.com/qdm12/gluetun/commit/10a13bc8a7498028ed67f16a292c62aa3e3c1def
I don't see your full logs, are you sure it's running version v3.32.0 (logged at the top of the logs)?
is it by VPN server IP address or for all VPN servers
I think so yes - I have to connect to a dedicated endpoint as the forwarded ports I request are by the server address, not regional/global.
Maybe the Unraid template is outdated for that variable
This doesn't exist in the template, I had to add it manually.
are you sure it's running version v3.32.0
I don't see the full logs for some reason, they're cut off. Need to find out where they're stored :thinking:
Did you try with FIREWALL=off?
Also could you try the latest image instead of a tagged release image?
Also sorry if I'm answering with such delay, but job+life+popular open source drains a lot of time 😸
Did you try with FIREWALL=off?
I hadn't, but I've just switched it off now.
Also could you try the latest image instead of a tagged release image?
Thought I had specified the latest tag, but seems I didn't change it from the default that the Unraid template set (no tag) (I'm not sure what this does with docker to be honest).
I'll test with this for a day, the issue is usually reproducible within that time.
Also sorry if I'm answering with such delay, but job+life+popular open source drains a lot of time smile_cat
Don't be sorry, I know exactly what you mean.. :smile:
So with Firewall off, same issue: I have to forcibly restart the VPN container:
2022-11-24T10:32:05+02:00 INFO [healthcheck] healthy!
2022-11-24T10:32:22+02:00 INFO [openvpn] TCP connection established with [AF_INET]<redacted>:1912
2022-11-24T10:32:22+02:00 INFO [openvpn] TCP_CLIENT link local: (not bound)
2022-11-24T10:32:22+02:00 INFO [openvpn] TCP_CLIENT link remote: [AF_INET]<redacted>:1912
2022-11-24T10:32:28+02:00 WARN [openvpn] 'link-mtu' is used inconsistently, local='link-mtu 1583', remote='link-mtu 1571'
2022-11-24T10:32:28+02:00 WARN [openvpn] 'tun-mtu' is used inconsistently, local='tun-mtu 1532', remote='tun-mtu 1500'
2022-11-24T10:32:28+02:00 WARN [openvpn] 'cipher' is used inconsistently, local='cipher AES-256-GCM', remote='cipher AES-128-CBC'
2022-11-24T10:32:28+02:00 WARN [openvpn] 'auth' is used inconsistently, local='auth [null-digest]', remote='auth SHA256'
2022-11-24T10:32:28+02:00 WARN [openvpn] 'keysize' is used inconsistently, local='keysize 256', remote='keysize 128'
2022-11-24T10:32:28+02:00 INFO [openvpn] [server] Peer Connection Initiated with [AF_INET]<redacted>:1912
2022-11-24T10:32:29+02:00 INFO [openvpn] TUN/TAP device tun0 opened
2022-11-24T10:32:29+02:00 INFO [openvpn] /sbin/ip link set dev tun0 up mtu 1500
2022-11-24T10:32:29+02:00 INFO [openvpn] /sbin/ip addr add dev tun0 local 10.34.0.97 peer 10.34.0.98
2022-11-24T10:32:29+02:00 ERROR [openvpn] OpenVPN tried to add an IP route which already exists (RTNETLINK answers: File exists)
2022-11-24T10:32:29+02:00 WARN [openvpn] Previous error details: Linux route add command failed: external program exited with error status: 2
2022-11-24T10:32:29+02:00 INFO [openvpn] UID set to nonrootuser
2022-11-24T10:32:29+02:00 INFO [openvpn] Initialization Sequence Completed
2022-11-24T10:32:29+02:00 INFO [firewall] firewall disabled, only updating allowed ports internal state
2022-11-24T10:32:29+02:00 INFO [firewall] firewall disabled, only updating allowed ports internal state
2022-11-24T10:32:29+02:00 INFO [ip getter] Public IP address is <redacted> (Switzerland, Zurich, Zürich)
2022-11-24T10:58:53+02:00 INFO [healthcheck] unhealthy: cannot dial: dial tcp4: lookup github.com: i/o timeout(see https://github.com/qdm12/gluetun/wiki/Healthcheck)
2022-11-24T10:59:01+02:00 INFO [healthcheck] program has been unhealthy for 6s: restarting VPN
2022-11-24T10:59:01+02:00 INFO [vpn] stopping
2022-11-24T10:59:01+02:00 INFO [firewall] firewall disabled, only updating allowed ports internal list
2022-11-24T10:59:01+02:00 INFO [firewall] firewall disabled, only updating allowed ports internal list
2022-11-24T10:59:01+02:00 INFO [vpn] starting
2022-11-24T10:59:01+02:00 INFO [firewall] firewall disabled, only updating internal VPN connection
2022-11-24T10:59:01+02:00 INFO [openvpn] OpenVPN 2.4.12 x86_64-alpine-linux-musl [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [MH/PKTINFO] [AEAD] built on Mar 24 2022
2022-11-24T10:59:01+02:00 INFO [openvpn] library versions: OpenSSL 1.1.1s 1 Nov 2022, LZO 2.10
2022-11-24T10:59:01+02:00 WARN [openvpn] --ping should normally be used with --ping-restart or --ping-exit
2022-11-24T10:59:01+02:00 INFO [openvpn] TCP/UDP: Preserving recently used remote address: [AF_INET]<redacted>:1912
2022-11-24T10:59:01+02:00 INFO [openvpn] Attempting to establish TCP connection with [AF_INET]<redacted>:1912 [nonblock]
2022-11-24T10:59:04+02:00 INFO [healthcheck] healthy!
EDIT: It seems like the port forwarding doesn't work at all with the firewall off. When I re-enable it port forwarding works instantly again.
And it died again.. I enabled additional Firewall logs beforehand:
2022-11-24T11:18:46+02:00 INFO [healthcheck] healthy!
2022-11-24T11:18:47+02:00 INFO [dns over tls] downloading hostnames and IP block lists
2022-11-24T11:18:52+02:00 INFO [dns over tls] init module 0: validator
2022-11-24T11:18:52+02:00 INFO [dns over tls] init module 1: iterator
2022-11-24T11:18:52+02:00 INFO [dns over tls] start of service (unbound 1.15.0).
2022-11-24T11:18:52+02:00 INFO [dns over tls] generate keytag query _ta-4a5c-4f66. NULL IN
2022-11-24T11:18:52+02:00 INFO [dns over tls] generate keytag query _ta-4a5c-4f66. NULL IN
2022-11-24T11:18:53+02:00 INFO [dns over tls] ready
2022-11-24T11:18:53+02:00 INFO [ip getter] Public IP address is <redacted> (Switzerland, Zurich, Zürich)
2022-11-24T11:18:53+02:00 INFO [vpn] You are running on the bleeding edge of latest!
2022-11-24T11:23:26+02:00 INFO [healthcheck] unhealthy: cannot dial: dial tcp4: lookup github.com: i/o timeout(see https://github.com/qdm12/gluetun/wiki/Healthcheck)
2022-11-24T11:23:34+02:00 INFO [healthcheck] program has been unhealthy for 6s: restarting VPN
2022-11-24T11:23:34+02:00 INFO [vpn] stopping
2022-11-24T11:23:34+02:00 INFO [firewall] removing allowed port 54321...
2022-11-24T11:23:34+02:00 DEBUG [firewall] iptables --delete INPUT -i tun0 -p tcp --dport 54321 -j ACCEPT
2022-11-24T11:23:34+02:00 DEBUG [firewall] ip6tables --delete INPUT -i tun0 -p tcp --dport 54321 -j ACCEPT
2022-11-24T11:23:34+02:00 DEBUG [firewall] iptables --delete INPUT -i tun0 -p udp --dport 54321 -j ACCEPT
2022-11-24T11:23:34+02:00 DEBUG [firewall] ip6tables --delete INPUT -i tun0 -p udp --dport 54321 -j ACCEPT
2022-11-24T11:23:34+02:00 INFO [firewall] removing allowed port 51234...
2022-11-24T11:23:34+02:00 DEBUG [firewall] iptables --delete INPUT -i tun0 -p tcp --dport 51234 -j ACCEPT
2022-11-24T11:23:34+02:00 DEBUG [firewall] ip6tables --delete INPUT -i tun0 -p tcp --dport 51234 -j ACCEPT
2022-11-24T11:23:34+02:00 DEBUG [firewall] iptables --delete INPUT -i tun0 -p udp --dport 51234 -j ACCEPT
2022-11-24T11:23:34+02:00 DEBUG [firewall] ip6tables --delete INPUT -i tun0 -p udp --dport 51234 -j ACCEPT
2022-11-24T11:23:34+02:00 INFO [vpn] starting
2022-11-24T11:23:34+02:00 INFO [firewall] allowing VPN connection...
2022-11-24T11:23:34+02:00 INFO [openvpn] OpenVPN 2.4.12 x86_64-alpine-linux-musl [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [MH/PKTINFO] [AEAD] built on Mar 24 2022
2022-11-24T11:23:34+02:00 INFO [openvpn] library versions: OpenSSL 1.1.1s 1 Nov 2022, LZO 2.10
2022-11-24T11:23:34+02:00 WARN [openvpn] --ping should normally be used with --ping-restart or --ping-exit
2022-11-24T11:23:34+02:00 INFO [openvpn] TCP/UDP: Preserving recently used remote address: [AF_INET]<redacted>:1912
2022-11-24T11:23:34+02:00 INFO [openvpn] Attempting to establish TCP connection with [AF_INET]<redacted>:1912 [nonblock]
2022-11-24T11:23:45+02:00 INFO [healthcheck] program has been unhealthy for 11s: restarting VPN
2022-11-24T11:23:45+02:00 INFO [vpn] stopping
2022-11-24T11:23:45+02:00 INFO [firewall] removing allowed port 54321...
2022-11-24T11:23:45+02:00 INFO [firewall] removing allowed port 51234...
2022-11-24T11:23:45+02:00 INFO [vpn] starting
2022-11-24T11:23:45+02:00 INFO [firewall] allowing VPN connection...
2022-11-24T11:23:45+02:00 INFO [openvpn] OpenVPN 2.4.12 x86_64-alpine-linux-musl [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [MH/PKTINFO] [AEAD] built on Mar 24 2022
2022-11-24T11:23:45+02:00 INFO [openvpn] library versions: OpenSSL 1.1.1s 1 Nov 2022, LZO 2.10
2022-11-24T11:23:45+02:00 WARN [openvpn] --ping should normally be used with --ping-restart or --ping-exit
2022-11-24T11:23:45+02:00 INFO [openvpn] TCP/UDP: Preserving recently used remote address: [AF_INET]<redacted>:1912
2022-11-24T11:23:45+02:00 INFO [openvpn] Attempting to establish TCP connection with [AF_INET]<redacted>:1912 [nonblock]
2022-11-24T11:23:47+02:00 INFO [openvpn] TCP connection established with [AF_INET]<redacted>:1912
2022-11-24T11:23:47+02:00 INFO [openvpn] TCP_CLIENT link local: (not bound)
2022-11-24T11:23:47+02:00 INFO [openvpn] TCP_CLIENT link remote: [AF_INET]<redacted>:1912
2022-11-24T11:23:48+02:00 WARN [openvpn] 'link-mtu' is used inconsistently, local='link-mtu 1583', remote='link-mtu 1571'
2022-11-24T11:23:48+02:00 WARN [openvpn] 'tun-mtu' is used inconsistently, local='tun-mtu 1532', remote='tun-mtu 1500'
2022-11-24T11:23:48+02:00 WARN [openvpn] 'cipher' is used inconsistently, local='cipher AES-256-GCM', remote='cipher AES-128-CBC'
2022-11-24T11:23:48+02:00 WARN [openvpn] 'auth' is used inconsistently, local='auth [null-digest]', remote='auth SHA256'
2022-11-24T11:23:48+02:00 WARN [openvpn] 'keysize' is used inconsistently, local='keysize 256', remote='keysize 128'
2022-11-24T11:23:48+02:00 INFO [openvpn] [server] Peer Connection Initiated with [AF_INET]<redacted>:1912
2022-11-24T11:23:49+02:00 INFO [openvpn] TUN/TAP device tun0 opened
2022-11-24T11:23:49+02:00 INFO [openvpn] /sbin/ip link set dev tun0 up mtu 1500
2022-11-24T11:23:49+02:00 INFO [openvpn] /sbin/ip addr add dev tun0 local 10.34.0.97 peer 10.34.0.98
2022-11-24T11:23:49+02:00 ERROR [openvpn] OpenVPN tried to add an IP route which already exists (RTNETLINK answers: File exists)
2022-11-24T11:23:49+02:00 WARN [openvpn] Previous error details: Linux route add command failed: external program exited with error status: 2
2022-11-24T11:23:49+02:00 INFO [openvpn] UID set to nonrootuser
2022-11-24T11:23:49+02:00 INFO [openvpn] Initialization Sequence Completed
2022-11-24T11:23:49+02:00 INFO [firewall] setting allowed input port 54321 through interface tun0...
2022-11-24T11:23:49+02:00 DEBUG [firewall] iptables --append INPUT -i tun0 -p tcp --dport 54321 -j ACCEPT
2022-11-24T11:23:49+02:00 DEBUG [firewall] ip6tables --append INPUT -i tun0 -p tcp --dport 54321 -j ACCEPT
2022-11-24T11:23:49+02:00 DEBUG [firewall] iptables --append INPUT -i tun0 -p udp --dport 54321 -j ACCEPT
2022-11-24T11:23:49+02:00 DEBUG [firewall] ip6tables --append INPUT -i tun0 -p udp --dport 54321 -j ACCEPT
2022-11-24T11:23:49+02:00 INFO [firewall] setting allowed input port 51234 through interface tun0...
2022-11-24T11:23:49+02:00 DEBUG [firewall] iptables --append INPUT -i tun0 -p tcp --dport 51234 -j ACCEPT
2022-11-24T11:23:49+02:00 DEBUG [firewall] ip6tables --append INPUT -i tun0 -p tcp --dport 51234 -j ACCEPT
2022-11-24T11:23:49+02:00 DEBUG [firewall] iptables --append INPUT -i tun0 -p udp --dport 51234 -j ACCEPT
2022-11-24T11:23:49+02:00 DEBUG [firewall] ip6tables --append INPUT -i tun0 -p udp --dport 51234 -j ACCEPT
2022-11-24T11:23:50+02:00 INFO [healthcheck] healthy!
Still seeing tonnes of these errors, no matter what I try (OpenVPN 2.5 over 2.4, DOT on/off, blocking on/off, DNS @ google/cloudflare, healthcheck @ google/cloudflare):
2022-12-06T21:14:41+02:00 INFO [healthcheck] unhealthy: cannot dial: dial tcp4 140.82.121.4:443: i/o timeout(see https://github.com/qdm12/gluetun/wiki/Healthcheck)
2022-12-06T21:14:44+02:00 INFO [healthcheck] healthy!
2022-12-06T21:38:51+02:00 INFO [healthcheck] unhealthy: cannot dial: dial tcp4 140.82.121.4:443: i/o timeout(see https://github.com/qdm12/gluetun/wiki/Healthcheck)
2022-12-06T21:38:54+02:00 INFO [healthcheck] healthy!
2022-12-06T22:05:02+02:00 INFO [healthcheck] unhealthy: cannot dial: dial tcp4 140.82.121.4:443: i/o timeout(see https://github.com/qdm12/gluetun/wiki/Healthcheck)
2022-12-06T22:05:03+02:00 INFO [healthcheck] healthy!
2022-12-06T22:14:45+02:00 INFO [healthcheck] unhealthy: cannot dial: dial tcp4 140.82.121.4:443: i/o timeout(see https://github.com/qdm12/gluetun/wiki/Healthcheck)
2022-12-06T22:14:47+02:00 INFO [healthcheck] healthy!
2022-12-06T22:48:22+02:00 INFO [healthcheck] unhealthy: cannot dial: dial tcp4 140.82.121.3:443: i/o timeout(see https://github.com/qdm12/gluetun/wiki/Healthcheck)
2022-12-06T22:48:23+02:00 INFO [healthcheck] healthy!
2022-12-06T23:00:58+02:00 INFO [healthcheck] unhealthy: cannot dial: dial tcp4 140.82.121.3:443: i/o timeout(see https://github.com/qdm12/gluetun/wiki/Healthcheck)
2022-12-06T23:00:59+02:00 INFO [healthcheck] healthy!
So I've started using ncat
to check this within the container.. eg. ncat -l 54321
. While this works initially with OpenVPN, and I can access the port from outside, after the VPN restarts it dies instantly. I can no longer access the port remotely.
On a side note I tried Wireguard but I get no remote access at all there - I've filed a ticket with Torguard regarding that. But there's still something wrong here with OpenVPN I'm afraid.
EDIT: Is there something I can do to help with this? Would providing my credentials help with debugging this? For me it drops out almost instantly.. after some hour or so.
Is this still broken on the latest image now? There has been a lot of changes since then 🤔 Sorry for the mega delay, I've been swamped with issues on this project, and slowly catching up bit by bit.
Is this urgent?
Yes
Host OS
Unraid / Docker
CPU arch
x86_64
VPN service provider
TorGuard
What are you using to run the container
Other
What is the version of Gluetun
v3.32.0
What's the problem 🤔
It seems like some options passed in via the Unraid template don't work, or are ignored. The first being the cipher. I setAES-256-CBC
as the cipher and got the error mentioned in the title. Later, in the logs, I get this:After running fine for some time (with port forwarding working), the healthcheck fails with this error:
And later, these errors are shown:
Share your logs
Share your configuration