Client permanently disconnects after one day

easyvictor

Hi,

I've got an openvpn server running on my TomatoUSB based router. Users log in with keys/certs, and it seems to work fine. Renegotiation with the server happens once per hour, and "keepalive 10 60" is used. For some reason, however, it seems the client can only stay connected for around 36 hours, anywhere between one and two days.

I don't think it's a connection issue as the client should reconnect automatically. I looked at the log files coming from the server, and the one-hour check in seemed to be going normally until one of them went awry. I did notice that the final failed renegotiation did not occur at the standard one hour interval; could that be a hint?

I would greatly appreciate any help on this. Here's the server log for the disconnection as well as the previous two successful renegotiations:

Mar  2 10:35:51 tomato daemon.notice openvpn[18287]: johnny-vaio/134.117.15.2:60623 TLS: tls_process: killed expiring key
Mar  2 10:35:53 tomato daemon.notice openvpn[18287]: johnny-vaio/134.117.15.2:60623 TLS: soft reset sec=0 bytes=57400/0 pkts=759/0
Mar  2 10:35:54 tomato daemon.notice openvpn[18287]: johnny-vaio/134.117.15.2:60623 VERIFY OK: depth=1, /C=US/ST=CA/L=NewportBeach/O=JLoInc/OU=NA/CN=tomato/name=tomato/emailAddress=jlo@mail.com
Mar  2 10:35:54 tomato daemon.notice openvpn[18287]: johnny-vaio/134.117.15.2:60623 VERIFY OK: depth=0, /C=US/ST=CA/L=NewportBeach/O=NA/CN=johnny-vaio/emailAddress=myemail@gmail.com
Mar  2 10:35:55 tomato daemon.notice openvpn[18287]: johnny-vaio/134.117.15.2:60623 Data Channel Encrypt: Cipher 'AES-128-CBC' initialized with 128 bit key
Mar  2 10:35:55 tomato daemon.notice openvpn[18287]: johnny-vaio/134.117.15.2:60623 Data Channel Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Mar  2 10:35:55 tomato daemon.notice openvpn[18287]: johnny-vaio/134.117.15.2:60623 Data Channel Decrypt: Cipher 'AES-128-CBC' initialized with 128 bit key
Mar  2 10:35:55 tomato daemon.notice openvpn[18287]: johnny-vaio/134.117.15.2:60623 Data Channel Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Mar  2 10:35:55 tomato daemon.notice openvpn[18287]: johnny-vaio/134.117.15.2:60623 Control Channel: TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA, 1024 bit RSA
Mar  2 11:35:53 tomato daemon.notice openvpn[18287]: johnny-vaio/134.117.15.2:60623 TLS: tls_process: killed expiring key
Mar  2 11:35:56 tomato daemon.notice openvpn[18287]: johnny-vaio/134.117.15.2:60623 TLS: soft reset sec=-1 bytes=56821/0 pkts=755/0
Mar  2 11:35:56 tomato daemon.notice openvpn[18287]: johnny-vaio/134.117.15.2:60623 VERIFY OK: depth=1, /C=US/ST=CA/L=NewportBeach/O=JLoInc/OU=NA/CN=tomato/name=tomato/emailAddress=jlo@mail.com
Mar  2 11:35:56 tomato daemon.notice openvpn[18287]: johnny-vaio/134.117.15.2:60623 VERIFY OK: depth=0, /C=US/ST=CA/L=NewportBeach/O=NA/CN=johnny-vaio/emailAddress=myemail@gmail.com
Mar  2 11:35:57 tomato daemon.notice openvpn[18287]: johnny-vaio/134.117.15.2:60623 Data Channel Encrypt: Cipher 'AES-128-CBC' initialized with 128 bit key
Mar  2 11:35:57 tomato daemon.notice openvpn[18287]: johnny-vaio/134.117.15.2:60623 Data Channel Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Mar  2 11:35:57 tomato daemon.notice openvpn[18287]: johnny-vaio/134.117.15.2:60623 Data Channel Decrypt: Cipher 'AES-128-CBC' initialized with 128 bit key
Mar  2 11:35:57 tomato daemon.notice openvpn[18287]: johnny-vaio/134.117.15.2:60623 Data Channel Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Mar  2 11:35:57 tomato daemon.notice openvpn[18287]: johnny-vaio/134.117.15.2:60623 Control Channel: TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA, 1024 bit RSA
Mar  2 12:35:56 tomato daemon.notice openvpn[18287]: johnny-vaio/134.117.15.2:60623 TLS: tls_process: killed expiring key
Mar  2 12:35:58 tomato daemon.notice openvpn[18287]: johnny-vaio/134.117.15.2:60623 VERIFY OK: depth=1, /C=US/ST=CA/L=NewportBeach/O=JLoInc/OU=NA/CN=tomato/name=tomato/emailAddress=jlo@mail.com
Mar  2 12:35:58 tomato daemon.notice openvpn[18287]: johnny-vaio/134.117.15.2:60623 VERIFY OK: depth=0, /C=US/ST=CA/L=NewportBeach/O=NA/CN=johnny-vaio/emailAddress=myemail@gmail.com
Mar  2 12:35:59 tomato daemon.notice openvpn[18287]: johnny-vaio/134.117.15.2:60623 Data Channel Encrypt: Cipher 'AES-128-CBC' initialized with 128 bit key
Mar  2 12:35:59 tomato daemon.notice openvpn[18287]: johnny-vaio/134.117.15.2:60623 Data Channel Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Mar  2 12:35:59 tomato daemon.notice openvpn[18287]: johnny-vaio/134.117.15.2:60623 Data Channel Decrypt: Cipher 'AES-128-CBC' initialized with 128 bit key
Mar  2 12:35:59 tomato daemon.notice openvpn[18287]: johnny-vaio/134.117.15.2:60623 Data Channel Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Mar  2 12:35:59 tomato daemon.notice openvpn[18287]: johnny-vaio/134.117.15.2:60623 Control Channel: TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA, 1024 bit RSA
Mar  2 13:08:15 tomato daemon.notice openvpn[18287]: MULTI: multi_create_instance called
Mar  2 13:08:15 tomato daemon.notice openvpn[18287]: Re-using SSL/TLS context
Mar  2 13:08:15 tomato daemon.notice openvpn[18287]: LZO compression initialized
Mar  2 13:08:15 tomato daemon.notice openvpn[18287]: Control Channel MTU parms [ L:1560 D:140 EF:40 EB:0 ET:0 EL:0 ]
Mar  2 13:08:15 tomato daemon.notice openvpn[18287]: Data Channel MTU parms [ L:1560 D:1450 EF:60 EB:135 ET:0 EL:0 AF:3/1 ]
Mar  2 13:08:15 tomato daemon.notice openvpn[18287]: TCP connection established with 134.117.15.2:60822
Mar  2 13:08:15 tomato daemon.notice openvpn[18287]: Socket Buffers: R=[131072->131072] S=[131072->131072]
Mar  2 13:08:15 tomato daemon.notice openvpn[18287]: TCPv4_SERVER link local: [undef]
Mar  2 13:08:15 tomato daemon.notice openvpn[18287]: TCPv4_SERVER link remote: 134.117.15.2:60822
Mar  2 13:08:16 tomato daemon.notice openvpn[18287]: 134.117.15.2:60822 TLS: Initial packet from 134.117.15.2:60822, sid=ede46515 78dc193a
Mar  2 13:08:18 tomato daemon.err openvpn[18287]: johnny-vaio/134.117.15.2:60623 Connection reset, restarting [-1]
Mar  2 13:08:18 tomato daemon.notice openvpn[18287]: johnny-vaio/134.117.15.2:60623 SIGUSR1[soft,connection-reset] received, client-instance restarting
Mar  2 13:08:18 tomato daemon.notice openvpn[18287]: TCP/UDP: Closing socket
Mar  2 13:08:18 tomato daemon.notice openvpn[18287]: 134.117.15.2:60822 VERIFY OK: depth=1, /C=US/ST=CA/L=NewportBeach/O=JLoInc/OU=NA/CN=tomato/name=tomato/emailAddress=jlo@mail.com
Mar  2 13:08:18 tomato daemon.notice openvpn[18287]: 134.117.15.2:60822 VERIFY OK: depth=0, /C=US/ST=CA/L=NewportBeach/O=NA/CN=johnny-vaio/emailAddress=myemail@gmail.com
Mar  2 13:08:19 tomato daemon.notice openvpn[18287]: 134.117.15.2:60822 Data Channel Encrypt: Cipher 'AES-128-CBC' initialized with 128 bit key
Mar  2 13:08:19 tomato daemon.notice openvpn[18287]: 134.117.15.2:60822 Data Channel Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Mar  2 13:08:19 tomato daemon.notice openvpn[18287]: 134.117.15.2:60822 Data Channel Decrypt: Cipher 'AES-128-CBC' initialized with 128 bit key
Mar  2 13:08:19 tomato daemon.notice openvpn[18287]: 134.117.15.2:60822 Data Channel Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Mar  2 13:08:19 tomato daemon.notice openvpn[18287]: 134.117.15.2:60822 Control Channel: TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA, 1024 bit RSA
Mar  2 13:08:19 tomato daemon.notice openvpn[18287]: 134.117.15.2:60822 [johnny-vaio] Peer Connection Initiated with 134.117.15.2:60822
Mar  2 13:08:19 tomato daemon.notice openvpn[18287]: johnny-vaio/134.117.15.2:60822 OPTIONS IMPORT: reading client specific options from: /etc/openvpn/johnny-vaio
Mar  2 13:08:19 tomato daemon.notice openvpn[18287]: johnny-vaio/134.117.15.2:60822 MULTI: Learn: 10.8.0.6 -> johnny-vaio/134.117.15.2:60822
Mar  2 13:08:19 tomato daemon.notice openvpn[18287]: johnny-vaio/134.117.15.2:60822 MULTI: primary virtual IP for johnny-vaio/134.117.15.2:60822: 10.8.0.6
Mar  2 13:08:19 tomato daemon.notice openvpn[18287]: johnny-vaio/134.117.15.2:60822 MULTI: internal route 192.168.1.0/24 -> johnny-vaio/134.117.15.2:60822
Mar  2 13:08:19 tomato daemon.notice openvpn[18287]: johnny-vaio/134.117.15.2:60822 MULTI: Learn: 192.168.1.0/24 -> johnny-vaio/134.117.15.2:60822
Mar  2 13:08:21 tomato daemon.notice openvpn[18287]: johnny-vaio/134.117.15.2:60822 PUSH: Received control message: 'PUSH_REQUEST'
Mar  2 13:08:21 tomato daemon.notice openvpn[18287]: johnny-vaio/134.117.15.2:60822 SENT CONTROL [johnny-vaio]: 'PUSH_REPLY,route 192.168.10.0 255.255.255.0,dhcp-option DOMAIN tomato,dhcp-option DNS 192.168.10.1,route 10.8.0.0 255.255.255.0,topology net30,ping 10,ping-restart 60,ifconfig 10.8.0.6 10.8.0.5' (status=1)
Mar  2 13:08:22 tomato daemon.err openvpn[18287]: johnny-vaio/134.117.15.2:60822 Connection reset, restarting [0]
Mar  2 13:08:22 tomato daemon.notice openvpn[18287]: johnny-vaio/134.117.15.2:60822 SIGUSR1[soft,connection-reset] received, client-instance restarting
Mar  2 13:08:22 tomato daemon.notice openvpn[18287]: TCP/UDP: Closing socket

Any help is greatly appreciated!

Mimiko

Does this happens only with this client? Can you do a permanent test ping from routers internal LANs clients to some internet point, for exameple the ISP's gateway.