[OpenVPN home] [Date Prev] [Date Index] [Date Next]
[OpenVPN mailing lists] [Thread Prev] [Thread Index] [Thread Next]
Google
 
Web openvpn.net

Re: [Openvpn-users] Multiple "PUSH:" line logged?


  • Subject: Re: [Openvpn-users] Multiple "PUSH:" line logged?
  • From: Ralf Hildebrandt <Ralf.Hildebrandt@xxxxxxxxxx>
  • Date: Wed, 2 Jan 2008 23:21:38 +0100

* Ralf Hildebrandt <Ralf.Hildebrandt@xxxxxxxxxx>:
> I'm debugging a strange "connection hanging" problem with our openvpn
> setup here. Sometimes, the VPN connection would hang (no packet goes
> through for about 10 seconds, according to the mtr output)
> 
> One thing I noticed is that the connection is "hanging" whenever I see
> this in the log:
> 
> Jan  2 23:01:35 vpn-gw-int ovpn-server[12799]: aweima.vpn.charite.de/91.63.211.238:62245 PUSH: Received control message: 'PUSH_REQUEST'
> Jan  2 23:01:35 vpn-gw-int ovpn-server[12799]: aweima.vpn.charite.de/91.63.211.238:62245 PUSH: Received control message: 'PUSH_REQUEST'
> Jan  2 23:01:35 vpn-gw-int ovpn-server[12799]: aweima.vpn.charite.de/91.63.211.238:62245 PUSH: Received control message: 'PUSH_REQUEST'
> Jan  2 23:01:36 vpn-gw-int ovpn-server[12799]: aweima.vpn.charite.de/91.63.211.238:62245 PUSH: Received control message: 'PUSH_REQUEST'
> 
> (I didn't duplicate the lines, they were logged that way!)
> 
> I'm seeing this with some clients only:
> 
> Jan  2 23:03:50 vpn-gw-int ovpn-server[12799]: brost.vpn.charite.de/87.185.222.132:1155 PUSH: Received control message: 'PUSH_REQUEST'
> Jan  2 23:03:50 vpn-gw-int ovpn-server[12799]: brost.vpn.charite.de/87.185.222.132:1155 PUSH: Received control message: 'PUSH_REQUEST'
> Jan  2 23:03:50 vpn-gw-int ovpn-server[12799]: brost.vpn.charite.de/87.185.222.132:1155 PUSH: Received control message: 'PUSH_REQUEST'
> Jan  2 23:03:50 vpn-gw-int ovpn-server[12799]: brost.vpn.charite.de/87.185.222.132:1155 PUSH: Received control message: 'PUSH_REQUEST'

That user sent me his client's log:

Wed Jan 02 23:03:19 2008 OpenVPN 2.0.9 Win32-MinGW [SSL] [LZO] built on Oct  1 2006
Wed Jan 02 23:03:25 2008 LZO compression initialized
Wed Jan 02 23:03:25 2008 Control Channel MTU parms [ L:1542 D:138 EF:38 EB:0 ET:0 EL:0 ]
Wed Jan 02 23:03:26 2008 Data Channel MTU parms [ L:1542 D:1450 EF:42 EB:135 ET:0 EL:0 AF:3/1 ]
Wed Jan 02 23:03:26 2008 Local Options hash (VER=V4): '41690919'
Wed Jan 02 23:03:26 2008 Expected Remote Options hash (VER=V4): '530fdded'
Wed Jan 02 23:03:26 2008 UDPv4 link local: [undef]
Wed Jan 02 23:03:26 2008 UDPv4 link remote: 193.175.73.100:1194
Wed Jan 02 23:03:26 2008 TLS: Initial packet from 193.175.73.100:1194, sid=132c8828 9699c433
Wed Jan 02 23:03:30 2008 VERIFY OK: depth=1, /C=DE/ST=BERLIN/L=BERLIN/O=OpenVPN-Charite/CN=OpenVPN-Charite-CA/emailAddress=einwahl-admin@xxxxxxxxxx
Wed Jan 02 23:03:30 2008 VERIFY OK: depth=0, /C=DE/ST=BERLIN/O=OpenVPN-Charite/CN=server/emailAddress=einwahl-admin@xxxxxxxxxx
Wed Jan 02 23:03:35 2008 Data Channel Encrypt: Cipher 'BF-CBC' initialized with 128 bit key
Wed Jan 02 23:03:35 2008 Data Channel Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Wed Jan 02 23:03:35 2008 Data Channel Decrypt: Cipher 'BF-CBC' initialized with 128 bit key
Wed Jan 02 23:03:35 2008 Data Channel Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Wed Jan 02 23:03:35 2008 Control Channel: TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA, 1024 bit RSA
Wed Jan 02 23:03:35 2008 [server] Peer Connection Initiated with 193.175.73.100:1194

Wed Jan 02 23:03:36 2008 SENT CONTROL [server]: 'PUSH_REQUEST' (status=1)
Wed Jan 02 23:03:41 2008 SENT CONTROL [server]: 'PUSH_REQUEST' (status=1)
Wed Jan 02 23:03:47 2008 SENT CONTROL [server]: 'PUSH_REQUEST' (status=1)
Wed Jan 02 23:03:51 2008 SENT CONTROL [server]: 'PUSH_REQUEST' (status=1)

Wed Jan 02 23:03:51 2008 PUSH: Received control message: 'PUSH_REPLY,dhcp-option DNS 193.175.66.33,dhcp-option DNS 
   193.175.70.246,dhcp-option DOMAIN charite.de,dhcp-option WINS 
   10.47.2.200,dhcp-option WINS 141.42.111.210,dhcp-option WINS 
   10.43.120.59,route 172.28.0.1,ping 10,ping-restart 
   120,redirect-gateway,ifconfig 172.28.20.69 172.28.20.70'
Wed Jan 02 23:03:51 2008 OPTIONS IMPORT: timers and/or timeouts modified
Wed Jan 02 23:03:51 2008 OPTIONS IMPORT: --ifconfig/up options modified
Wed Jan 02 23:03:51 2008 OPTIONS IMPORT: route options modified
Wed Jan 02 23:03:51 2008 OPTIONS IMPORT: --ip-win32 and/or --dhcp-option  options modified
Wed Jan 02 23:03:51 2008 TAP-WIN32 device [LAN-Verbindung 2] opened: \\.\Global\{7B4C4494-0C33-47C0-BD61-10817BBD2D42}.tap
Wed Jan 02 23:03:51 2008 TAP-Win32 Driver Version 8.4
Wed Jan 02 23:03:51 2008 TAP-Win32 MTU=1500
Wed Jan 02 23:03:51 2008 Notified TAP-Win32 driver to set a DHCP IP/netmask of 172.28.20.69/255.255.255.252 on interface {7B4C4494-0C33-47C0-BD61-10817BBD2D42} [DHCP-serv: 172.28.20.70, lease-time: 31536000]
Wed Jan 02 23:03:51 2008 Successful ARP Flush on interface [2] {7B4C4494-0C33-47C0-BD61-10817BBD2D42}
Wed Jan 02 23:03:51 2008 TEST ROUTES: 0/0 succeeded len=1 ret=0 a=0 u/d=down
Wed Jan 02 23:03:51 2008 Route: Waiting for TUN/TAP interface to come up...
Wed Jan 02 23:03:51 2008 PUSH: Received control message: 'PUSH_REPLY,dhcp-option DNS 193.175.66.33,dhcp-option DNS 
  193.175.70.246,dhcp-option DOMAIN charite.de,dhcp-option WINS 
  10.47.2.200,dhcp-option WINS 141.42.111.210,dhcp-option WINS 
  10.43.120.59,route 172.28.0.1,ping 10,ping-restart 
  120,redirect-gateway,ifconfig 172.28.20.69 172.28.20.70'
Wed Jan 02 23:03:51 2008 PUSH: Received control message: 'PUSH_REPLY,dhcp-option DNS 193.175.66.33,dhcp-option DNS 
  193.175.70.246,dhcp-option DOMAIN charite.de,dhcp-option WINS 
  10.47.2.200,dhcp-option WINS 141.42.111.210,dhcp-option WINS 
  10.43.120.59,route 172.28.0.1,ping 10,ping-restart 
  120,redirect-gateway,ifconfig 172.28.20.69 172.28.20.70'
Wed Jan 02 23:03:51 2008 PUSH: Received control message: 'PUSH_REPLY,dhcp-option DNS 193.175.66.33,dhcp-option DNS 
  193.175.70.246,dhcp-option DOMAIN charite.de,dhcp-option WINS 
  10.47.2.200,dhcp-option WINS 141.42.111.210,dhcp-option WINS 
  10.43.120.59,route 172.28.0.1,ping 10,ping-restart 
  120,redirect-gateway,ifconfig 172.28.20.69 172.28.20.70'
Wed Jan 02 23:03:53 2008 TEST ROUTES: 0/0 succeeded len=1 ret=0 a=0 u/d=down
Wed Jan 02 23:03:53 2008 Route: Waiting for TUN/TAP interface to come up...
Wed Jan 02 23:03:54 2008 TEST ROUTES: 0/0 succeeded len=1 ret=0 a=0 u/d=down
Wed Jan 02 23:03:54 2008 Route: Waiting for TUN/TAP interface to come up...
Wed Jan 02 23:03:55 2008 TEST ROUTES: 0/0 succeeded len=1 ret=0 a=0 u/d=down
Wed Jan 02 23:03:55 2008 Route: Waiting for TUN/TAP interface to come up...
Wed Jan 02 23:03:56 2008 TEST ROUTES: 0/0 succeeded len=1 ret=0 a=0 u/d=down
Wed Jan 02 23:03:56 2008 Route: Waiting for TUN/TAP interface to come up...
Wed Jan 02 23:03:57 2008 TEST ROUTES: 2/2 succeeded len=1 ret=1 a=0 u/d=up
Wed Jan 02 23:03:57 2008 route ADD 193.175.73.100 MASK 255.255.255.255 192.168.2.1
Wed Jan 02 23:03:57 2008 Route addition via IPAPI succeeded
Wed Jan 02 23:03:57 2008 route DELETE 0.0.0.0 MASK 0.0.0.0 192.168.2.1
Wed Jan 02 23:03:58 2008 Route deletion via IPAPI succeeded
Wed Jan 02 23:03:58 2008 route ADD 0.0.0.0 MASK 0.0.0.0 172.28.20.70
Wed Jan 02 23:03:58 2008 Route addition via IPAPI succeeded
Wed Jan 02 23:03:58 2008 route ADD 172.28.0.1 MASK 255.255.255.255 172.28.20.70
Wed Jan 02 23:03:58 2008 Route addition via IPAPI succeeded
Wed Jan 02 23:03:58 2008 Initialization Sequence Completed
______________________
OpenVPN mailing lists
https://lists.sourceforge.net/lists/listinfo/openvpn-users