[Openswan Users] openswan + l2tpd + iptables problem

Wed Oct 18 03:42:38 EDT 2006

Hi,

On Tue, Oct 17, 2006 at 03:22:59PM +0200, mechanix at debian.org wrote:
> 
> I've taken care of the MTU issues now; and SA negotiation succeeds.
> 
> I'm still stuck at l2tp being blocked by the iptables rules however.
> I have these rules present:
> 
> ...
> iptables -t mangle -A PREROUTING -p ESP -j MARK --set-mark 50
> iptables -A INPUT -m mark --mark 50 -p udp --dport 1701 -j ACCEPT
> ...
>
> These are all at the very beginning of their respective chains.

And here is one important rule missing:

iptables -t mangle -A PREROUTING -p UDP -i eth1 --dport 4500 --set-mark 50

... as the clients testing from were behind NAT, thus l2tp traffic came in
encrypted over udp-encap, not esp.

I'm getting close now, but I'm still not there yet -- now ppp login is
giving me troubles :-/

Here's my options.ppp.l2tpd for reference:

ipcp-accept-local
ipcp-accept-remote
ms-dns 192.168.2.254
auth
crtscts
idle 1800
mtu 1200
mru 1200
nodefaultroute
nodetach
debug
lock
proxyarp
connect-delay 5000
refuse-pap
require-mschap-v2
plugin winbind.so
ntlm_auth-helper '/usr/bin/ntlm_auth --helper-protocol=ntlm-server-1'

And here's what happens when I try to connect with a roadwarrior:

Oct 18 15:24:00 scotos l2tpd[16079]: start_pppd: I'm running:  
Oct 18 15:24:00 scotos l2tpd[16079]: "/usr/sbin/pppd" 
Oct 18 15:24:00 scotos l2tpd[16079]: "passive" 
Oct 18 15:24:00 scotos l2tpd[16079]: "-detach" 
Oct 18 15:24:00 scotos l2tpd[16079]: "192.168.2.254:192.168.2.201" 
Oct 18 15:24:00 scotos l2tpd[16079]: "auth" 
Oct 18 15:24:00 scotos l2tpd[16079]: "name" 
Oct 18 15:24:00 scotos l2tpd[16079]: "scotos" 
Oct 18 15:24:00 scotos l2tpd[16079]: "debug" 
Oct 18 15:24:00 scotos l2tpd[16079]: "file" 
Oct 18 15:24:00 scotos l2tpd[16079]: "/etc/ppp/options.l2tpd.lns" 
Oct 18 15:24:00 scotos l2tpd[16079]: "/dev/ttyp0" 
Oct 18 15:24:00 scotos l2tpd[16079]:  
Oct 18 15:24:00 scotos pppd[16120]: using channel 7
Oct 18 15:24:00 scotos pppd[16120]: sent [LCP ConfReq id=0x1 <mru 1200> <asyncmap 0x0> <auth chap MS-v2> <magic 0x9fcb8fc7> <pcomp> <accomp>]
Oct 18 15:24:00 scotos l2tpd[16079]: check_control: control, cid = 0, Ns = 4, Nr = 2 
Oct 18 15:24:00 scotos pppd[16120]: rcvd [LCP ConfReq id=0x0 <mru 1400> <magic 0x2c3d20c0> <pcomp> <accomp> <callback CBCP> <mrru 1614> <endpoint [local:95.21.d7.70.e2.45.4b.6a.ad.23.8b.3d.b6.46.05.06.00.00.00.02]>]
Oct 18 15:24:00 scotos pppd[16120]: sent [LCP ConfRej id=0x0 <callback CBCP> <mrru 1614>]
Oct 18 15:24:00 scotos pppd[16120]: rcvd [LCP ConfAck id=0x1 <mru 1200> <asyncmap 0x0> <auth chap MS-v2> <magic 0x9fcb8fc7> <pcomp> <accomp>]
Oct 18 15:24:00 scotos pppd[16120]: rcvd [LCP ConfReq id=0x1 <mru 1400> <magic 0x2c3d20c0> <pcomp> <accomp> <endpoint [local:95.21.d7.70.e2.45.4b.6a.ad.23.8b.3d.b6.46.05.06.00.00.00.02]>]
Oct 18 15:24:00 scotos pppd[16120]: sent [LCP ConfAck id=0x1 <mru 1400> <magic 0x2c3d20c0> <pcomp> <accomp> <endpoint [local:95.21.d7.70.e2.45.4b.6a.ad.23.8b.3d.b6.46.05.06.00.00.00.02]>]
Oct 18 15:24:00 scotos pppd[16120]: sent [LCP EchoReq id=0x0 magic=0x9fcb8fc7]
Oct 18 15:24:00 scotos pppd[16120]: sent [CHAP Challenge id=0x53 <b22178cb0709f40803f1366fa7719b06>, name = "scotos"]
Oct 18 15:24:01 scotos pppd[16120]: rcvd [LCP Ident id=0x2 magic=0x2c3d20c0 "MSRASV5.10"]
Oct 18 15:24:01 scotos pppd[16120]: rcvd [LCP Ident id=0x3 magic=0x2c3d20c0 "MSRAS-0-GANYMEDES"]
Oct 18 15:24:01 scotos pppd[16120]: rcvd [LCP EchoRep id=0x0 magic=0x2c3d20c0]
Oct 18 15:24:01 scotos pppd[16120]: rcvd [CHAP Response id=0x53 <f7c5659f6a71325156fdffbe7153b92f0000000000000000f498dd47a4fa81a298eb90e7d726198586a90a77b374b46b00>, name = "DOMAIN\\username"]
Oct 18 15:24:01 scotos pppd[16120]: sent [CHAP Success id=0x53 "S=31B24FEAAE17966BA335FEAEA577109E002F750E M=Access granted"]
Oct 18 15:24:01 scotos pppd[16120]: sent [CCP ConfReq id=0x1 <deflate 15> <deflate(old#) 15> <bsd v1 15>]
Oct 18 15:24:01 scotos pppd[16120]: sent [IPCP ConfReq id=0x1 <compress VJ 0f 01> <addr 192.168.2.254>]
Oct 18 15:24:01 scotos pppd[16120]: rcvd [CCP ConfReq id=0x4 <mppe +H -M -S -L -D +C>]
Oct 18 15:24:01 scotos pppd[16120]: sent [CCP ConfRej id=0x4 <mppe +H -M -S -L -D +C>]
Oct 18 15:24:01 scotos pppd[16120]: rcvd [IPCP ConfReq id=0x5 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-wins 0.0.0.0> <ms-dns3 0.0.0.0> <ms-wins 0.0.0.0>]
Oct 18 15:24:01 scotos pppd[16120]: sent [IPCP ConfRej id=0x5 <ms-wins 0.0.0.0> <ms-wins 0.0.0.0>]
Oct 18 15:24:01 scotos pppd[16120]: rcvd [CCP ConfRej id=0x1 <deflate 15> <deflate(old#) 15> <bsd v1 15>]
Oct 18 15:24:01 scotos pppd[16120]: sent [CCP ConfReq id=0x2]
Oct 18 15:24:01 scotos pppd[16120]: rcvd [IPCP ConfRej id=0x1 <compress VJ 0f 01>]
Oct 18 15:24:01 scotos pppd[16120]: sent [IPCP ConfReq id=0x2 <addr 192.168.2.254>]
Oct 18 15:24:03 scotos pppd[16120]: rcvd [IPCP ConfReq id=0x6 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-wins 0.0.0.0> <ms-dns3 0.0.0.0> <ms-wins 0.0.0.0>]
Oct 18 15:24:03 scotos pppd[16120]: sent [IPCP ConfRej id=0x6 <ms-wins 0.0.0.0> <ms-wins 0.0.0.0>]
Oct 18 15:24:03 scotos pppd[16120]: rcvd [CCP ConfReq id=0x7 <mppe +H -M -S -L -D +C>]
Oct 18 15:24:03 scotos pppd[16120]: sent [CCP ConfRej id=0x7 <mppe +H -M -S -L -D +C>]
Oct 18 15:24:04 scotos pppd[16120]: sent [CCP ConfReq id=0x2]
Oct 18 15:24:04 scotos pppd[16120]: sent [IPCP ConfReq id=0x2 <addr 192.168.2.254>]
Oct 18 15:24:06 scotos pppd[16120]: rcvd [IPCP ConfReq id=0x8 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-wins 0.0.0.0> <ms-dns3 0.0.0.0> <ms-wins 0.0.0.0>]
Oct 18 15:24:06 scotos pppd[16120]: sent [IPCP ConfRej id=0x8 <ms-wins 0.0.0.0> <ms-wins 0.0.0.0>]
Oct 18 15:24:07 scotos pppd[16120]: sent [CCP ConfReq id=0x2]
Oct 18 15:24:07 scotos pppd[16120]: sent [IPCP ConfReq id=0x2 <addr 192.168.2.254>]
Oct 18 15:24:08 scotos pppd[16120]: rcvd [CCP ConfReq id=0x9 <mppe +H -M -S -L -D +C>]
Oct 18 15:24:08 scotos pppd[16120]: sent [CCP ConfRej id=0x9 <mppe +H -M -S -L -D +C>]
Oct 18 15:24:10 scotos pppd[16120]: sent [CCP ConfReq id=0x2]
Oct 18 15:24:10 scotos pppd[16120]: sent [IPCP ConfReq id=0x2 <addr 192.168.2.254>]
Oct 18 15:24:11 scotos pppd[16120]: rcvd [IPCP ConfReq id=0xa <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-wins 0.0.0.0> <ms-dns3 0.0.0.0> <ms-wins 0.0.0.0>]
Oct 18 15:24:11 scotos pppd[16120]: sent [IPCP ConfRej id=0xa <ms-wins 0.0.0.0> <ms-wins 0.0.0.0>]
Oct 18 15:24:13 scotos pppd[16120]: rcvd [CCP ConfReq id=0xb <mppe +H -M -S -L -D +C>]
Oct 18 15:24:13 scotos pppd[16120]: sent [CCP ConfRej id=0xb <mppe +H -M -S -L -D +C>]
Oct 18 15:24:13 scotos pppd[16120]: sent [CCP ConfReq id=0x2]
Oct 18 15:24:13 scotos pppd[16120]: sent [IPCP ConfReq id=0x2 <addr 192.168.2.254>]
Oct 18 15:24:16 scotos pppd[16120]: rcvd [IPCP ConfReq id=0xc <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-wins 0.0.0.0> <ms-dns3 0.0.0.0> <ms-wins 0.0.0.0>]
Oct 18 15:24:16 scotos pppd[16120]: sent [IPCP ConfRej id=0xc <ms-wins 0.0.0.0> <ms-wins 0.0.0.0>]
Oct 18 15:24:16 scotos pppd[16120]: sent [CCP ConfReq id=0x2]
Oct 18 15:24:16 scotos pppd[16120]: sent [IPCP ConfReq id=0x2 <addr 192.168.2.254>]
Oct 18 15:24:18 scotos pppd[16120]: rcvd [CCP ConfReq id=0xd <mppe +H -M -S -L -D +C>]
Oct 18 15:24:18 scotos pppd[16120]: sent [CCP ConfRej id=0xd <mppe +H -M -S -L -D +C>]
Oct 18 15:24:19 scotos pppd[16120]: sent [CCP ConfReq id=0x2]
Oct 18 15:24:19 scotos pppd[16120]: sent [IPCP ConfReq id=0x2 <addr 192.168.2.254>]
Oct 18 15:24:21 scotos pppd[16120]: rcvd [IPCP ConfReq id=0xe <addr 0.0.0.0>]
Oct 18 15:24:21 scotos pppd[16120]: sent [IPCP ConfNak id=0xe <addr 192.168.2.201>]
Oct 18 15:24:22 scotos pppd[16120]: sent [CCP ConfReq id=0x2]
Oct 18 15:24:22 scotos pppd[16120]: sent [IPCP ConfReq id=0x2 <addr 192.168.2.254>]
Oct 18 15:24:23 scotos pppd[16120]: rcvd [CCP ConfReq id=0xf <mppe +H -M -S -L -D +C>]
Oct 18 15:24:23 scotos pppd[16120]: sent [CCP ConfRej id=0xf <mppe +H -M -S -L -D +C>]
Oct 18 15:24:25 scotos pppd[16120]: sent [CCP ConfReq id=0x2]
Oct 18 15:24:25 scotos pppd[16120]: sent [IPCP ConfReq id=0x2 <addr 192.168.2.254>]
Oct 18 15:24:26 scotos pppd[16120]: rcvd [IPCP ConfReq id=0x10 <addr 0.0.0.0>]
Oct 18 15:24:26 scotos pppd[16120]: sent [IPCP ConfNak id=0x10 <addr 192.168.2.201>]
Oct 18 15:24:28 scotos pppd[16120]: rcvd [CCP ConfReq id=0x11 <mppe +H -M -S -L -D +C>]
Oct 18 15:24:28 scotos pppd[16120]: sent [CCP ConfRej id=0x11 <mppe +H -M -S -L -D +C>]
Oct 18 15:24:28 scotos pppd[16120]: sent [CCP ConfReq id=0x2]
Oct 18 15:24:28 scotos pppd[16120]: sent [IPCP ConfReq id=0x2 <addr 192.168.2.254>]
Oct 18 15:24:30 scotos pppd[16120]: sent [LCP EchoReq id=0x1 magic=0x9fcb8fc7]
Oct 18 15:24:31 scotos pppd[16120]: rcvd [IPCP ConfReq id=0x12 <addr 0.0.0.0>]
Oct 18 15:24:31 scotos pppd[16120]: sent [IPCP ConfNak id=0x12 <addr 192.168.2.201>]
Oct 18 15:24:31 scotos pppd[16120]: sent [LCP TermReq id=0x2 "No network protocols running"]
Oct 18 15:24:33 scotos pppd[16120]: rcvd [CCP ConfReq id=0x13 <mppe +H -M -S -L -D +C>]
Oct 18 15:24:33 scotos pppd[16120]: Discarded non-LCP packet when LCP not open
Oct 18 15:24:34 scotos pppd[16120]: sent [LCP TermReq id=0x3 "No network protocols running"]
Oct 18 15:24:36 scotos pppd[16120]: rcvd [IPCP ConfReq id=0x14 <addr 0.0.0.0>]
Oct 18 15:24:36 scotos pppd[16120]: Discarded non-LCP packet when LCP not open
Oct 18 15:24:37 scotos l2tpd[16079]: child_handler : pppd exited for call 1 with code 16 
Oct 18 15:24:38 scotos l2tpd[16079]: write_packet: tty is not open yet. 
Oct 18 15:24:41 scotos l2tpd[16079]: write_packet: tty is not open yet. 
Oct 18 15:24:42 scotos l2tpd[16079]: control_xmit: Maximum retries exceeded for tunnel 57393.  Closing. 
Oct 18 15:24:43 scotos l2tpd[16079]: get_call: can't find call 43087 in tunnel 57393 
Oct 18 15:24:47 scotos l2tpd[16079]: control_xmit: Unable to deliver closing message for tunnel 57393. Destroying anyway. 
Oct 18 15:24:48 scotos l2tpd[16079]: get_call:can't find tunnel 57393 
Oct 18 15:24:48 scotos l2tpd[16079]: network_thread: unable to find call or tunnel to handle packet.  call = 43087, tunnel = 57393 Dumping. 
Oct 18 15:24:52 scotos l2tpd[16079]: get_call:can't find tunnel 57393 
Oct 18 15:24:52 scotos l2tpd[16079]: network_thread: unable to find call or tunnel to handle packet.  call = 43087, tunnel = 57393 Dumping. 
Oct 18 15:24:56 scotos l2tpd[16079]: get_call:can't find tunnel 57393 
Oct 18 15:24:56 scotos l2tpd[16079]: network_thread: unable to find call or tunnel to handle packet.  call = 43087, tunnel = 57393 Dumping. 
Oct 18 15:25:06 scotos l2tpd[16079]: get_call:can't find tunnel 57393 
Oct 18 15:25:06 scotos l2tpd[16079]: network_thread: unable to find call or tunnel to handle packet.  call = 43087, tunnel = 57393 Dumping. 

It looks like the windows client never accepts the provided IP address,
but I have no idea why. The same client works fine when connecting to the
gateway in .be instead.

Any ideas?

Regards,

Filip

-- 
http://slider.rack66.net/~mechanix/blog/