Clients disconnects and confusing server log
Posted: Wed Feb 19, 2020 12:53 pm
OpenVPN 2.4.6 running on Pfsense 2.4.4-p3.
I have setup Openvpn for remote access clients with user auth and certificates but am having some issues with client disconnects. Each user has their own certificate and it is one user per device so the same user will not be connecting from multiple devices at the same time.
When a client connects and starts a continuous ping it stays connected for approx 5mins then disconnects. After a bit of reading I started the server with verb 4 and you can see the server log below. There are 2 client connections -
1) lgms2 from IP y.y.y.14 which was the first to connect.
2) jms (me) from x.x.x.37 which is in a completely different location with completely different public IP. What is confusing me is why halfway through the log am I trying to connect from the other IP (y.y.y.14) which obviously I cannot do purely from an IP networking point of view.
Could this be what is causing the disconnects or should I be looking elsewhere ?
Any help would be much appreciated.
Any further information please just ask.
dev ovpns1
verb 4
dev-type tun
dev-node /dev/tun1
writepid /var/run/openvpn_server1.pid
#user nobody
#group nobody
script-security 3
daemon
keepalive 10 60
ping-timer-rem
persist-tun
persist-key
proto udp4
cipher AES-128-CBC
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.3.1.5
tls-server
server 10.3.2.0 255.255.255.0
client-config-dir /var/etc/openvpn-csc/server1
username-as-common-name
plugin /usr/local/lib/openvpn/plugins/openvpn-plugin-auth-script.so /usr/local/sbin/ovpn_auth_verify_async user T G9jYWwgRGF0YWJhc2U= false server1 1194
tls-verify "/usr/local/sbin/ovpn_auth_verify tls 'LogmaCA' 1"
lport 1194
management /var/etc/openvpn/server1.sock unix
push "route 10.3.1.0 255.255.255.0"
ca /var/etc/openvpn/server1.ca
cert /var/etc/openvpn/server1.cert
key /var/etc/openvpn/server1.key
dh /etc/dh-parameters.2048
crl-verify /var/etc/openvpn/server1.crl-verify
tls-auth /var/etc/openvpn/server1.tls-auth 0
ncp-ciphers AES-128-GCM
persist-remote-ip
float
topology subnet
I have setup Openvpn for remote access clients with user auth and certificates but am having some issues with client disconnects. Each user has their own certificate and it is one user per device so the same user will not be connecting from multiple devices at the same time.
When a client connects and starts a continuous ping it stays connected for approx 5mins then disconnects. After a bit of reading I started the server with verb 4 and you can see the server log below. There are 2 client connections -
1) lgms2 from IP y.y.y.14 which was the first to connect.
2) jms (me) from x.x.x.37 which is in a completely different location with completely different public IP. What is confusing me is why halfway through the log am I trying to connect from the other IP (y.y.y.14) which obviously I cannot do purely from an IP networking point of view.
Could this be what is causing the disconnects or should I be looking elsewhere ?
Any help would be much appreciated.
Any further information please just ask.
Server config
dev ovpns1
verb 4
dev-type tun
dev-node /dev/tun1
writepid /var/run/openvpn_server1.pid
#user nobody
#group nobody
script-security 3
daemon
keepalive 10 60
ping-timer-rem
persist-tun
persist-key
proto udp4
cipher AES-128-CBC
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.3.1.5
tls-server
server 10.3.2.0 255.255.255.0
client-config-dir /var/etc/openvpn-csc/server1
username-as-common-name
plugin /usr/local/lib/openvpn/plugins/openvpn-plugin-auth-script.so /usr/local/sbin/ovpn_auth_verify_async user T G9jYWwgRGF0YWJhc2U= false server1 1194
tls-verify "/usr/local/sbin/ovpn_auth_verify tls 'LogmaCA' 1"
lport 1194
management /var/etc/openvpn/server1.sock unix
push "route 10.3.1.0 255.255.255.0"
ca /var/etc/openvpn/server1.ca
cert /var/etc/openvpn/server1.cert
key /var/etc/openvpn/server1.key
dh /etc/dh-parameters.2048
crl-verify /var/etc/openvpn/server1.crl-verify
tls-auth /var/etc/openvpn/server1.tls-auth 0
ncp-ciphers AES-128-GCM
persist-remote-ip
float
topology subnet
Code: Select all
Feb 19 11:35:45 openvpn 21777 lgms2/y.y.y.14:40874 SIGUSR1[soft,ping-restart] received, client-instance restarting
Feb 19 11:35:45 openvpn 21777 lgms2/y.y.y.14:40874 [lgms2] Inactivity timeout (--ping-restart), restarting
Feb 19 11:35:45 openvpn 21777 jms/x.x.x.37:1194 SIGUSR1[soft,ping-restart] received, client-instance restarting
Feb 19 11:35:45 openvpn 21777 jms/x.x.x.37:1194 [jms] Inactivity timeout (--ping-restart), restarting
Feb 19 11:35:18 openvpn 21777 MANAGEMENT: Client disconnected
Feb 19 11:35:18 openvpn 21777 MANAGEMENT: CMD 'quit'
Feb 19 11:35:17 openvpn 21777 MANAGEMENT: CMD 'status 2'
Feb 19 11:35:17 openvpn 21777 MANAGEMENT: Client connected from /var/etc/openvpn/server1.sock
Feb 19 11:34:16 openvpn 21777 MANAGEMENT: Client disconnected
Feb 19 11:34:16 openvpn 21777 MANAGEMENT: CMD 'quit'
Feb 19 11:34:15 openvpn 21777 MANAGEMENT: CMD 'status 2'
Feb 19 11:34:15 openvpn 21777 MANAGEMENT: Client connected from /var/etc/openvpn/server1.sock
Feb 19 11:34:11 openvpn 21777 MANAGEMENT: Client disconnected
Feb 19 11:34:11 openvpn 21777 MANAGEMENT: CMD 'status 2'
Feb 19 11:34:11 openvpn 21777 MANAGEMENT: Client connected from /var/etc/openvpn/server1.sock
Feb 19 11:33:14 openvpn 21777 MANAGEMENT: Client disconnected
Feb 19 11:33:14 openvpn 21777 MANAGEMENT: CMD 'quit'
Feb 19 11:33:14 openvpn 21777 MANAGEMENT: CMD 'status 2'
Feb 19 11:33:13 openvpn 21777 MANAGEMENT: Client connected from /var/etc/openvpn/server1.sock
Feb 19 11:32:48 openvpn 21777 lgms2/y.y.y.14:40874 Incoming Data Channel: Cipher 'AES-128-GCM' initialized with 128 bit key
Feb 19 11:32:48 openvpn 21777 lgms2/y.y.y.14:40874 Outgoing Data Channel: Cipher 'AES-128-GCM' initialized with 128 bit key
Feb 19 11:32:48 openvpn 21777 lgms2/y.y.y.14:40874 Data Channel MTU parms [ L:1549 D:1450 EF:49 EB:406 ET:0 EL:3 ]
Feb 19 11:32:48 openvpn 21777 lgms2/y.y.y.14:40874 Data Channel: using negotiated cipher 'AES-128-GCM'
Feb 19 11:32:48 openvpn 21777 lgms2/y.y.y.14:40874 SENT CONTROL [lgms2]: 'PUSH_REPLY,route 10.3.1.0 255.255.255.0,route-gateway 10.3.2.1,topology subnet,ping 10,ping-restart 60,ifconfig 10.3.2.2 255.255.255.0,peer-id 1,cipher AES-128-GCM' (status=1)
Feb 19 11:32:48 openvpn 21777 lgms2/y.y.y.14:40874 PUSH: Received control message: 'PUSH_REQUEST'
Feb 19 11:32:47 openvpn 21777 lgms2/y.y.y.14:40874 MULTI: primary virtual IP for lgms2/y.y.y.14:40874: 10.3.2.2
Feb 19 11:32:47 openvpn 21777 lgms2/y.y.y.14:40874 MULTI: Learn: 10.3.2.2 -> lgms2/y.y.y.14:40874
Feb 19 11:32:47 openvpn 21777 lgms2/y.y.y.14:40874 OPTIONS IMPORT: reading client specific options from: /tmp/openvpn_cc_5680581374075e5b21c2ba43e528ca55.tmp
Feb 19 11:32:47 openvpn 21777 lgms2/y.y.y.14:40874 MULTI_sva: pool returned IPv4=10.3.2.2, IPv6=(Not enabled)
Feb 19 11:32:46 openvpn user 'lgms2' authenticated
Feb 19 11:32:46 openvpn 21777 y.y.y.14:40874 [lgms2] Peer Connection Initiated with [AF_INET]y.y.y.14:40874
Feb 19 11:32:46 openvpn 21777 y.y.y.14:40874 Control Channel: TLSv1.2, cipher TLSv1/SSLv3 ECDHE-RSA-AES256-GCM-SHA384, 2048 bit RSA
Feb 19 11:32:46 openvpn 21777 y.y.y.14:40874 TLS: Username/Password authentication deferred for username 'lgms2' [CN SET]
Feb 19 11:32:46 openvpn 21777 y.y.y.14:40874 PLUGIN_CALL: POST /usr/local/lib/openvpn/plugins/openvpn-plugin-auth-script.so/PLUGIN_AUTH_USER_PASS_VERIFY status=2
Feb 19 11:32:46 openvpn 21777 y.y.y.14:40874 peer info: IV_GUI_VER=OpenVPN_GUI_11
Feb 19 11:32:46 openvpn 21777 y.y.y.14:40874 peer info: IV_TCPNL=1
Feb 19 11:32:46 openvpn 21777 y.y.y.14:40874 peer info: IV_COMP_STUBv2=1
Feb 19 11:32:46 openvpn 21777 y.y.y.14:40874 peer info: IV_COMP_STUB=1
Feb 19 11:32:46 openvpn 21777 y.y.y.14:40874 peer info: IV_LZO=1
Feb 19 11:32:46 openvpn 21777 y.y.y.14:40874 peer info: IV_LZ4v2=1
Feb 19 11:32:46 openvpn 21777 y.y.y.14:40874 peer info: IV_LZ4=1
Feb 19 11:32:46 openvpn 21777 y.y.y.14:40874 peer info: IV_NCP=2
Feb 19 11:32:46 openvpn 21777 y.y.y.14:40874 peer info: IV_PROTO=2
Feb 19 11:32:46 openvpn 21777 y.y.y.14:40874 peer info: IV_PLAT=win
Feb 19 11:32:46 openvpn 21777 y.y.y.14:40874 peer info: IV_VER=2.4.8
Feb 19 11:32:46 openvpn 21777 y.y.y.14:40874 VERIFY OK: depth=0, C=GB, ST=Greater Manchester, L=Manchester, O=Lgms, CN=lgms2
Feb 19 11:32:46 openvpn 21777 y.y.y.14:40874 VERIFY SCRIPT OK: depth=0, C=GB, ST=Greater Manchester, L=Manchester, O=Lgms, CN=lgms2
Feb 19 11:32:46 openvpn 21777 y.y.y.14:40874 VERIFY OK: depth=1, CN=LgmsVPN, C=GB, ST=Greater Manchester, L=Manchester, O=Lgms
Feb 19 11:32:46 openvpn 21777 y.y.y.14:40874 VERIFY SCRIPT OK: depth=1, CN=LgmsVPN, C=GB, ST=Greater Manchester, L=Manchester, O=Lgms
Feb 19 11:32:46 openvpn 21777 y.y.y.14:40874 TLS: Initial packet from [AF_INET]y.y.y.14:40874, sid=617a20f3 1d596f68
Feb 19 11:32:46 openvpn 21777 y.y.y.14:40874 Expected Remote Options String (VER=V4): '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'
Feb 19 11:32:46 openvpn 21777 y.y.y.14:40874 Local Options String (VER=V4): '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'
Feb 19 11:32:46 openvpn 21777 y.y.y.14:40874 Data Channel MTU parms [ L:1621 D:1450 EF:121 EB:406 ET:0 EL:3 ]
Feb 19 11:32:46 openvpn 21777 y.y.y.14:40874 Control Channel MTU parms [ L:1621 D:1172 EF:78 EB:0 ET:0 EL:3 ]
Feb 19 11:32:46 openvpn 21777 y.y.y.14:40874 Re-using SSL/TLS context
Feb 19 11:32:46 openvpn 21777 MULTI: multi_create_instance called
Feb 19 11:32:12 openvpn 21777 MANAGEMENT: Client disconnected
Feb 19 11:32:12 openvpn 21777 MANAGEMENT: CMD 'quit'
Feb 19 11:32:12 openvpn 21777 MANAGEMENT: CMD 'status 2'
Feb 19 11:32:12 openvpn 21777 MANAGEMENT: Client connected from /var/etc/openvpn/server1.sock
Feb 19 11:31:51 openvpn 21777 y.y.y.14:40874 SIGTERM[soft,delayed-exit] received, client-instance exiting
Feb 19 11:31:46 openvpn 21777 y.y.y.14:40874 SENT CONTROL [lgms2]: 'AUTH_FAILED' (status=1)
Feb 19 11:31:46 openvpn 21777 y.y.y.14:40874 Delayed exit in 5 seconds
Feb 19 11:31:46 openvpn 21777 y.y.y.14:40874 PUSH: Received control message: 'PUSH_REQUEST'
Feb 19 11:31:45 openvpn user 'lgms2' could not authenticate.
Feb 19 11:31:45 openvpn 21777 y.y.y.14:40874 [lgms2] Peer Connection Initiated with [AF_INET]y.y.y.14:40874
Feb 19 11:31:45 openvpn 21777 y.y.y.14:40874 Control Channel: TLSv1.2, cipher TLSv1/SSLv3 ECDHE-RSA-AES256-GCM-SHA384, 2048 bit RSA
Feb 19 11:31:45 openvpn 21777 y.y.y.14:40874 TLS: Username/Password authentication deferred for username 'lgms2' [CN SET]
Feb 19 11:31:45 openvpn 21777 y.y.y.14:40874 PLUGIN_CALL: POST /usr/local/lib/openvpn/plugins/openvpn-plugin-auth-script.so/PLUGIN_AUTH_USER_PASS_VERIFY status=2
Feb 19 11:31:45 openvpn 21777 y.y.y.14:40874 peer info: IV_GUI_VER=OpenVPN_GUI_11
Feb 19 11:31:45 openvpn 21777 y.y.y.14:40874 peer info: IV_TCPNL=1
Feb 19 11:31:45 openvpn 21777 y.y.y.14:40874 peer info: IV_COMP_STUBv2=1
Feb 19 11:31:45 openvpn 21777 y.y.y.14:40874 peer info: IV_COMP_STUB=1
Feb 19 11:31:45 openvpn 21777 y.y.y.14:40874 peer info: IV_LZO=1
Feb 19 11:31:45 openvpn 21777 y.y.y.14:40874 peer info: IV_LZ4v2=1
Feb 19 11:31:45 openvpn 21777 y.y.y.14:40874 peer info: IV_LZ4=1
Feb 19 11:31:45 openvpn 21777 y.y.y.14:40874 peer info: IV_NCP=2
Feb 19 11:31:45 openvpn 21777 y.y.y.14:40874 peer info: IV_PROTO=2
Feb 19 11:31:45 openvpn 21777 y.y.y.14:40874 peer info: IV_PLAT=win
Feb 19 11:31:45 openvpn 21777 y.y.y.14:40874 peer info: IV_VER=2.4.8
Feb 19 11:31:45 openvpn 21777 y.y.y.14:40874 VERIFY OK: depth=0, C=GB, ST=Greater Manchester, L=Manchester, O=Lgms, CN=lgms2
Feb 19 11:31:45 openvpn 21777 y.y.y.14:40874 VERIFY SCRIPT OK: depth=0, C=GB, ST=Greater Manchester, L=Manchester, O=Lgms, CN=lgms2
Feb 19 11:31:45 openvpn 21777 y.y.y.14:40874 VERIFY OK: depth=1, CN=LgmsVPN, C=GB, ST=Greater Manchester, L=Manchester, O=Lgms
Feb 19 11:31:45 openvpn 21777 y.y.y.14:40874 VERIFY SCRIPT OK: depth=1, CN=LgmsVPN, C=GB, ST=Greater Manchester, L=Manchester, O=Lgms
Feb 19 11:31:45 openvpn 21777 y.y.y.14:40874 TLS: Initial packet from [AF_INET]y.y.y.14:40874, sid=4fb1e3b7 bae76bc8
Feb 19 11:31:45 openvpn 21777 y.y.y.14:40874 Expected Remote Options String (VER=V4): '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'
Feb 19 11:31:45 openvpn 21777 y.y.y.14:40874 Local Options String (VER=V4): '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'
Feb 19 11:31:45 openvpn 21777 y.y.y.14:40874 Data Channel MTU parms [ L:1621 D:1450 EF:121 EB:406 ET:0 EL:3 ]
Feb 19 11:31:45 openvpn 21777 y.y.y.14:40874 Control Channel MTU parms [ L:1621 D:1172 EF:78 EB:0 ET:0 EL:3 ]
Feb 19 11:31:45 openvpn 21777 y.y.y.14:40874 Re-using SSL/TLS context
Feb 19 11:31:45 openvpn 21777 MULTI: multi_create_instance called
Feb 19 11:31:38 openvpn 21777 jms/x.x.x.37:1194 MULTI: bad source address from client [::], packet dropped
Feb 19 11:31:38 openvpn 21777 jms/x.x.x.37:1194 Incoming Data Channel: Cipher 'AES-128-GCM' initialized with 128 bit key
Feb 19 11:31:38 openvpn 21777 jms/x.x.x.37:1194 Outgoing Data Channel: Cipher 'AES-128-GCM' initialized with 128 bit key
Feb 19 11:31:38 openvpn 21777 jms/x.x.x.37:1194 Data Channel MTU parms [ L:1549 D:1450 EF:49 EB:406 ET:0 EL:3 ]
Feb 19 11:31:38 openvpn 21777 jms/x.x.x.37:1194 Data Channel: using negotiated cipher 'AES-128-GCM'
Feb 19 11:31:38 openvpn 21777 jms/x.x.x.37:1194 SENT CONTROL [jms]: 'PUSH_REPLY,route 10.3.1.0 255.255.255.0,route-gateway 10.3.2.1,topology subnet,ping 10,ping-restart 60,ifconfig 10.3.2.3 255.255.255.0,peer-id 0,cipher AES-128-GCM' (status=1)
Feb 19 11:31:38 openvpn 21777 jms/x.x.x.37:1194 PUSH: Received control message: 'PUSH_REQUEST'
Feb 19 11:31:38 openvpn 21777 jms/x.x.x.37:1194 MULTI: primary virtual IP for jms/x.x.x.37:1194: 10.3.2.3
Feb 19 11:31:38 openvpn 21777 jms/x.x.x.37:1194 MULTI: Learn: 10.3.2.3 -> jms/x.x.x.37:1194
Feb 19 11:31:38 openvpn 21777 jms/x.x.x.37:1194 OPTIONS IMPORT: reading client specific options from: /tmp/openvpn_cc_2be551311aaaf39e156994100fcb18db.tmp
Feb 19 11:31:38 openvpn 21777 jms/x.x.x.37:1194 MULTI_sva: pool returned IPv4=10.3.2.3, IPv6=(Not enabled)
Feb 19 11:31:37 openvpn user 'jms' authenticated
Feb 19 11:31:37 openvpn 21777 x.x.x.37:1194 [jms] Peer Connection Initiated with [AF_INET]x.x.x.37:1194
Feb 19 11:31:37 openvpn 21777 x.x.x.37:1194 Control Channel: TLSv1.2, cipher TLSv1/SSLv3 ECDHE-RSA-AES256-GCM-SHA384, 2048 bit RSA
Feb 19 11:31:37 openvpn 21777 x.x.x.37:1194 TLS: Username/Password authentication deferred for username 'jms' [CN SET]
Feb 19 11:31:37 openvpn 21777 x.x.x.37:1194 PLUGIN_CALL: POST /usr/local/lib/openvpn/plugins/openvpn-plugin-auth-script.so/PLUGIN_AUTH_USER_PASS_VERIFY status=2
Feb 19 11:31:37 openvpn 21777 x.x.x.37:1194 peer info: IV_GUI_VER=OpenVPN_GUI_11
Feb 19 11:31:37 openvpn 21777 x.x.x.37:1194 peer info: IV_TCPNL=1
Feb 19 11:31:37 openvpn 21777 x.x.x.37:1194 peer info: IV_COMP_STUBv2=1
Feb 19 11:31:37 openvpn 21777 x.x.x.37:1194 peer info: IV_COMP_STUB=1
Feb 19 11:31:37 openvpn 21777 x.x.x.37:1194 peer info: IV_LZO=1
Feb 19 11:31:37 openvpn 21777 x.x.x.37:1194 peer info: IV_LZ4v2=1
Feb 19 11:31:37 openvpn 21777 x.x.x.37:1194 peer info: IV_LZ4=1
Feb 19 11:31:37 openvpn 21777 x.x.x.37:1194 peer info: IV_NCP=2
Feb 19 11:31:37 openvpn 21777 x.x.x.37:1194 peer info: IV_PROTO=2
Feb 19 11:31:37 openvpn 21777 x.x.x.37:1194 peer info: IV_PLAT=win
Feb 19 11:31:37 openvpn 21777 x.x.x.37:1194 peer info: IV_VER=2.4.8
Feb 19 11:31:37 openvpn 21777 x.x.x.37:1194 VERIFY OK: depth=0, C=GB, ST=Greater Manchester, L=Manchester, O=Lgms, CN=jms
Feb 19 11:31:37 openvpn 21777 x.x.x.37:1194 VERIFY SCRIPT OK: depth=0, C=GB, ST=Greater Manchester, L=Manchester, O=Lgms, CN=jms
Feb 19 11:31:37 openvpn 21777 x.x.x.37:1194 VERIFY OK: depth=1, CN=LgmsVPN, C=GB, ST=Greater Manchester, L=Manchester, O=Lgms
Feb 19 11:31:37 openvpn 21777 x.x.x.37:1194 VERIFY SCRIPT OK: depth=1, CN=LgmsVPN, C=GB, ST=Greater Manchester, L=Manchester, O=Lgms
Feb 19 11:31:37 openvpn 21777 x.x.x.37:1194 TLS: Initial packet from [AF_INET]x.x.x.37:1194, sid=5fba3f08 54914ad0
Feb 19 11:31:37 openvpn 21777 x.x.x.37:1194 Expected Remote Options String (VER=V4): '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'
Feb 19 11:31:37 openvpn 21777 x.x.x.37:1194 Local Options String (VER=V4): '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'
Feb 19 11:31:37 openvpn 21777 x.x.x.37:1194 Data Channel MTU parms [ L:1621 D:1450 EF:121 EB:406 ET:0 EL:3 ]
Feb 19 11:31:37 openvpn 21777 x.x.x.37:1194 Control Channel MTU parms [ L:1621 D:1172 EF:78 EB:0 ET:0 EL:3 ]
Feb 19 11:31:37 openvpn 21777 x.x.x.37:1194 Re-using SSL/TLS context
Feb 19 11:31:37 openvpn 21777 MULTI: multi_create_instance called
Feb 19 11:31:27 openvpn 21777 jms/y.y.y.14:40874 SIGTERM[soft,delayed-exit] received, client-instance exiting
Feb 19 11:31:22 openvpn 21777 jms/y.y.y.14:40874 SENT CONTROL [lgms2]: 'AUTH_FAILED' (status=1)
Feb 19 11:31:22 openvpn 21777 jms/y.y.y.14:40874 Delayed exit in 5 seconds
Feb 19 11:31:22 openvpn 21777 jms/y.y.y.14:40874 PUSH: Received control message: 'PUSH_REQUEST'
Feb 19 11:31:21 openvpn user 'lgms2' authenticated
Feb 19 11:31:21 openvpn 21777 jms/y.y.y.14:40874 Control Channel: TLSv1.2, cipher TLSv1/SSLv3 ECDHE-RSA-AES256-GCM-SHA384, 2048 bit RSA
Feb 19 11:31:21 openvpn 21777 jms/y.y.y.14:40874 TLS: tls_multi_process: untrusted session promoted to semi-trusted
Feb 19 11:31:21 openvpn 21777 jms/y.y.y.14:40874 TLS: move_session: dest=TM_ACTIVE src=TM_UNTRUSTED reinit_src=1
Feb 19 11:31:21 openvpn 21777 jms/y.y.y.14:40874 TLS Auth Error: Auth Username/Password verification failed for peer
Feb 19 11:31:21 openvpn 21777 jms/y.y.y.14:40874 TLS Auth Error: username attempted to change from 'jms' to 'lgms2' -- tunnel disabled
Feb 19 11:31:21 openvpn 21777 jms/y.y.y.14:40874 PLUGIN_CALL: POST /usr/local/lib/openvpn/plugins/openvpn-plugin-auth-script.so/PLUGIN_AUTH_USER_PASS_VERIFY status=2
Feb 19 11:31:21 openvpn 21777 jms/y.y.y.14:40874 peer info: IV_GUI_VER=OpenVPN_GUI_11
Feb 19 11:31:21 openvpn 21777 jms/y.y.y.14:40874 peer info: IV_TCPNL=1
Feb 19 11:31:21 openvpn 21777 jms/y.y.y.14:40874 peer info: IV_COMP_STUBv2=1
Feb 19 11:31:21 openvpn 21777 jms/y.y.y.14:40874 peer info: IV_COMP_STUB=1
Feb 19 11:31:21 openvpn 21777 jms/y.y.y.14:40874 peer info: IV_LZO=1
Feb 19 11:31:21 openvpn 21777 jms/y.y.y.14:40874 peer info: IV_LZ4v2=1
Feb 19 11:31:21 openvpn 21777 jms/y.y.y.14:40874 peer info: IV_LZ4=1
Feb 19 11:31:21 openvpn 21777 jms/y.y.y.14:40874 peer info: IV_NCP=2
Feb 19 11:31:21 openvpn 21777 jms/y.y.y.14:40874 peer info: IV_PROTO=2
Feb 19 11:31:21 openvpn 21777 jms/y.y.y.14:40874 peer info: IV_PLAT=win
Feb 19 11:31:21 openvpn 21777 jms/y.y.y.14:40874 peer info: IV_VER=2.4.8
Feb 19 11:31:21 openvpn 21777 jms/y.y.y.14:40874 VERIFY OK: depth=0, C=GB, ST=Greater Manchester, L=Manchester, O=Lgms, CN=lgms2
Feb 19 11:31:21 openvpn 21777 jms/y.y.y.14:40874 VERIFY SCRIPT OK: depth=0, C=GB, ST=Greater Manchester, L=Manchester, O=Lgms, CN=lgms2
Feb 19 11:31:21 openvpn 21777 jms/y.y.y.14:40874 VERIFY OK: depth=1, CN=LgmsVPN, C=GB, ST=Greater Manchester, L=Manchester, O=Lgms
Feb 19 11:31:21 openvpn 21777 jms/y.y.y.14:40874 VERIFY SCRIPT OK: depth=1, CN=LgmsVPN, C=GB, ST=Greater Manchester, L=Manchester, O=Lgms
Feb 19 11:31:21 openvpn 21777 jms/y.y.y.14:40874 TLS: new session incoming connection from [AF_INET]y.y.y.14:40874
Feb 19 11:31:12 openvpn 21777 jms/y.y.y.14:40874 Key [AF_INET]y.y.y.14:40874 [0] not initialized (yet), dropping packet.
Feb 19 11:31:10 openvpn 21777 MANAGEMENT: Client disconnected
Feb 19 11:31:10 openvpn 21777 MANAGEMENT: CMD 'quit'
Feb 19 11:31:10 openvpn 21777 MANAGEMENT: CMD 'status 2'
Feb 19 11:31:10 openvpn 21777 MANAGEMENT: Client connected from /var/etc/openvpn/server1.sock
Feb 19 11:31:09 openvpn 21777 jms/y.y.y.14:40874 Key [AF_INET]y.y.y.14:40874 [0] not initialized (yet), dropping packet.
Feb 19 11:31:08 openvpn 21777 jms/y.y.y.14:40874 Key [AF_INET]y.y.y.14:40874 [0] not initialized (yet), dropping packet.
Feb 19 11:30:59 openvpn 21777 jms/y.y.y.14:40874 Key [AF_INET]y.y.y.14:40874 [0] not initialized (yet), dropping packet.
Feb 19 11:30:53 openvpn 21777 jms/y.y.y.14:40874 Key [AF_INET]y.y.y.14:40874 [0] not initialized (yet), dropping packet.
Feb 19 11:30:50 openvpn 21777 jms/y.y.y.14:40874 Key [AF_INET]y.y.y.14:40874 [0] not initialized (yet), dropping packet.
Feb 19 11:30:49 openvpn 21777 jms/y.y.y.14:40874 Key [AF_INET]y.y.y.14:40874 [0] not initialized (yet), dropping packet.
Feb 19 11:30:40 openvpn 21777 jms/y.y.y.14:40874 Key [AF_INET]y.y.y.14:40874 [0] not initialized (yet), dropping packet.
Feb 19 11:30:36 openvpn 21777 jms/y.y.y.14:40874 Key [AF_INET]y.y.y.14:40874 [0] not initialized (yet), dropping packet.
Feb 19 11:30:34 openvpn 21777 jms/y.y.y.14:40874 Key [AF_INET]y.y.y.14:40874 [0] not initialized (yet), dropping packet.
Feb 19 11:30:31 openvpn 21777 jms/y.y.y.14:40874 Key [AF_INET]y.y.y.14:40874 [0] not initialized (yet), dropping packet.
Feb 19 11:30:30 openvpn 21777 jms/y.y.y.14:40874 Key [AF_INET]y.y.y.14:40874 [0] not initialized (yet), dropping packet.
Feb 19 11:30:29 openvpn 21777 jms/y.y.y.14:40874 MULTI: primary virtual IP for jms/y.y.y.14:40874: 10.3.2.3
Feb 19 11:30:29 openvpn 21777 jms/y.y.y.14:40874 MULTI: Learn: 10.3.2.3 -> jms/y.y.y.14:40874
Feb 19 11:30:29 openvpn 21777 jms/y.y.y.14:40874 OPTIONS IMPORT: reading client specific options from: /tmp/openvpn_cc_26c30e2eb33ddf3c47329a9bba9e13fd.tmp
Feb 19 11:30:29 openvpn 21777 jms/y.y.y.14:40874 MULTI_sva: pool returned IPv4=10.3.2.3, IPv6=(Not enabled)
Feb 19 11:30:29 openvpn 21777 peer 0 (jms) floated from x.x.x.37:1194 to [AF_INET]y.y.y.14:40874
Feb 19 11:30:29 openvpn 21777 TLS Error: local/remote TLS keys are out of sync: [AF_INET]x.x.x.37:1194 [0]
Feb 19 11:30:29 openvpn 21777 Float requested for peer 0 to y.y.y.14:40874
Feb 19 11:30:29 openvpn user 'jms' authenticated
Feb 19 11:30:29 openvpn 21777 x.x.x.37:1194 [jms] Peer Connection Initiated with [AF_INET]x.x.x.37:1194
Feb 19 11:30:29 openvpn 21777 x.x.x.37:1194 Control Channel: TLSv1.2, cipher TLSv1/SSLv3 ECDHE-RSA-AES256-GCM-SHA384, 2048 bit RSA
Feb 19 11:30:29 openvpn 21777 x.x.x.37:1194 TLS: Username/Password authentication deferred for username 'jms' [CN SET]
Feb 19 11:30:29 openvpn 21777 x.x.x.37:1194 PLUGIN_CALL: POST /usr/local/lib/openvpn/plugins/openvpn-plugin-auth-script.so/PLUGIN_AUTH_USER_PASS_VERIFY status=2
Feb 19 11:30:29 openvpn 21777 x.x.x.37:1194 peer info: IV_GUI_VER=OpenVPN_GUI_11
Feb 19 11:30:29 openvpn 21777 x.x.x.37:1194 peer info: IV_TCPNL=1
Feb 19 11:30:29 openvpn 21777 x.x.x.37:1194 peer info: IV_COMP_STUBv2=1
Feb 19 11:30:29 openvpn 21777 x.x.x.37:1194 peer info: IV_COMP_STUB=1
Feb 19 11:30:29 openvpn 21777 x.x.x.37:1194 peer info: IV_LZO=1
Feb 19 11:30:29 openvpn 21777 x.x.x.37:1194 peer info: IV_LZ4v2=1
Feb 19 11:30:29 openvpn 21777 x.x.x.37:1194 peer info: IV_LZ4=1
Feb 19 11:30:29 openvpn 21777 x.x.x.37:1194 peer info: IV_NCP=2
Feb 19 11:30:29 openvpn 21777 x.x.x.37:1194 peer info: IV_PROTO=2
Feb 19 11:30:29 openvpn 21777 x.x.x.37:1194 peer info: IV_PLAT=win
Feb 19 11:30:29 openvpn 21777 x.x.x.37:1194 peer info: IV_VER=2.4.8
Feb 19 11:30:29 openvpn 21777 x.x.x.37:1194 VERIFY OK: depth=0, C=GB, ST=Greater Manchester, L=Manchester, O=Lgms, CN=jms
Feb 19 11:30:29 openvpn 21777 x.x.x.37:1194 VERIFY SCRIPT OK: depth=0, C=GB, ST=Greater Manchester, L=Manchester, O=Lgms, CN=jms
Feb 19 11:30:29 openvpn 21777 x.x.x.37:1194 VERIFY OK: depth=1, CN=LgmsVPN, C=GB, ST=Greater Manchester, L=Manchester, O=Lgms
Feb 19 11:30:29 openvpn 21777 x.x.x.37:1194 VERIFY SCRIPT OK: depth=1, CN=LgmsVPN, C=GB, ST=Greater Manchester, L=Manchester, O=Lgms
Feb 19 11:30:29 openvpn 21777 x.x.x.37:1194 TLS: Initial packet from [AF_INET]x.x.x.37:1194, sid=3b67cb6b 6f72b1f6
Feb 19 11:30:29 openvpn 21777 x.x.x.37:1194 Expected Remote Options String (VER=V4): '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'
Feb 19 11:30:29 openvpn 21777 x.x.x.37:1194 Local Options String (VER=V4): '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'
Feb 19 11:30:29 openvpn 21777 x.x.x.37:1194 Data Channel MTU parms [ L:1621 D:1450 EF:121 EB:406 ET:0 EL:3 ]
Feb 19 11:30:29 openvpn 21777 x.x.x.37:1194 Control Channel MTU parms [ L:1621 D:1172 EF:78 EB:0 ET:0 EL:3 ]
Feb 19 11:30:29 openvpn 21777 x.x.x.37:1194 Re-using SSL/TLS context
Feb 19 11:30:29 openvpn 21777 MULTI: multi_create_instance called
Feb 19 11:30:16 openvpn 21777 lgms2/y.y.y.14:40874 SIGUSR1[soft,ping-restart] received, client-instance restarting
Feb 19 11:30:16 openvpn 21777 lgms2/y.y.y.14:40874 [lgms2] Inactivity timeout (--ping-restart), restart