jamesmcm / vopono

Run applications through VPN tunnels with temporary network namespaces
GNU General Public License v3.0
888 stars 46 forks source link

Vopono unable to connect to VPN (but bare openvpn command succeeds) #198

Open pinghedm opened 1 year ago

pinghedm commented 1 year ago

I'm trying to try out using vopono but I can't get it to complete startup.

I'm running it with a custom openvpn file on PIA (downloaded the custom file from PIA itself using their generator - the ones generated by vopono sync didn't work when I passed them to openvpn itself, but the custom ones do) - running openvpn with this as a config file does work, but vopono times out trying to start up open vpn.

I'm not a huge networking guy, so apologies if I leave out something useful; if the answer turns out to be 'I dunno, sounds like your setup is odd' I totally understand!

Version info

danny:~/.config/vopono/custom 🐍 vopono --version                                                                                                                               Sat 7 13:22:32
vopono 0.10.4
danny:~/.config/vopono/custom 🐍 openvpn --version                                                                                                                              Sat 7 13:23:55
OpenVPN 2.5.5 x86_64-pc-linux-gnu [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [PKCS11] [MH/PKTINFO] [AEAD] built on Jul 14 2022
library versions: OpenSSL 3.0.2 15 Mar 2022, LZO 2.10
Originally developed by James Yonan
Copyright (C) 2002-2021 OpenVPN Inc <sales@openvpn.net>
Compile time defines: enable_async_push=no enable_comp_stub=no enable_crypto_ofb_cfb=yes enable_debug=yes enable_def_auth=yes enable_dependency_tracking=no enable_dlopen=unknown enable_dlopen_self=unknown enable_dlopen_self_static=unknown enable_fast_install=needless enable_fragment=yes enable_iproute2=no enable_libtool_lock=yes enable_lz4=yes enable_lzo=yes enable_maintainer_mode=no enable_management=yes enable_multihome=yes enable_option_checking=no enable_pam_dlopen=no enable_pedantic=no enable_pf=yes enable_pkcs11=yes enable_plugin_auth_pam=yes enable_plugin_down_root=yes enable_plugins=yes enable_port_share=yes enable_selinux=no enable_shared=yes enable_shared_with_static_runtimes=no enable_silent_rules=no enable_small=no enable_static=yes enable_strict=no enable_strict_options=no enable_systemd=yes enable_werror=no enable_win32_dll=yes enable_x509_alt_username=yes with_aix_soname=aix with_crypto_library=openssl with_gnu_ld=yes with_mem_check=no with_sysroot=no
danny:~ 🐍 lsb_release -a                                                                                                                                                       Sat 7 13:31:36
No LSB modules are available.
Distributor ID: Ubuntu
Description:    Ubuntu 22.04.1 LTS
Release:    22.04
Codename:   jammy

vopono example command (fails)

danny:~/.config/vopono/custom 🐍 vopono -v exec --custom ~/.config/vopono/custom/france-aes-128-cbc-tcp-ip.ovpn "bash"                                                          Sat 7 13:27:33
 2023-01-07T18:27:36.578Z DEBUG vopono_core::util > Using config dir from $HOME config: /home/danny/.config
 2023-01-07T18:27:36.578Z DEBUG vopono_core::util > Cleaning dead lock files...
 2023-01-07T18:27:37.595Z DEBUG vopono_core::util::pulseaudio > Setting PULSE_SERVER to /run/user/1000/pulse/native
 2023-01-07T18:27:37.595Z INFO  vopono_core::util             > Calling sudo for elevated privileges, current user will be used as default user
 2023-01-07T18:27:37.595Z DEBUG vopono_core::util             > Args: ["vopono", "-v", "exec", "--custom", "/home/danny/.config/vopono/custom/france-aes-128-cbc-tcp-ip.ovpn", "bash"]
 2023-01-07T18:27:37.794Z DEBUG vopono_core::util > Using config dir from $HOME config: /home/danny/.config
 2023-01-07T18:27:37.794Z DEBUG vopono_core::util > Cleaning dead lock files...
 2023-01-07T18:27:38.803Z DEBUG vopono_core::util::pulseaudio > Setting PULSE_SERVER to /run/user/1000/pulse/native
 2023-01-07T18:27:38.803Z DEBUG vopono_core::util             > Using config dir from $HOME config: /home/danny/.config
 2023-01-07T18:27:38.805Z DEBUG vopono_core::util             > Existing namespaces: ["vopono_c_wyXL2eLTsm1"]
 2023-01-07T18:27:38.808Z DEBUG vopono_core::util             > PIDs active in vopono_c_wyXL2eLTsm1: []
 2023-01-07T18:27:38.808Z DEBUG vopono_core::util             > Removing dead namespace: vopono_c_wyXL2eLTsm1
 2023-01-07T18:27:38.808Z DEBUG vopono_core::util             > ip netns delete vopono_c_wyXL2eLTsm1
 2023-01-07T18:27:38.810Z DEBUG vopono_core::util             > Using config dir from $HOME config: /home/danny/.config
 2023-01-07T18:27:38.810Z DEBUG vopono_core::util             > Using config dir from $HOME config: /home/danny/.config
 2023-01-07T18:27:38.810Z DEBUG vopono::exec                  > vopono config.toml: configuration property "firewall" not found
 2023-01-07T18:27:38.810Z DEBUG vopono::exec                  > vopono config.toml: configuration property "custom_netns_name" not found
 2023-01-07T18:27:38.810Z DEBUG vopono::exec                  > vopono config.toml: configuration property "open_hosts" not found
 2023-01-07T18:27:38.810Z DEBUG vopono::exec                  > vopono config.toml: configuration property "allow_host_access" not found
 2023-01-07T18:27:38.810Z DEBUG vopono::exec                  > vopono config.toml: configuration property "postup" not found
 2023-01-07T18:27:38.810Z DEBUG vopono::exec                  > vopono config.toml: configuration property "predown" not found
 2023-01-07T18:27:38.810Z DEBUG vopono::exec                  > vopono config.toml: configuration property "user" not found
 2023-01-07T18:27:38.810Z DEBUG vopono::exec                  > vopono config.toml: configuration property "group" not found
 2023-01-07T18:27:38.810Z DEBUG vopono::exec                  > vopono config.toml: configuration property "working-directory" not found
 2023-01-07T18:27:38.810Z DEBUG vopono::exec                  > vopono config.toml: configuration property "dns" not found
 2023-01-07T18:27:38.810Z DEBUG vopono::exec                  > vopono config.toml: configuration property "interface" not found
 2023-01-07T18:27:38.810Z DEBUG vopono_core::network::network_interface > ip addr
 2023-01-07T18:27:38.813Z WARN  vopono::exec                            > Multiple network interfaces are active: [
    "enp1s0f1",
    "wlp2s0",
    "c_wyXL2eLTsm1_d@if87",
], consider specifying the interface with the -i argument. Using enp1s0f1
 2023-01-07T18:27:38.813Z DEBUG vopono::exec                            > Interface: enp1s0f1
 2023-01-07T18:27:38.816Z DEBUG vopono_core::util                       > Existing namespaces: []
 2023-01-07T18:27:38.816Z DEBUG vopono_core::util                       > ip netns add vopono_c_wyXL2eLTsm1
 2023-01-07T18:27:38.821Z INFO  vopono_core::network::netns             > Created new network namespace: vopono_c_wyXL2eLTsm1
 2023-01-07T18:27:38.824Z DEBUG vopono_core::util                       > Existing interfaces: 88: c_wyXL2eLTsm1_d@if87: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc noqueue state UP group default qlen 1000
    link/ether 32:83:04:8b:6a:97 brd ff:ff:ff:ff:ff:ff link-netnsid unknown
    inet 10.200.2.1/24 scope global c_wyXL2eLTsm1_d
       valid_lft forever preferred_lft forever
    inet6 fe80::3083:4ff:fe8b:6a97/64 scope link 
       valid_lft forever preferred_lft forever

 2023-01-07T18:27:38.825Z DEBUG vopono_core::util                       > Assigned IPs: [10.200.2.1/24]
 2023-01-07T18:27:38.826Z DEBUG vopono_core::network::netns             > ip netns exec vopono_c_wyXL2eLTsm1 ip addr add 127.0.0.1/8 dev lo
 2023-01-07T18:27:38.831Z DEBUG vopono_core::network::netns             > ip netns exec vopono_c_wyXL2eLTsm1 ip link set lo up
STATE      CONNECTIVITY  WIFI-HW  WIFI     WWAN-HW  WWAN    
connected  full          enabled  enabled  enabled  enabled 
 2023-01-07T18:27:38.881Z DEBUG vopono_core::network::veth_pair         > Detected NetworkManager running
 2023-01-07T18:27:38.881Z DEBUG vopono_core::network::veth_pair         > NetworkManager detected, adding c_wyXL2eLTsm1_d to unmanaged devices
 2023-01-07T18:27:38.881Z DEBUG vopono_core::network::veth_pair         > Appending to existing NetworkManager config file: /etc/NetworkManager/conf.d/unmanaged.conf
 2023-01-07T18:27:38.881Z DEBUG vopono_core::util                       > nmcli connection reload
 2023-01-07T18:27:38.901Z DEBUG vopono_core::network::veth_pair         > firewalld not detected running
 2023-01-07T18:27:38.901Z DEBUG vopono_core::util                       > ip link add c_wyXL2eLTsm1_d type veth peer name c_wyXL2eLTsm1_s
 2023-01-07T18:27:38.905Z DEBUG vopono_core::util                       > ip link set c_wyXL2eLTsm1_d up
 2023-01-07T18:27:38.907Z DEBUG vopono_core::util                       > ip link set c_wyXL2eLTsm1_s netns vopono_c_wyXL2eLTsm1 up
 2023-01-07T18:27:38.938Z DEBUG vopono_core::util                       > ip addr add 10.200.1.1/24 dev c_wyXL2eLTsm1_d
 2023-01-07T18:27:38.939Z DEBUG vopono_core::network::netns             > ip netns exec vopono_c_wyXL2eLTsm1 ip addr add 10.200.1.2/24 dev c_wyXL2eLTsm1_s
 2023-01-07T18:27:38.943Z DEBUG vopono_core::network::netns             > ip netns exec vopono_c_wyXL2eLTsm1 ip route add default via 10.200.1.1 dev c_wyXL2eLTsm1_s
 2023-01-07T18:27:38.947Z INFO  vopono_core::network::netns             > IP address of namespace as seen from host: 10.200.1.2
 2023-01-07T18:27:38.947Z INFO  vopono_core::network::netns             > IP address of host as seen from namespace: 10.200.1.1
 2023-01-07T18:27:38.947Z DEBUG vopono_core::util                       > nft add table inet vopono_nat
 2023-01-07T18:27:38.951Z DEBUG vopono_core::util                       > nft add chain inet vopono_nat postrouting { type nat hook postrouting priority 100 ; }
 2023-01-07T18:27:38.962Z DEBUG vopono_core::util                       > nft add rule inet vopono_nat postrouting oifname enp1s0f1 ip saddr 10.200.1.0/24 counter masquerade
 2023-01-07T18:27:38.968Z DEBUG vopono_core::util                       > nft add table inet vopono_bridge
 2023-01-07T18:27:38.971Z DEBUG vopono_core::util                       > nft add chain inet vopono_bridge forward { type filter hook forward priority -10 ; }
 2023-01-07T18:27:38.977Z DEBUG vopono_core::util                       > nft add rule inet vopono_bridge forward iifname c_wyXL2eLTsm1_d oifname enp1s0f1 counter accept
 2023-01-07T18:27:38.985Z DEBUG vopono_core::util                       > nft add rule inet vopono_bridge forward oifname c_wyXL2eLTsm1_d iifname enp1s0f1 counter accept
 2023-01-07T18:27:38.992Z DEBUG vopono_core::util                       > sysctl -q net.ipv4.ip_forward=1
 2023-01-07T18:27:38.993Z DEBUG vopono_core::network::dns_config        > Setting namespace vopono_c_wyXL2eLTsm1 DNS server to 8.8.8.8
 2023-01-07T18:27:38.995Z DEBUG vopono_core::util                       > Using config dir from $HOME config: /home/danny/.config
 2023-01-07T18:27:38.995Z DEBUG vopono_core::util                       > Using config dir from $HOME config: /home/danny/.config
 2023-01-07T18:27:38.995Z DEBUG vopono_core::util                       > Using config dir from $HOME config: /home/danny/.config
 2023-01-07T18:27:38.998Z INFO  vopono_core::network::openvpn           > Launching OpenVPN...
 2023-01-07T18:27:38.998Z DEBUG vopono_core::network::openvpn           > Detected IPv6 enabled in /sys/module/ipv6/parameters/disable
 2023-01-07T18:27:38.999Z DEBUG vopono_core::network::openvpn           > Found remotes: [Remote { host: IPv4(191.101.31.61), port: 502, protocol: TCP }]
 2023-01-07T18:27:38.999Z DEBUG vopono_core::network::netns             > ip netns exec vopono_c_wyXL2eLTsm1 openvpn --config /home/danny/.config/vopono/custom/france-aes-128-cbc-tcp-ip.ovpn --machine-readable-output --log /home/danny/.config/vopono/logs/vopono_c_wyXL2eLTsm1_openvpn.log --connect-retry-max 1 --pull-filter ignore block-outside-dns
 2023-01-07T18:27:39.004Z DEBUG vopono_core::network::openvpn           > 1673116059.004830 40 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-01-07T18:27:39.007Z DEBUG vopono_core::network::openvpn           > 1673116059.007057 40 WARNING: file 'auth.txt' is group or others accessible
 2023-01-07T18:27:39.007Z DEBUG vopono_core::network::openvpn           > 1673116059.007078 1 OpenVPN 2.5.5 x86_64-pc-linux-gnu [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [PKCS11] [MH/PKTINFO] [AEAD] built on Jul 14 2022
 2023-01-07T18:27:39.007Z DEBUG vopono_core::network::openvpn           > 1673116059.007094 1 library versions: OpenSSL 3.0.2 15 Mar 2022, LZO 2.10
 2023-01-07T18:27:39.009Z DEBUG vopono_core::network::openvpn           > 1673116059.009591 1 CRL: loaded 1 CRLs from file -----BEGIN X509 CRL-----
 2023-01-07T18:27:39.009Z DEBUG vopono_core::network::openvpn           > MIICWDCCAUAwDQYJKoZIhvcNAQENBQAwgegxCzAJBgNVBAYTAlVTMQswCQYDVQQI
 2023-01-07T18:27:39.009Z DEBUG vopono_core::network::openvpn           > EwJDQTETMBEGA1UEBxMKTG9zQW5nZWxlczEgMB4GA1UEChMXUHJpdmF0ZSBJbnRl
 2023-01-07T18:27:39.009Z DEBUG vopono_core::network::openvpn           > cm5ldCBBY2Nlc3MxIDAeBgNVBAsTF1ByaXZhdGUgSW50ZXJuZXQgQWNjZXNzMSAw
 2023-01-07T18:27:39.009Z DEBUG vopono_core::network::openvpn           > HgYDVQQDExdQcml2YXRlIEludGVybmV0IEFjY2VzczEgMB4GA1UEKRMXUHJpdmF0
 2023-01-07T18:27:39.009Z DEBUG vopono_core::network::openvpn           > ZSBJbnRlcm5ldCBBY2Nlc3MxLzAtBgkqhkiG9w0BCQEWIHNlY3VyZUBwcml2YXRl
 2023-01-07T18:27:39.010Z DEBUG vopono_core::network::openvpn           > aW50ZXJuZXRhY2Nlc3MuY29tFw0xNjA3MDgxOTAwNDZaFw0zNjA3MDMxOTAwNDZa
 2023-01-07T18:27:39.010Z DEBUG vopono_core::network::openvpn           > MCYwEQIBARcMMTYwNzA4MTkwMDQ2MBECAQYXDDE2MDcwODE5MDA0NjANBgkqhkiG
 2023-01-07T18:27:39.010Z DEBUG vopono_core::network::openvpn           > 9w0BAQ0FAAOCAQEAQZo9X97ci8EcPYu/uK2HB152OZbeZCINmYyluLDOdcSvg6B5
 2023-01-07T18:27:39.010Z DEBUG vopono_core::network::openvpn           > jI+ffKN3laDvczsG6CxmY3jNyc79XVpEYUnq4rT3FfveW1+Ralf+Vf38HdpwB8EW
 2023-01-07T18:27:39.010Z DEBUG vopono_core::network::openvpn           > B4hZlQ205+21CALLvZvR8HcPxC9KEnev1mU46wkTiov0EKc+EdRxkj5yMgv0V2Re
 2023-01-07T18:27:39.010Z DEBUG vopono_core::network::openvpn           > ze7AP+NQ9ykvDScH4eYCsmufNpIjBLhpLE2cuZZXBLcPhuRzVoU3l7A9lvzG9mjA
 2023-01-07T18:27:39.010Z DEBUG vopono_core::network::openvpn           > 5YijHJGHNjlWFqyrn1CfYS6koa4TGEPngBoAziWRbDGdhEgJABHrpoaFYaL61zqy
 2023-01-07T18:27:39.010Z DEBUG vopono_core::network::openvpn           > MR6jC0K2ps9qyZAN74LEBedEfK7tBOzWMwr58A==
 2023-01-07T18:27:39.010Z DEBUG vopono_core::network::openvpn           > -----END X509 CRL-----
 2023-01-07T18:27:39.010Z DEBUG vopono_core::network::openvpn           > 
 2023-01-07T18:27:39.010Z DEBUG vopono_core::network::openvpn           > 1673116059.009770 1 TCP/UDP: Preserving recently used remote address: [AF_INET]191.101.31.61:502
 2023-01-07T18:27:39.010Z DEBUG vopono_core::network::openvpn           > 1673116059.009799 1 Attempting to establish TCP connection with [AF_INET]191.101.31.61:502 [nonblock]
 2023-01-07T18:29:39.127Z DEBUG vopono_core::network::openvpn           > 1673116179.127933 1000021 TCP: connect to [AF_INET]191.101.31.61:502 failed: Connection timed out
 2023-01-07T18:29:39.128Z DEBUG vopono_core::network::openvpn           > 1673116179.128028 1 SIGUSR1[connection failed(soft),init_instance] received, process restarting
 2023-01-07T18:29:44.128Z DEBUG vopono_core::network::openvpn           > 1673116184.128140 10 All connections have been connect-retry-max (1) times unsuccessful, exiting
 2023-01-07T18:29:44.128Z DEBUG vopono_core::network::openvpn           > 1673116184.128156 1 Exiting due to fatal error

openvpn command that vopono is executing, as per its output (I removed the logfile flag so it would just print directly) (succeeds - in a different split I can run ex curl ifconfig.me and I get a different ip address than my actual one)

danny:~/.config/vopono/custom 🐍 sudo openvpn --config /home/danny/.config/vopono/custom/france-aes-128-cbc-tcp-ip.ovpn --machine-readable-output --connect-retry-max 1 --pull-filter ignore block-outside-dns
1673116287.172555 40 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.
1673116287.174104 40 WARNING: file 'auth.txt' is group or others accessible
1673116287.174117 1 OpenVPN 2.5.5 x86_64-pc-linux-gnu [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [PKCS11] [MH/PKTINFO] [AEAD] built on Jul 14 2022
1673116287.174132 1 library versions: OpenSSL 3.0.2 15 Mar 2022, LZO 2.10
1673116287.175794 1 CRL: loaded 1 CRLs from file -----BEGIN X509 CRL-----
MIICWDCCAUAwDQYJKoZIhvcNAQENBQAwgegxCzAJBgNVBAYTAlVTMQswCQYDVQQI
EwJDQTETMBEGA1UEBxMKTG9zQW5nZWxlczEgMB4GA1UEChMXUHJpdmF0ZSBJbnRl
cm5ldCBBY2Nlc3MxIDAeBgNVBAsTF1ByaXZhdGUgSW50ZXJuZXQgQWNjZXNzMSAw
HgYDVQQDExdQcml2YXRlIEludGVybmV0IEFjY2VzczEgMB4GA1UEKRMXUHJpdmF0
ZSBJbnRlcm5ldCBBY2Nlc3MxLzAtBgkqhkiG9w0BCQEWIHNlY3VyZUBwcml2YXRl
aW50ZXJuZXRhY2Nlc3MuY29tFw0xNjA3MDgxOTAwNDZaFw0zNjA3MDMxOTAwNDZa
MCYwEQIBARcMMTYwNzA4MTkwMDQ2MBECAQYXDDE2MDcwODE5MDA0NjANBgkqhkiG
9w0BAQ0FAAOCAQEAQZo9X97ci8EcPYu/uK2HB152OZbeZCINmYyluLDOdcSvg6B5
jI+ffKN3laDvczsG6CxmY3jNyc79XVpEYUnq4rT3FfveW1+Ralf+Vf38HdpwB8EW
B4hZlQ205+21CALLvZvR8HcPxC9KEnev1mU46wkTiov0EKc+EdRxkj5yMgv0V2Re
ze7AP+NQ9ykvDScH4eYCsmufNpIjBLhpLE2cuZZXBLcPhuRzVoU3l7A9lvzG9mjA
5YijHJGHNjlWFqyrn1CfYS6koa4TGEPngBoAziWRbDGdhEgJABHrpoaFYaL61zqy
MR6jC0K2ps9qyZAN74LEBedEfK7tBOzWMwr58A==
-----END X509 CRL-----

1673116287.175950 1 TCP/UDP: Preserving recently used remote address: [AF_INET]191.101.31.61:502
1673116287.175972 1 Attempting to establish TCP connection with [AF_INET]191.101.31.61:502 [nonblock]
1673116287.255331 1 TCP connection established with [AF_INET]191.101.31.61:502
1673116287.255370 1 TCP_CLIENT link local: (not bound)
1673116287.255383 1 TCP_CLIENT link remote: [AF_INET]191.101.31.61:502
1673116287.915347 1 [paris412] Peer Connection Initiated with [AF_INET]191.101.31.61:502
1673116287.997279 40 sitnl_send: rtnl: generic error (-101): Network is unreachable
1673116287.998343 1 TUN/TAP device tun0 opened
1673116287.998431 1 net_iface_mtu_set: mtu 1500 for tun0
1673116287.998551 1 net_iface_up: set tun0 up
1673116287.999900 1 net_addr_v4_add: 10.21.111.33/24 dev tun0
1673116288.002548 1 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.
1673116288.002567 1 add_route_ipv6(2000::/3 -> :: metric -1) dev tun0
1673116288.002902 40 WARNING: this configuration may cache passwords in memory -- use the auth-nocache option to prevent this
1673116288.002917 1 Initialization Sequence Completed

I notice that the openvpn command does initially say network is unreachable (

1673116287.915347 1 [paris412] Peer Connection Initiated with [AF_INET]191.101.31.61:502
1673116287.997279 40 sitnl_send: rtnl: generic error (-101): Network is unreachable

)

but then continues on, whereas in the vopono command it seems to just fail after timing out there. I don't know enough to know if this is significant or trivial, or if there's something obvious that implies about my networking (which is not unusual as far as I know!) that either I or vopono can change.

If there's other information I can provide, happy to.
Thanks!

jamesmcm commented 1 year ago

It's weird that it works when run separately despite having --connect-retry-max 1 set and the same temporary connection issue.

Maybe try using iptables in case it's a firewall issue - --firewall iptables

pinghedm commented 1 year ago

That did fix things. Thank you for your help, and for building the tool in the first place!