Having an "interesting" time with Sierra Wireless WWAN router & OpenVPN

Need help configuring your VPN? Just post here and you'll get that help.

Moderators: TinCanTech, TinCanTech, TinCanTech, TinCanTech, TinCanTech, TinCanTech

Forum rules
Please use the [oconf] BB tag for openvpn Configurations. See viewtopic.php?f=30&t=21589 for an example.
etaoin
OpenVPN User
Posts: 24
Joined: Wed Aug 09, 2017 5:53 pm

Having an "interesting" time with Sierra Wireless WWAN router & OpenVPN

Post by etaoin » Wed Aug 09, 2017 6:04 pm

Hi all,

I've been hacking away for a couple of days now, trying to get the OpenVPN client running on a Sierra Wireless WWAN router to connect with my 2.3.10 OpenVPN server. Having already negotiated some other issues I now find myself stuck with:

Code: Select all

TLS_ERROR: BIO read tls_read_plaintext error: error:1408A0C1:SSL routines:ssl3_get_client_hello:no shared cipher

I think I understand that this relates to what TLS ciphers are available (and enabled) on the client and server, and that they cannot negotiate a matching cipher method. In desperation I have enabled a whole slew of ciphers on the server, so my OpenVPN config now contains:

Code: Select all

tls-cipher TLS-DHE-RSA-WITH-AES-128-GCM-SHA256:TLS-ECDHE-RSA-WITH-AES-128-GCM-SHA256:TLS-ECDHE-ECDSA-WITH-AES-128-GCM-SHA256:TLS-ECDHE-RSA-WITH-AES-256-GCM-SHA384:TLS-DHE-RSA-WITH-AES-128-GCM-SHA256
Bit of a mouthful, but still the same error. I am unable to verify which TLS ciphers are supported by the client; the manual doesn't say anything other than:
Additional TLS Authentication
Enables or disables use of Transport Layer Security (TLS) authentication.

Load Client TLS Key
This field appears only if Additional TLS Authentication is enabled. Loads the client TLS key. When you click the button, a window pops up and enables you to browse and select the file containing the client TLS key.

Client TLS Key Name
Displays the name of the most recently uploaded client TLS key.
And the SSH console provided by the router only allows "AT" commands, so I cannot query the OpenVPN or OpenSSL versions running on it. What steps can I take to analyse this further?

etaoin
OpenVPN User
Posts: 24
Joined: Wed Aug 09, 2017 5:53 pm

Re: Having an "interesting" time with Sierra Wireless WWAN router & OpenVPN

Post by etaoin » Mon Aug 14, 2017 10:02 pm

*bump*

Also, to add, I can connect just fine to the OpenVPN server from my laptop, with a second set of certificates and keys generated with the same settings. So it's not going to be a firewall issue, for example (I have tried turning all filtering off on the WWAN router as well).

One thing has changed though: if I comment out the "tls-cipher" line altogether in server.conf and restart the openvpn service, I no longer get the "no shared cipher" error on incoming connections from the WLAN router - but instead a "TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity)". This happens only when trying to connect from the WWAN router - the test connection I set up on my laptop still works fine - and it happens regardless of whether the WLAN router's (inbound and outbound) firewall is enabled or not. Please, I'm several days into this now, if anyone can give me some helpful pointers or suggestions for what to check I would be tremendously thankful.

TinCanTech
OpenVPN Protagonist
Posts: 11137
Joined: Fri Jun 03, 2016 1:17 pm

Re: Having an "interesting" time with Sierra Wireless WWAN router & OpenVPN

Post by TinCanTech » Tue Aug 15, 2017 10:47 am

Please see:
HOWTO: Request Help ! {2}

Basically, your logs at --verb 4 and your config files.

And your router details .. like model number.

etaoin
OpenVPN User
Posts: 24
Joined: Wed Aug 09, 2017 5:53 pm

Re: Having an "interesting" time with Sierra Wireless WWAN router & OpenVPN

Post by etaoin » Wed Aug 16, 2017 2:15 pm

@TinCanTech: Thank you - see below:

/etc/openvpn/server.conf

Code: Select all

local 22.33.44.55
port 1194
proto udp
dev tun
user nobody
group nogroup
persist-key
persist-tun
keepalive 10 120
topology subnet
server 10.8.0.0 255.255.255.0
ifconfig-pool-persist ipp.txt
push "dhcp-option DNS 80.68.80.24"
push "dhcp-option DNS 80.68.80.25"
push "redirect-gateway def1 bypass-dhcp"
crl-verify crl.pem
ca ca.crt
cert server.crt
key server.key
tls-auth tls-auth.key 0
dh dh.pem
auth SHA256
cipher AES-128-CBC
tls-server
tls-version-min 1.0
# tls-cipher TLS-DHE-RSA-WITH-AES-128-CBC-SHA256:TLS-DHE-RSA-WITH-AES-256-CBC-SHA256
status openvpn.log
verb 4
/var/log/syslog (OpenVPN startup)

Code: Select all

Aug 16 14:44:23 myvpn systemd[1]: Starting OpenVPN service...
Aug 16 14:44:23 myvpn systemd[1]: Starting OpenVPN connection to server...
Aug 16 14:44:23 myvpn ovpn-server[15043]: Current Parameter Settings:
Aug 16 14:44:23 myvpn ovpn-server[15043]:   config = '/etc/openvpn/server.conf'
Aug 16 14:44:23 myvpn ovpn-server[15043]:   mode = 1
Aug 16 14:44:23 myvpn ovpn-server[15043]:   persist_config = DISABLED
Aug 16 14:44:23 myvpn ovpn-server[15043]:   persist_mode = 1
Aug 16 14:44:23 myvpn ovpn-server[15043]:   show_ciphers = DISABLED
Aug 16 14:44:23 myvpn ovpn-server[15043]:   show_digests = DISABLED
Aug 16 14:44:23 myvpn ovpn-server[15043]:   show_engines = DISABLED
Aug 16 14:44:23 myvpn ovpn-server[15043]:   genkey = DISABLED
Aug 16 14:44:23 myvpn ovpn-server[15043]:   key_pass_file = '[UNDEF]'
Aug 16 14:44:23 myvpn ovpn-server[15043]:   show_tls_ciphers = DISABLED
Aug 16 14:44:23 myvpn ovpn-server[15043]: Connection profiles [default]:
Aug 16 14:44:23 myvpn ovpn-server[15043]:   proto = udp
Aug 16 14:44:23 myvpn ovpn-server[15043]:   local = '22.33.44.55'
Aug 16 14:44:23 myvpn ovpn-server[15043]:   local_port = 1194
Aug 16 14:44:23 myvpn ovpn-server[15043]:   remote = '[UNDEF]'
Aug 16 14:44:23 myvpn ovpn-server[15043]:   remote_port = 1194
Aug 16 14:44:23 myvpn ovpn-server[15043]:   remote_float = DISABLED
Aug 16 14:44:23 myvpn ovpn-server[15043]:   bind_defined = DISABLED
Aug 16 14:44:23 myvpn ovpn-server[15043]:   bind_local = ENABLED
Aug 16 14:44:23 myvpn ovpn-server[15043]:   connect_retry_seconds = 5
Aug 16 14:44:23 myvpn ovpn-server[15043]:   connect_timeout = 10
Aug 16 14:44:23 myvpn ovpn-server[15043]:   connect_retry_max = 0
Aug 16 14:44:23 myvpn ovpn-server[15043]:   socks_proxy_server = '[UNDEF]'
Aug 16 14:44:23 myvpn ovpn-server[15043]:   socks_proxy_port = 0
Aug 16 14:44:23 myvpn ovpn-server[15043]:   socks_proxy_retry = DISABLED
Aug 16 14:44:23 myvpn ovpn-server[15043]:   tun_mtu = 1500
Aug 16 14:44:23 myvpn ovpn-server[15043]:   tun_mtu_defined = ENABLED
Aug 16 14:44:23 myvpn ovpn-server[15043]:   link_mtu = 1500
Aug 16 14:44:23 myvpn ovpn-server[15043]:   link_mtu_defined = DISABLED
Aug 16 14:44:23 myvpn ovpn-server[15043]:   tun_mtu_extra = 0
Aug 16 14:44:23 myvpn ovpn-server[15043]:   tun_mtu_extra_defined = DISABLED
Aug 16 14:44:23 myvpn ovpn-server[15043]:   mtu_discover_type = -1
Aug 16 14:44:23 myvpn ovpn-server[15043]:   fragment = 0
Aug 16 14:44:23 myvpn ovpn-server[15043]:   mssfix = 1450
Aug 16 14:44:23 myvpn ovpn-server[15043]:   explicit_exit_notification = 0
Aug 16 14:44:23 myvpn ovpn-server[15043]: Connection profiles END
Aug 16 14:44:23 myvpn ovpn-server[15043]:   remote_random = DISABLED
Aug 16 14:44:23 myvpn ovpn-server[15043]:   ipchange = '[UNDEF]'
Aug 16 14:44:23 myvpn ovpn-server[15043]:   dev = 'tun'
Aug 16 14:44:23 myvpn ovpn-server[15043]:   dev_type = '[UNDEF]'
Aug 16 14:44:23 myvpn ovpn-server[15043]:   dev_node = '[UNDEF]'
Aug 16 14:44:23 myvpn ovpn-server[15043]:   lladdr = '[UNDEF]'
Aug 16 14:44:23 myvpn ovpn-server[15043]:   topology = 3
Aug 16 14:44:23 myvpn ovpn-server[15043]:   tun_ipv6 = DISABLED
Aug 16 14:44:23 myvpn ovpn-server[15043]:   ifconfig_local = '10.8.0.1'
Aug 16 14:44:23 myvpn ovpn-server[15043]:   ifconfig_remote_netmask = '255.255.255.0'
Aug 16 14:44:23 myvpn ovpn-server[15043]:   ifconfig_noexec = DISABLED
Aug 16 14:44:23 myvpn ovpn-server[15043]:   ifconfig_nowarn = DISABLED
Aug 16 14:44:23 myvpn ovpn-server[15043]:   ifconfig_ipv6_local = '[UNDEF]'
Aug 16 14:44:23 myvpn ovpn-server[15043]:   ifconfig_ipv6_netbits = 0
Aug 16 14:44:23 myvpn ovpn-server[15043]:   ifconfig_ipv6_remote = '[UNDEF]'
Aug 16 14:44:23 myvpn ovpn-server[15043]:   shaper = 0
Aug 16 14:44:23 myvpn ovpn-server[15043]:   mtu_test = 0
Aug 16 14:44:23 myvpn ovpn-server[15043]:   mlock = DISABLED
Aug 16 14:44:23 myvpn ovpn-server[15043]:   keepalive_ping = 10
Aug 16 14:44:23 myvpn ovpn-server[15043]:   keepalive_timeout = 120
Aug 16 14:44:23 myvpn ovpn-server[15043]:   inactivity_timeout = 0
Aug 16 14:44:23 myvpn ovpn-server[15043]:   ping_send_timeout = 10
Aug 16 14:44:23 myvpn ovpn-server[15043]:   ping_rec_timeout = 240
Aug 16 14:44:23 myvpn ovpn-server[15043]:   ping_rec_timeout_action = 2
Aug 16 14:44:23 myvpn ovpn-server[15043]:   ping_timer_remote = DISABLED
Aug 16 14:44:23 myvpn ovpn-server[15043]:   remap_sigusr1 = 0
Aug 16 14:44:23 myvpn ovpn-server[15043]:   persist_tun = ENABLED
Aug 16 14:44:23 myvpn ovpn-server[15043]:   persist_local_ip = DISABLED
Aug 16 14:44:23 myvpn systemd[1]: Started OpenVPN service.
Aug 16 14:44:23 myvpn ovpn-server[15043]:   persist_remote_ip = DISABLED
Aug 16 14:44:23 myvpn systemd[1]: Started OpenVPN connection to server.
Aug 16 14:44:23 myvpn ovpn-server[15043]:   persist_key = ENABLED
Aug 16 14:44:23 myvpn ovpn-server[15043]:   passtos = DISABLED
Aug 16 14:44:23 myvpn ovpn-server[15043]:   resolve_retry_seconds = 1000000000
Aug 16 14:44:23 myvpn ovpn-server[15043]:   username = 'nobody'
Aug 16 14:44:23 myvpn ovpn-server[15043]:   groupname = 'nogroup'
Aug 16 14:44:23 myvpn ovpn-server[15043]:   chroot_dir = '[UNDEF]'
Aug 16 14:44:23 myvpn ovpn-server[15043]:   cd_dir = '/etc/openvpn'
Aug 16 14:44:23 myvpn ovpn-server[15043]:   writepid = '/run/openvpn/server.pid'
Aug 16 14:44:23 myvpn ovpn-server[15043]:   up_script = '[UNDEF]'
Aug 16 14:44:23 myvpn ovpn-server[15043]:   down_script = '[UNDEF]'
Aug 16 14:44:23 myvpn ovpn-server[15043]:   down_pre = DISABLED
Aug 16 14:44:23 myvpn ovpn-server[15043]:   up_restart = DISABLED
Aug 16 14:44:23 myvpn ovpn-server[15043]:   up_delay = DISABLED
Aug 16 14:44:23 myvpn ovpn-server[15043]:   daemon = ENABLED
Aug 16 14:44:23 myvpn ovpn-server[15043]:   inetd = 0
Aug 16 14:44:23 myvpn ovpn-server[15043]:   log = DISABLED
Aug 16 14:44:23 myvpn ovpn-server[15043]:   suppress_timestamps = DISABLED
Aug 16 14:44:23 myvpn ovpn-server[15043]:   nice = 0
Aug 16 14:44:23 myvpn ovpn-server[15043]:   verbosity = 4
Aug 16 14:44:23 myvpn ovpn-server[15043]:   mute = 0
Aug 16 14:44:23 myvpn ovpn-server[15043]:   gremlin = 0
Aug 16 14:44:23 myvpn ovpn-server[15043]:   status_file = 'openvpn.log'
Aug 16 14:44:23 myvpn ovpn-server[15043]:   status_file_version = 1
Aug 16 14:44:23 myvpn ovpn-server[15043]:   status_file_update_freq = 10
Aug 16 14:44:23 myvpn ovpn-server[15043]:   occ = ENABLED
Aug 16 14:44:23 myvpn ovpn-server[15043]:   rcvbuf = 0
Aug 16 14:44:23 myvpn ovpn-server[15043]:   sndbuf = 0
Aug 16 14:44:23 myvpn ovpn-server[15043]:   mark = 0
Aug 16 14:44:23 myvpn ovpn-server[15043]:   sockflags = 0
Aug 16 14:44:23 myvpn ovpn-server[15043]:   fast_io = DISABLED
Aug 16 14:44:23 myvpn ovpn-server[15043]:   lzo = 0
Aug 16 14:44:23 myvpn ovpn-server[15043]:   route_script = '[UNDEF]'
Aug 16 14:44:23 myvpn ovpn-server[15043]:   route_default_gateway = '10.8.0.2'
Aug 16 14:44:23 myvpn ovpn-server[15043]:   route_default_metric = 0
Aug 16 14:44:23 myvpn ovpn-server[15043]:   route_noexec = DISABLED
Aug 16 14:44:23 myvpn ovpn-server[15043]:   route_delay = 0
Aug 16 14:44:23 myvpn ovpn-server[15043]:   route_delay_window = 30
Aug 16 14:44:23 myvpn ovpn-server[15043]:   route_delay_defined = DISABLED
Aug 16 14:44:23 myvpn ovpn-server[15043]:   route_nopull = DISABLED
Aug 16 14:44:23 myvpn ovpn-server[15043]:   route_gateway_via_dhcp = DISABLED
Aug 16 14:44:23 myvpn ovpn-server[15043]:   max_routes = 100
Aug 16 14:44:23 myvpn ovpn-server[15043]:   allow_pull_fqdn = DISABLED
Aug 16 14:44:23 myvpn ovpn-server[15043]:   management_addr = '[UNDEF]'
Aug 16 14:44:23 myvpn ovpn-server[15043]:   management_port = 0
Aug 16 14:44:23 myvpn ovpn-server[15043]:   management_user_pass = '[UNDEF]'
Aug 16 14:44:23 myvpn ovpn-server[15043]:   management_log_history_cache = 250
Aug 16 14:44:23 myvpn ovpn-server[15043]:   management_echo_buffer_size = 100
Aug 16 14:44:23 myvpn ovpn-server[15043]:   management_write_peer_info_file = '[UNDEF]'
Aug 16 14:44:23 myvpn ovpn-server[15043]:   management_client_user = '[UNDEF]'
Aug 16 14:44:23 myvpn ovpn-server[15043]:   management_client_group = '[UNDEF]'
Aug 16 14:44:23 myvpn ovpn-server[15043]:   management_flags = 0
Aug 16 14:44:23 myvpn ovpn-server[15043]:   shared_secret_file = '[UNDEF]'
Aug 16 14:44:23 myvpn ovpn-server[15043]:   key_direction = 1
Aug 16 14:44:23 myvpn ovpn-server[15043]:   ciphername_defined = ENABLED
Aug 16 14:44:23 myvpn ovpn-server[15043]:   ciphername = 'AES-128-CBC'
Aug 16 14:44:23 myvpn ovpn-server[15043]:   authname_defined = ENABLED
Aug 16 14:44:23 myvpn ovpn-server[15043]:   authname = 'SHA256'
Aug 16 14:44:23 myvpn ovpn-server[15043]:   prng_hash = 'SHA1'
Aug 16 14:44:23 myvpn ovpn-server[15043]:   prng_nonce_secret_len = 16
Aug 16 14:44:23 myvpn ovpn-server[15043]:   keysize = 0
Aug 16 14:44:23 myvpn ovpn-server[15043]:   engine = DISABLED
Aug 16 14:44:23 myvpn ovpn-server[15043]:   replay = ENABLED
Aug 16 14:44:23 myvpn ovpn-server[15043]:   mute_replay_warnings = DISABLED
Aug 16 14:44:23 myvpn ovpn-server[15043]:   replay_window = 64
Aug 16 14:44:23 myvpn ovpn-server[15043]:   replay_time = 15
Aug 16 14:44:23 myvpn ovpn-server[15043]:   packet_id_file = '[UNDEF]'
Aug 16 14:44:23 myvpn ovpn-server[15043]:   use_iv = ENABLED
Aug 16 14:44:23 myvpn ovpn-server[15043]:   test_crypto = DISABLED
Aug 16 14:44:23 myvpn ovpn-server[15043]:   tls_server = ENABLED
Aug 16 14:44:23 myvpn ovpn-server[15043]:   tls_client = DISABLED
Aug 16 14:44:23 myvpn ovpn-server[15043]:   key_method = 2
Aug 16 14:44:23 myvpn ovpn-server[15043]:   ca_file = 'ca.crt'
Aug 16 14:44:23 myvpn ovpn-server[15043]:   ca_path = '[UNDEF]'
Aug 16 14:44:23 myvpn ovpn-server[15043]:   dh_file = 'dh.pem'
Aug 16 14:44:23 myvpn ovpn-server[15043]:   cert_file = 'server.crt'
Aug 16 14:44:23 myvpn ovpn-server[15043]:   extra_certs_file = '[UNDEF]'
Aug 16 14:44:23 myvpn ovpn-server[15043]:   priv_key_file = 'server.key'
Aug 16 14:44:23 myvpn ovpn-server[15043]:   pkcs12_file = '[UNDEF]'
Aug 16 14:44:23 myvpn ovpn-server[15043]:   cipher_list = '[UNDEF]'
Aug 16 14:44:23 myvpn ovpn-server[15043]:   tls_verify = '[UNDEF]'
Aug 16 14:44:23 myvpn ovpn-server[15043]:   tls_export_cert = '[UNDEF]'
Aug 16 14:44:23 myvpn ovpn-server[15043]:   verify_x509_type = 0
Aug 16 14:44:23 myvpn ovpn-server[15043]:   verify_x509_name = '[UNDEF]'
Aug 16 14:44:23 myvpn ovpn-server[15043]:   crl_file = 'crl.pem'
Aug 16 14:44:23 myvpn ovpn-server[15043]:   ns_cert_type = 0
Aug 16 14:44:23 myvpn ovpn-server[15043]:   remote_cert_ku[i] = 0
Aug 16 14:44:23 myvpn ovpn-server[15043]: message repeated 15 times: [   remote_cert_ku[i] = 0]
Aug 16 14:44:23 myvpn ovpn-server[15043]:   remote_cert_eku = '[UNDEF]'
Aug 16 14:44:23 myvpn ovpn-server[15043]:   ssl_flags = 64
Aug 16 14:44:23 myvpn ovpn-server[15043]:   tls_timeout = 2
Aug 16 14:44:23 myvpn ovpn-server[15043]:   renegotiate_bytes = 0
Aug 16 14:44:23 myvpn ovpn-server[15043]:   renegotiate_packets = 0
Aug 16 14:44:23 myvpn ovpn-server[15043]:   renegotiate_seconds = 3600
Aug 16 14:44:23 myvpn ovpn-server[15043]:   handshake_window = 60
Aug 16 14:44:23 myvpn ovpn-server[15043]:   transition_window = 3600
Aug 16 14:44:23 myvpn ovpn-server[15043]:   single_session = DISABLED
Aug 16 14:44:23 myvpn ovpn-server[15043]:   push_peer_info = DISABLED
Aug 16 14:44:23 myvpn ovpn-server[15043]:   tls_exit = DISABLED
Aug 16 14:44:23 myvpn ovpn-server[15043]:   tls_auth_file = 'tls-auth.key'
Aug 16 14:44:23 myvpn ovpn-server[15043]:   pkcs11_protected_authentication = DISABLED
Aug 16 14:44:23 myvpn ovpn-server[15043]: message repeated 15 times: [   pkcs11_protected_authentication = DISABLED]
Aug 16 14:44:23 myvpn ovpn-server[15043]:   pkcs11_private_mode = 00000000
Aug 16 14:44:23 myvpn ovpn-server[15043]: message repeated 15 times: [   pkcs11_private_mode = 00000000]
Aug 16 14:44:23 myvpn ovpn-server[15043]:   pkcs11_cert_private = DISABLED
Aug 16 14:44:23 myvpn ovpn-server[15043]: message repeated 15 times: [   pkcs11_cert_private = DISABLED]
Aug 16 14:44:23 myvpn ovpn-server[15043]:   pkcs11_pin_cache_period = -1
Aug 16 14:44:23 myvpn ovpn-server[15043]:   pkcs11_id = '[UNDEF]'
Aug 16 14:44:23 myvpn ovpn-server[15043]:   pkcs11_id_management = DISABLED
Aug 16 14:44:23 myvpn ovpn-server[15043]:   server_network = 10.8.0.0
Aug 16 14:44:23 myvpn ovpn-server[15043]:   server_netmask = 255.255.255.0
Aug 16 14:44:23 myvpn ovpn-server[15043]:   server_network_ipv6 = ::
Aug 16 14:44:23 myvpn ovpn-server[15043]:   server_netbits_ipv6 = 0
Aug 16 14:44:23 myvpn ovpn-server[15043]:   server_bridge_ip = 0.0.0.0
Aug 16 14:44:23 myvpn ovpn-server[15043]:   server_bridge_netmask = 0.0.0.0
Aug 16 14:44:23 myvpn ovpn-server[15043]:   server_bridge_pool_start = 0.0.0.0
Aug 16 14:44:23 myvpn ovpn-server[15043]:   server_bridge_pool_end = 0.0.0.0
Aug 16 14:44:23 myvpn ovpn-server[15043]:   push_entry = 'dhcp-option DNS 80.68.80.24'
Aug 16 14:44:23 myvpn ovpn-server[15043]:   push_entry = 'dhcp-option DNS 80.68.80.25'
Aug 16 14:44:23 myvpn ovpn-server[15043]:   push_entry = 'redirect-gateway def1 bypass-dhcp'
Aug 16 14:44:23 myvpn ovpn-server[15043]:   push_entry = 'route-gateway 10.8.0.1'
Aug 16 14:44:23 myvpn ovpn-server[15043]:   push_entry = 'topology subnet'
Aug 16 14:44:23 myvpn ovpn-server[15043]:   push_entry = 'ping 10'
Aug 16 14:44:23 myvpn ovpn-server[15043]:   push_entry = 'ping-restart 120'
Aug 16 14:44:23 myvpn ovpn-server[15043]:   ifconfig_pool_defined = ENABLED
Aug 16 14:44:23 myvpn ovpn-server[15043]:   ifconfig_pool_start = 10.8.0.2
Aug 16 14:44:23 myvpn ovpn-server[15043]:   ifconfig_pool_end = 10.8.0.253
Aug 16 14:44:23 myvpn ovpn-server[15043]:   ifconfig_pool_netmask = 255.255.255.0
Aug 16 14:44:23 myvpn ovpn-server[15043]:   ifconfig_pool_persist_filename = 'ipp.txt'
Aug 16 14:44:23 myvpn ovpn-server[15043]:   ifconfig_pool_persist_refresh_freq = 600
Aug 16 14:44:23 myvpn ovpn-server[15043]:   ifconfig_ipv6_pool_defined = DISABLED
Aug 16 14:44:23 myvpn ovpn-server[15043]:   ifconfig_ipv6_pool_base = ::
Aug 16 14:44:23 myvpn ovpn-server[15043]:   ifconfig_ipv6_pool_netbits = 0
Aug 16 14:44:23 myvpn ovpn-server[15043]:   n_bcast_buf = 256
Aug 16 14:44:23 myvpn ovpn-server[15043]:   tcp_queue_limit = 64
Aug 16 14:44:23 myvpn ovpn-server[15043]:   real_hash_size = 256
Aug 16 14:44:23 myvpn ovpn-server[15043]:   virtual_hash_size = 256
Aug 16 14:44:23 myvpn ovpn-server[15043]:   client_connect_script = '[UNDEF]'
Aug 16 14:44:23 myvpn ovpn-server[15043]:   learn_address_script = '[UNDEF]'
Aug 16 14:44:23 myvpn ovpn-server[15043]:   client_disconnect_script = '[UNDEF]'
Aug 16 14:44:23 myvpn ovpn-server[15043]:   client_config_dir = '[UNDEF]'
Aug 16 14:44:23 myvpn ovpn-server[15043]:   ccd_exclusive = DISABLED
Aug 16 14:44:23 myvpn ovpn-server[15043]:   tmp_dir = '/tmp'
Aug 16 14:44:23 myvpn ovpn-server[15043]:   push_ifconfig_defined = DISABLED
Aug 16 14:44:23 myvpn ovpn-server[15043]:   push_ifconfig_local = 0.0.0.0
Aug 16 14:44:23 myvpn ovpn-server[15043]:   push_ifconfig_remote_netmask = 0.0.0.0
Aug 16 14:44:23 myvpn ovpn-server[15043]:   push_ifconfig_ipv6_defined = DISABLED
Aug 16 14:44:23 myvpn ovpn-server[15043]:   push_ifconfig_ipv6_local = ::/0
Aug 16 14:44:23 myvpn ovpn-server[15043]:   push_ifconfig_ipv6_remote = ::
Aug 16 14:44:23 myvpn ovpn-server[15043]:   enable_c2c = DISABLED
Aug 16 14:44:23 myvpn ovpn-server[15043]:   duplicate_cn = DISABLED
Aug 16 14:44:23 myvpn ovpn-server[15043]:   cf_max = 0
Aug 16 14:44:23 myvpn ovpn-server[15043]:   cf_per = 0
Aug 16 14:44:23 myvpn ovpn-server[15043]:   max_clients = 1024
Aug 16 14:44:23 myvpn ovpn-server[15043]:   max_routes_per_client = 256
Aug 16 14:44:23 myvpn ovpn-server[15043]:   auth_user_pass_verify_script = '[UNDEF]'
Aug 16 14:44:23 myvpn ovpn-server[15043]:   auth_user_pass_verify_script_via_file = DISABLED
Aug 16 14:44:23 myvpn ovpn-server[15043]:   port_share_host = '[UNDEF]'
Aug 16 14:44:23 myvpn ovpn-server[15043]:   port_share_port = 0
Aug 16 14:44:23 myvpn ovpn-server[15043]:   client = DISABLED
Aug 16 14:44:23 myvpn ovpn-server[15043]:   pull = DISABLED
Aug 16 14:44:23 myvpn ovpn-server[15043]:   auth_user_pass_file = '[UNDEF]'
Aug 16 14:44:23 myvpn ovpn-server[15043]: OpenVPN 2.3.10 x86_64-pc-linux-gnu [SSL (OpenSSL)] [LZO] [EPOLL] [PKCS11] [MH] [IPv6] built on Jun 22 2017
Aug 16 14:44:23 myvpn ovpn-server[15043]: library versions: OpenSSL 1.0.2g  1 Mar 2016, LZO 2.08
Aug 16 14:44:23 myvpn ovpn-server[15048]: Diffie-Hellman initialized with 2048 bit key
Aug 16 14:44:23 myvpn ovpn-server[15048]: Control Channel Authentication: using 'tls-auth.key' as a OpenVPN static key file
Aug 16 14:44:23 myvpn ovpn-server[15048]: Outgoing Control Channel Authentication: Using 256 bit message hash 'SHA256' for HMAC authentication
Aug 16 14:44:23 myvpn ovpn-server[15048]: Incoming Control Channel Authentication: Using 256 bit message hash 'SHA256' for HMAC authentication
Aug 16 14:44:23 myvpn ovpn-server[15048]: TLS-Auth MTU parms [ L:1569 D:1172 EF:78 EB:0 ET:0 EL:3 ]
Aug 16 14:44:23 myvpn ovpn-server[15048]: Socket Buffers: R=[212992->212992] S=[212992->212992]
Aug 16 14:44:23 myvpn ovpn-server[15048]: TUN/TAP device tun0 opened
Aug 16 14:44:23 myvpn ovpn-server[15048]: TUN/TAP TX queue length set to 100
Aug 16 14:44:23 myvpn ovpn-server[15048]: do_ifconfig, tt->ipv6=0, tt->did_ifconfig_ipv6_setup=0
Aug 16 14:44:23 myvpn ovpn-server[15048]: /sbin/ip link set dev tun0 up mtu 1500
Aug 16 14:44:23 myvpn ovpn-server[15048]: /sbin/ip addr add dev tun0 10.8.0.1/24 broadcast 10.8.0.255
Aug 16 14:44:23 myvpn ovpn-server[15048]: Data Channel MTU parms [ L:1569 D:1450 EF:69 EB:12 ET:0 EL:3 ]
Aug 16 14:44:23 myvpn ovpn-server[15048]: GID set to nogroup
Aug 16 14:44:23 myvpn ovpn-server[15048]: UID set to nobody
Aug 16 14:44:23 myvpn ovpn-server[15048]: UDPv4 link local (bound): [AF_INET]22.33.44.55:1194
Aug 16 14:44:23 myvpn ovpn-server[15048]: UDPv4 link remote: [undef]
Aug 16 14:44:23 myvpn ovpn-server[15048]: MULTI: multi_init called, r=256 v=256
Aug 16 14:44:23 myvpn ovpn-server[15048]: IFCONFIG POOL: base=10.8.0.2 size=252, ipv6=0
Aug 16 14:44:23 myvpn ovpn-server[15048]: ifconfig_pool_read(), in='laptop,10.8.0.2', TODO: IPv6
Aug 16 14:44:23 myvpn ovpn-server[15048]: succeeded -> ifconfig_pool_set()
Aug 16 14:44:23 myvpn ovpn-server[15048]: IFCONFIG POOL LIST
Aug 16 14:44:23 myvpn ovpn-server[15048]: laptop,10.8.0.2
Aug 16 14:44:23 myvpn ovpn-server[15048]: Initialization Sequence Completed
/var/log/syslog (successful connection from "laptop")

Code: Select all

Aug 16 14:48:35 myvpn ovpn-server[15048]: MULTI: multi_create_instance called
Aug 16 14:48:35 myvpn ovpn-server[15048]: 33.44.55.66:42132 Re-using SSL/TLS context
Aug 16 14:48:35 myvpn ovpn-server[15048]: 33.44.55.66:42132 Control Channel MTU parms [ L:1569 D:1172 EF:78 EB:0 ET:0 EL:3 ]
Aug 16 14:48:35 myvpn ovpn-server[15048]: 33.44.55.66:42132 Data Channel MTU parms [ L:1569 D:1450 EF:69 EB:12 ET:0 EL:3 ]
Aug 16 14:48:35 myvpn ovpn-server[15048]: 33.44.55.66:42132 Local Options String: 'V4,dev-type tun,link-mtu 1569,tun-mtu 1500,proto UDPv4,keydir 0,cipher AES-128-CBC,auth SHA256,keysize 128,tls-auth,key-method 2,tls-server'
Aug 16 14:48:35 myvpn ovpn-server[15048]: 33.44.55.66:42132 Expected Remote Options String: 'V4,dev-type tun,link-mtu 1569,tun-mtu 1500,proto UDPv4,keydir 1,cipher AES-128-CBC,auth SHA256,keysize 128,tls-auth,key-method 2,tls-client'
Aug 16 14:48:35 myvpn ovpn-server[15048]: 33.44.55.66:42132 Local Options hash (VER=V4): 'a4229d97'
Aug 16 14:48:35 myvpn ovpn-server[15048]: 33.44.55.66:42132 Expected Remote Options hash (VER=V4): '0781f50e'
Aug 16 14:48:35 myvpn ovpn-server[15048]: 33.44.55.66:42132 TLS: Initial packet from [AF_INET]33.44.55.66:42132, sid=9108e672 f4ec3d5f
Aug 16 14:48:35 myvpn ovpn-server[15048]: 33.44.55.66:42132 CRL CHECK OK: CN=ChangeMe
Aug 16 14:48:35 myvpn ovpn-server[15048]: 33.44.55.66:42132 VERIFY OK: depth=1, CN=ChangeMe
Aug 16 14:48:35 myvpn ovpn-server[15048]: 33.44.55.66:42132 CRL CHECK OK: CN=laptop
Aug 16 14:48:35 myvpn ovpn-server[15048]: 33.44.55.66:42132 VERIFY OK: depth=0, CN=laptop
Aug 16 14:48:35 myvpn ovpn-server[15048]: 33.44.55.66:42132 Data Channel Encrypt: Cipher 'AES-128-CBC' initialized with 128 bit key
Aug 16 14:48:35 myvpn ovpn-server[15048]: 33.44.55.66:42132 Data Channel Encrypt: Using 256 bit message hash 'SHA256' for HMAC authentication
Aug 16 14:48:35 myvpn ovpn-server[15048]: 33.44.55.66:42132 Data Channel Decrypt: Cipher 'AES-128-CBC' initialized with 128 bit key
Aug 16 14:48:35 myvpn ovpn-server[15048]: 33.44.55.66:42132 Data Channel Decrypt: Using 256 bit message hash 'SHA256' for HMAC authentication
Aug 16 14:48:35 myvpn ovpn-server[15048]: 33.44.55.66:42132 Control Channel: TLSv1.2, cipher TLSv1/SSLv3 DHE-RSA-AES256-GCM-SHA384, 2048 bit RSA
Aug 16 14:48:35 myvpn ovpn-server[15048]: 33.44.55.66:42132 [laptop] Peer Connection Initiated with [AF_INET]33.44.55.66:42132
Aug 16 14:48:35 myvpn ovpn-server[15048]: laptop/33.44.55.66:42132 MULTI_sva: pool returned IPv4=10.8.0.2, IPv6=(Not enabled)
Aug 16 14:48:35 myvpn ovpn-server[15048]: laptop/33.44.55.66:42132 MULTI: Learn: 10.8.0.2 -> laptop/33.44.55.66:42132
Aug 16 14:48:35 myvpn ovpn-server[15048]: laptop/33.44.55.66:42132 MULTI: primary virtual IP for laptop/33.44.55.66:42132: 10.8.0.2
Aug 16 14:48:37 myvpn ovpn-server[15048]: laptop/33.44.55.66:42132 PUSH: Received control message: 'PUSH_REQUEST'
Aug 16 14:48:37 myvpn ovpn-server[15048]: laptop/33.44.55.66:42132 send_push_reply(): safe_cap=940
Aug 16 14:48:37 myvpn ovpn-server[15048]: laptop/33.44.55.66:42132 SENT CONTROL [laptop]: 'PUSH_REPLY,dhcp-option DNS 88.99.11.24,dhcp-option DNS 88.99.11.25,redirect-gateway def1 bypass-dhcp,route-gateway 10.8.0.1,topology subnet,ping 10,ping-restart 120,ifconfig 10.8.0.2 255.255.255.0' (status=1)
/var/log/syslog (failing connection from WWAN router "raven")

Code: Select all

Aug 16 14:59:53 myvpn ovpn-server[15048]: MULTI: multi_create_instance called
Aug 16 14:59:53 myvpn ovpn-server[15048]: 44.55.66.77:53725 Re-using SSL/TLS context
Aug 16 14:59:53 myvpn ovpn-server[15048]: 44.55.66.77:53725 Control Channel MTU parms [ L:1569 D:1172 EF:78 EB:0 ET:0 EL:3 ]
Aug 16 14:59:53 myvpn ovpn-server[15048]: 44.55.66.77:53725 Data Channel MTU parms [ L:1569 D:1450 EF:69 EB:12 ET:0 EL:3 ]
Aug 16 14:59:53 myvpn ovpn-server[15048]: 44.55.66.77:53725 Local Options String: 'V4,dev-type tun,link-mtu 1569,tun-mtu 1500,proto UDPv4,keydir 0,cipher AES-128-CBC,auth SHA256,keysize 128,tls-auth,key-method 2,tls-server'
Aug 16 14:59:53 myvpn ovpn-server[15048]: 44.55.66.77:53725 Expected Remote Options String: 'V4,dev-type tun,link-mtu 1569,tun-mtu 1500,proto UDPv4,keydir 1,cipher AES-128-CBC,auth SHA256,keysize 128,tls-auth,key-method 2,tls-client'
Aug 16 14:59:53 myvpn ovpn-server[15048]: 44.55.66.77:53725 Local Options hash (VER=V4): 'a4229d97'
Aug 16 14:59:53 myvpn ovpn-server[15048]: 44.55.66.77:53725 Expected Remote Options hash (VER=V4): '0781f50e'
Aug 16 14:59:53 myvpn ovpn-server[15048]: 44.55.66.77:53725 TLS: Initial packet from [AF_INET]44.55.66.77:53725, sid=d176a28b 8a78bb2e
Aug 16 14:59:57 myvpn ovpn-server[15048]: MULTI: multi_create_instance called
Aug 16 14:59:57 myvpn ovpn-server[15048]: 44.55.66.77:41461 Re-using SSL/TLS context
Aug 16 14:59:57 myvpn ovpn-server[15048]: 44.55.66.77:41461 Control Channel MTU parms [ L:1569 D:1172 EF:78 EB:0 ET:0 EL:3 ]
Aug 16 14:59:57 myvpn ovpn-server[15048]: 44.55.66.77:41461 Data Channel MTU parms [ L:1569 D:1450 EF:69 EB:12 ET:0 EL:3 ]
Aug 16 14:59:57 myvpn ovpn-server[15048]: 44.55.66.77:41461 Local Options String: 'V4,dev-type tun,link-mtu 1569,tun-mtu 1500,proto UDPv4,keydir 0,cipher AES-128-CBC,auth SHA256,keysize 128,tls-auth,key-method 2,tls-server'
Aug 16 14:59:57 myvpn ovpn-server[15048]: 44.55.66.77:41461 Expected Remote Options String: 'V4,dev-type tun,link-mtu 1569,tun-mtu 1500,proto UDPv4,keydir 1,cipher AES-128-CBC,auth SHA256,keysize 128,tls-auth,key-method 2,tls-client'
Aug 16 14:59:57 myvpn ovpn-server[15048]: 44.55.66.77:41461 Local Options hash (VER=V4): 'a4229d97'
Aug 16 14:59:57 myvpn ovpn-server[15048]: 44.55.66.77:41461 Expected Remote Options hash (VER=V4): '0781f50e'
Aug 16 14:59:57 myvpn ovpn-server[15048]: 44.55.66.77:41461 TLS: Initial packet from [AF_INET]44.55.66.77:41461, sid=44cc73e2 e49da8cb
Aug 16 15:00:01 myvpn ovpn-server[15048]: MULTI: multi_create_instance called
Aug 16 15:00:01 myvpn ovpn-server[15048]: 44.55.66.77:49104 Re-using SSL/TLS context
Aug 16 15:00:01 myvpn ovpn-server[15048]: 44.55.66.77:49104 Control Channel MTU parms [ L:1569 D:1172 EF:78 EB:0 ET:0 EL:3 ]
Aug 16 15:00:01 myvpn ovpn-server[15048]: 44.55.66.77:49104 Data Channel MTU parms [ L:1569 D:1450 EF:69 EB:12 ET:0 EL:3 ]
Aug 16 15:00:01 myvpn ovpn-server[15048]: 44.55.66.77:49104 Local Options String: 'V4,dev-type tun,link-mtu 1569,tun-mtu 1500,proto UDPv4,keydir 0,cipher AES-128-CBC,auth SHA256,keysize 128,tls-auth,key-method 2,tls-server'
Aug 16 15:00:01 myvpn ovpn-server[15048]: 44.55.66.77:49104 Expected Remote Options String: 'V4,dev-type tun,link-mtu 1569,tun-mtu 1500,proto UDPv4,keydir 1,cipher AES-128-CBC,auth SHA256,keysize 128,tls-auth,key-method 2,tls-client'
Aug 16 15:00:01 myvpn ovpn-server[15048]: 44.55.66.77:49104 Local Options hash (VER=V4): 'a4229d97'
Aug 16 15:00:01 myvpn ovpn-server[15048]: 44.55.66.77:49104 Expected Remote Options hash (VER=V4): '0781f50e'

... repeating ad infinitum ...
Screengrab from router config:

Image

The WWAN router is a Sierra Wireless AirLink RV50 (Raven), running ALEOS firmware v4.8.1. Full software configuration manual is available here.

Gratefully,

Lomax

etaoin
OpenVPN User
Posts: 24
Joined: Wed Aug 09, 2017 5:53 pm

Re: Having an "interesting" time with Sierra Wireless WWAN router & OpenVPN

Post by etaoin » Wed Aug 16, 2017 5:49 pm

Please note that it says "VPN Status 1: Disabled" on the screengrab in my previous post only because it was taken prior to rebooting the WWAN router. It seems it needs a full reboot every time I change any VPN parameters - the "Set VPN Policy" button doesn't appear to activate the new settings, even though the manual suggests it would have this function.

TinCanTech
OpenVPN Protagonist
Posts: 11137
Joined: Fri Jun 03, 2016 1:17 pm

Re: Having an "interesting" time with Sierra Wireless WWAN router & OpenVPN

Post by TinCanTech » Wed Aug 16, 2017 6:45 pm

Some settings, especially logs, require that openvpn be restarted to apply changes.

Still looking at your problem .. perhaps increasing server to --verb 6 may help a little.

etaoin
OpenVPN User
Posts: 24
Joined: Wed Aug 09, 2017 5:53 pm

Re: Having an "interesting" time with Sierra Wireless WWAN router & OpenVPN

Post by etaoin » Sun Aug 20, 2017 1:15 pm

TinCanTech wrote:Still looking at your problem .. perhaps increasing server to --verb 6 may help a little.
Thanks, really appreciate it. Apologies for the delay in getting back to you; other aspects of this project have been taking up my attention. But without a functioning VPN connection it will all be pointless, and so I return to this issue. Here is a sample of the server log output at verb 6:

Code: Select all

Aug 20 14:06:12 myvpn systemd[1]: Started OpenVPN service.
Aug 20 14:06:12 myvpn systemd[1]: Starting OpenVPN connection to server...
Aug 20 14:06:12 myvpn ovpn-server[11331]: OpenVPN 2.3.10 x86_64-pc-linux-gnu [SSL (OpenSSL)] [LZO] [EPOLL] [PKCS11] [MH] [IPv6] built on Jun 22 2017
Aug 20 14:06:12 myvpn ovpn-server[11331]: library versions: OpenSSL 1.0.2g  1 Mar 2016, LZO 2.08
Aug 20 14:06:12 myvpn ovpn-server[11333]: Control Channel Authentication: using 'tls-auth.key' as a OpenVPN static key file
Aug 20 14:06:12 myvpn ovpn-server[11333]: TUN/TAP device tun0 opened
Aug 20 14:06:12 myvpn ovpn-server[11333]: do_ifconfig, tt->ipv6=0, tt->did_ifconfig_ipv6_setup=0
Aug 20 14:06:12 myvpn ovpn-server[11333]: /sbin/ip link set dev tun0 up mtu 1500
Aug 20 14:06:12 myvpn ovpn-server[11333]: /sbin/ip addr add dev tun0 10.8.0.1/24 broadcast 10.8.0.255
Aug 20 14:06:12 myvpn ovpn-server[11333]: GID set to nogroup
Aug 20 14:06:12 myvpn systemd[1]: Started OpenVPN connection to server.
Aug 20 14:06:12 myvpn ovpn-server[11206]: UID set to nobody
Aug 20 14:06:12 myvpn ovpn-server[11206]: UDPv4 link local (bound): [AF_INET]22.33.44.55:1194
Aug 20 14:06:12 myvpn ovpn-server[11206]: UDPv4 link remote: [undef]
Aug 20 14:06:12 myvpn ovpn-server[11206]: MULTI: multi_init called, r=256 v=256
Aug 20 14:06:12 myvpn ovpn-server[11206]: IFCONFIG POOL: base=10.8.0.2 size=252, ipv6=0
Aug 20 14:06:12 myvpn ovpn-server[11206]: ifconfig_pool_read(), in='laptop,10.8.0.2', TODO: IPv6
Aug 20 14:06:12 myvpn ovpn-server[11206]: succeeded -> ifconfig_pool_set()
Aug 20 14:06:12 myvpn ovpn-server[11206]: IFCONFIG POOL LIST
Aug 20 14:06:12 myvpn ovpn-server[11206]: laptop,10.8.0.2
Aug 20 14:06:12 myvpn ovpn-server[11206]: Initialization Sequence Completed
Aug 20 14:07:08 myvpn ovpn-server[11206]: MULTI: multi_create_instance called
Aug 20 14:07:08 myvpn ovpn-server[11206]: 44.55.66.77:39309 Re-using SSL/TLS context
Aug 20 14:07:08 myvpn ovpn-server[11206]: 44.55.66.77:39309 Control Channel MTU parms [ L:1569 D:1172 EF:78 EB:0 ET:0 EL:3 ]
Aug 20 14:07:08 myvpn ovpn-server[11206]: 44.55.66.77:39309 Data Channel MTU parms [ L:1569 D:1450 EF:69 EB:12 ET:0 EL:3 ]
Aug 20 14:07:08 myvpn ovpn-server[11206]: 44.55.66.77:39309 Local Options String: 'V4,dev-type tun,link-mtu 1569,tun-mtu 1500,proto UDPv4,keydir 0,cipher AES-128-CBC,auth SHA256,keysize 128,tls-auth,key-method 2,tls-server'
Aug 20 14:07:08 myvpn ovpn-server[11206]: 44.55.66.77:39309 Expected Remote Options String: 'V4,dev-type tun,link-mtu 1569,tun-mtu 1500,proto UDPv4,keydir 1,cipher AES-128-CBC,auth SHA256,keysize 128,tls-auth,key-method 2,tls-client'
Aug 20 14:07:08 myvpn ovpn-server[11206]: 44.55.66.77:39309 Local Options hash (VER=V4): 'a4229d97'
Aug 20 14:07:08 myvpn ovpn-server[11206]: 44.55.66.77:39309 Expected Remote Options hash (VER=V4): '0781f50e'
Aug 20 14:07:08 myvpn ovpn-server[11206]: 44.55.66.77:39309 UDPv4 READ [54] from [AF_INET]44.55.66.77:39309: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 pid=[ #1 ] [ ] pid=0 DATA len=0
Aug 20 14:07:08 myvpn ovpn-server[11206]: 44.55.66.77:39309 TLS: Initial packet from [AF_INET]44.55.66.77:39309, sid=468bbf98 493ec12b
Aug 20 14:07:08 myvpn ovpn-server[11206]: 44.55.66.77:39309 UDPv4 WRITE [66] to [AF_INET]44.55.66.77:39309: P_CONTROL_HARD_RESET_SERVER_V2 kid=0 pid=[ #1 ] [ 0 ] pid=0 DATA len=0
Aug 20 14:07:10 myvpn ovpn-server[11206]: 44.55.66.77:39309 UDPv4 READ [62] from [AF_INET]44.55.66.77:39309: P_ACK_V1 kid=0 pid=[ #2 ] [ 0 ]
Aug 20 14:07:10 myvpn ovpn-server[11206]: 44.55.66.77:39309 UDPv4 READ [154] from [AF_INET]44.55.66.77:39309: P_CONTROL_V1 kid=0 pid=[ #3 ] [ ] pid=1 DATA len=100
Aug 20 14:07:10 myvpn ovpn-server[11206]: 44.55.66.77:39309 UDPv4 WRITE [62] to [AF_INET]44.55.66.77:39309: P_ACK_V1 kid=0 pid=[ #2 ] [ 1 ]
Aug 20 14:07:10 myvpn ovpn-server[11206]: 44.55.66.77:39309 UDPv4 READ [151] from [AF_INET]44.55.66.77:39309: P_CONTROL_V1 kid=0 pid=[ #4 ] [ ] pid=2 DATA len=97
Aug 20 14:07:10 myvpn ovpn-server[11206]: 44.55.66.77:39309 UDPv4 WRITE [1160] to [AF_INET]44.55.66.77:39309: P_CONTROL_V1 kid=0 pid=[ #3 ] [ 2 ] pid=1 DATA len=1094
Aug 20 14:07:10 myvpn ovpn-server[11206]: 44.55.66.77:39309 UDPv4 WRITE [1148] to [AF_INET]44.55.66.77:39309: P_CONTROL_V1 kid=0 pid=[ #4 ] [ ] pid=2 DATA len=1094
Aug 20 14:07:10 myvpn ovpn-server[11206]: 44.55.66.77:39309 UDPv4 WRITE [412] to [AF_INET]44.55.66.77:39309: P_CONTROL_V1 kid=0 pid=[ #5 ] [ ] pid=3 DATA len=358
Aug 20 14:07:11 myvpn ovpn-server[11206]: 44.55.66.77:39309 UDPv4 READ [62] from [AF_INET]44.55.66.77:39309: P_ACK_V1 kid=0 pid=[ #5 ] [ 1 ]
Aug 20 14:07:13 myvpn ovpn-server[11206]: MULTI: multi_create_instance called
Aug 20 14:07:13 myvpn ovpn-server[11206]: 44.55.66.77:44246 Re-using SSL/TLS context
Aug 20 14:07:13 myvpn ovpn-server[11206]: 44.55.66.77:44246 Control Channel MTU parms [ L:1569 D:1172 EF:78 EB:0 ET:0 EL:3 ]
Aug 20 14:07:13 myvpn ovpn-server[11206]: 44.55.66.77:44246 Data Channel MTU parms [ L:1569 D:1450 EF:69 EB:12 ET:0 EL:3 ]
Aug 20 14:07:13 myvpn ovpn-server[11206]: 44.55.66.77:44246 Local Options String: 'V4,dev-type tun,link-mtu 1569,tun-mtu 1500,proto UDPv4,keydir 0,cipher AES-128-CBC,auth SHA256,keysize 128,tls-auth,key-method 2,tls-server'
Aug 20 14:07:13 myvpn ovpn-server[11206]: 44.55.66.77:44246 Expected Remote Options String: 'V4,dev-type tun,link-mtu 1569,tun-mtu 1500,proto UDPv4,keydir 1,cipher AES-128-CBC,auth SHA256,keysize 128,tls-auth,key-method 2,tls-client'
Aug 20 14:07:13 myvpn ovpn-server[11206]: 44.55.66.77:44246 Local Options hash (VER=V4): 'a4229d97'
Aug 20 14:07:13 myvpn ovpn-server[11206]: 44.55.66.77:44246 Expected Remote Options hash (VER=V4): '0781f50e'
Aug 20 14:07:13 myvpn ovpn-server[11206]: 44.55.66.77:44246 UDPv4 READ [54] from [AF_INET]44.55.66.77:44246: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 pid=[ #1 ] [ ] pid=0 DATA len=0
Aug 20 14:07:13 myvpn ovpn-server[11206]: 44.55.66.77:44246 TLS: Initial packet from [AF_INET]44.55.66.77:44246, sid=d3822855 9f5bd28a
Aug 20 14:07:13 myvpn ovpn-server[11206]: 44.55.66.77:44246 UDPv4 WRITE [66] to [AF_INET]44.55.66.77:44246: P_CONTROL_HARD_RESET_SERVER_V2 kid=0 pid=[ #1 ] [ 0 ] pid=0 DATA len=0
Aug 20 14:07:13 myvpn ovpn-server[11206]: 44.55.66.77:39309 UDPv4 WRITE [1148] to [AF_INET]44.55.66.77:39309: P_CONTROL_V1 kid=0 pid=[ #6 ] [ ] pid=2 DATA len=1094
Aug 20 14:07:14 myvpn ovpn-server[11206]: 44.55.66.77:44246 UDPv4 READ [62] from [AF_INET]44.55.66.77:44246: P_ACK_V1 kid=0 pid=[ #2 ] [ 0 ]
Aug 20 14:07:14 myvpn ovpn-server[11206]: 44.55.66.77:44246 UDPv4 READ [154] from [AF_INET]44.55.66.77:44246: P_CONTROL_V1 kid=0 pid=[ #3 ] [ ] pid=1 DATA len=100
Aug 20 14:07:14 myvpn ovpn-server[11206]: 44.55.66.77:44246 UDPv4 WRITE [62] to [AF_INET]44.55.66.77:44246: P_ACK_V1 kid=0 pid=[ #2 ] [ 1 ]
Aug 20 14:07:14 myvpn ovpn-server[11206]: 44.55.66.77:44246 UDPv4 READ [151] from [AF_INET]44.55.66.77:44246: P_CONTROL_V1 kid=0 pid=[ #4 ] [ ] pid=2 DATA len=97
Aug 20 14:07:14 myvpn ovpn-server[11206]: 44.55.66.77:44246 UDPv4 WRITE [1160] to [AF_INET]44.55.66.77:44246: P_CONTROL_V1 kid=0 pid=[ #3 ] [ 2 ] pid=1 DATA len=1094
Aug 20 14:07:14 myvpn ovpn-server[11206]: 44.55.66.77:44246 UDPv4 WRITE [1148] to [AF_INET]44.55.66.77:44246: P_CONTROL_V1 kid=0 pid=[ #4 ] [ ] pid=2 DATA len=1094
Aug 20 14:07:14 myvpn ovpn-server[11206]: 44.55.66.77:44246 UDPv4 WRITE [412] to [AF_INET]44.55.66.77:44246: P_CONTROL_V1 kid=0 pid=[ #5 ] [ ] pid=3 DATA len=358
Aug 20 14:07:14 myvpn ovpn-server[11206]: 44.55.66.77:39309 UDPv4 WRITE [412] to [AF_INET]44.55.66.77:39309: P_CONTROL_V1 kid=0 pid=[ #7 ] [ ] pid=3 DATA len=358
Aug 20 14:07:15 myvpn ovpn-server[11206]: 44.55.66.77:44246 UDPv4 READ [154] from [AF_INET]44.55.66.77:44246: P_CONTROL_V1 kid=0 pid=[ #5 ] [ ] pid=1 DATA len=100
Aug 20 14:07:15 myvpn ovpn-server[11206]: 44.55.66.77:44246 UDPv4 WRITE [62] to [AF_INET]44.55.66.77:44246: P_ACK_V1 kid=0 pid=[ #6 ] [ 1 ]
Aug 20 14:07:15 myvpn ovpn-server[11206]: 44.55.66.77:44246 UDPv4 READ [151] from [AF_INET]44.55.66.77:44246: P_CONTROL_V1 kid=0 pid=[ #6 ] [ ] pid=2 DATA len=97
Aug 20 14:07:15 myvpn ovpn-server[11206]: 44.55.66.77:44246 UDPv4 WRITE [62] to [AF_INET]44.55.66.77:44246: P_ACK_V1 kid=0 pid=[ #7 ] [ 2 ]
Aug 20 14:07:16 myvpn ovpn-server[11206]: 44.55.66.77:44246 UDPv4 READ [62] from [AF_INET]44.55.66.77:44246: P_ACK_V1 kid=0 pid=[ #7 ] [ 1 ]
Aug 20 14:07:17 myvpn ovpn-server[11206]: 44.55.66.77:44246 UDPv4 WRITE [1148] to [AF_INET]44.55.66.77:44246: P_CONTROL_V1 kid=0 pid=[ #8 ] [ ] pid=2 DATA len=1094
Aug 20 14:07:17 myvpn ovpn-server[11206]: 44.55.66.77:39309 UDPv4 WRITE [1148] to [AF_INET]44.55.66.77:39309: P_CONTROL_V1 kid=0 pid=[ #8 ] [ ] pid=2 DATA len=1094
Aug 20 14:07:18 myvpn ovpn-server[11206]: 44.55.66.77:44246 UDPv4 WRITE [412] to [AF_INET]44.55.66.77:44246: P_CONTROL_V1 kid=0 pid=[ #9 ] [ ] pid=3 DATA len=358
Aug 20 14:07:18 myvpn ovpn-server[11206]: MULTI: multi_create_instance called
Aug 20 14:07:18 myvpn ovpn-server[11206]: 44.55.66.77:42604 Re-using SSL/TLS context
Aug 20 14:07:18 myvpn ovpn-server[11206]: 44.55.66.77:42604 Control Channel MTU parms [ L:1569 D:1172 EF:78 EB:0 ET:0 EL:3 ]
Aug 20 14:07:18 myvpn ovpn-server[11206]: 44.55.66.77:42604 Data Channel MTU parms [ L:1569 D:1450 EF:69 EB:12 ET:0 EL:3 ]
Aug 20 14:07:18 myvpn ovpn-server[11206]: 44.55.66.77:42604 Local Options String: 'V4,dev-type tun,link-mtu 1569,tun-mtu 1500,proto UDPv4,keydir 0,cipher AES-128-CBC,auth SHA256,keysize 128,tls-auth,key-method 2,tls-server'
Aug 20 14:07:18 myvpn ovpn-server[11206]: 44.55.66.77:42604 Expected Remote Options String: 'V4,dev-type tun,link-mtu 1569,tun-mtu 1500,proto UDPv4,keydir 1,cipher AES-128-CBC,auth SHA256,keysize 128,tls-auth,key-method 2,tls-client'
Aug 20 14:07:18 myvpn ovpn-server[11206]: 44.55.66.77:42604 Local Options hash (VER=V4): 'a4229d97'
Aug 20 14:07:18 myvpn ovpn-server[11206]: 44.55.66.77:42604 Expected Remote Options hash (VER=V4): '0781f50e'
Aug 20 14:07:18 myvpn ovpn-server[11206]: 44.55.66.77:42604 UDPv4 READ [54] from [AF_INET]44.55.66.77:42604: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 pid=[ #1 ] [ ] pid=0 DATA len=0
Aug 20 14:07:18 myvpn ovpn-server[11206]: 44.55.66.77:42604 TLS: Initial packet from [AF_INET]44.55.66.77:42604, sid=4ef5ee81 4f3cd619
Aug 20 14:07:18 myvpn ovpn-server[11206]: 44.55.66.77:42604 UDPv4 WRITE [66] to [AF_INET]44.55.66.77:42604: P_CONTROL_HARD_RESET_SERVER_V2 kid=0 pid=[ #1 ] [ 0 ] pid=0 DATA len=0
Aug 20 14:07:18 myvpn ovpn-server[11206]: 44.55.66.77:39309 UDPv4 WRITE [412] to [AF_INET]44.55.66.77:39309: P_CONTROL_V1 kid=0 pid=[ #9 ] [ ] pid=3 DATA len=358
Aug 20 14:07:20 myvpn ovpn-server[11206]: 44.55.66.77:42604 UDPv4 WRITE [54] to [AF_INET]44.55.66.77:42604: P_CONTROL_HARD_RESET_SERVER_V2 kid=0 pid=[ #2 ] [ ] pid=0 DATA len=0
Aug 20 14:07:20 myvpn ovpn-server[11206]: 44.55.66.77:42604 UDPv4 READ [62] from [AF_INET]44.55.66.77:42604: P_ACK_V1 kid=0 pid=[ #2 ] [ 0 ]
Aug 20 14:07:20 myvpn ovpn-server[11206]: 44.55.66.77:42604 UDPv4 READ [154] from [AF_INET]44.55.66.77:42604: P_CONTROL_V1 kid=0 pid=[ #3 ] [ ] pid=1 DATA len=100
Aug 20 14:07:20 myvpn ovpn-server[11206]: 44.55.66.77:42604 UDPv4 WRITE [62] to [AF_INET]44.55.66.77:42604: P_ACK_V1 kid=0 pid=[ #3 ] [ 1 ]
Aug 20 14:07:20 myvpn ovpn-server[11206]: 44.55.66.77:42604 UDPv4 READ [151] from [AF_INET]44.55.66.77:42604: P_CONTROL_V1 kid=0 pid=[ #4 ] [ ] pid=2 DATA len=97
Aug 20 14:07:20 myvpn ovpn-server[11206]: 44.55.66.77:42604 UDPv4 WRITE [1160] to [AF_INET]44.55.66.77:42604: P_CONTROL_V1 kid=0 pid=[ #4 ] [ 2 ] pid=1 DATA len=1094
Aug 20 14:07:20 myvpn ovpn-server[11206]: 44.55.66.77:42604 UDPv4 WRITE [1148] to [AF_INET]44.55.66.77:42604: P_CONTROL_V1 kid=0 pid=[ #5 ] [ ] pid=2 DATA len=1094
Aug 20 14:07:20 myvpn ovpn-server[11206]: 44.55.66.77:42604 UDPv4 WRITE [412] to [AF_INET]44.55.66.77:42604: P_CONTROL_V1 kid=0 pid=[ #6 ] [ ] pid=3 DATA len=358
Aug 20 14:07:20 myvpn ovpn-server[11206]: 44.55.66.77:42604 UDPv4 READ [62] from [AF_INET]44.55.66.77:42604: P_ACK_V1 kid=0 pid=[ #5 ] [ 0 ]
Aug 20 14:07:21 myvpn ovpn-server[11206]: 44.55.66.77:42604 UDPv4 READ [151] from [AF_INET]44.55.66.77:42604: P_CONTROL_V1 kid=0 pid=[ #6 ] [ ] pid=2 DATA len=97
Aug 20 14:07:21 myvpn ovpn-server[11206]: 44.55.66.77:42604 UDPv4 WRITE [62] to [AF_INET]44.55.66.77:42604: P_ACK_V1 kid=0 pid=[ #7 ] [ 2 ]
Aug 20 14:07:21 myvpn ovpn-server[11206]: 44.55.66.77:42604 UDPv4 READ [62] from [AF_INET]44.55.66.77:42604: P_ACK_V1 kid=0 pid=[ #7 ] [ 1 ]
Aug 20 14:07:21 myvpn ovpn-server[11206]: 44.55.66.77:44246 UDPv4 WRITE [1148] to [AF_INET]44.55.66.77:44246: P_CONTROL_V1 kid=0 pid=[ #10 ] [ ] pid=2 DATA len=1094
Aug 20 14:07:22 myvpn ovpn-server[11206]: 44.55.66.77:44246 UDPv4 WRITE [412] to [AF_INET]44.55.66.77:44246: P_CONTROL_V1 kid=0 pid=[ #11 ] [ ] pid=3 DATA len=358
It keeps retrying every three seconds or so, with the same outcome, and a minute later the connection attempts start timing out:

Code: Select all

Aug 20 14:08:13 myvpn ovpn-server[11206]: 44.55.66.77:44246 TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity)
Aug 20 14:08:13 myvpn ovpn-server[11206]: 44.55.66.77:44246 TLS Error: TLS handshake failed
Aug 20 14:08:13 myvpn ovpn-server[11206]: 44.55.66.77:44246 SIGUSR1[soft,tls-error] received, client-instance restarting
Still completely at a loss as to what could be causing this!

TinCanTech
OpenVPN Protagonist
Posts: 11137
Joined: Fri Jun 03, 2016 1:17 pm

Re: Having an "interesting" time with Sierra Wireless WWAN router & OpenVPN

Post by TinCanTech » Sun Aug 20, 2017 3:56 pm

etaoin wrote:Aug 20 14:07:08 myvpn ovpn-server[11206]: 44.55.66.77:39309 TLS: Initial packet from [AF_INET]44.55.66.77:39309, sid=468bbf98 493ec12b
Aug 20 14:07:08 myvpn ovpn-server[11206]: 44.55.66.77:39309 UDPv4 WRITE [66] to [AF_INET]44.55.66.77:39309: P_CONTROL_HARD_RESET_SERVER_V2 kid=0 pid=[ #1 ] [ 0 ] pid=0 DATA len=0
I don't know what the cause is but your server is rejecting your client .. Try without --tls-auth ..

etaoin
OpenVPN User
Posts: 24
Joined: Wed Aug 09, 2017 5:53 pm

Re: Having an "interesting" time with Sierra Wireless WWAN router & OpenVPN

Post by etaoin » Sun Aug 20, 2017 5:01 pm

Thanks. I've tried disabling TLS Auth by commenting out the option in server.conf, and disabling it in the WWAN router's client settings . I've got a capture of the resulting traffic at verb 6, but first, I noticed OpenVPN throwing out the whole current config when starting at verb 6 - I missed this in my previous post so here it is now, perhaps you can glean something from this:

Code: Select all

Aug 20 17:43:36 myvpn ovpn-server[15532]: Current Parameter Settings:
Aug 20 17:43:36 myvpn systemd[1]: Starting OpenVPN connection to server...
Aug 20 17:43:36 myvpn ovpn-server[15532]:   config = '/etc/openvpn/server.conf'
Aug 20 17:43:36 myvpn ovpn-server[15532]:   mode = 1
Aug 20 17:43:36 myvpn ovpn-server[15532]:   persist_config = DISABLED
Aug 20 17:43:36 myvpn ovpn-server[15532]:   persist_mode = 1
Aug 20 17:43:36 myvpn ovpn-server[15532]:   show_ciphers = DISABLED
Aug 20 17:43:36 myvpn ovpn-server[15532]:   show_digests = DISABLED
Aug 20 17:43:36 myvpn ovpn-server[15532]:   show_engines = DISABLED
Aug 20 17:43:36 myvpn ovpn-server[15532]:   genkey = DISABLED
Aug 20 17:43:36 myvpn ovpn-server[15532]:   key_pass_file = '[UNDEF]'
Aug 20 17:43:36 myvpn ovpn-server[15532]:   show_tls_ciphers = DISABLED
Aug 20 17:43:36 myvpn ovpn-server[15532]: Connection profiles [default]:
Aug 20 17:43:36 myvpn ovpn-server[15532]:   proto = udp
Aug 20 17:43:36 myvpn ovpn-server[15532]:   local = '22.33.44.55'
Aug 20 17:43:36 myvpn ovpn-server[15532]:   local_port = 1194
Aug 20 17:43:36 myvpn ovpn-server[15532]:   remote = '[UNDEF]'
Aug 20 17:43:36 myvpn ovpn-server[15532]:   remote_port = 1194
Aug 20 17:43:36 myvpn ovpn-server[15532]:   remote_float = DISABLED
Aug 20 17:43:36 myvpn ovpn-server[15532]:   bind_defined = DISABLED
Aug 20 17:43:36 myvpn ovpn-server[15532]:   bind_local = ENABLED
Aug 20 17:43:36 myvpn ovpn-server[15532]:   connect_retry_seconds = 5
Aug 20 17:43:36 myvpn ovpn-server[15532]:   connect_timeout = 10
Aug 20 17:43:36 myvpn ovpn-server[15532]:   connect_retry_max = 0
Aug 20 17:43:36 myvpn ovpn-server[15532]:   socks_proxy_server = '[UNDEF]'
Aug 20 17:43:36 myvpn ovpn-server[15532]:   socks_proxy_port = 0
Aug 20 17:43:36 myvpn ovpn-server[15532]:   socks_proxy_retry = DISABLED
Aug 20 17:43:36 myvpn ovpn-server[15532]:   tun_mtu = 1500
Aug 20 17:43:36 myvpn ovpn-server[15532]:   tun_mtu_defined = ENABLED
Aug 20 17:43:36 myvpn ovpn-server[15532]:   link_mtu = 1500
Aug 20 17:43:36 myvpn systemd[1]: Started OpenVPN connection to server.
Aug 20 17:43:36 myvpn ovpn-server[15532]:   link_mtu_defined = DISABLED
Aug 20 17:43:36 myvpn ovpn-server[15532]:   tun_mtu_extra = 0
Aug 20 17:43:36 myvpn ovpn-server[15532]:   tun_mtu_extra_defined = DISABLED
Aug 20 17:43:36 myvpn ovpn-server[15532]:   mtu_discover_type = -1
Aug 20 17:43:36 myvpn ovpn-server[15532]:   fragment = 0
Aug 20 17:43:36 myvpn ovpn-server[15532]:   mssfix = 1450
Aug 20 17:43:36 myvpn ovpn-server[15532]:   explicit_exit_notification = 0
Aug 20 17:43:36 myvpn ovpn-server[15532]: Connection profiles END
Aug 20 17:43:36 myvpn ovpn-server[15532]:   remote_random = DISABLED
Aug 20 17:43:36 myvpn ovpn-server[15532]:   ipchange = '[UNDEF]'
Aug 20 17:43:36 myvpn ovpn-server[15532]:   dev = 'tun'
Aug 20 17:43:36 myvpn ovpn-server[15532]:   dev_type = '[UNDEF]'
Aug 20 17:43:36 myvpn ovpn-server[15532]:   dev_node = '[UNDEF]'
Aug 20 17:43:36 myvpn ovpn-server[15532]:   lladdr = '[UNDEF]'
Aug 20 17:43:36 myvpn ovpn-server[15532]:   topology = 3
Aug 20 17:43:36 myvpn ovpn-server[15532]:   tun_ipv6 = DISABLED
Aug 20 17:43:36 myvpn ovpn-server[15532]:   ifconfig_local = '10.8.0.1'
Aug 20 17:43:36 myvpn ovpn-server[15532]:   ifconfig_remote_netmask = '255.255.255.0'
Aug 20 17:43:36 myvpn ovpn-server[15532]:   ifconfig_noexec = DISABLED
Aug 20 17:43:36 myvpn ovpn-server[15532]:   ifconfig_nowarn = DISABLED
Aug 20 17:43:36 myvpn ovpn-server[15532]:   ifconfig_ipv6_local = '[UNDEF]'
Aug 20 17:43:36 myvpn ovpn-server[15532]:   ifconfig_ipv6_netbits = 0
Aug 20 17:43:36 myvpn ovpn-server[15532]:   ifconfig_ipv6_remote = '[UNDEF]'
Aug 20 17:43:36 myvpn ovpn-server[15532]:   shaper = 0
Aug 20 17:43:36 myvpn ovpn-server[15532]:   mtu_test = 0
Aug 20 17:43:36 myvpn ovpn-server[15532]:   mlock = DISABLED
Aug 20 17:43:36 myvpn ovpn-server[15532]:   keepalive_ping = 10
Aug 20 17:43:36 myvpn ovpn-server[15532]:   keepalive_timeout = 120
Aug 20 17:43:36 myvpn ovpn-server[15532]:   inactivity_timeout = 0
Aug 20 17:43:36 myvpn ovpn-server[15532]:   ping_send_timeout = 10
Aug 20 17:43:36 myvpn ovpn-server[15532]:   ping_rec_timeout = 240
Aug 20 17:43:36 myvpn ovpn-server[15532]:   ping_rec_timeout_action = 2
Aug 20 17:43:36 myvpn ovpn-server[15532]:   ping_timer_remote = DISABLED
Aug 20 17:43:36 myvpn ovpn-server[15532]:   remap_sigusr1 = 0
Aug 20 17:43:36 myvpn ovpn-server[15532]:   persist_tun = ENABLED
Aug 20 17:43:36 myvpn ovpn-server[15532]:   persist_local_ip = DISABLED
Aug 20 17:43:36 myvpn ovpn-server[15532]:   persist_remote_ip = DISABLED
Aug 20 17:43:36 myvpn ovpn-server[15532]:   persist_key = ENABLED
Aug 20 17:43:36 myvpn ovpn-server[15532]:   passtos = DISABLED
Aug 20 17:43:36 myvpn ovpn-server[15532]:   resolve_retry_seconds = 1000000000
Aug 20 17:43:36 myvpn ovpn-server[15532]:   username = 'nobody'
Aug 20 17:43:36 myvpn ovpn-server[15532]:   groupname = 'nogroup'
Aug 20 17:43:36 myvpn ovpn-server[15532]:   chroot_dir = '[UNDEF]'
Aug 20 17:43:36 myvpn ovpn-server[15532]:   cd_dir = '/etc/openvpn'
Aug 20 17:43:36 myvpn ovpn-server[15532]:   writepid = '/run/openvpn/server.pid'
Aug 20 17:43:36 myvpn ovpn-server[15532]:   up_script = '[UNDEF]'
Aug 20 17:43:36 myvpn ovpn-server[15532]:   down_script = '[UNDEF]'
Aug 20 17:43:36 myvpn ovpn-server[15532]:   down_pre = DISABLED
Aug 20 17:43:36 myvpn ovpn-server[15532]:   up_restart = DISABLED
Aug 20 17:43:36 myvpn ovpn-server[15532]:   up_delay = DISABLED
Aug 20 17:43:36 myvpn ovpn-server[15532]:   daemon = ENABLED
Aug 20 17:43:36 myvpn ovpn-server[15532]:   inetd = 0
Aug 20 17:43:36 myvpn ovpn-server[15532]:   log = DISABLED
Aug 20 17:43:36 myvpn ovpn-server[15532]:   suppress_timestamps = DISABLED
Aug 20 17:43:36 myvpn ovpn-server[15532]:   nice = 0
Aug 20 17:43:36 myvpn ovpn-server[15532]:   verbosity = 6
Aug 20 17:43:36 myvpn ovpn-server[15532]:   mute = 0
Aug 20 17:43:36 myvpn ovpn-server[15532]:   gremlin = 0
Aug 20 17:43:36 myvpn ovpn-server[15532]:   status_file = 'openvpn.log'
Aug 20 17:43:36 myvpn ovpn-server[15532]:   status_file_version = 1
Aug 20 17:43:36 myvpn ovpn-server[15532]:   status_file_update_freq = 10
Aug 20 17:43:36 myvpn ovpn-server[15532]:   occ = ENABLED
Aug 20 17:43:36 myvpn ovpn-server[15532]:   rcvbuf = 0
Aug 20 17:43:36 myvpn ovpn-server[15532]:   sndbuf = 0
Aug 20 17:43:36 myvpn ovpn-server[15532]:   mark = 0
Aug 20 17:43:36 myvpn ovpn-server[15532]:   sockflags = 0
Aug 20 17:43:36 myvpn ovpn-server[15532]:   fast_io = DISABLED
Aug 20 17:43:36 myvpn ovpn-server[15532]:   lzo = 0
Aug 20 17:43:36 myvpn ovpn-server[15532]:   route_script = '[UNDEF]'
Aug 20 17:43:36 myvpn ovpn-server[15532]:   route_default_gateway = '10.8.0.2'
Aug 20 17:43:36 myvpn ovpn-server[15532]:   route_default_metric = 0
Aug 20 17:43:36 myvpn ovpn-server[15532]:   route_noexec = DISABLED
Aug 20 17:43:36 myvpn ovpn-server[15532]:   route_delay = 0
Aug 20 17:43:36 myvpn ovpn-server[15532]:   route_delay_window = 30
Aug 20 17:43:36 myvpn ovpn-server[15532]:   route_delay_defined = DISABLED
Aug 20 17:43:36 myvpn ovpn-server[15532]:   route_nopull = DISABLED
Aug 20 17:43:36 myvpn ovpn-server[15532]:   route_gateway_via_dhcp = DISABLED
Aug 20 17:43:36 myvpn ovpn-server[15532]:   max_routes = 100
Aug 20 17:43:36 myvpn ovpn-server[15532]:   allow_pull_fqdn = DISABLED
Aug 20 17:43:36 myvpn ovpn-server[15532]:   management_addr = '[UNDEF]'
Aug 20 17:43:36 myvpn ovpn-server[15532]:   management_port = 0
Aug 20 17:43:36 myvpn ovpn-server[15532]:   management_user_pass = '[UNDEF]'
Aug 20 17:43:36 myvpn ovpn-server[15532]:   management_log_history_cache = 250
Aug 20 17:43:36 myvpn ovpn-server[15532]:   management_echo_buffer_size = 100
Aug 20 17:43:36 myvpn ovpn-server[15532]:   management_write_peer_info_file = '[UNDEF]'
Aug 20 17:43:36 myvpn ovpn-server[15532]:   management_client_user = '[UNDEF]'
Aug 20 17:43:36 myvpn ovpn-server[15532]:   management_client_group = '[UNDEF]'
Aug 20 17:43:36 myvpn ovpn-server[15532]:   management_flags = 0
Aug 20 17:43:36 myvpn ovpn-server[15532]:   shared_secret_file = '[UNDEF]'
Aug 20 17:43:36 myvpn ovpn-server[15532]:   key_direction = 0
Aug 20 17:43:36 myvpn ovpn-server[15532]:   ciphername_defined = ENABLED
Aug 20 17:43:36 myvpn ovpn-server[15532]:   ciphername = 'AES-128-CBC'
Aug 20 17:43:36 myvpn ovpn-server[15532]:   authname_defined = ENABLED
Aug 20 17:43:36 myvpn ovpn-server[15532]:   authname = 'SHA256'
Aug 20 17:43:36 myvpn ovpn-server[15532]:   prng_hash = 'SHA1'
Aug 20 17:43:36 myvpn ovpn-server[15532]:   prng_nonce_secret_len = 16
Aug 20 17:43:36 myvpn ovpn-server[15532]:   keysize = 0
Aug 20 17:43:36 myvpn ovpn-server[15532]:   engine = DISABLED
Aug 20 17:43:36 myvpn ovpn-server[15532]:   replay = ENABLED
Aug 20 17:43:36 myvpn ovpn-server[15532]:   mute_replay_warnings = DISABLED
Aug 20 17:43:36 myvpn ovpn-server[15532]:   replay_window = 64
Aug 20 17:43:36 myvpn ovpn-server[15532]:   replay_time = 15
Aug 20 17:43:36 myvpn ovpn-server[15532]:   packet_id_file = '[UNDEF]'
Aug 20 17:43:36 myvpn ovpn-server[15532]:   use_iv = ENABLED
Aug 20 17:43:36 myvpn ovpn-server[15532]:   test_crypto = DISABLED
Aug 20 17:43:36 myvpn ovpn-server[15532]:   tls_server = ENABLED
Aug 20 17:43:36 myvpn ovpn-server[15532]:   tls_client = DISABLED
Aug 20 17:43:36 myvpn ovpn-server[15532]:   key_method = 2
Aug 20 17:43:36 myvpn ovpn-server[15532]:   ca_file = 'ca.crt'
Aug 20 17:43:36 myvpn ovpn-server[15532]:   ca_path = '[UNDEF]'
Aug 20 17:43:36 myvpn ovpn-server[15532]:   dh_file = 'dh.pem'
Aug 20 17:43:36 myvpn ovpn-server[15532]:   cert_file = 'server.crt'
Aug 20 17:43:36 myvpn ovpn-server[15532]:   extra_certs_file = '[UNDEF]'
Aug 20 17:43:36 myvpn ovpn-server[15532]:   priv_key_file = 'server.key'
Aug 20 17:43:36 myvpn ovpn-server[15532]:   pkcs12_file = '[UNDEF]'
Aug 20 17:43:36 myvpn ovpn-server[15532]:   cipher_list = '[UNDEF]'
Aug 20 17:43:36 myvpn ovpn-server[15532]:   tls_verify = '[UNDEF]'
Aug 20 17:43:36 myvpn ovpn-server[15532]:   tls_export_cert = '[UNDEF]'
Aug 20 17:43:36 myvpn ovpn-server[15532]:   verify_x509_type = 0
Aug 20 17:43:36 myvpn ovpn-server[15532]:   verify_x509_name = '[UNDEF]'
Aug 20 17:43:36 myvpn ovpn-server[15532]:   crl_file = 'crl.pem'
Aug 20 17:43:36 myvpn ovpn-server[15532]:   ns_cert_type = 0
Aug 20 17:43:36 myvpn ovpn-server[15532]:   remote_cert_ku[i] = 0
Aug 20 17:43:36 myvpn ovpn-server[15532]: message repeated 15 times: [   remote_cert_ku[i] = 0]
Aug 20 17:43:36 myvpn ovpn-server[15532]:   remote_cert_eku = '[UNDEF]'
Aug 20 17:43:36 myvpn ovpn-server[15532]:   ssl_flags = 64
Aug 20 17:43:36 myvpn ovpn-server[15532]:   tls_timeout = 2
Aug 20 17:43:36 myvpn ovpn-server[15532]:   renegotiate_bytes = 0
Aug 20 17:43:36 myvpn ovpn-server[15532]:   renegotiate_packets = 0
Aug 20 17:43:36 myvpn ovpn-server[15532]:   renegotiate_seconds = 3600
Aug 20 17:43:36 myvpn ovpn-server[15532]:   handshake_window = 60
Aug 20 17:43:36 myvpn ovpn-server[15532]:   transition_window = 3600
Aug 20 17:43:36 myvpn ovpn-server[15532]:   single_session = DISABLED
Aug 20 17:43:36 myvpn ovpn-server[15532]:   push_peer_info = DISABLED
Aug 20 17:43:36 myvpn ovpn-server[15532]:   tls_exit = DISABLED
Aug 20 17:43:36 myvpn ovpn-server[15532]:   tls_auth_file = '[UNDEF]'
Aug 20 17:43:36 myvpn ovpn-server[15532]:   pkcs11_protected_authentication = DISABLED
Aug 20 17:43:36 myvpn ovpn-server[15532]: message repeated 15 times: [   pkcs11_protected_authentication = DISABLED]
Aug 20 17:43:36 myvpn ovpn-server[15532]:   pkcs11_private_mode = 00000000
Aug 20 17:43:36 myvpn ovpn-server[15532]: message repeated 15 times: [   pkcs11_private_mode = 00000000]
Aug 20 17:43:36 myvpn ovpn-server[15532]:   pkcs11_cert_private = DISABLED
Aug 20 17:43:36 myvpn ovpn-server[15532]: message repeated 15 times: [   pkcs11_cert_private = DISABLED]
Aug 20 17:43:36 myvpn ovpn-server[15532]:   pkcs11_pin_cache_period = -1
Aug 20 17:43:36 myvpn ovpn-server[15532]:   pkcs11_id = '[UNDEF]'
Aug 20 17:43:36 myvpn ovpn-server[15532]:   pkcs11_id_management = DISABLED
Aug 20 17:43:36 myvpn ovpn-server[15532]:   server_network = 10.8.0.0
Aug 20 17:43:36 myvpn ovpn-server[15532]:   server_netmask = 255.255.255.0
Aug 20 17:43:36 myvpn ovpn-server[15532]:   server_network_ipv6 = ::
Aug 20 17:43:36 myvpn ovpn-server[15532]:   server_netbits_ipv6 = 0
Aug 20 17:43:36 myvpn ovpn-server[15532]:   server_bridge_ip = 0.0.0.0
Aug 20 17:43:36 myvpn ovpn-server[15532]:   server_bridge_netmask = 0.0.0.0
Aug 20 17:43:36 myvpn ovpn-server[15532]:   server_bridge_pool_start = 0.0.0.0
Aug 20 17:43:36 myvpn ovpn-server[15532]:   server_bridge_pool_end = 0.0.0.0
Aug 20 17:43:36 myvpn ovpn-server[15532]:   push_entry = 'dhcp-option DNS 80.68.80.24'
Aug 20 17:43:36 myvpn ovpn-server[15532]:   push_entry = 'dhcp-option DNS 80.68.80.25'
Aug 20 17:43:36 myvpn ovpn-server[15532]:   push_entry = 'redirect-gateway def1 bypass-dhcp'
Aug 20 17:43:36 myvpn ovpn-server[15532]:   push_entry = 'route-gateway 10.8.0.1'
Aug 20 17:43:36 myvpn ovpn-server[15532]:   push_entry = 'topology subnet'
Aug 20 17:43:36 myvpn ovpn-server[15532]:   push_entry = 'ping 10'
Aug 20 17:43:36 myvpn ovpn-server[15532]:   push_entry = 'ping-restart 120'
Aug 20 17:43:36 myvpn ovpn-server[15532]:   ifconfig_pool_defined = ENABLED
Aug 20 17:43:36 myvpn ovpn-server[15532]:   ifconfig_pool_start = 10.8.0.2
Aug 20 17:43:36 myvpn ovpn-server[15532]:   ifconfig_pool_end = 10.8.0.253
Aug 20 17:43:36 myvpn ovpn-server[15532]:   ifconfig_pool_netmask = 255.255.255.0
Aug 20 17:43:36 myvpn ovpn-server[15532]:   ifconfig_pool_persist_filename = 'ipp.txt'
Aug 20 17:43:36 myvpn ovpn-server[15532]:   ifconfig_pool_persist_refresh_freq = 600
Aug 20 17:43:36 myvpn ovpn-server[15532]:   ifconfig_ipv6_pool_defined = DISABLED
Aug 20 17:43:36 myvpn ovpn-server[15532]:   ifconfig_ipv6_pool_base = ::
Aug 20 17:43:36 myvpn ovpn-server[15532]:   ifconfig_ipv6_pool_netbits = 0
Aug 20 17:43:36 myvpn ovpn-server[15532]:   n_bcast_buf = 256
Aug 20 17:43:36 myvpn ovpn-server[15532]:   tcp_queue_limit = 64
Aug 20 17:43:36 myvpn ovpn-server[15532]:   real_hash_size = 256
Aug 20 17:43:36 myvpn ovpn-server[15532]:   virtual_hash_size = 256
Aug 20 17:43:36 myvpn ovpn-server[15532]:   client_connect_script = '[UNDEF]'
Aug 20 17:43:36 myvpn ovpn-server[15532]:   learn_address_script = '[UNDEF]'
Aug 20 17:43:36 myvpn ovpn-server[15532]:   client_disconnect_script = '[UNDEF]'
Aug 20 17:43:36 myvpn ovpn-server[15532]:   client_config_dir = '[UNDEF]'
Aug 20 17:43:36 myvpn ovpn-server[15532]:   ccd_exclusive = DISABLED
Aug 20 17:43:36 myvpn ovpn-server[15532]:   tmp_dir = '/tmp'
Aug 20 17:43:36 myvpn ovpn-server[15532]:   push_ifconfig_defined = DISABLED
Aug 20 17:43:36 myvpn ovpn-server[15532]:   push_ifconfig_local = 0.0.0.0
Aug 20 17:43:36 myvpn ovpn-server[15532]:   push_ifconfig_remote_netmask = 0.0.0.0
Aug 20 17:43:36 myvpn ovpn-server[15532]:   push_ifconfig_ipv6_defined = DISABLED
Aug 20 17:43:36 myvpn ovpn-server[15532]:   push_ifconfig_ipv6_local = ::/0
Aug 20 17:43:36 myvpn ovpn-server[15532]:   push_ifconfig_ipv6_remote = ::
Aug 20 17:43:36 myvpn ovpn-server[15532]:   enable_c2c = DISABLED
Aug 20 17:43:36 myvpn ovpn-server[15532]:   duplicate_cn = DISABLED
Aug 20 17:43:36 myvpn ovpn-server[15532]:   cf_max = 0
Aug 20 17:43:36 myvpn ovpn-server[15532]:   cf_per = 0
Aug 20 17:43:36 myvpn ovpn-server[15532]:   max_clients = 1024
Aug 20 17:43:36 myvpn ovpn-server[15532]:   max_routes_per_client = 256
Aug 20 17:43:36 myvpn ovpn-server[15532]:   auth_user_pass_verify_script = '[UNDEF]'
Aug 20 17:43:36 myvpn ovpn-server[15532]:   auth_user_pass_verify_script_via_file = DISABLED
Aug 20 17:43:36 myvpn ovpn-server[15532]:   port_share_host = '[UNDEF]'
Aug 20 17:43:36 myvpn ovpn-server[15532]:   port_share_port = 0
Aug 20 17:43:36 myvpn ovpn-server[15532]:   client = DISABLED
Aug 20 17:43:36 myvpn ovpn-server[15532]:   pull = DISABLED
Aug 20 17:43:36 myvpn ovpn-server[15532]:   auth_user_pass_file = '[UNDEF]'
And here is the traffic log with TLS Auth disabled at both ends:

Code: Select all

Aug 20 17:43:36 myvpn ovpn-server[15532]: OpenVPN 2.3.10 x86_64-pc-linux-gnu [SSL (OpenSSL)] [LZO] [EPOLL] [PKCS11] [MH] [IPv6] built on Jun 22 2017
Aug 20 17:43:36 myvpn ovpn-server[15532]: library versions: OpenSSL 1.0.2g  1 Mar 2016, LZO 2.08
Aug 20 17:43:36 myvpn ovpn-server[15535]: Diffie-Hellman initialized with 2048 bit key
Aug 20 17:43:36 myvpn ovpn-server[15535]: TLS-Auth MTU parms [ L:1569 D:1212 EF:38 EB:0 ET:0 EL:3 ]
Aug 20 17:43:36 myvpn ovpn-server[15535]: Socket Buffers: R=[212992->212992] S=[212992->212992]
Aug 20 17:43:36 myvpn ovpn-server[15535]: TUN/TAP device tun0 opened
Aug 20 17:43:36 myvpn ovpn-server[15535]: TUN/TAP TX queue length set to 100
Aug 20 17:43:36 myvpn ovpn-server[15535]: do_ifconfig, tt->ipv6=0, tt->did_ifconfig_ipv6_setup=0
Aug 20 17:43:36 myvpn ovpn-server[15535]: /sbin/ip link set dev tun0 up mtu 1500
Aug 20 17:43:36 myvpn ovpn-server[15535]: /sbin/ip addr add dev tun0 10.8.0.1/24 broadcast 10.8.0.255
Aug 20 17:43:36 myvpn ovpn-server[15535]: Data Channel MTU parms [ L:1569 D:1450 EF:69 EB:12 ET:0 EL:3 ]
Aug 20 17:43:36 myvpn ovpn-server[15535]: GID set to nogroup
Aug 20 17:43:36 myvpn ovpn-server[15535]: UID set to nobody
Aug 20 17:43:36 myvpn ovpn-server[15535]: UDPv4 link local (bound): [AF_INET]22.33.44.55:1194
Aug 20 17:43:36 myvpn ovpn-server[15535]: UDPv4 link remote: [undef]
Aug 20 17:43:36 myvpn ovpn-server[15535]: MULTI: multi_init called, r=256 v=256
Aug 20 17:43:36 myvpn ovpn-server[15535]: IFCONFIG POOL: base=10.8.0.2 size=252, ipv6=0
Aug 20 17:43:36 myvpn ovpn-server[15535]: ifconfig_pool_read(), in='laptop,10.8.0.2', TODO: IPv6
Aug 20 17:43:36 myvpn ovpn-server[15535]: succeeded -> ifconfig_pool_set()
Aug 20 17:43:36 myvpn ovpn-server[15535]: IFCONFIG POOL LIST
Aug 20 17:43:36 myvpn ovpn-server[15535]: laptop,10.8.0.2
Aug 20 17:43:36 myvpn ovpn-server[15535]: Initialization Sequence Completed
Aug 20 17:44:56 myvpn ovpn-server[15535]: MULTI: multi_create_instance called
Aug 20 17:44:56 myvpn ovpn-server[15535]: 44.55.66.77:43861 Re-using SSL/TLS context
Aug 20 17:44:56 myvpn ovpn-server[15535]: 44.55.66.77:43861 Control Channel MTU parms [ L:1569 D:1212 EF:38 EB:0 ET:0 EL:3 ]
Aug 20 17:44:56 myvpn ovpn-server[15535]: 44.55.66.77:43861 Data Channel MTU parms [ L:1569 D:1450 EF:69 EB:12 ET:0 EL:3 ]
Aug 20 17:44:56 myvpn ovpn-server[15535]: 44.55.66.77:43861 Local Options String: 'V4,dev-type tun,link-mtu 1569,tun-mtu 1500,proto UDPv4,cipher AES-128-CBC,auth SHA256,keysize 128,key-method 2,tls-server'
Aug 20 17:44:56 myvpn ovpn-server[15535]: 44.55.66.77:43861 Expected Remote Options String: 'V4,dev-type tun,link-mtu 1569,tun-mtu 1500,proto UDPv4,cipher AES-128-CBC,auth SHA256,keysize 128,key-method 2,tls-client'
Aug 20 17:44:56 myvpn ovpn-server[15535]: 44.55.66.77:43861 Local Options hash (VER=V4): 'cbc99a1e'
Aug 20 17:44:56 myvpn ovpn-server[15535]: 44.55.66.77:43861 Expected Remote Options hash (VER=V4): '74006a71'
Aug 20 17:44:56 myvpn ovpn-server[15535]: 44.55.66.77:43861 UDPv4 READ [14] from [AF_INET]44.55.66.77:43861: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 [ ] pid=0 DATA len=0
Aug 20 17:44:56 myvpn ovpn-server[15535]: 44.55.66.77:43861 TLS: Initial packet from [AF_INET]44.55.66.77:43861, sid=1c7c67e0 2fa8a5ce
Aug 20 17:44:56 myvpn ovpn-server[15535]: 44.55.66.77:43861 UDPv4 WRITE [26] to [AF_INET]44.55.66.77:43861: P_CONTROL_HARD_RESET_SERVER_V2 kid=0 [ 0 ] pid=0 DATA len=0
Aug 20 17:44:56 myvpn ovpn-server[15535]: 44.55.66.77:43861 UDPv4 READ [14] from [AF_INET]44.55.66.77:43861: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 [ ] pid=0 DATA len=0
Aug 20 17:44:56 myvpn ovpn-server[15535]: 44.55.66.77:43861 UDPv4 WRITE [22] to [AF_INET]44.55.66.77:43861: P_ACK_V1 kid=0 [ 0 ]
Aug 20 17:44:56 myvpn ovpn-server[15535]: 44.55.66.77:43861 UDPv4 READ [14] from [AF_INET]44.55.66.77:43861: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 [ ] pid=0 DATA len=0
Aug 20 17:44:56 myvpn ovpn-server[15535]: 44.55.66.77:43861 UDPv4 WRITE [22] to [AF_INET]44.55.66.77:43861: P_ACK_V1 kid=0 [ 0 ]
Aug 20 17:44:57 myvpn ovpn-server[15535]: 44.55.66.77:43861 UDPv4 READ [22] from [AF_INET]44.55.66.77:43861: P_ACK_V1 kid=0 [ 0 ]
Aug 20 17:44:57 myvpn ovpn-server[15535]: 44.55.66.77:43861 UDPv4 READ [114] from [AF_INET]44.55.66.77:43861: P_CONTROL_V1 kid=0 [ ] pid=1 DATA len=100
Aug 20 17:44:57 myvpn ovpn-server[15535]: 44.55.66.77:43861 UDPv4 WRITE [22] to [AF_INET]44.55.66.77:43861: P_ACK_V1 kid=0 [ 1 ]
Aug 20 17:44:57 myvpn ovpn-server[15535]: 44.55.66.77:43861 UDPv4 READ [111] from [AF_INET]44.55.66.77:43861: P_CONTROL_V1 kid=0 [ ] pid=2 DATA len=97
Aug 20 17:44:57 myvpn ovpn-server[15535]: 44.55.66.77:43861 UDPv4 WRITE [1200] to [AF_INET]44.55.66.77:43861: P_CONTROL_V1 kid=0 [ 2 ] pid=1 DATA len=1174
Aug 20 17:44:57 myvpn ovpn-server[15535]: 44.55.66.77:43861 UDPv4 WRITE [1188] to [AF_INET]44.55.66.77:43861: P_CONTROL_V1 kid=0 [ ] pid=2 DATA len=1174
Aug 20 17:44:57 myvpn ovpn-server[15535]: 44.55.66.77:43861 UDPv4 WRITE [212] to [AF_INET]44.55.66.77:43861: P_CONTROL_V1 kid=0 [ ] pid=3 DATA len=198
Aug 20 17:44:58 myvpn ovpn-server[15535]: 44.55.66.77:43861 UDPv4 READ [22] from [AF_INET]44.55.66.77:43861: P_ACK_V1 kid=0 [ 1 ]
Aug 20 17:45:00 myvpn ovpn-server[15535]: 44.55.66.77:43861 UDPv4 WRITE [1188] to [AF_INET]44.55.66.77:43861: P_CONTROL_V1 kid=0 [ ] pid=2 DATA len=1174
Aug 20 17:45:00 myvpn ovpn-server[15535]: MULTI: multi_create_instance called
Aug 20 17:45:00 myvpn ovpn-server[15535]: 44.55.66.77:39053 Re-using SSL/TLS context
Aug 20 17:45:00 myvpn ovpn-server[15535]: 44.55.66.77:39053 Control Channel MTU parms [ L:1569 D:1212 EF:38 EB:0 ET:0 EL:3 ]
Aug 20 17:45:00 myvpn ovpn-server[15535]: 44.55.66.77:39053 Data Channel MTU parms [ L:1569 D:1450 EF:69 EB:12 ET:0 EL:3 ]
Aug 20 17:45:00 myvpn ovpn-server[15535]: 44.55.66.77:39053 Local Options String: 'V4,dev-type tun,link-mtu 1569,tun-mtu 1500,proto UDPv4,cipher AES-128-CBC,auth SHA256,keysize 128,key-method 2,tls-server'
Aug 20 17:45:00 myvpn ovpn-server[15535]: 44.55.66.77:39053 Expected Remote Options String: 'V4,dev-type tun,link-mtu 1569,tun-mtu 1500,proto UDPv4,cipher AES-128-CBC,auth SHA256,keysize 128,key-method 2,tls-client'
Aug 20 17:45:00 myvpn ovpn-server[15535]: 44.55.66.77:39053 Local Options hash (VER=V4): 'cbc99a1e'
Aug 20 17:45:00 myvpn ovpn-server[15535]: 44.55.66.77:39053 Expected Remote Options hash (VER=V4): '74006a71'
Aug 20 17:45:00 myvpn ovpn-server[15535]: 44.55.66.77:39053 UDPv4 READ [14] from [AF_INET]44.55.66.77:39053: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 [ ] pid=0 DATA len=0
Aug 20 17:45:00 myvpn ovpn-server[15535]: 44.55.66.77:39053 TLS: Initial packet from [AF_INET]44.55.66.77:39053, sid=0254fa4f 045eb91b
Aug 20 17:45:00 myvpn ovpn-server[15535]: 44.55.66.77:39053 UDPv4 WRITE [26] to [AF_INET]44.55.66.77:39053: P_CONTROL_HARD_RESET_SERVER_V2 kid=0 [ 0 ] pid=0 DATA len=0
Aug 20 17:45:01 myvpn ovpn-server[15535]: 44.55.66.77:39053 UDPv4 READ [22] from [AF_INET]44.55.66.77:39053: P_ACK_V1 kid=0 [ 0 ]
Aug 20 17:45:01 myvpn ovpn-server[15535]: 44.55.66.77:39053 UDPv4 READ [114] from [AF_INET]44.55.66.77:39053: P_CONTROL_V1 kid=0 [ ] pid=1 DATA len=100
Aug 20 17:45:01 myvpn ovpn-server[15535]: 44.55.66.77:39053 UDPv4 WRITE [22] to [AF_INET]44.55.66.77:39053: P_ACK_V1 kid=0 [ 1 ]
Aug 20 17:45:01 myvpn ovpn-server[15535]: 44.55.66.77:39053 UDPv4 READ [111] from [AF_INET]44.55.66.77:39053: P_CONTROL_V1 kid=0 [ ] pid=2 DATA len=97
Aug 20 17:45:01 myvpn ovpn-server[15535]: 44.55.66.77:39053 UDPv4 WRITE [1200] to [AF_INET]44.55.66.77:39053: P_CONTROL_V1 kid=0 [ 2 ] pid=1 DATA len=1174
Aug 20 17:45:01 myvpn ovpn-server[15535]: 44.55.66.77:39053 UDPv4 WRITE [1188] to [AF_INET]44.55.66.77:39053: P_CONTROL_V1 kid=0 [ ] pid=2 DATA len=1174
Aug 20 17:45:01 myvpn ovpn-server[15535]: 44.55.66.77:39053 UDPv4 WRITE [212] to [AF_INET]44.55.66.77:39053: P_CONTROL_V1 kid=0 [ ] pid=3 DATA len=198
Aug 20 17:45:01 myvpn ovpn-server[15535]: 44.55.66.77:43861 UDPv4 WRITE [212] to [AF_INET]44.55.66.77:43861: P_CONTROL_V1 kid=0 [ ] pid=3 DATA len=198
Aug 20 17:45:02 myvpn ovpn-server[15535]: 44.55.66.77:39053 UDPv4 READ [22] from [AF_INET]44.55.66.77:39053: P_ACK_V1 kid=0 [ 1 ]
Aug 20 17:45:04 myvpn ovpn-server[15535]: MULTI: multi_create_instance called
Aug 20 17:45:04 myvpn ovpn-server[15535]: 44.55.66.77:57154 Re-using SSL/TLS context
Aug 20 17:45:04 myvpn ovpn-server[15535]: 44.55.66.77:57154 Control Channel MTU parms [ L:1569 D:1212 EF:38 EB:0 ET:0 EL:3 ]
Aug 20 17:45:04 myvpn ovpn-server[15535]: 44.55.66.77:57154 Data Channel MTU parms [ L:1569 D:1450 EF:69 EB:12 ET:0 EL:3 ]
Aug 20 17:45:04 myvpn ovpn-server[15535]: 44.55.66.77:57154 Local Options String: 'V4,dev-type tun,link-mtu 1569,tun-mtu 1500,proto UDPv4,cipher AES-128-CBC,auth SHA256,keysize 128,key-method 2,tls-server'
Aug 20 17:45:04 myvpn ovpn-server[15535]: 44.55.66.77:57154 Expected Remote Options String: 'V4,dev-type tun,link-mtu 1569,tun-mtu 1500,proto UDPv4,cipher AES-128-CBC,auth SHA256,keysize 128,key-method 2,tls-client'
Aug 20 17:45:04 myvpn ovpn-server[15535]: 44.55.66.77:57154 Local Options hash (VER=V4): 'cbc99a1e'
Aug 20 17:45:04 myvpn ovpn-server[15535]: 44.55.66.77:57154 Expected Remote Options hash (VER=V4): '74006a71'
Aug 20 17:45:04 myvpn ovpn-server[15535]: 44.55.66.77:57154 UDPv4 READ [14] from [AF_INET]44.55.66.77:57154: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 [ ] pid=0 DATA len=0
Aug 20 17:45:04 myvpn ovpn-server[15535]: 44.55.66.77:57154 TLS: Initial packet from [AF_INET]44.55.66.77:57154, sid=3474aeef db9f8f07
Aug 20 17:45:04 myvpn ovpn-server[15535]: 44.55.66.77:57154 UDPv4 WRITE [26] to [AF_INET]44.55.66.77:57154: P_CONTROL_HARD_RESET_SERVER_V2 kid=0 [ 0 ] pid=0 DATA len=0
Aug 20 17:45:04 myvpn ovpn-server[15535]: 44.55.66.77:43861 UDPv4 WRITE [1188] to [AF_INET]44.55.66.77:43861: P_CONTROL_V1 kid=0 [ ] pid=2 DATA len=1174
Aug 20 17:45:04 myvpn ovpn-server[15535]: 44.55.66.77:39053 UDPv4 WRITE [1188] to [AF_INET]44.55.66.77:39053: P_CONTROL_V1 kid=0 [ ] pid=2 DATA len=1174
Aug 20 17:45:05 myvpn ovpn-server[15535]: 44.55.66.77:57154 UDPv4 READ [22] from [AF_INET]44.55.66.77:57154: P_ACK_V1 kid=0 [ 0 ]
Aug 20 17:45:05 myvpn ovpn-server[15535]: 44.55.66.77:57154 UDPv4 READ [114] from [AF_INET]44.55.66.77:57154: P_CONTROL_V1 kid=0 [ ] pid=1 DATA len=100
Aug 20 17:45:05 myvpn ovpn-server[15535]: 44.55.66.77:57154 UDPv4 WRITE [22] to [AF_INET]44.55.66.77:57154: P_ACK_V1 kid=0 [ 1 ]
Aug 20 17:45:05 myvpn ovpn-server[15535]: 44.55.66.77:43861 UDPv4 WRITE [212] to [AF_INET]44.55.66.77:43861: P_CONTROL_V1 kid=0 [ ] pid=3 DATA len=198
Aug 20 17:45:05 myvpn ovpn-server[15535]: 44.55.66.77:57154 UDPv4 READ [111] from [AF_INET]44.55.66.77:57154: P_CONTROL_V1 kid=0 [ ] pid=2 DATA len=97
Aug 20 17:45:05 myvpn ovpn-server[15535]: 44.55.66.77:57154 UDPv4 WRITE [1200] to [AF_INET]44.55.66.77:57154: P_CONTROL_V1 kid=0 [ 2 ] pid=1 DATA len=1174
Aug 20 17:45:05 myvpn ovpn-server[15535]: 44.55.66.77:57154 UDPv4 WRITE [1188] to [AF_INET]44.55.66.77:57154: P_CONTROL_V1 kid=0 [ ] pid=2 DATA len=1174
Aug 20 17:45:05 myvpn ovpn-server[15535]: 44.55.66.77:57154 UDPv4 WRITE [212] to [AF_INET]44.55.66.77:57154: P_CONTROL_V1 kid=0 [ ] pid=3 DATA len=198
Aug 20 17:45:05 myvpn ovpn-server[15535]: 44.55.66.77:39053 UDPv4 WRITE [212] to [AF_INET]44.55.66.77:39053: P_CONTROL_V1 kid=0 [ ] pid=3 DATA len=198
Aug 20 17:45:06 myvpn ovpn-server[15535]: 44.55.66.77:57154 UDPv4 READ [22] from [AF_INET]44.55.66.77:57154: P_ACK_V1 kid=0 [ 1 ]
Again, this keeps repeating and after a minute the time-outs start appearing:

Code: Select all

Aug 20 17:46:01 myvpn ovpn-server[15535]: 44.55.66.77:39053 TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity)
Aug 20 17:46:01 myvpn ovpn-server[15535]: 44.55.66.77:39053 TLS Error: TLS handshake failed
Aug 20 17:46:01 myvpn ovpn-server[15535]: 44.55.66.77:39053 SIGUSR1[soft,tls-error] received, client-instance restarting
I'm confused now, as to what TLS actually refers to here - I thought commenting out tls-auth in server.config would disable TLS shared key authentication, but then what it the "TLS handshake" above? Do I also need to comment out these two?

Code: Select all

tls-server
tls-version-min 1.0
Edit: Tried commenting out those two lines as well but it made no difference; "TLS handshake failed" still appears from 1 min after initial request onwards.

TinCanTech
OpenVPN Protagonist
Posts: 11137
Joined: Fri Jun 03, 2016 1:17 pm

Re: Having an "interesting" time with Sierra Wireless WWAN router & OpenVPN

Post by TinCanTech » Sun Aug 20, 2017 5:19 pm

etaoin wrote:I'm confused now, as to what TLS actually refers to here - I thought commenting out tls-auth in server.config would disable TLS shared key authentication, but then what it the "TLS handshake" above? Do I also need to comment out these two?

tls-server
This is implied by --server so commenting it out here makes no difference.
etaoin wrote:tls-version-min 1.0
This can cause problems .. leave it commented out for now.

TLS is in use all the time but --tls-auth is an HMAC on top of that ..

See --tls-auth in The Manual v24x

It is complicated .. don't expect to understand it :(

etaoin
OpenVPN User
Posts: 24
Joined: Wed Aug 09, 2017 5:53 pm

Re: Having an "interesting" time with Sierra Wireless WWAN router & OpenVPN

Post by etaoin » Sun Aug 20, 2017 5:31 pm

TinCanTech wrote:
etaoin wrote:tls-server
This is implied by --server so commenting it out here makes no difference.
I'm still confused; are you saying I haven't disabled TLS Auth, or that the tls-server setting has nothing to do with TLS Auth - or something else altogether?
TinCanTech wrote:
etaoin wrote:tls-version-min 1.0
This can cause problems .. leave it commented out for now.

Will do - I only added this out of desperation, thinking if the OpenVPN server version is more recent than on the client (likely) it might push for a more recent TLS standard by default - especially since there have been some serious security issues found recently. My thinking was that by explicitly telling the server to accept TLS 1.0 I'd maximise my chances of the client being able to connect.
TinCanTech wrote:TLS is in use all the time but --tls-auth is an HMAC on top of that ..
Cool, yeah, that's pretty much how I understood things - I mean a VPN is basically a TLS encrypted channel, so... The syslog output is a little overwhelming for a VPN noob though, and I'm never quite sure if I might be misunderstanding something elementary.
TinCanTech wrote:See --tls-auth in The Manual v24x
Oh I have. If you had any idea how many days I have spent reading this and dozens of guides, blogs, Server Fault and Stack Overflow messages, as well as trawling this forum for information. Much of it is over my head, I admit, but I'm not that inexperienced, and usually trust my own ability to figure things out. But I've clearly met my match here!
TinCanTech wrote:It is complicated .. don't expect to understand it :(
If you think you understand quantum mechanics, you don't understand quantum mechanics.
- Richard Feynman

etaoin
OpenVPN User
Posts: 24
Joined: Wed Aug 09, 2017 5:53 pm

Re: Having an "interesting" time with Sierra Wireless WWAN router & OpenVPN

Post by etaoin » Sun Aug 20, 2017 5:40 pm

Since I'm able to connect to the VPN server from my laptop I'm pretty sure that the server side firewall is correctly set up, but just to eliminate the possibility of the client side firewall (on the WWAN router) interfering, exactly what ports need to be unfiltered for OpenVPN to function? I mean I know 1194 needs to be unfiltered of course, but any others? It's true that I have tried connecting with the client side firewall disabled (no ports filtered) with the same results, but I'm pretty desperate here!

TinCanTech
OpenVPN Protagonist
Posts: 11137
Joined: Fri Jun 03, 2016 1:17 pm

Re: Having an "interesting" time with Sierra Wireless WWAN router & OpenVPN

Post by TinCanTech » Sun Aug 20, 2017 6:42 pm

etaoin wrote:
TinCanTech wrote:It is complicated .. don't expect to understand it :(
If you think you understand quantum mechanics, you don't understand quantum mechanics.
- Richard Feynman
:lol:
etaoin wrote:I'm not that inexperienced, and usually trust my own ability to figure things out. But I've clearly met my match here!
The problem is clearly with that particular client .. I would redo that client from scratch.

Also, you have not posted the version of openvpn that the router is running.

etaoin
OpenVPN User
Posts: 24
Joined: Wed Aug 09, 2017 5:53 pm

Re: Having an "interesting" time with Sierra Wireless WWAN router & OpenVPN

Post by etaoin » Sun Aug 20, 2017 7:54 pm

TinCanTech wrote:
etaoin wrote:I'm not that inexperienced, and usually trust my own ability to figure things out. But I've clearly met my match here!
The problem is clearly with that particular client .. I would redo that client from scratch.
If by "redoing" you mean revoking and regenerating the keys for it, and updating them in the router management interface, I have done this, oh, at least three times - one of them just earlier today. I'm using the OpenVPN management script from https://github.com/Angristan/OpenVPN-install/ for this, which gives me an .ovpn file which I open in a text editor and copy out the relevant certificates and keys into separate files:

Into raven-ca.pem I copy these lines from inside <ca>

Code: Select all

-----BEGIN CERTIFICATE-----
...
-----END CERTIFICATE-----
Into raven-cert.pem I copy these lines from inside <cert>:

Code: Select all

-----BEGIN CERTIFICATE-----
...
-----END CERTIFICATE-----
Into raven-key.pem I copy these lines from iniside <key>

Code: Select all

-----BEGIN PRIVATE KEY-----
...
-----END PRIVATE KEY-----
Finally, into raven-tls-auth.pem, I copy these lines from inside <tls-auth>

Code: Select all

-----BEGIN OpenVPN Static key V1-----
...
-----END OpenVPN Static key V1-----
These four files are then uploaded on the router's VPN setup page, and confirmed as updated by changing the filenames (the filenames listed above are those which match the screengrab I posted earlier, but I have changed them each time to eliminate any potential caching issue, and have confirmed the new filenames in the router UI after each switch).
TinCanTech wrote:Also, you have not posted the version of openvpn that the router is running.


I would love to know myself! Alas, Sierra Wireless do not provide this information, and the SSH console provided by the router only accepts "AT commands", none of which allow me to query the OpenVPN or OpenSSL library versions. I have looked through the firmware release notes, and have contacted Sierra Wireless via their support forum for clarification on this, but my post there has gone unanswered for a week. That said, we are talking about a $700 router designed for vehicular use by emergency respondents; not only is it a pretty solid piece of kit but firmware updates are frequent, and I am running the latest (July?) firmware on it. Since they explicitly provide an OpenVPN client, which they shout about in the product literature, I would be very surprised if it couldn't be made to work.

After my previous post I had a brainwave for something I hadn't tested yet; to hook my laptop up to the WWAN router and use the OpenVPN client on it to connect through the WWAN. Previously I had tested connecting to the VPN server from the laptop over the ADSL connection I have here at home, and was able to connect on first attempt by importing the .ovpn file generated for "laptop" on the server into Network Manager (Ubuntu). I figured it would be interesting to see if this would still work when going through the WWAN - if nothing else it would serve as final confirmation that the WWAN router's firewall isn't preventing successful OpenVPN connections, or that the mobile service provider's network blocks the traffic, in whatever way, for whatever reason. Having tested a few times, with and without TLS Auth enabled on the server and/or on the client, I can confirm it does indeed work, if a bit sluggishly, and I have a confirmed negative as well in that disabling TLS Auth on the NM client while it is enabled on the server results in a connection failure. So the WWAN router's firewall is not the problem, nor does the mobile network pose a stumbling block, far as I can reasonably tell.

TinCanTech
OpenVPN Protagonist
Posts: 11137
Joined: Fri Jun 03, 2016 1:17 pm

Re: Having an "interesting" time with Sierra Wireless WWAN router & OpenVPN

Post by TinCanTech » Sun Aug 20, 2017 8:11 pm

etaoin wrote:I would love to know myself! Alas, Sierra Wireless do not provide this information, and the SSH console provided by the router only accepts "AT commands", none of which allow me to query the OpenVPN or OpenSSL library versions. I have looked through the firmware release notes, and have contacted Sierra Wireless via their support forum for clarification on this, but my post there has gone unanswered for a week. That said, we are talking about a $700 router designed for vehicular use by emergency respondents; not only is it a pretty solid piece of kit but firmware updates are frequent, and I am running the latest (July?) firmware on it. Since they explicitly provide an OpenVPN client, which they shout about in the product literature, I would be very surprised if it couldn't be made to work.
Agreed .. and for that sort of money they can provide support for their product.

tincanteksup <at> gmail
Last edited by TinCanTech on Sun Aug 20, 2017 8:19 pm, edited 1 time in total.

etaoin
OpenVPN User
Posts: 24
Joined: Wed Aug 09, 2017 5:53 pm

Re: Having an "interesting" time with Sierra Wireless WWAN router & OpenVPN

Post by etaoin » Sun Aug 20, 2017 8:19 pm

Just to avoid confusion: I have modified the openvpn-install script I got from https://github.com/Angristan/OpenVPN-install/ to say tls-version-min 1.0 instead of the 1.2 it defaults to - and I have re-installed OpenVPN using the updated script to make sure that there's nothing in the way the TLS key gets generated that would disallow a downgrade to TLS 1.0. That said, I still can't get things to work even with TLS Auth completely disabled, so this is likely not the issue. And to further clarify, the cipher and authentication schemes chosen are AES-128-CBC and SHA-256 respectively. The WWAN router's VPN config options do not explicitly list an AES-128-CBC option, only AES-128, but I assume CBC to be the logical default and that had they provided a GCM option then this would have been explicitly mentioned (with GCM being far newer).

etaoin
OpenVPN User
Posts: 24
Joined: Wed Aug 09, 2017 5:53 pm

Re: Having an "interesting" time with Sierra Wireless WWAN router & OpenVPN

Post by etaoin » Sun Aug 20, 2017 8:52 pm

TinCanTech wrote:
etaoin wrote:I would love to know myself! Alas, Sierra Wireless do not provide this information, and the SSH console provided by the router only accepts "AT commands", none of which allow me to query the OpenVPN or OpenSSL library versions. I have looked through the firmware release notes, and have contacted Sierra Wireless via their support forum for clarification on this, but my post there has gone unanswered for a week. That said, we are talking about a $700 router designed for vehicular use by emergency respondents; not only is it a pretty solid piece of kit but firmware updates are frequent, and I am running the latest (July?) firmware on it. Since they explicitly provide an OpenVPN client, which they shout about in the product literature, I would be very surprised if it couldn't be made to work.
Agreed .. and for that sort of money they can provide support for their product.
Agreed. But what if they don't? I didn't buy the RV50 new, and can't send it back. I chose to buy a second-hand RV50 rather than a new "Chinese" device at a similar price point precisely because I wanted something that would "just work". Boy do I feel like a sucker now.

But I'm not ready to give up just yet! It would be really great if someone could give me a quick explanation of what it is I'm seeing in the syslog when the connection from the WWAN router fails. As far as I can tell, each attempt consists of the following conversation (with TLS Auth disabled):

Code: Select all

Aug 20 21:38:03 myvpn ovpn-server[20695]: MULTI: multi_create_instance called
Aug 20 21:38:03 myvpn ovpn-server[20695]: 44.55.66.77:50586 Re-using SSL/TLS context
Aug 20 21:38:03 myvpn ovpn-server[20695]: 44.55.66.77:50586 Control Channel MTU parms [ L:1569 D:1212 EF:38 EB:0 ET:0 EL:3 ]
Aug 20 21:38:03 myvpn ovpn-server[20695]: 44.55.66.77:50586 Data Channel MTU parms [ L:1569 D:1450 EF:69 EB:12 ET:0 EL:3 ]
Aug 20 21:38:03 myvpn ovpn-server[20695]: 44.55.66.77:50586 Local Options String: 'V4,dev-type tun,link-mtu 1569,tun-mtu 1500,proto UDPv4,cipher AES-128-CBC,auth SHA256,keysize 128,key-method 2,tls-server'
Aug 20 21:38:03 myvpn ovpn-server[20695]: 44.55.66.77:50586 Expected Remote Options String: 'V4,dev-type tun,link-mtu 1569,tun-mtu 1500,proto UDPv4,cipher AES-128-CBC,auth SHA256,keysize 128,key-method 2,tls-client'
Aug 20 21:38:03 myvpn ovpn-server[20695]: 44.55.66.77:50586 Local Options hash (VER=V4): 'cbc99a1e'
Aug 20 21:38:03 myvpn ovpn-server[20695]: 44.55.66.77:50586 Expected Remote Options hash (VER=V4): '74006a71'
Aug 20 21:38:03 myvpn ovpn-server[20695]: 44.55.66.77:50586 UDPv4 READ [14] from [AF_INET]44.55.66.77:50586: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 [ ] pid=0 DATA len=0
Aug 20 21:38:03 myvpn ovpn-server[20695]: 44.55.66.77:50586 TLS: Initial packet from [AF_INET]44.55.66.77:50586, sid=ea771ecf 5cd87f06
Aug 20 21:38:03 myvpn ovpn-server[20695]: 44.55.66.77:50586 UDPv4 WRITE [26] to [AF_INET]44.55.66.77:50586: P_CONTROL_HARD_RESET_SERVER_V2 kid=0 [ 0 ] pid=0 DATA len=0
Aug 20 21:38:04 myvpn ovpn-server[20695]: 44.55.66.77:36001 UDPv4 WRITE [1188] to [AF_INET]44.55.66.77:36001: P_CONTROL_V1 kid=0 [ ] pid=2 DATA len=1174
Aug 20 21:38:04 myvpn ovpn-server[20695]: 44.55.66.77:52777 UDPv4 WRITE [1188] to [AF_INET]44.55.66.77:52777: P_CONTROL_V1 kid=0 [ ] pid=2 DATA len=1174
Aug 20 21:38:04 myvpn ovpn-server[20695]: 44.55.66.77:58779 UDPv4 WRITE [1188] to [AF_INET]44.55.66.77:58779: P_CONTROL_V1 kid=0 [ ] pid=2 DATA len=1174
Aug 20 21:38:04 myvpn ovpn-server[20695]: 44.55.66.77:58787 UDPv4 WRITE [1188] to [AF_INET]44.55.66.77:58787: P_CONTROL_V1 kid=0 [ ] pid=2 DATA len=1174
Aug 20 21:38:05 myvpn ovpn-server[20695]: 44.55.66.77:50586 UDPv4 READ [22] from [AF_INET]44.55.66.77:50586: P_ACK_V1 kid=0 [ 0 ]
Aug 20 21:38:05 myvpn ovpn-server[20695]: 44.55.66.77:58787 UDPv4 WRITE [212] to [AF_INET]44.55.66.77:58787: P_CONTROL_V1 kid=0 [ ] pid=3 DATA len=198
Aug 20 21:38:05 myvpn ovpn-server[20695]: 44.55.66.77:50586 UDPv4 READ [114] from [AF_INET]44.55.66.77:50586: P_CONTROL_V1 kid=0 [ ] pid=1 DATA len=100
Aug 20 21:38:05 myvpn ovpn-server[20695]: 44.55.66.77:50586 UDPv4 WRITE [22] to [AF_INET]44.55.66.77:50586: P_ACK_V1 kid=0 [ 1 ]
Aug 20 21:38:05 myvpn ovpn-server[20695]: 44.55.66.77:50586 UDPv4 READ [111] from [AF_INET]44.55.66.77:50586: P_CONTROL_V1 kid=0 [ ] pid=2 DATA len=97
Aug 20 21:38:05 myvpn ovpn-server[20695]: 44.55.66.77:50586 UDPv4 WRITE [1200] to [AF_INET]44.55.66.77:50586: P_CONTROL_V1 kid=0 [ 2 ] pid=1 DATA len=1174
Aug 20 21:38:05 myvpn ovpn-server[20695]: 44.55.66.77:50586 UDPv4 WRITE [1188] to [AF_INET]44.55.66.77:50586: P_CONTROL_V1 kid=0 [ ] pid=2 DATA len=1174
Aug 20 21:38:05 myvpn ovpn-server[20695]: 44.55.66.77:50586 UDPv4 WRITE [212] to [AF_INET]44.55.66.77:50586: P_CONTROL_V1 kid=0 [ ] pid=3 DATA len=198
Aug 20 21:38:05 myvpn ovpn-server[20695]: 44.55.66.77:36001 UDPv4 WRITE [212] to [AF_INET]44.55.66.77:36001: P_CONTROL_V1 kid=0 [ ] pid=3 DATA len=198
Aug 20 21:38:05 myvpn ovpn-server[20695]: 44.55.66.77:52777 UDPv4 WRITE [212] to [AF_INET]44.55.66.77:52777: P_CONTROL_V1 kid=0 [ ] pid=3 DATA len=198
Aug 20 21:38:05 myvpn ovpn-server[20695]: 44.55.66.77:50586 UDPv4 READ [22] from [AF_INET]44.55.66.77:50586: P_ACK_V1 kid=0 [ 1 ]
and, a minute later:

Code: Select all

Aug 20 21:39:05 myvpn ovpn-server[20695]: 44.55.66.77:44082 TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity)
Aug 20 21:39:05 myvpn ovpn-server[20695]: 44.55.66.77:44082 TLS Error: TLS handshake failed
Aug 20 21:39:05 myvpn ovpn-server[20695]: 44.55.66.77:44082 SIGUSR1[soft,tls-error] received, client-instance restarting
What can you guys tell from this?

Edit: Is it worth looking at things like MTU, or is it clear from the above that the issue lies on the encryption side?

TinCanTech
OpenVPN Protagonist
Posts: 11137
Joined: Fri Jun 03, 2016 1:17 pm

Re: Having an "interesting" time with Sierra Wireless WWAN router & OpenVPN

Post by TinCanTech » Sun Aug 20, 2017 9:08 pm

How can we support your router when you can't even get the version of OpenVPN it has installed ?

etaoin
OpenVPN User
Posts: 24
Joined: Wed Aug 09, 2017 5:53 pm

Re: Having an "interesting" time with Sierra Wireless WWAN router & OpenVPN

Post by etaoin » Sun Aug 20, 2017 10:41 pm

TinCanTech wrote:How can we support your router when you can't even get the version of OpenVPN it has installed ?
For one thing, maybe someone could explain why the OpenVPN version might matter, and what could be done to enhance interoperability between the different versions, such as choice of settings, ciphers etc. Is the backwards compatibility really that bad? Is there not some minimal basic configuration that can be tried? A "bullet proof" default for quirky clients? I'm quite happy to start over from scratch, if it means any prospect of success - should I perhaps try to install an older version of OpenVPN? Or is there maybe some way to get the OpenVPN client to identify itself? Or to glean something about its capabilities from the server log? What does the server log say anyway? What does "P_CONTROL_HARD_RESET_CLIENT_V2" and "P_CONTROL_HARD_RESET_SERVER_V2" mean, and are the responses in the log consistent with success or failure? At what point is the failure clear in the logs, other than the eventual time-out? I see a few "P_ACK_V1" coming in from the client as well? Would it help to turn verbosity up to 11? Could it have something to do with MTU and other packet metrics? Would it help if I became a paying user of OpenVPN? Could I pay you for your time? I'm over a week in the hole on this one and if I cannot find a solution then all that time will have been wasted.

I mean really, there is no end to the questions I have in my head around how OpenVPN works and what might be the cause of this issue - not being able to get answers here would be a far bigger hindrance than any lack of support from Sierra's side, since this is where the software in question comes from. Chances are if they did respond that's what they would say as well!

etaoin
OpenVPN User
Posts: 24
Joined: Wed Aug 09, 2017 5:53 pm

Re: Having an "interesting" time with Sierra Wireless WWAN router & OpenVPN

Post by etaoin » Sun Aug 20, 2017 10:50 pm

I've just seen that there is a new thread in the Sierra forum about OpenVPN issues: https://forum.sierrawireless.com/viewto ... 49&t=10641 It looks like I might be able to get the OpenVPN client version if I push the router's syslog somewhere. Investigating.

Post Reply