openvpn client cycles connection every 6 minutes

This forum is for admins who are looking to build or expand their OpenVPN setup.

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
mapreri
OpenVpn Newbie
Posts: 3
Joined: Sat Jul 16, 2022 11:08 am

openvpn client cycles connection every 6 minutes

Post by mapreri » Sat Jul 16, 2022 11:31 am

Hi!

I'm trying to use an openvpn server (managed by pfsense) and set up several openvpn clients in some remove servers, configuered using systemd's jobs. However those clients seems to cycles the connection every 6 minutes. This is different from what some other clients (some configured through network-manager's GUI, some using the OpenVPN client on some windows systems) do, as those don't seem to exhibit this behaviour.

I've seen many posts about unexpected connection drops due to --ping-restart or similar, but I unfortunately failed to understand what does and what does not apply to my case and was unable to solve this.

on the server side, it's running openvpn 2.5.4, whereas the client (in this case) is running ubuntu 20.04 with openvpn 2.4.7.

here are some details:

server conf:

server

dev ovpns2
verb 4
dev-type tun
dev-node /dev/tun2
writepid /var/run/openvpn_server2.pid
#user nobody
#group nobody
script-security 3
daemon
keepalive 10 60
ping-timer-rem
persist-tun
persist-key
proto udp4
auth SHA256
up /usr/local/sbin/ovpn-linkup
down /usr/local/sbin/ovpn-linkdown
client-connect /usr/local/sbin/openvpn.attributes.sh
client-disconnect /usr/local/sbin/openvpn.attributes.sh
local 10.0.0.6
tls-server
server 10.0.8.0 255.255.255.0
client-config-dir /var/etc/openvpn/server2/csc
username-as-common-name
plugin /usr/local/lib/openvpn/plugins/openvpn-plugin-auth-script.so /usr/local/sbin/ovpn_auth_verify_async user REDACTED false server2 1194
tls-verify "/usr/local/sbin/ovpn_auth_verify tls 'DNS%3AREDACTED' 1"
lport 1194
management /var/etc/openvpn/server2/sock unix
push "route 10.0.0.0 255.255.255.0"
capath /var/etc/openvpn/server2/ca
cert /var/etc/openvpn/server2/cert
key /var/etc/openvpn/server2/key
dh /etc/dh-parameters.4096
tls-auth /var/etc/openvpn/server2/tls-auth 0
data-ciphers AES-256-GCM:AES-128-GCM:CHACHA20-POLY1305:AES-256-CBC
data-ciphers-fallback AES-256-CBC
allow-compression no
persist-remote-ip
float
topology subnet
explicit-exit-notify 1
inactive 300


client conf:

client

dev tun
client
proto udp
<ca>
READATED
</ca>
cert user.crt
key user.key
key-direction 1
<tls-auth>
REDATED
</tls-auth>
remote REDACTED 1194
persist-key
persist-tun
verb 5
mute 20
keepalive 10 60
cipher AES-256-GCM
auth SHA256
nobind
mute-replay-warnings
auth-nocache
auth-user-pass /etc/openvpn/user.login
remote-cert-tls server
link-mtu 1569
keysize 256


server log:

Code: Select all

Jul 16 11:06:45 jumper openvpn[23695]: MANAGEMENT: Client connected from /var/etc/openvpn/server2/sock
Jul 16 11:06:45 jumper openvpn[23695]: MANAGEMENT: CMD 'status 2'
Jul 16 11:06:46 jumper openvpn[23695]: MANAGEMENT: CMD 'quit'
Jul 16 11:06:46 jumper openvpn[23695]: MANAGEMENT: Client disconnected
Jul 16 11:06:54 jumper openvpn[23695]: USERNAME/IPADDRESS:39197 Inactivity timeout (--inactive), exiting
Jul 16 11:06:54 jumper openvpn[23695]: USERNAME/IPADDRESS:39197 SIGTERM[soft,inactive] received, client-instance exiting
Jul 16 11:06:54 jumper openvpn[58715]: openvpn server 'ovpns2' user 'USERNAME' address 'IPADDRESS' - disconnected
Jul 16 11:07:47 jumper openvpn[23695]: MANAGEMENT: Client connected from /var/etc/openvpn/server2/sock
Jul 16 11:07:47 jumper openvpn[23695]: MANAGEMENT: CMD 'status 2'
Jul 16 11:07:47 jumper openvpn[23695]: MANAGEMENT: CMD 'quit'
Jul 16 11:07:47 jumper openvpn[23695]: MANAGEMENT: Client disconnected
Jul 16 11:07:53 jumper openvpn[23695]: MULTI: multi_create_instance called
Jul 16 11:07:53 jumper openvpn[23695]: IPADDRESS:33261 Re-using SSL/TLS context
Jul 16 11:07:53 jumper openvpn[23695]: IPADDRESS:33261 Outgoing Control Channel Authentication: Using 256 bit message hash 'SHA256' for HMAC authentication
Jul 16 11:07:53 jumper openvpn[23695]: IPADDRESS:33261 Incoming Control Channel Authentication: Using 256 bit message hash 'SHA256' for HMAC authentication
Jul 16 11:07:53 jumper openvpn[23695]: IPADDRESS:33261 Control Channel MTU parms [ L:1621 D:1172 EF:78 EB:0 ET:0 EL:3 ]
Jul 16 11:07:53 jumper openvpn[23695]: IPADDRESS:33261 Data Channel MTU parms [ L:1621 D:1450 EF:121 EB:406 ET:0 EL:3 ]
Jul 16 11:07:53 jumper openvpn[23695]: IPADDRESS:33261 Local Options String (VER=V4): 'V4,dev-type tun,link-mtu 1569,tun-mtu 1500,proto UDPv4,keydir 0,cipher AES-256-CBC,auth SHA256,keysize 256,tls-auth,key-method 2,tls-server'
Jul 16 11:07:53 jumper openvpn[23695]: IPADDRESS:33261 Expected Remote Options String (VER=V4): 'V4,dev-type tun,link-mtu 1569,tun-mtu 1500,proto UDPv4,keydir 1,cipher AES-256-CBC,auth SHA256,keysize 256,tls-auth,key-method 2,tls-client'
Jul 16 11:07:53 jumper openvpn[23695]: IPADDRESS:33261 TLS: Initial packet from [AF_INET]IPADDRESS:33261, sid=83612927 851b2517
Jul 16 11:07:53 jumper openvpn[23695]: IPADDRESS:33261 VERIFY WARNING: depth=0, unable to get certificate CRL: C=IT, CN=USERNAME
Jul 16 11:07:53 jumper openvpn[23695]: IPADDRESS:33261 VERIFY WARNING: depth=1, unable to get certificate CRL: CN=email:support+azure@FQDN, C=IT
Jul 16 11:07:53 jumper openvpn[23695]: IPADDRESS:33261 VERIFY SCRIPT OK: depth=1, CN=email:support+azure@FQDN, C=IT
Jul 16 11:07:53 jumper openvpn[23695]: IPADDRESS:33261 VERIFY OK: depth=1, CN=email:support+azure@FQDN, C=IT
Jul 16 11:07:53 jumper openvpn[23695]: IPADDRESS:33261 VERIFY SCRIPT OK: depth=0, C=IT, CN=USERNAME
Jul 16 11:07:53 jumper openvpn[23695]: IPADDRESS:33261 VERIFY OK: depth=0, C=IT, CN=USERNAME
Jul 16 11:07:53 jumper openvpn[23695]: IPADDRESS:33261 peer info: IV_VER=2.4.7
Jul 16 11:07:53 jumper openvpn[23695]: IPADDRESS:33261 peer info: IV_PLAT=linux
Jul 16 11:07:53 jumper openvpn[23695]: IPADDRESS:33261 peer info: IV_PROTO=2
Jul 16 11:07:53 jumper openvpn[23695]: IPADDRESS:33261 peer info: IV_NCP=2
Jul 16 11:07:53 jumper openvpn[23695]: IPADDRESS:33261 peer info: IV_LZ4=1
Jul 16 11:07:53 jumper openvpn[23695]: IPADDRESS:33261 peer info: IV_LZ4v2=1
Jul 16 11:07:53 jumper openvpn[23695]: IPADDRESS:33261 peer info: IV_LZO=1
Jul 16 11:07:53 jumper openvpn[23695]: IPADDRESS:33261 peer info: IV_COMP_STUB=1
Jul 16 11:07:53 jumper openvpn[23695]: IPADDRESS:33261 peer info: IV_COMP_STUBv2=1
Jul 16 11:07:53 jumper openvpn[23695]: IPADDRESS:33261 peer info: IV_TCPNL=1
Jul 16 11:07:53 jumper openvpn[23695]: IPADDRESS:33261 PLUGIN_CALL: POST /usr/local/lib/openvpn/plugins/openvpn-plugin-auth-script.so/PLUGIN_AUTH_USER_PASS_VERIFY status=2
Jul 16 11:07:53 jumper openvpn[23695]: IPADDRESS:33261 TLS: Username/Password authentication deferred for username 'USERNAME' [CN SET]
Jul 16 11:07:53 jumper openvpn[23695]: IPADDRESS:33261 WARNING: 'tun-mtu' is used inconsistently, local='tun-mtu 1500', remote='tun-mtu 1448'
Jul 16 11:07:53 jumper openvpn[23695]: IPADDRESS:33261 WARNING: 'auth' is used inconsistently, local='auth SHA256', remote='auth [null-digest]'
Jul 16 11:07:53 jumper openvpn[23695]: IPADDRESS:33261 Control Channel: TLSv1.3, cipher TLSv1.3 TLS_AES_256_GCM_SHA384, peer certificate: 256 bit EC, curve prime256v1, signature: ecdsa-with-SHA256
Jul 16 11:07:53 jumper openvpn[23695]: IPADDRESS:33261 [USERNAME] Peer Connection Initiated with [AF_INET]IPADDRESS:33261
Jul 16 11:07:53 jumper openvpn[85390]: user 'USERNAME' authenticated
Jul 16 11:07:53 jumper openvpn[23695]: USERNAME/IPADDRESS:33261 MULTI_sva: pool returned IPv4=10.0.8.6, IPv6=(Not enabled)
Jul 16 11:07:53 jumper openvpn[23695]: USERNAME/IPADDRESS:33261 OPTIONS IMPORT: reading client specific options from: /var/etc/openvpn/server2/csc/USERNAME
Jul 16 11:07:53 jumper openvpn[23695]: USERNAME/IPADDRESS:33261 PUSH_REMOVE 'route'
Jul 16 11:07:53 jumper openvpn[85803]: openvpn server 'ovpns2' user 'USERNAME' address 'IPADDRESS' - connected
Jul 16 11:07:53 jumper openvpn[23695]: USERNAME/IPADDRESS:33261 OPTIONS IMPORT: reading client specific options from: /tmp/openvpn_cc_7614d5281267a9e66d3a31ada1982f25.tmp
Jul 16 11:07:53 jumper openvpn[23695]: USERNAME/IPADDRESS:33261 MULTI: Learn: 10.0.8.201 -> USERNAME/IPADDRESS:33261
Jul 16 11:07:53 jumper openvpn[23695]: USERNAME/IPADDRESS:33261 MULTI: primary virtual IP for USERNAME/IPADDRESS:33261: 10.0.8.201
Jul 16 11:07:53 jumper openvpn[23695]: USERNAME/IPADDRESS:33261 Data Channel: using negotiated cipher 'AES-256-GCM'
Jul 16 11:07:53 jumper openvpn[23695]: USERNAME/IPADDRESS:33261 Data Channel MTU parms [ L:1549 D:1450 EF:49 EB:406 ET:0 EL:3 ]
Jul 16 11:07:53 jumper openvpn[23695]: USERNAME/IPADDRESS:33261 Outgoing Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
Jul 16 11:07:53 jumper openvpn[23695]: USERNAME/IPADDRESS:33261 Incoming Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
Jul 16 11:07:54 jumper openvpn[23695]: USERNAME/IPADDRESS:33261 PUSH: Received control message: 'PUSH_REQUEST'
Jul 16 11:07:54 jumper openvpn[23695]: USERNAME/IPADDRESS:33261 SENT CONTROL [USERNAME]: 'PUSH_REPLY,topology subnet,ping 10,ping-restart 60,ifconfig 10.0.8.201 255.255.255.0,peer-id 1,cipher AES-256-GCM' (status=1)
Jul 16 11:12:53 jumper openvpn[23695]: USERNAME/IPADDRESS:33261 Inactivity timeout (--inactive), exiting
Jul 16 11:12:53 jumper openvpn[23695]: USERNAME/IPADDRESS:33261 SIGTERM[soft,inactive] received, client-instance exiting
Jul 16 11:12:53 jumper openvpn[88951]: openvpn server 'ovpns2' user 'USERNAME' address 'IPADDRESS' - disconnected
Jul 16 11:12:55 jumper openvpn[23695]: MANAGEMENT: Client connected from /var/etc/openvpn/server2/sock
Jul 16 11:12:56 jumper openvpn[23695]: MANAGEMENT: CMD 'status 2'
Jul 16 11:12:56 jumper openvpn[23695]: MANAGEMENT: CMD 'quit'
Jul 16 11:12:56 jumper openvpn[23695]: MANAGEMENT: Client disconnected
Jul 16 11:13:51 jumper openvpn[23695]: MULTI: multi_create_instance called
Jul 16 11:13:51 jumper openvpn[23695]: IPADDRESS:47126 Re-using SSL/TLS context
Jul 16 11:13:51 jumper openvpn[23695]: IPADDRESS:47126 Outgoing Control Channel Authentication: Using 256 bit message hash 'SHA256' for HMAC authentication
Jul 16 11:13:51 jumper openvpn[23695]: IPADDRESS:47126 Incoming Control Channel Authentication: Using 256 bit message hash 'SHA256' for HMAC authentication
Jul 16 11:13:51 jumper openvpn[23695]: IPADDRESS:47126 Control Channel MTU parms [ L:1621 D:1172 EF:78 EB:0 ET:0 EL:3 ]
Jul 16 11:13:51 jumper openvpn[23695]: IPADDRESS:47126 Data Channel MTU parms [ L:1621 D:1450 EF:121 EB:406 ET:0 EL:3 ]
Jul 16 11:13:51 jumper openvpn[23695]: IPADDRESS:47126 Local Options String (VER=V4): 'V4,dev-type tun,link-mtu 1569,tun-mtu 1500,proto UDPv4,keydir 0,cipher AES-256-CBC,auth SHA256,keysize 256,tls-auth,key-method 2,tls-server'
Jul 16 11:13:51 jumper openvpn[23695]: IPADDRESS:47126 Expected Remote Options String (VER=V4): 'V4,dev-type tun,link-mtu 1569,tun-mtu 1500,proto UDPv4,keydir 1,cipher AES-256-CBC,auth SHA256,keysize 256,tls-auth,key-method 2,tls-client'
Jul 16 11:13:51 jumper openvpn[23695]: IPADDRESS:47126 TLS: Initial packet from [AF_INET]IPADDRESS:47126, sid=4a17543a e96608bc
Jul 16 11:13:51 jumper openvpn[23695]: IPADDRESS:47126 VERIFY WARNING: depth=0, unable to get certificate CRL: C=IT, CN=USERNAME
Jul 16 11:13:51 jumper openvpn[23695]: IPADDRESS:47126 VERIFY WARNING: depth=1, unable to get certificate CRL: CN=email:support+azure@FQDN, C=IT
Jul 16 11:13:51 jumper openvpn[23695]: IPADDRESS:47126 VERIFY SCRIPT OK: depth=1, CN=email:support+azure@FQDN, C=IT
Jul 16 11:13:51 jumper openvpn[23695]: IPADDRESS:47126 VERIFY OK: depth=1, CN=email:support+azure@FQDN, C=IT
Jul 16 11:13:51 jumper openvpn[23695]: IPADDRESS:47126 VERIFY SCRIPT OK: depth=0, C=IT, CN=USERNAME
Jul 16 11:13:51 jumper openvpn[23695]: IPADDRESS:47126 VERIFY OK: depth=0, C=IT, CN=USERNAME
Jul 16 11:13:51 jumper openvpn[23695]: IPADDRESS:47126 peer info: IV_VER=2.4.7
Jul 16 11:13:51 jumper openvpn[23695]: IPADDRESS:47126 peer info: IV_PLAT=linux
Jul 16 11:13:51 jumper openvpn[23695]: IPADDRESS:47126 peer info: IV_PROTO=2
Jul 16 11:13:51 jumper openvpn[23695]: IPADDRESS:47126 peer info: IV_NCP=2
Jul 16 11:13:51 jumper openvpn[23695]: IPADDRESS:47126 peer info: IV_LZ4=1
Jul 16 11:13:51 jumper openvpn[23695]: IPADDRESS:47126 peer info: IV_LZ4v2=1
Jul 16 11:13:51 jumper openvpn[23695]: IPADDRESS:47126 peer info: IV_LZO=1
Jul 16 11:13:51 jumper openvpn[23695]: IPADDRESS:47126 peer info: IV_COMP_STUB=1
Jul 16 11:13:51 jumper openvpn[23695]: IPADDRESS:47126 peer info: IV_COMP_STUBv2=1
Jul 16 11:13:51 jumper openvpn[23695]: IPADDRESS:47126 peer info: IV_TCPNL=1
Jul 16 11:13:51 jumper openvpn[23695]: IPADDRESS:47126 PLUGIN_CALL: POST /usr/local/lib/openvpn/plugins/openvpn-plugin-auth-script.so/PLUGIN_AUTH_USER_PASS_VERIFY status=2
Jul 16 11:13:51 jumper openvpn[23695]: IPADDRESS:47126 TLS: Username/Password authentication deferred for username 'USERNAME' [CN SET]
Jul 16 11:13:51 jumper openvpn[23695]: IPADDRESS:47126 WARNING: 'tun-mtu' is used inconsistently, local='tun-mtu 1500', remote='tun-mtu 1448'
Jul 16 11:13:51 jumper openvpn[23695]: IPADDRESS:47126 WARNING: 'auth' is used inconsistently, local='auth SHA256', remote='auth [null-digest]'
Jul 16 11:13:51 jumper openvpn[23695]: IPADDRESS:47126 Control Channel: TLSv1.3, cipher TLSv1.3 TLS_AES_256_GCM_SHA384, peer certificate: 256 bit EC, curve prime256v1, signature: ecdsa-with-SHA256
Jul 16 11:13:51 jumper openvpn[23695]: IPADDRESS:47126 [USERNAME] Peer Connection Initiated with [AF_INET]IPADDRESS:47126
Jul 16 11:13:52 jumper openvpn[15413]: user 'USERNAME' authenticated
Jul 16 11:13:52 jumper openvpn[23695]: USERNAME/IPADDRESS:47126 MULTI_sva: pool returned IPv4=10.0.8.6, IPv6=(Not enabled)
Jul 16 11:13:52 jumper openvpn[23695]: USERNAME/IPADDRESS:47126 OPTIONS IMPORT: reading client specific options from: /var/etc/openvpn/server2/csc/USERNAME
Jul 16 11:13:52 jumper openvpn[23695]: USERNAME/IPADDRESS:47126 PUSH_REMOVE 'route'
Jul 16 11:13:52 jumper openvpn[16032]: openvpn server 'ovpns2' user 'USERNAME' address 'IPADDRESS' - connected
Jul 16 11:13:52 jumper openvpn[23695]: USERNAME/IPADDRESS:47126 OPTIONS IMPORT: reading client specific options from: /tmp/openvpn_cc_e5a1f4a77e47d8b381a517b71867d8e.tmp
Jul 16 11:13:52 jumper openvpn[23695]: USERNAME/IPADDRESS:47126 MULTI: Learn: 10.0.8.201 -> USERNAME/IPADDRESS:47126
Jul 16 11:13:52 jumper openvpn[23695]: USERNAME/IPADDRESS:47126 MULTI: primary virtual IP for USERNAME/IPADDRESS:47126: 10.0.8.201
Jul 16 11:13:52 jumper openvpn[23695]: USERNAME/IPADDRESS:47126 Data Channel: using negotiated cipher 'AES-256-GCM'
Jul 16 11:13:52 jumper openvpn[23695]: USERNAME/IPADDRESS:47126 Data Channel MTU parms [ L:1549 D:1450 EF:49 EB:406 ET:0 EL:3 ]
Jul 16 11:13:52 jumper openvpn[23695]: USERNAME/IPADDRESS:47126 Outgoing Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
Jul 16 11:13:52 jumper openvpn[23695]: USERNAME/IPADDRESS:47126 Incoming Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
Jul 16 11:13:53 jumper openvpn[23695]: USERNAME/IPADDRESS:47126 PUSH: Received control message: 'PUSH_REQUEST'
Jul 16 11:13:53 jumper openvpn[23695]: USERNAME/IPADDRESS:47126 SENT CONTROL [USERNAME]: 'PUSH_REPLY,topology subnet,ping 10,ping-restart 60,ifconfig 10.0.8.201 255.255.255.0,peer-id 1,cipher AES-256-GCM' (status=1)
Jul 16 11:13:57 jumper openvpn[23695]: MANAGEMENT: Client connected from /var/etc/openvpn/server2/sock
Jul 16 11:13:57 jumper openvpn[23695]: MANAGEMENT: CMD 'status 2'
Jul 16 11:13:57 jumper openvpn[23695]: MANAGEMENT: CMD 'quit'
Jul 16 11:13:57 jumper openvpn[23695]: MANAGEMENT: Client disconnected
client log:

Code: Select all

Jul 16 13:01:55 HOSTNAME ovpn-Azure[745]: OPTIONS IMPORT: timers and/or timeouts modified
Jul 16 13:01:55 HOSTNAME ovpn-Azure[745]: OPTIONS IMPORT: --ifconfig/up options modified
Jul 16 13:01:55 HOSTNAME ovpn-Azure[745]: OPTIONS IMPORT: peer-id set
Jul 16 13:01:55 HOSTNAME ovpn-Azure[745]: OPTIONS IMPORT: WARNING: peer-id set, but link-mtu fixed by config - reducing tun-mtu to 1445, expect MTU problems
Jul 16 13:01:55 HOSTNAME ovpn-Azure[745]: OPTIONS IMPORT: data channel crypto options modified
Jul 16 13:01:55 HOSTNAME ovpn-Azure[745]: Data Channel MTU parms [ L:1569 D:1450 EF:52 EB:397 ET:0 EL:3 ]
Jul 16 13:01:55 HOSTNAME ovpn-Azure[745]: Outgoing Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
Jul 16 13:01:55 HOSTNAME ovpn-Azure[745]: Incoming Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
Jul 16 13:01:55 HOSTNAME ovpn-Azure[745]: Preserving previous TUN/TAP instance: tun0
Jul 16 13:01:55 HOSTNAME ovpn-Azure[745]: Initialization Sequence Completed
Jul 16 13:07:48 HOSTNAME ovpn-Azure[745]: [DNS:SERVERNAME] Inactivity timeout (--ping-restart), restarting
Jul 16 13:07:48 HOSTNAME ovpn-Azure[745]: TCP/UDP: Closing socket
Jul 16 13:07:48 HOSTNAME ovpn-Azure[745]: SIGUSR1[soft,ping-restart] received, process restarting
Jul 16 13:07:48 HOSTNAME ovpn-Azure[745]: Restart pause, 5 second(s)
Jul 16 13:07:53 HOSTNAME ovpn-Azure[745]: Re-using SSL/TLS context
Jul 16 13:07:53 HOSTNAME ovpn-Azure[745]: WARNING: normally if you use --mssfix and/or --fragment, you should also set --tun-mtu 1500 (currently it is 1448)
Jul 16 13:07:53 HOSTNAME ovpn-Azure[745]: Control Channel MTU parms [ L:1569 D:1172 EF:78 EB:0 ET:0 EL:3 ]
Jul 16 13:07:53 HOSTNAME ovpn-Azure[745]: Data Channel MTU parms [ L:1569 D:1450 EF:121 EB:397 ET:0 EL:3 ]
Jul 16 13:07:53 HOSTNAME ovpn-Azure[745]: Local Options String (VER=V4): 'V4,dev-type tun,link-mtu 1569,tun-mtu 1448,proto UDPv4,keydir 1,cipher AES-256-GCM,auth [null-digest],keysize 256,tls-auth,key-method 2,tls-client'
Jul 16 13:07:53 HOSTNAME ovpn-Azure[745]: Expected Remote Options String (VER=V4): 'V4,dev-type tun,link-mtu 1569,tun-mtu 1448,proto UDPv4,keydir 0,cipher AES-256-GCM,auth [null-digest],keysize 256,tls-auth,key-method 2,tls-server'
Jul 16 13:07:53 HOSTNAME ovpn-Azure[745]: TCP/UDP: Preserving recently used remote address: [AF_INET]SERVERIP:1194
Jul 16 13:07:53 HOSTNAME ovpn-Azure[745]: Socket Buffers: R=[212992->212992] S=[212992->212992]
Jul 16 13:07:53 HOSTNAME ovpn-Azure[745]: UDP link local: (not bound)
Jul 16 13:07:53 HOSTNAME ovpn-Azure[745]: UDP link remote: [AF_INET]SERVERIP:1194
Jul 16 13:07:53 HOSTNAME ovpn-Azure[745]: TLS: Initial packet from [AF_INET]SERVERIP:1194, sid=9fb837eb 6b9ad3a3
Jul 16 13:07:53 HOSTNAME ovpn-Azure[745]: VERIFY OK: depth=1, CN=email:support+azure@FQDN, C=IT
Jul 16 13:07:53 HOSTNAME ovpn-Azure[745]: VERIFY KU OK
Jul 16 13:07:53 HOSTNAME ovpn-Azure[745]: Validating certificate extended key usage
Jul 16 13:07:53 HOSTNAME ovpn-Azure[745]: ++ Certificate has EKU (str) TLS Web Server Authentication, expects TLS Web Server Authentication
Jul 16 13:07:53 HOSTNAME ovpn-Azure[745]: VERIFY EKU OK
Jul 16 13:07:53 HOSTNAME ovpn-Azure[745]: VERIFY OK: depth=0, CN=DNS:SERVERNAME, C=IT
Jul 16 13:07:53 HOSTNAME ovpn-Azure[745]: WARNING: 'tun-mtu' is used inconsistently, local='tun-mtu 1448', remote='tun-mtu 1500'
Jul 16 13:07:53 HOSTNAME ovpn-Azure[745]: WARNING: 'cipher' is used inconsistently, local='cipher AES-256-GCM', remote='cipher AES-256-CBC'
Jul 16 13:07:53 HOSTNAME ovpn-Azure[745]: WARNING: 'auth' is used inconsistently, local='auth [null-digest]', remote='auth SHA256'
Jul 16 13:07:53 HOSTNAME ovpn-Azure[745]: Control Channel: TLSv1.3, cipher TLSv1.3 TLS_AES_256_GCM_SHA384, 256 bit EC, curve: prime256v1
Jul 16 13:07:53 HOSTNAME ovpn-Azure[745]: [DNS:SERVERNAME] Peer Connection Initiated with [AF_INET]SERVERIP:1194
Jul 16 13:07:54 HOSTNAME ovpn-Azure[745]: SENT CONTROL [DNS:SERVERNAME]: 'PUSH_REQUEST' (status=1)
Jul 16 13:07:54 HOSTNAME ovpn-Azure[745]: PUSH: Received control message: 'PUSH_REPLY,topology subnet,ping 10,ping-restart 60,ifconfig 10.0.8.201 255.255.255.0,peer-id 1,cipher AES-256-GCM'
Jul 16 13:07:54 HOSTNAME ovpn-Azure[745]: OPTIONS IMPORT: timers and/or timeouts modified
Jul 16 13:07:54 HOSTNAME ovpn-Azure[745]: OPTIONS IMPORT: --ifconfig/up options modified
Jul 16 13:07:54 HOSTNAME ovpn-Azure[745]: OPTIONS IMPORT: peer-id set
Jul 16 13:07:54 HOSTNAME ovpn-Azure[745]: OPTIONS IMPORT: WARNING: peer-id set, but link-mtu fixed by config - reducing tun-mtu to 1445, expect MTU problems
Jul 16 13:07:54 HOSTNAME ovpn-Azure[745]: OPTIONS IMPORT: data channel crypto options modified
Jul 16 13:07:54 HOSTNAME ovpn-Azure[745]: Data Channel MTU parms [ L:1569 D:1450 EF:52 EB:397 ET:0 EL:3 ]
Jul 16 13:07:54 HOSTNAME ovpn-Azure[745]: Outgoing Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
Jul 16 13:07:54 HOSTNAME ovpn-Azure[745]: Incoming Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
Jul 16 13:07:54 HOSTNAME ovpn-Azure[745]: Preserving previous TUN/TAP instance: tun0
Jul 16 13:07:54 HOSTNAME ovpn-Azure[745]: Initialization Sequence Completed
Jul 16 13:13:46 HOSTNAME ovpn-Azure[745]: [DNS:SERVERNAME] Inactivity timeout (--ping-restart), restarting
Jul 16 13:13:46 HOSTNAME ovpn-Azure[745]: TCP/UDP: Closing socket
Jul 16 13:13:46 HOSTNAME ovpn-Azure[745]: SIGUSR1[soft,ping-restart] received, process restarting
Jul 16 13:13:46 HOSTNAME ovpn-Azure[745]: Restart pause, 5 second(s)
Jul 16 13:13:51 HOSTNAME ovpn-Azure[745]: Re-using SSL/TLS context
Jul 16 13:13:51 HOSTNAME ovpn-Azure[745]: WARNING: normally if you use --mssfix and/or --fragment, you should also set --tun-mtu 1500 (currently it is 1448)
Jul 16 13:13:51 HOSTNAME ovpn-Azure[745]: Control Channel MTU parms [ L:1569 D:1172 EF:78 EB:0 ET:0 EL:3 ]
Jul 16 13:13:51 HOSTNAME ovpn-Azure[745]: Data Channel MTU parms [ L:1569 D:1450 EF:121 EB:397 ET:0 EL:3 ]
Jul 16 13:13:51 HOSTNAME ovpn-Azure[745]: Local Options String (VER=V4): 'V4,dev-type tun,link-mtu 1569,tun-mtu 1448,proto UDPv4,keydir 1,cipher AES-256-GCM,auth [null-digest],keysize 256,tls-auth,key-method 2,tls-client'
Jul 16 13:13:51 HOSTNAME ovpn-Azure[745]: Expected Remote Options String (VER=V4): 'V4,dev-type tun,link-mtu 1569,tun-mtu 1448,proto UDPv4,keydir 0,cipher AES-256-GCM,auth [null-digest],keysize 256,tls-auth,key-method 2,tls-server'
Jul 16 13:13:51 HOSTNAME ovpn-Azure[745]: TCP/UDP: Preserving recently used remote address: [AF_INET]SERVERIP:1194
Jul 16 13:13:51 HOSTNAME ovpn-Azure[745]: Socket Buffers: R=[212992->212992] S=[212992->212992]
Jul 16 13:13:51 HOSTNAME ovpn-Azure[745]: UDP link local: (not bound)
Jul 16 13:13:51 HOSTNAME ovpn-Azure[745]: UDP link remote: [AF_INET]SERVERIP:1194
Jul 16 13:13:51 HOSTNAME ovpn-Azure[745]: TLS: Initial packet from [AF_INET]SERVERIP:1194, sid=e1f81df3 848d0934
Jul 16 13:13:51 HOSTNAME ovpn-Azure[745]: VERIFY OK: depth=1, CN=email:support+azure@FQDN, C=IT
Jul 16 13:13:51 HOSTNAME ovpn-Azure[745]: VERIFY KU OK
Jul 16 13:13:51 HOSTNAME ovpn-Azure[745]: Validating certificate extended key usage
Jul 16 13:13:51 HOSTNAME ovpn-Azure[745]: ++ Certificate has EKU (str) TLS Web Server Authentication, expects TLS Web Server Authentication
Jul 16 13:13:51 HOSTNAME ovpn-Azure[745]: VERIFY EKU OK
Jul 16 13:13:51 HOSTNAME ovpn-Azure[745]: VERIFY OK: depth=0, CN=DNS:SERVERNAME, C=IT
Jul 16 13:13:51 HOSTNAME ovpn-Azure[745]: WARNING: 'tun-mtu' is used inconsistently, local='tun-mtu 1448', remote='tun-mtu 1500'
Jul 16 13:13:51 HOSTNAME ovpn-Azure[745]: WARNING: 'cipher' is used inconsistently, local='cipher AES-256-GCM', remote='cipher AES-256-CBC'
Jul 16 13:13:51 HOSTNAME ovpn-Azure[745]: WARNING: 'auth' is used inconsistently, local='auth [null-digest]', remote='auth SHA256'
Jul 16 13:13:51 HOSTNAME ovpn-Azure[745]: Control Channel: TLSv1.3, cipher TLSv1.3 TLS_AES_256_GCM_SHA384, 256 bit EC, curve: prime256v1
Jul 16 13:13:51 HOSTNAME ovpn-Azure[745]: [DNS:SERVERNAME] Peer Connection Initiated with [AF_INET]SERVERIP:1194
Jul 16 13:13:53 HOSTNAME ovpn-Azure[745]: SENT CONTROL [DNS:SERVERNAME]: 'PUSH_REQUEST' (status=1)
Jul 16 13:13:53 HOSTNAME ovpn-Azure[745]: PUSH: Received control message: 'PUSH_REPLY,topology subnet,ping 10,ping-restart 60,ifconfig 10.0.8.201 255.255.255.0,peer-id 1,cipher AES-256-GCM'
Jul 16 13:13:53 HOSTNAME ovpn-Azure[745]: OPTIONS IMPORT: timers and/or timeouts modified
Jul 16 13:13:53 HOSTNAME ovpn-Azure[745]: OPTIONS IMPORT: --ifconfig/up options modified
Jul 16 13:13:53 HOSTNAME ovpn-Azure[745]: OPTIONS IMPORT: peer-id set
Jul 16 13:13:53 HOSTNAME ovpn-Azure[745]: OPTIONS IMPORT: WARNING: peer-id set, but link-mtu fixed by config - reducing tun-mtu to 1445, expect MTU problems
Jul 16 13:13:53 HOSTNAME ovpn-Azure[745]: OPTIONS IMPORT: data channel crypto options modified
Jul 16 13:13:53 HOSTNAME ovpn-Azure[745]: Data Channel MTU parms [ L:1569 D:1450 EF:52 EB:397 ET:0 EL:3 ]
Jul 16 13:13:53 HOSTNAME ovpn-Azure[745]: Outgoing Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
Jul 16 13:13:53 HOSTNAME ovpn-Azure[745]: Incoming Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
Jul 16 13:13:53 HOSTNAME ovpn-Azure[745]: Preserving previous TUN/TAP instance: tun0
Jul 16 13:13:53 HOSTNAME ovpn-Azure[745]: Initialization Sequence Completed

Thank you in advance for any help you can give!
Top
TinCanTech
OpenVPN Protagonist
Posts: 11139
Joined: Fri Jun 03, 2016 1:17 pm

Re: openvpn client cycles connection every 6 minutes

Post by TinCanTech » Sat Jul 16, 2022 12:21 pm

From your client log:

Jul 16 13:07:48 HOSTNAME ovpn-Azure[745]: [DNS:SERVERNAME] Inactivity timeout (--ping-restart), restarting

Remove 'inactive' from your server config.
Top
mapreri
OpenVpn Newbie
Posts: 3
Joined: Sat Jul 16, 2022 11:08 am

Re: openvpn client cycles connection every 6 minutes

Post by mapreri » Sat Jul 16, 2022 12:34 pm

Hi TinCanTech!

thank you. Removing that option clearly works, but can you explain/guess why it wouldn't work with the timeout turned on..? It clearly is documented to work in a way that it timeouts only if no traffic happens, but with the regular pings from the client and other traffic I can't imagine why it would timeout.
Top
TinCanTech
OpenVPN Protagonist
Posts: 11139
Joined: Fri Jun 03, 2016 1:17 pm

Re: openvpn client cycles connection every 6 minutes

Post by TinCanTech » Sat Jul 16, 2022 5:02 pm

The best place to learn what the options do is by reading the manual.

If you like, I can copy & paste that here ..
Top
mapreri
OpenVpn Newbie
Posts: 3
Joined: Sat Jul 16, 2022 11:08 am

Re: openvpn client cycles connection every 6 minutes

Post by mapreri » Sun Jul 17, 2022 10:31 am

Oh....
In any case, OpenVPN's internal ping packets (which are just keepalives) and TLS control packets are not considered "activity", nor are they counted as traffic, as they are used internally by OpenVPN and are not an indication of actual user activity.
:facepalm:

sorry, and thank you for helping me out in this obvious PEBKAC case! :\
Top
Post Reply

Return to “Server Administration”