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
6.77k stars 333 forks source link

Bug: Container Crashes Periodically within IP Getter #191

Closed raph521 closed 3 years ago

raph521 commented 3 years ago

TLDR: Container crashes periodically every few hours, always in "ip getter"

  1. Is this urgent?

    • [ ] Yes
    • [x] No
  2. What VPN service provider are you using?

    • [x] PIA
    • [ ] Mullvad
    • [ ] Windscribe
    • [ ] Surfshark
    • [ ] Cyberghost
  3. What's the version of the program?

    See the line at the top of your logs

    Running version latest built on 2020-07-11T23:52:34Z (commit 8b096af)

  4. What are you using to run the container?

    • [ ] Docker run
    • [x] Docker Compose
    • [ ] Kubernetes
    • [ ] Docker stack
    • [ ] Docker swarm
    • [ ] Podman
    • [ ] Other:
  5. Extra information

Logs:

=========================================,
================ Gluetun ================,
=========================================,
==== A mix of OpenVPN, DNS over TLS, ====,
======= Shadowsocks and Tinyproxy =======,
========= all glued up with Go ==========,
=========================================,
=========== For tunneling to ============,
======== your favorite VPN server =======,
=========================================,
=== Made with ❤️  by github.com/qdm12 ====,
=========================================,
,
Running version latest built on 2020-07-11T23:52:34Z (commit 8b096af),
,
,
🔧  Need help? https://github.com/qdm12/private-internet-access-docker/issues/new,
💻  Email? quentin.mcgaw@gmail.com,
☕  Slack? Join from the Slack button on Github,
💸  Help me? https://github.com/sponsors/qdm12,
2020-07-11T21:42:52.059-0400    INFO    OpenVPN version: 2.4.9,
2020-07-11T21:42:52.094-0400    INFO    Unbound version: 1.10.1,
2020-07-11T21:42:52.105-0400    INFO    IPtables version: v1.8.4,
2020-07-11T21:42:52.153-0400    INFO    TinyProxy version: 1.10.0,
2020-07-11T21:42:52.194-0400    INFO    ShadowSocks version: 3.3.4,
2020-07-11T21:42:52.202-0400    INFO    Settings summary below:,
OpenVPN settings:,
|--User: [redacted],
|--Password: [redacted],
|--Verbosity level: 1,
|--Run as root: no,
|--Private Internet Access settings:,
 |--Network protocol: udp,
 |--Region: ca montreal,
 |--Encryption preset: normal,
 |--Port forwarding: on, saved in /SOME_DIR/SOME_FILE,
System settings:,
|--User ID: 1000,
|--Group ID: 1000,
|--Timezone: XXXXXX,
|--IP Status filepath: /ip,
DNS over TLS settings:,
 |--DNS over TLS provider:,
  |--cloudflare,
 |--Caching: enabled,
 |--Block malicious: enabled,
 |--Block surveillance: disabled,
 |--Block ads: disabled,
 |--Allowed hostnames:,
  |--,
 |--Private addresses:,
  |--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:0:0/96,
 |--Verbosity level: 1/5,
 |--Verbosity details level: 0/4,
 |--Validation log level: 0/2,
 |--IPv6 resolution: disabled,
 |--Update: every 24h0m0s,
 |--Keep nameserver (disabled blocking): no,
Firewall settings:,
 |--Allowed subnets: 192.168.29.0/24,
TinyProxy settings:,
Port: 8888,
 |--Authentication: enabled,
 |--Log level: critical,
ShadowSocks settings: disabled,
,
2020-07-11T21:42:52.205-0400    INFO    openvpn configurator: checking for device /dev/net/tun,
2020-07-11T21:42:52.206-0400    WARN    TUN device is not available: open /dev/net/tun: no such file or directory,
2020-07-11T21:42:52.206-0400    INFO    openvpn configurator: creating /dev/net/tun,
2020-07-11T21:42:52.206-0400    INFO    firewall: enabling...,
2020-07-11T21:42:52.206-0400    INFO    routing: detecting default network route,
2020-07-11T21:42:52.206-0400    INFO    Launching standard output merger,
2020-07-11T21:42:52.207-0400    INFO    routing: default route found: interface eth0, gateway 192.168.170.1, subnet 192.168.170.0/24,
1,
2020-07-11T21:42:52.255-0400    INFO    firewall: enabled successfully,
2020-07-11T21:42:52.256-0400    INFO    http server: listening on 0.0.0.0:8000,
2020-07-11T21:42:52.256-0400    INFO    tinyproxy configurator: generating tinyproxy configuration file,
2020-07-11T21:42:52.275-0400    INFO    dns over tls: falling back on plaintext DNS at address 1.1.1.1,
2020-07-11T21:42:52.275-0400    INFO    dns configurator: using DNS address 1.1.1.1 internally,
2020-07-11T21:42:52.275-0400    INFO    dns configurator: using DNS address 1.1.1.1 system wide,
2020-07-11T21:42:52.280-0400    INFO    firewall: setting allowed port 8888 through firewall...,
2020-07-11T21:42:52.283-0400    INFO    openvpn configurator: writing auth file /etc/openvpn/auth.conf,
2020-07-11T21:42:52.289-0400    INFO    tinyproxy configurator: starting tinyproxy server,
2020-07-11T21:42:52.289-0400    INFO    firewall: setting VPN connections through firewall...,
2020-07-11T21:42:52.289-0400    INFO    routing: detecting default network route,
2020-07-11T21:42:52.291-0400    INFO    routing: default route found: interface eth0, gateway 192.168.170.1, subnet 192.168.170.0/24,
2020-07-11T21:42:52.298-0400    INFO    openvpn configurator: starting openvpn,
2020-07-11T21:42:52.310-0400    INFO    openvpn: OpenVPN 2.4.9 armv7-alpine-linux-musleabihf [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [MH/PKTINFO] [AEAD] built on Apr 20 2020,
2020-07-11T21:42:52.311-0400    INFO    openvpn: library versions: OpenSSL 1.1.1g  21 Apr 2020, LZO 2.10,
2020-07-11T21:42:52.313-0400    INFO    openvpn: WARNING: you are using user/group/chroot/setcon without persist-tun -- this may cause restarts to fail,
2020-07-11T21:42:52.326-0400    INFO    openvpn: CRL: loaded 1 CRLs from file [[INLINE]],
2020-07-11T21:42:52.328-0400    INFO    openvpn: TCP/UDP: Preserving recently used remote address: [AF_INET]199.229.249.142:1198,
2020-07-11T21:42:52.329-0400    INFO    openvpn: UDP link local: (not bound),
2020-07-11T21:42:52.329-0400    INFO    openvpn: UDP link remote: [AF_INET]199.229.249.142:1198,
2020-07-11T21:42:52.329-0400    INFO    openvpn: NOTE: UID/GID downgrade will be delayed because of --client, --pull, or --up-delay,
2020-07-11T21:42:52.427-0400    INFO    openvpn: WARNING: 'link-mtu' is used inconsistently, local='link-mtu 1558', remote='link-mtu 1542',
2020-07-11T21:42:52.427-0400    INFO    openvpn: WARNING: 'cipher' is used inconsistently, local='cipher AES-128-CBC', remote='cipher BF-CBC',
2020-07-11T21:42:52.428-0400    INFO    openvpn: [bb17b76bafc34f6ab4e9608a15c1f7c7] Peer Connection Initiated with [AF_INET]199.229.249.142:1198,
2020-07-11T21:42:53.562-0400    INFO    openvpn: TUN/TAP device tun0 opened,
2020-07-11T21:42:53.562-0400    INFO    openvpn: /sbin/ip link set dev tun0 up mtu 1500,
2020-07-11T21:42:53.588-0400    INFO    openvpn: /sbin/ip addr add dev tun0 local 10.20.10.10 peer 10.20.10.9,
2020-07-11T21:42:53.609-0400    INFO    openvpn: UID set to nonrootuser,
2020-07-11T21:42:53.609-0400    INFO    openvpn: Initialization Sequence Completed,
2020-07-11T21:42:53.611-0400    INFO    dns configurator: downloading root hints from https://raw.githubusercontent.com/qdm12/files/master/named.root.updated,
2020-07-11T21:42:53.611-0400    INFO    routing: detecting default network route,
2020-07-11T21:42:53.612-0400    INFO    routing: default route found: interface tun0, gateway 10.20.10.9, subnet 0.0.0.0/0,
2020-07-11T21:42:53.613-0400    WARN    cannot find VPN gateway IP address from ip routes,
2020-07-11T21:42:53.700-0400    INFO    ip getter: Public IP address is 199.229.249.142,
2020-07-11T21:42:54.170-0400    INFO    dns configurator: downloading root key from https://raw.githubusercontent.com/qdm12/files/master/root.key.updated,
2020-07-11T21:42:54.274-0400    INFO    dns configurator: generating Unbound configuration,
2020-07-11T21:42:54.679-0400    INFO    dns configurator: 60220 hostnames blocked overall,
2020-07-11T21:42:54.680-0400    INFO    dns configurator: 2523 IP addresses blocked overall,
2020-07-11T21:42:54.819-0400    INFO    dns configurator: starting unbound,
2020-07-11T21:42:54.822-0400    INFO    dns configurator: using DNS address 127.0.0.1 internally,
2020-07-11T21:42:54.822-0400    INFO    dns configurator: using DNS address 127.0.0.1 system wide,
2020-07-11T21:42:55.313-0400    INFO    unbound: notice: init module 0: validator,
2020-07-11T21:42:55.313-0400    INFO    unbound: notice: init module 1: iterator,
2020-07-11T21:42:55.386-0400    INFO    unbound: info: start of service (unbound 1.10.1).,
2020-07-11T21:42:55.447-0400    INFO    unbound: info: generate keytag query _ta-4a5c-4f66. NULL IN,
2020-07-11T21:43:00.105-0400    INFO    openvpn: port forwarded is 33070,
2020-07-11T21:43:00.106-0400    INFO    openvpn: writing forwarded port to /SOME_DIR/SOME_FILE,
2020-07-11T22:42:52.727-0400    INFO    ip getter: Public IP address is 199.229.249.142,
2020-07-11T22:47:23.780-0400    INFO    unbound: info: generate keytag query _ta-4a5c-4f66. NULL IN,
2020-07-11T23:42:52.537-0400    INFO    ip getter: Public IP address is 199.229.249.142,
2020-07-12T00:42:52.312-0400    INFO    ip getter: Public IP address is 199.229.249.142,
2020-07-12T00:47:25.239-0400    INFO    unbound: info: generate keytag query _ta-4a5c-4f66. NULL IN,
2020-07-12T01:42:52.542-0400    INFO    ip getter: Public IP address is 199.229.249.142,
2020-07-12T02:29:30.195-0400    INFO    unbound: info: generate keytag query _ta-4a5c-4f66. NULL IN,
2020-07-12T02:42:52.717-0400    INFO    ip getter: Public IP address is 199.229.249.142,
2020-07-12T03:42:52.497-0400    INFO    ip getter: Public IP address is 199.229.249.142,
2020-07-12T04:42:52.611-0400    INFO    ip getter: Public IP address is 199.229.249.142,
2020-07-12T05:00:01.830-0400    INFO    unbound: info: generate keytag query _ta-4a5c-4f66. NULL IN,
2020-07-12T05:42:52.548-0400    INFO    ip getter: Public IP address is 199.229.249.142,
2020-07-12T06:24:57.956-0400    INFO    unbound: info: generate keytag query _ta-4a5c-4f66. NULL IN,
2020-07-12T06:42:52.498-0400    INFO    ip getter: Public IP address is 199.229.249.142,
2020-07-12T07:31:35.389-0400    INFO    unbound: info: generate keytag query _ta-4a5c-4f66. NULL IN,
2020-07-12T07:42:52.536-0400    INFO    ip getter: Public IP address is 199.229.249.142,
2020-07-12T08:42:52.256-0400    WARN    ip getter: loop exited,
panic: runtime error: index out of range [-3],
,
goroutine 30 [running]:,
github.com/qdm12/golibs/network.(*client).GetContent(0x213bd60, 0x464724, 0x1e, 0x218c360, 0x1, 0x1, 0x201a20f, 0x1, 0x1, 0x0, ...),
    /go/pkg/mod/github.com/qdm12/golibs@v0.0.0-20200528010515-765b7cd4f0db/network/requests.go:100 +0x28c,
github.com/qdm12/private-internet-access-docker/internal/publicip.(*ipGetter).Get(0x216e930, 0x0, 0x0, 0x0, 0x1, 0x1),
    /tmp/gobuild/internal/publicip/publicip.go:41 +0x140,
github.com/qdm12/private-internet-access-docker/internal/publicip.(*looper).Run(0x20d05d0, 0x6018d0, 0x213bc20, 0x22aa240),
    /tmp/gobuild/internal/publicip/loop.go:56 +0x13c,
created by main._main,
    /tmp/gobuild/main.go:136 +0x1564,

Configuration file:

    vpn:
        container_name: pia
        image: qmcgaw/private-internet-access
        restart: unless-stopped
        init: true
        cap_add:
            - NET_ADMIN
        volumes:
            - /SOME_DIR:/SOME_DIR
        ports:
            - 8888:8888     # Tinyproxy
            - 8388:8388/tcp # Shadowsocks (SOCKS5)
            - 8388:8388/udp # Shadowsocks (SOCKS5)
        environment:
            - TZ=XXXXXX
            - PUID=${PUID}
            - PGID=${PGID}
            - VPNSP=private internet access
            - REGION=CA Montreal
            - PORT_FORWARDING=on
            - PORT_FORWARDING_STATUS_FILE=/SOME_DIR/SOME_FILE
            - PROTOCOL=udp
            - PIA_ENCRYPTION=normal
            - USER=someusername
            - PASSWORD=somepassword
            - EXTRA_SUBNETS=192.168.29.0/24
            - TINYPROXY=on
            - TINYPROXY_LOG=Critical
            - TINYPROXY_USER=someotherusername
            - TINYPROXY_PASSWORD=someotherpassword
            - SHADOWSOCKS=off
            - SHADOWSOCKS_USER=anotherusername
            - SHADOWSOCKS_PASSWORD=anotherpassword
        networks:
            pia_network:
                ipv4_address: X.X.X.X

Host OS: Raspbian Buster

qdm12 commented 3 years ago

Ouf that was a tough one to find!

It was in Go libraries (golibs) I developed that I use across my projects as well, so quite useful to know.

Anyway, fun story, the bug was that it generates a random integer to use a random 'realistic' http user agent string to get your IP address (so we don't get blocked really) with the steps

  1. Generate 8 random bytes
  2. Make an unsigned 64 bits integer from those 8 bytes
  3. Convert that to a Go int for convenience... that's where the bug was! int in Go is an 64 bit integer on 64 bit system but a 32 bit integer on 32 bit system (a.k.a. your Raspberry Pi!). Effectively, converting an enforced positive 64 bit integer to 32 bit would 50% chance give a negative 32 bit integer, hence crashing the whole thing.
  4. Use the positive integer made to get one of the user agent strings in a list (so from 0 to n)
raph521 commented 3 years ago

Wow, that is a fun one - thanks for the quick turnaround!