Menu
▾
▴
Re: [Openvpn-users] Unexplainable "bad source address from client" after reconnect (bug?)
|
From: Erik LE V. <er...@le...> - 2014-10-29 17:29:40
|
Hi Dave, A question: do u use ccd/ individual confs files in order to push iroutes to each individual client ? I saw this error in most cases, when the client configuration file name located within the ccd/ directory of the server does not exactly correspond to the client CN. ie, if the CN for one of your clients is host1500.domain.com, the ccd file containing dedicated iroute to push to this particular client should be named host1500.domain.com (and not host1500 ie). How do you manage those confs on the server side ? I assume you generate kind of "on the fly" conf/ccd files with so many connections (like a unique hash or something) ? Hope this helps, Let us know, Thx E. Le 2014-10-29 10:29, David Schweikert a écrit : > Hi, > > We operate an OpenVPN network with about 2000 clients in the whole > world, sometimes with bad connections (packet loss and high RTT). > > Since a long time, we notice the following sporadic behavior: > > 1. The OpenVPN connection is lost by a client, who then tries another > server > 2. The connection comes up, but pings don't work > 3. The openvpn server is discarding incoming packets from the tunnel > > We had this behavior already with OpenVPN 2.1.1, and now use OpenVPN > 2.3.4. > > I did increase the verbosity on all severs to 4, and got a pretty > interesting > log, which clearly shows the problem (see below). > > Question: as far as I know, this message "bad source address from > client" > happens when the server sees an incoming packet on the tunnel for > which he has > no "iroute" entry. Why is this happening in this case? It wrote just > a few > minute before: > > Learn: 192.0.2.12 -> h55268/203.0.113.12:3144 > > And then, after 5 minutes: > > h55268/203.0.113.12:3144 MULTI: bad source address from client > [192.0.2.12], packet dropped > > That shouldn't happen, right? That's the correct tunnel IP of the > host... > > Thanks > David > > Here are the full logs with some comments: > > > --------------------------------------------------------------------------------- > > OpenVPN version: 2.3.4 > > * Used IPs (changed from real ones for privacy): > > 203.0.113.12: Client Public IP (name: h55268) > 192.0.2.1: Server Tunnel IP > 192.0.2.12: Client Tunnel IP > > * 08:53:00: first try > > Oct 29 08:53:00 v-gate openvpn[29681]: 203.0.113.12:3133 Re-using > SSL/TLS context > Oct 29 08:53:00 v-gate openvpn[29681]: 203.0.113.12:3133 LZO > compression initialized > Oct 29 08:53:00 v-gate openvpn[29681]: 203.0.113.12:3133 Control > Channel MTU parms [ L:1558 D:166 EF:66 EB:0 ET:0 EL:0 ] > Oct 29 08:53:00 v-gate openvpn[29681]: 203.0.113.12:3133 Data Channel > MTU parms [ L:1558 D:1450 EF:58 EB:135 ET:0 EL:0 AF:3/1 ] > Oct 29 08:53:00 v-gate openvpn[29681]: 203.0.113.12:3133 Local > Options String: 'V4,dev-type tun,link-mtu 1558,tun-mtu 1500,proto > UDPv4,comp-lzo,cipher AES-128-CBC,auth SHA1,keysize > 128,tls-auth,key-method 2,tls-server' > Oct 29 08:53:00 v-gate openvpn[29681]: 203.0.113.12:3133 Expected > Remote Options String: 'V4,dev-type tun,link-mtu 1558,tun-mtu > 1500,proto UDPv4,comp-lzo,cipher AES-128-CBC,auth SHA1,keysize > 128,tls-auth,key-method 2,tls-client' > Oct 29 08:53:00 v-gate openvpn[29681]: 203.0.113.12:3133 Local > Options hash (VER=V4): '2f29e19c' > Oct 29 08:53:00 v-gate openvpn[29681]: 203.0.113.12:3133 Expected > Remote Options hash (VER=V4): '9fde0044' > Oct 29 08:53:00 v-gate openvpn[29681]: 203.0.113.12:3133 TLS: Initial > packet from [AF_INET]203.0.113.12:3133, sid=ec179990 11c3ed56 > Oct 29 08:53:08 v-gate openvpn[29681]: 203.0.113.12:3133 VERIFY > SCRIPT OK: depth=1, C=CH, [...] > Oct 29 08:53:08 v-gate openvpn[29681]: 203.0.113.12:3133 VERIFY OK: > depth=1, C=CH, [...] > Oct 29 08:53:08 v-gate openvpn[29681]: 203.0.113.12:3133 VERIFY > SCRIPT OK: depth=0, C=CH, [...] > Oct 29 08:53:08 v-gate openvpn[29681]: 203.0.113.12:3133 VERIFY OK: > depth=0, C=CH, [...] > > * 08:54:00: timeout for TLS handshake > > Oct 29 08:54:00 v-gate openvpn[29681]: 203.0.113.12:3133 TLS Error: > TLS key negotiation failed to occur within 60 seconds (check your > network connectivity) > Oct 29 08:54:00 v-gate openvpn[29681]: 203.0.113.12:3133 TLS Error: > TLS handshake failed > Oct 29 08:54:00 v-gate openvpn[29681]: 203.0.113.12:3133 > SIGUSR1[soft,tls-error] received, client-instance restarting > > * 08:55:25: second try > > Oct 29 08:55:25 v-gate openvpn[29681]: 203.0.113.12:3128 Re-using > SSL/TLS context > Oct 29 08:55:25 v-gate openvpn[29681]: 203.0.113.12:3128 LZO > compression initialized > Oct 29 08:55:25 v-gate openvpn[29681]: 203.0.113.12:3128 Control > Channel MTU parms [ L:1558 D:166 EF:66 EB:0 ET:0 EL:0 ] > Oct 29 08:55:25 v-gate openvpn[29681]: 203.0.113.12:3128 Data Channel > MTU parms [ L:1558 D:1450 EF:58 EB:135 ET:0 EL:0 AF:3/1 ] > Oct 29 08:55:25 v-gate openvpn[29681]: 203.0.113.12:3128 Local > Options String: 'V4,dev-type tun,link-mtu 1558,tun-mtu 1500,proto > UDPv4,comp-lzo,cipher AES-128-CBC,auth SHA1,keysize > 128,tls-auth,key-method 2,tls-server' > Oct 29 08:55:25 v-gate openvpn[29681]: 203.0.113.12:3128 Expected > Remote Options String: 'V4,dev-type tun,link-mtu 1558,tun-mtu > 1500,proto UDPv4,comp-lzo,cipher AES-128-CBC,auth SHA1,keysize > 128,tls-auth,key-method 2,tls-client' > Oct 29 08:55:25 v-gate openvpn[29681]: 203.0.113.12:3128 Local > Options hash (VER=V4): '2f29e19c' > Oct 29 08:55:25 v-gate openvpn[29681]: 203.0.113.12:3128 Expected > Remote Options hash (VER=V4): '9fde0044' > Oct 29 08:55:25 v-gate openvpn[29681]: 203.0.113.12:3128 TLS: Initial > packet from [AF_INET]203.0.113.12:3128, sid=61f0e44c fe37d197 > Oct 29 08:55:32 v-gate openvpn[29681]: 203.0.113.12:3128 VERIFY > SCRIPT OK: depth=1, C=CH, [...] > Oct 29 08:55:32 v-gate openvpn[29681]: 203.0.113.12:3128 VERIFY OK: > depth=1, C=CH, [...] > Oct 29 08:55:32 v-gate openvpn[29681]: 203.0.113.12:3128 VERIFY > SCRIPT OK: depth=0, C=CH, [...] > Oct 29 08:55:32 v-gate openvpn[29681]: 203.0.113.12:3128 VERIFY OK: > depth=0, C=CH, [...] > Oct 29 08:55:41 v-gate openvpn[29681]: 203.0.113.12:3128 Data Channel > Encrypt: Cipher 'AES-128-CBC' initialized with 128 bit key > Oct 29 08:55:41 v-gate openvpn[29681]: 203.0.113.12:3128 Data Channel > Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication > Oct 29 08:55:41 v-gate openvpn[29681]: 203.0.113.12:3128 Data Channel > Decrypt: Cipher 'AES-128-CBC' initialized with 128 bit key > Oct 29 08:55:41 v-gate openvpn[29681]: 203.0.113.12:3128 Data Channel > Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication > > * 08:56:25: timeout for TLS handshake > > Oct 29 08:56:25 v-gate openvpn[29681]: 203.0.113.12:3128 TLS Error: > TLS key negotiation failed to occur within 60 seconds (check your > network connectivity) > Oct 29 08:56:25 v-gate openvpn[29681]: 203.0.113.12:3128 TLS Error: > TLS handshake failed > Oct 29 08:56:25 v-gate openvpn[29681]: 203.0.113.12:3128 > SIGUSR1[soft,tls-error] received, client-instance restarting > > * 09:03:50: third try, succesful this time > > Oct 29 09:03:50 v-gate openvpn[29681]: 203.0.113.12:3144 Re-using > SSL/TLS context > Oct 29 09:03:50 v-gate openvpn[29681]: 203.0.113.12:3144 LZO > compression initialized > Oct 29 09:03:50 v-gate openvpn[29681]: 203.0.113.12:3144 Control > Channel MTU parms [ L:1558 D:166 EF:66 EB:0 ET:0 EL:0 ] > Oct 29 09:03:50 v-gate openvpn[29681]: 203.0.113.12:3144 Data Channel > MTU parms [ L:1558 D:1450 EF:58 EB:135 ET:0 EL:0 AF:3/1 ] > Oct 29 09:03:50 v-gate openvpn[29681]: 203.0.113.12:3144 Local > Options String: 'V4,dev-type tun,link-mtu 1558,tun-mtu 1500,proto > UDPv4,comp-lzo,cipher AES-128-CBC,auth SHA1,keysize > 128,tls-auth,key-method 2,tls-server' > Oct 29 09:03:50 v-gate openvpn[29681]: 203.0.113.12:3144 Expected > Remote Options String: 'V4,dev-type tun,link-mtu 1558,tun-mtu > 1500,proto UDPv4,comp-lzo,cipher AES-128-CBC,auth SHA1,keysize > 128,tls-auth,key-method 2,tls-client' > Oct 29 09:03:50 v-gate openvpn[29681]: 203.0.113.12:3144 Local > Options hash (VER=V4): '2f29e19c' > Oct 29 09:03:50 v-gate openvpn[29681]: 203.0.113.12:3144 Expected > Remote Options hash (VER=V4): '9fde0044' > Oct 29 09:03:50 v-gate openvpn[29681]: 203.0.113.12:3144 TLS: Initial > packet from [AF_INET]203.0.113.12:3144, sid=72f54961 bee9340a > Oct 29 09:03:52 v-gate openvpn[29681]: 203.0.113.12:3144 VERIFY > SCRIPT OK: depth=1, C=CH, [...] > Oct 29 09:03:52 v-gate openvpn[29681]: 203.0.113.12:3144 VERIFY OK: > depth=1, C=CH, [...] > Oct 29 09:03:52 v-gate openvpn[29681]: 203.0.113.12:3144 VERIFY > SCRIPT OK: depth=0, C=CH, [...] > Oct 29 09:03:52 v-gate openvpn[29681]: 203.0.113.12:3144 VERIFY OK: > depth=0, C=CH, [...] > Oct 29 09:03:52 v-gate openvpn[29681]: 203.0.113.12:3144 Data Channel > Encrypt: Cipher 'AES-128-CBC' initialized with 128 bit key > Oct 29 09:03:52 v-gate openvpn[29681]: 203.0.113.12:3144 Data Channel > Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication > Oct 29 09:03:52 v-gate openvpn[29681]: 203.0.113.12:3144 Data Channel > Decrypt: Cipher 'AES-128-CBC' initialized with 128 bit key > Oct 29 09:03:52 v-gate openvpn[29681]: 203.0.113.12:3144 Data Channel > Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication > Oct 29 09:03:52 v-gate openvpn[29681]: 203.0.113.12:3144 Control > Channel: TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA, 1024 bit RSA > Oct 29 09:03:52 v-gate openvpn[29681]: 203.0.113.12:3144 [h55268] > Peer Connection Initiated with [AF_INET]203.0.113.12:3144 > Oct 29 09:03:52 v-gate openvpn[29681]: h55268/203.0.113.12:3144 > MULTI_sva: pool returned IPv4=192.0.2.12, IPv6=(Not enabled) > Oct 29 09:03:52 v-gate openvpn[29681]: OPENVPN:CLIENT:CONNECT h55268 > 203.0.113.12 BY 192.0.2.12 > Oct 29 09:03:52 v-gate openvpn[29681]: h55268/203.0.113.12:3144 > OPTIONS IMPORT: reading client specific options from: > /tmp/openvpn_cc_aeca221ba15dfff275feaca96fd6e33b.tmp > Oct 29 09:03:52 v-gate openvpn[29681]: h55268/203.0.113.12:3144 > MULTI: Learn: 192.0.2.12 -> h55268/203.0.113.12:3144 > Oct 29 09:03:52 v-gate openvpn[29681]: h55268/203.0.113.12:3144 > MULTI: primary virtual IP for h55268/203.0.113.12:3144: 192.0.2.12 > Oct 29 09:03:55 v-gate openvpn[29681]: h55268/203.0.113.12:3144 PUSH: > Received control message: 'PUSH_REQUEST' > Oct 29 09:03:55 v-gate openvpn[29681]: h55268/203.0.113.12:3144 > send_push_reply(): safe_cap=940 > Oct 29 09:03:55 v-gate openvpn[29681]: h55268/203.0.113.12:3144 SENT > CONTROL [h55268]: 'PUSH_REPLY,route 192.0.2.0 255.255.255.0 > vpn_gateway,topology p2p,ping 10,ping-restart 60,ifconfig 192.0.2.12 > 192.0.2.1' (status=1) > > * 09:08:57: incoming packets get dropped because of missing iroute > (?) > > Oct 29 09:08:57 v-gate openvpn[29681]: h55268/203.0.113.12:3144 > MULTI: bad source address from client [192.0.2.12], packet dropped > Oct 29 09:10:57 v-gate openvpn[29681]: h55268/203.0.113.12:3144 > MULTI: bad source address from client [192.0.2.12], packet dropped > Oct 29 09:12:57 v-gate openvpn[29681]: h55268/203.0.113.12:3144 > MULTI: bad source address from client [192.0.2.12], packet dropped > Oct 29 09:14:57 v-gate openvpn[29681]: h55268/203.0.113.12:3144 > MULTI: bad source address from client [192.0.2.12], packet dropped > Oct 29 09:16:57 v-gate openvpn[29681]: h55268/203.0.113.12:3144 > MULTI: bad source address from client [192.0.2.12], packet dropped > Oct 29 09:18:57 v-gate openvpn[29681]: h55268/203.0.113.12:3144 > MULTI: bad source address from client [192.0.2.12], packet dropped > Oct 29 09:20:57 v-gate openvpn[29681]: h55268/203.0.113.12:3144 > MULTI: bad source address from client [192.0.2.12], packet dropped > Oct 29 09:22:36 v-gate openvpn[29681]: h55268/203.0.113.12:3144 > MULTI: bad source address from client [192.0.2.12], packet dropped > Oct 29 09:22:57 v-gate openvpn[29681]: h55268/203.0.113.12:3144 > MULTI: bad source address from client [192.0.2.12], packet dropped > > > ------------------------------------------------------------------------------ > _______________________________________________ > Openvpn-users mailing list > Ope...@li... > https://lists.sourceforge.net/lists/listinfo/openvpn-users |
