[Openswan Users] Windows Mobile 6.5 connects, but loses connection

[Paul Wouters]

On Tue, 7 Sep 2010, Bart Smink wrote:

> I am trying to get Windows Mobile 6.5 to work with Openswan in combination with XL2TPD which is connected to freeradius. When
> I am trying to send data through the tunnel, the connection goes down, when I wait for 3 minutes, the connection goes down.
> 
> What I notice is that I get "ignoring informational payload, type INVALID_COOKIE msgid=00000000" messages. Openswan sees it as
> information messages, but I think it is the client trying to communicate.
> 
> I am using the example config file l2tp-cert.conf. I have not configured "esp=", because I would like Openswan to find out
> what encryption methods can be used, but this is not working.
> 
> Can someone help me?

Is this a recent openswan 2.6.x?

> Sep  7 15:50:31 gateway pluto[1749]: "l2tp-X.509"[11] 62.140.137.125 #14: STATE_MAIN_R2: sent MR2, expecting MI3
> Sep  7 15:50:32 gateway pluto[1749]: "l2tp-X.509"[11] 62.140.137.125 #14: discarding duplicate packet; already STATE_MAIN_R2
> Sep  7 15:50:34 gateway pluto[1749]: "l2tp-X.509"[11] 62.140.137.125 #14: Main mode peer ID is ID_DER_ASN1_DN: 'C=NL,
> ST=Utrecht, L=Utrecht, O=Testing Corporation, OU=Research and Development, CN=Left1024, E=admin at testingcorporation.nl'
> Sep  7 15:50:34 gateway pluto[1749]: "l2tp-X.509"[11] 62.140.137.125 #14: switched from "l2tp-X.509" to "l2tp-X.509"

This is a little odd.

> Sep  7 15:50:34 gateway pluto[1749]: "l2tp-X.509"[12] 62.140.137.125 #14: I am sending my cert
> Sep  7 15:50:34 gateway pluto[1749]: "l2tp-X.509"[12] 62.140.137.125 #14: deleting connection "l2tp-X.509" instance with peer
> 62.140.137.107 {isakmp=#0/ipsec=#13}
> Sep  7 15:50:34 gateway pluto[1749]: "l2tp-X.509" #13: deleting state (STATE_QUICK_R2)
> Sep  7 15:50:34 gateway pluto[1749]: "l2tp-X.509"[12] 62.140.137.125 #14: transition from state STATE_MAIN_R2 to state
> STATE_MAIN_R3
> Sep  7 15:50:34 gateway pluto[1749]: "l2tp-X.509"[12] 62.140.137.125 #14: new NAT mapping for #14, was 62.140.137.125:29237,
> now 62.140.137.125:29528
> Sep  7 15:50:34 gateway pluto[1749]: "l2tp-X.509"[12] 62.140.137.125 #14: STATE_MAIN_R3: sent MR3, ISAKMP SA established
> {auth=OAKLEY_RSA_SIG cipher=oakley_3des_cbc_192 prf=oakley_sha group=modp2048}
> Sep  7 15:50:34 gateway pluto[1749]: "l2tp-X.509"[12] 62.140.137.125 #14: peer client type is FQDN
> Sep  7 15:50:34 gateway pluto[1749]: "l2tp-X.509"[12] 62.140.137.125 #14: Applying workaround for MS-818043 NAT-T bug
> Sep  7 15:50:34 gateway pluto[1749]: "l2tp-X.509"[12] 62.140.137.125 #14: IDci was FQDN: U\221\224j, using
> NAT_OA=10.66.108.51/32 as IDci
> Sep  7 15:50:34 gateway pluto[1749]: "l2tp-X.509"[12] 62.140.137.125 #14: the peer proposed: 85.145.148.106/32:17/1701 ->
> 10.66.108.51/32:17/0

There might be confusion between the two instances.

> O=Testing Corporation, OU=Research and Development, CN=Left1024, E=admin at testingcorporation.nl,+S=C]:17/0===10.66.108.51/32
> Sep  7 15:50:34 gateway pluto[1749]: "l2tp-X.509"[12] 62.140.137.125 #16: transition from state STATE_QUICK_R0 to state
> STATE_QUICK_R1
> Sep  7 15:50:34 gateway pluto[1749]: "l2tp-X.509"[12] 62.140.137.125 #16: STATE_QUICK_R1: sent QR1, inbound IPsec SA
> installed, expecting QI2
> Sep  7 15:50:34 gateway pluto[1749]: "l2tp-X.509"[12] 62.140.137.125 #16: netlink_raw_eroute: WARNING: that_client port 0 and
> that_host port 29528 don't match. Using that_client port.
> Sep  7 15:50:34 gateway pluto[1749]: "l2tp-X.509"[12] 62.140.137.125 #16: transition from state STATE_QUICK_R1 to state
> STATE_QUICK_R2
> Sep  7 15:50:34 gateway pluto[1749]: "l2tp-X.509"[12] 62.140.137.125 #16: STATE_QUICK_R2: IPsec SA established transport mode
> {ESP=>0x00bc42b0 <0x44d1a644 xfrm=3DES_0-HMAC_SHA1 NATOA=10.66.108.51 NATD=62.140.137.125:29528 DPD=none}
> Sep  7 15:50:37 gateway pluto[1749]: "l2tp-X.509"[11] 62.140.137.125 #15: ignoring informational payload, type INVALID_COOKIE
> msgid=00000000

This looks like the phone started a new attempt from scratch (hence the null cookie)

> The output of xl2tpd -D:
> 
> xl2tpd[1808]: control_finish: Peer requested tunnel 14 twice, ignoring second one.
> xl2tpd[1808]: Connection established to 62.140.137.125, 1701.  Local: 15271, Remote: 14 (ref=0/0).  LNS session is 'default'
> xl2tpd[1808]: start_pppd: I'm running: 
> xl2tpd[1808]: "/usr/sbin/pppd" 
> xl2tpd[1808]: "passive" 
> xl2tpd[1808]: "nodetach" 
> xl2tpd[1808]: "172.28.1.1:172.28.1.10" 
> xl2tpd[1808]: "auth" 
> xl2tpd[1808]: "name" 
> xl2tpd[1808]: "Helios.Lan" 
> xl2tpd[1808]: "debug" 
> xl2tpd[1808]: "file" 
> xl2tpd[1808]: "/etc/ppp/options.xl2tpd" 
> xl2tpd[1808]: "/dev/pts/4" 
> xl2tpd[1808]: Call established with 62.140.137.125, Local: 38486, Remote: 1, Serial: 0
> xl2tpd[1808]: control_finish: Connection closed to 62.140.137.125, serial 0 ()
> xl2tpd[1808]: Terminating pppd: sending TERM signal to pid 6365
> xl2tpd[1808]: control_finish: Connection closed to 62.140.137.125, port 1701 (), Local: 15271, Remote: 14

Is there any pppd logs? add "debug" to /etc/ppp/options.xl2tpd and look there? This might simply be an
authentication error, and the logs at the openswan end just show the phone trying again from scratch.

Paul