I have an OpenVPN server with some clients and one of the client reported to me, that the connection is dropped every now and then.
I logged in to the client computer and extracted the logfile from the client, here it is:
Code: Select all
Tue Apr 02 15:36:41 2013 OpenVPN 2.3.0 x86_64-w64-mingw32 [SSL (OpenSSL)] [LZO] [PKCS11] [eurephia] [IPv6] built on Mar 7 2013
Tue Apr 02 15:36:41 2013 MANAGEMENT: TCP Socket listening on [AF_INET]127.0.0.1:25340
Tue Apr 02 15:36:41 2013 Need hold release from management interface, waiting...
Tue Apr 02 15:36:42 2013 MANAGEMENT: Client connected from [AF_INET]127.0.0.1:25340
Tue Apr 02 15:36:42 2013 MANAGEMENT: CMD 'state on'
Tue Apr 02 15:36:42 2013 MANAGEMENT: CMD 'log all on'
Tue Apr 02 15:36:42 2013 MANAGEMENT: CMD 'hold off'
Tue Apr 02 15:36:42 2013 MANAGEMENT: CMD 'hold release'
Tue Apr 02 15:36:50 2013 MANAGEMENT: CMD 'username "Auth" "*********"'
Tue Apr 02 15:36:50 2013 MANAGEMENT: CMD 'password [...]'
Tue Apr 02 15:36:50 2013 NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Tue Apr 02 15:36:50 2013 Control Channel Authentication: using 'ta.key' as a OpenVPN static key file
Tue Apr 02 15:36:50 2013 Outgoing Control Channel Authentication: Using 160 bit message hash 'SHA1' for HMAC authentication
Tue Apr 02 15:36:50 2013 Incoming Control Channel Authentication: Using 160 bit message hash 'SHA1' for HMAC authentication
Tue Apr 02 15:36:50 2013 Socket Buffers: R=[8192->8192] S=[8192->8192]
Tue Apr 02 15:36:50 2013 MANAGEMENT: >STATE:1364909810,RESOLVE,,,
Tue Apr 02 15:36:50 2013 UDPv4 link local: [undef]
Tue Apr 02 15:36:50 2013 UDPv4 link remote: [AF_INET]***.***.***.***:1194
Tue Apr 02 15:36:50 2013 MANAGEMENT: >STATE:1364909810,WAIT,,,
Tue Apr 02 15:36:50 2013 MANAGEMENT: >STATE:1364909810,AUTH,,,
Tue Apr 02 15:36:50 2013 TLS: Initial packet from [AF_INET]***.***.***.***:1194, sid=7deb5744 e1e20e31
Tue Apr 02 15:36:50 2013 VERIFY OK: depth=1, C=HU, ST=HU, L=Budapest, O=Budapest, OU=vpn, CN=openvpn.*****.info, name=openvpn.*****.info, emailAddress=info@*****.info
Tue Apr 02 15:36:50 2013 VERIFY OK: nsCertType=SERVER
Tue Apr 02 15:36:50 2013 VERIFY OK: depth=0, C=HU, ST=HU, L=Budapest, O=Budapest, OU=vpn, CN=openvpn.*****.info, name=openvpn.*****.info, emailAddress=info@*****.info
Tue Apr 02 15:36:51 2013 Data Channel Encrypt: Cipher 'BF-CBC' initialized with 128 bit key
Tue Apr 02 15:36:51 2013 Data Channel Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Tue Apr 02 15:36:51 2013 Data Channel Decrypt: Cipher 'BF-CBC' initialized with 128 bit key
Tue Apr 02 15:36:51 2013 Data Channel Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Tue Apr 02 15:36:51 2013 Control Channel: TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA, 2048 bit RSA
Tue Apr 02 15:36:51 2013 [openvpn.*****.info] Peer Connection Initiated with [AF_INET]***.***.***.***:1194
Tue Apr 02 15:36:52 2013 MANAGEMENT: >STATE:1364909812,GET_CONFIG,,,
Tue Apr 02 15:36:53 2013 SENT CONTROL [openvpn.*****.info]: 'PUSH_REQUEST' (status=1)
Tue Apr 02 15:36:53 2013 PUSH: Received control message: 'PUSH_REPLY,route 10.8.0.1,topology net30,ping 10,ping-restart 120,ifconfig 10.8.0.10 10.8.0.9'
Tue Apr 02 15:36:53 2013 OPTIONS IMPORT: timers and/or timeouts modified
Tue Apr 02 15:36:53 2013 OPTIONS IMPORT: --ifconfig/up options modified
Tue Apr 02 15:36:53 2013 OPTIONS IMPORT: route options modified
Tue Apr 02 15:36:53 2013 do_ifconfig, tt->ipv6=0, tt->did_ifconfig_ipv6_setup=0
Tue Apr 02 15:36:53 2013 MANAGEMENT: >STATE:1364909813,ASSIGN_IP,,10.8.0.10,
Tue Apr 02 15:36:53 2013 open_tun, tt->ipv6=0
Tue Apr 02 15:36:53 2013 TAP-WIN32 device [Helyi kapcsolat 2] opened: \\.\Global\{38814019-2D1D-4FD7-A1E2-107AA6B00886}.tap
Tue Apr 02 15:36:53 2013 TAP-Windows Driver Version 9.9
Tue Apr 02 15:36:53 2013 Notified TAP-Windows driver to set a DHCP IP/netmask of 10.8.0.10/255.255.255.252 on interface {38814019-2D1D-4FD7-A1E2-107AA6B00886} [DHCP-serv: 10.8.0.9, lease-time: 31536000]
Tue Apr 02 15:36:53 2013 Successful ARP Flush on interface [16] {38814019-2D1D-4FD7-A1E2-107AA6B00886}
Tue Apr 02 15:36:58 2013 TEST ROUTES: 1/1 succeeded len=1 ret=1 a=0 u/d=up
Tue Apr 02 15:36:58 2013 MANAGEMENT: >STATE:1364909818,ADD_ROUTES,,,
Tue Apr 02 15:36:58 2013 C:\Windows\system32\route.exe ADD 10.8.0.1 MASK 255.255.255.255 10.8.0.9
Tue Apr 02 15:36:58 2013 ROUTE: CreateIpForwardEntry succeeded with dwForwardMetric1=30 and dwForwardType=4
Tue Apr 02 15:36:58 2013 Route addition via IPAPI succeeded [adaptive]
Tue Apr 02 15:36:58 2013 Initialization Sequence Completed
Tue Apr 02 15:36:58 2013 MANAGEMENT: >STATE:1364909818,CONNECTED,SUCCESS,10.8.0.10,***.***.***.***
Tue Apr 02 15:49:32 2013 MANAGEMENT: CMD 'signal SIGHUP'
Tue Apr 02 15:49:32 2013 C:\Windows\system32\route.exe DELETE 10.8.0.1 MASK 255.255.255.255 10.8.0.9
Tue Apr 02 15:49:32 2013 Route deletion via IPAPI succeeded [adaptive]
Tue Apr 02 15:49:32 2013 Closing TUN/TAP interface
Tue Apr 02 15:49:32 2013 SIGHUP[hard,] received, process restarting
Tue Apr 02 15:49:32 2013 MANAGEMENT: >STATE:1364910572,RECONNECTING,SIGHUP,,
Tue Apr 02 15:49:32 2013 OpenVPN 2.3.0 x86_64-w64-mingw32 [SSL (OpenSSL)] [LZO] [PKCS11] [eurephia] [IPv6] built on Mar 7 2013
Tue Apr 02 15:49:39 2013 MANAGEMENT: CMD 'username "Auth" "******"'
Tue Apr 02 15:49:39 2013 MANAGEMENT: CMD 'password [...]'
Tue Apr 02 15:49:39 2013 Restart pause, 2 second(s)
Tue Apr 02 15:49:41 2013 NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Tue Apr 02 15:49:41 2013 Control Channel Authentication: using 'ta.key' as a OpenVPN static key file
Tue Apr 02 15:49:41 2013 Outgoing Control Channel Authentication: Using 160 bit message hash 'SHA1' for HMAC authentication
Tue Apr 02 15:49:41 2013 Incoming Control Channel Authentication: Using 160 bit message hash 'SHA1' for HMAC authentication
Tue Apr 02 15:49:41 2013 Socket Buffers: R=[8192->8192] S=[8192->8192]
Tue Apr 02 15:49:41 2013 MANAGEMENT: >STATE:1364910581,RESOLVE,,,
Tue Apr 02 15:49:41 2013 UDPv4 link local: [undef]
Tue Apr 02 15:49:41 2013 UDPv4 link remote: [AF_INET]***.***.***.***:1194
Tue Apr 02 15:49:41 2013 MANAGEMENT: >STATE:1364910581,WAIT,,,
Tue Apr 02 15:49:41 2013 MANAGEMENT: >STATE:1364910581,AUTH,,,
Tue Apr 02 15:49:41 2013 TLS: Initial packet from [AF_INET]***.***.***.***:1194, sid=09510fee a78914c0
Tue Apr 02 15:49:41 2013 VERIFY OK: depth=1, C=HU, ST=HU, L=Budapest, O=Budapest, OU=vpn, CN=openvpn.*****.info, name=openvpn.*****.info, emailAddress=info@*****.info
Tue Apr 02 15:49:41 2013 VERIFY OK: nsCertType=SERVER
Tue Apr 02 15:49:41 2013 VERIFY OK: depth=0, C=HU, ST=HU, L=Budapest, O=Budapest, OU=vpn, CN=openvpn.*****.info, name=openvpn.*****.info, emailAddress=info@*****.info
Tue Apr 02 15:49:41 2013 Data Channel Encrypt: Cipher 'BF-CBC' initialized with 128 bit key
Tue Apr 02 15:49:41 2013 Data Channel Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Tue Apr 02 15:49:41 2013 Data Channel Decrypt: Cipher 'BF-CBC' initialized with 128 bit key
Tue Apr 02 15:49:41 2013 Data Channel Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Tue Apr 02 15:49:41 2013 Control Channel: TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA, 2048 bit RSA
Tue Apr 02 15:49:41 2013 [openvpn.*****.info] Peer Connection Initiated with [AF_INET]***.***.***.***:1194
Tue Apr 02 15:49:42 2013 MANAGEMENT: >STATE:1364910582,GET_CONFIG,,,
Tue Apr 02 15:49:43 2013 SENT CONTROL [openvpn.*****.info]: 'PUSH_REQUEST' (status=1)
Tue Apr 02 15:49:43 2013 PUSH: Received control message: 'PUSH_REPLY,route 10.8.0.1,topology net30,ping 10,ping-restart 120,ifconfig 10.8.0.10 10.8.0.9'
Tue Apr 02 15:49:43 2013 OPTIONS IMPORT: timers and/or timeouts modified
Tue Apr 02 15:49:43 2013 OPTIONS IMPORT: --ifconfig/up options modified
Tue Apr 02 15:49:43 2013 OPTIONS IMPORT: route options modified
Tue Apr 02 15:49:43 2013 do_ifconfig, tt->ipv6=0, tt->did_ifconfig_ipv6_setup=0
Tue Apr 02 15:49:43 2013 MANAGEMENT: >STATE:1364910583,ASSIGN_IP,,10.8.0.10,
Tue Apr 02 15:49:43 2013 open_tun, tt->ipv6=0
Tue Apr 02 15:49:43 2013 TAP-WIN32 device [Helyi kapcsolat 2] opened: \\.\Global\{38814019-2D1D-4FD7-A1E2-107AA6B00886}.tap
Tue Apr 02 15:49:43 2013 TAP-Windows Driver Version 9.9
Tue Apr 02 15:49:43 2013 Notified TAP-Windows driver to set a DHCP IP/netmask of 10.8.0.10/255.255.255.252 on interface {38814019-2D1D-4FD7-A1E2-107AA6B00886} [DHCP-serv: 10.8.0.9, lease-time: 31536000]
Tue Apr 02 15:49:43 2013 Successful ARP Flush on interface [16] {38814019-2D1D-4FD7-A1E2-107AA6B00886}
Tue Apr 02 15:49:48 2013 TEST ROUTES: 1/1 succeeded len=1 ret=1 a=0 u/d=up
Tue Apr 02 15:49:48 2013 MANAGEMENT: >STATE:1364910588,ADD_ROUTES,,,
Tue Apr 02 15:49:48 2013 C:\Windows\system32\route.exe ADD 10.8.0.1 MASK 255.255.255.255 10.8.0.9
Tue Apr 02 15:49:48 2013 ROUTE: CreateIpForwardEntry succeeded with dwForwardMetric1=30 and dwForwardType=4
Tue Apr 02 15:49:48 2013 Route addition via IPAPI succeeded [adaptive]
Tue Apr 02 15:49:48 2013 Initialization Sequence Completed
Tue Apr 02 15:49:48 2013 MANAGEMENT: >STATE:1364910588,CONNECTED,SUCCESS,10.8.0.10,***.***.***.***
Tue Apr 02 15:51:02 2013 MANAGEMENT: CMD 'signal SIGHUP'
Tue Apr 02 15:51:02 2013 C:\Windows\system32\route.exe DELETE 10.8.0.1 MASK 255.255.255.255 10.8.0.9
Tue Apr 02 15:51:02 2013 Route deletion via IPAPI succeeded [adaptive]
Tue Apr 02 15:51:02 2013 Closing TUN/TAP interface
Tue Apr 02 15:51:02 2013 SIGHUP[hard,] received, process restarting
Tue Apr 02 15:51:02 2013 MANAGEMENT: >STATE:1364910662,RECONNECTING,SIGHUP,,
Tue Apr 02 15:51:02 2013 OpenVPN 2.3.0 x86_64-w64-mingw32 [SSL (OpenSSL)] [LZO] [PKCS11] [eurephia] [IPv6] built on Mar 7 2013
Tue Apr 02 15:51:09 2013 MANAGEMENT: CMD 'username "Auth" "******"'
Tue Apr 02 15:51:09 2013 MANAGEMENT: CMD 'password [...]'
Tue Apr 02 15:51:09 2013 Restart pause, 2 second(s)
Tue Apr 02 15:51:11 2013 NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Tue Apr 02 15:51:11 2013 Control Channel Authentication: using 'ta.key' as a OpenVPN static key file
Tue Apr 02 15:51:11 2013 Outgoing Control Channel Authentication: Using 160 bit message hash 'SHA1' for HMAC authentication
Tue Apr 02 15:51:11 2013 Incoming Control Channel Authentication: Using 160 bit message hash 'SHA1' for HMAC authentication
Tue Apr 02 15:51:11 2013 Socket Buffers: R=[8192->8192] S=[8192->8192]
Tue Apr 02 15:51:11 2013 MANAGEMENT: >STATE:1364910671,RESOLVE,,,
Tue Apr 02 15:51:11 2013 UDPv4 link local: [undef]
Tue Apr 02 15:51:11 2013 UDPv4 link remote: [AF_INET]***.***.***.***:1194
Tue Apr 02 15:51:11 2013 MANAGEMENT: >STATE:1364910671,WAIT,,,
Tue Apr 02 15:51:11 2013 MANAGEMENT: >STATE:1364910671,AUTH,,,
Tue Apr 02 15:51:11 2013 TLS: Initial packet from [AF_INET]***.***.***.***:1194, sid=ef6f8166 82a3d106
Tue Apr 02 15:51:11 2013 VERIFY OK: depth=1, C=HU, ST=HU, L=Budapest, O=Budapest, OU=vpn, CN=openvpn.*****.info, name=openvpn.*****.info, emailAddress=info@*****.info
Tue Apr 02 15:51:11 2013 VERIFY OK: nsCertType=SERVER
Tue Apr 02 15:51:11 2013 VERIFY OK: depth=0, C=HU, ST=HU, L=Budapest, O=Budapest, OU=vpn, CN=openvpn.*****.info, name=openvpn.*****.info, emailAddress=info@*****.info
Tue Apr 02 15:51:12 2013 Data Channel Encrypt: Cipher 'BF-CBC' initialized with 128 bit key
Tue Apr 02 15:51:12 2013 Data Channel Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Tue Apr 02 15:51:12 2013 Data Channel Decrypt: Cipher 'BF-CBC' initialized with 128 bit key
Tue Apr 02 15:51:12 2013 Data Channel Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Tue Apr 02 15:51:12 2013 Control Channel: TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA, 2048 bit RSA
Tue Apr 02 15:51:12 2013 [openvpn.*****.info] Peer Connection Initiated with [AF_INET]***.***.***.***:1194
Tue Apr 02 15:51:13 2013 MANAGEMENT: >STATE:1364910673,GET_CONFIG,,,
Tue Apr 02 15:51:14 2013 SENT CONTROL [openvpn.*****.info]: 'PUSH_REQUEST' (status=1)
Tue Apr 02 15:51:14 2013 PUSH: Received control message: 'PUSH_REPLY,route 10.8.0.1,topology net30,ping 10,ping-restart 120,ifconfig 10.8.0.10 10.8.0.9'
Tue Apr 02 15:51:14 2013 OPTIONS IMPORT: timers and/or timeouts modified
Tue Apr 02 15:51:14 2013 OPTIONS IMPORT: --ifconfig/up options modified
Tue Apr 02 15:51:14 2013 OPTIONS IMPORT: route options modified
Tue Apr 02 15:51:14 2013 do_ifconfig, tt->ipv6=0, tt->did_ifconfig_ipv6_setup=0
Tue Apr 02 15:51:14 2013 MANAGEMENT: >STATE:1364910674,ASSIGN_IP,,10.8.0.10,
Tue Apr 02 15:51:14 2013 open_tun, tt->ipv6=0
Tue Apr 02 15:51:14 2013 TAP-WIN32 device [Helyi kapcsolat 2] opened: \\.\Global\{38814019-2D1D-4FD7-A1E2-107AA6B00886}.tap
Tue Apr 02 15:51:14 2013 TAP-Windows Driver Version 9.9
Tue Apr 02 15:51:14 2013 Notified TAP-Windows driver to set a DHCP IP/netmask of 10.8.0.10/255.255.255.252 on interface {38814019-2D1D-4FD7-A1E2-107AA6B00886} [DHCP-serv: 10.8.0.9, lease-time: 31536000]
Tue Apr 02 15:51:14 2013 Successful ARP Flush on interface [16] {38814019-2D1D-4FD7-A1E2-107AA6B00886}
Tue Apr 02 15:51:19 2013 TEST ROUTES: 1/1 succeeded len=1 ret=1 a=0 u/d=up
Tue Apr 02 15:51:19 2013 MANAGEMENT: >STATE:1364910679,ADD_ROUTES,,,
Tue Apr 02 15:51:19 2013 C:\Windows\system32\route.exe ADD 10.8.0.1 MASK 255.255.255.255 10.8.0.9
Tue Apr 02 15:51:19 2013 ROUTE: CreateIpForwardEntry succeeded with dwForwardMetric1=30 and dwForwardType=4
Tue Apr 02 15:51:19 2013 Route addition via IPAPI succeeded [adaptive]
Tue Apr 02 15:51:19 2013 Initialization Sequence Completed
Tue Apr 02 15:51:19 2013 MANAGEMENT: >STATE:1364910679,CONNECTED,SUCCESS,10.8.0.10,***.***.***.***
Code: Select all
Tue Apr 02 15:49:48 2013 Route addition via IPAPI succeeded [adaptive]
Tue Apr 02 15:49:48 2013 Initialization Sequence Completed
Tue Apr 02 15:49:48 2013 MANAGEMENT: >STATE:1364910588,CONNECTED,SUCCESS,10.8.0.10,***.***.***.***
Tue Apr 02 15:51:02 2013 MANAGEMENT: CMD 'signal SIGHUP'
Tue Apr 02 15:51:02 2013 C:\Windows\system32\route.exe DELETE 10.8.0.1 MASK 255.255.255.255 10.8.0.9
Tue Apr 02 15:51:02 2013 Route deletion via IPAPI succeeded [adaptive]
Does anybody have any idea?
Thanks a lot!