[Swan] EXPECTATION FAILED at libreswan-3.18 ikev2_parent.c !IS_CHILD_SA(st)

John Crisp jcrisp at safeandsoundit.co.uk
Fri Oct 28 17:39:06 UTC 2016 

Trying to set up a pure ipsec v2 connection from an Endian box with
Strongswan as initiator to Libreswan 3.18 receiver only

The connection comes up but pretty well immediately throws an error

[root at test ipsec.d]# tailf /var/log/pluto/pluto.log
Oct 27 13:15:31: | setup callback for interface lo:500 fd 20
Oct 27 13:15:31: | setup callback for interface eth0:4500 fd 19
Oct 27 13:15:31: | setup callback for interface eth0:500 fd 18
Oct 27 13:15:31: | setup callback for interface eth1:4500 fd 17
Oct 27 13:15:31: | setup callback for interface eth1:500 fd 16
Oct 27 13:15:31: loading secrets from "/etc/ipsec.secrets"
Oct 27 13:15:31: loading secrets from "/etc/ipsec.d/ipsec.secrets"
Oct 27 13:15:31: loading secrets from "/etc/ipsec.d/rsa.secrets"
Oct 27 13:15:31: loaded private key for keyid: PPK_RSA:AQPeO/dFJ
Oct 27 13:15:31: reapchild failed with errno=10 No child processes
Oct 27 13:20:15: packet from 1.2.3.4:500: ReetpToVoip IKE proposals for
initial responder:
1:IKE:ENCR=AES_GCM_C_256;PRF=HMAC_SHA2-512,HMAC_SHA2-256,HMAC_SHA1;INTEG=NONE;DH=MODP2048,MODP3072,MODP4096,MODP8192
2:IKE:ENCR=AES_GCM_C_128;PRF=HMAC_SHA2-512,HMAC_SHA2-256,HMAC_SHA1;INTEG=NONE;DH=MODP2048,MODP3072,MODP4096,MODP8192
3:IKE:ENCR=AES_CBC_256;PRF=HMAC_SHA2-512,HMAC_SHA2-256,HMAC_SHA1;INTEG=HMAC_SHA2_512_256,HMAC_SHA2_256_128,HMAC_SHA1_96;DH=MODP2048,MODP3072,MODP1536
4:IKE:ENCR=AES_CBC_128;PRF=HMAC_SHA2-512,HMAC_SHA2-256,HMAC_SHA1;INTEG=HMAC_SHA2_512_256,HMAC_SHA2_256_128,HMAC_SHA1_96;DH=MODP2048,MODP3072,MODP1536
(default)
Oct 27 13:20:15: packet from 1.2.3.4:500: proposal
1:IKE:ENCR=AES_CBC_256;PRF=HMAC_SHA2-256;INTEG=HMAC_SHA2_256_128;DH=MODP2048
chosen from:
1:IKE:ENCR=AES_CBC_256;INTEG=HMAC_SHA2_256_128;PRF=HMAC_SHA2-256;DH=MODP2048[first-match]
2:IKE:ENCR=AES_CBC_256;INTEG=HMAC_SHA2_256_128;PRF=HMAC_SHA2-256;DH=MODP1536
3:IKE:ENCR=AES_CBC_256;INTEG=HMAC_SHA2_384_192;PRF=HMAC_SHA2-384;DH=MODP2048
4:IKE:ENCR=AES_CBC_256;INTEG=HMAC_SHA2_384_192;PRF=HMAC_SHA2-384;DH=MODP1536
5:IKE:ENCR=AES_CBC_256;INTEG=HMAC_SHA2_512_256;PRF=HMAC_SHA2-512;DH=MODP2048
6:IKE:ENCR=AES_CBC_256;INTEG=HMAC_SHA2_512_256;PRF=HMAC_SHA2-512;DH=MODP1536
7:IKE:ENCR=AES_CBC_192;INTEG=HMAC_SHA2_256_128;PRF=HMAC_SHA2-256;DH=MODP2048
8:IKE:ENCR=AES_CBC_192;INTEG=HMAC_SHA2_256_128;PRF=HMAC_SHA2-256;DH=MODP1536
9:IKE:ENCR=AES_CBC_192;INTEG=HMAC_SHA2_384_192;PRF=HMAC_SHA2-384;DH=MODP2048
10:IKE:ENCR=AES_CBC_192;INTEG=HMAC_SHA2_384_192;PRF=HMAC_SHA2-384;DH=MODP1536
11:IKE:ENCR=AES_CBC_192;INTEG=HMAC_SHA2_512_256;PRF=HMAC_SHA2-512;DH=MODP2048
12:IKE:ENCR=AES_CBC_192;INTEG
Oct 27 13:20:15: "ReetpToVoip" #1: STATE_PARENT_R1: received v2I1, sent
v2R1 {auth=IKEv2 cipher=aes_256 integ=sha256_128 prf=OAKLEY_SHA2_256
group=MODP2048}
Oct 27 13:20:15: "ReetpToVoip" #1: new NAT mapping for #1, was
1.2.3.4:500, now 1.2.3.4:4500
Oct 27 13:20:15: "ReetpToVoip" #1: IKEv2 mode peer ID is ID_FQDN: '@endian'
Oct 27 13:20:15: "ReetpToVoip" #1: ReetpToVoip ESP/AH proposals for
responder: 1:ESP:ENCR=AES_GCM_C_256;INTEG=NONE;ESN=DISABLED
2:ESP:ENCR=AES_GCM_C_128;INTEG=NONE;ESN=DISABLED
3:ESP:ENCR=AES_CBC_256;INTEG=HMAC_SHA2_512_256,HMAC_SHA2_256_128;ESN=DISABLED
4:ESP:ENCR=AES_CBC_128;INTEG=HMAC_SHA2_512_256,HMAC_SHA2_256_128;ESN=DISABLED
5:ESP:ENCR=AES_CBC_128;INTEG=HMAC_SHA1_96;ESN=DISABLED (default)
Oct 27 13:20:15: "ReetpToVoip" #1: proposal
1:ESP:SPI=cbbfd7be;ENCR=AES_CBC_256;INTEG=HMAC_SHA2_256_128;ESN=DISABLED
chosen from:
1:ESP:ENCR=AES_CBC_256;INTEG=HMAC_SHA2_256_128;ESN=DISABLED[first-match]
2:ESP:ENCR=AES_CBC_256;INTEG=HMAC_SHA2_384_192;ESN=DISABLED
3:ESP:ENCR=AES_CBC_256;INTEG=HMAC_SHA2_512_256;ESN=DISABLED
4:ESP:ENCR=AES_CBC_192;INTEG=HMAC_SHA2_256_128;ESN=DISABLED
5:ESP:ENCR=AES_CBC_192;INTEG=HMAC_SHA2_384_192;ESN=DISABLED
6:ESP:ENCR=AES_CBC_192;INTEG=HMAC_SHA2_512_256;ESN=DISABLED
7:ESP:ENCR=AES_CBC_128;INTEG=HMAC_SHA2_256_128;ESN=DISABLED
8:ESP:ENCR=AES_CBC_128;INTEG=HMAC_SHA2_384_192;ESN=DISABLED
9:ESP:ENCR=AES_CBC_128;INTEG=HMAC_SHA2_512_256;ESN=DISABLED
10:ESP:ENCR=AES_CBC_128;ENCR=AES_CBC_192;ENCR=AES_CBC_256;ENCR=3DES;ENCR=BLOWFISH(obsoleted)_256;INTEG=HMAC_SHA1_96;INTEG=AES_XCBC_96;INTEG=HMAC_MD5_96;ESN=DISABLED
Oct 27 13:20:15: "ReetpToVoip" #2: negotiated connection
[192.168.97.0,192.168.97.255:0-65535 0] ->
[192.168.10.0,192.168.10.255:0-65535 0]
Oct 27 13:20:15: "ReetpToVoip" #2: STATE_PARENT_R2: received v2I2,
PARENT SA established tunnel mode {ESP=>0xcbbfd7be <0x0dcfd9eb
xfrm=AES_256-HMAC_SHA2_256 NATOA=none NATD= 1.2.3.4:4500 DPD=active}
Oct 27 13:20:35: "ReetpToVoip" #2: EXPECTATION FAILED at
/builddir/build/BUILD/libreswan-3.18/programs/pluto/ikev2_parent.c:4323:
!IS_CHILD_SA(st)

Traffic seems to pass OK.

The delay is 20secs after the link comes up which is the timeout set in
dpddelay.

If I remove dpddelay I do not get the error, but if the link goes down
it never gets cleared

I have seen the same sort of error with various different configs that I
have tried.


If I reset the Endian side I also get this in the logs:

Oct 27 13:24:59: "ReetpToVoip" #1: rejecting create child SA from
1.2.3.4:4500 -- new KE in DH for PFS is not yet supported
Oct 27 13:24:59: "ReetpToVoip" #1: sending unencrypted notification
v2N_INVALID_KE_PAYLOAD to 1.2.3.4:4500

I also see this a lot :

Oct 27 14:54:40: "HomeToVoip" #49: new NAT mapping for #49, was
1.2.3.4:500, now 1.2.3.4:4500
Oct 27 14:54:40: "HomeToVoip" #49: payload(s) (ISAKMP_NEXT_v2KE)
unexpected. Message dropped.
Oct 27 14:54:40: | ikev2_parent_inI2outR2_tail returned STF_FAIL with
v2N_INVALID_SYNTAX

I tried to simplify the setup as much as possible but still get errors
like this

Oct 28 19:27:57: "HomeToVoip" #106: failed to match authenticator
Oct 28 19:27:57: | ikev2_parent_inI2outR2_tail returned STF_FAIL

Oct 28 19:27:57: "HomeToVoip" #106: failed to match authenticator
Oct 28 19:27:57: | ikev2_parent_inI2outR2_tail returned STF_FAIL

Libre:

conn HomeToVoip
    type=tunnel
    authby=secret
    auto=add
    ikev2=insist
    ike=aes-sha1
    phase2alg=aes-sha1
    keyingtries=0
    ikelifetime=3600s
    salifetime=28800s
    dpdaction=clear
    dpddelay=30
    dpdtimeout=20
    pfs=yes
    left=%defaultroute
    leftid=@cloud
    leftsourceip=192.168.98.1
    leftsubnet=192.168.98.0/24
    right= 1.2.3.4
    rightid=@endian
    rightsubnet=192.168.10.0/24

Strongswan

conn Cloud
    dpdaction=restart
    left= 1.2.3.4
    leftsubnet=192.168.10.0/24
    right=5.6.7.8
    rightsubnet=192.168.98.0/24
    leftauth=psk
    rightauth=psk
    leftid="@endian"
    rightid="@cloud"
    ikelifetime=1h
    keylife=8h
    ike=aes256-sha2_256-modp2048
    esp=aes256-sha2_256-modp2048
    auto=start
    keyexchange=ikev2

Driving me mad trying to get a nice peaceful connection !

B. Rgds
John

-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 490 bytes
Desc: OpenPGP digital signature
URL: <https://lists.libreswan.org/pipermail/swan/attachments/20161028/e50539d8/attachment.sig>

More information about the Swan mailing list