schwabe / ics-openvpn

OpenVPN for Android
3.31k stars 1.2k forks source link

Authentications breaks after connecting successfully a few times #1569

Closed NotAPerso closed 1 year ago

NotAPerso commented 1 year ago

General information

  1. Android Version 13
  2. Android Vendor/Custom ROM GrapheneOS
  3. Device Pixel 7 Pro
  4. Version of the app (version number/play store version/self-built) 0.7.43 F-droid

Description of the issue

After setting a default VPN all VPN connections will fail authentication. Without default VPN set authentication works properly.

This issue is not present in 0.7.42 f-droid

schwabe commented 1 year ago

Can you give a log or some more details? What authentication are you using for the VPN? And this would also be very surprising since 0.7.43 does not touch anything related to authentication or default VPN at all.

NotAPerso commented 1 year ago

Sorry, I guess I was a bit overconfident in my quick troubleshooting tests. The issue just took a bit longer to show up when I didn't set default VPN and when I used the older version.

But here's a log of the with failing after it has succeeded using the same credentials several times previously.

2022-12-27 21:00:55 F-Droid built and signed version 0.7.43 running on google Pixel 7 Pro (cheetah), Android 13 (TQ1A.221205.011) API 33, ABI arm64-v8a, (google/cheetah/cheetah:13/TQ1A.221205.011/2022122000:user/release-keys)
2022-12-27 21:00:55 Building configuration…
2022-12-27 21:00:55 Fetched VPN profile (us9398.nordvpn.com.tcp) triggered by main profile list
2022-12-27 21:00:55 started Socket Thread
2022-12-27 21:00:55 Network Status: CONNECTED  to WIFI 
2022-12-27 21:00:55 Debug state info: CONNECTED  to WIFI , pause: userPause, shouldbeconnected: true, network: SHOULDBECONNECTED 
2022-12-27 21:00:55 Debug state info: CONNECTED  to WIFI , pause: userPause, shouldbeconnected: true, network: SHOULDBECONNECTED 
2022-12-27 21:00:55 P:WARNING: linker: Warning: "/data/app/~~Ddvijq4dF03U-WSeDChmrQ==/de.blinkt.openvpn-zuTVbC9ca4YEZ98-qInE_g==/lib/arm64/libovpnexec.so" is not a directory (ignoring)
2022-12-27 21:00:55 WARNING: Compression for receiving enabled. Compression has been used in the past to break encryption. Sent packets are not compressed unless "allow-compression yes" is also set.
2022-12-27 21:00:55 DEPRECATED OPTION: --cipher set to 'AES-256-CBC' but missing in --data-ciphers (AES-256-GCM:AES-128-GCM:CHACHA20-POLY1305). OpenVPN ignores --cipher for cipher negotiations. 
2022-12-27 21:00:55 Current Parameter Settings:
2022-12-27 21:00:55   config = 'stdin'
2022-12-27 21:00:55   mode = 0
2022-12-27 21:00:55   show_ciphers = DISABLED
2022-12-27 21:00:55   show_digests = DISABLED
2022-12-27 21:00:55   show_engines = DISABLED
2022-12-27 21:00:55   genkey = DISABLED
2022-12-27 21:00:55   genkey_filename = '[UNDEF]'
2022-12-27 21:00:55   key_pass_file = '[UNDEF]'
2022-12-27 21:00:55   show_tls_ciphers = DISABLED
2022-12-27 21:00:55   connect_retry_max = 5
2022-12-27 21:00:55 Connection profiles [0]:
2022-12-27 21:00:55   proto = tcp-client
2022-12-27 21:00:55   local = '[UNDEF]'
2022-12-27 21:00:55   local_port = '[UNDEF]'
2022-12-27 21:00:55   remote = '185.203.218.156'
2022-12-27 21:00:55   remote_port = '443'
2022-12-27 21:00:55   remote_float = DISABLED
2022-12-27 21:00:55   bind_defined = DISABLED
2022-12-27 21:00:55   bind_local = DISABLED
2022-12-27 21:00:55   bind_ipv6_only = DISABLED
2022-12-27 21:00:55   connect_retry_seconds = 10
2022-12-27 21:00:55   connect_timeout = 120
2022-12-27 21:00:55   socks_proxy_server = '[UNDEF]'
2022-12-27 21:00:55   socks_proxy_port = '[UNDEF]'
2022-12-27 21:00:55   tun_mtu = 1500
2022-12-27 21:00:55   tun_mtu_defined = ENABLED
2022-12-27 21:00:55   link_mtu = 1500
2022-12-27 21:00:55   link_mtu_defined = DISABLED
2022-12-27 21:00:55   tun_mtu_extra = 32
2022-12-27 21:00:55   tun_mtu_extra_defined = ENABLED
2022-12-27 21:00:55   tls_mtu = 1250
2022-12-27 21:00:55   mtu_discover_type = -1
2022-12-27 21:00:55   fragment = 0
2022-12-27 21:00:55   mssfix = 1492
2022-12-27 21:00:55   mssfix_encap = ENABLED
2022-12-27 21:00:55   mssfix_fixed = DISABLED
2022-12-27 21:00:55   explicit_exit_notification = 0
2022-12-27 21:00:55   tls_auth_file = '[INLINE]'
2022-12-27 21:00:55   key_direction = 1
2022-12-27 21:00:55   tls_crypt_file = '[UNDEF]'
2022-12-27 21:00:55   tls_crypt_v2_file = '[UNDEF]'
2022-12-27 21:00:55 Connection profiles END
2022-12-27 21:00:55   remote_random = DISABLED
2022-12-27 21:00:55   ipchange = '[UNDEF]'
2022-12-27 21:00:55   dev = 'tun'
2022-12-27 21:00:55   dev_type = '[UNDEF]'
2022-12-27 21:00:55   dev_node = '[UNDEF]'
2022-12-27 21:00:55   lladdr = '[UNDEF]'
2022-12-27 21:00:55   topology = 1
2022-12-27 21:00:55   ifconfig_local = '[UNDEF]'
2022-12-27 21:00:55   ifconfig_remote_netmask = '[UNDEF]'
2022-12-27 21:00:55   ifconfig_noexec = DISABLED
2022-12-27 21:00:55   ifconfig_nowarn = ENABLED
2022-12-27 21:00:55   ifconfig_ipv6_local = '[UNDEF]'
2022-12-27 21:00:55   ifconfig_ipv6_netbits = 0
2022-12-27 21:00:55   ifconfig_ipv6_remote = '[UNDEF]'
2022-12-27 21:00:55   shaper = 0
2022-12-27 21:00:55   mtu_test = 0
2022-12-27 21:00:55   mlock = DISABLED
2022-12-27 21:00:55   keepalive_ping = 0
2022-12-27 21:00:55 Waiting 0s seconds between connection attempt
2022-12-27 21:00:55   keepalive_timeout = 0
2022-12-27 21:00:55   inactivity_timeout = 0
2022-12-27 21:00:55   session_timeout = 0
2022-12-27 21:00:55   inactivity_minimum_bytes = 0
2022-12-27 21:00:55   ping_send_timeout = 15
2022-12-27 21:00:55   ping_rec_timeout = 0
2022-12-27 21:00:55   ping_rec_timeout_action = 2
2022-12-27 21:00:55   ping_timer_remote = ENABLED
2022-12-27 21:00:55   remap_sigusr1 = 0
2022-12-27 21:00:55   persist_tun = ENABLED
2022-12-27 21:00:55   persist_local_ip = DISABLED
2022-12-27 21:00:55   persist_remote_ip = DISABLED
2022-12-27 21:00:55   persist_key = DISABLED
2022-12-27 21:00:55   passtos = DISABLED
2022-12-27 21:00:55   resolve_retry_seconds = 1000000000
2022-12-27 21:00:55   resolve_in_advance = ENABLED
2022-12-27 21:00:55   username = '[UNDEF]'
2022-12-27 21:00:55   groupname = '[UNDEF]'
2022-12-27 21:00:55   chroot_dir = '[UNDEF]'
2022-12-27 21:00:55   cd_dir = '[UNDEF]'
2022-12-27 21:00:55   writepid = '[UNDEF]'
2022-12-27 21:00:55   up_script = '[UNDEF]'
2022-12-27 21:00:55   down_script = '[UNDEF]'
2022-12-27 21:00:55   down_pre = DISABLED
2022-12-27 21:00:55   up_restart = DISABLED
2022-12-27 21:00:55   up_delay = DISABLED
2022-12-27 21:00:55   daemon = DISABLED
2022-12-27 21:00:55   log = DISABLED
2022-12-27 21:00:55   suppress_timestamps = DISABLED
2022-12-27 21:00:55   machine_readable_output = ENABLED
2022-12-27 21:00:55   nice = 0
2022-12-27 21:00:55   verbosity = 4
2022-12-27 21:00:55   mute = 0
2022-12-27 21:00:55   gremlin = 0
2022-12-27 21:00:55   status_file = '[UNDEF]'
2022-12-27 21:00:55   status_file_version = 1
2022-12-27 21:00:55   status_file_update_freq = 60
2022-12-27 21:00:55   occ = ENABLED
2022-12-27 21:00:55   rcvbuf = 0
2022-12-27 21:00:55   sndbuf = 0
2022-12-27 21:00:55   sockflags = 0
2022-12-27 21:00:55   fast_io = ENABLED
2022-12-27 21:00:55   comp.alg = 2
2022-12-27 21:00:55   comp.flags = 1
2022-12-27 21:00:55   route_script = '[UNDEF]'
2022-12-27 21:00:55   route_default_gateway = '[UNDEF]'
2022-12-27 21:00:55   route_default_metric = 0
2022-12-27 21:00:55   route_noexec = DISABLED
2022-12-27 21:00:55   route_delay = 0
2022-12-27 21:00:55   route_delay_window = 30
2022-12-27 21:00:55   route_delay_defined = DISABLED
2022-12-27 21:00:55   route_nopull = DISABLED
2022-12-27 21:00:55   route_gateway_via_dhcp = DISABLED
2022-12-27 21:00:55   allow_pull_fqdn = DISABLED
2022-12-27 21:00:55   management_addr = '/data/user/0/de.blinkt.openvpn/cache/mgmtsocket'
2022-12-27 21:00:55   management_port = 'unix'
2022-12-27 21:00:55   management_user_pass = '[UNDEF]'
2022-12-27 21:00:55   management_log_history_cache = 250
2022-12-27 21:00:55   management_echo_buffer_size = 100
2022-12-27 21:00:55   management_client_user = '[UNDEF]'
2022-12-27 21:00:55   management_client_group = '[UNDEF]'
2022-12-27 21:00:55   management_flags = 16678
2022-12-27 21:00:55   shared_secret_file = '[UNDEF]'
2022-12-27 21:00:55   key_direction = 1
2022-12-27 21:00:55   ciphername = 'AES-256-CBC'
2022-12-27 21:00:55   ncp_ciphers = 'AES-256-GCM:AES-128-GCM:CHACHA20-POLY1305'
2022-12-27 21:00:55   authname = 'SHA512'
2022-12-27 21:00:55   engine = DISABLED
2022-12-27 21:00:55   replay = ENABLED
2022-12-27 21:00:55   mute_replay_warnings = DISABLED
2022-12-27 21:00:55   replay_window = 64
2022-12-27 21:00:55   replay_time = 15
2022-12-27 21:00:55   packet_id_file = '[UNDEF]'
2022-12-27 21:00:55   test_crypto = DISABLED
2022-12-27 21:00:55   tls_server = DISABLED
2022-12-27 21:00:55   tls_client = ENABLED
2022-12-27 21:00:55   ca_file = '[INLINE]'
2022-12-27 21:00:55   ca_path = '[UNDEF]'
2022-12-27 21:00:55   dh_file = '[UNDEF]'
2022-12-27 21:00:55   cert_file = '[UNDEF]'
2022-12-27 21:00:55   extra_certs_file = '[UNDEF]'
2022-12-27 21:00:55   priv_key_file = '[UNDEF]'
2022-12-27 21:00:55   pkcs12_file = '[UNDEF]'
2022-12-27 21:00:55   cipher_list = '[UNDEF]'
2022-12-27 21:00:55   cipher_list_tls13 = '[UNDEF]'
2022-12-27 21:00:55   tls_cert_profile = 'legacy'
2022-12-27 21:00:55   tls_verify = '[UNDEF]'
2022-12-27 21:00:55   tls_export_cert = '[UNDEF]'
2022-12-27 21:00:55   verify_x509_type = 1
2022-12-27 21:00:55   verify_x509_name = 'CN=us9398.nordvpn.com'
2022-12-27 21:00:55   crl_file = '[UNDEF]'
2022-12-27 21:00:55   ns_cert_type = 0
2022-12-27 21:00:55   remote_cert_ku[i] = 65535
2022-12-27 21:00:55   remote_cert_ku[i] = 0
2022-12-27 21:00:55   remote_cert_ku[i] = 0
2022-12-27 21:00:55   remote_cert_ku[i] = 0
2022-12-27 21:00:55   remote_cert_ku[i] = 0
2022-12-27 21:00:55   remote_cert_ku[i] = 0
2022-12-27 21:00:55   remote_cert_ku[i] = 0
2022-12-27 21:00:55   remote_cert_ku[i] = 0
2022-12-27 21:00:55   remote_cert_ku[i] = 0
2022-12-27 21:00:55   remote_cert_ku[i] = 0
2022-12-27 21:00:55   remote_cert_ku[i] = 0
2022-12-27 21:00:55   remote_cert_ku[i] = 0
2022-12-27 21:00:55   remote_cert_ku[i] = 0
2022-12-27 21:00:55   remote_cert_ku[i] = 0
2022-12-27 21:00:55   remote_cert_ku[i] = 0
2022-12-27 21:00:55   remote_cert_ku[i] = 0
2022-12-27 21:00:55   remote_cert_eku = 'TLS Web Server Authentication'
2022-12-27 21:00:55   ssl_flags = 192
2022-12-27 21:00:55   tls_timeout = 2
2022-12-27 21:00:55   renegotiate_bytes = -1
2022-12-27 21:00:55   renegotiate_packets = 0
2022-12-27 21:00:55   renegotiate_seconds = 0
2022-12-27 21:00:55   handshake_window = 60
2022-12-27 21:00:55   transition_window = 3600
2022-12-27 21:00:55   single_session = DISABLED
2022-12-27 21:00:55   push_peer_info = DISABLED
2022-12-27 21:00:55   tls_exit = DISABLED
2022-12-27 21:00:55   tls_crypt_v2_metadata = '[UNDEF]'
2022-12-27 21:00:55   server_network = 0.0.0.0
2022-12-27 21:00:55   server_netmask = 0.0.0.0
2022-12-27 21:00:55   server_network_ipv6 = ::
2022-12-27 21:00:55   server_netbits_ipv6 = 0
2022-12-27 21:00:55   server_bridge_ip = 0.0.0.0
2022-12-27 21:00:55   server_bridge_netmask = 0.0.0.0
2022-12-27 21:00:55   server_bridge_pool_start = 0.0.0.0
2022-12-27 21:00:55   server_bridge_pool_end = 0.0.0.0
2022-12-27 21:00:55   ifconfig_pool_defined = DISABLED
2022-12-27 21:00:55   ifconfig_pool_start = 0.0.0.0
2022-12-27 21:00:55   ifconfig_pool_end = 0.0.0.0
2022-12-27 21:00:55   ifconfig_pool_netmask = 0.0.0.0
2022-12-27 21:00:55   ifconfig_pool_persist_filename = '[UNDEF]'
2022-12-27 21:00:55   ifconfig_pool_persist_refresh_freq = 600
2022-12-27 21:00:55   ifconfig_ipv6_pool_defined = DISABLED
2022-12-27 21:00:55   ifconfig_ipv6_pool_base = ::
2022-12-27 21:00:55   ifconfig_ipv6_pool_netbits = 0
2022-12-27 21:00:55   n_bcast_buf = 256
2022-12-27 21:00:55   tcp_queue_limit = 64
2022-12-27 21:00:55   real_hash_size = 256
2022-12-27 21:00:55   virtual_hash_size = 256
2022-12-27 21:00:55   client_connect_script = '[UNDEF]'
2022-12-27 21:00:55   learn_address_script = '[UNDEF]'
2022-12-27 21:00:55   client_disconnect_script = '[UNDEF]'
2022-12-27 21:00:55   client_crresponse_script = '[UNDEF]'
2022-12-27 21:00:55   client_config_dir = '[UNDEF]'
2022-12-27 21:00:55   ccd_exclusive = DISABLED
2022-12-27 21:00:55   tmp_dir = '/data/data/de.blinkt.openvpn/cache'
2022-12-27 21:00:55   push_ifconfig_defined = DISABLED
2022-12-27 21:00:55   push_ifconfig_local = 0.0.0.0
2022-12-27 21:00:55   push_ifconfig_remote_netmask = 0.0.0.0
2022-12-27 21:00:55   push_ifconfig_ipv6_defined = DISABLED
2022-12-27 21:00:55   push_ifconfig_ipv6_local = ::/0
2022-12-27 21:00:55   push_ifconfig_ipv6_remote = ::
2022-12-27 21:00:55   enable_c2c = DISABLED
2022-12-27 21:00:55   duplicate_cn = DISABLED
2022-12-27 21:00:55   cf_max = 0
2022-12-27 21:00:55   cf_per = 0
2022-12-27 21:00:55   max_clients = 1024
2022-12-27 21:00:55   max_routes_per_client = 256
2022-12-27 21:00:55   auth_user_pass_verify_script = '[UNDEF]'
2022-12-27 21:00:55   auth_user_pass_verify_script_via_file = DISABLED
2022-12-27 21:00:55   auth_token_generate = DISABLED
2022-12-27 21:00:55   auth_token_lifetime = 0
2022-12-27 21:00:55   auth_token_secret_file = '[UNDEF]'
2022-12-27 21:00:55   port_share_host = '[UNDEF]'
2022-12-27 21:00:55   port_share_port = '[UNDEF]'
2022-12-27 21:00:55   vlan_tagging = DISABLED
2022-12-27 21:00:55   vlan_accept = all
2022-12-27 21:00:55   vlan_pvid = 1
2022-12-27 21:00:55   client = ENABLED
2022-12-27 21:00:55   pull = ENABLED
2022-12-27 21:00:55   auth_user_pass_file = 'stdin'
2022-12-27 21:00:55 OpenVPN 2.7-icsopenvpn [git:icsopenvpn/v0.7.43-0-gd861a123] arm64-v8a [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [MH/PKTINFO] [AEAD] built on Dec 17 2022
2022-12-27 21:00:55 library versions: OpenSSL 3.0.7 1 Nov 2022, LZO 2.10
2022-12-27 21:00:55 MANAGEMENT: Connected to management server at /data/user/0/de.blinkt.openvpn/cache/mgmtsocket
2022-12-27 21:00:55 MANAGEMENT: CMD 'version 3'
2022-12-27 21:00:55 MANAGEMENT: CMD 'hold release'
2022-12-27 21:00:55 MANAGEMENT: CMD 'bytecount 2'
2022-12-27 21:00:55 MANAGEMENT: CMD 'state on'
2022-12-27 21:00:55 MANAGEMENT: CMD 'username 'Auth' azhooligan@yahoo.com'
2022-12-27 21:00:55 MANAGEMENT: CMD 'password [...]'
2022-12-27 21:00:55 MANAGEMENT: CMD 'proxy NONE'
2022-12-27 21:00:56 WARNING: --ping should normally be used with --ping-restart or --ping-exit
2022-12-27 21:00:56 NOTE: --fast-io is disabled since we are not using UDP
2022-12-27 21:00:56 Outgoing Control Channel Authentication: Using 512 bit message hash 'SHA512' for HMAC authentication
2022-12-27 21:00:56 Incoming Control Channel Authentication: Using 512 bit message hash 'SHA512' for HMAC authentication
2022-12-27 21:00:56 LZO compression initializing
2022-12-27 21:00:56 Control Channel MTU parms [ mss_fix:0 max_frag:0 tun_mtu:1250 tun_max_mtu:0 headroom:126 payload:1600 tailroom:126 ET:0 ]
2022-12-27 21:00:56 Data Channel MTU parms [ mss_fix:0 max_frag:0 tun_mtu:1500 tun_max_mtu:1600 headroom:136 payload:1800 tailroom:568 ET:32 ]
2022-12-27 21:00:56 Local Options String (VER=V4): 'V4,dev-type tun,link-mtu 1636,tun-mtu 1500,proto TCPv4_CLIENT,comp-lzo,keydir 1,auth SHA512,keysize 256,tls-auth,key-method 2,tls-client'
2022-12-27 21:00:56 Expected Remote Options String (VER=V4): 'V4,dev-type tun,link-mtu 1636,tun-mtu 1500,proto TCPv4_SERVER,comp-lzo,keydir 0,auth SHA512,keysize 256,tls-auth,key-method 2,tls-server'
2022-12-27 21:00:56 TCP/UDP: Preserving recently used remote address: [AF_INET]185.203.218.156:443
2022-12-27 21:00:56 Socket Buffers: R=[2097152->2097152] S=[524288->524288]
2022-12-27 21:00:56 Attempting to establish TCP connection with [AF_INET]185.203.218.156:443
2022-12-27 21:00:56 MANAGEMENT: >STATE:1672192856,TCP_CONNECT,,,,,,
2022-12-27 21:00:56 MANAGEMENT: CMD 'needok 'PROTECTFD' ok'
2022-12-27 21:00:56 TCP connection established with [AF_INET]185.203.218.156:443
2022-12-27 21:00:56 MANAGEMENT: CMD 'needok 'PROTECTFD' ok'
2022-12-27 21:00:56 TCPv4_CLIENT link local: (not bound)
2022-12-27 21:00:56 TCPv4_CLIENT link remote: [AF_INET]185.203.218.156:443
2022-12-27 21:00:56 MANAGEMENT: >STATE:1672192856,WAIT,,,,,,
2022-12-27 21:00:56 MANAGEMENT: >STATE:1672192856,AUTH,,,,,,
2022-12-27 21:00:56 TLS: Initial packet from [AF_INET]185.203.218.156:443, sid=fd990402 88360d5f
2022-12-27 21:00:56 WARNING: this configuration may cache passwords in memory -- use the auth-nocache option to prevent this
2022-12-27 21:00:56 VERIFY OK: depth=2, C=PA, O=NordVPN, CN=NordVPN Root CA
2022-12-27 21:00:56 VERIFY OK: depth=1, C=PA, O=NordVPN, CN=NordVPN CA7
2022-12-27 21:00:56 VERIFY KU OK
2022-12-27 21:00:56 Validating certificate extended key usage
2022-12-27 21:00:56 ++ Certificate has EKU (str) TLS Web Server Authentication, expects TLS Web Server Authentication
2022-12-27 21:00:56 VERIFY EKU OK
2022-12-27 21:00:56 VERIFY X509NAME OK: CN=us9398.nordvpn.com
2022-12-27 21:00:56 VERIFY OK: depth=0, CN=us9398.nordvpn.com
2022-12-27 21:00:56 WARNING: 'tun-mtu' is used inconsistently, local='tun-mtu 1500', remote='tun-mtu 1532'
2022-12-27 21:00:56 Control Channel: TLSv1.3, cipher TLSv1.3 TLS_AES_256_GCM_SHA384, peer certificate: 4096 bit RSA, signature: RSA-SHA512
2022-12-27 21:00:56 [us9398.nordvpn.com] Peer Connection Initiated with [AF_INET]185.203.218.156:443
2022-12-27 21:00:57 MANAGEMENT: >STATE:1672192857,GET_CONFIG,,,,,,
2022-12-27 21:00:57 SENT CONTROL [us9398.nordvpn.com]: 'PUSH_REQUEST' (status=1)
2022-12-27 21:01:02 SENT CONTROL [us9398.nordvpn.com]: 'PUSH_REQUEST' (status=1)
2022-12-27 21:01:02 AUTH: Received control message: AUTH_FAILED
2022-12-27 21:01:02 TCP/UDP: Closing socket
2022-12-27 21:01:02 SIGTERM[soft,auth-failure] received, process exiting
2022-12-27 21:01:02 MANAGEMENT: >STATE:1672192862,EXITING,auth-failure,,,,,
schwabe commented 1 year ago

Try to contact Nordvpn support. I need to know why the client is getting AUTH_FAILED.