Hi, I'm another QNAP user trying to get this package to work... I was able to tackle the daemon_conf issues raised earlier - and I can connect to PIA and it looks to be stable. However, whenever I try to download a torrent I see peers connect, but then they drop after 5 seconds or so. The only traffic I see is network overhead. I feel like it is probably something in my setup somewhere, but I can't see where.
I'm using CA-Montreal, which I think supports port forwarding. I'd really appreciate any help.
I have gone through this link and made sure I did everything there:
https://github.com/binhex/documentation/blob/master/docker/faq/vpn.md
Supervisor.log:
Created by...
___. .__ .__
\_ |__ |__| ____ | |__ ____ ___ ___
| __ \| |/ \| | \_/ __ \\ \/ /
| \_\ \ | | \ Y \ ___/ > <
|___ /__|___| /___| /\___ >__/\_ \
\/ \/ \/ \/ \/
https://hub.docker.com/u/binhex/
2020-02-11 19:29:40.786334 [info] System information Linux 40ddf0579d56 4.14.24-qnap #1 SMP Fri Dec 6 11:32:47 CST 2019 x86_64 GNU/Linux
2020-02-11 19:29:40.892961 [info] PUID defined as '0'
2020-02-11 19:29:41.009574 [info] PGID defined as '0'
2020-02-11 19:29:41.378818 [warn] UMASK not defined (via -e UMASK), defaulting to '000'
2020-02-11 19:29:41.508641 [info] Permissions already set for volume mappings
2020-02-11 19:29:41.648921 [info] DELUGE_DAEMON_LOG_LEVEL not defined,(via -e DELUGE_DAEMON_LOG_LEVEL), defaulting to 'info'
2020-02-11 19:29:41.741220 [info] DELUGE_WEB_LOG_LEVEL not defined,(via -e DELUGE_WEB_LOG_LEVEL), defaulting to 'info'
2020-02-11 19:29:41.834308 [info] VPN_ENABLED defined as 'yes'
2020-02-11 19:29:41.938699 [info] OpenVPN config file (ovpn extension) is located at /config/openvpn/CA Montreal.ovpn
2020-02-11 19:29:42.153039 [info] VPN remote line defined as 'remote ca-montreal.privateinternetaccess.com 1198'
2020-02-11 19:29:42.254781 [info] VPN_REMOTE defined as 'ca-montreal.privateinternetaccess.com'
2020-02-11 19:29:42.363284 [info] VPN_PORT defined as '1198'
2020-02-11 19:29:42.479173 [info] VPN_PROTOCOL defined as 'udp'
2020-02-11 19:29:42.593731 [info] VPN_DEVICE_TYPE defined as 'tun0'
2020-02-11 19:29:42.686322 [info] VPN_PROV defined as 'pia'
2020-02-11 19:29:42.777204 [info] LAN_NETWORK defined as '192.168.0.0/24'
2020-02-11 19:29:42.869337 [warn] NAME_SERVERS not defined (via -e NAME_SERVERS), defaulting to name servers defined in readme.md
2020-02-11 19:29:42.960482 [info] VPN_USER defined as ''
2020-02-11 19:29:43.053043 [info] VPN_PASS defined as ''
2020-02-11 19:29:43.144605 [info] VPN_OPTIONS not defined (via -e VPN_OPTIONS)
2020-02-11 19:29:43.235445 [info] STRICT_PORT_FORWARD defined as 'YES'
2020-02-11 19:29:43.327747 [warn] ENABLE_PRIVOXY not defined (via -e ENABLE_PRIVOXY), defaulting to 'no'
2020-02-11 19:29:43.472356 [info] Deleting files in /tmp (non recursive)...
2020-02-11 19:29:43.567638 [info] Starting Supervisor...
2020-02-11 19:29:44,210 INFO Included extra file "/etc/supervisor/conf.d/delugevpn.conf" during parsing
2020-02-11 19:29:44,211 INFO Set uid to user 0 succeeded
2020-02-11 19:29:44,220 INFO supervisord started with pid 8
2020-02-11 19:29:45,224 INFO spawned: 'start-script' with pid 163
2020-02-11 19:29:45,228 INFO spawned: 'watchdog-script' with pid 164
2020-02-11 19:29:45,229 INFO reaped unknown pid 9
2020-02-11 19:29:45,247 DEBG 'start-script' stdout output:
[info] VPN is enabled, beginning configuration of VPN
2020-02-11 19:29:45,247 INFO success: start-script entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
2020-02-11 19:29:45,247 INFO success: watchdog-script entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
2020-02-11 19:29:45,419 DEBG 'start-script' stdout output:
[info] Default route for container is 10.0.3.1
2020-02-11 19:29:45,431 DEBG 'start-script' stdout output:
[info] Adding 209.222.18.222 to /etc/resolv.conf
2020-02-11 19:29:45,442 DEBG 'start-script' stdout output:
[info] Adding 84.200.69.80 to /etc/resolv.conf
2020-02-11 19:29:45,454 DEBG 'start-script' stdout output:
[info] Adding 37.235.1.174 to /etc/resolv.conf
2020-02-11 19:29:45,468 DEBG 'start-script' stdout output:
[info] Adding 1.1.1.1 to /etc/resolv.conf
2020-02-11 19:29:45,478 DEBG 'start-script' stdout output:
[info] Adding 209.222.18.218 to /etc/resolv.conf
2020-02-11 19:29:45,489 DEBG 'start-script' stdout output:
[info] Adding 37.235.1.177 to /etc/resolv.conf
2020-02-11 19:29:45,500 DEBG 'start-script' stdout output:
[info] Adding 84.200.70.40 to /etc/resolv.conf
2020-02-11 19:29:45,509 DEBG 'start-script' stdout output:
[info] Adding 1.0.0.1 to /etc/resolv.conf
2020-02-11 19:29:45,629 DEBG 'start-script' stdout output:
[info] Attempting to load iptable_mangle module...
2020-02-11 19:29:45,633 DEBG 'start-script' stderr output:
modprobe: FATAL: Module iptable_mangle not found in directory /lib/modules/4.14.24-qnap
2020-02-11 19:29:45,636 DEBG 'start-script' stdout output:
[warn] Unable to load iptable_mangle module using modprobe, trying insmod...
2020-02-11 19:29:45,639 DEBG 'start-script' stderr output:
insmod: ERROR: could not load module /lib/modules/iptable_mangle.ko: No such file or directory
2020-02-11 19:29:45,641 DEBG 'start-script' stdout output:
[warn] Unable to load iptable_mangle module, you will not be able to connect to the applications Web UI or Privoxy outside of your LAN
[info] unRAID/Ubuntu users: Please attempt to load the module by executing the following on your host: '/sbin/modprobe iptable_mangle'
[info] Synology users: Please attempt to load the module by executing the following on your host: 'insmod /lib/modules/iptable_mangle.ko'
2020-02-11 19:29:45,720 DEBG 'start-script' stdout output:
[info] Docker network defined as 10.0.3.0/24
2020-02-11 19:29:45,731 DEBG 'start-script' stdout output:
[info] Adding 192.168.0.0/24 as route via docker eth0
2020-02-11 19:29:45,735 DEBG 'start-script' stdout output:
[info] ip route defined as follows...
--------------------
2020-02-11 19:29:45,738 DEBG 'start-script' stdout output:
default via 10.0.3.1 dev eth0
10.0.3.0/24 dev eth0 proto kernel scope link src 10.0.3.2
192.168.0.0/24 via 10.0.3.1 dev eth0
2020-02-11 19:29:45,739 DEBG 'start-script' stdout output:
--------------------
2020-02-11 19:29:45,882 DEBG 'start-script' stdout output:
[info] iptables defined as follows...
--------------------
2020-02-11 19:29:45,885 DEBG 'start-script' stdout output:
-P INPUT DROP
-P FORWARD DROP
-P OUTPUT DROP
-A INPUT -s 10.0.3.0/24 -d 10.0.3.0/24 -j ACCEPT
-A INPUT -i eth0 -p udp -m udp --sport 1198 -j ACCEPT
-A INPUT -i eth0 -p tcp -m tcp --dport 8112 -j ACCEPT
-A INPUT -i eth0 -p tcp -m tcp --sport 8112 -j ACCEPT
-A INPUT -s 192.168.0.0/24 -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 10.0.3.0/24 -d 10.0.3.0/24 -j ACCEPT
-A OUTPUT -o eth0 -p udp -m udp --dport 1198 -j ACCEPT
-A OUTPUT -o eth0 -p tcp -m tcp --dport 8112 -j ACCEPT
-A OUTPUT -o eth0 -p tcp -m tcp --sport 8112 -j ACCEPT
-A OUTPUT -d 192.168.0.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
2020-02-11 19:29:45,889 DEBG 'start-script' stdout output:
--------------------
2020-02-11 19:29:45,893 DEBG 'start-script' stdout output:
[info] Starting OpenVPN...
2020-02-11 19:29:45,907 DEBG 'start-script' stdout output:
Tue Feb 11 19:29:45 2020 WARNING: file 'credentials.conf' is group or others accessible
Tue Feb 11 19:29:45 2020 OpenVPN 2.4.8 [git:makepkg/3976acda9bf10b5e+] x86_64-pc-linux-gnu [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [PKCS11] [MH/PKTINFO] [AEAD] built on Jan 3 2020
Tue Feb 11 19:29:45 2020 library versions: OpenSSL 1.1.1d 10 Sep 2019, LZO 2.10
2020-02-11 19:29:45,909 DEBG 'start-script' stdout output:
[info] OpenVPN started
2020-02-11 19:29:45,924 DEBG 'start-script' stdout output:
Tue Feb 11 19:29:45 2020 NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
2020-02-11 19:29:45,928 DEBG 'start-script' stdout output:
Tue Feb 11 19:29:45 2020 TCP/UDP: Preserving recently used remote address: [AF_INET]199.229.249.152:1198
Tue Feb 11 19:29:45 2020 UDP link local: (not bound)
Tue Feb 11 19:29:45 2020 UDP link remote: [AF_INET]199.229.249.152:1198
2020-02-11 19:29:46,301 DEBG 'start-script' stdout output:
Tue Feb 11 19:29:46 2020 [06c7d7a2a99775b068106fd6379327f7] Peer Connection Initiated with [AF_INET]199.229.249.152:1198
2020-02-11 19:29:47,622 DEBG 'start-script' stdout output:
Tue Feb 11 19:29:47 2020 TUN/TAP device tun0 opened
Tue Feb 11 19:29:47 2020 /usr/bin/ip link set dev tun0 up mtu 1500
2020-02-11 19:29:47,625 DEBG 'start-script' stdout output:
Tue Feb 11 19:29:47 2020 /usr/bin/ip addr add dev tun0 local 10.30.11.6 peer 10.30.11.5
2020-02-11 19:29:47,629 DEBG 'start-script' stdout output:
Tue Feb 11 19:29:47 2020 /root/openvpnup.sh tun0 1500 1558 10.30.11.6 10.30.11.5 init
2020-02-11 19:29:47,649 DEBG 'start-script' stdout output:
Tue Feb 11 19:29:47 2020 Initialization Sequence Completed
2020-02-11 19:29:47,787 DEBG 'start-script' stdout output:
[info] Port forwarding is enabled
[info] Checking endpoint 'ca-montreal.privateinternetaccess.com' is port forward enabled...
2020-02-11 19:29:47,799 DEBG 'start-script' stdout output:
[info] Attempting to curl https://www.privateinternetaccess.com/vpninfo/servers?version=82...
2020-02-11 19:29:48,655 DEBG 'start-script' stdout output:
[info] Curl successful for https://www.privateinternetaccess.com/vpninfo/servers?version=82, response code 200
2020-02-11 19:29:48,871 DEBG 'start-script' stdout output:
[info] PIA endpoint 'ca-montreal.privateinternetaccess.com' is in the list of endpoints that support port forwarding
2020-02-11 19:29:48,871 DEBG 'start-script' stdout output:
[info] List of PIA endpoints that support port forwarding:-
2020-02-11 19:29:48,872 DEBG 'start-script' stdout output:
[info] ca-toronto.privateinternetaccess.com
[info] ca-montreal.privateinternetaccess.com
[info] ca-vancouver.privateinternetaccess.com
[info] de-berlin.privateinternetaccess.com
[info] de-frankfurt.privateinternetaccess.com
[info] sweden.privateinternetaccess.com
[info] swiss.privateinternetaccess.com
[info] france.privateinternetaccess.com
[info] czech.privateinternetaccess.com
[info] spain.privateinternetaccess.com
[info] ro.privateinternetaccess.com
[info] israel.privateinternetaccess.com
2020-02-11 19:29:48,872 DEBG 'start-script' stdout output:
[info] Attempting to get dynamically assigned port...
2020-02-11 19:29:48,890 DEBG 'start-script' stdout output:
[info] Attempting to curl http://209.222.18.222:2000/?client_id=1c3a9cb50585793078223832ad2c4a3440f36c46f0b3f4e69cf109170d37dcf9...
2020-02-11 19:29:49,514 DEBG 'start-script' stdout output:
[info] Curl successful for http://209.222.18.222:2000/?client_id=1c3a9cb50585793078223832ad2c4a3440f36c46f0b3f4e69cf109170d37dcf9, response code 200
2020-02-11 19:29:49,634 DEBG 'start-script' stdout output:
[info] Successfully assigned incoming port 39838
2020-02-11 19:29:49,637 DEBG 'start-script' stdout output:
[info] Checking we can resolve name 'www.google.com' to address...
2020-02-11 19:29:49,827 DEBG 'start-script' stdout output:
[info] DNS operational, we can resolve name 'www.google.com' to address '216.58.206.4'
2020-02-11 19:29:49,832 DEBG 'start-script' stdout output:
[info] Attempting to get external IP using Name Server 'ns1.google.com'...
2020-02-11 19:29:50,284 DEBG 'start-script' stdout output:
[info] Successfully retrieved external IP address 199.229.249.152
2020-02-11 19:29:50,326 DEBG 'watchdog-script' stdout output:
[info] Deluge listening interface IP 0.0.0.0 and VPN provider IP 10.30.11.6 different, marking for reconfigure
2020-02-11 19:29:50,336 DEBG 'watchdog-script' stdout output:
[info] Deluge not running
2020-02-11 19:29:50,353 DEBG 'watchdog-script' stdout output:
[info] Deluge Web UI not running
2020-02-11 19:29:50,355 DEBG 'watchdog-script' stdout output:
[info] Deluge incoming port 6890 and VPN incoming port 39838 different, marking for reconfigure
2020-02-11 19:29:50,357 DEBG 'watchdog-script' stdout output:
[info] Attempting to start Deluge...
[info] Removing deluge pid file (if it exists)...
2020-02-11 19:29:51,605 DEBG 'watchdog-script' stdout output:
[info] Deluge key 'listen_interface' currently has a value of '10.3.10.6'
[info] Deluge key 'listen_interface' will have a new value '10.30.11.6'
[info] Writing changes to Deluge config file '/config/core.conf'...
2020-02-11 19:29:52,309 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'...
2020-02-11 19:29:53,012 DEBG 'watchdog-script' stdout output:
[info] Deluge key 'default_daemon' currently has a value of 'e1bd94b2a5e84de7b6d6b6cae0ca4f2b'
[info] Deluge key 'default_daemon' will have a new value 'e1bd94b2a5e84de7b6d6b6cae0ca4f2b'
[info] Writing changes to Deluge config file '/config/web.conf'...
2020-02-11 19:29:54,172 DEBG 'watchdog-script' stdout output:
[info] Deluge process started
[info] Waiting for Deluge process to start listening on port 58846...
2020-02-11 19:29:54,755 DEBG 'watchdog-script' stdout output:
[info] Deluge process listening on port 58846
2020-02-11 19:29:55,755 DEBG 'watchdog-script' stderr output:
Unable to initialize gettext/locale!
2020-02-11 19:29:55,756 DEBG 'watchdog-script' stderr output:
'ngettext'
Traceback (most recent call last):
File "/usr/lib/python3.8/site-packages/deluge/i18n/util.py", line 118, in setup_translation
builtins.__dict__['_n'] = builtins.__dict__['ngettext']
KeyError: 'ngettext'
2020-02-11 19:30:05,825 DEBG 'watchdog-script' stdout output:
Setting "random_port" to: False
Configuration value successfully updated.
2020-02-11 19:30:07,067 DEBG 'watchdog-script' stderr output:
Unable to initialize gettext/locale!
2020-02-11 19:30:07,068 DEBG 'watchdog-script' stderr output:
'ngettext'
Traceback (most recent call last):
File "/usr/lib/python3.8/site-packages/deluge/i18n/util.py", line 118, in setup_translation
builtins.__dict__['_n'] = builtins.__dict__['ngettext']
KeyError: 'ngettext'
2020-02-11 19:30:16,023 DEBG 'watchdog-script' stdout output:
Setting "listen_ports" to: (39838, 39838)
Configuration value successfully updated.
2020-02-11 19:30:17,280 DEBG 'watchdog-script' stderr output:
Unable to initialize gettext/locale!
2020-02-11 19:30:17,323 DEBG 'watchdog-script' stderr output:
'ngettext'
Traceback (most recent call last):
File "/usr/lib/python3.8/site-packages/deluge/i18n/util.py", line 118, in setup_translation
builtins.__dict__['_n'] = builtins.__dict__['ngettext']
KeyError: 'ngettext'
2020-02-11 19:30:26,776 DEBG 'watchdog-script' stdout output:
[info] No torrents with state 'Error' found
2020-02-11 19:30:26,777 DEBG 'watchdog-script' stdout output:
[info] Starting Deluge Web UI...
2020-02-11 19:30:26,777 DEBG 'watchdog-script' stdout output:
[info] Deluge Web UI started
2020-02-11 19:30:27,756 DEBG 'watchdog-script' stderr output:
Unable to initialize gettext/locale!
2020-02-11 19:30:27,757 DEBG 'watchdog-script' stderr output:
'ngettext'
Traceback (most recent call last):
File "/usr/lib/python3.8/site-packages/deluge/i18n/util.py", line 118, in setup_translation
builtins.__dict__['_n'] = builtins.__dict__['ngettext']
KeyError: 'ngettext'
2020-02-11 19:32:40,894 WARN received SIGTERM indicating exit request
2020-02-11 19:32:40,895 DEBG killing watchdog-script (pid 164) with signal SIGTERM
2020-02-11 19:32:40,895 INFO waiting for start-script, watchdog-script to die
2020-02-11 19:32:41,897 DEBG fd 11 closed, stopped monitoring <POutputDispatcher at 140310345230224 for <Subprocess at 140310345229552 with name watchdog-script in state STOPPING> (stdout)>
2020-02-11 19:32:41,897 DEBG fd 15 closed, stopped monitoring <POutputDispatcher at 140310344568448 for <Subprocess at 140310345229552 with name watchdog-script in state STOPPING> (stderr)>
2020-02-11 19:32:41,898 INFO stopped: watchdog-script (terminated by SIGTERM)
2020-02-11 19:32:41,898 DEBG received SIGCHLD indicating a child quit
2020-02-11 19:32:41,898 DEBG killing start-script (pid 163) with signal SIGTERM
2020-02-11 19:32:42,900 DEBG fd 8 closed, stopped monitoring <POutputDispatcher at 140310345475312 for <Subprocess at 140310345475360 with name start-script in state STOPPING> (stdout)>
2020-02-11 19:32:42,901 DEBG fd 10 closed, stopped monitoring <POutputDispatcher at 140310345229456 for <Subprocess at 140310345475360 with name start-script in state STOPPING> (stderr)>
2020-02-11 19:32:42,901 INFO stopped: start-script (terminated by SIGTERM)
2020-02-11 19:32:42,901 DEBG received SIGCHLD indicating a child quit
and then the deluged.log
19:44:40.089 [INFO ][deluge.configmanager:52 ] Setting config directory to: /config
19:44:40.571 [INFO ][deluge.core.daemon :94 ] Deluge daemon 2.0.4.dev23
19:44:40.573 [WARNING ][deluge.core.core :337 ] Unable to load /config/session.state: [Errno 2] No such file or directory: '/config/session.state'
19:44:40.574 [WARNING ][deluge.core.core :337 ] Unable to load /config/session.state.bak: [Errno 2] No such file or directory: '/config/session.state.bak'
19:44:40.577 [INFO ][deluge.core.alertmanager :148 ] Alert Queue Size set to 10000
19:44:40.622 [INFO ][deluge.core.rpcserver :402 ] Starting DelugeRPC server :58846
19:44:40.630 [INFO ][twisted :154 ] Factory (TLS) starting on 58846
19:44:40.630 [INFO ][twisted :154 ] Starting factory <twisted.internet.protocol.Factory object at 0x7f79766e2280>
19:44:40.634 [INFO ][deluge.core.daemon :154 ] Deluge daemon starting...
19:44:40.666 [INFO ][deluge_label.core :78 ] *** Start Label plugin ***
19:44:40.667 [INFO ][deluge.pluginmanagerbase :189 ] Plugin Label enabled...
19:44:40.703 [WARNING ][deluge.config :410 ] Unable to open config file /config/blocklist.conf: [Errno 2] No such file or directory: '/config/blocklist.conf'
19:44:40.704 [INFO ][deluge.pluginmanagerbase :189 ] Plugin Blocklist enabled...
19:44:40.705 [INFO ][deluge.core.authmanager :228 ] Opening auth for load: /config/auth
19:44:40.706 [INFO ][deluge.core.authmanager :236 ] Successfully loaded auth: /config/auth
19:44:40.707 [WARNING ][deluge.core.torrentmanager :1165] Bad shutdown detected so archiving state files
19:44:40.708 [WARNING ][deluge.common :195 ] Too many existing archives for state. Deleting oldest archive.
19:44:40.743 [INFO ][deluge.core.torrentmanager :806 ] Loading torrent state: /config/state/torrents.state
19:44:40.743 [INFO ][deluge.core.torrentmanager :822 ] Successfully loaded /config/state/torrents.state
19:44:40.744 [INFO ][deluge.core.torrentmanager :1069] Opening torrents.fastresume for load: /config/state/torrents.fastresume
19:44:40.744 [INFO ][deluge.core.torrentmanager :1080] Successfully loaded torrents.fastresume: /config/state/torrents.fastresume
19:44:40.947 [INFO ][deluge.core.torrentmanager :668 ] Torrent slackware64-14.2-iso from user "localclient" loaded
19:44:40.947 [INFO ][deluge.core.torrentmanager :885 ] Finished loading 1 torrents in 0:00:00.205042
19:44:41.546 [INFO ][deluge.core.torrentmanager :1612] on_alert_external_ip: 199.229.249.180
19:44:50.304 [INFO ][deluge.core.rpcserver :171 ] Deluge Client connection made from: 127.0.0.1:37718
19:44:50.558 [INFO ][deluge.core.rpcserver :197 ] Deluge client disconnected: Connection to the other side was lost in a non-clean fashion: Connection lost.
19:45:00.413 [INFO ][deluge.core.rpcserver :171 ] Deluge Client connection made from: 127.0.0.1:37726
19:45:00.453 [INFO ][deluge.core.rpcserver :197 ] Deluge client disconnected: Connection to the other side was lost in a non-clean fashion: Connection lost.
19:45:10.223 [INFO ][deluge.core.rpcserver :171 ] Deluge Client connection made from: 127.0.0.1:37732
19:45:10.355 [INFO ][deluge.core.rpcserver :197 ] Deluge client disconnected: Connection to the other side was lost in a non-clean fashion: Connection lost.
19:45:12.406 [INFO ][deluge.core.rpcserver :171 ] Deluge Client connection made from: 127.0.0.1:37734
19:45:31.945 [INFO ][deluge.core.torrentmanager :1612] on_alert_external_ip: 199.229.249.180
