qdm12 / gluetun

VPN client in a thin Docker container for multiple VPN providers, written in Go, and using OpenVPN or Wireguard, DNS over TLS, with a few proxy servers built-in.
https://hub.docker.com/r/qmcgaw/gluetun
MIT License
7.69k stars 359 forks source link

Bug: Port forwarding not always restoring after unhealthy VPN #1095

Open DcR-NL opened 2 years ago

DcR-NL commented 2 years ago

Is this urgent?

No

Host OS

Synology DSM 6.2.4

CPU arch

x86_64

VPN service provider

Private Internet Access

What are you using to run the container

docker-compose

What is the version of Gluetun

Running version latest built on 2022-07-24T03:13:44.061Z (commit 877617c)

What's the problem 🤔

Port file gets removed, including the allowed port in the firewall after detecting an unhealthy VPN and doesn't restore. Zero output with the [port forwarding] tag after the "[vpn] VPN gateway IP address" message.

The first times it restores fine, but the moment it stops renewing, a container restart is needed.

I've added logs from a good and bad situation.

If a discussion is needed; I've created a discussion (https://github.com/qdm12/gluetun/discussions/1086) a week ago.

Share your logs

BAD SITUATION:

2022-07-31T12:09:03+02:00 INFO [healthcheck] unhealthy: cannot dial: dial tcp4: lookup protonvpn.com on 127.0.0.1:53: read udp 127.0.0.1:48127->127.0.0.1:53: read: connection refused
2022-07-31T12:09:16+02:00 INFO [healthcheck] program has been unhealthy for 13s: restarting VPN
2022-07-31T12:09:16+02:00 INFO [vpn] stopping
2022-07-31T12:09:16+02:00 INFO [port forwarding] stopping
2022-07-31T12:09:16+02:00 INFO [port forwarding] removing port file /gluetun/forwarded_port
2022-07-31T12:09:16+02:00 INFO [firewall] removing allowed port 36259...
2022-07-31T12:09:16+02:00 INFO [vpn] starting
2022-07-31T12:09:17+02:00 INFO [firewall] allowing VPN connection...
2022-07-31T12:09:18+02:00 INFO [openvpn] OpenVPN 2.5.6 x86_64-alpine-linux-musl [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [MH/PKTINFO] [AEAD] built on Apr 17 2022
*REMOVED OPENVPN LOG OUTPUT*
2022-07-31T12:09:18+02:00 INFO [openvpn] Initialization Sequence Completed
2022-07-31T12:09:22+02:00 INFO [dns over tls] init module 0: validator
2022-07-31T12:09:22+02:00 INFO [dns over tls] init module 1: iterator
2022-07-31T12:09:22+02:00 INFO [dns over tls] start of service (unbound 1.15.0).
2022-07-31T12:09:22+02:00 INFO [dns over tls] generate keytag query _ta-4a5c-4f66. NULL IN
2022-07-31T12:09:22+02:00 INFO [dns over tls] generate keytag query _ta-4a5c-4f66. NULL IN
2022-07-31T12:09:23+02:00 INFO [healthcheck] healthy!
2022-07-31T12:09:23+02:00 INFO [dns over tls] ready
2022-07-31T12:09:23+02:00 INFO [vpn] VPN gateway IP address: *REMOVED*
2022-07-31T12:09:24+02:00 INFO [ip getter] Public IP address is *REMOVED* (Switzerland, Zurich, Zürich)
2022-07-31T12:16:34+02:00 INFO [healthcheck] unhealthy: cannot dial: dial tcp4 185.159.159.140:443: i/o timeout
2022-07-31T12:16:35+02:00 INFO [healthcheck] healthy!
2022-07-31T15:23:23+02:00 INFO [dns over tls] generate keytag query _ta-4a5c-4f66. NULL IN
2022-07-31T18:31:09+02:00 INFO [dns over tls] generate keytag query _ta-4a5c-4f66. NULL IN

GOOD SITUATION (earlier in the same run):

2022-07-30T12:10:15+02:00 INFO [healthcheck] unhealthy: cannot dial: dial tcp4: lookup protonvpn.com on 127.0.0.1:53: read udp 127.0.0.1:33092->127.0.0.1:53: read: connection refused
2022-07-30T12:10:28+02:00 INFO [healthcheck] program has been unhealthy for 13s: restarting VPN
2022-07-30T12:10:28+02:00 INFO [vpn] stopping
2022-07-30T12:10:28+02:00 INFO [port forwarding] stopping
2022-07-30T12:10:28+02:00 INFO [port forwarding] removing port file /gluetun/forwarded_port
2022-07-30T12:10:28+02:00 INFO [firewall] removing allowed port 36259...
2022-07-30T12:10:28+02:00 INFO [vpn] starting
2022-07-30T12:10:28+02:00 INFO [firewall] allowing VPN connection...
2022-07-30T12:10:29+02:00 INFO [openvpn] OpenVPN 2.5.6 x86_64-alpine-linux-musl [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [MH/PKTINFO] [AEAD] built on Apr 17 2022
*REMOVED OPENVPN LOG OUTPUT*
2022-07-30T12:10:29+02:00 INFO [openvpn] Initialization Sequence Completed
2022-07-30T12:10:29+02:00 INFO [vpn] VPN gateway IP address: *REMOVED*
2022-07-30T12:10:29+02:00 INFO [port forwarding] starting
2022-07-30T12:10:29+02:00 INFO [port forwarding] Found saved forwarded port data for port 36259
2022-07-30T12:10:29+02:00 INFO [port forwarding] Port forwarded data expires in 41 days
2022-07-30T12:10:29+02:00 INFO [port forwarding] port forwarded is 36259
2022-07-30T12:10:29+02:00 INFO [firewall] setting allowed input port 36259 through interface tun0...
2022-07-30T12:10:29+02:00 INFO [port forwarding] writing port file /gluetun/forwarded_port
2022-07-30T12:10:30+02:00 INFO [dns over tls] init module 0: validator
2022-07-30T12:10:30+02:00 INFO [dns over tls] init module 1: iterator
2022-07-30T12:10:30+02:00 INFO [dns over tls] start of service (unbound 1.15.0).
2022-07-30T12:10:30+02:00 INFO [dns over tls] generate keytag query _ta-4a5c-4f66. NULL IN
2022-07-30T12:10:30+02:00 INFO [dns over tls] generate keytag query _ta-4a5c-4f66. NULL IN
2022-07-30T12:10:30+02:00 INFO [ip getter] Public IP address is *REMOVED* (Netherlands, North Holland, Amsterdam)
2022-07-30T12:10:30+02:00 INFO [healthcheck] healthy!
2022-07-30T12:10:31+02:00 INFO [dns over tls] ready

Share your configuration

services:
 gluetun:
    image: qmcgaw/gluetun:latest
    container_name: gluetun
    cap_add:
      - NET_ADMIN
    networks:
      - pia
    ports:
      - 8888:8888/tcp
      - 8112:8112/tcp
      - 58846:58846/tcp
    volumes:
      - ${VOLUME_GLUETUN_MAIN}:/gluetun
      - ${VOLUME_BASE}/gluetun/iptables:/iptables
    environment:
      - TZ=${TZ}
      - PUID=${PUID}
      - PGID=${PGID}
      - VPN_SERVICE_PROVIDER=pia
      - OPENVPN_VERBOSITY=3
      - OPENVPN_USER=${PIA_U}
      - OPENVPN_PASSWORD=${PIA_P}
      - SERVER_REGIONS=Switzerland,Netherlands
      - PRIVATE_INTERNET_ACCESS_OPENVPN_ENCRYPTION_PRESET=strong
      - PRIVATE_INTERNET_ACCESS_VPN_PORT_FORWARDING=on
      - PRIVATE_INTERNET_ACCESS_VPN_PORT_FORWARDING_STATUS_FILE=/gluetun/forwarded_port
      - HEALTH_TARGET_ADDRESS=protonvpn.com:443
      - HEALTH_VPN_DURATION_INITIAL=13s
      - HEALTH_VPN_DURATION_ADDITION=5s
      - FIREWALL=on
      - FIREWALL_OUTBOUND_SUBNETS=172.16.16.0/24
      - DOT=on
      - DOT_PROVIDERS=cloudflare
      - DOT_VERBOSITY=1
      - DOT_VERBOSITY_DETAILS=0
      - DOT_IPV6=off
      - BLOCK_MALICIOUS=on
      - BLOCK_SURVEILLANCE=on
      - BLOCK_ADS=on
      - DNS_UPDATE_PERIOD=24h
      - HTTPPROXY=on
      - HTTPPROXY_LOG=off
      - HTTPPROXY_STEALTH=on
      - SHADOWSOCKS=off
      - SHADOWSOCKS_LOG=on
    security_opt:
      - no-new-privileges:true
DcR-NL commented 2 years ago

Closing (for now). Has been running fine for at least a month.

ghost commented 2 years ago

This actually happens to me as well, but it never restores after VPN restart.

At the start of the container it's fine, even if the port was saved before:

2022-10-16T12:43:18Z INFO [firewall] allowing VPN connection...
2022-10-16T12:43:18Z INFO [openvpn] OpenVPN 2.5.6 aarch64-alpine-linux-musl [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [MH/PKTINFO] [AEAD] built on Apr 17 2022
2022-10-16T12:43:18Z INFO [openvpn] library versions: OpenSSL 1.1.1q  5 Jul 2022, LZO 2.10
2022-10-16T12:43:18Z INFO [openvpn] CRL: loaded 1 CRLs from file -----BEGIN X509 CRL-----
2022-10-16T12:43:18Z INFO [openvpn] *REDACTED*
2022-10-16T12:43:18Z INFO [openvpn] -----END X509 CRL-----
2022-10-16T12:43:18Z INFO [openvpn] TCP/UDP: Preserving recently used remote address: [AF_INET]191.96.168.252:1197
2022-10-16T12:43:18Z INFO [openvpn] UDP link local: (not bound)
2022-10-16T12:43:18Z INFO [openvpn] UDP link remote: [AF_INET]*REDACTED*
2022-10-16T12:43:18Z INFO [openvpn] [amsterdam433] Peer Connection Initiated with [AF_INET]*REDACTED*
2022-10-16T12:43:18Z INFO [openvpn] TUN/TAP device tun0 opened
2022-10-16T12:43:18Z INFO [openvpn] /sbin/ip link set dev tun0 up mtu 1500
2022-10-16T12:43:18Z INFO [openvpn] /sbin/ip link set dev tun0 up
2022-10-16T12:43:18Z INFO [openvpn] /sbin/ip addr add dev tun0 10.42.110.182/24
2022-10-16T12:43:18Z INFO [openvpn] UID set to nonrootuser
2022-10-16T12:43:18Z INFO [openvpn] Initialization Sequence Completed
2022-10-16T12:43:18Z INFO [ip getter] Public IP address is *REDACTED*
2022-10-16T12:43:18Z INFO [vpn] You are running on the bleeding edge of latest!
2022-10-16T12:43:18Z INFO [vpn] VPN gateway IP address: *REDACTED*
2022-10-16T12:43:19Z INFO [port forwarding] Found saved forwarded port data for port 49747
2022-10-16T12:43:19Z INFO [port forwarding] Port forwarded data expires in 52 days
2022-10-16T12:43:19Z INFO [healthcheck] healthy!
2022-10-16T12:43:19Z INFO [port forwarding] port forwarded is 49747
2022-10-16T12:43:19Z INFO [firewall] setting allowed input port 49747 through interface tun0...
2022-10-16T12:43:19Z INFO [port forwarding] writing port file /gluetun/forwarded_port

But then inevitably this happens:

2022-10-16T21:39:12Z INFO [healthcheck] program has been unhealthy for 13s: restarting VPN
2022-10-16T21:39:17Z INFO [vpn] stopping
2022-10-16T21:39:17Z INFO [port forwarding] stopping
2022-10-16T21:39:19Z INFO [port forwarding] removing port file /gluetun/forwarded_port
2022-10-16T21:39:23Z INFO [vpn] starting
2022-10-16T21:39:24Z INFO [firewall] removing allowed port 49747...
2022-10-16T21:40:09Z INFO [firewall] allowing VPN connection...
2022-10-16T21:40:25Z INFO [openvpn] OpenVPN 2.5.6 aarch64-alpine-linux-musl [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [MH/PKTINFO] [AEAD] built on Apr 17 2022
2022-10-16T21:40:26Z INFO [openvpn] library versions: OpenSSL 1.1.1q  5 Jul 2022, LZO 2.10
2022-10-16T21:40:26Z INFO [openvpn] CRL: loaded 1 CRLs from file -----BEGIN X509 CRL-----
2022-10-16T21:40:27Z INFO [openvpn] *REDACTED*
2022-10-16T21:40:27Z INFO [openvpn] -----END X509 CRL-----
2022-10-16T21:40:27Z INFO [openvpn] TCP/UDP: Preserving recently used remote address: [AF_INET]*REDACTED*
2022-10-16T21:40:27Z INFO [openvpn] UDP link local: (not bound)
2022-10-16T21:40:27Z INFO [openvpn] UDP link remote: [AF_INET]*REDACTED*
2022-10-16T21:40:27Z INFO [openvpn] [amsterdam433] Peer Connection Initiated with [AF_INET]*REDACTED*
2022-10-16T21:40:27Z INFO [openvpn] TUN/TAP device tun0 opened
2022-10-16T21:40:27Z INFO [openvpn] /sbin/ip link set dev tun0 up mtu 1500
2022-10-16T21:40:29Z INFO [openvpn] /sbin/ip link set dev tun0 up
2022-10-16T21:40:29Z INFO [openvpn] /sbin/ip addr add dev tun0 *REDACTED*
2022-10-16T21:40:29Z INFO [openvpn] UID set to nonrootuser
2022-10-16T21:40:29Z INFO [openvpn] Initialization Sequence Completed
2022-10-16T21:40:32Z INFO [healthcheck] healthy!
2022-10-16T21:40:33Z INFO [vpn] VPN gateway IP address: *REDACTED*
2022-10-16T21:40:36Z INFO [ip getter] Public IP address is *REDACTED*

Nothing about port forwarding after reconnect.

Raspberry Pi 4B on Raspbian (Debian) Buster latest, arm64 VPN Provider: Private Internet Access Using docker-compose Running version latest built on 2022-10-02T09:36:14.095Z (commit cb80457)

docker-compose.yml:

version: "3.7"
services:
  pia:
    image: qmcgaw/gluetun:latest
    container_name: pia
    cap_add:
      - NET_ADMIN
    devices:
      - /dev/net/tun:/dev/net/tun
    ports:
      - 8888:8888/tcp # HTTP proxy
      - 8001:8000/tcp # Gluetun API
      - 8005:8005
      - 3001:3001
    volumes:
      - ${PATH_CONFIG}/gluetun:/config
      - ${PATH_CONFIG}/gluetun/tmp:/gluetun
    environment:
      - TZ=${TZ:-Etc/UTC}
      - VPN_SERVICE_PROVIDER=private internet access
      - SERVER_REGIONS=${PIA_REGION}
      - OPENVPN_USER=${PIA_USER}
      - OPENVPN_PASSWORD=${PIA_PASS}
      - PRIVATE_INTERNET_ACCESS_OPENVPN_ENCRYPTION_PRESET=strong
      - PRIVATE_INTERNET_ACCESS_VPN_PORT_FORWARDING=on
      - PRIVATE_INTERNET_ACCESS_VPN_PORT_FORWARDING_STATUS_FILE=/gluetun/forwarded_port
      - FIREWALL=on
      - LOG_LEVEL=info
      - HEALTH_SERVER_ADDRESS=127.0.0.1:9999
      - HEALTH_TARGET_ADDRESS=protonvpn.com:443
      - HEALTH_VPN_DURATION_INITIAL=13s
      - HEALTH_VPN_DURATION_ADDITION=30s
      - DOT=off
      - BLOCK_MALICIOUS=on
      - BLOCK_SURVEILLANCE=off
      - BLOCK_ADS=off
      - DNS_UPDATE_PERIOD=24h
      - DNS_ADDRESS=127.0.0.1
      - DNS_KEEP_NAMESERVER=off
      - HTTP_CONTROL_SERVER_ADDRESS=:8000
      - UPDATER_VPN_SERVICE_PROVIDERS=private internet access
      - PUBLICIP_FILE=/gluetun/ip
      - PUBLICIP_PERIOD=12h
      - VERSION_INFORMATION=on
      - HTTPPROXY=on
      - HTTPPROXY_LOG=off
      - HTTPPROXY_STEALTH=on
    extra_hosts:
      - ${HOST}
qdm12 commented 1 year ago

@manz4rk see + subscribe to #1086

DcR-NL commented 1 year ago

Reopening, because it's still an issue for me. See https://github.com/qdm12/gluetun/discussions/1086#discussioncomment-4832378