MULTI: bad source address from client [x.x.x.x]

vcarrot-jim

First, I have done some research on this in this forum and elsewhere, and I have been unable to solve this issue. I'm sure I'm missing something fairly obvious, but I've banged my head against this for a few hours and can't figure it out.

I am trying to set up site-to-site vpn from our office network to an Amazon VPC.
Office network: 10.0.0.0/24
VPC: 10.1.0.0/20
VPN subnet: 10.1.1.0/24

Pinging from the openvpn client to the openvpn server is successful, but pinging from another machine on the office network fails, with the following message in the log:

Apr 27 21:11:44 tklvpn01 ovpn-server[3194]: prime/x.x.x.x:48373 MULTI: bad source address from client [10.0.0.100], packet dropped

Thanks in advance for any help or suggestions.

Jim

Server side configs:
/etc/openvpn/server.conf

port 1194
proto udp
dev tun

comp-lzo
keepalive 10 120

persist-key
persist-tun
user nobody
group nogroup

chroot /etc/openvpn/easy-rsa/keys/crl.jail
crl-verify crl.pem

ca /etc/openvpn/easy-rsa/keys/ca.crt
dh /etc/openvpn/easy-rsa/keys/dh1024.pem
tls-auth /etc/openvpn/easy-rsa/keys/ta.key 0
key /etc/openvpn/easy-rsa/keys/server.key
cert /etc/openvpn/easy-rsa/keys/server.crt

ifconfig-pool-persist /var/lib/openvpn/server.ipp
client-config-dir /etc/openvpn/server.ccd
status /var/log/openvpn/server.log
verb 4

server 10.1.1.0 255.255.255.0
route 10.0.0.0 255.255.255.0

/etc/openvpn/server.ccd/prime

iroute 10.0.0.0 255.255.255.0

Client config:

remote <x.x.x.x>
proto udp
ns-cert-type server

client
dev tun
resolv-retry infinite
keepalive 10 120
nobind
comp-lzo
verb 3

;user nobody
;group nogroup

key-direction 1

I have removed the embedded certificates from the client config.

Client log:

Apr 27 21:11:07 tklclientvpn01 ovpn-prime-to-oregon-AZ-A[2904]: OpenVPN 2.2.1 x86_64-linux-gnu [SSL] [LZO2] [EPOLL] [PKCS11] [eurephia] [MH] [PF_INET6] [IPv6 payload 20110424-2 (2.2RC2)] built on Jun 18 2013
Apr 27 21:11:07 tklclientvpn01 ovpn-prime-to-oregon-AZ-A[2904]: NOTE: OpenVPN 2.1 requires '--script-security 2' or higher to call user-defined scripts or executables
Apr 27 21:11:07 tklclientvpn01 ovpn-prime-to-oregon-AZ-A[2904]: Control Channel Authentication: tls-auth using INLINE static key file
Apr 27 21:11:07 tklclientvpn01 ovpn-prime-to-oregon-AZ-A[2904]: Outgoing Control Channel Authentication: Using 160 bit message hash 'SHA1' for HMAC authentication
Apr 27 21:11:07 tklclientvpn01 ovpn-prime-to-oregon-AZ-A[2904]: Incoming Control Channel Authentication: Using 160 bit message hash 'SHA1' for HMAC authentication
Apr 27 21:11:07 tklclientvpn01 ovpn-prime-to-oregon-AZ-A[2904]: LZO compression initialized
Apr 27 21:11:07 tklclientvpn01 ovpn-prime-to-oregon-AZ-A[2904]: Control Channel MTU parms [ L:1542 D:166 EF:66 EB:0 ET:0 EL:0 ]
Apr 27 21:11:07 tklclientvpn01 ovpn-prime-to-oregon-AZ-A[2904]: Socket Buffers: R=[229376->131072] S=[229376->131072]
Apr 27 21:11:07 tklclientvpn01 ovpn-prime-to-oregon-AZ-A[2904]: Data Channel MTU parms [ L:1542 D:1450 EF:42 EB:135 ET:0 EL:0 AF:3/1 ]
Apr 27 21:11:07 tklclientvpn01 ovpn-prime-to-oregon-AZ-A[2904]: Local Options hash (VER=V4): '504e774e'
Apr 27 21:11:07 tklclientvpn01 ovpn-prime-to-oregon-AZ-A[2904]: Expected Remote Options hash (VER=V4): '14168603'
Apr 27 21:11:07 tklclientvpn01 ovpn-prime-to-oregon-AZ-A[2905]: UDPv4 link local: [undef]
Apr 27 21:11:07 tklclientvpn01 ovpn-prime-to-oregon-AZ-A[2905]: UDPv4 link remote: [AF_INET]x.x.x.x:1194
Apr 27 21:11:07 tklclientvpn01 ovpn-prime-to-oregon-AZ-A[2905]: TLS: Initial packet from [AF_INET]x.x.x.x:1194, sid=2d180a5e fd176b9b
Apr 27 21:11:08 tklclientvpn01 ovpn-prime-to-oregon-AZ-A[2905]: VERIFY OK: depth=1, /C=US/ST=CA/L=San_Francisco/O=TurnKey_Linux/OU=OpenVPN/CN=server/name=openvpn/emailAddress=<snip>
Apr 27 21:11:08 tklclientvpn01 ovpn-prime-to-oregon-AZ-A[2905]: VERIFY OK: nsCertType=SERVER
Apr 27 21:11:08 tklclientvpn01 ovpn-prime-to-oregon-AZ-A[2905]: VERIFY OK: depth=0, /C=US/ST=CA/L=San_Francisco/O=TurnKey_Linux/OU=OpenVPN/CN=server/name=openvpn/emailAddress=<snip>
Apr 27 21:11:08 tklclientvpn01 ovpn-prime-to-oregon-AZ-A[2905]: Data Channel Encrypt: Cipher 'BF-CBC' initialized with 128 bit key
Apr 27 21:11:08 tklclientvpn01 ovpn-prime-to-oregon-AZ-A[2905]: Data Channel Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Apr 27 21:11:08 tklclientvpn01 ovpn-prime-to-oregon-AZ-A[2905]: Data Channel Decrypt: Cipher 'BF-CBC' initialized with 128 bit key
Apr 27 21:11:08 tklclientvpn01 ovpn-prime-to-oregon-AZ-A[2905]: Data Channel Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Apr 27 21:11:08 tklclientvpn01 ovpn-prime-to-oregon-AZ-A[2905]: Control Channel: TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA, 1024 bit RSA
Apr 27 21:11:08 tklclientvpn01 ovpn-prime-to-oregon-AZ-A[2905]: [server] Peer Connection Initiated with [AF_INET]x.x.x.x:1194
Apr 27 21:11:11 tklclientvpn01 ovpn-prime-to-oregon-AZ-A[2905]: SENT CONTROL [server]: 'PUSH_REQUEST' (status=1)
Apr 27 21:11:11 tklclientvpn01 ovpn-prime-to-oregon-AZ-A[2905]: PUSH: Received control message: 'PUSH_REPLY,route 10.1.1.1,topology net30,ping 10,ping-restart 120,ifconfig 10.1.1.6 10.1.1.5'
Apr 27 21:11:11 tklclientvpn01 ovpn-prime-to-oregon-AZ-A[2905]: OPTIONS IMPORT: timers and/or timeouts modified
Apr 27 21:11:11 tklclientvpn01 ovpn-prime-to-oregon-AZ-A[2905]: OPTIONS IMPORT: --ifconfig/up options modified
Apr 27 21:11:11 tklclientvpn01 ovpn-prime-to-oregon-AZ-A[2905]: OPTIONS IMPORT: route options modified
Apr 27 21:11:11 tklclientvpn01 ovpn-prime-to-oregon-AZ-A[2905]: ROUTE default_gateway=10.0.0.254
Apr 27 21:11:11 tklclientvpn01 ovpn-prime-to-oregon-AZ-A[2905]: TUN/TAP device tun0 opened
Apr 27 21:11:11 tklclientvpn01 ovpn-prime-to-oregon-AZ-A[2905]: TUN/TAP TX queue length set to 100
Apr 27 21:11:11 tklclientvpn01 ovpn-prime-to-oregon-AZ-A[2905]: do_ifconfig, tt->ipv6=0, tt->did_ifconfig_ipv6_setup=0
Apr 27 21:11:11 tklclientvpn01 ovpn-prime-to-oregon-AZ-A[2905]: /sbin/ifconfig tun0 10.1.1.6 pointopoint 10.1.1.5 mtu 1500
Apr 27 21:11:11 tklclientvpn01 ovpn-prime-to-oregon-AZ-A[2905]: /sbin/route add -net 10.1.1.1 netmask 255.255.255.255 gw 10.1.1.5
Apr 27 21:11:11 tklclientvpn01 ovpn-prime-to-oregon-AZ-A[2905]: Initialization Sequence Completed

Server log (configuration logging omitted, can include if necessary)

<configuration snipped>
Apr 27 21:11:19 tklvpn01 ovpn-server[3194]: chroot to '/etc/openvpn/easy-rsa/keys/crl.jail' and cd to '/' succeeded
Apr 27 21:11:19 tklvpn01 ovpn-server[3194]: GID set to nogroup
Apr 27 21:11:19 tklvpn01 ovpn-server[3194]: UID set to nobody
Apr 27 21:11:19 tklvpn01 ovpn-server[3194]: UDPv4 link local (bound): [undef]
Apr 27 21:11:19 tklvpn01 ovpn-server[3194]: UDPv4 link remote: [undef]
Apr 27 21:11:19 tklvpn01 ovpn-server[3194]: MULTI: multi_init called, r=256 v=256
Apr 27 21:11:19 tklvpn01 ovpn-server[3194]: IFCONFIG POOL: base=10.1.1.4 size=62, ipv6=0
Apr 27 21:11:19 tklvpn01 ovpn-server[3194]: ifconfig_pool_read(), in='prime,10.1.1.4', TODO: IPv6
Apr 27 21:11:19 tklvpn01 ovpn-server[3194]: succeeded -> ifconfig_pool_set()
Apr 27 21:11:19 tklvpn01 ovpn-server[3194]: IFCONFIG POOL LIST
Apr 27 21:11:19 tklvpn01 ovpn-server[3194]: prime,10.1.1.4
Apr 27 21:11:19 tklvpn01 ovpn-server[3194]: Initialization Sequence Completed
Apr 27 21:11:33 tklvpn01 ovpn-server[3194]: MULTI: multi_create_instance called
Apr 27 21:11:33 tklvpn01 ovpn-server[3194]: x.x.x.x:48373 Re-using SSL/TLS context
Apr 27 21:11:33 tklvpn01 ovpn-server[3194]: x.x.x.x:48373 LZO compression initialized
Apr 27 21:11:33 tklvpn01 ovpn-server[3194]: x.x.x.x:48373 Control Channel MTU parms [ L:1542 D:166 EF:66 EB:0 ET:0 EL:0 ]
Apr 27 21:11:33 tklvpn01 ovpn-server[3194]: x.x.x.x:48373 Data Channel MTU parms [ L:1542 D:1450 EF:42 EB:135 ET:0 EL:0 AF:3/1 ]
Apr 27 21:11:33 tklvpn01 ovpn-server[3194]: x.x.x.x:48373 Local Options String: 'V4,dev-type tun,link-mtu 1542,tun-mtu 1500,proto UDPv4,comp-lzo,keydir 0,cipher BF-CBC,auth SHA1,keysize 128,tls-auth,key-method 2,tls-server'
Apr 27 21:11:33 tklvpn01 ovpn-server[3194]: x.x.x.x:48373 Expected Remote Options String: 'V4,dev-type tun,link-mtu 1542,tun-mtu 1500,proto UDPv4,comp-lzo,keydir 1,cipher BF-CBC,auth SHA1,keysize 128,tls-auth,key-method 2,tls-client'
Apr 27 21:11:33 tklvpn01 ovpn-server[3194]: x.x.x.x:48373 Local Options hash (VER=V4): '14168603'
Apr 27 21:11:33 tklvpn01 ovpn-server[3194]: x.x.x.x:48373 Expected Remote Options hash (VER=V4): '504e774e'
Apr 27 21:11:33 tklvpn01 ovpn-server[3194]: x.x.x.x:48373 TLS: Initial packet from [AF_INET]x.x.x.x:48373, sid=9a600346 0b6b8f91
Apr 27 21:11:34 tklvpn01 ovpn-server[3194]: x.x.x.x:48373 CRL CHECK OK: /C=US/ST=CA/L=San_Francisco/O=TurnKey_Linux/OU=OpenVPN/CN=server/name=openvpn/emailAddress=admin@vcarrot.com
Apr 27 21:11:34 tklvpn01 ovpn-server[3194]: x.x.x.x:48373 VERIFY OK: depth=1, /C=US/ST=CA/L=San_Francisco/O=TurnKey_Linux/OU=OpenVPN/CN=server/name=openvpn/emailAddress=admin@vcarrot.com
Apr 27 21:11:34 tklvpn01 ovpn-server[3194]: x.x.x.x:48373 CRL CHECK OK: /C=US/ST=CA/L=San_Francisco/O=TurnKey_Linux/OU=OpenVPN/CN=prime/name=openvpn/emailAddress=admin@vcarrot.com
Apr 27 21:11:34 tklvpn01 ovpn-server[3194]: x.x.x.x:48373 VERIFY OK: depth=0, /C=US/ST=CA/L=San_Francisco/O=TurnKey_Linux/OU=OpenVPN/CN=prime/name=openvpn/emailAddress=admin@vcarrot.com
Apr 27 21:11:34 tklvpn01 ovpn-server[3194]: x.x.x.x:48373 Data Channel Encrypt: Cipher 'BF-CBC' initialized with 128 bit key
Apr 27 21:11:34 tklvpn01 ovpn-server[3194]: x.x.x.x:48373 Data Channel Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Apr 27 21:11:34 tklvpn01 ovpn-server[3194]: x.x.x.x:48373 Data Channel Decrypt: Cipher 'BF-CBC' initialized with 128 bit key
Apr 27 21:11:34 tklvpn01 ovpn-server[3194]: x.x.x.x:48373 Data Channel Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Apr 27 21:11:34 tklvpn01 ovpn-server[3194]: x.x.x.x:48373 Control Channel: TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA, 1024 bit RSA
Apr 27 21:11:34 tklvpn01 ovpn-server[3194]: x.x.x.x:48373 [prime] Peer Connection Initiated with [AF_INET]x.x.x.x:48373
Apr 27 21:11:34 tklvpn01 ovpn-server[3194]: prime/x.x.x.x:48373 MULTI_sva: pool returned IPv4=10.1.1.6, IPv6=2e00::68e4:819e:367f:0
Apr 27 21:11:34 tklvpn01 ovpn-server[3194]: prime/x.x.x.x:48373 MULTI: Learn: 10.1.1.6 -> prime/x.x.x.x:48373
Apr 27 21:11:34 tklvpn01 ovpn-server[3194]: prime/x.x.x.x:48373 MULTI: primary virtual IP for prime/x.x.x.x:48373: 10.1.1.6
Apr 27 21:11:37 tklvpn01 ovpn-server[3194]: prime/x.x.x.x:48373 PUSH: Received control message: 'PUSH_REQUEST'
Apr 27 21:11:37 tklvpn01 ovpn-server[3194]: prime/x.x.x.x:48373 send_push_reply(): safe_cap=960
Apr 27 21:11:37 tklvpn01 ovpn-server[3194]: prime/x.x.x.x:48373 SENT CONTROL [prime]: 'PUSH_REPLY,route 10.1.1.1,topology net30,ping 10,ping-restart 120,ifconfig 10.1.1.6 10.1.1.5' (status=1)
Apr 27 21:11:44 tklvpn01 ovpn-server[3194]: prime/x.x.x.x:48373 MULTI: bad source address from client [10.0.0.100], packet dropped

vcarrot-jim

Allow me to provide my thinking of the problem here, if it helps troubleshoot.

After applying the configuration above, I try to ping from another computer on the office network. Ping returns request timed out for each attempt, and every attempt is followed by the bad source address from client error appearing in the log. Everything I've looked up indicates that this is because the iroute statement is missing from the client config. However, as above, it is there and matches the office subnet. The directory structure and names were generated by the openvpn-addclient tool (not sure if this is part of the normal distribution or provided by TurnKey Linux), but I double checked those as well. Name on the client config file matches the CN on the client certificate. There are no security group restrictions on the client config file or directory that should cause a problem (owned by root:root but world readable), and if there were, openvpn is not complaining about it in any case. There is a static route on the office router pointing to the vpn client server, and since I am seeing entries in the server side log when I ping, it seems the packets are making it through - they're just being dropped.

My networking-fu is fairly weak, but I'm pretty certain the subnet definitions are correct. The client config looks right. The only hits I've gotten on google for this error are either a problem with the client config file, or Windows sending extraneous ipv6 packets which are then rejected.

Out of ideas at this point.

Jim