# openvpn drops, won't restart: TLS key negotiation timeout

## Felig

I have a vpn with several clients.  Two of them are Macs, one is gentoo ~amd64.  The server is also gentoo ~amd64.  The Mac clients haven't changed in ages, neither has the server, but the gentoo client gets an emerge update every week or so.  The last two times I have updated it, the vpn has shut down, dropped the connection, soon after the emerge, while running various checks (config files, revdep-rebuild, etc).  Nothing terribly interesting was rebuilt either time -- no system libs, neither kernel nor openvpn.  The first time, about a week ago, I remerged to the previous version (2.1.3), then back (2.1.4), tried a couple of different kernels (2.6.36-gentoo-r[35]), and suddenly it started working again.  I do not know what did it, as I tried each combination a couple of times.  This time, those attempts haven't worked (yet?).  One of the reasons for rebooting was in case the emerge had updated any system files which ". /etc/profile" wouldn't pick up after the emerge, and certainly not for already running code.  When the first failure "fixed itself", I assumed the reboot was part of it, and this second update a week later didn't seem dangerous.

EDIT TO ADD -- Strike that -- the two Mac clients do not set up their vpns -- they merely ssh in to the server.  I had forgotten I had changed this.  The only vpn client is the gentoo one.  It's been way too long since I set this up.

The error message is that TLS key negotiation has timed out after 60 seconds ... check network connection.  Yes, the network is working.  ifconfig shows lo and eth2 (which is proper on that system).

What would cause this -- having one client stop creating the tun interface and not connect, with "TLS key negotiation timeout"?

This is running over a sat link with 1.5 second ping times, but it has been working for years up until now.

Here is the server log:

```
TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity)

TLS Error: TLS handshake failed
```

I changed the gentoo server and client to have a 5 second timeout (tls-timeout = 5); the Mac clients can still connect, the gentoo client still can't.

How very odd ... just like the first time, it came back by itself, 5 minutes before midnight.  The difference starts at 23:55:35, where it stopped complaing about an unroutable control packet being received.

```
Wed Dec 22 23:54:30 2010 us=254403 TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity)

Wed Dec 22 23:54:30 2010 us=254506 TLS Error: TLS handshake failed

Wed Dec 22 23:54:30 2010 us=254687 TCP/UDP: Closing socket

Wed Dec 22 23:54:30 2010 us=254735 SIGUSR1[soft,tls-error] received, process restarting

Wed Dec 22 23:54:30 2010 us=254764 Restart pause, 2 second(s)

Wed Dec 22 23:54:32 2010 us=256410 NOTE: the current --script-security setting may allow this configuration to call user-defined scripts

Wed Dec 22 23:54:32 2010 us=257694 Control Channel Authentication: using '/etc/openvpn/ta.key' as a OpenVPN static key file

Wed Dec 22 23:54:32 2010 us=257726 Outgoing Control Channel Authentication: Using 160 bit message hash 'SHA1' for HMAC authentication

Wed Dec 22 23:54:32 2010 us=257749 Incoming Control Channel Authentication: Using 160 bit message hash 'SHA1' for HMAC authentication

Wed Dec 22 23:54:32 2010 us=257776 LZO compression initialized

Wed Dec 22 23:54:32 2010 us=257836 Control Channel MTU parms [ L:1542 D:166 EF:66 EB:0 ET:0 EL:0 ]

Wed Dec 22 23:54:32 2010 us=257891 Socket Buffers: R=[124928->131072] S=[124928->131072]

Wed Dec 22 23:54:32 2010 us=257928 Data Channel MTU parms [ L:1542 D:1450 EF:42 EB:135 ET:0 EL:0 AF:3/1 ]

Wed Dec 22 23:54:32 2010 us=257963 Local Options String: 'V4,dev-type tun,link-mtu 1542,tun-mtu 1500,proto UDPv4,comp-lzo,keydir 1,cipher BF-CBC,auth SHA1,keysize 128,tls-auth,key-method 2,tls-client'

Wed Dec 22 23:54:32 2010 us=257982 Expected Remote Options String: 'V4,dev-type tun,link-mtu 1542,tun-mtu 1500,proto UDPv4,comp-lzo,keydir 0,cipher BF-CBC,auth SHA1,keysize 128,tls-auth,key-method 2,tls-server'

Wed Dec 22 23:54:32 2010 us=258015 Local Options hash (VER=V4): '504e774e'

Wed Dec 22 23:54:32 2010 us=258042 Expected Remote Options hash (VER=V4): '14168603'

Wed Dec 22 23:54:32 2010 us=258073 UDPv4 link local (bound): [undef]

Wed Dec 22 23:54:32 2010 us=258096 UDPv4 link remote: [AF_INET]x.x.x.x:x

Wed Dec 22 23:55:09 2010 us=503467 TLS Error: Unroutable control packet received from [AF_INET]x.x.x.x:x (si=3 op=P_ACK_V1)

Wed Dec 22 23:55:13 2010 us=584396 TLS: Initial packet from [AF_INET]x.x.x.x:x, sid=5b632d61 84641f52

Wed Dec 22 23:55:29 2010 us=513968 VERIFY OK: depth=1, /C=...

Wed Dec 22 23:55:29 2010 us=514326 VERIFY OK: nsCertType=SERVER

Wed Dec 22 23:55:29 2010 us=514350 VERIFY OK: depth=0, /C=...

Wed Dec 22 23:55:32 2010 us=381152 TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity)

Wed Dec 22 23:55:32 2010 us=381253 TLS Error: TLS handshake failed

Wed Dec 22 23:55:32 2010 us=381491 TCP/UDP: Closing socket

Wed Dec 22 23:55:32 2010 us=381548 SIGUSR1[soft,tls-error] received, process restarting

Wed Dec 22 23:55:32 2010 us=381577 Restart pause, 2 second(s)

Wed Dec 22 23:55:34 2010 us=383251 NOTE: the current --script-security setting may allow this configuration to call user-defined scripts

Wed Dec 22 23:55:34 2010 us=384464 Control Channel Authentication: using '/etc/openvpn/ta.key' as a OpenVPN static key file

Wed Dec 22 23:55:34 2010 us=384494 Outgoing Control Channel Authentication: Using 160 bit message hash 'SHA1' for HMAC authentication

Wed Dec 22 23:55:34 2010 us=384517 Incoming Control Channel Authentication: Using 160 bit message hash 'SHA1' for HMAC authentication

Wed Dec 22 23:55:34 2010 us=384544 LZO compression initialized

Wed Dec 22 23:55:34 2010 us=384604 Control Channel MTU parms [ L:1542 D:166 EF:66 EB:0 ET:0 EL:0 ]

Wed Dec 22 23:55:34 2010 us=384659 Socket Buffers: R=[124928->131072] S=[124928->131072]

Wed Dec 22 23:55:34 2010 us=384696 Data Channel MTU parms [ L:1542 D:1450 EF:42 EB:135 ET:0 EL:0 AF:3/1 ]

Wed Dec 22 23:55:34 2010 us=384730 Local Options String: 'V4,dev-type tun,link-mtu 1542,tun-mtu 1500,proto UDPv4,comp-lzo,keydir 1,cipher BF-CBC,auth SHA1,keysize 128,tls-auth,key-method 2,tls-client'

Wed Dec 22 23:55:34 2010 us=384749 Expected Remote Options String: 'V4,dev-type tun,link-mtu 1542,tun-mtu 1500,proto UDPv4,comp-lzo,keydir 0,cipher BF-CBC,auth SHA1,keysize 128,tls-auth,key-method 2,tls-server'

Wed Dec 22 23:55:34 2010 us=384782 Local Options hash (VER=V4): '504e774e'

Wed Dec 22 23:55:34 2010 us=384810 Expected Remote Options hash (VER=V4): '14168603'

Wed Dec 22 23:55:34 2010 us=384840 UDPv4 link local (bound): [undef]

Wed Dec 22 23:55:34 2010 us=384932 UDPv4 link remote: [AF_INET]x.x.x.x:x

Wed Dec 22 23:55:35 2010 us=803906 TLS: Initial packet from [AF_INET]x.x.x.x:x, sid=9dbf6de1 f1e961d8

Wed Dec 22 23:55:48 2010 us=700088 VERIFY OK: depth=1, /C=...

Wed Dec 22 23:55:48 2010 us=700460 VERIFY OK: nsCertType=SERVER

Wed Dec 22 23:55:48 2010 us=700483 VERIFY OK: depth=0, /C=...

Wed Dec 22 23:56:15 2010 us=87611 Data Channel Encrypt: Cipher 'BF-CBC' initialized with 128 bit key

Wed Dec 22 23:56:15 2010 us=87698 Data Channel Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication

Wed Dec 22 23:56:15 2010 us=87774 Data Channel Decrypt: Cipher 'BF-CBC' initialized with 128 bit key

Wed Dec 22 23:56:15 2010 us=87796 Data Channel Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication

Wed Dec 22 23:56:15 2010 us=87861 Control Channel: TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA, 2048 bit RSA

Wed Dec 22 23:56:15 2010 us=87906 [xxx.com] Peer Connection Initiated with [AF_INET]x.x.x.x:x

```

----------

