Hi,
I have a problem with a working OpenVPN setup, where the connection drops and the client fails to reconnect logging continuous TLS key negotiation failures. The client is connected via a 3G router and I presume there are occasional network outages, but I can't prove it yet. When the client fails to reconnect, stopping the OpenVPN server for a few minutes and then restarting it restores the connection.
When the connection is working I get 'TLS: tls_process: killed expiring key' errors every hour in the logs, but I'm not sure if this is related.
I'd appreciate any help in resolving this. I attach both the server and client configs below and annotated excerpts from the server and client syslogs.
A few things to note:
1. the client timezone is set to UTC and the server is BST, hence the one hour difference in timestamps; and
2. while investigating I noticed the server was not synchronised via NTP, hence the ~30 second discrepancy between client and server timestamps. I have corrected this, but it has not resolved the TLS key expiry issue and I presume it won't affect the main issue.
Thanks,
Chris
Server config:
proto udp
port 1194
dev tun
status /var/log/openvpn_status
management 127.0.0.1 10000
ca xx.crt
cert xx.crt
key xx.key # This file should be kept secret
dh dh1024.pem
topology subnet
server 172.30.10.0 255.255.255.0
push "route 192.168.0.0 255.255.0.0"
push "route 172.16.0.0 255.240.0.0"
push "explicit-exit-notify 3"
client-config-dir ccd
# client config for X99880 simply contains: ifconfig-push 172.30.10.2 255.255.255.0
keepalive 10 120
comp-lzo
user nobody
group nogroup
persist-key
persist-tun
status openvpn-status.log
verb 3
Client config:
client
dev tun
proto udp
remote xx.xx.xx.xx 1194
resolv-retry infinite
nobind
user nobody
group nogroup
persist-key
persist-tun
mute-replay-warnings
ca xx.crt
cert xx.crt
key xx.key
ns-cert-type server
comp-lzo
verb 3
mute 20
Client syslog:
Jul 7 22:49:28 X99880 ovpn-client[1076]: 1191 variation(s) on previous 20 message(s) suppressed by --mute
Jul 7 22:49:28 X99880 ovpn-client[1076]: read UDPv4 [EHOSTUNREACH]: No route to host (code=113)
Jul 7 22:50:53 X99880 ovpn-client[1076]: TLS: tls_process: killed expiring key
Jul 7 22:51:03 X99880 ovpn-client[1076]: TLS: soft reset sec=0 bytes=363393/0 pkts=2231/0
Jul 7 22:51:10 X99880 ovpn-client[1076]: [openvpn_server] Inactivity timeout (--ping-restart), restarting
Jul 7 22:51:10 X99880 ovpn-client[1076]: TCP/UDP: Closing socket
Jul 7 22:51:10 X99880 ovpn-client[1076]: SIGUSR1[soft,ping-restart] received, process restarting
Jul 7 22:51:10 X99880 ovpn-client[1076]: Restart pause, 2 second(s)
Jul 7 22:51:12 X99880 ovpn-client[1076]: Re-using SSL/TLS context
Jul 7 22:51:12 X99880 ovpn-client[1076]: LZO compression initialized
Jul 7 22:51:12 X99880 ovpn-client[1076]: Control Channel MTU parms [ L:1542 D:138 EF:38 EB:0 ET:0 EL:0 ]
Jul 7 22:51:12 X99880 ovpn-client[1076]: Data Channel MTU parms [ L:1542 D:1450 EF:42 EB:135 ET:0 EL:0 AF:3/1 ]
Jul 7 22:51:12 X99880 ovpn-client[1076]: Local Options hash (VER=V4): '41690919'
Jul 7 22:51:12 X99880 ovpn-client[1076]: Expected Remote Options hash (VER=V4): '530fdded'
Jul 7 22:51:12 X99880 ovpn-client[1076]: Socket Buffers: R=[112640->131072] S=[112640->131072]
Jul 7 22:51:12 X99880 ovpn-client[1076]: UDPv4 link local: [undef]
Jul 7 22:51:12 X99880 ovpn-client[1076]: UDPv4 link remote: xx.xx.xx.xx:1194
Jul 7 22:52:12 X99880 ovpn-client[1076]: TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity)
Jul 7 22:52:12 X99880 ovpn-client[1076]: TLS Error: TLS handshake failed
Jul 7 22:52:12 X99880 ovpn-client[1076]: TCP/UDP: Closing socket
Jul 7 22:52:12 X99880 ovpn-client[1076]: SIGUSR1[soft,tls-error] received, process restarting
Jul 7 22:52:12 X99880 ovpn-client[1076]: Restart pause, 2 second(s)
Jul 7 22:52:14 X99880 ovpn-client[1076]: Re-using SSL/TLS context
Jul 7 22:52:14 X99880 ovpn-client[1076]: LZO compression initialized
Jul 7 22:52:14 X99880 ovpn-client[1076]: Control Channel MTU parms [ L:1542 D:138 EF:38 EB:0 ET:0 EL:0 ]
Jul 7 22:52:14 X99880 ovpn-client[1076]: Data Channel MTU parms [ L:1542 D:1450 EF:42 EB:135 ET:0 EL:0 AF:3/1 ]
Jul 7 22:52:14 X99880 ovpn-client[1076]: Local Options hash (VER=V4): '41690919'
Jul 7 22:52:14 X99880 ovpn-client[1076]: Expected Remote Options hash (VER=V4): '530fdded'
Jul 7 22:52:14 X99880 ovpn-client[1076]: Socket Buffers: R=[112640->131072] S=[112640->131072]
Jul 7 22:52:14 X99880 ovpn-client[1076]: UDPv4 link local: [undef]
Jul 7 22:52:14 X99880 ovpn-client[1076]: UDPv4 link remote: xx.xx.xx.xx:1194
**** TLS key negotiation error repeated every minute ****
**** push 'explicit-exit-notify 3' added to the server config and restarted the server, which caused the client to crash out! ****
Jul 8 09:38:31 X99880 ovpn-client[1076]: read UDPv4 [ECONNREFUSED]: Connection refused (code=111)
Jul 8 09:38:34 X99880 ovpn-client[1076]: TLS: Initial packet from xx.xx.xx.xx:1194, sid=cdb9fff3 1f77c48e
Jul 8 09:38:39 X99880 ovpn-client[1076]: VERIFY OK: depth=1, /C=UK/ST=xx/L=xx/O=Oozlum-BCC/CN=xx/emailAddress=xx
Jul 8 09:38:39 X99880 ovpn-client[1076]: VERIFY OK: nsCertType=SERVER
Jul 8 09:38:39 X99880 ovpn-client[1076]: VERIFY OK: depth=0, /C=UK/ST=xx/L=xx/O=Oozlum-BCC/CN=openvpn_server/emailAddress=xx
Jul 8 09:38:45 X99880 ovpn-client[1076]: Data Channel Encrypt: Cipher 'BF-CBC' initialized with 128 bit key
Jul 8 09:38:45 X99880 ovpn-client[1076]: Data Channel Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Jul 8 09:38:45 X99880 ovpn-client[1076]: Data Channel Decrypt: Cipher 'BF-CBC' initialized with 128 bit key
Jul 8 09:38:45 X99880 ovpn-client[1076]: Data Channel Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Jul 8 09:38:45 X99880 ovpn-client[1076]: Control Channel: TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA, 1024 bit RSA
Jul 8 09:38:45 X99880 ovpn-client[1076]: [openvpn_server] Peer Connection Initiated with xx.xx.xx.xx:1194
Jul 8 09:38:46 X99880 ovpn-client[1076]: SENT CONTROL [openvpn_server]: 'PUSH_REQUEST' (status=1)
Jul 8 09:38:47 X99880 ovpn-client[1076]: PUSH: Received control message: 'PUSH_REPLY,route 192.168.0.0 255.255.0.0,route 172.16.0.0 255.240.0.0,explicit-exit-notify 3,route-gateway 172.30.10.1,topology subnet,ping 10,ping-restart 120,ifconfig 172.30.10.2 255.255.255.0'
Jul 8 09:38:47 X99880 ovpn-client[1076]: OPTIONS IMPORT: timers and/or timeouts modified
Jul 8 09:38:47 X99880 ovpn-client[1076]: OPTIONS IMPORT: explicit notify parm(s) modified
Jul 8 09:38:47 X99880 ovpn-client[1076]: OPTIONS IMPORT: --ifconfig/up options modified
Jul 8 09:38:47 X99880 ovpn-client[1076]: OPTIONS IMPORT: route options modified
Jul 8 09:38:47 X99880 ovpn-client[1076]: OPTIONS IMPORT: route-related options modified
Jul 8 09:38:47 X99880 ovpn-client[1076]: Preserving previous TUN/TAP instance: tun0
Jul 8 09:38:47 X99880 ovpn-client[1076]: NOTE: Pulled options changed on restart, will need to close and reopen TUN/TAP device.
Jul 8 09:38:47 X99880 ovpn-client[1076]: /sbin/route del -net 172.16.0.0 netmask 255.240.0.0
Jul 8 09:38:47 X99880 ovpn-client[1076]: ERROR: Linux route delete command failed: external program exited with error status: 7
Jul 8 09:38:47 X99880 ovpn-client[1076]: /sbin/route del -net 192.168.0.0 netmask 255.255.0.0
Jul 8 09:38:47 X99880 ovpn-client[1076]: ERROR: Linux route delete command failed: external program exited with error status: 7
Jul 8 09:38:47 X99880 ovpn-client[1076]: Closing TUN/TAP interface
Jul 8 09:38:47 X99880 ovpn-client[1076]: /sbin/ifconfig tun0 0.0.0.0
Jul 8 09:38:47 X99880 ovpn-client[1076]: Linux ip addr del failed: external program exited with error status: 255
Jul 8 09:38:47 X99880 kernel: device tun0 left promiscuous mode
Jul 8 09:38:48 X99880 ovpn-client[1076]: ROUTE default_gateway=10.42.41.1
Jul 8 09:38:48 X99880 ovpn-client[1076]: Note: Cannot ioctl TUNSETIFF tun: Operation not permitted (errno=1)
Jul 8 09:38:48 X99880 ovpn-client[1076]: Note: Attempting fallback to kernel 2.2 TUN/TAP interface
Jul 8 09:38:48 X99880 ovpn-client[1076]: Cannot allocate TUN/TAP dev dynamically
Jul 8 09:38:48 X99880 ovpn-client[1076]: Exiting
**** openvpn restarted manually on client. ****
Jul 8 12:47:11 X99880 ovpn-client[7118]: OpenVPN 2.1_rc11 arm-unknown-linux-gnueabi [SSL] [LZO2] [EPOLL] [PKCS11] built on Sep 18 2008
Jul 8 12:47:11 X99880 ovpn-client[7118]: /usr/bin/openssl-vulnkey -q -b 1024 -m <modulus omitted>
Jul 8 12:47:14 X99880 ovpn-client[7118]: LZO compression initialized
Jul 8 12:47:14 X99880 ovpn-client[7118]: Control Channel MTU parms [ L:1542 D:138 EF:38 EB:0 ET:0 EL:0 ]
Jul 8 12:47:14 X99880 ovpn-client[7118]: Data Channel MTU parms [ L:1542 D:1450 EF:42 EB:135 ET:0 EL:0 AF:3/1 ]
Jul 8 12:47:14 X99880 ovpn-client[7118]: Local Options hash (VER=V4): '41690919'
Jul 8 12:47:14 X99880 ovpn-client[7118]: Expected Remote Options hash (VER=V4): '530fdded'
Jul 8 12:47:14 X99880 ovpn-client[7120]: NOTE: UID/GID downgrade will be delayed because of --client, --pull, or --up-delay
Jul 8 12:47:14 X99880 ovpn-client[7120]: Socket Buffers: R=[112640->131072] S=[112640->131072]
Jul 8 12:47:14 X99880 ovpn-client[7120]: UDPv4 link local: [undef]
Jul 8 12:47:14 X99880 ovpn-client[7120]: UDPv4 link remote: xx.xx.xx.xx:1194
Jul 8 12:47:15 X99880 ovpn-client[7120]: TLS: Initial packet from xx.xx.xx.xx:1194, sid=536fe624 e01057c1
Jul 8 12:47:16 X99880 ovpn-client[7120]: VERIFY OK: depth=1, /C=UK/ST=xx/L=xx/O=Oozlum-BCC/CN=xx/emailAddress=xx
Jul 8 12:47:16 X99880 ovpn-client[7120]: VERIFY OK: nsCertType=SERVER
Jul 8 12:47:16 X99880 ovpn-client[7120]: VERIFY OK: depth=0, /C=UK/ST=xx/L=xx/O=Oozlum-BCC/CN=openvpn_server/emailAddress=xx
Jul 8 12:47:18 X99880 ovpn-client[7120]: Data Channel Encrypt: Cipher 'BF-CBC' initialized with 128 bit key
Jul 8 12:47:18 X99880 ovpn-client[7120]: Data Channel Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Jul 8 12:47:18 X99880 ovpn-client[7120]: Data Channel Decrypt: Cipher 'BF-CBC' initialized with 128 bit key
Jul 8 12:47:18 X99880 ovpn-client[7120]: Data Channel Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Jul 8 12:47:18 X99880 ovpn-client[7120]: Control Channel: TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA, 1024 bit RSA
Jul 8 12:47:18 X99880 ovpn-client[7120]: [openvpn_server] Peer Connection Initiated with xx.xx.xx.xx:1194
Jul 8 12:47:19 X99880 ovpn-client[7120]: SENT CONTROL [openvpn_server]: 'PUSH_REQUEST' (status=1)
Jul 8 12:47:19 X99880 ovpn-client[7120]: PUSH: Received control message: 'PUSH_REPLY,route 192.168.0.0 255.255.0.0,route 172.16.0.0 255.240.0.0,explicit-exit-notify 3,route-gateway 172.30.10.1,topology subnet,ping 10,ping-restart 120,ifconfig 172.30.10.2 255.255.255.0'
Jul 8 12:47:19 X99880 ovpn-client[7120]: OPTIONS IMPORT: timers and/or timeouts modified
Jul 8 12:47:19 X99880 ovpn-client[7120]: OPTIONS IMPORT: explicit notify parm(s) modified
Jul 8 12:47:19 X99880 ovpn-client[7120]: OPTIONS IMPORT: --ifconfig/up options modified
Jul 8 12:47:19 X99880 ovpn-client[7120]: OPTIONS IMPORT: route options modified
Jul 8 12:47:19 X99880 ovpn-client[7120]: OPTIONS IMPORT: route-related options modified
Jul 8 12:47:19 X99880 ovpn-client[7120]: ROUTE default_gateway=10.42.41.1
Jul 8 12:47:19 X99880 ovpn-client[7120]: TUN/TAP device tun0 opened
Jul 8 12:47:19 X99880 ovpn-client[7120]: TUN/TAP TX queue length set to 100
Jul 8 12:47:19 X99880 ovpn-client[7120]: /sbin/ifconfig tun0 172.30.10.2 netmask 255.255.255.0 mtu 1500 broadcast 172.30.10.255
Jul 8 12:47:19 X99880 ovpn-client[7120]: /sbin/route add -net 192.168.0.0 netmask 255.255.0.0 gw 172.30.10.1
Jul 8 12:47:19 X99880 ovpn-client[7120]: /sbin/route add -net 172.16.0.0 netmask 255.240.0.0 gw 172.30.10.1
Jul 8 12:47:19 X99880 ovpn-client[7120]: GID set to nogroup
Jul 8 12:47:19 X99880 ovpn-client[7120]: UID set to nobody
Jul 8 12:47:19 X99880 ovpn-client[7120]: Initialization Sequence Completed
Jul 8 13:47:23 X99880 ovpn-client[7120]: VERIFY OK: depth=1, /C=UK/ST=xx/L=xx/O=Oozlum-BCC/CN=xx/emailAddress=xx
Jul 8 13:47:23 X99880 ovpn-client[7120]: VERIFY OK: nsCertType=SERVER
Jul 8 13:47:23 X99880 ovpn-client[7120]: VERIFY OK: depth=0, /C=UK/ST=xx/L=xx/O=Oozlum-BCC/CN=openvpn_server/emailAddress=xx
Jul 8 13:47:27 X99880 ovpn-client[7120]: Data Channel Encrypt: Cipher 'BF-CBC' initialized with 128 bit key
Jul 8 13:47:27 X99880 ovpn-client[7120]: Data Channel Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Jul 8 13:47:27 X99880 ovpn-client[7120]: Data Channel Decrypt: Cipher 'BF-CBC' initialized with 128 bit key
Jul 8 13:47:27 X99880 ovpn-client[7120]: Data Channel Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Jul 8 13:47:27 X99880 ovpn-client[7120]: Control Channel: TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA, 1024 bit RSA
Jul 8 14:09:26 X99880 ovpn-client[7120]: [openvpn_server] Inactivity timeout (--ping-restart), restarting
Jul 8 14:09:26 X99880 ovpn-client[7120]: TCP/UDP: Closing socket
Jul 8 14:09:26 X99880 ovpn-client[7120]: SIGUSR1[soft,ping-restart] received, process restarting
Jul 8 14:09:26 X99880 ovpn-client[7120]: Restart pause, 2 second(s)
Jul 8 14:09:28 X99880 ovpn-client[7120]: Re-using SSL/TLS context
Jul 8 14:09:28 X99880 ovpn-client[7120]: LZO compression initialized
Jul 8 14:09:28 X99880 ovpn-client[7120]: Control Channel MTU parms [ L:1542 D:138 EF:38 EB:0 ET:0 EL:0 ]
Jul 8 14:09:28 X99880 ovpn-client[7120]: Data Channel MTU parms [ L:1542 D:1450 EF:42 EB:135 ET:0 EL:0 AF:3/1 ]
Jul 8 14:09:28 X99880 ovpn-client[7120]: Local Options hash (VER=V4): '41690919'
Jul 8 14:09:28 X99880 ovpn-client[7120]: Expected Remote Options hash (VER=V4): '530fdded'
Jul 8 14:09:28 X99880 ovpn-client[7120]: Socket Buffers: R=[112640->131072] S=[112640->131072]
Jul 8 14:09:28 X99880 ovpn-client[7120]: UDPv4 link local: [undef]
Jul 8 14:09:28 X99880 ovpn-client[7120]: UDPv4 link remote: xx.xx.xx.xx:1194
Jul 8 14:10:28 X99880 ovpn-client[7120]: TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity)
Jul 8 14:10:28 X99880 ovpn-client[7120]: TLS Error: TLS handshake failed
Jul 8 14:10:28 X99880 ovpn-client[7120]: TCP/UDP: Closing socket
Jul 8 14:10:28 X99880 ovpn-client[7120]: SIGUSR1[soft,tls-error] received, process restarting
Jul 8 14:10:28 X99880 ovpn-client[7120]: Restart pause, 2 second(s)
Jul 8 14:10:30 X99880 ovpn-client[7120]: Re-using SSL/TLS context
Jul 8 14:10:30 X99880 ovpn-client[7120]: LZO compression initialized
Jul 8 14:10:30 X99880 ovpn-client[7120]: Control Channel MTU parms [ L:1542 D:138 EF:38 EB:0 ET:0 EL:0 ]
Jul 8 14:10:30 X99880 ovpn-client[7120]: Data Channel MTU parms [ L:1542 D:1450 EF:42 EB:135 ET:0 EL:0 AF:3/1 ]
Jul 8 14:10:30 X99880 ovpn-client[7120]: Local Options hash (VER=V4): '41690919'
Jul 8 14:10:30 X99880 ovpn-client[7120]: Expected Remote Options hash (VER=V4): '530fdded'
Jul 8 14:10:30 X99880 ovpn-client[7120]: Socket Buffers: R=[112640->131072] S=[112640->131072]
Jul 8 14:10:30 X99880 ovpn-client[7120]: UDPv4 link local: [undef]
Jul 8 14:10:30 X99880 ovpn-client[7120]: UDPv4 link remote: xx.xx.xx.xx:1194
Server syslog:
Jul 7 22:50:24 openvpn ovpn-server[12875]: X99880/xx.xx.xx.xx:59029 TLS: tls_process: killed expiring key
Jul 7 22:50:40 openvpn ovpn-server[12875]: X99880/xx.xx.xx.xx:59029 VERIFY OK: depth=1, C=UK, ST=xx, L=xx, O=xx, CN=yy, emailAddress=zzz
Jul 7 22:50:40 openvpn ovpn-server[12875]: X99880/xx.xx.xx.xx:59029 VERIFY OK: depth=0, C=UK, ST=xx, L=xx, O=xx, CN=X99880, emailAddress=zzz
Jul 7 22:50:40 openvpn ovpn-server[12875]: X99880/xx.xx.xx.xx:59029 Data Channel Encrypt: Cipher 'BF-CBC' initialized with 128 bit key
Jul 7 22:50:40 openvpn ovpn-server[12875]: X99880/xx.xx.xx.xx:59029 Data Channel Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Jul 7 22:50:40 openvpn ovpn-server[12875]: X99880/xx.xx.xx.xx:59029 Data Channel Decrypt: Cipher 'BF-CBC' initialized with 128 bit key
Jul 7 22:50:40 openvpn ovpn-server[12875]: X99880/xx.xx.xx.xx:59029 Data Channel Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Jul 7 22:50:40 openvpn ovpn-server[12875]: X99880/xx.xx.xx.xx:59029 Control Channel: TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA, 1024 bit RSA
Jul 7 23:50:31 openvpn ovpn-server[12875]: X99880/xx.xx.xx.xx:59029 TLS: tls_process: killed expiring key
Jul 7 23:50:49 openvpn ovpn-server[12875]: xx.xx.xx.xx:22697 TLS: Initial packet from [AF_INET]xx.xx.xx.xx:22697, sid=eb4cec3c e620e5e2
Jul 7 23:51:40 openvpn ovpn-server[12875]: X99880/xx.xx.xx.xx:59029 TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity)
Jul 7 23:51:40 openvpn ovpn-server[12875]: X99880/xx.xx.xx.xx:59029 TLS Error: TLS handshake failed
Jul 7 23:51:40 openvpn ovpn-server[12875]: X99880/xx.xx.xx.xx:59029 TLS: move_session: dest=TM_LAME_DUCK src=TM_ACTIVE reinit_src=1
Jul 7 23:51:49 openvpn ovpn-server[12875]: xx.xx.xx.xx:22697 TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity)
Jul 7 23:51:49 openvpn ovpn-server[12875]: xx.xx.xx.xx:22697 TLS Error: TLS handshake failed
Jul 7 23:51:49 openvpn ovpn-server[12875]: xx.xx.xx.xx:22697 SIGUSR1[soft,tls-error] received, client-instance restarting
Jul 7 23:51:51 openvpn ovpn-server[12875]: xx.xx.xx.xx:22701 TLS: Initial packet from [AF_INET]xx.xx.xx.xx:22701, sid=a734cb5c aa490cae
Jul 7 23:52:51 openvpn ovpn-server[12875]: xx.xx.xx.xx:22701 TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity)
Jul 7 23:52:51 openvpn ovpn-server[12875]: xx.xx.xx.xx:22701 TLS Error: TLS handshake failed
Jul 7 23:52:51 openvpn ovpn-server[12875]: xx.xx.xx.xx:22701 SIGUSR1[soft,tls-error] received, client-instance restarting
Jul 7 23:52:53 openvpn ovpn-server[12875]: xx.xx.xx.xx:22707 TLS: Initial packet from [AF_INET]xx.xx.xx.xx:22707, sid=c593510c 2c90c18e
Jul 7 23:52:55 openvpn ovpn-server[12875]: X99880/xx.xx.xx.xx:59029 TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity)
Jul 7 23:52:55 openvpn ovpn-server[12875]: X99880/xx.xx.xx.xx:59029 TLS Error: TLS handshake failed
**** TLS key negotiation error repeated every minute ****
Jul 8 09:49:25 openvpn kernel: [3201523.644710] perf interrupt took too long (5008 > 5000), lowering kernel.perf_event_max_sample_rate to 25000
**** push 'explicit-exit-notify 3' added to server config and restarted. ****
**** openvpn restarted manually on client ****
Jul 8 13:46:50 openvpn ovpn-server[17728]: xx.xx.xx.xx:31683 TLS: Initial packet from [AF_INET]xx.xx.xx.xx:31683, sid=61f52d20 affb45ed
Jul 8 13:46:52 openvpn ovpn-server[17728]: xx.xx.xx.xx:31683 VERIFY OK: depth=1, C=UK, ST=xx, L=xx, O=xx, CN=yy, emailAddress=zzz
Jul 8 13:46:52 openvpn ovpn-server[17728]: xx.xx.xx.xx:31683 VERIFY OK: depth=0, C=UK, ST=xx, L=xx, O=xx, CN=X99880, emailAddress=zzz
Jul 8 13:46:53 openvpn ovpn-server[17728]: xx.xx.xx.xx:31683 Data Channel Encrypt: Cipher 'BF-CBC' initialized with 128 bit key
Jul 8 13:46:53 openvpn ovpn-server[17728]: xx.xx.xx.xx:31683 Data Channel Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Jul 8 13:46:53 openvpn ovpn-server[17728]: xx.xx.xx.xx:31683 Data Channel Decrypt: Cipher 'BF-CBC' initialized with 128 bit key
Jul 8 13:46:53 openvpn ovpn-server[17728]: xx.xx.xx.xx:31683 Data Channel Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Jul 8 13:46:53 openvpn ovpn-server[17728]: xx.xx.xx.xx:31683 Control Channel: TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA, 1024 bit RSA
Jul 8 13:46:53 openvpn ovpn-server[17728]: xx.xx.xx.xx:31683 [X99880] Peer Connection Initiated with [AF_INET]xx.xx.xx.xx:31683
Jul 8 13:46:53 openvpn ovpn-server[17728]: X99880/xx.xx.xx.xx:31683 OPTIONS IMPORT: reading client specific options from: ccd/X99880
Jul 8 13:46:53 openvpn ovpn-server[17728]: X99880/xx.xx.xx.xx:31683 MULTI: Learn: 172.30.10.2 -> X99880/xx.xx.xx.xx:31683
Jul 8 13:46:53 openvpn ovpn-server[17728]: X99880/xx.xx.xx.xx:31683 MULTI: primary virtual IP for X99880/xx.xx.xx.xx:31683: 172.30.10.2
Jul 8 13:46:54 openvpn ovpn-server[17728]: X99880/xx.xx.xx.xx:31683 PUSH: Received control message: 'PUSH_REQUEST'
Jul 8 13:46:54 openvpn ovpn-server[17728]: X99880/xx.xx.xx.xx:31683 send_push_reply(): safe_cap=940
Jul 8 13:46:54 openvpn ovpn-server[17728]: X99880/xx.xx.xx.xx:31683 SENT CONTROL [X99880]: 'PUSH_REPLY,route 192.168.0.0 255.255.0.0,route 172.16.0.0 255.240.0.0,explicit-exit-notify 3,route-gateway 172.30.10.1,topology subnet,ping 10,ping-restart 120,ifconfig 172.30.10.2 255.255.255.0' (status=1)
Jul 8 14:46:53 openvpn ovpn-server[17728]: X99880/xx.xx.xx.xx:31683 TLS: soft reset sec=0 bytes=691121/0 pkts=2878/0
Jul 8 14:47:02 openvpn ovpn-server[17728]: X99880/xx.xx.xx.xx:31683 VERIFY OK: depth=1, C=UK, ST=xx, L=xx, O=xx, CN=yy, emailAddress=zzz
Jul 8 14:47:02 openvpn ovpn-server[17728]: X99880/xx.xx.xx.xx:31683 VERIFY OK: depth=0, C=UK, ST=xx, L=xx, O=xx, CN=X99880, emailAddress=zzz
Jul 8 14:47:02 openvpn ovpn-server[17728]: X99880/xx.xx.xx.xx:31683 Data Channel Encrypt: Cipher 'BF-CBC' initialized with 128 bit key
Jul 8 14:47:02 openvpn ovpn-server[17728]: X99880/xx.xx.xx.xx:31683 Data Channel Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Jul 8 14:47:02 openvpn ovpn-server[17728]: X99880/xx.xx.xx.xx:31683 Data Channel Decrypt: Cipher 'BF-CBC' initialized with 128 bit key
Jul 8 14:47:02 openvpn ovpn-server[17728]: X99880/xx.xx.xx.xx:31683 Data Channel Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Jul 8 14:47:02 openvpn ovpn-server[17728]: X99880/xx.xx.xx.xx:31683 Control Channel: TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA, 1024 bit RSA
Jul 8 15:09:03 openvpn ovpn-server[17728]: xx.xx.xx.xx:32703 TLS: Initial packet from [AF_INET]xx.xx.xx.xx:32703, sid=2d6b7d79 2961bd4f
Jul 8 15:10:03 openvpn ovpn-server[17728]: xx.xx.xx.xx:32703 TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity)
Jul 8 15:10:03 openvpn ovpn-server[17728]: xx.xx.xx.xx:32703 TLS Error: TLS handshake failed
Jul 8 15:10:03 openvpn ovpn-server[17728]: xx.xx.xx.xx:32703 SIGUSR1[soft,tls-error] received, client-instance restarting
Jul 8 15:10:05 openvpn ovpn-server[17728]: xx.xx.xx.xx:32709 TLS: Initial packet from [AF_INET]xx.xx.xx.xx:32709, sid=4f07700f 880c31b2
Jul 8 15:11:05 openvpn ovpn-server[17728]: xx.xx.xx.xx:32709 TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity)
Jul 8 15:11:05 openvpn ovpn-server[17728]: xx.xx.xx.xx:32709 TLS Error: TLS handshake failed
Jul 8 15:11:05 openvpn ovpn-server[17728]: xx.xx.xx.xx:32709 SIGUSR1[soft,tls-error] received, client-instance restarting
Jul 8 15:11:07 openvpn ovpn-server[17728]: xx.xx.xx.xx:32717 TLS: Initial packet from [AF_INET]xx.xx.xx.xx:32717, sid=1bbd3ee6 12069d4
