PIA PORT UPDATER not connecting

begunfx commented 1 year ago

Is there a pinned issue for this?

[X] I have read the pinned issues and could not find my issue

Is there an existing or similar issue/discussion for this?

[X] I have searched the existing issues
[X] I have searched the existing discussions

Is there any comment in the documentation for this?

[X] I have read the documentation, especially the FAQ and Troubleshooting parts

Is this related to a provider?

[X] I have checked the provider repo for issues
[X] My issue is NOT related to a provider

Are you using the latest release?

[X] I am using the latest release

Have you tried using the dev branch latest?

[X] I have tried using dev branch

Docker run config used

docker run --cap-add=NET_ADMIN -d \ --name=transmission \ -p 9091:9091 \ -e TRANSMISSION_RPC_USERNAME=**** \ -e TRANSMISSION_RPC_PASSWORD=***** \ -e TRANSMISSION_RPC_AUTHENTICATION_REQUIRED=true \ -e LOCAL_NETWORK=192.168.1.0/24 \ -e OPENVPN_PROVIDER=PIA \ -e OPENVPN_CONFIG=us_california,us_las_vegas,us_seattle,us_west \ -e OPENVPN_USERNAME=**None** \ -e OPENVPN_PASSWORD=**None** \ -e TZ=America/Los_Angeles \ -e OPENVPN_OPTS='--inactive 3600 --ping 10 --ping-exit 60' \ -v /volume1/docker/transmission/data:/data \ -v /volume1/docker/transmission/config:/config \ -v /volume1/docker/transmission/config/openvpn-credentials.txt:/config/openvpn-credentials.txt \ --log-driver json-file \ --log-opt max-size=10m \ haugene/transmission-openvpn:dev

Current Behavior

If I run the above docker command without the port updater variable disabled: -e DISABLE_PORT_UPDATER=true

Then, transmission doesn't seem to connect to any trackers whatsoever. However, if I include the above environment variable, it runs without issue.

Please see issue haugene/docker-transmission-openvpn#1570 This is most likely the same issue, but that issue was closed.

Expected Behavior

I expect transmission and an openVPN connection so I can connect to trackers to download files.

How have you tried to solve the problem?

I started by following the troubleshooting page - ran through every step and in the end the docker command provided there had Transmission and OpenVPN working correctly. I slowly added my Docker run to the sample command and found the only difference that caused the failures was not having: -e DISABLE_PORT_UPDATER=true

Log output

I cannot find any logs to provide.

HW/SW Environment

- OS: Synology DSM 7.1.1
- Docker: latest dev version

Anything else?

My VPN provider is PIA and I'm using US based servers.

pkishino commented 1 year ago

Without at least docker logs can’t do much.. please provide these

begunfx commented 1 year ago

Where can I find them? I looked inside the log in the container itself and it's empty. I have a synology RS1815+ running the latest DSM 7.2

begunfx commented 1 year ago

Okay. Here are the logs when I do NOT disable the port updater script:

2023-05-17 17:36:59 OPTIONS IMPORT: route-related options modified
2023-05-17 17:36:59 OPTIONS IMPORT: --ip-win32 and/or --dhcp-option options modified
2023-05-17 17:36:59 OPTIONS IMPORT: peer-id set
2023-05-17 17:36:59 OPTIONS IMPORT: adjusting link_mtu to 1625
2023-05-17 17:36:59 OPTIONS IMPORT: data channel crypto options modified
2023-05-17 17:36:59 Data Channel: using negotiated cipher 'AES-128-GCM'
2023-05-17 17:36:59 Outgoing Data Channel: Cipher 'AES-128-GCM' initialized with 128 bit key
2023-05-17 17:36:59 Incoming Data Channel: Cipher 'AES-128-GCM' initialized with 128 bit key
2023-05-17 17:36:59 net_route_v4_best_gw query: dst 0.0.0.0
2023-05-17 17:36:59 net_route_v4_best_gw result: via 172.17.0.1 dev eth0
2023-05-17 17:36:59 ROUTE_GATEWAY 172.17.0.1/255.255.0.0 IFACE=eth0 HWADDR=02:42:ac:11:00:04
2023-05-17 17:36:59 GDG6: remote_host_ipv6=n/a
2023-05-17 17:36:59 net_route_v6_best_gw query: dst ::
2023-05-17 17:36:59 net_route_v6_best_gw result: via :: dev lo
2023-05-17 17:36:59 ROUTE6_GATEWAY :: ON_LINK IFACE=lo
2023-05-17 17:36:59 TUN/TAP device tun0 opened
2023-05-17 17:36:59 net_iface_mtu_set: mtu 1500 for tun0
2023-05-17 17:36:59 net_iface_up: set tun0 up
2023-05-17 17:36:59 net_addr_v4_add: 10.19.112.199/24 dev tun0
2023-05-17 17:36:59 net_route_v4_add: 191.101.61.152/32 via 172.17.0.1 dev [NULL] table 0 metric -1
2023-05-17 17:36:59 net_route_v4_add: 0.0.0.0/1 via 10.19.112.1 dev [NULL] table 0 metric -1
2023-05-17 17:36:59 net_route_v4_add: 128.0.0.0/1 via 10.19.112.1 dev [NULL] table 0 metric -1
2023-05-17 17:36:59 WARNING: OpenVPN was configured to add an IPv6 route. However, no IPv6 has been configured for tun0, therefore the route installation may fail or may not work as expected.
2023-05-17 17:36:59 add_route_ipv6(2000::/3 -> :: metric -1) dev tun0
2023-05-17 17:36:59 net_route_v6_add: 2000::/3 via :: dev tun0 table 0 metric -1
Up script executed with device=tun0 ifconfig_local=10.19.112.199
Updating TRANSMISSION_BIND_ADDRESS_IPV4 to the ip of tun0 : 10.19.112.199
-------------------------------------
Transmission will run as
-------------------------------------
User name:   [REDACTED]
User uid:    [REDACTED]
User gid:    [REDACTED]
-------------------------------------
Updating Transmission settings.json with values from env variables
Attempting to use existing settings.json for Transmission
Could not read existing settings.json. Generating settings.json for Transmission from environment and defaults /etc/transmission/default-settings.json
Overriding bind-address-ipv4 because TRANSMISSION_BIND_ADDRESS_IPV4 is set to 10.19.112.199
Overriding download-dir because TRANSMISSION_DOWNLOAD_DIR is set to /data/completed
Overriding incomplete-dir because TRANSMISSION_INCOMPLETE_DIR is set to /data/incomplete
Overriding rpc-authentication-required because TRANSMISSION_RPC_AUTHENTICATION_REQUIRED is set to true
Overriding rpc-password because TRANSMISSION_RPC_PASSWORD is set to [REDACTED]
Overriding rpc-port because TRANSMISSION_RPC_PORT is set to 9091
Overriding rpc-username because TRANSMISSION_RPC_USERNAME is set to [REDACTED]
Overriding watch-dir because TRANSMISSION_WATCH_DIR is set to /data/watch
sed'ing True to true
STARTING TRANSMISSION
Provider PIA has a script for automatic port forwarding. Will run it now.
If you want to disable this, set environment variable DISABLE_PORT_UPDATER=true
Transmission startup script complete.
2023-05-17 17:36:59 WARNING: this configuration may cache passwords in memory -- use the auth-nocache option to prevent this
2023-05-17 17:36:59 Initialization Sequence Completed
Running functions for token based port fowarding
curl: (7) Failed to connect to 10.19.112.1 port 19999 after 18 ms: Connection refused
Wed May 17 17:37:05 PDT 2023: getSignature error
the has been a fatal_error
curl: (7) Failed to connect to 10.19.112.1 port 19999 after 17 ms: Connection refused
Wed May 17 17:37:05 PDT 2023: bindPort error
the has been a fatal_error
transmission auth required
waiting for transmission to become responsive
transmission became responsive
    ID   Done       Have  ETA           Up    Down  Ratio  Status       Name
Sum:                None               0.0     0.0
setting transmission port to 
localhost:9091/transmission/rpc/ responded: success
Checking port...
Error: Couldn't test port: Bad Request (400)
#######################
        SUCCESS        
#######################
Port: 
Expiration Wed May 17 00:00:00 PDT 2023
#######################
Entering infinite while loop
Every 15 minutes, check port status
60 day port reservation reached
Getting a new one
curl: (7) Failed to connect to 10.19.112.1 port 19999 after 19 ms: Connection refused
Wed May 17 17:37:17 PDT 2023: getSignature error
the has been a fatal_error
curl: (7) Failed to connect to 10.19.112.1 port 19999 after 17 ms: Connection refused
Wed May 17 17:37:18 PDT 2023: bindPort error
the has been a fatal_error
transmission auth required
waiting for transmission to become responsive
transmission became responsive
    ID   Done       Have  ETA           Up    Down  Ratio  Status       Name
Sum:                None               0.0     0.0
setting transmission port to 
localhost:9091/transmission/rpc/ responded: success
Checking port...
Error: Couldn't test port: Bad Request (400)

begunfx commented 1 year ago

As you can see there are failed to connect errors when the port updater script is allowed to run. I'll post another log with it disabled.

begunfx commented 1 year ago

The following log is with the Port Updater script disabled:


Modification: Change ping options
Modification: Update/set resolv-retry to 15 seconds
Modification: Change tls-crypt keyfile path
Modification: Set output verbosity to 3
Modification: Remap SIGUSR1 signal to SIGTERM, avoid OpenVPN restart loop
Modification: Updating status for config failure detection
Found existing OPENVPN credentials at /config/openvpn-credentials.txt
adding route to local network 192.168.1.0/24 via 172.17.0.1 dev eth0
2023-05-17 17:44:02 DEPRECATED OPTION: --cipher set to 'aes-128-cbc' but missing in --data-ciphers (AES-256-GCM:AES-128-GCM). Future OpenVPN version will ignore --cipher for cipher negotiations. Add 'aes-128-cbc' to --data-ciphers or change --cipher 'aes-128-cbc' to --data-ciphers-fallback 'aes-128-cbc' to silence this warning.
2023-05-17 17:44:02 OpenVPN 2.5.5 x86_64-pc-linux-gnu [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [PKCS11] [MH/PKTINFO] [AEAD] built on Jul 14 2022
2023-05-17 17:44:02 library versions: OpenSSL 3.0.2 15 Mar 2022, LZO 2.10
2023-05-17 17:44:02 NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
2023-05-17 17:44:02 CRL: loaded 1 CRLs from file -----BEGIN X509 CRL-----
[Redacted]
-----END X509 CRL-----
2023-05-17 17:44:02 TCP/UDP: Preserving recently used remote address: [AF_INET]191.101.61.66:1198
2023-05-17 17:44:02 Socket Buffers: R=[212992->212992] S=[212992->212992]
2023-05-17 17:44:02 UDP link local: (not bound)
2023-05-17 17:44:02 UDP link remote: [AF_INET]191.101.61.66:1198
2023-05-17 17:44:02 TLS: Initial packet from [AF_INET]191.101.61.66:1198, sid=dc98f394 93e4be9e
2023-05-17 17:44:02 VERIFY OK: depth=1, C=US, ST=CA, L=LosAngeles, O=Private Internet Access, OU=Private Internet Access, CN=Private Internet Access, name=Private Internet Access, emailAddress=secure@privateinternetaccess.com
2023-05-17 17:44:02 VERIFY KU OK
2023-05-17 17:44:02 Validating certificate extended key usage
2023-05-17 17:44:02 ++ Certificate has EKU (str) TLS Web Server Authentication, expects TLS Web Server Authentication
2023-05-17 17:44:02 VERIFY EKU OK
2023-05-17 17:44:02 VERIFY OK: depth=0, C=US, ST=CA, L=LosAngeles, O=Private Internet Access, OU=Private Internet Access, CN=lasvegas421, name=lasvegas421
2023-05-17 17:44:03 Control Channel: TLSv1.3, cipher TLSv1.3 TLS_AES_256_GCM_SHA384, peer certificate: 2048 bit RSA, signature: RSA-SHA512
2023-05-17 17:44:03 [lasvegas421] Peer Connection Initiated with [AF_INET]191.101.61.66:1198
2023-05-17 17:44:03 PUSH: Received control message: 'PUSH_REPLY,comp-lzo no,redirect-gateway def1,route-ipv6 2000::/3,dhcp-option DNS 10.0.0.243,route-gateway 10.26.112.1,topology subnet,ping 10,ping-restart 60,ifconfig 10.26.112.196 255.255.255.0,peer-id 4,cipher AES-128-GCM'
2023-05-17 17:44:03 OPTIONS IMPORT: timers and/or timeouts modified
2023-05-17 17:44:03 OPTIONS IMPORT: compression parms modified
2023-05-17 17:44:03 OPTIONS IMPORT: --ifconfig/up options modified
2023-05-17 17:44:03 OPTIONS IMPORT: route options modified
2023-05-17 17:44:03 OPTIONS IMPORT: route-related options modified
2023-05-17 17:44:03 OPTIONS IMPORT: --ip-win32 and/or --dhcp-option options modified
2023-05-17 17:44:03 OPTIONS IMPORT: peer-id set
2023-05-17 17:44:03 OPTIONS IMPORT: adjusting link_mtu to 1625
2023-05-17 17:44:03 OPTIONS IMPORT: data channel crypto options modified
2023-05-17 17:44:03 Data Channel: using negotiated cipher 'AES-128-GCM'
2023-05-17 17:44:03 Outgoing Data Channel: Cipher 'AES-128-GCM' initialized with 128 bit key
2023-05-17 17:44:03 Incoming Data Channel: Cipher 'AES-128-GCM' initialized with 128 bit key
2023-05-17 17:44:03 net_route_v4_best_gw query: dst 0.0.0.0
2023-05-17 17:44:03 net_route_v4_best_gw result: via 172.17.0.1 dev eth0
2023-05-17 17:44:03 ROUTE_GATEWAY 172.17.0.1/255.255.0.0 IFACE=eth0 HWADDR=02:42:ac:11:00:04
2023-05-17 17:44:03 GDG6: remote_host_ipv6=n/a
2023-05-17 17:44:03 net_route_v6_best_gw query: dst ::
2023-05-17 17:44:03 net_route_v6_best_gw result: via :: dev lo
2023-05-17 17:44:03 ROUTE6_GATEWAY :: ON_LINK IFACE=lo
2023-05-17 17:44:03 TUN/TAP device tun0 opened
2023-05-17 17:44:03 net_iface_mtu_set: mtu 1500 for tun0
2023-05-17 17:44:03 net_iface_up: set tun0 up
2023-05-17 17:44:03 net_addr_v4_add: 10.26.112.196/24 dev tun0
2023-05-17 17:44:03 net_route_v4_add: 191.101.61.66/32 via 172.17.0.1 dev [NULL] table 0 metric -1
2023-05-17 17:44:03 net_route_v4_add: 0.0.0.0/1 via 10.26.112.1 dev [NULL] table 0 metric -1
2023-05-17 17:44:03 net_route_v4_add: 128.0.0.0/1 via 10.26.112.1 dev [NULL] table 0 metric -1
2023-05-17 17:44:03 WARNING: OpenVPN was configured to add an IPv6 route. However, no IPv6 has been configured for tun0, therefore the route installation may fail or may not work as expected.
2023-05-17 17:44:03 add_route_ipv6(2000::/3 -> :: metric -1) dev tun0
2023-05-17 17:44:03 net_route_v6_add: 2000::/3 via :: dev tun0 table 0 metric -1
Up script executed with device=tun0 ifconfig_local=10.26.112.196
Updating TRANSMISSION_BIND_ADDRESS_IPV4 to the ip of tun0 : 10.26.112.196
-------------------------------------
Transmission will run as
-------------------------------------
User name:   [Redacted]
User uid:    [Redacted]
User gid:    [Redacted]
-------------------------------------
Updating Transmission settings.json with values from env variables
Attempting to use existing settings.json for Transmission
Could not read existing settings.json. Generating settings.json for Transmission from environment and defaults /etc/transmission/default-settings.json
Overriding bind-address-ipv4 because TRANSMISSION_BIND_ADDRESS_IPV4 is set to 10.26.112.196
Overriding download-dir because TRANSMISSION_DOWNLOAD_DIR is set to /data/completed
Overriding incomplete-dir because TRANSMISSION_INCOMPLETE_DIR is set to /data/incomplete
Overriding rpc-authentication-required because TRANSMISSION_RPC_AUTHENTICATION_REQUIRED is set to true
Overriding rpc-password because TRANSMISSION_RPC_PASSWORD is set to [REDACTED]
Overriding rpc-port because TRANSMISSION_RPC_PORT is set to 9091
Overriding rpc-username because TRANSMISSION_RPC_USERNAME is set to [Redacted]
Overriding watch-dir because TRANSMISSION_WATCH_DIR is set to /data/watch
sed'ing True to true
STARTING TRANSMISSION
Transmission startup script complete.
2023-05-17 17:44:03 WARNING: this configuration may cache passwords in memory -- use the auth-nocache option to prevent this
2023-05-17 17:44:03 Initialization Sequence Completed```

begunfx commented 1 year ago

As you can see by the two logs, if the port updater script is not used I don't get connection errors.

pkishino commented 1 year ago

Yeah, this is some connection problem with PIA provider script then, I’ll move it the provider repo and hopefully someone who uses pia can fix this

pkishino commented 1 year ago

This seems to be related to PiA servers that do not support port forwarding.. I’ll take a look at the script and see if I can catch the error and print a message about checking with PIA if the server supports this feature or not

begunfx commented 1 year ago

Awesome. Thank you.

pkishino commented 1 year ago

added a simple log update [5113025] this should better help users understand the problem

haugene / vpn-configs-contrib