search

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.43k stars 350 forks source link

Bug: Sending multiple PUT requests to /v1/openvpn/status freezes http controller #547

Closed francisokoyo closed 3 years ago

francisokoyo commented 3 years ago

Is this urgent?: Yes

Host OS (approximate answer is fine too): Ubuntu 20.04.2

CPU arch or device name: amd64

What VPN provider are you using: nordvpn

What are you using to run your container?: Docker Compose

What is the version of the program 3.21.0

Running version latest built on 2021-07-28T15:38:56Z (commit 2998cf5)

What's the problem πŸ€”

I'm running an environment where I have to randomly rotate IPs after a set amount of time. I'm doing this by setting the openvpn status as stopped then running (forcing openvpn to connect to a random IP in the region I selected).

When I send the first PUT request to set the status as stopped everything works just fine. Sending a second PUT request with status running seems to work just fine. The third PUT request to stop openvpn gets stuck until the request times out.

Checking the status with GET /v1/openvpn/status responds with 

{"status": "stopping"}

It seems like the second request to stop openvpn never gets executed.

setup

version: '3.9'

services:
  gluetun:
    image: qmcgaw/gluetun:latest
    container_name: gluetun
    cap_add:
      - NET_ADMIN
    environment:
      - VPNSP=nordvpn
      - PROTOCOL=tcp
      - OPENVPN_USER=<FILL_IN>
      - OPENVPN_PASSWORD=<FILL_IN>
      - REGION=United States
      - TZ=Canada/Eastern
    ports: 
      - 8000:8000

Share your logs... (careful to remove in example tokens)


[+] Running 1/1
 β Ώ Container gluetun  Started                                                                             0.6s
Attaching to gluetun
gluetun  | ========================================
gluetun  | ========================================
gluetun  | =============== gluetun ================
gluetun  | ========================================
gluetun  | =========== Made with ❀️ by ============
gluetun  | ======= https://github.com/qdm12 =======
gluetun  | ========================================
gluetun  | ========================================
gluetun  | 
gluetun  | Running version latest built on 2021-07-28T15:38:56Z (commit 2998cf5)
gluetun  | 
gluetun  | πŸ”§ Need help? https://github.com/qdm12/gluetun/discussions/new
gluetun  | πŸ› Bug? https://github.com/qdm12/gluetun/issues/new
gluetun  | ✨ New feature? https://github.com/qdm12/gluetun/issues/new
gluetun  | β˜• Discussion? https://github.com/qdm12/gluetun/discussions/new
gluetun  | πŸ’» Email? quentin.mcgaw@gmail.com
gluetun  | πŸ’° Help me? https://www.paypal.me/qmcgaw https://github.com/sponsors/qdm12
gluetun  | 2021/07/28 16:45:56 INFO Alpine version: 3.14.0
gluetun  | 2021/07/28 16:45:56 INFO OpenVPN 2.4 version: 2.4.11
gluetun  | 2021/07/28 16:45:56 INFO OpenVPN 2.5 version: 2.5.2
gluetun  | 2021/07/28 16:45:56 INFO Unbound version: 1.13.1
gluetun  | 2021/07/28 16:45:56 INFO IPtables version: v1.8.7
gluetun  | 2021/07/28 16:45:56 INFO Settings summary below:
gluetun  | |--OpenVPN:
gluetun  |    |--Version: 2.5
gluetun  |    |--Verbosity level: 1
gluetun  |    |--Run as root: enabled
gluetun  |    |--Provider:
gluetun  |       |--Nordvpn settings:
gluetun  |          |--Network protocol: tcp
gluetun  |          |--Regions: united states
gluetun  | |--DNS:
gluetun  |    |--Plaintext address: 1.1.1.1
gluetun  |    |--DNS over TLS:
gluetun  |       |--Unbound:
gluetun  |           |--DNS over TLS providers:
gluetun  |               |--Cloudflare
gluetun  |           |--Listening port: 53
gluetun  |           |--Access control:
gluetun  |               |--Allowed:
gluetun  |                   |--0.0.0.0/0
gluetun  |                   |--::/0
gluetun  |           |--Caching: enabled
gluetun  |           |--IPv4 resolution: enabled
gluetun  |           |--IPv6 resolution: disabled
gluetun  |           |--Verbosity level: 1/5
gluetun  |           |--Verbosity details level: 0/4
gluetun  |           |--Validation log level: 0/2
gluetun  |           |--Username: 
gluetun  |       |--Blacklist:
gluetun  |          |--Blocked categories: malicious
gluetun  |          |--Additional IP networks blocked: 13
gluetun  |       |--Update: every 24h0m0s
gluetun  | |--Firewall:
gluetun  | |--System:
gluetun  |    |--Process user ID: 1000
gluetun  |    |--Process group ID: 1000
gluetun  |    |--Timezone: canada/eastern
gluetun  | |--Health:
gluetun  |    |--Server address: 127.0.0.1:9999
gluetun  |    |--OpenVPN:
gluetun  |       |--Initial duration: 6s
gluetun  |       |--Addition duration: 5s
gluetun  | |--HTTP control server:
gluetun  |    |--Listening port: 8000
gluetun  |    |--Logging: enabled
gluetun  | |--Public IP getter:
gluetun  |    |--Fetch period: 12h0m0s
gluetun  |    |--IP file: /tmp/gluetun/ip
gluetun  | |--Github version information: enabled
gluetun  | 2021/07/28 16:45:56 INFO storage: merging by most recent 11021 hardcoded servers and 11021 servers read from /gluetun/servers.json
gluetun  | 2021/07/28 16:45:56 INFO routing: default route found: interface eth0, gateway 192.168.160.1
gluetun  | 2021/07/28 16:45:56 INFO routing: local ethernet link found: eth0
gluetun  | 2021/07/28 16:45:56 INFO routing: local ipnet found: 192.168.160.0/20
gluetun  | 2021/07/28 16:45:56 INFO routing: default route found: interface eth0, gateway 192.168.160.1
gluetun  | 2021/07/28 16:45:56 INFO routing: adding route for 0.0.0.0/0
gluetun  | 2021/07/28 16:45:56 INFO firewall: firewall disabled, only updating allowed subnets internal list
gluetun  | 2021/07/28 16:45:56 INFO routing: default route found: interface eth0, gateway 192.168.160.1
gluetun  | 2021/07/28 16:45:56 INFO openvpn configurator: checking for device /dev/net/tun
gluetun  | 2021/07/28 16:45:56 WARN TUN device is not available: open /dev/net/tun: no such file or directory
gluetun  | 2021/07/28 16:45:56 INFO openvpn configurator: creating /dev/net/tun
gluetun  | 2021/07/28 16:45:56 INFO firewall: enabling...
gluetun  | 2021/07/28 16:45:56 INFO firewall: enabled successfully
gluetun  | 2021/07/28 16:45:56 INFO dns over tls: using plaintext DNS at address 1.1.1.1
gluetun  | 2021/07/28 16:45:56 INFO http server: listening on :8000
gluetun  | 2021/07/28 16:45:56 INFO healthcheck: listening on 127.0.0.1:9999
gluetun  | 2021/07/28 16:45:56 INFO firewall: setting VPN connection through firewall...
gluetun  | 2021/07/28 16:45:56 INFO openvpn configurator: starting OpenVPN 2.5
gluetun  | 2021/07/28 16:45:56 INFO openvpn: OpenVPN 2.5.2 x86_64-alpine-linux-musl [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [MH/PKTINFO] [AEAD] built on May  4 2021
gluetun  | 2021/07/28 16:45:56 INFO openvpn: library versions: OpenSSL 1.1.1k  25 Mar 2021, LZO 2.10
gluetun  | 2021/07/28 16:45:56 WARN openvpn: --ping should normally be used with --ping-restart or --ping-exit
gluetun  | 2021/07/28 16:45:56 INFO openvpn: TCP/UDP: Preserving recently used remote address: [AF_INET]176.113.72.227:443
gluetun  | 2021/07/28 16:45:56 INFO openvpn: Attempting to establish TCP connection with [AF_INET]176.113.72.227:443 [nonblock]
gluetun  | 2021/07/28 16:45:56 INFO openvpn: TCP connection established with [AF_INET]176.113.72.227:443
gluetun  | 2021/07/28 16:45:56 INFO openvpn: TCP_CLIENT link local: (not bound)
gluetun  | 2021/07/28 16:45:56 INFO openvpn: TCP_CLIENT link remote: [AF_INET]176.113.72.227:443
gluetun  | 2021/07/28 16:45:56 INFO openvpn: [us6044.nordvpn.com] Peer Connection Initiated with [AF_INET]176.113.72.227:443
gluetun  | 2021/07/28 16:45:57 INFO openvpn: TUN/TAP device tun0 opened
gluetun  | 2021/07/28 16:45:57 INFO openvpn: /sbin/ip link set dev tun0 up mtu 1500
gluetun  | 2021/07/28 16:45:57 INFO openvpn: /sbin/ip link set dev tun0 up
gluetun  | 2021/07/28 16:45:57 INFO openvpn: /sbin/ip addr add dev tun0 10.7.2.4/24
gluetun  | 2021/07/28 16:45:57 INFO openvpn: Initialization Sequence Completed
gluetun  | 2021/07/28 16:45:57 INFO VPN routing IP address: 176.113.72.227
gluetun  | 2021/07/28 16:45:57 INFO dns over tls: downloading DNS over TLS cryptographic files
gluetun  | 2021/07/28 16:45:58 INFO dns over tls: downloading hostnames and IP block lists
gluetun  | 2021/07/28 16:45:58 INFO healthcheck: healthy!
gluetun  | 2021/07/28 16:45:59 INFO dns over tls: init module 0: validator
gluetun  | 2021/07/28 16:45:59 INFO dns over tls: init module 1: iterator
gluetun  | 2021/07/28 16:45:59 INFO dns over tls: start of service (unbound 1.13.1).
gluetun  | 2021/07/28 16:45:59 INFO dns over tls: generate keytag query _ta-4a5c-4f66. NULL IN
gluetun  | 2021/07/28 16:45:59 INFO dns over tls: generate keytag query _ta-4a5c-4f66. NULL IN
gluetun  | 2021/07/28 16:45:59 INFO dns over tls: ready
gluetun  | 2021/07/28 16:45:59 INFO You are running on the bleeding edge of latest!
gluetun  | 2021/07/28 16:45:59 INFO ip getter: Public IP address is 176.113.72.230 (United States, New York, New York City)
gluetun  | 2021/07/28 16:46:22 INFO http server: 200 GET /status wrote 21B to 192.168.160.1:56760 in 228Β΅s
gluetun  | 2021/07/28 16:46:35 INFO openvpn: stopping
gluetun  | 2021/07/28 16:46:35 INFO http server: 200 PUT /status wrote 22B to 192.168.160.1:56760 in 10.8553ms
gluetun  | 2021/07/28 16:46:44 INFO http server: 200 GET /status wrote 21B to 192.168.160.1:56760 in 80.3Β΅s
gluetun  | 2021/07/28 16:46:54 INFO openvpn: starting
gluetun  | 2021/07/28 16:46:54 INFO firewall: setting VPN connection through firewall...
gluetun  | 2021/07/28 16:46:54 INFO openvpn configurator: starting OpenVPN 2.5
gluetun  | 2021/07/28 16:46:54 INFO http server: 200 PUT /status wrote 22B to 192.168.160.1:56760 in 35.0732ms
gluetun  | 2021/07/28 16:46:54 INFO openvpn: OpenVPN 2.5.2 x86_64-alpine-linux-musl [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [MH/PKTINFO] [AEAD] built on May  4 2021
gluetun  | 2021/07/28 16:46:54 INFO openvpn: library versions: OpenSSL 1.1.1k  25 Mar 2021, LZO 2.10
gluetun  | 2021/07/28 16:46:54 WARN openvpn: --ping should normally be used with --ping-restart or --ping-exit
gluetun  | 2021/07/28 16:46:54 INFO openvpn: TCP/UDP: Preserving recently used remote address: [AF_INET]83.136.182.124:443
gluetun  | 2021/07/28 16:46:54 INFO openvpn: Attempting to establish TCP connection with [AF_INET]83.136.182.124:443 [nonblock]
gluetun  | 2021/07/28 16:46:54 INFO openvpn: TCP connection established with [AF_INET]83.136.182.124:443
gluetun  | 2021/07/28 16:46:54 INFO openvpn: TCP_CLIENT link local: (not bound)
gluetun  | 2021/07/28 16:46:54 INFO openvpn: TCP_CLIENT link remote: [AF_INET]83.136.182.124:443
gluetun  | 2021/07/28 16:46:55 INFO openvpn: [us9195.nordvpn.com] Peer Connection Initiated with [AF_INET]83.136.182.124:443
gluetun  | 2021/07/28 16:46:56 INFO openvpn: TUN/TAP device tun0 opened
gluetun  | 2021/07/28 16:46:56 INFO openvpn: /sbin/ip link set dev tun0 up mtu 1500
gluetun  | 2021/07/28 16:46:56 INFO openvpn: /sbin/ip link set dev tun0 up
gluetun  | 2021/07/28 16:46:56 INFO openvpn: /sbin/ip addr add dev tun0 10.7.1.3/24
gluetun  | 2021/07/28 16:46:56 INFO openvpn: Initialization Sequence Completed
gluetun  | 2021/07/28 16:46:56 INFO VPN routing IP address: 83.136.182.124
gluetun  | 2021/07/28 16:47:02 INFO http server: 200 GET /status wrote 21B to 192.168.160.1:56760 in 26Β΅s
gluetun  | 2021/07/28 16:47:11 ERROR ip getter: Get "https://ipinfo.io/ip": context deadline exceeded (Client.Timeout exceeded while awaiting headers)
gluetun  | 2021/07/28 16:47:11 INFO ip getter: retrying in 5s
gluetun  | 2021/07/28 16:47:14 INFO openvpn: stopping
gluetun  | 2021/07/28 16:47:31 ERROR ip getter: Get "https://ipinfo.io/ip": context deadline exceeded (Client.Timeout exceeded while awaiting headers)
gluetun  | 2021/07/28 16:47:31 INFO ip getter: retrying in 5s
gluetun  | 2021/07/28 16:47:53 WARN ip getter: Get "https://ipinfo.io/83.136.182.125": context deadline exceeded (Client.Timeout exceeded while awaiting headers)
gluetun  | 2021/07/28 16:47:53 INFO ip getter: Public IP address is 83.136.182.125
gluetun  | 2021/07/28 16:50:18 INFO http server: 200 GET /status wrote 22B to 192.168.160.1:56902 in 113.8Β΅s
qdm12 commented 3 years ago

Indeed! I think the bug got introduced with #543 commit 2998cf5e4854b0b451b2f0618a89e1d8bcf07e90, @manz4rk it looks like we didn't restart it twice in #542 πŸ˜„

@francis-ceng you can use qmcgaw/gluetun:v3.21.0 for now which is just 1 or 2 commits behind latest without the bug.

francisokoyo commented 3 years ago

@qdm12 thanks a lot! It's working as expected now. I'll let you know if I come across anything weird. Thanks again for the help.

PS. I think you meant v3.20.0 not 3.21.0

qdm12 commented 3 years ago

Cool! No actually it worked on v3.21.0 πŸ˜‰ I broke it like very recently. It's always nice to have quick user feedback though so thanks for that!

ghost commented 3 years ago

@manz4rk it looks like we didn't restart it twice in #542 πŸ˜„

Whoops πŸ˜„ I knew it went too easy! Sounds like I'm not fit for QA haha

jathek commented 3 years ago

Host OS (approximate answer is fine too): unraid 6.9.2

cat /etc/os-release

NAME=Slackware
VERSION="14.2"
ID=slackware
VERSION_ID=14.2
PRETTY_NAME="Slackware 14.2 x86_64 (post 14.2 -current)"
ANSI_COLOR="0;34"
CPE_NAME="cpe:/o:slackware:slackware_linux:14.2"
HOME_URL="http://slackware.com/"
SUPPORT_URL="http://www.linuxquestions.org/questions/slackware-14/"
BUG_REPORT_URL="http://www.linuxquestions.org/questions/slackware-14/"
VERSION_CODENAME=current

CPU arch or device name: amd64

What VPN provider are you using: windscribe

What are you using to run your container?: Docker Compose

What is the version of the program (See the line at the top of your logs)

Running version latest built on 2021-08-01T15:05:22Z (commit abbcf60)

What's the problem πŸ€”

Inspired by this post I attempted to put together my own shortcut for getting a new ip address. Below is my bash alias for toggling, and below that are my logs for times it failed and times it seemed to succeed. Sharing in case it helps with solving the issue.

# curl via docker container
dcurl() { docker run --name curl_$(date "+%Y-%m-%d_%H-%M-%S") --rm -it --network=t2_proxy curlimages/curl "$@"; }
# toggle vpn in gluetun container(s)
vtog() {
  for c in "$@"; do
    echo $c - $(dcurl -m 15 -s -f -X PUT -d '{"status":"stopped"}' $c:8000/v1/openvpn/status)
  done
  for c in "$@"; do
    echo $c - $(dcurl -m 15 -s -f -X PUT -d '{"status":"running"}' $c:8000/v1/openvpn/status)
  done
}
# wget docker container's external IP
dip() {
  for c in "$@"; do
    echo $c - $(docker run --name alpine_$(date "+%Y-%m-%d_%H-%M-%S") --rm -it --network=container:$c alpine wget -T 15 -qO- https://ipinfo.io | jq -r '.ip + " - " + .city + ", " + .region + ", " + .country' 2>&1)
  done
}

Below is a time it hung. The "ERROR ip getter" repeated forever.

2021-08-01 11:55:52.05012920 CDT ========================================
2021-08-01 11:55:52.05015588 CDT ========================================
2021-08-01 11:55:52.05016186 CDT =============== gluetun ================
2021-08-01 11:55:52.05016442 CDT ========================================
2021-08-01 11:55:52.05016682 CDT =========== Made with ❀️ by ============
2021-08-01 11:55:52.05016968 CDT ======= https://github.com/qdm12 =======
2021-08-01 11:55:52.05017202 CDT ========================================
2021-08-01 11:55:52.05017433 CDT ========================================
2021-08-01 11:55:52.05017668 CDT
2021-08-01 11:55:52.05017900 CDT Running version latest built on 2021-08-01T15:05:22Z (commit abbcf60)
2021-08-01 11:55:52.05018212 CDT
2021-08-01 11:55:52.05018440 CDT πŸ”§ Need help? https://github.com/qdm12/gluetun/discussions/new
2021-08-01 11:55:52.05018677 CDT πŸ› Bug? https://github.com/qdm12/gluetun/issues/new
2021-08-01 11:55:52.05018909 CDT ✨ New feature? https://github.com/qdm12/gluetun/issues/new
2021-08-01 11:55:52.05019145 CDT β˜• Discussion? https://github.com/qdm12/gluetun/discussions/new
2021-08-01 11:55:52.05019383 CDT πŸ’» Email? quentin.mcgaw@gmail.com
2021-08-01 11:55:52.05019635 CDT πŸ’° Help me? https://www.paypal.me/qmcgaw https://github.com/sponsors/qdm12
2021-08-01 11:55:52.05057086 CDT 2021/08/01 11:55:52 INFO Alpine version: 3.14.0
2021-08-01 11:55:52.05758281 CDT 2021/08/01 11:55:52 INFO OpenVPN 2.4 version: 2.4.11
2021-08-01 11:55:52.06039810 CDT 2021/08/01 11:55:52 INFO OpenVPN 2.5 version: 2.5.2
2021-08-01 11:55:52.06286152 CDT 2021/08/01 11:55:52 INFO Unbound version: 1.13.1
2021-08-01 11:55:52.06507833 CDT 2021/08/01 11:55:52 INFO IPtables version: v1.8.7
2021-08-01 11:55:52.06625229 CDT 2021/08/01 11:55:52 INFO Settings summary below:
2021-08-01 11:55:52.06627043 CDT |--OpenVPN:
2021-08-01 11:55:52.06627658 CDT    |--Version: 2.5
2021-08-01 11:55:52.06628218 CDT    |--Verbosity level: 1
2021-08-01 11:55:52.06628783 CDT    |--Run as root: enabled
2021-08-01 11:55:52.06629326 CDT    |--Provider:
2021-08-01 11:55:52.06629864 CDT       |--Windscribe settings:
2021-08-01 11:55:52.06630409 CDT          |--Network protocol: udp
2021-08-01 11:55:52.06630952 CDT          |--Cities: vancouver
2021-08-01 11:55:52.06631481 CDT |--DNS:
2021-08-01 11:55:52.06632011 CDT    |--Plaintext address: 1.1.1.1
2021-08-01 11:55:52.06632550 CDT    |--DNS over TLS:
2021-08-01 11:55:52.06633083 CDT       |--Unbound:
2021-08-01 11:55:52.06633618 CDT           |--DNS over TLS providers:
2021-08-01 11:55:52.06634152 CDT               |--Cloudflare
2021-08-01 11:55:52.06634688 CDT           |--Listening port: 53
2021-08-01 11:55:52.06635227 CDT           |--Access control:
2021-08-01 11:55:52.06637316 CDT               |--Allowed:
2021-08-01 11:55:52.06637987 CDT                   |--0.0.0.0/0
2021-08-01 11:55:52.06638538 CDT                   |--::/0
2021-08-01 11:55:52.06639076 CDT           |--Caching: enabled
2021-08-01 11:55:52.06639616 CDT           |--IPv4 resolution: enabled
2021-08-01 11:55:52.06640157 CDT           |--IPv6 resolution: disabled
2021-08-01 11:55:52.06640698 CDT           |--Verbosity level: 1/5
2021-08-01 11:55:52.06641236 CDT           |--Verbosity details level: 0/4
2021-08-01 11:55:52.06641776 CDT           |--Validation log level: 0/2
2021-08-01 11:55:52.06642310 CDT           |--Username:
2021-08-01 11:55:52.06642849 CDT       |--Blacklist:
2021-08-01 11:55:52.06643383 CDT          |--Blocked categories:
2021-08-01 11:55:52.06643921 CDT          |--Additional IP networks blocked: 13
2021-08-01 11:55:52.06644465 CDT |--Firewall:
2021-08-01 11:55:52.06645003 CDT |--System:
2021-08-01 11:55:52.06645533 CDT    |--Process user ID: 1000
2021-08-01 11:55:52.06646067 CDT    |--Process group ID: 100
2021-08-01 11:55:52.06646630 CDT    |--Timezone: america/chicago
2021-08-01 11:55:52.06647169 CDT |--HTTP proxy:
2021-08-01 11:55:52.06647703 CDT    |--Port: 1080
2021-08-01 11:55:52.06648239 CDT    |--Authentication: enabled
2021-08-01 11:55:52.06648770 CDT    |--Stealth: enabled
2021-08-01 11:55:52.06649303 CDT |--Health:
2021-08-01 11:55:52.06649833 CDT    |--Server address: 127.0.0.1:9999
2021-08-01 11:55:52.06650376 CDT    |--OpenVPN:
2021-08-01 11:55:52.06650907 CDT       |--Initial duration: 6s
2021-08-01 11:55:52.06651439 CDT       |--Addition duration: 5s
2021-08-01 11:55:52.06651973 CDT |--HTTP control server:
2021-08-01 11:55:52.06652504 CDT    |--Listening port: 8000
2021-08-01 11:55:52.06653038 CDT    |--Logging: enabled
2021-08-01 11:55:52.06653567 CDT |--Public IP getter:
2021-08-01 11:55:52.06654098 CDT    |--Fetch period: 12h0m0s
2021-08-01 11:55:52.06654734 CDT    |--IP file: /gluetun/ip
2021-08-01 11:55:52.10778678 CDT 2021/08/01 11:55:52 INFO storage: merging by most recent 11000 hardcoded servers and 11000 servers read from /gluetun/servers.json
2021-08-01 11:55:52.14542116 CDT 2021/08/01 11:55:52 INFO routing: default route found: interface eth0, gateway 192.168.90.1
2021-08-01 11:55:52.14553588 CDT 2021/08/01 11:55:52 INFO routing: local ethernet link found: gretap0
2021-08-01 11:55:52.14556337 CDT 2021/08/01 11:55:52 INFO routing: local ethernet link found: erspan0
2021-08-01 11:55:52.14556928 CDT 2021/08/01 11:55:52 INFO routing: local ethernet link found: eth0
2021-08-01 11:55:52.14557443 CDT 2021/08/01 11:55:52 INFO routing: local ipnet found: 192.168.90.0/24
2021-08-01 11:55:52.14684301 CDT 2021/08/01 11:55:52 INFO routing: default route found: interface eth0, gateway 192.168.90.1
2021-08-01 11:55:52.14691046 CDT 2021/08/01 11:55:52 INFO routing: adding route for 0.0.0.0/0
2021-08-01 11:55:52.14697580 CDT 2021/08/01 11:55:52 INFO firewall: firewall disabled, only updating allowed subnets internal list
2021-08-01 11:55:52.14703979 CDT 2021/08/01 11:55:52 INFO routing: default route found: interface eth0, gateway 192.168.90.1
2021-08-01 11:55:52.14704806 CDT 2021/08/01 11:55:52 INFO openvpn configurator: checking for device /dev/net/tun
2021-08-01 11:55:52.14705999 CDT 2021/08/01 11:55:52 WARN TUN device is not available: open /dev/net/tun: no such file or directory
2021-08-01 11:55:52.14706740 CDT 2021/08/01 11:55:52 INFO openvpn configurator: creating /dev/net/tun
2021-08-01 11:55:52.14713529 CDT 2021/08/01 11:55:52 INFO firewall: enabling...
2021-08-01 11:55:52.16095771 CDT 2021/08/01 11:55:52 INFO firewall: enabled successfully
2021-08-01 11:55:52.16102468 CDT 2021/08/01 11:55:52 INFO healthcheck: listening on 127.0.0.1:9999
2021-08-01 11:55:52.16108849 CDT 2021/08/01 11:55:52 INFO dns over tls: using plaintext DNS at address 1.1.1.1
2021-08-01 11:55:52.16109575 CDT 2021/08/01 11:55:52 INFO http server: listening on :8000
2021-08-01 11:55:52.16112182 CDT 2021/08/01 11:55:52 INFO http proxy: listening on :1080
2021-08-01 11:55:52.16137907 CDT 2021/08/01 11:55:52 INFO firewall: setting VPN connection through firewall...
2021-08-01 11:55:52.16224091 CDT 2021/08/01 11:55:52 INFO openvpn configurator: starting OpenVPN 2.5
2021-08-01 11:55:52.16456846 CDT 2021/08/01 11:55:52 INFO openvpn: 2021-08-01 11:55:52 DEPRECATED OPTION: ncp-disable. Disabling cipher negotiation is a deprecated debug feature that will be removed in OpenVPN 2.6
2021-08-01 11:55:52.16459635 CDT 2021/08/01 11:55:52 INFO openvpn: OpenVPN 2.5.2 x86_64-alpine-linux-musl [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [MH/PKTINFO] [AEAD] built on May  4 2021
2021-08-01 11:55:52.16461187 CDT 2021/08/01 11:55:52 INFO openvpn: library versions: OpenSSL 1.1.1k  25 Mar 2021, LZO 2.10
2021-08-01 11:55:52.16523473 CDT 2021/08/01 11:55:52 INFO openvpn: TCP/UDP: Preserving recently used remote address: [AF_INET]208.78.41.162:443
2021-08-01 11:55:52.16524083 CDT 2021/08/01 11:55:52 INFO openvpn: UDP link local: (not bound)
2021-08-01 11:55:52.16525531 CDT 2021/08/01 11:55:52 INFO openvpn: UDP link remote: [AF_INET]208.78.41.162:443
2021-08-01 11:55:52.63424361 CDT 2021/08/01 11:55:52 WARN openvpn: 'link-mtu' is used inconsistently, local='link-mtu 1601', remote='link-mtu 1550'
2021-08-01 11:55:52.63427530 CDT 2021/08/01 11:55:52 WARN openvpn: 'auth' is used inconsistently, local='auth SHA512', remote='auth [null-digest]'
2021-08-01 11:55:52.63428219 CDT 2021/08/01 11:55:52 WARN openvpn: 'comp-lzo' is present in remote config but missing in local config, remote='comp-lzo'
2021-08-01 11:55:52.63434290 CDT 2021/08/01 11:55:52 INFO openvpn: [yvr-311.windscribe.com] Peer Connection Initiated with [AF_INET]208.78.41.162:443
2021-08-01 11:55:53.87299836 CDT 2021/08/01 11:55:53 INFO openvpn: TUN/TAP device tun0 opened
2021-08-01 11:55:53.87302985 CDT 2021/08/01 11:55:53 INFO openvpn: /sbin/ip link set dev tun0 up mtu 1500
2021-08-01 11:55:53.87566001 CDT 2021/08/01 11:55:53 INFO openvpn: /sbin/ip link set dev tun0 up
2021-08-01 11:55:53.87624755 CDT 2021/08/01 11:55:53 INFO openvpn: /sbin/ip addr add dev tun0 10.120.130.29/23
2021-08-01 11:55:53.87873817 CDT 2021/08/01 11:55:53 INFO openvpn: Initialization Sequence Completed
2021-08-01 11:55:53.87888128 CDT 2021/08/01 11:55:53 INFO VPN routing IP address: 208.78.41.162
2021-08-01 11:55:53.87888758 CDT 2021/08/01 11:55:53 INFO dns over tls: downloading DNS over TLS cryptographic files
2021-08-01 11:55:54.23154265 CDT 2021/08/01 11:55:54 INFO healthcheck: healthy!
2021-08-01 11:55:55.00816025 CDT 2021/08/01 11:55:55 INFO dns over tls: downloading hostnames and IP block lists
2021-08-01 11:55:55.02172614 CDT 2021/08/01 11:55:55 INFO dns over tls: init module 0: validator
2021-08-01 11:55:55.02174458 CDT 2021/08/01 11:55:55 INFO dns over tls: init module 1: iterator
2021-08-01 11:55:55.06279312 CDT 2021/08/01 11:55:55 INFO dns over tls: start of service (unbound 1.13.1).
2021-08-01 11:55:55.97677946 CDT 2021/08/01 11:55:55 INFO dns over tls: generate keytag query _ta-4a5c-4f66. NULL IN
2021-08-01 11:55:55.98612841 CDT 2021/08/01 11:55:55 INFO dns over tls: generate keytag query _ta-4a5c-4f66. NULL IN
2021-08-01 11:55:56.71399661 CDT 2021/08/01 11:55:56 INFO dns over tls: ready
2021-08-01 11:56:00.53291992 CDT 2021/08/01 11:56:00 INFO ip getter: Public IP address is 208.78.41.173 (Canada, British Columbia, Vancouver)
2021-08-01 11:56:24.24940064 CDT 2021/08/01 11:56:24 INFO http server: 200 GET /status wrote 21B to 192.168.90.51:46938 in 46.519Β΅s
2021-08-01 11:56:56.76620139 CDT 2021/08/01 11:56:56 INFO openvpn: stopping
2021-08-01 11:56:56.78308476 CDT 2021/08/01 11:56:56 INFO http server: 200 PUT /status wrote 22B to 192.168.90.51:47724 in 16.923616ms
2021-08-01 11:56:58.12443223 CDT 2021/08/01 11:56:58 INFO openvpn: starting
2021-08-01 11:56:58.12463974 CDT 2021/08/01 11:56:58 INFO firewall: setting VPN connection through firewall...
2021-08-01 11:56:58.12672820 CDT 2021/08/01 11:56:58 INFO openvpn configurator: starting OpenVPN 2.5
2021-08-01 11:56:58.12701117 CDT 2021/08/01 11:56:58 INFO http server: 200 PUT /status wrote 22B to 192.168.90.51:47770 in 2.656245ms
2021-08-01 11:56:58.12882044 CDT 2021/08/01 11:56:58 INFO openvpn: 2021-08-01 11:56:58 DEPRECATED OPTION: ncp-disable. Disabling cipher negotiation is a deprecated debug feature that will be removed in OpenVPN 2.6
2021-08-01 11:56:58.12894332 CDT 2021/08/01 11:56:58 INFO openvpn: OpenVPN 2.5.2 x86_64-alpine-linux-musl [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [MH/PKTINFO] [AEAD] built on May  4 2021
2021-08-01 11:56:58.12895646 CDT 2021/08/01 11:56:58 INFO openvpn: library versions: OpenSSL 1.1.1k  25 Mar 2021, LZO 2.10
2021-08-01 11:56:58.12990092 CDT 2021/08/01 11:56:58 INFO openvpn: TCP/UDP: Preserving recently used remote address: [AF_INET]71.19.251.152:443
2021-08-01 11:56:58.12993036 CDT 2021/08/01 11:56:58 INFO openvpn: UDP link local: (not bound)
2021-08-01 11:56:58.12993978 CDT 2021/08/01 11:56:58 INFO openvpn: UDP link remote: [AF_INET]71.19.251.152:443
2021-08-01 11:56:58.50883522 CDT 2021/08/01 11:56:58 WARN openvpn: 'link-mtu' is used inconsistently, local='link-mtu 1601', remote='link-mtu 1550'
2021-08-01 11:56:58.50886320 CDT 2021/08/01 11:56:58 WARN openvpn: 'auth' is used inconsistently, local='auth SHA512', remote='auth [null-digest]'
2021-08-01 11:56:58.50887456 CDT 2021/08/01 11:56:58 WARN openvpn: 'comp-lzo' is present in remote config but missing in local config, remote='comp-lzo'
2021-08-01 11:56:58.50901801 CDT 2021/08/01 11:56:58 INFO openvpn: [yvr-187.windscribe.com] Peer Connection Initiated with [AF_INET]71.19.251.152:443
2021-08-01 11:57:04.90815546 CDT 2021/08/01 11:57:04 INFO openvpn: TUN/TAP device tun0 opened
2021-08-01 11:57:04.90818290 CDT 2021/08/01 11:57:04 INFO openvpn: /sbin/ip link set dev tun0 up mtu 1500
2021-08-01 11:57:04.90906427 CDT 2021/08/01 11:57:04 INFO openvpn: /sbin/ip link set dev tun0 up
2021-08-01 11:57:04.90977787 CDT 2021/08/01 11:57:04 INFO openvpn: /sbin/ip addr add dev tun0 10.123.34.2/23
2021-08-01 11:57:04.91230223 CDT 2021/08/01 11:57:04 INFO openvpn: Initialization Sequence Completed
2021-08-01 11:57:04.91245300 CDT 2021/08/01 11:57:04 INFO VPN routing IP address: 71.19.251.152
2021-08-01 11:57:19.91348958 CDT 2021/08/01 11:57:19 ERROR ip getter: Get "https://ipinfo.io/ip": context deadline exceeded (Client.Timeout exceeded while awaiting headers)
2021-08-01 11:57:19.91352164 CDT 2021/08/01 11:57:19 INFO ip getter: retrying in 5s
2021-08-01 11:57:22.16999093 CDT 2021/08/01 11:57:22 INFO openvpn: stopping
2021-08-01 11:57:22.18805594 CDT 2021/08/01 11:57:22 INFO http server: 200 PUT /status wrote 22B to 192.168.90.51:48448 in 18.09317ms
2021-08-01 11:57:35.61703876 CDT 2021/08/01 11:57:35 INFO http server: 200 GET /status wrote 21B to 192.168.90.51:48754 in 10.831Β΅s
2021-08-01 11:57:39.91502131 CDT 2021/08/01 11:57:39 ERROR ip getter: Get "https://ipinfo.io/ip": context deadline exceeded (Client.Timeout exceeded while awaiting headers)
2021-08-01 11:57:39.91505680 CDT 2021/08/01 11:57:39 INFO ip getter: retrying in 5s
2021-08-01 11:57:43.04725581 CDT 2021/08/01 11:57:43 INFO http server: 200 PUT /status wrote 30B to 192.168.90.51:48988 in 83.85Β΅s
2021-08-01 11:57:54.91799240 CDT 2021/08/01 11:57:54 ERROR ip getter: Get "https://api.ipify.org": dial tcp: lookup api.ipify.org on 127.0.0.1:53: read udp 127.0.0.1:44226->127.0.0.1:53: i/o timeout
2021-08-01 11:57:54.91802436 CDT 2021/08/01 11:57:54 INFO ip getter: retrying in 5s
2021-08-01 11:58:14.91850728 CDT 2021/08/01 11:58:14 ERROR ip getter: Get "http://ip1.dynupdate.no-ip.com:8245": context deadline exceeded (Client.Timeout exceeded while awaiting headers)
2021-08-01 11:58:14.91854092 CDT 2021/08/01 11:58:14 INFO ip getter: retrying in 5s
2021-08-01 11:58:29.92042179 CDT 2021/08/01 11:58:29 ERROR ip getter: Get "https://ifconfig.io/ip": dial tcp: lookup ifconfig.io on 127.0.0.1:53: read udp 127.0.0.1:48992->127.0.0.1:53: i/o timeout
2021-08-01 11:58:29.92045244 CDT 2021/08/01 11:58:29 INFO ip getter: retrying in 5s
2021-08-01 11:58:49.92206859 CDT 2021/08/01 11:58:49 ERROR ip getter: Get "http://ip1.dynupdate.no-ip.com:8245": context deadline exceeded (Client.Timeout exceeded while awaiting headers)
2021-08-01 11:58:49.92210969 CDT 2021/08/01 11:58:49 INFO ip getter: retrying in 5s
2021-08-01 11:58:59.92408036 CDT 2021/08/01 11:58:59 ERROR ip getter: Get "https://diagnostic.opendns.com/myip": dial tcp: lookup diagnostic.opendns.com on 127.0.0.1:53: server misbehaving
2021-08-01 11:58:59.92411473 CDT 2021/08/01 11:58:59 INFO ip getter: retrying in 5s
2021-08-01 11:59:04.92506455 CDT 2021/08/01 11:59:04 ERROR ip getter: Get "https://ifconfig.me/ip": dial tcp: lookup ifconfig.me on 127.0.0.1:53: server misbehaving
2021-08-01 11:59:04.92510572 CDT 2021/08/01 11:59:04 INFO ip getter: retrying in 5s
2021-08-01 11:59:19.92810023 CDT 2021/08/01 11:59:19 ERROR ip getter: Get "https://diagnostic.opendns.com/myip": dial tcp: lookup diagnostic.opendns.com on 127.0.0.1:53: read udp 127.0.0.1:35812->127.0.0.1:53: i/o timeout
2021-08-01 11:59:19.92813885 CDT 2021/08/01 11:59:19 INFO ip getter: retrying in 5s
2021-08-01 11:59:24.92981828 CDT 2021/08/01 11:59:24 ERROR ip getter: Get "https://ifconfig.io/ip": dial tcp: lookup ifconfig.io on 127.0.0.1:53: server misbehaving
2021-08-01 11:59:24.92985959 CDT 2021/08/01 11:59:24 INFO ip getter: retrying in 5s
2021-08-01 11:59:44.93079367 CDT 2021/08/01 11:59:44 ERROR ip getter: Get "https://ipinfo.io/ip": context deadline exceeded (Client.Timeout exceeded while awaiting headers)
2021-08-01 11:59:44.93084772 CDT 2021/08/01 11:59:44 INFO ip getter: retrying in 5s
2021-08-01 12:00:04.93113896 CDT 2021/08/01 12:00:04 ERROR ip getter: Get "http://ip1.dynupdate.no-ip.com": context deadline exceeded (Client.Timeout exceeded while awaiting headers)
2021-08-01 12:00:04.93117595 CDT 2021/08/01 12:00:04 INFO ip getter: retrying in 5s
2021-08-01 12:00:24.93254980 CDT 2021/08/01 12:00:24 ERROR ip getter: Get "http://ip1.dynupdate.no-ip.com:8245": context deadline exceeded (Client.Timeout exceeded while awaiting headers)
2021-08-01 12:00:24.93257507 CDT 2021/08/01 12:00:24 INFO ip getter: retrying in 5s

Below is a time I think it was successful? The log doesn't end with the normal ipgetter line (INFO ip getter: Public IP address is blah.blah.blah) but curling through the container shows the VPN's ip.

2021-08-01 13:28:59.43451690 CDT ========================================
2021-08-01 13:28:59.43453730 CDT ========================================
2021-08-01 13:28:59.43454211 CDT =============== gluetun ================
2021-08-01 13:28:59.43454799 CDT ========================================
2021-08-01 13:28:59.43455523 CDT =========== Made with ❀️ by ============
2021-08-01 13:28:59.43455906 CDT ======= https://github.com/qdm12 =======
2021-08-01 13:28:59.43456223 CDT ========================================
2021-08-01 13:28:59.43456558 CDT ========================================
2021-08-01 13:28:59.43456882 CDT
2021-08-01 13:28:59.43457200 CDT Running version latest built on 2021-08-01T15:05:22Z (commit abbcf60)
2021-08-01 13:28:59.43457631 CDT
2021-08-01 13:28:59.43457952 CDT πŸ”§ Need help? https://github.com/qdm12/gluetun/discussions/new
2021-08-01 13:28:59.43458303 CDT πŸ› Bug? https://github.com/qdm12/gluetun/issues/new
2021-08-01 13:28:59.43458659 CDT ✨ New feature? https://github.com/qdm12/gluetun/issues/new
2021-08-01 13:28:59.43458971 CDT β˜• Discussion? https://github.com/qdm12/gluetun/discussions/new
2021-08-01 13:28:59.43459210 CDT πŸ’» Email? quentin.mcgaw@gmail.com
2021-08-01 13:28:59.43459447 CDT πŸ’° Help me? https://www.paypal.me/qmcgaw https://github.com/sponsors/qdm12
2021-08-01 13:28:59.43486279 CDT 2021/08/01 13:28:59 INFO Alpine version: 3.14.0
2021-08-01 13:28:59.44186701 CDT 2021/08/01 13:28:59 INFO OpenVPN 2.4 version: 2.4.11
2021-08-01 13:28:59.44538909 CDT 2021/08/01 13:28:59 INFO OpenVPN 2.5 version: 2.5.2
2021-08-01 13:28:59.44794963 CDT 2021/08/01 13:28:59 INFO Unbound version: 1.13.1
2021-08-01 13:28:59.45014704 CDT 2021/08/01 13:28:59 INFO IPtables version: v1.8.7
2021-08-01 13:28:59.45137295 CDT 2021/08/01 13:28:59 INFO Settings summary below:
2021-08-01 13:28:59.45138389 CDT |--OpenVPN:
2021-08-01 13:28:59.45138775 CDT    |--Version: 2.5
2021-08-01 13:28:59.45139122 CDT    |--Verbosity level: 1
2021-08-01 13:28:59.45139457 CDT    |--Run as root: enabled
2021-08-01 13:28:59.45139798 CDT    |--Provider:
2021-08-01 13:28:59.45140127 CDT       |--Windscribe settings:
2021-08-01 13:28:59.45140462 CDT          |--Network protocol: udp
2021-08-01 13:28:59.45140793 CDT          |--Cities: vancouver
2021-08-01 13:28:59.45141120 CDT |--DNS:
2021-08-01 13:28:59.45141445 CDT    |--Plaintext address: 1.1.1.1
2021-08-01 13:28:59.45141776 CDT    |--DNS over TLS:
2021-08-01 13:28:59.45142152 CDT       |--Unbound:
2021-08-01 13:28:59.45142484 CDT           |--DNS over TLS providers:
2021-08-01 13:28:59.45142817 CDT               |--Cloudflare
2021-08-01 13:28:59.45143154 CDT           |--Listening port: 53
2021-08-01 13:28:59.45143484 CDT           |--Access control:
2021-08-01 13:28:59.45145085 CDT               |--Allowed:
2021-08-01 13:28:59.45145503 CDT                   |--0.0.0.0/0
2021-08-01 13:28:59.45145844 CDT                   |--::/0
2021-08-01 13:28:59.45146176 CDT           |--Caching: enabled
2021-08-01 13:28:59.45146516 CDT           |--IPv4 resolution: enabled
2021-08-01 13:28:59.45146854 CDT           |--IPv6 resolution: disabled
2021-08-01 13:28:59.45147185 CDT           |--Verbosity level: 1/5
2021-08-01 13:28:59.45147516 CDT           |--Verbosity details level: 0/4
2021-08-01 13:28:59.45147867 CDT           |--Validation log level: 0/2
2021-08-01 13:28:59.45148203 CDT           |--Username:
2021-08-01 13:28:59.45148537 CDT       |--Blacklist:
2021-08-01 13:28:59.45148871 CDT          |--Blocked categories:
2021-08-01 13:28:59.45149204 CDT          |--Additional IP networks blocked: 13
2021-08-01 13:28:59.45149540 CDT |--Firewall:
2021-08-01 13:28:59.45149872 CDT |--System:
2021-08-01 13:28:59.45150196 CDT    |--Process user ID: 1000
2021-08-01 13:28:59.45150520 CDT    |--Process group ID: 100
2021-08-01 13:28:59.45150849 CDT    |--Timezone: america/chicago
2021-08-01 13:28:59.45151179 CDT |--HTTP proxy:
2021-08-01 13:28:59.45151513 CDT    |--Port: 1080
2021-08-01 13:28:59.45151844 CDT    |--Authentication: enabled
2021-08-01 13:28:59.45152173 CDT    |--Stealth: enabled
2021-08-01 13:28:59.45152507 CDT |--Health:
2021-08-01 13:28:59.45152835 CDT    |--Server address: 127.0.0.1:9999
2021-08-01 13:28:59.45153165 CDT    |--OpenVPN:
2021-08-01 13:28:59.45153491 CDT       |--Initial duration: 6s
2021-08-01 13:28:59.45153821 CDT       |--Addition duration: 5s
2021-08-01 13:28:59.45154149 CDT |--HTTP control server:
2021-08-01 13:28:59.45154475 CDT    |--Listening port: 8000
2021-08-01 13:28:59.45154800 CDT    |--Logging: enabled
2021-08-01 13:28:59.45155127 CDT |--Public IP getter:
2021-08-01 13:28:59.45155458 CDT    |--Fetch period: 12h0m0s
2021-08-01 13:28:59.45155791 CDT    |--IP file: /gluetun/ip
2021-08-01 13:28:59.49417756 CDT 2021/08/01 13:28:59 INFO storage: merging by most recent 11000 hardcoded servers and 11000 servers read from /gluetun/servers.json
2021-08-01 13:28:59.53369582 CDT 2021/08/01 13:28:59 INFO routing: default route found: interface eth0, gateway 192.168.90.1
2021-08-01 13:28:59.53381659 CDT 2021/08/01 13:28:59 INFO routing: local ethernet link found: gretap0
2021-08-01 13:28:59.53384750 CDT 2021/08/01 13:28:59 INFO routing: local ethernet link found: erspan0
2021-08-01 13:28:59.53385326 CDT 2021/08/01 13:28:59 INFO routing: local ethernet link found: eth0
2021-08-01 13:28:59.53385833 CDT 2021/08/01 13:28:59 INFO routing: local ipnet found: 192.168.90.0/24
2021-08-01 13:28:59.53536302 CDT 2021/08/01 13:28:59 INFO routing: default route found: interface eth0, gateway 192.168.90.1
2021-08-01 13:28:59.53541739 CDT 2021/08/01 13:28:59 INFO routing: adding route for 0.0.0.0/0
2021-08-01 13:28:59.53548893 CDT 2021/08/01 13:28:59 INFO firewall: firewall disabled, only updating allowed subnets internal list
2021-08-01 13:28:59.53555319 CDT 2021/08/01 13:28:59 INFO routing: default route found: interface eth0, gateway 192.168.90.1
2021-08-01 13:28:59.53556203 CDT 2021/08/01 13:28:59 INFO openvpn configurator: checking for device /dev/net/tun
2021-08-01 13:28:59.53558253 CDT 2021/08/01 13:28:59 WARN TUN device is not available: open /dev/net/tun: no such file or directory
2021-08-01 13:28:59.53558906 CDT 2021/08/01 13:28:59 INFO openvpn configurator: creating /dev/net/tun
2021-08-01 13:28:59.53564505 CDT 2021/08/01 13:28:59 INFO firewall: enabling...
2021-08-01 13:28:59.54671442 CDT 2021/08/01 13:28:59 INFO firewall: enabled successfully
2021-08-01 13:28:59.54680754 CDT 2021/08/01 13:28:59 INFO healthcheck: listening on 127.0.0.1:9999
2021-08-01 13:28:59.54685806 CDT 2021/08/01 13:28:59 INFO http proxy: listening on :1080
2021-08-01 13:28:59.54686524 CDT 2021/08/01 13:28:59 INFO dns over tls: using plaintext DNS at address 1.1.1.1
2021-08-01 13:28:59.54690721 CDT 2021/08/01 13:28:59 INFO http server: listening on :8000
2021-08-01 13:28:59.54704620 CDT 2021/08/01 13:28:59 INFO firewall: setting VPN connection through firewall...
2021-08-01 13:28:59.54796676 CDT 2021/08/01 13:28:59 INFO openvpn configurator: starting OpenVPN 2.5
2021-08-01 13:28:59.54979165 CDT 2021/08/01 13:28:59 INFO openvpn: 2021-08-01 13:28:59 DEPRECATED OPTION: ncp-disable. Disabling cipher negotiation is a deprecated debug feature that will be removed in OpenVPN 2.6
2021-08-01 13:28:59.54984936 CDT 2021/08/01 13:28:59 INFO openvpn: OpenVPN 2.5.2 x86_64-alpine-linux-musl [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [MH/PKTINFO] [AEAD] built on May  4 2021
2021-08-01 13:28:59.54985923 CDT 2021/08/01 13:28:59 INFO openvpn: library versions: OpenSSL 1.1.1k  25 Mar 2021, LZO 2.10
2021-08-01 13:28:59.55049440 CDT 2021/08/01 13:28:59 INFO openvpn: TCP/UDP: Preserving recently used remote address: [AF_INET]71.19.251.152:443
2021-08-01 13:28:59.55051081 CDT 2021/08/01 13:28:59 INFO openvpn: UDP link local: (not bound)
2021-08-01 13:28:59.55051584 CDT 2021/08/01 13:28:59 INFO openvpn: UDP link remote: [AF_INET]71.19.251.152:443
2021-08-01 13:29:00.05054065 CDT 2021/08/01 13:29:00 WARN openvpn: 'link-mtu' is used inconsistently, local='link-mtu 1601', remote='link-mtu 1550'
2021-08-01 13:29:00.05056823 CDT 2021/08/01 13:29:00 WARN openvpn: 'auth' is used inconsistently, local='auth SHA512', remote='auth [null-digest]'
2021-08-01 13:29:00.05057530 CDT 2021/08/01 13:29:00 WARN openvpn: 'comp-lzo' is present in remote config but missing in local config, remote='comp-lzo'
2021-08-01 13:29:00.05063475 CDT 2021/08/01 13:29:00 INFO openvpn: [yvr-187.windscribe.com] Peer Connection Initiated with [AF_INET]71.19.251.152:443
2021-08-01 13:29:01.33405524 CDT 2021/08/01 13:29:01 INFO openvpn: TUN/TAP device tun0 opened
2021-08-01 13:29:01.33410087 CDT 2021/08/01 13:29:01 INFO openvpn: /sbin/ip link set dev tun0 up mtu 1500
2021-08-01 13:29:01.33703794 CDT 2021/08/01 13:29:01 INFO openvpn: /sbin/ip link set dev tun0 up
2021-08-01 13:29:01.33781598 CDT 2021/08/01 13:29:01 INFO openvpn: /sbin/ip addr add dev tun0 10.123.34.10/23
2021-08-01 13:29:01.34023945 CDT 2021/08/01 13:29:01 INFO openvpn: Initialization Sequence Completed
2021-08-01 13:29:01.34041090 CDT 2021/08/01 13:29:01 INFO VPN routing IP address: 71.19.251.152
2021-08-01 13:29:01.34043593 CDT 2021/08/01 13:29:01 INFO dns over tls: downloading DNS over TLS cryptographic files
2021-08-01 13:29:01.61893107 CDT 2021/08/01 13:29:01 INFO healthcheck: healthy!
2021-08-01 13:29:02.54483071 CDT 2021/08/01 13:29:02 INFO dns over tls: downloading hostnames and IP block lists
2021-08-01 13:29:02.57052436 CDT 2021/08/01 13:29:02 INFO dns over tls: init module 0: validator
2021-08-01 13:29:02.57060186 CDT 2021/08/01 13:29:02 INFO dns over tls: init module 1: iterator
2021-08-01 13:29:02.61068452 CDT 2021/08/01 13:29:02 INFO dns over tls: start of service (unbound 1.13.1).
2021-08-01 13:29:03.16770085 CDT 2021/08/01 13:29:03 INFO dns over tls: generate keytag query _ta-4a5c-4f66. NULL IN
2021-08-01 13:29:03.16812771 CDT 2021/08/01 13:29:03 INFO dns over tls: generate keytag query _ta-4a5c-4f66. NULL IN
2021-08-01 13:29:03.80994497 CDT 2021/08/01 13:29:03 INFO dns over tls: ready
2021-08-01 13:29:06.54683629 CDT 2021/08/01 13:29:06 INFO ip getter: Public IP address is 71.19.251.157 (Canada, British Columbia, Vancouver)
2021-08-01 13:35:01.74247633 CDT 2021/08/01 13:35:01 INFO openvpn: stopping
2021-08-01 13:35:01.76006900 CDT 2021/08/01 13:35:01 INFO http server: 200 PUT /status wrote 22B to 192.168.90.51:60010 in 17.674267ms
2021-08-01 13:35:03.42273483 CDT 2021/08/01 13:35:03 INFO openvpn: starting
2021-08-01 13:35:03.42290941 CDT 2021/08/01 13:35:03 INFO firewall: setting VPN connection through firewall...
2021-08-01 13:35:03.42413672 CDT 2021/08/01 13:35:03 INFO openvpn configurator: starting OpenVPN 2.5
2021-08-01 13:35:03.42439912 CDT 2021/08/01 13:35:03 INFO http server: 200 PUT /status wrote 22B to 192.168.90.51:60020 in 1.733442ms
2021-08-01 13:35:03.42561508 CDT 2021/08/01 13:35:03 INFO openvpn: 2021-08-01 13:35:03 DEPRECATED OPTION: ncp-disable. Disabling cipher negotiation is a deprecated debug feature that will be removed in OpenVPN 2.6
2021-08-01 13:35:03.42569893 CDT 2021/08/01 13:35:03 INFO openvpn: OpenVPN 2.5.2 x86_64-alpine-linux-musl [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [MH/PKTINFO] [AEAD] built on May  4 2021
2021-08-01 13:35:03.42571217 CDT 2021/08/01 13:35:03 INFO openvpn: library versions: OpenSSL 1.1.1k  25 Mar 2021, LZO 2.10
2021-08-01 13:35:03.42630728 CDT 2021/08/01 13:35:03 INFO openvpn: TCP/UDP: Preserving recently used remote address: [AF_INET]208.78.41.162:443
2021-08-01 13:35:03.42631947 CDT 2021/08/01 13:35:03 INFO openvpn: UDP link local: (not bound)
2021-08-01 13:35:03.42632341 CDT 2021/08/01 13:35:03 INFO openvpn: UDP link remote: [AF_INET]208.78.41.162:443
2021-08-01 13:35:03.85325966 CDT 2021/08/01 13:35:03 WARN openvpn: 'link-mtu' is used inconsistently, local='link-mtu 1601', remote='link-mtu 1550'
2021-08-01 13:35:03.85327697 CDT 2021/08/01 13:35:03 WARN openvpn: 'auth' is used inconsistently, local='auth SHA512', remote='auth [null-digest]'
2021-08-01 13:35:03.85328113 CDT 2021/08/01 13:35:03 WARN openvpn: 'comp-lzo' is present in remote config but missing in local config, remote='comp-lzo'
2021-08-01 13:35:03.85330830 CDT 2021/08/01 13:35:03 INFO openvpn: [yvr-311.windscribe.com] Peer Connection Initiated with [AF_INET]208.78.41.162:443
2021-08-01 13:35:05.19355765 CDT 2021/08/01 13:35:05 INFO openvpn: TUN/TAP device tun0 opened
2021-08-01 13:35:05.19358659 CDT 2021/08/01 13:35:05 INFO openvpn: /sbin/ip link set dev tun0 up mtu 1500
2021-08-01 13:35:05.19439542 CDT 2021/08/01 13:35:05 INFO openvpn: /sbin/ip link set dev tun0 up
2021-08-01 13:35:05.19513848 CDT 2021/08/01 13:35:05 INFO openvpn: /sbin/ip addr add dev tun0 10.120.130.20/23
2021-08-01 13:35:05.19806688 CDT 2021/08/01 13:35:05 INFO openvpn: Initialization Sequence Completed
2021-08-01 13:35:05.19824787 CDT 2021/08/01 13:35:05 INFO VPN routing IP address: 71.19.251.152
2021-08-01 13:35:05.76107337 CDT 2021/08/01 13:35:05 INFO ip getter: Public IP address is 208.78.41.171 (Canada, British Columbia, Vancouver)
2021-08-01 13:40:54.25226655 CDT 2021/08/01 13:40:54 INFO openvpn: stopping
2021-08-01 13:40:54.27610957 CDT 2021/08/01 13:40:54 INFO http server: 200 PUT /status wrote 22B to 192.168.90.51:41038 in 23.882269ms
2021-08-01 13:40:55.96284995 CDT 2021/08/01 13:40:55 INFO openvpn: starting
2021-08-01 13:40:55.96306888 CDT 2021/08/01 13:40:55 INFO firewall: setting VPN connection through firewall...
2021-08-01 13:40:55.96453734 CDT 2021/08/01 13:40:55 INFO openvpn configurator: starting OpenVPN 2.5
2021-08-01 13:40:55.96478169 CDT 2021/08/01 13:40:55 INFO http server: 200 PUT /status wrote 22B to 192.168.90.51:41062 in 1.984712ms
2021-08-01 13:40:55.96637582 CDT 2021/08/01 13:40:55 INFO openvpn: 2021-08-01 13:40:55 DEPRECATED OPTION: ncp-disable. Disabling cipher negotiation is a deprecated debug feature that will be removed in OpenVPN 2.6
2021-08-01 13:40:55.96651223 CDT 2021/08/01 13:40:55 INFO openvpn: OpenVPN 2.5.2 x86_64-alpine-linux-musl [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [MH/PKTINFO] [AEAD] built on May  4 2021
2021-08-01 13:40:55.96652208 CDT 2021/08/01 13:40:55 INFO openvpn: library versions: OpenSSL 1.1.1k  25 Mar 2021, LZO 2.10
2021-08-01 13:40:55.96778958 CDT 2021/08/01 13:40:55 INFO openvpn: TCP/UDP: Preserving recently used remote address: [AF_INET]198.8.92.98:443
2021-08-01 13:40:55.96780688 CDT 2021/08/01 13:40:55 INFO openvpn: UDP link local: (not bound)
2021-08-01 13:40:55.96784508 CDT 2021/08/01 13:40:55 INFO openvpn: UDP link remote: [AF_INET]198.8.92.98:443
2021-08-01 13:40:56.31508017 CDT 2021/08/01 13:40:56 WARN openvpn: 'link-mtu' is used inconsistently, local='link-mtu 1601', remote='link-mtu 1550'
2021-08-01 13:40:56.31510733 CDT 2021/08/01 13:40:56 WARN openvpn: 'auth' is used inconsistently, local='auth SHA512', remote='auth [null-digest]'
2021-08-01 13:40:56.31513401 CDT 2021/08/01 13:40:56 WARN openvpn: 'comp-lzo' is present in remote config but missing in local config, remote='comp-lzo'
2021-08-01 13:40:56.31514341 CDT 2021/08/01 13:40:56 INFO openvpn: [yvr-311.windscribe.com] Peer Connection Initiated with [AF_INET]198.8.92.98:443
2021-08-01 13:40:57.59601850 CDT 2021/08/01 13:40:57 INFO openvpn: TUN/TAP device tun0 opened
2021-08-01 13:40:57.59604159 CDT 2021/08/01 13:40:57 INFO openvpn: /sbin/ip link set dev tun0 up mtu 1500
2021-08-01 13:40:57.59685271 CDT 2021/08/01 13:40:57 INFO openvpn: /sbin/ip link set dev tun0 up
2021-08-01 13:40:57.59764374 CDT 2021/08/01 13:40:57 INFO openvpn: /sbin/ip addr add dev tun0 10.123.202.36/23
2021-08-01 13:40:57.60006926 CDT 2021/08/01 13:40:57 INFO openvpn: Initialization Sequence Completed
2021-08-01 13:40:57.60026335 CDT 2021/08/01 13:40:57 INFO VPN routing IP address: 71.19.251.152
2021-08-01 13:48:41.47543856 CDT 2021/08/01 13:48:41 INFO openvpn: stopping
2021-08-01 13:48:41.48704175 CDT 2021/08/01 13:48:41 INFO http server: 200 PUT /status wrote 22B to 192.168.90.51:53330 in 11.655148ms
2021-08-01 13:48:52.15845180 CDT 2021/08/01 13:48:52 INFO openvpn: starting
2021-08-01 13:48:52.15859975 CDT 2021/08/01 13:48:52 INFO firewall: setting VPN connection through firewall...
2021-08-01 13:48:52.16040429 CDT 2021/08/01 13:48:52 INFO openvpn configurator: starting OpenVPN 2.5
2021-08-01 13:48:52.16071276 CDT 2021/08/01 13:48:52 INFO http server: 200 PUT /status wrote 22B to 192.168.90.51:53598 in 2.310735ms
2021-08-01 13:48:52.16246227 CDT 2021/08/01 13:48:52 INFO openvpn: 2021-08-01 13:48:52 DEPRECATED OPTION: ncp-disable. Disabling cipher negotiation is a deprecated debug feature that will be removed in OpenVPN 2.6
2021-08-01 13:48:52.16253253 CDT 2021/08/01 13:48:52 INFO openvpn: OpenVPN 2.5.2 x86_64-alpine-linux-musl [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [MH/PKTINFO] [AEAD] built on May  4 2021
2021-08-01 13:48:52.16254549 CDT 2021/08/01 13:48:52 INFO openvpn: library versions: OpenSSL 1.1.1k  25 Mar 2021, LZO 2.10
2021-08-01 13:48:52.16351986 CDT 2021/08/01 13:48:52 INFO openvpn: TCP/UDP: Preserving recently used remote address: [AF_INET]208.78.41.131:443
2021-08-01 13:48:52.16353647 CDT 2021/08/01 13:48:52 INFO openvpn: UDP link local: (not bound)
2021-08-01 13:48:52.16358029 CDT 2021/08/01 13:48:52 INFO openvpn: UDP link remote: [AF_INET]208.78.41.131:443
2021-08-01 13:48:52.52248015 CDT 2021/08/01 13:48:52 WARN openvpn: 'link-mtu' is used inconsistently, local='link-mtu 1601', remote='link-mtu 1550'
2021-08-01 13:48:52.52251083 CDT 2021/08/01 13:48:52 WARN openvpn: 'auth' is used inconsistently, local='auth SHA512', remote='auth [null-digest]'
2021-08-01 13:48:52.52251744 CDT 2021/08/01 13:48:52 WARN openvpn: 'comp-lzo' is present in remote config but missing in local config, remote='comp-lzo'
2021-08-01 13:48:52.52262232 CDT 2021/08/01 13:48:52 INFO openvpn: [yvr-311.windscribe.com] Peer Connection Initiated with [AF_INET]208.78.41.131:443
2021-08-01 13:48:53.70091175 CDT 2021/08/01 13:48:53 INFO openvpn: TUN/TAP device tun0 opened
2021-08-01 13:48:53.70094216 CDT 2021/08/01 13:48:53 INFO openvpn: /sbin/ip link set dev tun0 up mtu 1500
2021-08-01 13:48:53.70173483 CDT 2021/08/01 13:48:53 INFO openvpn: /sbin/ip link set dev tun0 up
2021-08-01 13:48:53.70244203 CDT 2021/08/01 13:48:53 INFO openvpn: /sbin/ip addr add dev tun0 10.120.122.34/23
2021-08-01 13:48:53.70451519 CDT 2021/08/01 13:48:53 INFO openvpn: Initialization Sequence Completed

Below is another time it hung. I tried to toggle the above success, but then it failed the second time I toggled. The container shows as healthy in portainer but curling through the container times out. This is the only line added to the log.

2021-08-01 13:58:48.79466751 CDT 2021/08/01 13:58:48 INFO openvpn: stopping