New server on RPi3 only allows one connection....

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.
Post Reply
BobAGI
OpenVPN Power User
Posts: 167
Joined: Mon May 05, 2014 10:17 pm

New server on RPi3 only allows one connection....

Post by BobAGI » Sun Jun 06, 2021 9:55 am

I have discussed this problem on the openvpn-users mail list but was advised to move to the forum and supply log and conf info.
So here goes:
After installing the openvpn server and configuring it like I usually do I put it at my summer home behind a mobile 4G broadband router. Initially it seemed to work OK.
But then I discovered that when I tried to connect two clients at the same time the second one always fails to connect.
Furthermore after the first connected client disconnects it cannot connect again until some yet unknown timeout of several minutes has passed....
So during the timeout the OVPN server is inaccessible to all for a while.

This is what I have done:
1) I have installed openvpn on a brand new operating system install on a RPi3B+ device:
These are the only install commands used following operating system install (from history):

Code: Select all

   19  2021-06-06 00:41:06 sudo apt install subversion
   34  2021-05-26 13:16:14 sudo apt install openvpn dos2unix openssl
  330  2021-05-28 15:06:28 sudo apt install iptables-persistent
I have also set up IPTABLES as follows (there are actually 3 openvpn instances but the other two are shut down during these tests):

Code: Select all

$ sudo iptables-save
# Generated by xtables-save v1.8.2 on Sun Jun  6 11:34:18 2021
*nat
:PREROUTING ACCEPT [135:28592]
:INPUT ACCEPT [83:17331]
:POSTROUTING ACCEPT [79:6072]
:OUTPUT ACCEPT [78:5734]
-A POSTROUTING -s 10.117.1.0/24 -j MASQUERADE
-A POSTROUTING -s 10.117.2.0/24 -j MASQUERADE
-A POSTROUTING -s 10.117.3.0/24 -j MASQUERADE
COMMIT
# Completed on Sun Jun  6 11:34:18 2021
# Generated by xtables-save v1.8.2 on Sun Jun  6 11:34:18 2021
*filter
:INPUT ACCEPT [10044:1230276]
:FORWARD ACCEPT [10908:10611331]
:OUTPUT ACCEPT [15882:12058330]
COMMIT
# Completed on Sun Jun  6 11:34:18 2021
2) The server conf file looks like this for connection only to the server side LAN but no Internet:
serverconf

port 1195
server 10.117.2.0 255.255.255.0 'nopool'
proto udp4 #Use only ipv4
dev tun
ca /etc/openvpn/keys/ca.crt
cert /etc/openvpn/keys/AGIVPN.crt
key /etc/openvpn/keys/AGIVPN.key
dh /etc/openvpn/keys/dh2048.pem
tls-auth /etc/openvpn/keys/ta.key 0
key-direction 0
topology subnet
ifconfig-pool 10.117.2.2 10.117.2.127 255.255.255.0
client-config-dir /etc/openvpn/ccdlan
ifconfig-pool-persist ipplan.txt
push "route 192.168.117.0 255.255.255.0"
push "dhcp-option DNS 192.168.117.1" #Set DNS to the local router
push "dhcp-option DNS 208.67.220.220" #Set DNS to the public server 2
keepalive 10 120
cipher AES-256-CBC
client-to-client #Allow inter-client communication
comp-lzo
max-clients 20
persist-key
persist-tun
verb 4
explicit-exit-notify 1 #Make sure the server notify the client before restarting
status /etc/openvpn/log/ovpn-status_lan.log
#log-append /etc/openvpn/log/ovpn_lan.log #Use this to keep log across server restarts
log /etc/openvpn/log/ovpn_lan.log #Use this to start a new log when server restarts


3) There are two different client connect ovpn file types, one where the file is password protected and one without this.
The password protected file is for use on Windows to connect to the server by a human, the other is for use on Linux for automatic connection since there is no user to enter the password.
Here they are:

The RPi autoconnect conf:
clientconf-nopwd

remote xxxx.yyyyyy.com 1195
client
dev tun
proto udp
resolv-retry infinite
nobind
persist-key
persist-tun
auth-nocache
mute-replay-warnings
remote-cert-tls server
key-direction 1
cipher AES-256-CBC
explicit-exit-notify
comp-lzo
verb 4
mute 20


The Windows manual connect conf:
clientconf-pwd

remote xxxx.yyyyyy.com 1195
client
dev tun
proto udp
resolv-retry infinite
nobind
persist-key
persist-tun
auth-nocache
mute-replay-warnings
remote-cert-tls server
key-direction 1
cipher AES-256-CBC
comp-lzo
verb 1
mute 20


4) The server was re-started today and the server log looks like this from start to idle:

Code: Select all

Sun Jun  6 08:10:25 2021 us=88705 Current Parameter Settings:
Sun Jun  6 08:10:25 2021 us=88888   config = '/etc/openvpn/serverlan.conf'
Sun Jun  6 08:10:25 2021 us=88924   mode = 1
Sun Jun  6 08:10:25 2021 us=88956   persist_config = DISABLED
Sun Jun  6 08:10:25 2021 us=88987   persist_mode = 1
Sun Jun  6 08:10:25 2021 us=89017   show_ciphers = DISABLED
Sun Jun  6 08:10:25 2021 us=89047   show_digests = DISABLED
Sun Jun  6 08:10:25 2021 us=89077   show_engines = DISABLED
Sun Jun  6 08:10:25 2021 us=89108   genkey = DISABLED
Sun Jun  6 08:10:25 2021 us=89138   key_pass_file = '[UNDEF]'
Sun Jun  6 08:10:25 2021 us=89168   show_tls_ciphers = DISABLED
Sun Jun  6 08:10:25 2021 us=89198   connect_retry_max = 0
Sun Jun  6 08:10:25 2021 us=89228 Connection profiles [0]:
Sun Jun  6 08:10:25 2021 us=89260   proto = udp4
Sun Jun  6 08:10:25 2021 us=89290   local = '[UNDEF]'
Sun Jun  6 08:10:25 2021 us=89319   local_port = '1195'
Sun Jun  6 08:10:25 2021 us=89349   remote = '[UNDEF]'
Sun Jun  6 08:10:25 2021 us=89379   remote_port = '1195'
Sun Jun  6 08:10:25 2021 us=89409   remote_float = DISABLED
Sun Jun  6 08:10:25 2021 us=89438   bind_defined = DISABLED
Sun Jun  6 08:10:25 2021 us=89468   bind_local = ENABLED
Sun Jun  6 08:10:25 2021 us=89499   bind_ipv6_only = DISABLED
Sun Jun  6 08:10:25 2021 us=89529   connect_retry_seconds = 5
Sun Jun  6 08:10:25 2021 us=89559   connect_timeout = 120
Sun Jun  6 08:10:25 2021 us=89588   socks_proxy_server = '[UNDEF]'
Sun Jun  6 08:10:25 2021 us=89618   socks_proxy_port = '[UNDEF]'
Sun Jun  6 08:10:25 2021 us=89649   tun_mtu = 1500
Sun Jun  6 08:10:25 2021 us=89678   tun_mtu_defined = ENABLED
Sun Jun  6 08:10:25 2021 us=89708   link_mtu = 1500
Sun Jun  6 08:10:25 2021 us=89738   link_mtu_defined = DISABLED
Sun Jun  6 08:10:25 2021 us=89768   tun_mtu_extra = 0
Sun Jun  6 08:10:25 2021 us=89797   tun_mtu_extra_defined = DISABLED
Sun Jun  6 08:10:25 2021 us=89827   mtu_discover_type = -1
Sun Jun  6 08:10:25 2021 us=89857   fragment = 0
Sun Jun  6 08:10:25 2021 us=89886   mssfix = 1450
Sun Jun  6 08:10:25 2021 us=89916   explicit_exit_notification = 1
Sun Jun  6 08:10:25 2021 us=89946 Connection profiles END
Sun Jun  6 08:10:25 2021 us=89976   remote_random = DISABLED
Sun Jun  6 08:10:25 2021 us=90006   ipchange = '[UNDEF]'
Sun Jun  6 08:10:25 2021 us=90035   dev = 'tun'
Sun Jun  6 08:10:25 2021 us=90065   dev_type = '[UNDEF]'
Sun Jun  6 08:10:25 2021 us=90095   dev_node = '[UNDEF]'
Sun Jun  6 08:10:25 2021 us=90124   lladdr = '[UNDEF]'
Sun Jun  6 08:10:25 2021 us=90154   topology = 3
Sun Jun  6 08:10:25 2021 us=90183   ifconfig_local = '10.117.2.1'
Sun Jun  6 08:10:25 2021 us=90213   ifconfig_remote_netmask = '255.255.255.0'
Sun Jun  6 08:10:25 2021 us=90244   ifconfig_noexec = DISABLED
Sun Jun  6 08:10:25 2021 us=90273   ifconfig_nowarn = DISABLED
Sun Jun  6 08:10:25 2021 us=90304   ifconfig_ipv6_local = '[UNDEF]'
Sun Jun  6 08:10:25 2021 us=90334   ifconfig_ipv6_netbits = 0
Sun Jun  6 08:10:25 2021 us=90364   ifconfig_ipv6_remote = '[UNDEF]'
Sun Jun  6 08:10:25 2021 us=90394   shaper = 0
Sun Jun  6 08:10:25 2021 us=90424   mtu_test = 0
Sun Jun  6 08:10:25 2021 us=90453   mlock = DISABLED
Sun Jun  6 08:10:25 2021 us=90484   keepalive_ping = 10
Sun Jun  6 08:10:25 2021 us=90514   keepalive_timeout = 120
Sun Jun  6 08:10:25 2021 us=90544   inactivity_timeout = 0
Sun Jun  6 08:10:25 2021 us=90574   ping_send_timeout = 10
Sun Jun  6 08:10:25 2021 us=90604   ping_rec_timeout = 240
Sun Jun  6 08:10:25 2021 us=90634   ping_rec_timeout_action = 2
Sun Jun  6 08:10:25 2021 us=90663   ping_timer_remote = DISABLED
Sun Jun  6 08:10:25 2021 us=90694   remap_sigusr1 = 0
Sun Jun  6 08:10:25 2021 us=90723   persist_tun = ENABLED
Sun Jun  6 08:10:25 2021 us=90753   persist_local_ip = DISABLED
Sun Jun  6 08:10:25 2021 us=90782   persist_remote_ip = DISABLED
Sun Jun  6 08:10:25 2021 us=90812   persist_key = ENABLED
Sun Jun  6 08:10:25 2021 us=90842   passtos = DISABLED
Sun Jun  6 08:10:25 2021 us=90872   resolve_retry_seconds = 1000000000
Sun Jun  6 08:10:25 2021 us=90902   resolve_in_advance = DISABLED
Sun Jun  6 08:10:25 2021 us=90932   username = '[UNDEF]'
Sun Jun  6 08:10:25 2021 us=90980   groupname = '[UNDEF]'
Sun Jun  6 08:10:25 2021 us=91010   chroot_dir = '[UNDEF]'
Sun Jun  6 08:10:25 2021 us=91040   cd_dir = '/etc/openvpn'
Sun Jun  6 08:10:25 2021 us=91070   writepid = '/run/openvpn/serverlan.pid'
Sun Jun  6 08:10:25 2021 us=91100   up_script = '[UNDEF]'
Sun Jun  6 08:10:25 2021 us=91129   down_script = '[UNDEF]'
Sun Jun  6 08:10:25 2021 us=91159   down_pre = DISABLED
Sun Jun  6 08:10:25 2021 us=91189   up_restart = DISABLED
Sun Jun  6 08:10:25 2021 us=91218   up_delay = DISABLED
Sun Jun  6 08:10:25 2021 us=91248   daemon = ENABLED
Sun Jun  6 08:10:25 2021 us=91278   inetd = 0
Sun Jun  6 08:10:25 2021 us=91308   log = ENABLED
Sun Jun  6 08:10:25 2021 us=91337   suppress_timestamps = DISABLED
Sun Jun  6 08:10:25 2021 us=91367   machine_readable_output = DISABLED
Sun Jun  6 08:10:25 2021 us=91397   nice = 0
Sun Jun  6 08:10:25 2021 us=91427   verbosity = 4
Sun Jun  6 08:10:25 2021 us=91456   mute = 0
Sun Jun  6 08:10:25 2021 us=91486   gremlin = 0
Sun Jun  6 08:10:25 2021 us=91516   status_file = '/etc/openvpn/log/ovpn-status_lan.log'
Sun Jun  6 08:10:25 2021 us=91546   status_file_version = 1
Sun Jun  6 08:10:25 2021 us=91576   status_file_update_freq = 10
Sun Jun  6 08:10:25 2021 us=91606   occ = ENABLED
Sun Jun  6 08:10:25 2021 us=91637   rcvbuf = 0
Sun Jun  6 08:10:25 2021 us=91666   sndbuf = 0
Sun Jun  6 08:10:25 2021 us=91696   mark = 0
Sun Jun  6 08:10:25 2021 us=91726   sockflags = 0
Sun Jun  6 08:10:25 2021 us=91756   fast_io = DISABLED
Sun Jun  6 08:10:25 2021 us=91786   comp.alg = 2
Sun Jun  6 08:10:25 2021 us=91816   comp.flags = 1
Sun Jun  6 08:10:25 2021 us=91846   route_script = '[UNDEF]'
Sun Jun  6 08:10:25 2021 us=91877   route_default_gateway = '10.117.2.2'
Sun Jun  6 08:10:25 2021 us=91907   route_default_metric = 0
Sun Jun  6 08:10:25 2021 us=91937   route_noexec = DISABLED
Sun Jun  6 08:10:25 2021 us=91967   route_delay = 0
Sun Jun  6 08:10:25 2021 us=91997   route_delay_window = 30
Sun Jun  6 08:10:25 2021 us=92027   route_delay_defined = DISABLED
Sun Jun  6 08:10:25 2021 us=92057   route_nopull = DISABLED
Sun Jun  6 08:10:25 2021 us=92087   route_gateway_via_dhcp = DISABLED
Sun Jun  6 08:10:25 2021 us=92118   allow_pull_fqdn = DISABLED
Sun Jun  6 08:10:25 2021 us=92148   management_addr = '[UNDEF]'
Sun Jun  6 08:10:25 2021 us=92178   management_port = '[UNDEF]'
Sun Jun  6 08:10:25 2021 us=92208   management_user_pass = '[UNDEF]'
Sun Jun  6 08:10:25 2021 us=92240   management_log_history_cache = 250
Sun Jun  6 08:10:25 2021 us=92271   management_echo_buffer_size = 100
Sun Jun  6 08:10:25 2021 us=92301   management_write_peer_info_file = '[UNDEF]'
Sun Jun  6 08:10:25 2021 us=92331   management_client_user = '[UNDEF]'
Sun Jun  6 08:10:25 2021 us=92362   management_client_group = '[UNDEF]'
Sun Jun  6 08:10:25 2021 us=92392   management_flags = 0
Sun Jun  6 08:10:25 2021 us=92425   shared_secret_file = '[UNDEF]'
Sun Jun  6 08:10:25 2021 us=92456   key_direction = 0
Sun Jun  6 08:10:25 2021 us=92486   ciphername = 'AES-256-CBC'
Sun Jun  6 08:10:25 2021 us=92516   ncp_enabled = ENABLED
Sun Jun  6 08:10:25 2021 us=92547   ncp_ciphers = 'AES-256-GCM:AES-128-GCM'
Sun Jun  6 08:10:25 2021 us=92577   authname = 'SHA1'
Sun Jun  6 08:10:25 2021 us=92607   prng_hash = 'SHA1'
Sun Jun  6 08:10:25 2021 us=92637   prng_nonce_secret_len = 16
Sun Jun  6 08:10:25 2021 us=92667   keysize = 0
Sun Jun  6 08:10:25 2021 us=92697   engine = DISABLED
Sun Jun  6 08:10:25 2021 us=92728   replay = ENABLED
Sun Jun  6 08:10:25 2021 us=92758   mute_replay_warnings = DISABLED
Sun Jun  6 08:10:25 2021 us=92788   replay_window = 64
Sun Jun  6 08:10:25 2021 us=92819   replay_time = 15
Sun Jun  6 08:10:25 2021 us=92849   packet_id_file = '[UNDEF]'
Sun Jun  6 08:10:25 2021 us=92879   use_iv = ENABLED
Sun Jun  6 08:10:25 2021 us=92909   test_crypto = DISABLED
Sun Jun  6 08:10:25 2021 us=92939   tls_server = ENABLED
Sun Jun  6 08:10:25 2021 us=92970   tls_client = DISABLED
Sun Jun  6 08:10:25 2021 us=93000   key_method = 2
Sun Jun  6 08:10:25 2021 us=93030   ca_file = '/etc/openvpn/keys/ca.crt'
Sun Jun  6 08:10:25 2021 us=93077   ca_path = '[UNDEF]'
Sun Jun  6 08:10:25 2021 us=93108   dh_file = '/etc/openvpn/keys/dh2048.pem'
Sun Jun  6 08:10:25 2021 us=93139   cert_file = '/etc/openvpn/keys/AGIVPN.crt'
Sun Jun  6 08:10:25 2021 us=93169   extra_certs_file = '[UNDEF]'
Sun Jun  6 08:10:25 2021 us=93200   priv_key_file = '/etc/openvpn/keys/AGIVPN.key'
Sun Jun  6 08:10:25 2021 us=93230   pkcs12_file = '[UNDEF]'
Sun Jun  6 08:10:25 2021 us=93261   cipher_list = '[UNDEF]'
Sun Jun  6 08:10:25 2021 us=93290   cipher_list_tls13 = '[UNDEF]'
Sun Jun  6 08:10:25 2021 us=93320   tls_cert_profile = '[UNDEF]'
Sun Jun  6 08:10:25 2021 us=93350   tls_verify = '[UNDEF]'
Sun Jun  6 08:10:25 2021 us=93380   tls_export_cert = '[UNDEF]'
Sun Jun  6 08:10:25 2021 us=93411   verify_x509_type = 0
Sun Jun  6 08:10:25 2021 us=93441   verify_x509_name = '[UNDEF]'
Sun Jun  6 08:10:25 2021 us=93471   crl_file = '[UNDEF]'
Sun Jun  6 08:10:25 2021 us=93502   ns_cert_type = 0
Sun Jun  6 08:10:25 2021 us=93532   remote_cert_ku[i] = 0
Sun Jun  6 08:10:25 2021 us=93562   remote_cert_ku[i] = 0
Sun Jun  6 08:10:25 2021 us=93592   remote_cert_ku[i] = 0
Sun Jun  6 08:10:25 2021 us=93622   remote_cert_ku[i] = 0
Sun Jun  6 08:10:25 2021 us=93652   remote_cert_ku[i] = 0
Sun Jun  6 08:10:25 2021 us=93682   remote_cert_ku[i] = 0
Sun Jun  6 08:10:25 2021 us=93712   remote_cert_ku[i] = 0
Sun Jun  6 08:10:25 2021 us=93743   remote_cert_ku[i] = 0
Sun Jun  6 08:10:25 2021 us=93772   remote_cert_ku[i] = 0
Sun Jun  6 08:10:25 2021 us=93803   remote_cert_ku[i] = 0
Sun Jun  6 08:10:25 2021 us=93833   remote_cert_ku[i] = 0
Sun Jun  6 08:10:25 2021 us=93863   remote_cert_ku[i] = 0
Sun Jun  6 08:10:25 2021 us=93893   remote_cert_ku[i] = 0
Sun Jun  6 08:10:25 2021 us=93923   remote_cert_ku[i] = 0
Sun Jun  6 08:10:25 2021 us=93953   remote_cert_ku[i] = 0
Sun Jun  6 08:10:25 2021 us=93983   remote_cert_ku[i] = 0
Sun Jun  6 08:10:25 2021 us=94013   remote_cert_eku = '[UNDEF]'
Sun Jun  6 08:10:25 2021 us=94044   ssl_flags = 0
Sun Jun  6 08:10:25 2021 us=94075   tls_timeout = 2
Sun Jun  6 08:10:25 2021 us=94105   renegotiate_bytes = -1
Sun Jun  6 08:10:25 2021 us=94135   renegotiate_packets = 0
Sun Jun  6 08:10:25 2021 us=94165   renegotiate_seconds = 3600
Sun Jun  6 08:10:25 2021 us=94195   handshake_window = 60
Sun Jun  6 08:10:25 2021 us=94225   transition_window = 3600
Sun Jun  6 08:10:25 2021 us=94327   single_session = DISABLED
Sun Jun  6 08:10:25 2021 us=94357   push_peer_info = DISABLED
Sun Jun  6 08:10:25 2021 us=94388   tls_exit = DISABLED
Sun Jun  6 08:10:25 2021 us=94419   tls_auth_file = '/etc/openvpn/keys/ta.key'
Sun Jun  6 08:10:25 2021 us=94449   tls_crypt_file = '[UNDEF]'
Sun Jun  6 08:10:25 2021 us=94480   pkcs11_protected_authentication = DISABLED
Sun Jun  6 08:10:25 2021 us=94511   pkcs11_protected_authentication = DISABLED
Sun Jun  6 08:10:25 2021 us=94541   pkcs11_protected_authentication = DISABLED
Sun Jun  6 08:10:25 2021 us=94571   pkcs11_protected_authentication = DISABLED
Sun Jun  6 08:10:25 2021 us=94602   pkcs11_protected_authentication = DISABLED
Sun Jun  6 08:10:25 2021 us=94632   pkcs11_protected_authentication = DISABLED
Sun Jun  6 08:10:25 2021 us=94662   pkcs11_protected_authentication = DISABLED
Sun Jun  6 08:10:25 2021 us=94693   pkcs11_protected_authentication = DISABLED
Sun Jun  6 08:10:25 2021 us=94723   pkcs11_protected_authentication = DISABLED
Sun Jun  6 08:10:25 2021 us=94754   pkcs11_protected_authentication = DISABLED
Sun Jun  6 08:10:25 2021 us=94784   pkcs11_protected_authentication = DISABLED
Sun Jun  6 08:10:25 2021 us=94815   pkcs11_protected_authentication = DISABLED
Sun Jun  6 08:10:25 2021 us=94845   pkcs11_protected_authentication = DISABLED
Sun Jun  6 08:10:25 2021 us=94876   pkcs11_protected_authentication = DISABLED
Sun Jun  6 08:10:25 2021 us=94906   pkcs11_protected_authentication = DISABLED
Sun Jun  6 08:10:25 2021 us=94936   pkcs11_protected_authentication = DISABLED
Sun Jun  6 08:10:25 2021 us=94968   pkcs11_private_mode = 00000000
Sun Jun  6 08:10:25 2021 us=94999   pkcs11_private_mode = 00000000
Sun Jun  6 08:10:25 2021 us=95048   pkcs11_private_mode = 00000000
Sun Jun  6 08:10:25 2021 us=95079   pkcs11_private_mode = 00000000
Sun Jun  6 08:10:25 2021 us=95110   pkcs11_private_mode = 00000000
Sun Jun  6 08:10:25 2021 us=95141   pkcs11_private_mode = 00000000
Sun Jun  6 08:10:25 2021 us=95172   pkcs11_private_mode = 00000000
Sun Jun  6 08:10:25 2021 us=95202   pkcs11_private_mode = 00000000
Sun Jun  6 08:10:25 2021 us=95233   pkcs11_private_mode = 00000000
Sun Jun  6 08:10:25 2021 us=95263   pkcs11_private_mode = 00000000
Sun Jun  6 08:10:25 2021 us=95294   pkcs11_private_mode = 00000000
Sun Jun  6 08:10:25 2021 us=95325   pkcs11_private_mode = 00000000
Sun Jun  6 08:10:25 2021 us=95355   pkcs11_private_mode = 00000000
Sun Jun  6 08:10:25 2021 us=95386   pkcs11_private_mode = 00000000
Sun Jun  6 08:10:25 2021 us=95416   pkcs11_private_mode = 00000000
Sun Jun  6 08:10:25 2021 us=95447   pkcs11_private_mode = 00000000
Sun Jun  6 08:10:25 2021 us=95477   pkcs11_cert_private = DISABLED
Sun Jun  6 08:10:25 2021 us=95508   pkcs11_cert_private = DISABLED
Sun Jun  6 08:10:25 2021 us=95538   pkcs11_cert_private = DISABLED
Sun Jun  6 08:10:25 2021 us=95568   pkcs11_cert_private = DISABLED
Sun Jun  6 08:10:25 2021 us=95598   pkcs11_cert_private = DISABLED
Sun Jun  6 08:10:25 2021 us=95628   pkcs11_cert_private = DISABLED
Sun Jun  6 08:10:25 2021 us=95658   pkcs11_cert_private = DISABLED
Sun Jun  6 08:10:25 2021 us=95688   pkcs11_cert_private = DISABLED
Sun Jun  6 08:10:25 2021 us=95718   pkcs11_cert_private = DISABLED
Sun Jun  6 08:10:25 2021 us=95748   pkcs11_cert_private = DISABLED
Sun Jun  6 08:10:25 2021 us=95778   pkcs11_cert_private = DISABLED
Sun Jun  6 08:10:25 2021 us=95807   pkcs11_cert_private = DISABLED
Sun Jun  6 08:10:25 2021 us=95837   pkcs11_cert_private = DISABLED
Sun Jun  6 08:10:25 2021 us=95868   pkcs11_cert_private = DISABLED
Sun Jun  6 08:10:25 2021 us=95898   pkcs11_cert_private = DISABLED
Sun Jun  6 08:10:25 2021 us=95928   pkcs11_cert_private = DISABLED
Sun Jun  6 08:10:25 2021 us=95958   pkcs11_pin_cache_period = -1
Sun Jun  6 08:10:25 2021 us=95989   pkcs11_id = '[UNDEF]'
Sun Jun  6 08:10:25 2021 us=96019   pkcs11_id_management = DISABLED
Sun Jun  6 08:10:25 2021 us=96053   server_network = 10.117.2.0
Sun Jun  6 08:10:25 2021 us=96086   server_netmask = 255.255.255.0
Sun Jun  6 08:10:25 2021 us=96120   server_network_ipv6 = ::
Sun Jun  6 08:10:25 2021 us=96151   server_netbits_ipv6 = 0
Sun Jun  6 08:10:25 2021 us=96183   server_bridge_ip = 0.0.0.0
Sun Jun  6 08:10:25 2021 us=96216   server_bridge_netmask = 0.0.0.0
Sun Jun  6 08:10:25 2021 us=96249   server_bridge_pool_start = 0.0.0.0
Sun Jun  6 08:10:25 2021 us=96282   server_bridge_pool_end = 0.0.0.0
Sun Jun  6 08:10:25 2021 us=96312   push_entry = 'route 192.168.117.0 255.255.255.0'
Sun Jun  6 08:10:25 2021 us=96343   push_entry = 'dhcp-option DNS 192.168.117.1'
Sun Jun  6 08:10:25 2021 us=96373   push_entry = 'dhcp-option DNS 208.67.220.220'
Sun Jun  6 08:10:25 2021 us=96404   push_entry = 'route-gateway 10.117.2.1'
Sun Jun  6 08:10:25 2021 us=96434   push_entry = 'topology subnet'
Sun Jun  6 08:10:25 2021 us=96463   push_entry = 'ping 10'
Sun Jun  6 08:10:25 2021 us=96494   push_entry = 'ping-restart 120'
Sun Jun  6 08:10:25 2021 us=96524   ifconfig_pool_defined = ENABLED
Sun Jun  6 08:10:25 2021 us=96563   ifconfig_pool_start = 10.117.2.2
Sun Jun  6 08:10:25 2021 us=96597   ifconfig_pool_end = 10.117.2.127
Sun Jun  6 08:10:25 2021 us=96631   ifconfig_pool_netmask = 255.255.255.0
Sun Jun  6 08:10:25 2021 us=96661   ifconfig_pool_persist_filename = 'ipplan.txt'
Sun Jun  6 08:10:25 2021 us=96692   ifconfig_pool_persist_refresh_freq = 600
Sun Jun  6 08:10:25 2021 us=96722   ifconfig_ipv6_pool_defined = DISABLED
Sun Jun  6 08:10:25 2021 us=96754   ifconfig_ipv6_pool_base = ::
Sun Jun  6 08:10:25 2021 us=96785   ifconfig_ipv6_pool_netbits = 0
Sun Jun  6 08:10:25 2021 us=96815   n_bcast_buf = 256
Sun Jun  6 08:10:25 2021 us=96846   tcp_queue_limit = 64
Sun Jun  6 08:10:25 2021 us=96876   real_hash_size = 256
Sun Jun  6 08:10:25 2021 us=96906   virtual_hash_size = 256
Sun Jun  6 08:10:25 2021 us=96952   client_connect_script = '[UNDEF]'
Sun Jun  6 08:10:25 2021 us=96983   learn_address_script = '[UNDEF]'
Sun Jun  6 08:10:25 2021 us=97014   client_disconnect_script = '[UNDEF]'
Sun Jun  6 08:10:25 2021 us=97045   client_config_dir = '/etc/openvpn/ccdlan'
Sun Jun  6 08:10:25 2021 us=97076   ccd_exclusive = DISABLED
Sun Jun  6 08:10:25 2021 us=97106   tmp_dir = '/tmp'
Sun Jun  6 08:10:25 2021 us=97137   push_ifconfig_defined = DISABLED
Sun Jun  6 08:10:25 2021 us=97170   push_ifconfig_local = 0.0.0.0
Sun Jun  6 08:10:25 2021 us=97203   push_ifconfig_remote_netmask = 0.0.0.0
Sun Jun  6 08:10:25 2021 us=97233   push_ifconfig_ipv6_defined = DISABLED
Sun Jun  6 08:10:25 2021 us=97267   push_ifconfig_ipv6_local = ::/0
Sun Jun  6 08:10:25 2021 us=97300   push_ifconfig_ipv6_remote = ::
Sun Jun  6 08:10:25 2021 us=97331   enable_c2c = ENABLED
Sun Jun  6 08:10:25 2021 us=97360   duplicate_cn = DISABLED
Sun Jun  6 08:10:25 2021 us=97391   cf_max = 0
Sun Jun  6 08:10:25 2021 us=97421   cf_per = 0
Sun Jun  6 08:10:25 2021 us=97451   max_clients = 20
Sun Jun  6 08:10:25 2021 us=97481   max_routes_per_client = 256
Sun Jun  6 08:10:25 2021 us=97512   auth_user_pass_verify_script = '[UNDEF]'
Sun Jun  6 08:10:25 2021 us=97543   auth_user_pass_verify_script_via_file = DISABLED
Sun Jun  6 08:10:25 2021 us=97573   auth_token_generate = DISABLED
Sun Jun  6 08:10:25 2021 us=97603   auth_token_lifetime = 0
Sun Jun  6 08:10:25 2021 us=97633   port_share_host = '[UNDEF]'
Sun Jun  6 08:10:25 2021 us=97663   port_share_port = '[UNDEF]'
Sun Jun  6 08:10:25 2021 us=97693   client = DISABLED
Sun Jun  6 08:10:25 2021 us=97724   pull = DISABLED
Sun Jun  6 08:10:25 2021 us=97754   auth_user_pass_file = '[UNDEF]'
Sun Jun  6 08:10:25 2021 us=97789 OpenVPN 2.4.7 arm-unknown-linux-gnueabihf [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [PKCS11] [MH/PKTINFO] [AEAD] built on Feb 20 2019
Sun Jun  6 08:10:25 2021 us=97835 library versions: OpenSSL 1.1.1d  10 Sep 2019, LZO 2.10
Sun Jun  6 08:10:25 2021 us=99957 Diffie-Hellman initialized with 2048 bit key
Sun Jun  6 08:10:25 2021 us=102855 Outgoing Control Channel Authentication: Using 160 bit message hash 'SHA1' for HMAC authentication
Sun Jun  6 08:10:25 2021 us=103007 Incoming Control Channel Authentication: Using 160 bit message hash 'SHA1' for HMAC authentication
Sun Jun  6 08:10:25 2021 us=103065 TLS-Auth MTU parms [ L:1622 D:1184 EF:66 EB:0 ET:0 EL:3 ]
Sun Jun  6 08:10:25 2021 us=105561 TUN/TAP device tun1 opened
Sun Jun  6 08:10:25 2021 us=106089 TUN/TAP TX queue length set to 100
Sun Jun  6 08:10:25 2021 us=106235 do_ifconfig, tt->did_ifconfig_ipv6_setup=0
Sun Jun  6 08:10:25 2021 us=106309 /sbin/ip link set dev tun1 up mtu 1500
Sun Jun  6 08:10:25 2021 us=113355 /sbin/ip addr add dev tun1 10.117.2.1/24 broadcast 10.117.2.255
Sun Jun  6 08:10:25 2021 us=121110 Data Channel MTU parms [ L:1622 D:1450 EF:122 EB:406 ET:0 EL:3 ]
Sun Jun  6 08:10:25 2021 us=121329 Socket Buffers: R=[180224->180224] S=[180224->180224]
Sun Jun  6 08:10:25 2021 us=121402 UDPv4 link local (bound): [AF_INET][undef]:1195
Sun Jun  6 08:10:25 2021 us=121436 UDPv4 link remote: [AF_UNSPEC]
Sun Jun  6 08:10:25 2021 us=121492 MULTI: multi_init called, r=256 v=256
Sun Jun  6 08:10:25 2021 us=121591 IFCONFIG POOL: base=10.117.2.2 size=126, ipv6=0
Sun Jun  6 08:10:25 2021 us=121644 ifconfig_pool_read(), in='SSRClient001,10.117.2.2', TODO: IPv6
Sun Jun  6 08:10:25 2021 us=121690 succeeded -> ifconfig_pool_set()
Sun Jun  6 08:10:25 2021 us=121727 IFCONFIG POOL LIST
Sun Jun  6 08:10:25 2021 us=121761 SSRClient001,10.117.2.2
Sun Jun  6 08:10:25 2021 us=121971 Initialization Sequence Completed
5) Now I successfully connected to the server from my Windows10 laptop and this is the server side log until it is idle:

Code: Select all

Sun Jun  6 08:18:59 2021 us=916694 MULTI: multi_create_instance called
Sun Jun  6 08:18:59 2021 us=917102 158.174.104.130:59504 Re-using SSL/TLS context
Sun Jun  6 08:18:59 2021 us=917201 158.174.104.130:59504 LZO compression initializing
Sun Jun  6 08:18:59 2021 us=917814 158.174.104.130:59504 Control Channel MTU parms [ L:1622 D:1184 EF:66 EB:0 ET:0 EL:3 ]
Sun Jun  6 08:18:59 2021 us=917910 158.174.104.130:59504 Data Channel MTU parms [ L:1622 D:1450 EF:122 EB:406 ET:0 EL:3 ]
Sun Jun  6 08:18:59 2021 us=918213 158.174.104.130:59504 Local Options String (VER=V4): 'V4,dev-type tun,link-mtu 1558,tun-mtu 1500,proto UDPv4,comp-lzo,keydir 0,cipher AES-256-CBC,auth SHA1,keysize 256,tls-auth,key-method 2,tls-server'
Sun Jun  6 08:18:59 2021 us=918286 158.174.104.130:59504 Expected Remote Options String (VER=V4): 'V4,dev-type tun,link-mtu 1558,tun-mtu 1500,proto UDPv4,comp-lzo,keydir 1,cipher AES-256-CBC,auth SHA1,keysize 256,tls-auth,key-method 2,tls-client'
Sun Jun  6 08:18:59 2021 us=918447 158.174.104.130:59504 TLS: Initial packet from [AF_INET]158.174.104.130:59504, sid=2a3f4590 b7f048e6
---------------- Here the TLS check succeeds instantly! --------------------
Sun Jun  6 08:19:00 2021 us=68411 158.174.104.130:59504 VERIFY OK: depth=1, C=US, ST=TX, L=Austin, O=companyname, OU=IT, CN=AGIVPN, name=AGIVPN, emailAddress=xxxx@yyyy.com
Sun Jun  6 08:19:00 2021 us=69552 158.174.104.130:59504 VERIFY OK: depth=0, C=US, ST=TX, L=Austin, O=companyname, OU=IT, CN=SSRClient001, name=changeme, emailAddress=xxxx@yyyy.com
Sun Jun  6 08:19:00 2021 us=106659 158.174.104.130:59504 peer info: IV_VER=2.4.8
Sun Jun  6 08:19:00 2021 us=106808 158.174.104.130:59504 peer info: IV_PLAT=win
Sun Jun  6 08:19:00 2021 us=106863 158.174.104.130:59504 peer info: IV_PROTO=2
Sun Jun  6 08:19:00 2021 us=106912 158.174.104.130:59504 peer info: IV_NCP=2
Sun Jun  6 08:19:00 2021 us=106960 158.174.104.130:59504 peer info: IV_LZ4=1
Sun Jun  6 08:19:00 2021 us=107009 158.174.104.130:59504 peer info: IV_LZ4v2=1
Sun Jun  6 08:19:00 2021 us=107058 158.174.104.130:59504 peer info: IV_LZO=1
Sun Jun  6 08:19:00 2021 us=107107 158.174.104.130:59504 peer info: IV_COMP_STUB=1
Sun Jun  6 08:19:00 2021 us=107156 158.174.104.130:59504 peer info: IV_COMP_STUBv2=1
Sun Jun  6 08:19:00 2021 us=107204 158.174.104.130:59504 peer info: IV_TCPNL=1
Sun Jun  6 08:19:00 2021 us=107254 158.174.104.130:59504 peer info: IV_GUI_VER=OpenVPN_GUI_11
Sun Jun  6 08:19:00 2021 us=145309 158.174.104.130:59504 Control Channel: TLSv1.2, cipher TLSv1.2 ECDHE-RSA-AES256-GCM-SHA384, 2048 bit RSA
Sun Jun  6 08:19:00 2021 us=145481 158.174.104.130:59504 [SSRClient001] Peer Connection Initiated with [AF_INET]158.174.104.130:59504
Sun Jun  6 08:19:00 2021 us=145755 SSRClient001/158.174.104.130:59504 MULTI_sva: pool returned IPv4=10.117.2.2, IPv6=(Not enabled)
Sun Jun  6 08:19:00 2021 us=146015 SSRClient001/158.174.104.130:59504 MULTI: Learn: 10.117.2.2 -> SSRClient001/158.174.104.130:59504
Sun Jun  6 08:19:00 2021 us=146093 SSRClient001/158.174.104.130:59504 MULTI: primary virtual IP for SSRClient001/158.174.104.130:59504: 10.117.2.2
Sun Jun  6 08:19:01 2021 us=336632 SSRClient001/158.174.104.130:59504 PUSH: Received control message: 'PUSH_REQUEST'
Sun Jun  6 08:19:01 2021 us=337012 SSRClient001/158.174.104.130:59504 SENT CONTROL [SSRClient001]: 'PUSH_REPLY,route 192.168.117.0 255.255.255.0,dhcp-option DNS 192.168.117.1,dhcp-option DNS 208.67.220.220,route-gateway 10.117.2.1,topology subnet,ping 10,ping-restart 120,ifconfig 10.117.2.2 255.255.255.0,peer-id 0,cipher AES-256-GCM' (status=1)
Sun Jun  6 08:19:01 2021 us=337099 SSRClient001/158.174.104.130:59504 Data Channel: using negotiated cipher 'AES-256-GCM'
Sun Jun  6 08:19:01 2021 us=337227 SSRClient001/158.174.104.130:59504 Data Channel MTU parms [ L:1550 D:1450 EF:50 EB:406 ET:0 EL:3 ]
Sun Jun  6 08:19:01 2021 us=337931 SSRClient001/158.174.104.130:59504 Outgoing Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
Sun Jun  6 08:19:01 2021 us=338026 SSRClient001/158.174.104.130:59504 Incoming Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
Sun Jun  6 08:19:01 2021 us=822461 SSRClient001/158.174.104.130:59504 MULTI: bad source address from client [::], packet dropped
6) At this point I can reach the LAN and communicate with other devices there.

7) Now I try to connect from the RPi device, which fails with the following printed to the command window on the client RPi:

Code: Select all

Sun Jun  6 08:21:58 2021 us=643040 Current Parameter Settings:
Sun Jun  6 08:21:58 2021 us=643290   config = '/home/pi/openvpn/SSRemote001.ovpn'
Sun Jun  6 08:21:58 2021 us=643423   mode = 0
Sun Jun  6 08:21:58 2021 us=643526   persist_config = DISABLED
Sun Jun  6 08:21:58 2021 us=643624   persist_mode = 1
Sun Jun  6 08:21:58 2021 us=643722   show_ciphers = DISABLED
Sun Jun  6 08:21:58 2021 us=643818   show_digests = DISABLED
Sun Jun  6 08:21:58 2021 us=643914   show_engines = DISABLED
Sun Jun  6 08:21:58 2021 us=644009   genkey = DISABLED
Sun Jun  6 08:21:58 2021 us=644105   key_pass_file = '[UNDEF]'
Sun Jun  6 08:21:58 2021 us=644201   show_tls_ciphers = DISABLED
Sun Jun  6 08:21:58 2021 us=644299   connect_retry_max = 0
Sun Jun  6 08:21:58 2021 us=644396 Connection profiles [0]:
Sun Jun  6 08:21:58 2021 us=644495   proto = udp
Sun Jun  6 08:21:58 2021 us=644590   local = '[UNDEF]'
Sun Jun  6 08:21:58 2021 us=644685   local_port = '[UNDEF]'
Sun Jun  6 08:21:58 2021 us=644779   remote = 'aspo.boberglund.com'
Sun Jun  6 08:21:58 2021 us=644874   remote_port = '1192'
Sun Jun  6 08:21:58 2021 us=644969   remote_float = DISABLED
Sun Jun  6 08:21:58 2021 us=645064   bind_defined = DISABLED
Sun Jun  6 08:21:58 2021 us=645159 NOTE: --mute triggered...
Sun Jun  6 08:21:58 2021 us=645270 262 variation(s) on previous 20 message(s) suppressed by --mute
Sun Jun  6 08:21:58 2021 us=645371 OpenVPN 2.4.7 arm-unknown-linux-gnueabihf [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [PKCS11] [MH/PKTINFO] [AEAD] built on Feb 20 2019
Sun Jun  6 08:21:58 2021 us=645493 library versions: OpenSSL 1.1.1d  10 Sep 2019, LZO 2.10
Sun Jun  6 08:21:58 2021 us=648435 Outgoing Control Channel Authentication: Using 160 bit message hash 'SHA1' for HMAC authentication
Sun Jun  6 08:21:58 2021 us=648595 Incoming Control Channel Authentication: Using 160 bit message hash 'SHA1' for HMAC authentication
Sun Jun  6 08:21:58 2021 us=648704 LZO compression initializing
Sun Jun  6 08:21:58 2021 us=649268 Control Channel MTU parms [ L:1622 D:1184 EF:66 EB:0 ET:0 EL:3 ]
Sun Jun  6 08:21:58 2021 us=665066 Data Channel MTU parms [ L:1622 D:1450 EF:122 EB:406 ET:0 EL:3 ]
Sun Jun  6 08:21:58 2021 us=665296 Local Options String (VER=V4): 'V4,dev-type tun,link-mtu 1558,tun-mtu 1500,proto UDPv4,comp-lzo,keydir 1,cipher AES-256-CBC,auth SHA1,keysize 256,tls-auth,key-method 2,tls-client'
Sun Jun  6 08:21:58 2021 us=665401 Expected Remote Options String (VER=V4): 'V4,dev-type tun,link-mtu 1558,tun-mtu 1500,proto UDPv4,comp-lzo,keydir 0,cipher AES-256-CBC,auth SHA1,keysize 256,tls-auth,key-method 2,tls-server'
Sun Jun  6 08:21:58 2021 us=665533 TCP/UDP: Preserving recently used remote address: [AF_INET]95.192.35.35:1192
Sun Jun  6 08:21:58 2021 us=665661 Socket Buffers: R=[180224->180224] S=[180224->180224]
Sun Jun  6 08:21:58 2021 us=665769 UDP link local: (not bound)
Sun Jun  6 08:21:58 2021 us=665873 UDP link remote: [AF_INET]95.192.35.35:1192
------- Here the check should be instant but instead TLS fails!  ------------
Sun Jun  6 08:22:58 2021 us=281691 TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity)
Sun Jun  6 08:22:58 2021 us=281825 TLS Error: TLS handshake failed
Sun Jun  6 08:22:58 2021 us=282213 TCP/UDP: Closing socket
Sun Jun  6 08:22:58 2021 us=282367 SIGUSR1[soft,tls-error] received, process restarting
Sun Jun  6 08:22:58 2021 us=282488 Restart pause, 5 second(s)
Sun Jun  6 08:23:03 2021 us=282676 Re-using SSL/TLS context
Sun Jun  6 08:23:03 2021 us=282814 LZO compression initializing
Sun Jun  6 08:23:03 2021 us=283146 Control Channel MTU parms [ L:1622 D:1184 EF:66 EB:0 ET:0 EL:3 ]
Sun Jun  6 08:23:03 2021 us=284203 Data Channel MTU parms [ L:1622 D:1450 EF:122 EB:406 ET:0 EL:3 ]
Sun Jun  6 08:23:03 2021 us=284393 Local Options String (VER=V4): 'V4,dev-type tun,link-mtu 1558,tun-mtu 1500,proto UDPv4,comp-lzo,keydir 1,cipher AES-256-CBC,auth SHA1,keysize 256,tls-auth,key-method 2,tls-client'
Sun Jun  6 08:23:03 2021 us=284477 Expected Remote Options String (VER=V4): 'V4,dev-type tun,link-mtu 1558,tun-mtu 1500,proto UDPv4,comp-lzo,keydir 0,cipher AES-256-CBC,auth SHA1,keysize 256,tls-auth,key-method 2,tls-server'
Sun Jun  6 08:23:03 2021 us=284561 TCP/UDP: Preserving recently used remote address: [AF_INET]95.192.35.35:1192
Sun Jun  6 08:23:03 2021 us=284670 Socket Buffers: R=[180224->180224] S=[180224->180224]
Sun Jun  6 08:23:03 2021 us=284740 UDP link local: (not bound)
Sun Jun  6 08:23:03 2021 us=284820 UDP link remote: [AF_INET]95.192.35.35:1192
^CSun Jun  6 08:23:59 2021 us=643303 event_wait : Interrupted system call (code=4)
Sun Jun  6 08:23:59 2021 us=643427 SIGTERM received, sending exit notification to peer
Sun Jun  6 08:24:00 2021 us=850552 TCP/UDP: Closing socket
Sun Jun  6 08:24:00 2021 us=850752 SIGTERM[soft,exit-with-notification] received, process exiting
[/olog]
At 08:23:59 I stopped the connection attempt using Ctrl-C in the RPi terminal window.

The server side log for this connection attempt:
[olog]
Sun Jun  6 08:21:58 2021 us=687022 MULTI: multi_create_instance called
Sun Jun  6 08:21:58 2021 us=687402 158.174.104.130:57305 Re-using SSL/TLS context
Sun Jun  6 08:21:58 2021 us=687496 158.174.104.130:57305 LZO compression initializing
Sun Jun  6 08:21:58 2021 us=688016 158.174.104.130:57305 Control Channel MTU parms [ L:1622 D:1184 EF:66 EB:0 ET:0 EL:3 ]
Sun Jun  6 08:21:58 2021 us=688177 158.174.104.130:57305 Data Channel MTU parms [ L:1622 D:1450 EF:122 EB:406 ET:0 EL:3 ]
Sun Jun  6 08:21:58 2021 us=688420 158.174.104.130:57305 Local Options String (VER=V4): 'V4,dev-type tun,link-mtu 1558,tun-mtu 1500,proto UDPv4,comp-lzo,keydir 0,cipher AES-256-CBC,auth SHA1,keysize 256,tls-auth,key-method 2,tls-server'
Sun Jun  6 08:21:58 2021 us=688494 158.174.104.130:57305 Expected Remote Options String (VER=V4): 'V4,dev-type tun,link-mtu 1558,tun-mtu 1500,proto UDPv4,comp-lzo,keydir 1,cipher AES-256-CBC,auth SHA1,keysize 256,tls-auth,key-method 2,tls-client'
Sun Jun  6 08:21:58 2021 us=688663 158.174.104.130:57305 TLS: Initial packet from [AF_INET]158.174.104.130:57305, sid=ae4603f0 855964ef
Sun Jun  6 08:22:58 2021 us=276075 158.174.104.130:57305 TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity)
Sun Jun  6 08:22:58 2021 us=276321 158.174.104.130:57305 TLS Error: TLS handshake failed
Sun Jun  6 08:22:58 2021 us=276715 158.174.104.130:57305 SIGUSR1[soft,tls-error] received, client-instance restarting
Sun Jun  6 08:23:03 2021 us=544062 MULTI: multi_create_instance called
Sun Jun  6 08:23:03 2021 us=544554 158.174.104.130:38306 Re-using SSL/TLS context
Sun Jun  6 08:23:03 2021 us=544686 158.174.104.130:38306 LZO compression initializing
Sun Jun  6 08:23:03 2021 us=545093 158.174.104.130:38306 Control Channel MTU parms [ L:1622 D:1184 EF:66 EB:0 ET:0 EL:3 ]
Sun Jun  6 08:23:03 2021 us=545199 158.174.104.130:38306 Data Channel MTU parms [ L:1622 D:1450 EF:122 EB:406 ET:0 EL:3 ]
Sun Jun  6 08:23:03 2021 us=545453 158.174.104.130:38306 Local Options String (VER=V4): 'V4,dev-type tun,link-mtu 1558,tun-mtu 1500,proto UDPv4,comp-lzo,keydir 0,cipher AES-256-CBC,auth SHA1,keysize 256,tls-auth,key-method 2,tls-server'
Sun Jun  6 08:23:03 2021 us=545535 158.174.104.130:38306 Expected Remote Options String (VER=V4): 'V4,dev-type tun,link-mtu 1558,tun-mtu 1500,proto UDPv4,comp-lzo,keydir 1,cipher AES-256-CBC,auth SHA1,keysize 256,tls-auth,key-method 2,tls-client'
Sun Jun  6 08:23:03 2021 us=545714 158.174.104.130:38306 TLS: Initial packet from [AF_INET]158.174.104.130:38306, sid=79a41040 8755de0f
--------------------RPi3 client connection aborted 08:24:00, but no server log entry! ---------------
Sun Jun  6 08:24:03 2021 us=225425 158.174.104.130:38306 TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity)
Sun Jun  6 08:24:03 2021 us=225696 158.174.104.130:38306 TLS Error: TLS handshake failed
Sun Jun  6 08:24:03 2021 us=226124 158.174.104.130:38306 SIGUSR1[soft,tls-error] received, client-instance restarting
8) At this point the Windows client still has full connectivity to the remote LAN.

9) Now I shut down the Windows client too and retrieved the logs...

Notice that if I reverse the connection sequence so I connect the RPi first, then it connects fine and can talk to devices on the remote LAN, but now the Windows client fails to connect instead!

And after a session like this all connection attempts fail until some time has passed (yet unknown) when it is all at some original state again and I can repeat the above.

This has been a big surprise since I have installed so many OVPN servers before without any of these problems.
Here is the version of openvpn on the server RPi3B+:

Code: Select all

$ openvpn --version
OpenVPN 2.4.7 arm-unknown-linux-gnueabihf [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [PKCS11] [MH/PKTINFO] [AEAD] built on Feb 20 2019
library versions: OpenSSL 1.1.1d  10 Sep 2019, LZO 2.10
PS:
I tried to use the olog tag to format the log outputs but apparently the forum does not actually recognize this tag even though it is available in the format bar, only normal text was produced so I had to switch to code instead....
DS

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

Re: New server on RPi3 only allows one connection....

Post by TinCanTech » Sun Jun 06, 2021 12:59 pm

BobAGI wrote:
Sun Jun 06, 2021 9:55 am
I tried to use the olog tag to format the log outputs but apparently the forum does not actually recognize this tag
The way to use it is like this (Code tag used to display required code):

Code: Select all

[oconf="client config"]
client

etc ..

<ca>

-----BEGIN CERTIFICATE-----
MIIDPzCCAiegAwIBAgIULCWzZ9AFxMXxXjG75G4PQiMsUa0wDQYJKoZIhvcNAQEL
BQAwEjEQMA4GA1UEAwwHZWFzeXRsczAeFw0yMTA2MDQxNDUzMzFaFw0zMTA2MDIx
NDUzMzFaMBIxEDAOBgNVBAMMB2Vhc3l0bHMwggEiMA0GCSqGSIb3DQEBAQUAA4IB
DwAwggEKAoIBAQC6IUdXuaD71KPxtOQFxbk23P+usU+335IasETvmHvEdgRKfAki
0wyLQhDyhwuEy7lQRsqj8j6iD35oIMOeYny4W2YoUNCsec9M0SA4rD3iSaR9iYzS
1ezMrItcG0fLkuQOgUfauhB58R5uoBHlXmUqzF5MnDu1EzFkD5cZ7FJxUrgPjMEX
CIKQx42BJuWkiNUyh8z+/rbgEyAapfClJcvwzDOTx6k7aLtFtzUQ5kqa+eOpDH9x
NkSxkX9V7EA+iaRs0DbqQE5fRfpJFiC5TyUgaNQEBkxcbtUcDtuhvO6wUWh8+hY4
iTJKnWP+usDkdxNaIx5BDDAFCa+Kdnf4CaaxAgMBAAGjgYwwgYkwHQYDVR0OBBYE
FGUpQHjP2JP+OjZltr8WkgVigVI+ME0GA1UdIwRGMESAFGUpQHjP2JP+OjZltr8W
kgVigVI+oRakFDASMRAwDgYDVQQDDAdlYXN5dGxzghQsJbNn0AXExfFeMbvkbg9C
IyxRrTAMBgNVHRMEBTADAQH/MAsGA1UdDwQEAwIBBjANBgkqhkiG9w0BAQsFAAOC
AQEARlUqt2CZiPQ1OvfqLsWFuqpNLb8hm9vRdbtG/N/bOJhOjz7sknk3u674q7wQ
m9aYsxtpTOlUq2jgWf9iIZSd6PKpLQs0MegmPBAXawVkGCoGxLB5YTnziWbzanUU
ZV6+ykEDIz7910ZYIbKYwwEdgGu4XyB2JNZzNvcfkLmjcihuafdq2LKr0Ve/RRR/
HHTidyPq039wcWmxXKOagXtgjuAjI03sbqBI9bI3PXbUxDYiIC8u6dRvglfPbim3
LT/08AsbtTIsBHDV+fHEwI/1z5m9JkxYB0Ci+MCMP/7zXSIbpuDzKqHJakJh9g1M
4j/9msySPPoMid95jgOW2eJbYA==
-----END CERTIFICATE-----

</ca>

[/oconf]
client config

client
nobind

etc ..

<ca>

-----BEGIN CERTIFICATE-----
MIIDPzCCAiegAwIBAgIULCWzZ9AFxMXxXjG75G4PQiMsUa0wDQYJKoZIhvcNAQEL
BQAwEjEQMA4GA1UEAwwHZWFzeXRsczAeFw0yMTA2MDQxNDUzMzFaFw0zMTA2MDIx
NDUzMzFaMBIxEDAOBgNVBAMMB2Vhc3l0bHMwggEiMA0GCSqGSIb3DQEBAQUAA4IB
DwAwggEKAoIBAQC6IUdXuaD71KPxtOQFxbk23P+usU+335IasETvmHvEdgRKfAki
0wyLQhDyhwuEy7lQRsqj8j6iD35oIMOeYny4W2YoUNCsec9M0SA4rD3iSaR9iYzS
1ezMrItcG0fLkuQOgUfauhB58R5uoBHlXmUqzF5MnDu1EzFkD5cZ7FJxUrgPjMEX
CIKQx42BJuWkiNUyh8z+/rbgEyAapfClJcvwzDOTx6k7aLtFtzUQ5kqa+eOpDH9x
NkSxkX9V7EA+iaRs0DbqQE5fRfpJFiC5TyUgaNQEBkxcbtUcDtuhvO6wUWh8+hY4
iTJKnWP+usDkdxNaIx5BDDAFCa+Kdnf4CaaxAgMBAAGjgYwwgYkwHQYDVR0OBBYE
FGUpQHjP2JP+OjZltr8WkgVigVI+ME0GA1UdIwRGMESAFGUpQHjP2JP+OjZltr8W
kgVigVI+oRakFDASMRAwDgYDVQQDDAdlYXN5dGxzghQsJbNn0AXExfFeMbvkbg9C
IyxRrTAMBgNVHRMEBTADAQH/MAsGA1UdDwQEAwIBBjANBgkqhkiG9w0BAQsFAAOC
AQEARlUqt2CZiPQ1OvfqLsWFuqpNLb8hm9vRdbtG/N/bOJhOjz7sknk3u674q7wQ
m9aYsxtpTOlUq2jgWf9iIZSd6PKpLQs0MegmPBAXawVkGCoGxLB5YTnziWbzanUU
ZV6+ykEDIz7910ZYIbKYwwEdgGu4XyB2JNZzNvcfkLmjcihuafdq2LKr0Ve/RRR/
HHTidyPq039wcWmxXKOagXtgjuAjI03sbqBI9bI3PXbUxDYiIC8u6dRvglfPbim3
LT/08AsbtTIsBHDV+fHEwI/1z5m9JkxYB0Ci+MCMP/7zXSIbpuDzKqHJakJh9g1M
4j/9msySPPoMid95jgOW2eJbYA==
-----END CERTIFICATE-----

</ca>

oconf= needs a name ... But it is very buggy .. for example: It works better with a blank last line.

From the details you have posted above, I would say that either:
  • Your server side router is badly configured or even broken ..
  • Your ISP is imposing some bizarre limitation on your server inbound traffic ..
You should try tcpdump to see if any packets reaches your server during the failure period.

BobAGI
OpenVPN Power User
Posts: 167
Joined: Mon May 05, 2014 10:17 pm

Re: New server on RPi3 only allows one connection....

Post by BobAGI » Sun Jun 06, 2021 5:39 pm

Hmm, I was referring to olog and not oconf.
As shown in my post I have used oconf for the config files, but when I tried olog for the log files it simply did not work (at least not in preview) so I replaced it with code instead.

Concerning the server side router, it is an older Dovado PRO using a 4G USB modem.
Last time I was there I tried to replace it with a newer ASUS RT-AC68U router but it turned out it had issues with the 4G modem and lost connection and then could not reconnect. So I had to reinstate the Dovado PRO.
I am getting out there again on Thursday so I can have a look at it and put the ASUS in place again for testing.

So in your view this should simply just work, then?

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

Re: New server on RPi3 only allows one connection....

Post by TinCanTech » Sun Jun 06, 2021 7:22 pm

Ah 'olog' .. I think it was a work in progress. Using code tag is preferred.
BobAGI wrote:
Sun Jun 06, 2021 5:39 pm
So in your view this should simply just work, then?
In my view, you said it yourself right here:
BobAGI wrote:
Sun Jun 06, 2021 9:55 am
The server side log for this connection attempt:

Code: Select all

Sun Jun  6 08:21:58 2021 us=687022 MULTI: multi_create_instance called
Sun Jun  6 08:21:58 2021 us=687402 158.174.104.130:57305 Re-using SSL/TLS context
Sun Jun  6 08:21:58 2021 us=687496 158.174.104.130:57305 LZO compression initializing
Sun Jun  6 08:21:58 2021 us=688016 158.174.104.130:57305 Control Channel MTU parms [ L:1622 D:1184 EF:66 EB:0 ET:0 EL:3 ]
Sun Jun  6 08:21:58 2021 us=688177 158.174.104.130:57305 Data Channel MTU parms [ L:1622 D:1450 EF:122 EB:406 ET:0 EL:3 ]
Sun Jun  6 08:21:58 2021 us=688420 158.174.104.130:57305 Local Options String (VER=V4): 'V4,dev-type tun,link-mtu 1558,tun-mtu 1500,proto UDPv4,comp-lzo,keydir 0,cipher AES-256-CBC,auth SHA1,keysize 256,tls-auth,key-method 2,tls-server'
Sun Jun  6 08:21:58 2021 us=688494 158.174.104.130:57305 Expected Remote Options String (VER=V4): 'V4,dev-type tun,link-mtu 1558,tun-mtu 1500,proto UDPv4,comp-lzo,keydir 1,cipher AES-256-CBC,auth SHA1,keysize 256,tls-auth,key-method 2,tls-client'
Sun Jun  6 08:21:58 2021 us=688663 158.174.104.130:57305 TLS: Initial packet from [AF_INET]158.174.104.130:57305, sid=ae4603f0 855964ef
Sun Jun  6 08:22:58 2021 us=276075 158.174.104.130:57305 TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity)
Sun Jun  6 08:22:58 2021 us=276321 158.174.104.130:57305 TLS Error: TLS handshake failed
Sun Jun  6 08:22:58 2021 us=276715 158.174.104.130:57305 SIGUSR1[soft,tls-error] received, client-instance restarting
Sun Jun  6 08:23:03 2021 us=544062 MULTI: multi_create_instance called
Sun Jun  6 08:23:03 2021 us=544554 158.174.104.130:38306 Re-using SSL/TLS context
Sun Jun  6 08:23:03 2021 us=544686 158.174.104.130:38306 LZO compression initializing
Sun Jun  6 08:23:03 2021 us=545093 158.174.104.130:38306 Control Channel MTU parms [ L:1622 D:1184 EF:66 EB:0 ET:0 EL:3 ]
Sun Jun  6 08:23:03 2021 us=545199 158.174.104.130:38306 Data Channel MTU parms [ L:1622 D:1450 EF:122 EB:406 ET:0 EL:3 ]
Sun Jun  6 08:23:03 2021 us=545453 158.174.104.130:38306 Local Options String (VER=V4): 'V4,dev-type tun,link-mtu 1558,tun-mtu 1500,proto UDPv4,comp-lzo,keydir 0,cipher AES-256-CBC,auth SHA1,keysize 256,tls-auth,key-method 2,tls-server'
Sun Jun  6 08:23:03 2021 us=545535 158.174.104.130:38306 Expected Remote Options String (VER=V4): 'V4,dev-type tun,link-mtu 1558,tun-mtu 1500,proto UDPv4,comp-lzo,keydir 1,cipher AES-256-CBC,auth SHA1,keysize 256,tls-auth,key-method 2,tls-client'
Sun Jun  6 08:23:03 2021 us=545714 158.174.104.130:38306 TLS: Initial packet from [AF_INET]158.174.104.130:38306, sid=79a41040 8755de0f


--------------------RPi3 client connection aborted 08:24:00, but no server log entry! ---------------


Sun Jun  6 08:24:03 2021 us=225425 158.174.104.130:38306 TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity)
Sun Jun  6 08:24:03 2021 us=225696 158.174.104.130:38306 TLS Error: TLS handshake failed
Sun Jun  6 08:24:03 2021 us=226124 158.174.104.130:38306 SIGUSR1[soft,tls-error] received, client-instance restarting
--------------------RPi3 client connection aborted 08:24:00, but no server log entry! ---------------
You have setup Openvpn before and you know it works .. the only reason things like this occur is when your network is broken. (unless you are running a development snapshot of Openvpn, which is unlikely here)

Use tcpdump and other standard tools to verify your wire-traffic.

BobAGI
OpenVPN Power User
Posts: 167
Joined: Mon May 05, 2014 10:17 pm

Re: New server on RPi3 only allows one connection....

Post by BobAGI » Sun Jun 06, 2021 8:00 pm

Thanks,
if I cannot use the test environment at the location in Sweden, then I need another test server.

So I decided to go into the main company OpenVPN server and create a no-password client there.
Also set the client-to-client directive on that server.
Next I transferred the new ovpn file to my test RPi4 unit and used it to connect (while my Windows machine is still connected too with address 10.8.1.2).
Worked fine.
And after getting the tun0 IP address on the RPi4 I could access the web-server on the RPi4 using its 10.8.1.7 address!
So in fact the whole system does work as I wanted it to, only my test environment network seems broken!
I really MUST replace the 4G router over there!
And I will look into what tcpdump can do (never used that tool before).

Thank you for your patience!

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

Re: New server on RPi3 only allows one connection....

Post by TinCanTech » Sun Jun 06, 2021 8:07 pm

You are welcome.

I am quite handy around a network and as this is for business, if you need some qualified help then you can contact me privately, you already have my email. I am quite reasonably priced as well.

300000
OpenVPN Expert
Posts: 685
Joined: Tue May 01, 2012 9:30 pm

Re: New server on RPi3 only allows one connection....

Post by 300000 » Sun Jun 06, 2021 10:06 pm

Your trouble is create only one certificate and want to use multi user to connect so it drop the connection. if you like to make it work just simple add this line into your server config and restart again . it will let multi user connec to it.

duplicate-cn

BobAGI
OpenVPN Power User
Posts: 167
Joined: Mon May 05, 2014 10:17 pm

Re: New server on RPi3 only allows one connection....

Post by BobAGI » Sun Jun 06, 2021 10:45 pm

300000 wrote:
Sun Jun 06, 2021 10:06 pm
Your trouble is create only one certificate and want to use multi user to connect so it drop the connection. if you like to make it work just simple add this line into your server config and restart again . it will let multi user connec to it.

duplicate-cn
No, you are wrong here. I have unique clients with full discrete certificates and keys.
This is what I have always done and it is done here as well.
The password-less clients are also set to get a fixed tunnel address via the ccd directory directive, one IP for each such client.
The "human" clients are getting ovpn files with password protected keys, so they have to enter their unique password when connecting.

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

Re: New server on RPi3 only allows one connection....

Post by TinCanTech » Sun Jun 06, 2021 11:27 pm

Don't worry about 300000 .. he thinks he knows stuff but he really doesn't.

It's funny to have a clown in the house ..

BobAGI
OpenVPN Power User
Posts: 167
Joined: Mon May 05, 2014 10:17 pm

Re: New server on RPi3 only allows one connection....

Post by BobAGI » Mon Jun 07, 2021 6:27 am

ISSUE RESOLVED!
Today when the openvpn-users mail list started working again and my posts and replies appeared I also had a reply from Gert Doering where he writes:
My gut feeling points to the NAT box. Especially if it "heals" itself
after a few minutes.
Not sure why that box would get into "I can only have one session to
1193" stuck mode, but it very much looks like it.
You could move the server to 1193, and avoid the port translation on
the NAT box.
And this is spot-on!

I have now reconfigured the test server so the openvpn server uses the ports that are incoming to the router rather than the router translating the port number towards the openvpn server.
So I changed the openvpn ports to the same as on the router incoming.
And set port forward to NOT translate the port numbers.
After a restart of openvpn and the router itself all is now working as expected!

The reason for the port translation was that the test network already had an openvpn server operating on 1194 and 1195 and the test box openvpn used 1194, 1195 and 1196 too. Not so anymore.

Post Reply