[strongSwan] Replay state copy problem after UPD_SA_ADDR, ikev2/mobike

Kimmo Koivisto koippa at gmail.com
Thu Feb 9 13:17:40 CET 2012 

Hello

I have Windows 7 client and I'm using strongswan 4.6.1 as vpn server,
Centos 5.7 with kernel 2.6.18-274.7.1.el5. Ikev2 and Mobike is used
and I can establish tunnels ok and traffic works until I change
network interface from Windows 7 client.

First I have LAN connected and  Win7 client negotiates tunnels ok.
When I change interface to WLAN, I can see from the log:
 Feb  9 13:50:10 vpn2 charon: 06[ENC] parsed INFORMATIONAL request 5 [
N(UPD_SA_ADDR) N(NATD_S_IP) N(NATD_D_IP) N(COOKIE2) ]
, where Win7 client informs about the address update. After this,
traffic does not work anymore. I can see from the log:
 Feb  9 13:50:10 vpn2 charon: 06[KNL] unable to copy replay state from
old SAD entry with SPI c62cb34c
 Feb  9 13:50:10 vpn2 charon: 06[KNL] unable to copy replay state from
old SAD entry with SPI b33d56aa

Does the above mean that replay protection window is not copied from
old SA and thus new SA cannot work?
Is this a valid problem or my misconfiguration?

I can get the connection up and running using DPD delay
Feb  9 13:55:11 vpn2 charon: 08[IKE] sending DPD request

, for example 300s but this is not really Mobike :=)
Searched from google, but did not find any similar problems.


Best Regards,
Kimmo Koivisto


full log:

Feb  9 13:39:48 vpn2 charon: 12[NET] received packet: from
client-public-ip[500] to vpn-server-ip[500]
Feb  9 13:39:48 vpn2 charon: 12[ENC] parsed IKE_SA_INIT request 0 [ SA
KE No N(NATD_S_IP) N(NATD_D_IP) ]
Feb  9 13:39:48 vpn2 charon: 12[IKE] client-public-ip is initiating an IKE_SA
Feb  9 13:39:48 vpn2 charon: 12[IKE] remote host is behind NAT
Feb  9 13:39:48 vpn2 charon: 12[IKE] sending cert request for
"DC=local, DC=example, CN=Example Domain CA"
Feb  9 13:39:48 vpn2 charon: 12[ENC] generating IKE_SA_INIT response 0
[ SA KE No N(NATD_S_IP) N(NATD_D_IP) CERTREQ N(MULT_AUTH) ]
Feb  9 13:39:48 vpn2 charon: 12[NET] sending packet: from
vpn-server-ip[500] to client-public-ip[500]
Feb  9 13:39:48 vpn2 charon: 06[NET] received packet: from
client-public-ip[4500] to vpn-server-ip[4500]
Feb  9 13:39:48 vpn2 charon: 06[ENC] unknown attribute type INTERNAL_IP4_SERVER
Feb  9 13:39:48 vpn2 charon: 06[ENC] parsed IKE_AUTH request 1 [ IDi
CERT CERTREQ AUTH N(MOBIKE_SUP) CP(ADDR DNS NBNS SRV) SA TSi TSr ]
Feb  9 13:39:48 vpn2 charon: 06[IKE] received cert request for
"DC=local, DC=example, CN=Example Domain CA"
Feb  9 13:39:48 vpn2 charon: 06[IKE] received 315 cert requests for an
unknown ca
Feb  9 13:39:48 vpn2 charon: 06[IKE] received end entity cert
"CN=EXAMPLE-User.example.local"
Feb  9 13:39:48 vpn2 charon: 06[CFG] looking for peer configs matching
vpn-server-ip[%any]...client-public-ip[CN=EXAMPLE-User.example.local]
Feb  9 13:39:48 vpn2 charon: 06[CFG] selected peer config 'win7'
Feb  9 13:39:48 vpn2 charon: 06[CFG]   using certificate
"CN=EXAMPLE-User.example.local"
Feb  9 13:39:48 vpn2 charon: 06[CFG]   using trusted ca certificate
"DC=local, DC=example, CN=Example Domain CA"
Feb  9 13:39:48 vpn2 charon: 06[CFG] checking certificate status of
"CN=EXAMPLE-User.example.local"
Feb  9 13:39:48 vpn2 charon: 06[CFG]   using trusted certificate
"DC=local, DC=example, CN=Example Domain CA"
Feb  9 13:39:48 vpn2 charon: 06[CFG]   crl correctly signed by
"DC=local, DC=example, CN=Example Domain CA"
Feb  9 13:39:48 vpn2 charon: 06[CFG]   crl is valid: until Feb 12 08:42:07 2012
Feb  9 13:39:48 vpn2 charon: 06[CFG]   using cached crl
Feb  9 13:39:48 vpn2 charon: 06[CFG]   fetching crl from
'ldap:///CN=Example%20Domain%20CA,CN=ad,CN=CDP,CN=Public%20Key%20Services,CN=Services,CN=Configuration,DC=example,DC=local?deltaRevocationList?base?objectClass=cRLDistributionPoint'
...
Feb  9 13:39:48 vpn2 charon: 06[LIB] LDAP bind to
'ldap:///CN=Example%20Domain%20CA,CN=ad,CN=CDP,CN=Public%20Key%20Services,CN=Services,CN=Configuration,DC=example,DC=local?deltaRevocationList?base?objectClass=cRLDistributionPoint'
failed: Can't contact LDAP server
Feb  9 13:39:48 vpn2 charon: 06[CFG] crl fetching failed
Feb  9 13:39:48 vpn2 charon: 06[CFG] certificate status is good
Feb  9 13:39:48 vpn2 charon: 06[CFG]   reached self-signed root ca
with a path length of 0
Feb  9 13:39:48 vpn2 charon: 06[IKE] authentication of
'CN=EXAMPLE-User.example.local' with RSA signature successful
Feb  9 13:39:48 vpn2 charon: 06[IKE] peer supports MOBIKE
Feb  9 13:39:48 vpn2 charon: 06[IKE] authentication of
'vpn2.example.com' (myself) with RSA signature successful
Feb  9 13:39:48 vpn2 charon: 06[IKE] IKE_SA win7[3] established
between vpn-server-ip[vpn2.example.com]...client-public-ip[CN=EXAMPLE-User.example.local]
Feb  9 13:39:48 vpn2 charon: 06[IKE] sending end entity cert
"O=Example, CN=vpn2.example.com"
Feb  9 13:39:48 vpn2 charon: 06[IKE] peer requested virtual IP %any
Feb  9 13:39:48 vpn2 charon: 06[CFG] reassigning offline lease to
'CN=EXAMPLE-User.example.local'
Feb  9 13:39:48 vpn2 charon: 06[IKE] assigning virtual IP
172.26.24.129 to peer 'CN=EXAMPLE-User.example.local'
Feb  9 13:39:48 vpn2 charon: 06[IKE] CHILD_SA win7{3} established with
SPIs c909e31b_i 85484e5e_o and TS 0.0.0.0/0 === 172.26.24.129/32
Feb  9 13:39:48 vpn2 charon: 06[ENC] generating IKE_AUTH response 1 [
IDr CERT AUTH CP(ADDR DNS DNS) SA TSi TSr N(MOBIKE_SUP) N(NO_ADD_ADDR)
]
Feb  9 13:39:48 vpn2 charon: 06[NET] sending packet: from
vpn-server-ip[4500] to client-public-ip[4500]
Feb  9 13:41:47 vpn2 charon: 08[NET] received packet: from
client-public-ip[1024] to vpn-server-ip[4500]
Feb  9 13:41:47 vpn2 charon: 08[ENC] parsed INFORMATIONAL request 2 [
N(UPD_SA_ADDR) N(NATD_S_IP) N(NATD_D_IP) N(COOKIE2) ]
Feb  9 13:41:47 vpn2 charon: 08[KNL] unable to copy replay state from
old SAD entry with SPI c909e31b
Feb  9 13:41:47 vpn2 charon: 08[KNL] unable to copy replay state from
old SAD entry with SPI 85484e5e
Feb  9 13:41:47 vpn2 charon: 08[ENC] generating INFORMATIONAL response
2 [ N(NATD_S_IP) N(NATD_D_IP) N(COOKIE2) ]
Feb  9 13:41:47 vpn2 charon: 08[NET] sending packet: from
vpn-server-ip[4500] to client-public-ip[1024]
Feb  9 13:46:52 vpn2 charon: 09[NET] received packet: from
client-public-ip[1024] to vpn-server-ip[4500]
Feb  9 13:46:52 vpn2 charon: 09[ENC] parsed INFORMATIONAL request 3 [ D ]
Feb  9 13:46:52 vpn2 charon: 09[IKE] received DELETE for ESP CHILD_SA
with SPI 85484e5e
Feb  9 13:46:52 vpn2 charon: 09[IKE] closing CHILD_SA win7{3} with
SPIs c909e31b_i (40016 bytes) 85484e5e_o (53008 bytes) and TS
0.0.0.0/0 === 172.26.24.129/32
Feb  9 13:46:52 vpn2 charon: 09[IKE] sending DELETE for ESP CHILD_SA
with SPI c909e31b
Feb  9 13:46:52 vpn2 charon: 09[IKE] CHILD_SA closed
Feb  9 13:46:52 vpn2 charon: 09[ENC] generating INFORMATIONAL response 3 [ D ]
Feb  9 13:46:52 vpn2 charon: 09[NET] sending packet: from
vpn-server-ip[4500] to client-public-ip[1024]
Feb  9 13:46:52 vpn2 charon: 11[NET] received packet: from
client-public-ip[1024] to vpn-server-ip[4500]
Feb  9 13:46:52 vpn2 charon: 11[ENC] parsed CREATE_CHILD_SA request 4
[ SA No TSi TSr ]
Feb  9 13:46:52 vpn2 charon: 11[IKE] CHILD_SA win7{4} established with
SPIs c62cb34c_i b33d56aa_o and TS 0.0.0.0/0 === 172.26.24.129/32
Feb  9 13:46:52 vpn2 charon: 11[ENC] generating CREATE_CHILD_SA
response 4 [ SA No TSi TSr ]
Feb  9 13:46:52 vpn2 charon: 11[NET] sending packet: from
vpn-server-ip[4500] to client-public-ip[1024]
Feb  9 13:50:10 vpn2 charon: 06[NET] received packet: from
client-public-ip[4500] to vpn-server-ip[4500]
Feb  9 13:50:10 vpn2 charon: 06[ENC] parsed INFORMATIONAL request 5 [
N(UPD_SA_ADDR) N(NATD_S_IP) N(NATD_D_IP) N(COOKIE2) ]
Feb  9 13:50:10 vpn2 charon: 06[KNL] unable to copy replay state from
old SAD entry with SPI c62cb34c
Feb  9 13:50:10 vpn2 charon: 06[KNL] unable to copy replay state from
old SAD entry with SPI b33d56aa
Feb  9 13:50:10 vpn2 charon: 06[ENC] generating INFORMATIONAL response
5 [ N(NATD_S_IP) N(NATD_D_IP) N(COOKIE2) ]
Feb  9 13:50:10 vpn2 charon: 06[NET] sending packet: from
vpn-server-ip[4500] to client-public-ip[4500]
Feb  9 13:55:11 vpn2 charon: 08[IKE] sending DPD request
Feb  9 13:55:11 vpn2 charon: 08[ENC] generating INFORMATIONAL request 0 [ ]
Feb  9 13:55:11 vpn2 charon: 08[NET] sending packet: from
vpn-server-ip[4500] to client-public-ip[4500]
Feb  9 13:55:11 vpn2 charon: 10[NET] received packet: from
client-public-ip[4500] to vpn-server-ip[4500]
Feb  9 13:55:11 vpn2 charon: 10[ENC] parsed INFORMATIONAL response 0 [ ]
Feb  9 13:55:29 vpn2 charon: 11[NET] received packet: from
client-public-ip[4500] to vpn-server-ip[4500]
Feb  9 13:55:29 vpn2 charon: 11[ENC] parsed INFORMATIONAL request 6 [ D ]
Feb  9 13:55:29 vpn2 charon: 11[IKE] received DELETE for ESP CHILD_SA
with SPI b33d56aa
Feb  9 13:55:29 vpn2 charon: 11[IKE] closing CHILD_SA win7{4} with
SPIs c62cb34c_i (33563 bytes) b33d56aa_o (42976 bytes) and TS
0.0.0.0/0 === 172.26.24.129/32
Feb  9 13:55:29 vpn2 charon: 11[IKE] sending DELETE for ESP CHILD_SA
with SPI c62cb34c
Feb  9 13:55:29 vpn2 charon: 11[IKE] CHILD_SA closed
Feb  9 13:55:29 vpn2 charon: 11[ENC] generating INFORMATIONAL response 6 [ D ]
Feb  9 13:55:29 vpn2 charon: 11[NET] sending packet: from
vpn-server-ip[4500] to client-public-ip[4500]
Feb  9 13:55:30 vpn2 charon: 12[NET] received packet: from
client-public-ip[4500] to vpn-server-ip[4500]
Feb  9 13:55:30 vpn2 charon: 12[ENC] parsed CREATE_CHILD_SA request 7
[ SA No TSi TSr ]
Feb  9 13:55:30 vpn2 charon: 12[IKE] CHILD_SA win7{5} established with
SPIs cd509098_i e42a1f5f_o and TS 0.0.0.0/0 === 172.26.24.129/32
Feb  9 13:55:30 vpn2 charon: 12[ENC] generating CREATE_CHILD_SA
response 7 [ SA No TSi TSr ]
Feb  9 13:55:30 vpn2 charon: 12[NET] sending packet: from
vpn-server-ip[4500] to client-public-ip[4500]

More information about the Users mailing list