Open mnightingale opened 5 months ago
DFDC
commented
5 months ago Nothing much to add other than +1. Provider, docker log, and compose setup are pretty exact.
WARN [ip getter] too many requests sent for this month from https://ipinfo.io/: 429 429 Too Many Requests; not retrying.
fabiengagne
commented
4 months ago I have the same issue with airvpn. Here is my log of one of the occurences where healthcheck fails and then of course the port forwarding doesn't work anymore. If healthcheck doesn't fail, port forwarding works as expected.
========================================
========================================
=============== gluetun ================
========================================
=========== Made with ❤️ by ============
======= https://github.com/qdm12 =======
========================================
========================================
Running version latest built on 2024-02-21T17:01:05.694Z (commit a20695f)
🔧 Need help? https://github.com/qdm12/gluetun/discussions/new
🐛 Bug? https://github.com/qdm12/gluetun/issues/new
✨ New feature? https://github.com/qdm12/gluetun/issues/new
☕ Discussion? https://github.com/qdm12/gluetun/discussions/new
💻 Email? quentin.mcgaw@gmail.com
💰 Help me? https://www.paypal.me/qmcgaw https://github.com/sponsors/qdm12
2024-02-28T15:22:18-05:00 INFO [routing] default route found: interface eth0, gateway 192.168.80.1, assigned IP 192.168.80.2 and family v4
2024-02-28T15:22:18-05:00 INFO [routing] local ethernet link found: eth0
2024-02-28T15:22:18-05:00 INFO [routing] local ipnet found: 192.168.80.0/20
2024-02-28T15:22:19-05:00 INFO [firewall] enabling...
2024-02-28T15:22:19-05:00 INFO [firewall] enabled successfully
2024-02-28T15:22:21-05:00 INFO [storage] merging by most recent 17820 hardcoded servers and 17820 servers read from /gluetun/servers.json
2024-02-28T15:22:21-05:00 INFO Alpine version: 3.18.6
2024-02-28T15:22:21-05:00 INFO OpenVPN 2.5 version: 2.5.8
2024-02-28T15:22:21-05:00 INFO OpenVPN 2.6 version: 2.6.8
2024-02-28T15:22:21-05:00 INFO Unbound version: 1.19.1
2024-02-28T15:22:21-05:00 INFO IPtables version: v1.8.9
2024-02-28T15:22:21-05:00 INFO Settings summary:
├── VPN settings:
| ├── VPN provider settings:
| | ├── Name: airvpn
| | └── Server selection settings:
| | ├── VPN type: wireguard
| | ├── Hostnames: ca3.vpn.airdns.org, ca.vpn.airdns.org
| | └── Wireguard selection settings:
| └── Wireguard settings:
| ├── Private key: UDT...1U=
| ├── Pre-shared key: 1B/...lc=
| ├── Interface addresses:
| | └── 10.152.157.2/32
| ├── Allowed IPs:
| | ├── 0.0.0.0/0
| | └── ::/0
| └── Network interface: tun0
| └── MTU: 1320
├── DNS settings:
| ├── Keep existing nameserver(s): no
| ├── DNS server address to use: 127.0.0.1
| └── DNS over TLS settings:
| ├── Enabled: yes
| ├── Update period: every 24h0m0s
| ├── Unbound settings:
| | ├── Authoritative servers:
| | | └── cloudflare
| | ├── Caching: yes
| | ├── IPv6: no
| | ├── Verbosity level: 1
| | ├── Verbosity details level: 0
| | ├── Validation log level: 0
| | ├── System user: root
| | └── Allowed networks:
| | ├── 0.0.0.0/0
| | └── ::/0
| └── DNS filtering settings:
| ├── Block malicious: yes
| ├── Block ads: no
| ├── Block surveillance: no
| └── Blocked IP networks:
| ├── 127.0.0.1/8
| ├── 10.0.0.0/8
| ├── 172.16.0.0/12
| ├── 192.168.0.0/16
| ├── 169.254.0.0/16
| ├── ::1/128
| ├── fc00::/7
| ├── fe80::/10
| ├── ::ffff:127.0.0.1/104
| ├── ::ffff:10.0.0.0/104
| ├── ::ffff:169.254.0.0/112
| ├── ::ffff:172.16.0.0/108
| └── ::ffff:192.168.0.0/112
├── Firewall settings:
| ├── Enabled: yes
| └── VPN input ports:
| ├── 17486
| └── 45868
├── Log settings:
| └── Log level: INFO
├── Health settings:
| ├── Server listening address: 127.0.0.1:9999
| ├── Target address: cloudflare.com:443
| ├── Duration to wait after success: 5s
| ├── Read header timeout: 100ms
| ├── Read timeout: 500ms
| └── VPN wait durations:
| ├── Initial duration: 6s
| └── Additional duration: 5s
├── Shadowsocks server settings:
| └── Enabled: no
├── HTTP proxy settings:
| └── Enabled: no
├── Control server settings:
| ├── Listening address: :8000
| └── Logging: yes
├── OS Alpine settings:
| ├── Process UID: 1000
| ├── Process GID: 1000
| └── Timezone: america/montreal
├── Public IP settings:
| ├── Fetching: every 12h0m0s
| ├── IP file path: /tmp/gluetun/ip
| └── Public IP data API: ipinfo
├── Server data updater settings:
| ├── Update period: 24h0m0s
| ├── DNS address: 1.1.1.1:53
| ├── Minimum ratio: 0.8
| └── Providers to update: airvpn, cyberghost
└── Version settings:
└── Enabled: yes
2024-02-28T15:22:21-05:00 INFO [routing] default route found: interface eth0, gateway 192.168.80.1, assigned IP 192.168.80.2 and family v4
2024-02-28T15:22:21-05:00 INFO [routing] adding route for 0.0.0.0/0
2024-02-28T15:22:21-05:00 INFO [firewall] setting allowed subnets...
2024-02-28T15:22:21-05:00 INFO [routing] default route found: interface eth0, gateway 192.168.80.1, assigned IP 192.168.80.2 and family v4
2024-02-28T15:22:21-05:00 INFO [http server] http server listening on [::]:8000
2024-02-28T15:22:21-05:00 INFO [healthcheck] listening on 127.0.0.1:9999
2024-02-28T15:22:21-05:00 INFO [dns] using plaintext DNS at address 1.1.1.1
2024-02-28T15:22:21-05:00 INFO [firewall] allowing VPN connection...
2024-02-28T15:22:21-05:00 INFO [wireguard] Using available kernelspace implementation
2024-02-28T15:22:21-05:00 INFO [wireguard] Connecting to 184.75.221.194:1637
2024-02-28T15:22:21-05:00 INFO [wireguard] Wireguard setup is complete. Note Wireguard is a silent protocol and it may or may not work, without giving any error message. Typically i/o timeout errors indicate the Wireguard connection is not working.
2024-02-28T15:22:21-05:00 INFO [firewall] setting allowed input port 17486 through interface tun0...
2024-02-28T15:22:21-05:00 INFO [firewall] setting allowed input port 45868 through interface tun0...
2024-02-28T15:22:21-05:00 INFO [dns] downloading DNS over TLS cryptographic files
2024-02-28T15:22:22-05:00 INFO [dns] downloading hostnames and IP block lists
2024-02-28T15:22:22-05:00 INFO [healthcheck] healthy!
2024-02-28T15:22:38-05:00 INFO [healthcheck] program has been unhealthy for 6s: restarting VPN
2024-02-28T15:22:38-05:00 INFO [healthcheck] 👉 See https://github.com/qdm12/gluetun-wiki/blob/main/faq/healthcheck.md
2024-02-28T15:22:38-05:00 INFO [healthcheck] DO NOT OPEN AN ISSUE UNLESS YOU READ AND TRIED EACH POSSIBLE SOLUTION
2024-02-28T15:22:38-05:00 INFO [vpn] stopping
2024-02-28T15:22:38-05:00 INFO [firewall] removing allowed port 17486...
2024-02-28T15:22:39-05:00 INFO [firewall] removing allowed port 45868...
2024-02-28T15:22:39-05:00 ERROR [vpn] cannot get version information: Get "https://api.github.com/repos/qdm12/gluetun/commits": context canceled
2024-02-28T15:22:39-05:00 INFO [vpn] starting
2024-02-28T15:22:39-05:00 INFO [firewall] allowing VPN connection...
2024-02-28T15:22:39-05:00 INFO [wireguard] Using available kernelspace implementation
2024-02-28T15:22:39-05:00 INFO [wireguard] Connecting to 184.75.223.218:1637
2024-02-28T15:22:39-05:00 INFO [wireguard] Wireguard setup is complete. Note Wireguard is a silent protocol and it may or may not work, without giving any error message. Typically i/o timeout errors indicate the Wireguard connection is not working.
2024-02-28T15:22:39-05:00 INFO [firewall] setting allowed input port 17486 through interface tun0...
2024-02-28T15:22:39-05:00 INFO [firewall] setting allowed input port 45868 through interface tun0...
2024-02-28T15:22:43-05:00 INFO [dns] init module 0: validator
2024-02-28T15:22:43-05:00 INFO [dns] init module 1: iterator
2024-02-28T15:22:44-05:00 INFO [dns] start of service (unbound 1.19.1).
2024-02-28T15:22:44-05:00 INFO [dns] generate keytag query _ta-4a5c-4f66. NULL IN
2024-02-28T15:22:44-05:00 INFO [healthcheck] healthy!
2024-02-28T15:22:44-05:00 INFO [ip getter] Public IP address is 184.75.223.219 (Canada, Ontario, Toronto)
2024-02-28T15:22:44-05:00 INFO [ip getter] Public IP address is 184.75.223.219 (Canada, Ontario, Toronto)
2024-02-28T15:22:44-05:00 INFO [dns] ready
OfficialLambdax
commented
3 months ago The previous noted log is very similiar to my own. Whenever gluetun restarts itself because of any reason that makes it to, then some entries are shown twice in the log, just like above
in my case
... Container Started
2024-03-15T12:11:10Z INFO [firewall] setting allowed input port 12345 through interface tun0...
... Container goes unhealthy
2024-03-15T12:11:22Z INFO [healthcheck] program has been unhealthy for 6s: restarting VPN
... It seems to reset its previous settings
2024-03-15T12:11:22Z INFO [firewall] removing allowed port 12345...
... Connection was reestablished, reopening port
2024-03-15T12:11:22Z INFO [firewall] setting allowed input port 12345 through interface tun0...
... Now we see these duplicate entries in the log
2024-03-15T12:11:26Z INFO [dns] generate keytag query _ta-4a5c-4f66. NULL IN
2024-03-15T12:11:26Z INFO [dns] generate keytag query _ta-4a5c-4f66. NULL IN
...
2024-03-15T12:11:26Z INFO [ip getter] Public IP address is # (#)
2024-03-15T12:11:26Z INFO [ip getter] Public IP address is # (#)Makes me believe that the new port forwarding is applied twice or in a wrong manner. I cannot tell. But the duplicate entries only appear once the container tried to heal itself.
qdm12
commented
2 months ago I'm working on this; I believed this was fixed previously but apparently not!
qdm12
commented
1 month ago I've been trying to re-produce a failure to restart the port forwarding but it looks like it's working on my end.
What I've done is implement a "mock" provider with port forwarding feature, which logs what is up with port forwarding.
You can run it with image qmcgaw/gluetun:pr-2273 (produced from PR #2273) together with VPN_PORT_FORWARDING_PROVIDER=mock. For example I get:
2024-05-09T19:01:14Z INFO [wireguard] Wireguard setup is complete. Note Wireguard is a silent protocol and it may or may not work, without giving any error message. Typically i/o timeout errors indicate the Wireguard connection is not working.
2024-05-09T19:01:14Z INFO [port forwarding] starting
2024-05-09T19:01:14Z INFO [mock provider] port forward provider.go:L51
2024-05-09T19:01:14Z INFO [port forwarding] port forwarded is 12345
2024-05-09T19:01:14Z INFO [firewall] setting allowed input port 12345 through interface tun0...
2024-05-09T19:01:14Z INFO [port forwarding] writing port file /tmp/gluetun/forwarded_port
2024-05-09T19:01:14Z INFO [mock provider] keeping port forward start provider.go:L57
2024-05-09T19:01:14Z INFO [healthcheck] healthy!
2024-05-09T19:01:14Z INFO [ip getter] Public IP address is 185.209.196.252 (Germany, Hesse, Frankfurt am Main)
2024-05-09T19:01:24Z INFO [mock provider] keeping port forward ticked provider.go:L70
2024-05-09T19:01:34Z INFO [mock provider] keeping port forward ticked provider.go:L70I trigger the unhealthy state by running docker exec gluetun ip link set tun0 down which shuts down the VPN connection.
qdm12
commented
1 month ago some entries are shown twice in the log
The public IP address showing twice (or more) is fixed with 4218dba177674f4a9e8ac98f98fc5ee0da4f4ccc although I don't think it influences the port forwarding not re-triggering. [dns] generate keytag query _ta-4a5c-4f66. NULL IN is fine, this is coming from Unbound and nothing to fix here.
qdm12
commented
1 month ago Actually this may had influenced port forwarding, please pull and try the latest image to see if it's resolved (make sure it's built on or after 18 May 2024). I'll close this issue in 30 days if no one reports a problem again.
mnightingale
commented
1 month ago I've had far fewer problems recently, the only change I've made is regularly pulling the latest images and added an ipinfo.io api key.
I've pulled the latest and will so how it gets on, happy for you to close this if you think it is resolved.
Thanks for investigating it.
Is this urgent?
No
Host OS
Debian 12
CPU arch
x86_64
VPN service provider
ProtonVPN
What are you using to run the container
docker-compose
What is the version of Gluetun
Running version latest built on 2024-01-19T16:47:31.378Z (commit d8b9b2a)
What's the problem 🤔
Internet connection dropped, re-established but port forwarding wasn't setup.
I noticed a lot of similar events logged, but the cause seems to be if there is a failure in KeepPortForward it returns, so the port forward service stops hence it never tries to setup port forwarding again?
Maybe it should be able to retry after a delay or otherwise reset state and recover?
I restarted container and its working correctly again.
Thanks for looking!
Share your logs (at least 10 lines)
Share your configuration