Program has been unhealthy

[INeido]

I am repeatedly getting the following error:
INFO healthcheck: program has been unhealthy for 21s: restarting OpenVPN

Not even sure where to start looking. The authentication works, the connection is also okey. Are there maybe more detailed logs hidden somewhere?

I am using qmcgaw/private-internet-access

[qdm12]

I need more information. Share all your logs at least?

[INeido]

Oh, of course, sorry.
Here you go:

2021/09/10 18:23:38 INFO Alpine version: 3.14.2
2021/09/10 18:23:38 INFO OpenVPN 2.4 version: 2.4.11
2021/09/10 18:23:38 INFO OpenVPN 2.5 version: 2.5.2
2021/09/10 18:23:38 INFO Unbound version: 1.13.2
2021/09/10 18:23:38 INFO IPtables version: v1.8.7
2021/09/10 18:23:38 INFO Settings summary below:
|--VPN:
   |--Type: openvpn
   |--OpenVPN:
      |--Version: 2.5
      |--Verbosity level: 1
      |--Network interface: tun0
      |--Run as root: enabled
      |--Encryption preset: strong
   |--Private Internet Access settings:
      |--OpenVPN selection:
         |--Protocol: udp
         |--PIA encryption preset: strong
|--DNS:
   |--Plaintext address: 1.1.1.1
   |--DNS over TLS:
      |--Unbound:
          |--DNS over TLS providers:
              |--Cloudflare
          |--Listening port: 53
          |--Access control:
              |--Allowed:
                  |--0.0.0.0/0
                  |--::/0
          |--Caching: enabled
          |--IPv4 resolution: enabled
          |--IPv6 resolution: disabled
          |--Verbosity level: 1/5
          |--Verbosity details level: 0/4
          |--Validation log level: 0/2
          |--Username: 
      |--Blacklist:
         |--Blocked categories: malicious
         |--Additional IP networks blocked: 13
      |--Update: every 24h0m0s
|--Firewall:
   |--Outbound subnets: 192.168.1.0/24
|--Log:
   |--Level: INFO
|--System:
   |--Process user ID: 1000
   |--Process group ID: 1000
   |--Timezone: europe/london
|--Health:
   |--Server address: 127.0.0.1:9999
   |--OpenVPN:
      |--Initial duration: 6s
      |--Addition duration: 5s
|--HTTP control server:
   |--Listening port: 8000
   |--Logging: enabled
|--Public IP getter:
   |--Fetch period: 12h0m0s
   |--IP file: /tmp/gluetun/ip
2021/09/10 18:23:38 INFO routing: default route found: interface eth0, gateway 172.17.0.1
2021/09/10 18:23:38 INFO routing: adding route for 0.0.0.0/0
2021/09/10 18:23:38 INFO firewall: firewall disabled, only updating allowed subnets internal list
2021/09/10 18:23:38 INFO routing: default route found: interface eth0, gateway 172.17.0.1
2021/09/10 18:23:38 INFO routing: adding route for 192.168.1.0/24
2021/09/10 18:23:38 INFO TUN device is not available: open /dev/net/tun: no such file or directory; creating it...
2021/09/10 18:23:38 INFO firewall: enabling...
2021/09/10 18:23:38 INFO firewall: enabled successfully
2021/09/10 18:23:38 INFO dns over tls: using plaintext DNS at address 1.1.1.1
2021/09/10 18:23:38 INFO healthcheck: listening on 127.0.0.1:9999
2021/09/10 18:23:38 INFO http server: listening on :8000
2021/09/10 18:23:39 INFO firewall: setting VPN connection through firewall...
2021/09/10 18:23:39 INFO vpn: 2021-09-10 18:23:39 DEPRECATED OPTION: ncp-disable. Disabling cipher negotiation is a deprecated debug feature that will be removed in OpenVPN 2.6
2021/09/10 18:23:39 WARN vpn: file '/etc/openvpn/auth.conf' is group or others accessible
2021/09/10 18:23:39 INFO vpn: OpenVPN 2.5.2 x86_64-alpine-linux-musl [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [MH/PKTINFO] [AEAD] built on May  4 2021
2021/09/10 18:23:39 INFO vpn: library versions: OpenSSL 1.1.1l  24 Aug 2021, LZO 2.10
2021/09/10 18:23:39 INFO vpn: CRL: loaded 1 CRLs from file -----BEGIN X509 CRL-----
2021/09/10 18:23:39 INFO vpn: **_LONG KEY_**
2021/09/10 18:23:39 INFO vpn: -----END X509 CRL-----
2021/09/10 18:23:39 INFO vpn: TCP/UDP: Preserving recently used remote address: [AF_INET]86.106.74.117:1197
2021/09/10 18:23:39 INFO vpn: UDP link local: (not bound)
2021/09/10 18:23:39 INFO vpn: UDP link remote: [AF_INET]86.106.74.117:1197
2021/09/10 18:23:44 INFO healthcheck: program has been unhealthy for 6s: restarting OpenVPN
2021/09/10 18:23:44 INFO vpn: stopping
2021/09/10 18:23:44 INFO vpn: starting
2021/09/10 18:23:44 INFO firewall: setting VPN connection through firewall...
2021/09/10 18:23:45 INFO vpn: 2021-09-10 18:23:45 DEPRECATED OPTION: ncp-disable. Disabling cipher negotiation is a deprecated debug feature that will be removed in OpenVPN 2.6
2021/09/10 18:23:45 WARN vpn: file '/etc/openvpn/auth.conf' is group or others accessible
2021/09/10 18:23:45 INFO vpn: OpenVPN 2.5.2 x86_64-alpine-linux-musl [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [MH/PKTINFO] [AEAD] built on May  4 2021
2021/09/10 18:23:45 INFO vpn: library versions: OpenSSL 1.1.1l  24 Aug 2021, LZO 2.10
2021/09/10 18:23:45 INFO vpn: CRL: loaded 1 CRLs from file -----BEGIN X509 CRL-----
2021/09/10 18:23:45 INFO vpn: **_LONG KEY_**
2021/09/10 18:23:45 INFO vpn: -----END X509 CRL-----
2021/09/10 18:23:45 INFO vpn: TCP/UDP: Preserving recently used remote address: [AF_INET]5.253.204.105:1197
2021/09/10 18:23:45 INFO vpn: UDP link local: (not bound)
2021/09/10 18:23:45 INFO vpn: UDP link remote: [AF_INET]5.253.204.105:1197
2021/09/10 18:23:56 INFO healthcheck: program has been unhealthy for 11s: restarting OpenVPN
2021/09/10 18:23:56 INFO vpn: stopping

I replaced the CLR, not sure if its a security issue to post if here. But if I am correct, they are newly generated every time? Better safe than sorry.

[qdm12]

It's not private. If you are wondering, you can search through the gluetun repo and you'll find it's hardcoded in the repository. But we don't need it anyway so no worry 😉

But I don't see anything really, it seems to just not connect at all.

[INeido]

I hope noone saw my answer stating I found the cause, because I didn't. I don't know if I got lucky and it was just a coincidence, but when I also added qBittorrent to the compose, it worked once. Since then it doesn't anymore. The error message is the same, I guess I got lucky that one time?

@qdm12 If you need more info, please tell me.

[qdm12]

Try setting a REGION (see the list of servers: https://github.com/qdm12/gluetun/wiki/Private-Internet-Access-Servers), maybe one of their servers is unreachable?

Also you can try setting HEALTH_OPENVPN_DURATION_INITIAL=80s to wait longer for openvpn before restarting it.