I am struggling to figure out what happened to my container. Yesterday I had a momentary power loss which resulted in my internet going down, but my UPS kept my unRAID server online. I restored the internet and found my container GUI inaccessible a day or so later. I figure it was related to the internet loss and breaking the VPN connection. No biggie. I restarted the container to re-establish the connection and have no luck getting back into the GUI. Nothing has changed. No configuration change, nothing, but now it won't seem to work.
I dug through the startup log and cannot seem to find a glaring error either. Any guidance would be appreciated.
Container command (passwords removed):
# /usr/local/emhttp/plugins/dynamix.docker.manager/scripts/docker run -d --name='binhex-delugevpn' --net='bridge' --privileged=true -e TZ="America/Chicago" -e HOST_OS="Unraid" -e 'VPN_ENABLED'='yes' -e 'VPN_USER'='' -e 'VPN_PASS'='' -e 'VPN_PROV'='custom' -e 'VPN_CLIENT'='openvpn' -e 'VPN_OPTIONS'='' -e 'STRICT_PORT_FORWARD'='yes' -e 'ENABLE_PRIVOXY'='no' -e 'LAN_NETWORK'='192.168.10.0/24' -e 'NAME_SERVERS'='85.203.37.1,85.203.37.2' -e 'DELUGE_DAEMON_LOG_LEVEL'='info' -e 'DELUGE_WEB_LOG_LEVEL'='info' -e 'VPN_INPUT_PORTS'='7878,5800,5900,9117,8989,9897' -e 'VPN_OUTPUT_PORTS'='' -e 'DEBUG'='false' -e 'UMASK'='000' -e 'PUID'='99' -e 'PGID'='100' -p '8112:8112/tcp' -p '58846:58846/tcp' -p '58946:58946/tcp' -p '58946:58946/udp' -p '8118:8118/tcp' -p '7878:7878/tcp' -p '9117:9117/tcp' -p '8989:8989/tcp' -p '9897:9897/tcp' -p '8686:8686/tcp' -v '/mnt/user/Downloads/Downloads/':'/data':'rw' -v '/mnt/cache/appdata/binhex-delugevpn':'/config':'rw' --sysctl="net.ipv4.conf.all.src_valid_mark=1" 'binhex/arch-delugevpn'
Log from startup (passwords removed and IPs changed)
Created by...
___. .__ .__
\_ |__ |__| ____ | |__ ____ ___ ___
| __ \| |/ \| | \_/ __ \\ \/ /
| \_\ \ | | \ Y \ ___/ > <
|___ /__|___| /___| /\___ >__/\_ \
\/ \/ \/ \/ \/
https://hub.docker.com/u/binhex/
2022-08-05 13:41:36.554341 [info] Host is running unRAID
2022-08-05 13:41:36.606632 [info] System information Linux 8290c25a0b63 4.19.107-Unraid #1 SMP Thu Mar 5 13:55:57 PST 2020 x86_64 GNU/Linux
2022-08-05 13:41:36.664016 [info] OS_ARCH defined as 'x86-64'
2022-08-05 13:41:36.721235 [info] PUID defined as '99'
2022-08-05 13:41:38.346542 [info] PGID defined as '100'
2022-08-05 13:41:39.759059 [info] UMASK defined as '000'
2022-08-05 13:41:39.814989 [info] Permissions already set for '/config'
2022-08-05 13:41:39.877230 [info] Deleting files in /tmp (non recursive)...
2022-08-05 13:41:39.942277 [info] VPN_ENABLED defined as 'yes'
2022-08-05 13:41:39.999234 [info] VPN_CLIENT defined as 'openvpn'
2022-08-05 13:41:40.052263 [info] VPN_PROV defined as 'custom'
2022-08-05 13:41:40.115871 [info] OpenVPN config file (ovpn extension) is located at /config/openvpn/my_expressvpn_usa_-_chicago_udp.ovpn
2022-08-05 13:41:40.218392 [warn] VPN configuration file /config/openvpn/my_expressvpn_usa_-_chicago_udp.ovpn remote protocol is missing or malformed, assuming protocol 'udp'
2022-08-05 13:41:40.266851 [info] VPN remote server(s) defined as 'usa-chicago-ca-version-2.expressnetw.com,'
2022-08-05 13:41:40.313238 [info] VPN remote port(s) defined as '1195,'
2022-08-05 13:41:40.362507 [info] VPN remote protcol(s) defined as 'udp,'
2022-08-05 13:41:40.416098 [info] VPN_DEVICE_TYPE defined as 'tun0'
2022-08-05 13:41:40.469772 [info] VPN_OPTIONS not defined (via -e VPN_OPTIONS)
2022-08-05 13:41:40.524077 [info] LAN_NETWORK defined as '192.168.10.0/24'
2022-08-05 13:41:40.578576 [info] NAME_SERVERS defined as '85.203.37.1,85.203.37.2'
2022-08-05 13:41:40.632005 [info] VPN_USER defined as ''
2022-08-05 13:41:40.686763 [info] VPN_PASS defined as ''
2022-08-05 13:41:40.741505 [info] ENABLE_PRIVOXY defined as 'no'
2022-08-05 13:41:40.801958 [info] VPN_INPUT_PORTS defined as '7878,5800,5900,9117,8989,9897'
2022-08-05 13:41:40.857511 [info] VPN_OUTPUT_PORTS not defined (via -e VPN_OUTPUT_PORTS), skipping allow for custom outgoing ports
2022-08-05 13:41:40.913177 [info] DELUGE_DAEMON_LOG_LEVEL defined as 'info'
2022-08-05 13:41:40.968820 [info] DELUGE_WEB_LOG_LEVEL defined as 'info'
2022-08-05 13:41:41.026254 [info] Starting Supervisor...
2022-08-05 13:41:41,528 INFO Included extra file "/etc/supervisor/conf.d/delugevpn.conf" during parsing
2022-08-05 13:41:41,528 INFO Set uid to user 0 succeeded
2022-08-05 13:41:41,533 INFO supervisord started with pid 6
2022-08-05 13:41:42,535 INFO spawned: 'shutdown-script' with pid 187
2022-08-05 13:41:42,537 INFO spawned: 'start-script' with pid 188
2022-08-05 13:41:42,539 INFO spawned: 'watchdog-script' with pid 189
2022-08-05 13:41:42,539 INFO reaped unknown pid 7 (exit status 0)
2022-08-05 13:41:42,578 DEBG 'start-script' stdout output:
[info] VPN is enabled, beginning configuration of VPN
2022-08-05 13:41:42,579 INFO success: shutdown-script entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
2022-08-05 13:41:42,579 INFO success: start-script entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
2022-08-05 13:41:42,579 INFO success: watchdog-script entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
2022-08-05 13:41:42,666 DEBG 'start-script' stdout output:
[info] Adding 85.203.37.1 to /etc/resolv.conf
2022-08-05 13:41:42,671 DEBG 'start-script' stdout output:
[info] Adding 85.203.37.2 to /etc/resolv.conf
2022-08-05 13:41:43,045 DEBG 'start-script' stdout output:
[info] Default route for container is 172.17.0.1
2022-08-05 13:41:43,069 DEBG 'start-script' stdout output:
[info] Docker network defined as 172.17.0.0/16
2022-08-05 13:41:43,075 DEBG 'start-script' stdout output:
[info] Adding 192.168.10.0/24 as route via docker eth0
2022-08-05 13:41:43,077 DEBG 'start-script' stdout output:
[info] ip route defined as follows...
--------------------
2022-08-05 13:41:43,079 DEBG 'start-script' stdout output:
default via 172.17.0.1 dev eth0
172.17.0.0/16 dev eth0 proto kernel scope link src 172.17.0.5
192.168.10.0/24 via 172.17.0.1 dev eth0
2022-08-05 13:41:43,079 DEBG 'start-script' stdout output:
broadcast 127.0.0.0 dev lo table local proto kernel scope link src 127.0.0.1
local 127.0.0.0/8 dev lo table local proto kernel scope host src 127.0.0.1
local 127.0.0.1 dev lo table local proto kernel scope host src 127.0.0.1
broadcast 127.255.255.255 dev lo table local proto kernel scope link src 127.0.0.1
broadcast 172.17.0.0 dev eth0 table local proto kernel scope link src 172.17.0.5
local 172.17.0.5 dev eth0 table local proto kernel scope host src 172.17.0.5
broadcast 172.17.255.255 dev eth0 table local proto kernel scope link src 172.17.0.5
2022-08-05 13:41:43,079 DEBG 'start-script' stdout output:
--------------------
2022-08-05 13:41:43,084 DEBG 'start-script' stdout output:
iptable_mangle 16384 2
ip_tables 24576 5 iptable_filter,iptable_nat,iptable_mangle
2022-08-05 13:41:43,085 DEBG 'start-script' stdout output:
[info] iptable_mangle support detected, adding fwmark for tables
2022-08-05 13:41:43,282 DEBG 'start-script' stdout output:
[info] iptables defined as follows...
--------------------
2022-08-05 13:41:43,284 DEBG 'start-script' stdout output:
-P INPUT DROP
-P FORWARD DROP
-P OUTPUT DROP
-A INPUT -s 172.17.0.0/16 -d 172.17.0.0/16 -j ACCEPT
-A INPUT -s 149.19.196.239/32 -i eth0 -j ACCEPT
-A INPUT -s 45.39.44.2/32 -i eth0 -j ACCEPT
-A INPUT -s 45.39.44.105/32 -i eth0 -j ACCEPT
-A INPUT -s 149.19.196.116/32 -i eth0 -j ACCEPT
-A INPUT -i eth0 -p tcp -m tcp --dport 8112 -j ACCEPT
-A INPUT -i eth0 -p udp -m udp --dport 8112 -j ACCEPT
-A INPUT -i eth0 -p tcp -m tcp --dport 7878 -j ACCEPT
-A INPUT -i eth0 -p udp -m udp --dport 7878 -j ACCEPT
-A INPUT -i eth0 -p tcp -m tcp --dport 5800 -j ACCEPT
-A INPUT -i eth0 -p udp -m udp --dport 5800 -j ACCEPT
-A INPUT -i eth0 -p tcp -m tcp --dport 5900 -j ACCEPT
-A INPUT -i eth0 -p udp -m udp --dport 5900 -j ACCEPT
-A INPUT -i eth0 -p tcp -m tcp --dport 9117 -j ACCEPT
-A INPUT -i eth0 -p udp -m udp --dport 9117 -j ACCEPT
-A INPUT -i eth0 -p tcp -m tcp --dport 8989 -j ACCEPT
-A INPUT -i eth0 -p udp -m udp --dport 8989 -j ACCEPT
-A INPUT -i eth0 -p tcp -m tcp --dport 9897 -j ACCEPT
-A INPUT -i eth0 -p udp -m udp --dport 9897 -j ACCEPT
-A INPUT -s 192.168.10.0/24 -d 172.17.0.0/16 -i eth0 -p tcp -m tcp --dport 58846 -j ACCEPT
-A INPUT -p icmp -m icmp --icmp-type 0 -j ACCEPT
-A INPUT -i lo -j ACCEPT
-A INPUT -i tun0 -j ACCEPT
-A OUTPUT -s 172.17.0.0/16 -d 172.17.0.0/16 -j ACCEPT
-A OUTPUT -d 149.19.196.239/32 -o eth0 -j ACCEPT
-A OUTPUT -d 45.39.44.2/32 -o eth0 -j ACCEPT
-A OUTPUT -d 45.39.44.105/32 -o eth0 -j ACCEPT
-A OUTPUT -d 149.19.196.116/32 -o eth0 -j ACCEPT
-A OUTPUT -o eth0 -p tcp -m tcp --sport 8112 -j ACCEPT
-A OUTPUT -o eth0 -p udp -m udp --sport 8112 -j ACCEPT
-A OUTPUT -o eth0 -p tcp -m tcp --sport 7878 -j ACCEPT
-A OUTPUT -o eth0 -p udp -m udp --sport 7878 -j ACCEPT
-A OUTPUT -o eth0 -p tcp -m tcp --sport 5800 -j ACCEPT
-A OUTPUT -o eth0 -p udp -m udp --sport 5800 -j ACCEPT
-A OUTPUT -o eth0 -p tcp -m tcp --sport 5900 -j ACCEPT
-A OUTPUT -o eth0 -p udp -m udp --sport 5900 -j ACCEPT
-A OUTPUT -o eth0 -p tcp -m tcp --sport 9117 -j ACCEPT
-A OUTPUT -o eth0 -p udp -m udp --sport 9117 -j ACCEPT
-A OUTPUT -o eth0 -p tcp -m tcp --sport 8989 -j ACCEPT
-A OUTPUT -o eth0 -p udp -m udp --sport 8989 -j ACCEPT
-A OUTPUT -o eth0 -p tcp -m tcp --sport 9897 -j ACCEPT
-A OUTPUT -o eth0 -p udp -m udp --sport 9897 -j ACCEPT
-A OUTPUT -s 172.17.0.0/16 -d 192.168.10.0/24 -o eth0 -p tcp -m tcp --sport 58846 -j ACCEPT
-A OUTPUT -p icmp -m icmp --icmp-type 8 -j ACCEPT
-A OUTPUT -o lo -j ACCEPT
-A OUTPUT -o tun0 -j ACCEPT
2022-08-05 13:41:43,285 DEBG 'start-script' stdout output:
--------------------
2022-08-05 13:41:43,286 DEBG 'start-script' stdout output:
[info] Starting OpenVPN (non daemonised)...
2022-08-05 13:41:43,335 DEBG 'start-script' stdout output:
2022-08-05 13:41:43 DEPRECATED OPTION: --cipher set to 'AES-256-CBC' but missing in --data-ciphers (AES-256-GCM:AES-128-GCM). Future OpenVPN version will ignore --cipher for cipher negotiations. Add 'AES-256-CBC' to --data-ciphers or change --cipher 'AES-256-CBC' to --data-ciphers-fallback 'AES-256-CBC' to silence this warning.
2022-08-05 13:41:43 WARNING: --keysize is DEPRECATED and will be removed in OpenVPN 2.6
2022-08-05 13:41:43 WARNING: --keysize is DEPRECATED and will be removed in OpenVPN 2.6
2022-08-05 13:41:43 WARNING: --keysize is DEPRECATED and will be removed in OpenVPN 2.6
2022-08-05 13:41:43 WARNING: --keysize is DEPRECATED and will be removed in OpenVPN 2.6
2022-08-05 13:41:43 WARNING: --keysize is DEPRECATED and will be removed in OpenVPN 2.6
2022-08-05 13:41:43 WARNING: file 'credentials.conf' is group or others accessible
2022-08-05 13:41:43,335 DEBG 'start-script' stdout output:
2022-08-05 13:41:43 OpenVPN 2.5.7 [git:makepkg/a0f9a3e9404c8321+] x86_64-pc-linux-gnu [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [PKCS11] [MH/PKTINFO] [AEAD] built on May 31 2022
2022-08-05 13:41:43 library versions: OpenSSL 1.1.1q 5 Jul 2022, LZO 2.10
2022-08-05 13:41:43 WARNING: --ns-cert-type is DEPRECATED. Use --remote-cert-tls instead.
2022-08-05 13:41:43 NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
2022-08-05 13:41:43,337 DEBG 'start-script' stdout output:
2022-08-05 13:41:43 Outgoing Control Channel Authentication: Using 512 bit message hash 'SHA512' for HMAC authentication
2022-08-05 13:41:43 Incoming Control Channel Authentication: Using 512 bit message hash 'SHA512' for HMAC authentication
2022-08-05 13:41:43,337 DEBG 'start-script' stdout output:
2022-08-05 13:41:43 TCP/UDP: Preserving recently used remote address: [AF_INET]149.19.196.239:1195
2022-08-05 13:41:43 Socket Buffers: R=[212992->1048576] S=[212992->1048576]
2022-08-05 13:41:43 UDP link local: (not bound)
2022-08-05 13:41:43 UDP link remote: [AF_INET]149.19.196.239:1195
2022-08-05 13:41:43,356 DEBG 'start-script' stdout output:
2022-08-05 13:41:43 TLS: Initial packet from [AF_INET]149.19.196.239:1195, sid=3e2c64b4 29850e4d
2022-08-05 13:41:43,379 DEBG 'start-script' stdout output:
2022-08-05 13:41:43 VERIFY OK: depth=1, C=VG, ST=BVI, O=ExpressVPN, OU=ExpressVPN, CN=ExpressVPN CA,
[email protected]
2022-08-05 13:41:43,380 DEBG 'start-script' stdout output:
2022-08-05 13:41:43 VERIFY OK: nsCertType=SERVER
2022-08-05 13:41:43 VERIFY X509NAME OK: C=VG, ST=BVI, O=ExpressVPN, OU=ExpressVPN, CN=Server-11070-0a,
[email protected]
2022-08-05 13:41:43 VERIFY OK: depth=0, C=VG, ST=BVI, O=ExpressVPN, OU=ExpressVPN, CN=Server-11070-0a,
[email protected]
2022-08-05 13:41:43,406 DEBG 'start-script' stdout output:
2022-08-05 13:41:43 Control Channel: TLSv1.3, cipher TLSv1.3 TLS_AES_256_GCM_SHA384, peer certificate: 2048 bit RSA, signature: RSA-SHA256
2022-08-05 13:41:43 [Server-11070-0a] Peer Connection Initiated with [AF_INET]149.19.196.239:1195
2022-08-05 13:41:44,648 DEBG 'start-script' stdout output:
2022-08-05 13:41:44 SENT CONTROL [Server-11070-0a]: 'PUSH_REQUEST' (status=1)
2022-08-05 13:41:44,667 DEBG 'start-script' stdout output:
2022-08-05 13:41:44 PUSH: Received control message: 'PUSH_REPLY,redirect-gateway def1,dhcp-option DNS 10.122.0.1,comp-lzo no,route 10.122.0.1,topology net30,ping 10,ping-restart 60,ifconfig 10.122.1.218 10.122.1.217,peer-id 122,cipher AES-256-GCM'
2022-08-05 13:41:44 OPTIONS IMPORT: timers and/or timeouts modified
2022-08-05 13:41:44 OPTIONS IMPORT: compression parms modified
2022-08-05 13:41:44 OPTIONS IMPORT: --ifconfig/up options modified
2022-08-05 13:41:44,667 DEBG 'start-script' stdout output:
2022-08-05 13:41:44 OPTIONS IMPORT: route options modified
2022-08-05 13:41:44 OPTIONS IMPORT: --ip-win32 and/or --dhcp-option options modified
2022-08-05 13:41:44 OPTIONS IMPORT: peer-id set
2022-08-05 13:41:44 OPTIONS IMPORT: adjusting link_mtu to 1629
2022-08-05 13:41:44 OPTIONS IMPORT: data channel crypto options modified
2022-08-05 13:41:44 Data Channel: using negotiated cipher 'AES-256-GCM'
2022-08-05 13:41:44 NCP: overriding user-set keysize with default
2022-08-05 13:41:44 Outgoing Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
2022-08-05 13:41:44 Incoming Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
2022-08-05 13:41:44 net_route_v4_best_gw query: dst 0.0.0.0
2022-08-05 13:41:44 net_route_v4_best_gw result: via 172.17.0.1 dev eth0
2022-08-05 13:41:44,667 DEBG 'start-script' stdout output:
2022-08-05 13:41:44 ROUTE_GATEWAY 172.17.0.1/255.255.0.0 IFACE=eth0 HWADDR=02:42:ac:11:00:05
2022-08-05 13:41:44,668 DEBG 'start-script' stdout output:
2022-08-05 13:41:44 TUN/TAP device tun0 opened
2022-08-05 13:41:44 net_iface_mtu_set: mtu 1500 for tun0
2022-08-05 13:41:44,668 DEBG 'start-script' stdout output:
2022-08-05 13:41:44 net_iface_up: set tun0 up
2022-08-05 13:41:44 net_addr_ptp_v4_add: 10.122.1.218 peer 10.122.1.217 dev tun0
2022-08-05 13:41:44 /root/openvpnup.sh tun0 1500 1557 10.122.1.218 10.122.1.217 init
2022-08-05 13:41:46,914 DEBG 'start-script' stdout output:
2022-08-05 13:41:46 net_route_v4_add: 149.19.196.239/32 via 172.17.0.1 dev [NULL] table 0 metric -1
2022-08-05 13:41:46 net_route_v4_add: 0.0.0.0/1 via 10.122.1.217 dev [NULL] table 0 metric -1
2022-08-05 13:41:46 net_route_v4_add: 128.0.0.0/1 via 10.122.1.217 dev [NULL] table 0 metric -1
2022-08-05 13:41:46,914 DEBG 'start-script' stdout output:
2022-08-05 13:41:46 net_route_v4_add: 10.122.0.1/32 via 10.122.1.217 dev [NULL] table 0 metric -1
2022-08-05 13:41:46 Initialization Sequence Completed
2022-08-05 13:41:50,730 DEBG 'start-script' stdout output:
[info] Attempting to get external IP using 'http://checkip.amazonaws.com'...
2022-08-05 13:41:50,870 DEBG 'start-script' stdout output:
[info] Successfully retrieved external IP address 85.237.194.94
2022-08-05 13:41:50,872 DEBG 'start-script' stdout output:
[info] Application does not require port forwarding or VPN provider is != pia, skipping incoming port assignment
2022-08-05 13:41:50,959 DEBG 'watchdog-script' stdout output:
[info] Deluge listening interface IP 0.0.0.0 and VPN provider IP 10.122.1.218 different, marking for reconfigure
2022-08-05 13:41:50,967 DEBG 'watchdog-script' stdout output:
[info] Deluge not running
2022-08-05 13:41:50,973 DEBG 'watchdog-script' stdout output:
[info] Deluge Web UI not running
2022-08-05 13:41:50,974 DEBG 'watchdog-script' stdout output:
[info] Attempting to start Deluge...
[info] Removing deluge pid file (if it exists)...
2022-08-05 13:41:51,973 DEBG 'watchdog-script' stdout output:
[info] Deluge key 'listen_interface' currently has a value of '10.122.0.138'
[info] Deluge key 'listen_interface' will have a new value '10.122.1.218'
[info] Writing changes to Deluge config file '/config/core.conf'...
2022-08-05 13:41:52,494 DEBG 'watchdog-script' stdout output:
[info] Deluge key 'outgoing_interface' currently has a value of 'tun0'
[info] Deluge key 'outgoing_interface' will have a new value 'tun0'
[info] Writing changes to Deluge config file '/config/core.conf'...
2022-08-05 13:41:52,984 DEBG 'watchdog-script' stdout output:
[info] Deluge key 'default_daemon' currently has a value of 'e2015e2ba35049b9aea47ad89d31b6a5'
[info] Deluge key 'default_daemon' will have a new value 'e2015e2ba35049b9aea47ad89d31b6a5'
[info] Writing changes to Deluge config file '/config/web.conf'...
2022-08-05 13:41:54,409 DEBG 'watchdog-script' stdout output:
[info] Deluge process started
[info] Waiting for Deluge process to start listening on port 58846...
2022-08-05 13:41:54,741 DEBG 'watchdog-script' stdout output:
[info] Deluge process listening on port 58846
2022-08-05 13:42:01,909 DEBG 'watchdog-script' stderr output:
<Deferred at 0x14bb4ee22e30 current result: None>
2022-08-05 13:42:02,044 DEBG 'watchdog-script' stdout output:
[info] No torrents with state 'Error' found
2022-08-05 13:42:02,044 DEBG 'watchdog-script' stdout output:
[info] Starting Deluge Web UI...
2022-08-05 13:42:02,045 DEBG 'watchdog-script' stdout output:
[info] Deluge Web UI started