[OpenVPN home]	[Date Prev]	[Date Index]	[Date Next]
[OpenVPN mailing lists]	[Thread Prev]	[Thread Index]	[Thread Next]

[Openvpn-users] Connection reset, restarting [-1] without reason(?)

Subject: [Openvpn-users] Connection reset, restarting [-1] without reason(?)
From: Mathias Sundman <mathias@xxxxxxxxxx>
Date: Fri, 22 Oct 2004 23:59:50 +0200 (CEST)

I upgraded my OpenVPN server yesterday to 2.0-beta14.

Today I've been connected for more than a few minutes for the first time since the upgrade, and something pretty strange happend, that I havn't seen before.

First a little background info: Server: Linux with OpenVPN 2.0-beta14 in server mode bridging the clients into the local network.

Client:
Windows XP SP2 (tcpip.sys patched)
OpenVPN 2.0-beta14

Client Config:
dev tap
proto tcp-client
remote xxxxxx.xxxxx.xx 443

tls-client
pkcs12 mathias.sundman.p12
pull
nobind
mssfix 1400
persist-key
resolv-retry infinite
verb 3

All of sudden, exacty 30 minutes after I had connected I recieved the following msg, and the client re-connected: Fri Oct 22 21:50:08 2004 Connection reset, restarting [-1]


Then almost exactly one hour later I get this in the log:

Fri Oct 22 22:50:13 2004 TLS: soft reset sec=0 bytes=607062/0 pkts=4898/0
Fri Oct 22 22:50:13 2004 VERIFY OK: depth=1, /C=SE/ST=NA/L=STOCKHOLM/O=xxxxxxx/CN=xxxxxxx.OpenVPN.CA/emailAddress=info@xxxxxxxxxx
Fri Oct 22 22:50:13 2004 VERIFY OK: depth=0, /C=SE/ST=NA/O=xxxxxxx/CN=Server/emailAddress=info@xxxxxxxxxx
Fri Oct 22 22:50:14 2004 Data Channel Encrypt: Cipher 'BF-CBC' initialized with 128 bit key
Fri Oct 22 22:50:14 2004 Data Channel Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Fri Oct 22 22:50:14 2004 Data Channel Decrypt: Cipher 'BF-CBC' initialized with 128 bit key
Fri Oct 22 22:50:14 2004 Data Channel Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Fri Oct 22 22:50:14 2004 Control Channel: TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA, 1024 bit RSA

which I think means that a re-key negotiation has occured. Yet another hour later I get:

Fri Oct 22 23:50:13 2004 VERIFY OK: depth=1, /C=SE/ST=NA/L=STOCKHOLM/O=xxxxxxx/CN=xxxxxxx.OpenVPN.CA/emailAddress=info@xxxxxxxxxx
Fri Oct 22 23:50:13 2004 VERIFY OK: depth=0, /C=SE/ST=NA/O=xxxxxxx/CN=Server/emailAddress=info@xxxxxxxxxx
Fri Oct 22 23:50:14 2004 Data Channel Encrypt: Cipher 'BF-CBC' initialized with 128 bit key
Fri Oct 22 23:50:14 2004 Data Channel Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Fri Oct 22 23:50:14 2004 Data Channel Decrypt: Cipher 'BF-CBC' initialized with 128 bit key
Fri Oct 22 23:50:14 2004 Data Channel Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Fri Oct 22 23:50:14 2004 Control Channel: TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA, 1024 bit RSA
Fri Oct 22 23:50:13 2004 VERIFY OK: depth=1, /C=SE/ST=NA/L=STOCKHOLM/O=xxxxxxx/CN=xxxxxxx.OpenVPN.CA/emailAddress=info@xxxxxxxxxx


As the connection reset occured almost exactly one hour before the re-key negotiation that makes me wonder if it was a re-key attempt that was made at 21:50 which failed and caused connection reset.

I also wonder what the "TLS: soft reset..." I got at 22:50 means, as I did not get any such at 23:50.

Any idea what happend?

Here's my whole log on the client:

Fri Oct 22 21:19:51 2004 OpenVPN 2.0_beta14 Win32-MinGW [SSL] [LZO] built on Oct 20 2004 Fri Oct 22 21:19:52 2004 Control Channel MTU parms [ L:1575 D:140 EF:40 EB:0 ET:0 EL:0 ] Fri Oct 22 21:19:53 2004 Data Channel MTU parms [ L:1575 D:1400 EF:43 EB:0 ET:32 EL:0 ] Fri Oct 22 21:19:53 2004 Local Options hash (VER=V4): '10f35004' Fri Oct 22 21:19:53 2004 Expected Remote Options hash (VER=V4): 'a917298a' Fri Oct 22 21:19:53 2004 Attempting to establish TCP connection with xxx.xx.xx.xx:443 Fri Oct 22 21:19:53 2004 TCP connection established with xxx.xx.xx.xx:443 Fri Oct 22 21:19:53 2004 TCPv4_CLIENT link local: [undef] Fri Oct 22 21:19:53 2004 TCPv4_CLIENT link remote: xxx.xx.xx.xx:443 Fri Oct 22 21:19:53 2004 TLS: Initial packet from xxx.xx.xx.xx:443, sid=0e07c102 bedb5822 Fri Oct 22 21:19:53 2004 VERIFY OK: depth=1, /C=SE/ST=NA/L=STOCKHOLM/O=xxxxxxx/CN=xxxxxxx.OpenVPN.CA/emailAddress=info@xxxxxxxxxx Fri Oct 22 21:19:53 2004 VERIFY OK: depth=0, /C=SE/ST=NA/O=xxxxxxx/CN=Server/emailAddress=info@xxxxxxxxxx Fri Oct 22 21:19:54 2004 Data Channel Encrypt: Cipher 'BF-CBC' initialized with 128 bit key Fri Oct 22 21:19:54 2004 Data Channel Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication Fri Oct 22 21:19:54 2004 Data Channel Decrypt: Cipher 'BF-CBC' initialized with 128 bit key Fri Oct 22 21:19:54 2004 Data Channel Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication Fri Oct 22 21:19:54 2004 Control Channel: TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA, 1024 bit RSA Fri Oct 22 21:19:54 2004 [Server] Peer Connection Initiated with xxx.xx.xx.xx:443 Fri Oct 22 21:19:55 2004 SENT CONTROL [Server]: 'PUSH_REQUEST' (status=1) Fri Oct 22 21:19:55 2004 PUSH: Received control message: 'PUSH_REPLY,ping 10,ping-restart 60,dhcp-option DOMAIN xxxxxxx.se,dhcp-option NBT 8,dhcp-option DNS 193.15.191.33,dhcp-option WINS 10.105.0.5,route 193.15.191.32 255.255.255.240 10.105.255.1,route 193.13.81.0 255.255.255.224 10.105.255.1,route 213.247.12.96 255.255.255.248 10.105.255.1,route 192.168.2.0 255.255.255.0 10.105.255.1,route 172.16.1.0 255.255.255.0 10.105.255.1,route 80.163.165.224 255.255.255.248 10.105.255.1,route 212.247.12.96 255.255.255.248 10.105.255.1,route 217.13.252.32 255.255.255.224 10.105.255.1,route 217.13.252.160 255.255.255.224 10.105.255.1,ifconfig 10.105.11.3 255.255.0.0' Fri Oct 22 21:19:55 2004 OPTIONS IMPORT: timers and/or timeouts modified Fri Oct 22 21:19:55 2004 OPTIONS IMPORT: --ifconfig/up options modified Fri Oct 22 21:19:55 2004 OPTIONS IMPORT: route options modified Fri Oct 22 21:19:55 2004 OPTIONS IMPORT: --ip-win32 and/or --dhcp-option options modified Fri Oct 22 21:19:55 2004 TAP-WIN32 device [Local Area Connection 20] opened: \\.\Global\{ACF5AE0F-B0C0-443B-B14C-1B80544AE1F3}.tap Fri Oct 22 21:19:55 2004 TAP-Win32 Driver Version 8.1 Fri Oct 22 21:19:55 2004 TAP-Win32 MTU=1500 Fri Oct 22 21:19:55 2004 Notified TAP-Win32 driver to set a DHCP IP/netmask of 10.105.11.3/255.255.0.0 on interface {ACF5AE0F-B0C0-443B-B14C-1B80544AE1F3} [DHCP-serv: 10.105.0.0, lease-time: 31536000] Fri Oct 22 21:19:55 2004 Successful ARP Flush on interface [131077] {ACF5AE0F-B0C0-443B-B14C-1B80544AE1F3} Fri Oct 22 21:19:55 2004 TEST ROUTES: 0/0 succeeded len=9 ret=0 a=0 u/d=down Fri Oct 22 21:19:55 2004 Route: Waiting for TUN/TAP interface to come up... Fri Oct 22 21:19:56 2004 TEST ROUTES: 0/0 succeeded len=9 ret=0 a=0 u/d=down Fri Oct 22 21:19:56 2004 Route: Waiting for TUN/TAP interface to come up... Fri Oct 22 21:19:56 2004 TEST ROUTES: 0/0 succeeded len=9 ret=0 a=0 u/d=down Fri Oct 22 21:19:56 2004 Route: Waiting for TUN/TAP interface to come up... Fri Oct 22 21:19:58 2004 TEST ROUTES: 0/0 succeeded len=9 ret=0 a=0 u/d=down Fri Oct 22 21:19:58 2004 Route: Waiting for TUN/TAP interface to come up... Fri Oct 22 21:19:59 2004 TEST ROUTES: 0/0 succeeded len=9 ret=0 a=0 u/d=down Fri Oct 22 21:19:59 2004 Route: Waiting for TUN/TAP interface to come up... Fri Oct 22 21:20:00 2004 TEST ROUTES: 0/0 succeeded len=9 ret=0 a=0 u/d=down Fri Oct 22 21:20:00 2004 Route: Waiting for TUN/TAP interface to come up... Fri Oct 22 21:20:00 2004 TEST ROUTES: 9/9 succeeded len=9 ret=1 a=0 u/d=up Fri Oct 22 21:20:00 2004 route ADD 193.15.191.32 MASK 255.255.255.240 10.105.255.1 Fri Oct 22 21:20:01 2004 Route addition via IPAPI succeeded Fri Oct 22 21:20:01 2004 route ADD 193.13.81.0 MASK 255.255.255.224 10.105.255.1 Fri Oct 22 21:20:01 2004 Route addition via IPAPI succeeded Fri Oct 22 21:20:01 2004 route ADD 213.247.12.96 MASK 255.255.255.248 10.105.255.1 Fri Oct 22 21:20:01 2004 Route addition via IPAPI succeeded Fri Oct 22 21:20:01 2004 route ADD 192.168.2.0 MASK 255.255.255.0 10.105.255.1 Fri Oct 22 21:20:01 2004 Route addition via IPAPI succeeded Fri Oct 22 21:20:01 2004 route ADD 172.16.1.0 MASK 255.255.255.0 10.105.255.1 Fri Oct 22 21:20:01 2004 Route addition via IPAPI succeeded Fri Oct 22 21:20:01 2004 route ADD 80.163.165.224 MASK 255.255.255.248 10.105.255.1 Fri Oct 22 21:20:01 2004 Route addition via IPAPI succeeded Fri Oct 22 21:20:01 2004 route ADD 212.247.12.96 MASK 255.255.255.248 10.105.255.1 Fri Oct 22 21:20:01 2004 Route addition via IPAPI succeeded Fri Oct 22 21:20:01 2004 route ADD 217.13.252.32 MASK 255.255.255.224 10.105.255.1 Fri Oct 22 21:20:01 2004 Route addition via IPAPI succeeded Fri Oct 22 21:20:01 2004 route ADD 217.13.252.160 MASK 255.255.255.224 10.105.255.1 Fri Oct 22 21:20:01 2004 Route addition via IPAPI succeeded Fri Oct 22 21:20:01 2004 Initialization Sequence Completed Fri Oct 22 21:50:08 2004 Connection reset, restarting [-1] Fri Oct 22 21:50:08 2004 TCP/UDP: Closing socket Fri Oct 22 21:50:08 2004 route DELETE 217.13.252.160 Fri Oct 22 21:50:08 2004 Route deletion via IPAPI succeeded Fri Oct 22 21:50:08 2004 route DELETE 217.13.252.32 Fri Oct 22 21:50:08 2004 Route deletion via IPAPI succeeded Fri Oct 22 21:50:08 2004 route DELETE 212.247.12.96 Fri Oct 22 21:50:08 2004 Route deletion via IPAPI succeeded Fri Oct 22 21:50:08 2004 route DELETE 80.163.165.224 Fri Oct 22 21:50:08 2004 Route deletion via IPAPI succeeded Fri Oct 22 21:50:08 2004 route DELETE 172.16.1.0 Fri Oct 22 21:50:08 2004 Route deletion via IPAPI succeeded Fri Oct 22 21:50:08 2004 route DELETE 192.168.2.0 Fri Oct 22 21:50:08 2004 Route deletion via IPAPI succeeded Fri Oct 22 21:50:08 2004 route DELETE 213.247.12.96 Fri Oct 22 21:50:08 2004 Route deletion via IPAPI succeeded Fri Oct 22 21:50:08 2004 route DELETE 193.13.81.0 Fri Oct 22 21:50:08 2004 Route deletion via IPAPI succeeded Fri Oct 22 21:50:08 2004 route DELETE 193.15.191.32 Fri Oct 22 21:50:08 2004 Route deletion via IPAPI succeeded Fri Oct 22 21:50:08 2004 Closing TUN/TAP interface Fri Oct 22 21:50:08 2004 SIGUSR1[soft,connection-reset] received, process restarting Fri Oct 22 21:50:08 2004 Restart pause, 5 second(s) Fri Oct 22 21:50:13 2004 Re-using SSL/TLS context Fri Oct 22 21:50:13 2004 Control Channel MTU parms [ L:1575 D:140 EF:40 EB:0 ET:0 EL:0 ] Fri Oct 22 21:50:13 2004 Data Channel MTU parms [ L:1575 D:1400 EF:43 EB:0 ET:32 EL:0 ] Fri Oct 22 21:50:13 2004 Local Options hash (VER=V4): '10f35004' Fri Oct 22 21:50:13 2004 Expected Remote Options hash (VER=V4): 'a917298a' Fri Oct 22 21:50:13 2004 Attempting to establish TCP connection with xxx.xx.xx.xx:443 Fri Oct 22 21:50:13 2004 TCP connection established with xxx.xx.xx.xx:443 Fri Oct 22 21:50:13 2004 TCPv4_CLIENT link local: [undef] Fri Oct 22 21:50:13 2004 TCPv4_CLIENT link remote: xxx.xx.xx.xx:443 Fri Oct 22 21:50:13 2004 TLS: Initial packet from xxx.xx.xx.xx:443, sid=ae18b70d 592a35ca Fri Oct 22 21:50:13 2004 VERIFY OK: depth=1, /C=SE/ST=NA/L=STOCKHOLM/O=xxxxxxx/CN=xxxxxxx.OpenVPN.CA/emailAddress=info@xxxxxxxxxx Fri Oct 22 21:50:13 2004 VERIFY OK: depth=0, /C=SE/ST=NA/O=xxxxxxx/CN=Server/emailAddress=info@xxxxxxxxxx Fri Oct 22 21:50:14 2004 Data Channel Encrypt: Cipher 'BF-CBC' initialized with 128 bit key Fri Oct 22 21:50:14 2004 Data Channel Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication Fri Oct 22 21:50:14 2004 Data Channel Decrypt: Cipher 'BF-CBC' initialized with 128 bit key Fri Oct 22 21:50:14 2004 Data Channel Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication Fri Oct 22 21:50:14 2004 Control Channel: TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA, 1024 bit RSA Fri Oct 22 21:50:14 2004 [Server] Peer Connection Initiated with xxx.xx.xx.xx:443 Fri Oct 22 21:50:15 2004 SENT CONTROL [Server]: 'PUSH_REQUEST' (status=1) Fri Oct 22 21:50:15 2004 PUSH: Received control message: 'PUSH_REPLY,ping 10,ping-restart 60,dhcp-option DOMAIN xxxxxxx.se,dhcp-option NBT 8,dhcp-option DNS 193.15.191.33,dhcp-option WINS 10.105.0.5,route 193.15.191.32 255.255.255.240 10.105.255.1,route 193.13.81.0 255.255.255.224 10.105.255.1,route 213.247.12.96 255.255.255.248 10.105.255.1,route 192.168.2.0 255.255.255.0 10.105.255.1,route 172.16.1.0 255.255.255.0 10.105.255.1,route 80.163.165.224 255.255.255.248 10.105.255.1,route 212.247.12.96 255.255.255.248 10.105.255.1,route 217.13.252.32 255.255.255.224 10.105.255.1,route 217.13.252.160 255.255.255.224 10.105.255.1,ifconfig 10.105.11.3 255.255.0.0' Fri Oct 22 21:50:15 2004 OPTIONS IMPORT: timers and/or timeouts modified Fri Oct 22 21:50:15 2004 OPTIONS IMPORT: --ifconfig/up options modified Fri Oct 22 21:50:15 2004 OPTIONS IMPORT: route options modified Fri Oct 22 21:50:15 2004 OPTIONS IMPORT: --ip-win32 and/or --dhcp-option options modified Fri Oct 22 21:50:15 2004 TAP-WIN32 device [Local Area Connection 20] opened: \\.\Global\{ACF5AE0F-B0C0-443B-B14C-1B80544AE1F3}.tap Fri Oct 22 21:50:15 2004 TAP-Win32 Driver Version 8.1 Fri Oct 22 21:50:15 2004 TAP-Win32 MTU=1500 Fri Oct 22 21:50:15 2004 Notified TAP-Win32 driver to set a DHCP IP/netmask of 10.105.11.3/255.255.0.0 on interface {ACF5AE0F-B0C0-443B-B14C-1B80544AE1F3} [DHCP-serv: 10.105.0.0, lease-time: 31536000] Fri Oct 22 21:50:15 2004 Successful ARP Flush on interface [131077] {ACF5AE0F-B0C0-443B-B14C-1B80544AE1F3} Fri Oct 22 21:50:15 2004 TEST ROUTES: 0/0 succeeded len=9 ret=0 a=0 u/d=down Fri Oct 22 21:50:15 2004 Route: Waiting for TUN/TAP interface to come up... Fri Oct 22 21:50:16 2004 TEST ROUTES: 9/9 succeeded len=9 ret=1 a=0 u/d=up Fri Oct 22 21:50:16 2004 route ADD 193.15.191.32 MASK 255.255.255.240 10.105.255.1 Fri Oct 22 21:50:16 2004 Route addition via IPAPI succeeded Fri Oct 22 21:50:16 2004 route ADD 193.13.81.0 MASK 255.255.255.224 10.105.255.1 Fri Oct 22 21:50:16 2004 Route addition via IPAPI succeeded Fri Oct 22 21:50:16 2004 route ADD 213.247.12.96 MASK 255.255.255.248 10.105.255.1 Fri Oct 22 21:50:16 2004 Route addition via IPAPI succeeded Fri Oct 22 21:50:16 2004 route ADD 192.168.2.0 MASK 255.255.255.0 10.105.255.1 Fri Oct 22 21:50:16 2004 Route addition via IPAPI succeeded Fri Oct 22 21:50:16 2004 route ADD 172.16.1.0 MASK 255.255.255.0 10.105.255.1 Fri Oct 22 21:50:16 2004 Route addition via IPAPI succeeded Fri Oct 22 21:50:16 2004 route ADD 80.163.165.224 MASK 255.255.255.248 10.105.255.1 Fri Oct 22 21:50:16 2004 Route addition via IPAPI succeeded Fri Oct 22 21:50:16 2004 route ADD 212.247.12.96 MASK 255.255.255.248 10.105.255.1 Fri Oct 22 21:50:16 2004 Route addition via IPAPI succeeded Fri Oct 22 21:50:16 2004 route ADD 217.13.252.32 MASK 255.255.255.224 10.105.255.1 Fri Oct 22 21:50:16 2004 Route addition via IPAPI succeeded Fri Oct 22 21:50:16 2004 route ADD 217.13.252.160 MASK 255.255.255.224 10.105.255.1 Fri Oct 22 21:50:16 2004 Route addition via IPAPI succeeded Fri Oct 22 21:50:16 2004 Initialization Sequence Completed Fri Oct 22 22:50:13 2004 TLS: soft reset sec=0 bytes=607062/0 pkts=4898/0 Fri Oct 22 22:50:13 2004 VERIFY OK: depth=1, /C=SE/ST=NA/L=STOCKHOLM/O=xxxxxxx/CN=xxxxxxx.OpenVPN.CA/emailAddress=info@xxxxxxxxxx Fri Oct 22 22:50:13 2004 VERIFY OK: depth=0, /C=SE/ST=NA/O=xxxxxxx/CN=Server/emailAddress=info@xxxxxxxxxx Fri Oct 22 22:50:14 2004 Data Channel Encrypt: Cipher 'BF-CBC' initialized with 128 bit key Fri Oct 22 22:50:14 2004 Data Channel Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication Fri Oct 22 22:50:14 2004 Data Channel Decrypt: Cipher 'BF-CBC' initialized with 128 bit key Fri Oct 22 22:50:14 2004 Data Channel Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication Fri Oct 22 22:50:14 2004 Control Channel: TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA, 1024 bit RSA Fri Oct 22 23:50:13 2004 VERIFY OK: depth=1, /C=SE/ST=NA/L=STOCKHOLM/O=xxxxxxx/CN=xxxxxxx.OpenVPN.CA/emailAddress=info@xxxxxxxxxx Fri Oct 22 23:50:13 2004 VERIFY OK: depth=0, /C=SE/ST=NA/O=xxxxxxx/CN=Server/emailAddress=info@xxxxxxxxxx Fri Oct 22 23:50:14 2004 Data Channel Encrypt: Cipher 'BF-CBC' initialized with 128 bit key Fri Oct 22 23:50:14 2004 Data Channel Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication Fri Oct 22 23:50:14 2004 Data Channel Decrypt: Cipher 'BF-CBC' initialized with 128 bit key Fri Oct 22 23:50:14 2004 Data Channel Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication Fri Oct 22 23:50:14 2004 Control Channel: TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA, 1024 bit RSA


--
_____________________________________________________________
Mathias Sundman                  (^)   ASCII Ribbon Campaign
OpenVPN GUI for Windows           X    NO HTML/RTF in e-mail
http://www.nilings.se/openvpn    / \   NO Word docs in e-mail

____________________________________________
Openvpn-users mailing list
Openvpn-users@xxxxxxxxxxxxxxxxxxxxx
https://lists.sourceforge.net/lists/listinfo/openvpn-users

Follow-Ups:
- Re: [Openvpn-users] Connection reset, restarting [-1] without reason(?)
  - From: James Yonan

Prev by Date: Re: [Openvpn-users] Physical NIC IP being sent on TAP device. Hmmm.
Next by Date: Re: [Openvpn-users] Connection reset, restarting [-1] without reason(?)
Previous by thread: Re: [Openvpn-users] Can't ping, can't resolve DNS after openvpn connection established.
Next by thread: Re: [Openvpn-users] Connection reset, restarting [-1] without reason(?)
Index(es):
- Date
- Thread