Docker-transmission-openvpn: OpenVpn Connection Lost due to failed resolving host

Created on 30 Jul 2020  路  16Comments  路  Source: haugene/docker-transmission-openvpn

Describe the problem

The Vpn will timeout due to inactivity and tried to restart but will eventually fail in the loop of can not resolve the hostname to the VPN address.
It will recover after a manual restart of the docker container without having to make any other changes. The internet is online all the time with other services/container have no issue.
Add your docker run command

sudo docker run -d \
    --cap-add=NET_ADMIN \
    --device=/dev/net/tun \
    -v /volume1/networkconfig/resolv.conf:/etc/resolv.conf \
    -v /volume1/docker/transmission/data/:/data \
    -v /volume1/docker/transmission/config/:/etc/openvpn/custom/ \
    -v /volume1/hdhome:/hdhome \
    -e "TRANSMISSION_WEB_UI=transmission-web-control" \
    -e "OPENVPN_PROVIDER=CUSTOM" \
    -e "OPENVPN_USERNAME=*************" \
    -e "OPENVPN_PASSWORD=*************" \
    -e "LOCAL_NETWORK=192.168.0.0/24" \
    -e "OPENVPN_OPTS=--inactive 3600 --ping 10 --ping-exit 60" \
    -e "PGID=100" \
    -e "PUID=1028" \
    -p 9091:9091 \
    --sysctl net.ipv6.conf.all.disable_ipv6=0 \
    --name "transmission-openvpn-syno" \
    haugene/transmission-openvpn:latest

The command is modified from https://haugene.github.io/docker-transmission-openvpn/synology-nas/

Logs

The full logs are too long to be put in the comment, please see the logs file upload.
trans.logs.txt
Here are some hight lights from the logs:

Wed Jul 22 02:41:39 2020 SIGUSR1[soft,ping-restart] received, process restarting
Wed Jul 22 02:41:39 2020 Restart pause, 5 second(s)
Wed Jul 22 02:41:44 2020 WARNING: --ns-cert-type is DEPRECATED.  Use --remote-cert-tls instead.
Wed Jul 22 02:41:44 2020 NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Wed Jul 22 02:41:44 2020 TCP/UDP: Preserving recently used remote address: [AF_INET]45.41.180.33:1195
Wed Jul 22 02:41:44 2020 Socket Buffers: R=[212992->425984] S=[212992->425984]
Wed Jul 22 02:41:44 2020 UDP link local: (not bound)
Wed Jul 22 02:41:44 2020 UDP link remote: [AF_INET]45.41.180.33:1195
Wed Jul 22 02:41:46 2020 TLS: Initial packet from [AF_INET]45.41.180.33:1195, sid=3491a34b fad64595
Wed Jul 22 02:41:46 2020 VERIFY OK: depth=1, C=VG, ST=BVI, O=ExpressVPN, OU=ExpressVPN, CN=ExpressVPN CA, [email protected]
Wed Jul 22 02:41:46 2020 VERIFY OK: nsCertType=SERVER
Wed Jul 22 02:41:46 2020 VERIFY X509NAME OK: C=VG, ST=BVI, O=ExpressVPN, OU=ExpressVPN, CN=Server-8266-0a, [email protected]
Wed Jul 22 02:41:46 2020 VERIFY OK: depth=0, C=VG, ST=BVI, O=ExpressVPN, OU=ExpressVPN, CN=Server-8266-0a, [email protected]
Wed Jul 22 02:41:46 2020 Control Channel: TLSv1.3, cipher TLSv1.3 TLS_AES_256_GCM_SHA384, 2048 bit RSA
Wed Jul 22 02:41:46 2020 [Server-8266-0a] Peer Connection Initiated with [AF_INET]45.41.180.33:1195
Wed Jul 22 02:41:48 2020 SENT CONTROL [Server-8266-0a]: 'PUSH_REQUEST' (status=1)
Wed Jul 22 02:41:48 2020 PUSH: Received control message: 'PUSH_REPLY,redirect-gateway def1,dhcp-option DNS 10.160.0.1,comp-lzo no,route 10.160.0.1,topology net30,ping 10,ping-restart 60,ifconfig 10.160.0.150 10.160.0.149,peer-id 42,cipher AES-256-GCM'
Wed Jul 22 02:41:48 2020 OPTIONS IMPORT: timers and/or timeouts modified
Wed Jul 22 02:41:48 2020 OPTIONS IMPORT: compression parms modified
Wed Jul 22 02:41:48 2020 OPTIONS IMPORT: --ifconfig/up options modified
Wed Jul 22 02:41:48 2020 OPTIONS IMPORT: route options modified
Wed Jul 22 02:41:48 2020 OPTIONS IMPORT: --ip-win32 and/or --dhcp-option options modified
Wed Jul 22 02:41:48 2020 OPTIONS IMPORT: peer-id set
Wed Jul 22 02:41:48 2020 OPTIONS IMPORT: adjusting link_mtu to 1629
Wed Jul 22 02:41:48 2020 OPTIONS IMPORT: data channel crypto options modified
Wed Jul 22 02:41:48 2020 Data Channel: using negotiated cipher 'AES-256-GCM'
Wed Jul 22 02:41:48 2020 NCP: overriding user-set keysize with default
Wed Jul 22 02:41:48 2020 Outgoing Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
Wed Jul 22 02:41:48 2020 Incoming Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
Wed Jul 22 02:41:48 2020 Preserving previous TUN/TAP instance: tun0
Wed Jul 22 02:41:48 2020 NOTE: Pulled options changed on restart, will need to close and reopen TUN/TAP device.
Wed Jul 22 02:41:48 2020 /sbin/ip route del 10.160.0.1/32
Wed Jul 22 02:41:48 2020 /sbin/ip route del 45.41.180.33/32
Wed Jul 22 02:41:48 2020 /sbin/ip route del 0.0.0.0/1
Wed Jul 22 02:41:48 2020 /sbin/ip route del 128.0.0.0/1
Wed Jul 22 02:41:48 2020 Closing TUN/TAP interface
Wed Jul 22 02:41:48 2020 /sbin/ip addr del dev tun0 local 10.160.0.82 peer 10.160.0.81
Wed Jul 22 02:41:48 2020 /etc/openvpn/tunnelDown.sh tun0 1500 1557 10.160.0.82 10.160.0.81 init
Wed Jul 22 02:41:49 2020 ROUTE_GATEWAY 172.17.0.1/255.255.0.0 IFACE=eth0 HWADDR=02:42:ac:11:00:02
Wed Jul 22 02:41:49 2020 TUN/TAP device tun0 opened
Wed Jul 22 02:41:49 2020 TUN/TAP TX queue length set to 100
Wed Jul 22 02:41:49 2020 /sbin/ip link set dev tun0 up mtu 1500
Wed Jul 22 02:41:49 2020 /sbin/ip addr add dev tun0 local 10.160.0.150 peer 10.160.0.149
Wed Jul 22 02:41:49 2020 /etc/openvpn/tunnelUp.sh tun0 1500 1557 10.160.0.150 10.160.0.149 init
Up script executed with tun0 1500 1557 10.160.0.150 10.160.0.149 init
Updating TRANSMISSION_BIND_ADDRESS_IPV4 to the ip of tun0 : 10.160.0.150
Using Transmission Web Control  UI, overriding TRANSMISSION_WEB_HOME
Generating transmission settings.json from env variables
sed'ing True to true
Enforcing ownership on transmission config directories
Applying permissions to transmission config directories
Setting owner for transmission paths to 1028:100
Setting permission for files (644) and directories (755)
Setting permission for watch directory (775) and its files (664)

-------------------------------------
Transmission will run as
-------------------------------------
User name:   abc
User uid:    1028
User gid:    100
-------------------------------------

STARTING TRANSMISSION
NO PORT UPDATER FOR THIS PROVIDER
Transmission startup script complete.
Wed Jul 22 02:41:52 2020 /sbin/ip route add 45.41.180.33/32 via 172.17.0.1
Wed Jul 22 02:41:52 2020 /sbin/ip route add 0.0.0.0/1 via 10.160.0.149
Wed Jul 22 02:41:52 2020 /sbin/ip route add 128.0.0.0/1 via 10.160.0.149
Wed Jul 22 02:41:52 2020 /sbin/ip route add 10.160.0.1/32 via 10.160.0.149
Wed Jul 22 02:41:52 2020 Initialization Sequence Completed
Wed Jul 22 03:41:46 2020 TLS: soft reset sec=0 bytes=1560780573/-1 pkts=2093838/0
Wed Jul 22 03:41:46 2020 VERIFY OK: depth=1, C=VG, ST=BVI, O=ExpressVPN, OU=ExpressVPN, CN=ExpressVPN CA, [email protected]
Wed Jul 22 03:41:46 2020 VERIFY OK: nsCertType=SERVER
Wed Jul 22 03:41:46 2020 VERIFY X509NAME OK: C=VG, ST=BVI, O=ExpressVPN, OU=ExpressVPN, CN=Server-8266-0a, [email protected]
Wed Jul 22 03:41:46 2020 VERIFY OK: depth=0, C=VG, ST=BVI, O=ExpressVPN, OU=ExpressVPN, CN=Server-8266-0a, [email protected]
Wed Jul 22 03:41:46 2020 Outgoing Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
Wed Jul 22 03:41:46 2020 Incoming Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
Wed Jul 22 03:41:46 2020 Control Channel: TLSv1.3, cipher TLSv1.3 TLS_AES_256_GCM_SHA384, 2048 bit RSA
Wed Jul 22 04:41:46 2020 TLS: soft reset sec=0 bytes=1529856050/-1 pkts=2031648/0
Wed Jul 22 04:41:46 2020 VERIFY OK: depth=1, C=VG, ST=BVI, O=ExpressVPN, OU=ExpressVPN, CN=ExpressVPN CA, [email protected]
Wed Jul 22 04:41:46 2020 VERIFY OK: nsCertType=SERVER
Wed Jul 22 04:41:46 2020 VERIFY X509NAME OK: C=VG, ST=BVI, O=ExpressVPN, OU=ExpressVPN, CN=Server-8266-0a, [email protected]
Wed Jul 22 04:41:46 2020 VERIFY OK: depth=0, C=VG, ST=BVI, O=ExpressVPN, OU=ExpressVPN, CN=Server-8266-0a, [email protected]
Wed Jul 22 04:41:46 2020 Outgoing Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
Wed Jul 22 04:41:46 2020 Incoming Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
----
Tue Jul 28 18:41:46 2020 VERIFY X509NAME OK: C=VG, ST=BVI, O=ExpressVPN, OU=ExpressVPN, CN=Server-8266-0a, [email protected]
Tue Jul 28 18:41:46 2020 VERIFY OK: depth=0, C=VG, ST=BVI, O=ExpressVPN, OU=ExpressVPN, CN=Server-8266-0a, [email protected]
Tue Jul 28 18:41:46 2020 Outgoing Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
Tue Jul 28 18:41:46 2020 Incoming Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
Tue Jul 28 18:41:46 2020 Control Channel: TLSv1.3, cipher TLSv1.3 TLS_AES_256_GCM_SHA384, 2048 bit RSA
Tue Jul 28 19:02:43 2020 [Server-8266-0a] Inactivity timeout (--ping-restart), restarting
Tue Jul 28 19:02:43 2020 SIGUSR1[soft,ping-restart] received, process restarting
Tue Jul 28 19:02:43 2020 Restart pause, 5 second(s)
Tue Jul 28 19:02:48 2020 WARNING: --ns-cert-type is DEPRECATED.  Use --remote-cert-tls instead.
Tue Jul 28 19:02:48 2020 NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Tue Jul 28 19:02:48 2020 TCP/UDP: Preserving recently used remote address: [AF_INET]45.41.180.33:1195
Tue Jul 28 19:02:48 2020 Socket Buffers: R=[212992->425984] S=[212992->425984]
Tue Jul 28 19:02:48 2020 UDP link local: (not bound)
Tue Jul 28 19:02:48 2020 UDP link remote: [AF_INET]45.41.180.33:1195
Tue Jul 28 19:03:48 2020 [UNDEF] Inactivity timeout (--ping-restart), restarting
Tue Jul 28 19:03:48 2020 SIGUSR1[soft,ping-restart] received, process restarting
Tue Jul 28 19:03:48 2020 Restart pause, 5 second(s)
Tue Jul 28 19:03:53 2020 WARNING: --ns-cert-type is DEPRECATED.  Use --remote-cert-tls instead.
Tue Jul 28 19:03:53 2020 NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Tue Jul 28 19:03:53 2020 TCP/UDP: Preserving recently used remote address: [AF_INET]45.41.180.3:1195
Tue Jul 28 19:03:53 2020 Socket Buffers: R=[212992->425984] S=[212992->425984]
Tue Jul 28 19:03:53 2020 UDP link local: (not bound)
Tue Jul 28 19:03:53 2020 UDP link remote: [AF_INET]45.41.180.3:1195
Tue Jul 28 19:04:54 2020 [UNDEF] Inactivity timeout (--ping-restart), restarting
Tue Jul 28 19:04:54 2020 SIGUSR1[soft,ping-restart] received, process restarting
Tue Jul 28 19:04:54 2020 Restart pause, 5 second(s)
Tue Jul 28 19:04:59 2020 WARNING: --ns-cert-type is DEPRECATED.  Use --remote-cert-tls instead.
Tue Jul 28 19:04:59 2020 NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Tue Jul 28 19:04:59 2020 TCP/UDP: Preserving recently used remote address: [AF_INET]45.41.180.18:1195
Tue Jul 28 19:04:59 2020 Socket Buffers: R=[212992->425984] S=[212992->425984]
Tue Jul 28 19:04:59 2020 UDP link local: (not bound)
Tue Jul 28 19:04:59 2020 UDP link remote: [AF_INET]45.41.180.18:1195
Tue Jul 28 19:05:59 2020 [UNDEF] Inactivity timeout (--ping-restart), restarting
Tue Jul 28 19:05:59 2020 SIGUSR1[soft,ping-restart] received, process restarting
Tue Jul 28 19:05:59 2020 Restart pause, 5 second(s)
Tue Jul 28 19:06:04 2020 WARNING: --ns-cert-type is DEPRECATED.  Use --remote-cert-tls instead.
Tue Jul 28 19:06:04 2020 NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Tue Jul 28 19:06:04 2020 TCP/UDP: Preserving recently used remote address: [AF_INET]45.41.180.48:1195
Tue Jul 28 19:06:04 2020 Socket Buffers: R=[212992->425984] S=[212992->425984]
Tue Jul 28 19:06:04 2020 UDP link local: (not bound)
Tue Jul 28 19:06:04 2020 UDP link remote: [AF_INET]45.41.180.48:1195
Tue Jul 28 19:07:04 2020 [UNDEF] Inactivity timeout (--ping-restart), restarting
Tue Jul 28 19:07:04 2020 SIGUSR1[soft,ping-restart] received, process restarting
Tue Jul 28 19:07:04 2020 Restart pause, 5 second(s)
Tue Jul 28 19:07:09 2020 WARNING: --ns-cert-type is DEPRECATED.  Use --remote-cert-tls instead.
Tue Jul 28 19:07:09 2020 NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Tue Jul 28 19:07:09 2020 TCP/UDP: Preserving recently used remote address: [AF_INET]45.41.180.63:1195
Tue Jul 28 19:07:09 2020 Socket Buffers: R=[212992->425984] S=[212992->425984]
Tue Jul 28 19:07:09 2020 UDP link local: (not bound)
Tue Jul 28 19:07:09 2020 UDP link remote: [AF_INET]45.41.180.63:1195
Tue Jul 28 19:08:09 2020 [UNDEF] Inactivity timeout (--ping-restart), restarting
Tue Jul 28 19:08:09 2020 SIGUSR1[soft,ping-restart] received, process restarting
Tue Jul 28 19:08:09 2020 Restart pause, 5 second(s)
Tue Jul 28 19:08:14 2020 WARNING: --ns-cert-type is DEPRECATED.  Use --remote-cert-tls instead.
Tue Jul 28 19:08:14 2020 NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Tue Jul 28 19:08:34 2020 RESOLVE: Cannot resolve host address: usa-washingtondc-ca-version-2.expressnetw.com:1195 (Temporary failure in name resolution)
Tue Jul 28 19:08:54 2020 RESOLVE: Cannot resolve host address: usa-washingtondc-ca-version-2.expressnetw.com:1195 (Temporary failure in name resolution)
Tue Jul 28 19:08:54 2020 Could not determine IPv4/IPv6 protocol
Tue Jul 28 19:08:54 2020 SIGUSR1[soft,init_instance] received, process restarting
Tue Jul 28 19:08:54 2020 Restart pause, 5 second(s)
Tue Jul 28 19:08:59 2020 WARNING: --ns-cert-type is DEPRECATED.  Use --remote-cert-tls instead.
Tue Jul 28 19:08:59 2020 NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Tue Jul 28 19:09:19 2020 RESOLVE: Cannot resolve host address: usa-washingtondc-ca-version-2.expressnetw.com:1195 (Temporary failure in name resolution)
Tue Jul 28 19:09:39 2020 RESOLVE: Cannot resolve host address: usa-washingtondc-ca-version-2.expressnetw.com:1195 (Temporary failure in name resolution)
Tue Jul 28 19:09:39 2020 Could not determine IPv4/IPv6 protocol
Tue Jul 28 19:09:39 2020 SIGUSR1[soft,init_instance] received, process restarting
Tue Jul 28 19:09:39 2020 Restart pause, 5 second(s)
Tue Jul 28 19:09:44 2020 WARNING: --ns-cert-type is DEPRECATED.  Use --remote-cert-tls instead.
Tue Jul 28 19:09:44 2020 NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Tue Jul 28 19:10:04 2020 RESOLVE: Cannot resolve host address: usa-washingtondc-ca-version-2.expressnetw.com:1195 (Temporary failure in name resolution)
Tue Jul 28 19:10:24 2020 RESOLVE: Cannot resolve host address: usa-washingtondc-ca-version-2.expressnetw.com:1195 (Temporary failure in name resolution)
Tue Jul 28 19:10:24 2020 Could not determine IPv4/IPv6 protocol
Tue Jul 28 19:10:24 2020 SIGUSR1[soft,init_instance] received, process restarting
Tue Jul 28 19:10:24 2020 Restart pause, 5 second(s)
Tue Jul 28 19:10:29 2020 WARNING: --ns-cert-type is DEPRECATED.  Use --remote-cert-tls instead.
Tue Jul 28 19:10:29 2020 NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Tue Jul 28 19:10:49 2020 RESOLVE: Cannot resolve host address: usa-washingtondc-ca-version-2.expressnetw.com:1195 (Temporary failure in name resolution)
Tue Jul 28 19:11:09 2020 RESOLVE: Cannot resolve host address: usa-washingtondc-ca-version-2.expressnetw.com:1195 (Temporary failure in name resolution)
Tue Jul 28 19:11:09 2020 Could not determine IPv4/IPv6 protocol
Tue Jul 28 19:11:09 2020 SIGUSR1[soft,init_instance] received, process restarting
Tue Jul 28 19:11:09 2020 Restart pause, 5 second(s)
Tue Jul 28 19:11:14 2020 WARNING: --ns-cert-type is DEPRECATED.  Use --remote-cert-tls instead.
Tue Jul 28 19:11:14 2020 NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Tue Jul 28 19:11:34 2020 RESOLVE: Cannot resolve host address: usa-washingtondc-ca-version-2.expressnetw.com:1195 (Temporary failure in name resolution)
Tue Jul 28 19:11:54 2020 RESOLVE: Cannot resolve host address: usa-washingtondc-ca-version-2.expressnetw.com:1195 (Temporary failure in name resolution)
Tue Jul 28 19:11:54 2020 Could not determine IPv4/IPv6 protocol
Tue Jul 28 19:11:54 2020 SIGUSR1[soft,init_instance] received, process restarting
Tue Jul 28 19:11:54 2020 Restart pause, 10 second(s)
Tue Jul 28 19:12:04 2020 WARNING: --ns-cert-type is DEPRECATED.  Use --remote-cert-tls instead.
Tue Jul 28 19:12:04 2020 NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Tue Jul 28 19:12:24 2020 RESOLVE: Cannot resolve host address: usa-washingtondc-ca-version-2.expressnetw.com:1195 (Temporary failure in name resolution)
Tue Jul 28 19:12:44 2020 RESOLVE: Cannot resolve host address: usa-washingtondc-ca-version-2.expressnetw.com:1195 (Temporary failure in name resolution)
Tue Jul 28 19:12:44 2020 Could not determine IPv4/IPv6 protocol
Tue Jul 28 19:12:44 2020 SIGUSR1[soft,init_instance] received, process restarting
Tue Jul 28 19:12:44 2020 Restart pause, 20 second(s)
Tue Jul 28 19:13:04 2020 WARNING: --ns-cert-type is DEPRECATED.  Use --remote-cert-tls instead.
Tue Jul 28 19:13:04 2020 NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Tue Jul 28 19:13:24 2020 RESOLVE: Cannot resolve host address: usa-washingtondc-ca-version-2.expressnetw.com:1195 (Temporary failure in name resolution)
Tue Jul 28 19:13:44 2020 RESOLVE: Cannot resolve host address: usa-washingtondc-ca-version-2.expressnetw.com:1195 (Temporary failure in name resolution)
Tue Jul 28 19:13:44 2020 Could not determine IPv4/IPv6 protocol
Tue Jul 28 19:13:44 2020 SIGUSR1[soft,init_instance] received, process restarting
Tue Jul 28 19:13:44 2020 Restart pause, 40 second(s)
Tue Jul 28 19:14:24 2020 WARNING: --ns-cert-type is DEPRECATED.  Use --remote-cert-tls instead.
Tue Jul 28 19:14:24 2020 NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Tue Jul 28 19:14:44 2020 RESOLVE: Cannot resolve host address: usa-washingtondc-ca-version-2.expressnetw.com:1195 (Temporary failure in name resolution)
Tue Jul 28 19:15:04 2020 RESOLVE: Cannot resolve host address: usa-washingtondc-ca-version-2.expressnetw.com:1195 (Temporary failure in name resolution)
Tue Jul 28 19:15:04 2020 Could not determine IPv4/IPv6 protocol
Tue Jul 28 19:15:04 2020 SIGUSR1[soft,init_instance] received, process restarting
Tue Jul 28 19:15:04 2020 Restart pause, 80 second(s)
Tue Jul 28 19:16:24 2020 WARNING: --ns-cert-type is DEPRECATED.  Use --remote-cert-tls instead.
Tue Jul 28 19:16:24 2020 NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Tue Jul 28 19:16:44 2020 RESOLVE: Cannot resolve host address: usa-washingtondc-ca-version-2.expressnetw.com:1195 (Temporary failure in name resolution)
Tue Jul 28 19:17:04 2020 RESOLVE: Cannot resolve host address: usa-washingtondc-ca-version-2.expressnetw.com:1195 (Temporary failure in name resolution)
Tue Jul 28 19:17:04 2020 Could not determine IPv4/IPv6 protocol
Tue Jul 28 19:17:04 2020 SIGUSR1[soft,init_instance] received, process restarting
Tue Jul 28 19:17:04 2020 Restart pause, 160 second(s)
Tue Jul 28 19:19:44 2020 WARNING: --ns-cert-type is DEPRECATED.  Use --remote-cert-tls instead.
Tue Jul 28 19:19:44 2020 NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Tue Jul 28 19:20:04 2020 RESOLVE: Cannot resolve host address: usa-washingtondc-ca-version-2.expressnetw.com:1195 (Temporary failure in name resolution)
Tue Jul 28 19:20:24 2020 RESOLVE: Cannot resolve host address: usa-washingtondc-ca-version-2.expressnetw.com:1195 (Temporary failure in name resolution)
Tue Jul 28 19:20:24 2020 Could not determine IPv4/IPv6 protocol
Tue Jul 28 19:20:24 2020 SIGUSR1[soft,init_instance] received, process restarting
Tue Jul 28 19:20:24 2020 Restart pause, 300 second(s)
Tue Jul 28 19:25:24 2020 WARNING: --ns-cert-type is DEPRECATED.  Use --remote-cert-tls instead.
Tue Jul 28 19:25:24 2020 NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Tue Jul 28 19:25:44 2020 RESOLVE: Cannot resolve host address: usa-washingtondc-ca-version-2.expressnetw.com:1195 (Temporary failure in name resolution)
Tue Jul 28 19:26:04 2020 RESOLVE: Cannot resolve host address: usa-washingtondc-ca-version-2.expressnetw.com:1195 (Temporary failure in name resolution)
Tue Jul 28 19:26:04 2020 Could not determine IPv4/IPv6 protocol
Tue Jul 28 19:26:04 2020 SIGUSR1[soft,init_instance] received, process restarting
Tue Jul 28 19:26:04 2020 Restart pause, 300 second(s)
----
Wed Jul 29 04:12:27 2020 WARNING: --ns-cert-type is DEPRECATED.  Use --remote-cert-tls instead.
Wed Jul 29 04:12:27 2020 NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Wed Jul 29 04:12:47 2020 RESOLVE: Cannot resolve host address: usa-washingtondc-ca-version-2.expressnetw.com:1195 (Temporary failure in name resolution)
Wed Jul 29 04:13:07 2020 RESOLVE: Cannot resolve host address: usa-washingtondc-ca-version-2.expressnetw.com:1195 (Temporary failure in name resolution)
Wed Jul 29 04:13:07 2020 Could not determine IPv4/IPv6 protocol
Wed Jul 29 04:13:07 2020 SIGUSR1[soft,init_instance] received, process restarting
Wed Jul 29 04:13:07 2020 Restart pause, 300 second(s)
Wed Jul 29 04:18:07 2020 WARNING: --ns-cert-type is DEPRECATED.  Use --remote-cert-tls instead.
Wed Jul 29 04:18:07 2020 NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Wed Jul 29 04:18:27 2020 RESOLVE: Cannot resolve host address: usa-washingtondc-ca-version-2.expressnetw.com:1195 (Temporary failure in name resolution)
Wed Jul 29 04:18:47 2020 RESOLVE: Cannot resolve host address: usa-washingtondc-ca-version-2.expressnetw.com:1195 (Temporary failure in name resolution)
Wed Jul 29 04:18:47 2020 Could not determine IPv4/IPv6 protocol
Wed Jul 29 04:18:47 2020 SIGUSR1[soft,init_instance] received, process restarting
Wed Jul 29 04:18:47 2020 Restart pause, 300 second(s)
Wed Jul 29 04:21:53 2020 /sbin/ip route del 10.160.0.1/32
Wed Jul 29 04:21:53 2020 /sbin/ip route del 45.41.180.33/32
Wed Jul 29 04:21:53 2020 /sbin/ip route del 0.0.0.0/1
Wed Jul 29 04:21:53 2020 /sbin/ip route del 128.0.0.0/1
Wed Jul 29 04:21:53 2020 Closing TUN/TAP interface
Wed Jul 29 04:21:53 2020 /sbin/ip addr del dev tun0 local 10.160.0.150 peer 10.160.0.149
Wed Jul 29 04:21:54 2020 /etc/openvpn/tunnelDown.sh tun0 0 0 10.160.0.150 10.160.0.149 init
Wed Jul 29 04:21:54 2020 SIGTERM[hard,init_instance] received, process exiting
Using OpenVPN provider: CUSTOM
No VPN configuration provided. Using default.
Setting OPENVPN credentials...
adding route to local network 192.168.0.0/24 via 172.17.0.1 dev eth0
Wed Jul 29 04:21:56 2020 WARNING: --keysize is DEPRECATED and will be removed in OpenVPN 2.6
Wed Jul 29 04:21:56 2020 OpenVPN 2.4.7 x86_64-pc-linux-gnu [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [PKCS11] [MH/PKTINFO] [AEAD] built on Sep  5 2019
Wed Jul 29 04:21:56 2020 library versions: OpenSSL 1.1.1c  28 May 2019, LZO 2.10
Wed Jul 29 04:21:56 2020 WARNING: --ns-cert-type is DEPRECATED.  Use --remote-cert-tls instead.
Wed Jul 29 04:21:56 2020 NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Wed Jul 29 04:21:56 2020 Outgoing Control Channel Authentication: Using 512 bit message hash 'SHA512' for HMAC authentication
Wed Jul 29 04:21:56 2020 Incoming Control Channel Authentication: Using 512 bit message hash 'SHA512' for HMAC authentication
Wed Jul 29 04:21:56 2020 TCP/UDP: Preserving recently used remote address: [AF_INET]45.41.180.3:1195
Wed Jul 29 04:21:56 2020 Socket Buffers: R=[212992->425984] S=[212992->425984]
Wed Jul 29 04:21:56 2020 UDP link local: (not bound)
Wed Jul 29 04:21:56 2020 UDP link remote: [AF_INET]45.41.180.3:1195
Wed Jul 29 04:21:56 2020 TLS: Initial packet from [AF_INET]45.41.180.3:1195, sid=2a337209 46ec1eae
Wed Jul 29 04:21:56 2020 WARNING: this configuration may cache passwords in memory -- use the auth-nocache option to prevent this
Wed Jul 29 04:21:56 2020 VERIFY OK: depth=1, C=VG, ST=BVI, O=ExpressVPN, OU=ExpressVPN, CN=ExpressVPN CA, [email protected]
Wed Jul 29 04:21:56 2020 VERIFY OK: nsCertType=SERVER
Wed Jul 29 04:21:56 2020 VERIFY X509NAME OK: C=VG, ST=BVI, O=ExpressVPN, OU=ExpressVPN, CN=Server-8260-0a, [email protected]
Wed Jul 29 04:21:56 2020 VERIFY OK: depth=0, C=VG, ST=BVI, O=ExpressVPN, OU=ExpressVPN, CN=Server-8260-0a, [email protected]
Wed Jul 29 04:21:56 2020 Control Channel: TLSv1.3, cipher TLSv1.3 TLS_AES_256_GCM_SHA384, 2048 bit RSA
Wed Jul 29 04:21:56 2020 [Server-8260-0a] Peer Connection Initiated with [AF_INET]45.41.180.3:1195
Wed Jul 29 04:21:57 2020 SENT CONTROL [Server-8260-0a]: 'PUSH_REQUEST' (status=1)
Wed Jul 29 04:22:02 2020 SENT CONTROL [Server-8260-0a]: 'PUSH_REQUEST' (status=1)
Wed Jul 29 04:22:02 2020 PUSH: Received control message: 'PUSH_REPLY,redirect-gateway def1,dhcp-option DNS 10.49.0.1,comp-lzo no,route 10.49.0.1,topology net30,ping 10,ping-restart 60,ifconfig 10.49.0.194 10.49.0.193,peer-id 43,cipher AES-256-GCM'
Wed Jul 29 04:22:02 2020 OPTIONS IMPORT: timers and/or timeouts modified
Wed Jul 29 04:22:02 2020 OPTIONS IMPORT: compression parms modified
Wed Jul 29 04:22:02 2020 OPTIONS IMPORT: --ifconfig/up options modified
Wed Jul 29 04:22:02 2020 OPTIONS IMPORT: route options modified
Wed Jul 29 04:22:02 2020 OPTIONS IMPORT: --ip-win32 and/or --dhcp-option options modified
Wed Jul 29 04:22:02 2020 OPTIONS IMPORT: peer-id set
Wed Jul 29 04:22:02 2020 OPTIONS IMPORT: adjusting link_mtu to 1629
Wed Jul 29 04:22:02 2020 OPTIONS IMPORT: data channel crypto options modified
Wed Jul 29 04:22:02 2020 Data Channel: using negotiated cipher 'AES-256-GCM'
Wed Jul 29 04:22:02 2020 NCP: overriding user-set keysize with default
Wed Jul 29 04:22:02 2020 Outgoing Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
Wed Jul 29 04:22:02 2020 Incoming Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
Wed Jul 29 04:22:02 2020 ROUTE_GATEWAY 172.17.0.1/255.255.0.0 IFACE=eth0 HWADDR=02:42:ac:11:00:02
Wed Jul 29 04:22:02 2020 TUN/TAP device tun0 opened
Wed Jul 29 04:22:02 2020 TUN/TAP TX queue length set to 100
Wed Jul 29 04:22:02 2020 /sbin/ip link set dev tun0 up mtu 1500
Wed Jul 29 04:22:02 2020 /sbin/ip addr add dev tun0 local 10.49.0.194 peer 10.49.0.193
Wed Jul 29 04:22:02 2020 /etc/openvpn/tunnelUp.sh tun0 1500 1557 10.49.0.194 10.49.0.193 init
Up script executed with tun0 1500 1557 10.49.0.194 10.49.0.193 init
Updating TRANSMISSION_BIND_ADDRESS_IPV4 to the ip of tun0 : 10.49.0.194
Using Transmission Web Control  UI, overriding TRANSMISSION_WEB_HOME
Generating transmission settings.json from env variables
sed'ing True to true
Enforcing ownership on transmission config directories
Applying permissions to transmission config directories
Setting owner for transmission paths to 1028:100
Setting permission for files (644) and directories (755)
Setting permission for watch directory (775) and its files (664)

-------------------------------------
Transmission will run as
-------------------------------------
User name:   abc
User uid:    1028
User gid:    100
-------------------------------------

STARTING TRANSMISSION
NO PORT UPDATER FOR THIS PROVIDER
Transmission startup script complete.
Wed Jul 29 04:22:04 2020 /sbin/ip route add 45.41.180.3/32 via 172.17.0.1
Wed Jul 29 04:22:04 2020 /sbin/ip route add 0.0.0.0/1 via 10.49.0.193
Wed Jul 29 04:22:04 2020 /sbin/ip route add 128.0.0.0/1 via 10.49.0.193
Wed Jul 29 04:22:04 2020 /sbin/ip route add 10.49.0.1/32 via 10.49.0.193
Wed Jul 29 04:22:04 2020 Initialization Sequence Completed
Wed Jul 29 05:21:56 2020 TLS: soft reset sec=0 bytes=58037362/-1 pkts=127596/0
Wed Jul 29 05:21:56 2020 VERIFY OK: depth=1, C=VG, ST=BVI, O=ExpressVPN, OU=ExpressVPN, CN=ExpressVPN CA, [email protected]
Wed Jul 29 05:21:56 2020 VERIFY OK: nsCertType=SERVER
Wed Jul 29 05:21:56 2020 VERIFY X509NAME OK: C=VG, ST=BVI, O=ExpressVPN, OU=ExpressVPN, CN=Server-8260-0a, [email protected]
Wed Jul 29 05:21:56 2020 VERIFY OK: depth=0, C=VG, ST=BVI, O=ExpressVPN, OU=ExpressVPN, CN=Server-8260-0a, [email protected]
Wed Jul 29 05:21:56 2020 Outgoing Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
Wed Jul 29 05:21:56 2020 Incoming Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
Wed Jul 29 05:21:56 2020 Control Channel: TLSv1.3, cipher TLSv1.3 TLS_AES_256_GCM_SHA384, 2048 bit RSA
Wed Jul 29 06:21:56 2020 TLS: soft reset sec=0 bytes=1057507334/-1 pkts=1836170/0
Wed Jul 29 06:21:56 2020 VERIFY OK: depth=1, C=VG, ST=BVI, O=ExpressVPN, OU=ExpressVPN, CN=ExpressVPN CA, [email protected]
Wed Jul 29 06:21:56 2020 VERIFY OK: nsCertType=SERVER

Host system:

Running on Synology NAS DS1819+, Docker version 18.09.0-0513.
VPN provider is ExpressVPN and connects using the CUSTOM setting.

Most helpful comment

So I may have found the reason behind this very annoying behavior, and a fix on this without restarting the whole container. The issue comes down to the TUN dev is hanging. When this happens, the VPN lost connection, so it attempts to reconnect. However, the IP route is still configured to forward traffic to the dead tun0 interface, which of course all the packages will get lost those and it will not be able to resolve any domain name.

Restart the tun inside the container seems to work for me. ip link set tun0 down then ip link set tun0 up. (check the dev with ip link first)

This is because normally inside the container it can not get the status of the tun interface, so you will see something like "tun0: mtu 1500 qdisc pfifo_fast state UNKNOWN mode DEFAULT group default qlen 10000" which the state is unknown. Manually bring down the tun will make the ip route to update, so it stops forward traffic to the dead tun, then container wise the network is back up again.
Note: I have also done some other things during this debug process that may or may not help on this recovery, so if someone can try when it happens and give some feedback would be great. If not I will do more testing next time it happens to nail down what exactly will make it work.
A fix should be relatively easy if the above method work, add in the down scrip to have it bring down and bring back up the tun interface.
@haugene @pkishino

All 16 comments

I can see two issues, one is inactivity disconnect earlier on, then the dns part..
please check if you can resolve the ip inside the container via ssh, and check the /etc/resolver.conf file
I've seen this issue several times on the issue list, sometimes has to do with the provider and or local network/isp settings.. strange

That's correct. I will see what I can find next time it happens and make an update here. I do suspect there is an issue with the local ISP DNS settings as I got some failed DNS probe from the browser from time to time, but usually, a reflash of the page will do the trick.

root@7059ab6ebe51:/etc# cat hosts
127.0.0.1 localhost
::1 localhost ip6-localhost ip6-loopback
fe00::0 ip6-localnet
ff00::0 ip6-mcastprefix
ff02::1 ip6-allnodes
ff02::2 ip6-allrouters
172.17.0.2 7059ab6ebe51
root@7059ab6ebe51:/etc# cat resolv.conf
nameserver 8.8.8.8
nameserver 8.8.4.4
root@7059ab6ebe51:/etc# ping google.com
ping: google.com: Temporary failure in name resolution
root@7059ab6ebe51:/etc# apt-get install dnsutils -y
Reading package lists... Done
Building dependency tree
Reading state information... Done
E: Unable to locate package dnsutils
root@7059ab6ebe51:/etc# apt-get update
Err:1 http://archive.ubuntu.com/ubuntu eoan InRelease
Temporary failure resolving 'archive.ubuntu.com'
Err:2 http://ppa.launchpad.net/transmissionbt/ppa/ubuntu eoan InRelease
Temporary failure resolving 'ppa.launchpad.net'
Err:3 http://security.ubuntu.com/ubuntu eoan-security InRelease
Temporary failure resolving 'security.ubuntu.com'
Err:4 http://archive.ubuntu.com/ubuntu eoan-updates InRelease
Temporary failure resolving 'archive.ubuntu.com'
0% [Working]^C

Yeah. This has been a recurring issue for years. Some containers lose DNS after some period of time.
We have pondered to find a container-local solution, but they get complex. So for now we have a couple of external solutions.

  1. We have a health-check running that will ping google.com regularly and when it fails the container will be marked as unhealthy. Using some sort of container management tool (portainer/watchtower?) this can then trigger a re-start and the conatiner will typically heal.

  2. Set OPENVPN_OPTS: "--inactive 3600 --ping 10 --ping-exit 60" or something similar and then use restart: unless-stopped when starting the container. Then the openvpn daemon will ping the server and exit when that fails. Of course if the server is ip-based then there is no DNS involved. But many of the servers have dns names.

We have been receiving varying responses on both these approaches. I think it works for most people, but others just can't get a stable fix. Some people have set up cron jobs to restart the container on a daily basis.

Would love an update on what you try and how that works. Maybe a section on the problem and alternatives in the github pages if you're up for making a PR.

Thanks for the timely reply. Unfortrnly, keep restarting the container is not desirable in my case. The tracker I mainly using takes hours (maybe 12+) to sync the status of the client. Also, if the Tracker failed, the client has to be running continuously while the tracker is down and attempt the re-sync the status once the Tracker is back online again. That would not work if I have to restart the container from time to time. I will try to do some digging and see if I can try to fix this DNS issue.

That is some very unusual tracker behavior

Putting down some notes.

  1. The permission for the TUN device seems to not set to 755 but remains in 600, however, this does not seem to cause any issue as the OpenVPN was able to open/close TUN without issue. This might be because of the CgroupPermissions of the devices is set to "rwm".
  2. The TUN TX queue length is too small. It was 100 but sometimes it is 10, this cause package dropped on the TUN interface. increase the qlen with ip link set tun0 txqlen 10000 fixed the issue, but will need to fix this for longterm.
  3. This does not seem like a DNS issue only as PING a public IP address still failed inside the container. However, PING the host IP is OK. This might be an issue with the docker network bridge is hanged. Awaiting for it to happen again to do more testing.
  4. An issue here https://github.com/docker/for-win/issues/426#issue-202938307 indicate that there is an issue with docker in windows that cause the network connections to hang, someone can or when I have time can try to see if this issue exists for Linux as well, the issue was closed due to inactive and there is no fix for that yet.
  5. I founded lots of posted discussing the cause of Inactivity timeout, some turn out to be a server-side issue, some said it has to do with the TLS handshake on every hour. Some caused by connecting to the VPN with the same certificate from two machines (I need to double-check if this is happening)

So I may have found the reason behind this very annoying behavior, and a fix on this without restarting the whole container. The issue comes down to the TUN dev is hanging. When this happens, the VPN lost connection, so it attempts to reconnect. However, the IP route is still configured to forward traffic to the dead tun0 interface, which of course all the packages will get lost those and it will not be able to resolve any domain name.

Restart the tun inside the container seems to work for me. ip link set tun0 down then ip link set tun0 up. (check the dev with ip link first)

This is because normally inside the container it can not get the status of the tun interface, so you will see something like "tun0: mtu 1500 qdisc pfifo_fast state UNKNOWN mode DEFAULT group default qlen 10000" which the state is unknown. Manually bring down the tun will make the ip route to update, so it stops forward traffic to the dead tun, then container wise the network is back up again.
Note: I have also done some other things during this debug process that may or may not help on this recovery, so if someone can try when it happens and give some feedback would be great. If not I will do more testing next time it happens to nail down what exactly will make it work.
A fix should be relatively easy if the above method work, add in the down scrip to have it bring down and bring back up the tun interface.
@haugene @pkishino

I have edited the health check script to try to auto recover from a tun hang. Need to wait until it happens next time to test, for me it's like 7-10 days, it seems to depend on how large of the traffic it's going through, mine is not a lot. If someone has a way to reproduce this issue faster it might speed up my debug process.

@RickyXwang Hope you find a workable solution that you can share with the project, been experiencing this issue as well.

A PR is created with an updated health check script to try to fix this before it gets merge or update, you may manually replace the healthcheck.sh file under /etc/scripts inside the container with the updated version in the PR to have it fixed.
Let me know if you run into issues with the new scripts.
Note, the scripts run like every 5 mins, so you might have to wait a bit before it get run.

I am updating the health check script base on comments and issues that I have recently been work on.
The current version has an issue with some unpredictable restart after an unknown time, and the VPN tunnel may not recover from it. You may see event_wait: Interrupted system call (code=4) followed by SIGUSR1[hard,] received, process restarting Like in https://github.com/haugene/docker-transmission-openvpn/issues/1447

This is because the health check script triggered the OpenVPN restart because the ping failed. Now what is interesting is that the tunnel may not be down at this point, the ping may have been failed because of a packet loss (Currently only ping one time, so it gets unlucky here), but I think the reason for this is because of what I have been mentioned in the above

  1. The TUN TX queue length is too small. It was 100 but sometimes it is 10, this cause package dropped on the TUN interface. increase the qlen with ip link set tun0 txqlen 10000 fixed the issue, but will need to fix this for longterm.
    If you monitor the statists of the interface by watch ip -s link, you will see the dropped increase on tun0.
    I have tested it with the default size 100 and if I keep running the ping, it will fail after some time, now at 100, it depends on how much traffic you are currently running, this also explained why my container seems to fail more often when I add new torrent to download.

So the recommendation here is to add the following:
--txqueuelen 10000 in OPENVPN_OPTS

Also, like in this issue https://github.com/haugene/docker-transmission-openvpn/issues/1447 and https://github.com/haugene/docker-transmission-openvpn/pull/1373 the container sometime will not recover after the restart issued by the healcheck script. The current signal being used is SIGUSR1 according to the documentation https://openvpn.net/community-resources/reference-manual-for-openvpn-2-4/ SIGNALS section this should be the default way to restart when there is a ping time out, it will try to restart openvpn by keeping everything persistent (use the same ip, don't close the tun dev, etc. And keeping things persistent is preferred in most of the case), some VPN provider has an issue with this (Some maybe how the way the ovpn file is written, some server try to push configuration that messed things up), so when this happens, SIGHUP signal should be sent to initiate a hard restart. The SIGHUP signal works well in my testing.

I will start another PR, let me know if you have any comments/issues.

@haugene

So the recommendation here is to add the following:
--txqueuelen 10000 in OPENVPN_OPTS

Would you suggest the people having this issue do this even if the healthcheck gets updated?

So the recommendation here is to add the following:
--txqueuelen 10000 in OPENVPN_OPTS

Would you suggest the people having this issue do this even if the healthcheck gets updated?

Yes, the healthcheck update I make will not include the change in the size of the queue (I did think of it but decided the healthcheck script is not the right place for this change). This setting should be passed into OpenVPN as a param when the start script is called.

I have added --txqueuelen 10000 to my OPENVPN_OPTS and still have the issue re-occurring except mine begins the same as #1447

@steve-spiteri Hi, when you say issue, do you mean you still see Interrupted system call (code=4) and the container don't recover? Can you open a new issue and post your log and settings there, also the version of the image? Would like to take a look and see what's happening. The health check script has not been updated yet.

Was this page helpful?
0 / 5 - 0 ratings

Related issues

haugene picture haugene  路  4Comments

coulterj picture coulterj  路  4Comments

jsloan117 picture jsloan117  路  3Comments

Jafalex picture Jafalex  路  3Comments

SuperJakish picture SuperJakish  路  4Comments