[strongSwan] Failed to create IKEv2 CHILD_SA if peer rekeyed IKE_SA
Tianjie Mao
tjmao at tjmao.net
Tue Dec 18 22:21:56 CET 2012
Hi all,
TL;DR: The strongSwan responder was having trouble rekeying IKE SAs with
Windows 7 Agile VPN initiator every 3 hours due to "unacceptable traffic
selectors."
Topology:
[strongSwan responder]-[NAT fw]---Internet---[NAT fw]-[Win 7 initiator]
A quick search on the web would turn out that Windows 7 client rekeys IKEv2
SA every 3 hours or 10800 seconds. This seems to be a hard-coded value as
can be confirmed by some hex searching in %windir%\System32\vpnike.dll
(2A 30 00 00, little-endian).
Full description: If the IKE SA is rekeyed while Child SA is forever open,
the connection will not be interrupted at all. If, however, the IKE SA is
rekeyed while Child SA is closed or has been rekeyed, the connection will
turn defunct. According to strongSwan log, the responder (Linux) failed to
find appropriate traffic selectors upon receipt of subsequent
CREATE_CHILD_SA messages, therefore resulting in a refusal to create a Child
SA. At this point, the VPN will be unusable until either party signals a
reconnect.
This is annoying because the Win 7 host, secured with IKEv2 tunnel mode, may
experience outage easily. It happens at least every 3-4 hours no matter
whether the network is active or idle, or how much data has been transferred.
The Windows 7 client disregards a registry value
HKLM\SYSTEM\CCS\services\RemoteAccess\Parameters\IKEV2\idleTimeout
but insists on its own (which defaults to 300 seconds of inactivity). It
appears that those registry configs are meaningful to Windows Server 2008
RRAS only, not to client builds such as Windows 7 or 8. [2][3]
It also ignores any other publicly documented IKE options in the registry.
A plausible fix would be running a "ping -t somewhere-over-the-rainbow" but
that does not solve the problem. I used the dirty trick back into my high
school days to stop a NAT firewall from deleting corresponding ip_conntrack
entries. But here the Child SA will be rekeyed every hour (compared to 3h
IKE SA rekeying). After a) IKE SA is replaced and b) Child is deleted,
strongSwan will again fail to create Child anyway, complaining about traffic
selectors. I can check ip xfrm st/po right after IKE rekey, and the policies
are actually there. Now, Win 7 client rekeys Child SA, asking for traffic
selectors 0.0.0.0/0 === 0.0.0.0/0, but strongSwan is re-configured during
(passive) IKE rekey to use 0.0.0.0/0 === dynamic. So they fail to agree on
TS, the responder sending N(TS_UNACCEPT). In my example, TSi remained
10.192.233.1/32 until IKE SA rekey which turned it into dynamic. Also, note
the line that indicates the lease went offline after rekey.
strongSwan w/ strongSwan worked out-of-the-box.
strongSwan IKEv1 fine.
strongSwan IKEv1 w/ ShrewSoft client good, too.
I suspect it could be a strongSwan/Win7 interoperability issue but there
could also be errors in my configuration. Please tell me where I do not
understand things correctly.
My questions are:
i) How can I prevent the connection drop?
ii) Is there any configurable means to instruct strongSwan to link
traffic selectors (policies?) and/or IP leases to the new IKE SA in the
event that peer initiates an IKE rekey?
[1] Referred to a previous thread which shares exactly the same symptom:
https://lists.strongswan.org/pipermail/users/2012-January/007032.html
[2] Browsed the Wiki to get a starter configuration:
http://wiki.strongswan.org/projects/strongswan/wiki/Windows7
[3] 2.2.3.4.2.1 idleTimeout
http://msdn.microsoft.com/en-us/library/ee808301.aspx
Any ideas are appreciated.
Log & config follow. Thanks a lot.
(*) To help debug the situation, I sped up Win 7 IKE SA rekey interval
to 6 min.
(*) The log was simplified. A complete (almost) and unwrapped log is on
pastebin FYC: http://pastebin.com/raw.php?i=L93sNRq6
strongswan-5.0.1 --enable-blowfish --enable-md4 --enable-af-alg
--enable-eap-tls --enable-eap-md5 --enable-eap-mschapv2
--enable-eap-peap --enable-xauth-eap --enable-xauth-pam
--enable-shared=yes --disable-gmp --enable-openssl --enable-unity
--enable-kernel-pfkey --enable-socket-dynamic --enable-curl
Linux version 3.2.35 (user at kernal-build) (gcc version 4.3.2 (Debian
4.3.2-1.1) ) #1 Tue Dec 18 03:29:54 CST 2012
config setup
charondebug="ike 4, cfg 4, knl 4, mgr 4, lib 4, job 4"
uniqueids=never
conn mutualrsa
keyexchange=ike
#No compress=yes because we are behind NAT
right=%any
rightsourceip=10.192.233.0/26
left=server-host
leftid=@server.mydomain
leftsubnet=0.0.0.0/0
leftcert=myCert.pem
leftauth=pubkey
auto=add
type=tunnel
ike=aes256-sha1-modp1024,aes128-sha256-modp2048,aes128-sha1-modp2048,aes128-sha1-modp1536,3des-sha1-modp1536,3des-sha1-modp1024,3des-md5-modp1024!
esp=aes256-sha1,aes128-sha256-modp2048-noesn,aes128-sha1-modp2048-noesn,aes128-sha1-modp1536-noesn,3des-sha1-modp1536-noesn,3des-sha1-modp1024-noesn,3des-md5-modp1024-noesn!
forceencaps=yes
# No modeconfig=push because it has yet to be implemented
dpdaction=clear
lifetime=220m
ikelifetime=7d
reauth=no
keyingtries=%forever
charon {
threads = 16
load = aes des sha1 sha2 md5 pem pkcs1 random nonce x509
revocation hmac stroke kernel-pfkey kernel-netlink socket-default
updown openssl eap-identity eap-mschapv2 xauth-generic unity attr
}
21:51:58 server-host charon: 03[NET] received packet: from client-host[500] to
server-host[500]
21:51:58 server-host charon: 03[ENC] parsed IKE_SA_INIT request 0 [ SA KE No N
(NATD_S_IP) N(NATD_D_IP) ]
21:51:58 server-host charon: 03[CFG] selected proposal: IKE:AES_CBC_256/HMAC_S
HA1_96/PRF_HMAC_SHA1/MODP_1024
21:51:58 server-host charon: 03[ENC] generating IKE_SA_INIT response 0 [ SA KE
No N(NATD_S_IP) N(NATD_D_IP) CERTREQ N(MULT_AUTH) ]
21:51:58 server-host charon: 03[NET] sending packet: from server-host[500] to
client-host[500]
21:51:58 server-host charon: 05[NET] received packet: from client-host[4500] t
o server-host[4500]
21:51:58 server-host charon: 05[ENC] parsed IKE_AUTH request 1 [ IDi CERT CERT
REQ AUTH N(MOBIKE_SUP) CP(ADDR DNS NBNS SRV) SA TSi TSr ]
21:51:58 server-host charon: 05[CFG] peer config match local: 1 (ID_ANY -> )
21:51:58 server-host charon: 05[CFG] peer config match remote: 1 (ID_DER_ASN1_
DN -> [...])
21:51:58 server-host charon: 05[CFG] ike config match: 5 (server-host client-h
ost)
21:51:58 server-host charon: 05[CFG] candidate "mutualrsa", match: 1/1/5/1 (
me/other/ike/version)
21:51:58 server-host charon: 05[CFG] peer config match local: 1 (ID_ANY -> )
21:51:58 server-host charon: 05[CFG] peer config match remote: 1 (ID_DER_ASN1_
DN -> [...])
21:51:58 server-host charon: 05[CFG] ike config match: 5 (server-host client-h
ost)
21:51:58 server-host charon: 05[CFG] selected peer config 'mutualrsa'
21:51:58 server-host charon: 05[IKE] authentication of 'server.mydomain' (myse
lf) with RSA signature successful
21:51:58 server-host charon: 05[IKE] IKE_SA mutualrsa[24] established between
server-host[server.mydomain]...client-host[C=US, ST=CA, L=Los Angeles, O=My Or
ganisation, CN=client.mydomain, E=ras at mydomain]
21:51:58 server-host charon: 05[IKE] IKE_SA mutualrsa[24] state change: CONNEC
TING => ESTABLISHED
21:51:58 server-host charon: 05[CFG] reassigning offline lease to 'C=US, ST=CA
, L=Los Angeles, O=My Organisation, CN=client.mydomain, E=ras at mydomain'
21:51:58 server-host charon: 05[IKE] assigning virtual IP 10.192.233.1 to peer
'C=US, ST=CA, L=Los Angeles, O=My Organisation, CN=client.mydomain, E=ras at myd
omain'
21:51:58 server-host charon: 05[CFG] looking for a child config for 0.0.0.0/0
=== 0.0.0.0/0
21:51:58 server-host charon: 05[CFG] proposing traffic selectors for us:
21:51:58 server-host charon: 05[CFG] 0.0.0.0/0
21:51:58 server-host charon: 05[CFG] proposing traffic selectors for other:
21:51:58 server-host charon: 05[CFG] 10.192.233.1/32
21:51:58 server-host charon: 05[CFG] candidate "mutualrsa" with prio 5+1
21:51:58 server-host charon: 05[CFG] found matching child config "mutualrsa" w
ith prio 6
21:51:58 server-host charon: 05[CFG] selecting proposal:
21:51:58 server-host charon: 05[CFG] proposal matches
21:51:58 server-host charon: 05[CFG] received proposals: ESP:AES_CBC_256/HMAC_
SHA1_96/NO_EXT_SEQ, ESP:3DES_CBC/HMAC_SHA1_96/NO_EXT_SEQ
21:51:58 server-host charon: 05[CFG] configured proposals: ESP:AES_CBC_256/HMA
C_SHA1_96/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_SHA1_96/MODP_2048/NO_EXT_SEQ, ESP:A
ES_CBC_128/HMAC_SHA1_96/MODP_1536/NO_EXT_SEQ, ESP:3DES_CBC/HMAC_SHA1_96/MODP_1
536/NO_EXT_SEQ, ESP:3DES_CBC/HMAC_SHA1_96/MODP_1024/NO_EXT_SEQ, ESP:3DES_CBC/H
MAC_MD5_96/MODP_1024/NO_EXT_SEQ
21:51:58 server-host charon: 05[CFG] selected proposal: ESP:AES_CBC_256/HMAC_S
HA1_96/NO_EXT_SEQ
21:51:58 server-host charon: 05[KNL] getting SPI for reqid {12}
21:51:58 server-host charon: 05[KNL] got SPI cd5cce16 for reqid {12}
21:51:58 server-host charon: 05[CFG] selecting traffic selectors for us:
21:51:58 server-host charon: 05[CFG] config: 0.0.0.0/0, received: 0.0.0.0/0 =
> match: 0.0.0.0/0
21:51:58 server-host charon: 05[CFG] selecting traffic selectors for other:
21:51:58 server-host charon: 05[CFG] config: 10.192.233.1/32, received: 0.0.0
.0/0 => match: 10.192.233.1/32
21:51:58 server-host charon: 05[KNL] adding SAD entry with SPI cd5cce16 and re
qid {12} (mark 0/0x00000000)
21:51:58 server-host charon: 05[KNL] using encryption algorithm AES_CBC with
key size 256
21:51:58 server-host charon: 05[KNL] using integrity algorithm HMAC_SHA1_96
with key size 160
21:51:58 server-host charon: 05[KNL] using replay window of 32 packets
21:51:58 server-host charon: 05[KNL] adding policy 0.0.0.0/0 === 10.192.233.1/
32 out (mark 0/0x00000000)
21:51:58 server-host charon: 05[KNL] adding policy 10.192.233.1/32 === 0.0.0.0
/0 in (mark 0/0x00000000)
21:51:58 server-host charon: 05[KNL] adding policy 10.192.233.1/32 === 0.0.0.0
/0 fwd (mark 0/0x00000000)
21:51:58 server-host charon: 05[KNL] getting a local address in traffic select
or 0.0.0.0/0
21:51:58 server-host charon: 05[KNL] using host %any
21:51:58 server-host charon: 05[KNL] using gwip as nexthop to reach c
lient-host
21:51:58 server-host charon: 05[KNL] server-host is on interface eth0
21:51:58 server-host charon: 05[KNL] installing route: 10.192.233.1/32 via 192
.168.0.254 src %any dev eth0
21:51:58 server-host charon: 05[KNL] getting iface index for eth0
21:51:58 server-host charon: 05[KNL] policy 0.0.0.0/0 === 10.192.233.1/32 out
(mark 0/0x00000000) already exists, increasing refcount
21:51:58 server-host charon: 05[KNL] updating policy 0.0.0.0/0 === 10.192.233.
1/32 out (mark 0/0x00000000)
21:51:58 server-host charon: 05[KNL] policy 10.192.233.1/32 === 0.0.0.0/0 in
(mark 0/0x00000000) already exists, increasing refcount
21:51:58 server-host charon: 05[KNL] updating policy 10.192.233.1/32 === 0.0.0
.0/0 in (mark 0/0x00000000)
21:51:58 server-host charon: 05[KNL] policy 10.192.233.1/32 === 0.0.0.0/0 fwd
(mark 0/0x00000000) already exists, increasing refcount
21:51:58 server-host charon: 05[KNL] updating policy 10.192.233.1/32 === 0.0.0
.0/0 fwd (mark 0/0x00000000)
21:51:59 server-host charon: 05[KNL] getting a local address in traffic select
or 0.0.0.0/0
21:51:59 server-host charon: 05[KNL] using host %any
21:51:59 server-host charon: 05[KNL] using gwip as nexthop to reach c
lient-host
21:51:59 server-host charon: 05[KNL] server-host is on interface eth0
21:51:59 server-host charon: 05[IKE] CHILD_SA mutualrsa{12} established with S
PIs cd5cce16_i 0f84d776_o and TS 0.0.0.0/0 === 10.192.233.1/32
21:51:59 server-host charon: 05[KNL] server-host is on interface eth0
21:51:59 server-host charon: 05[ENC] generating IKE_AUTH response 1 [ IDr CERT
AUTH CP(ADDR) SA TSi TSr N(AUTH_LFT) N(MOBIKE_SUP) N(ADD_4_ADDR) N(ADD_4_ADDR
) ]
21:51:59 server-host charon: 05[NET] sending packet: from server-host[4500] to
client-host[4500]
21:51:59 server-host charon: 05[MGR] checkin IKE_SA mutualrsa[24]
21:51:59 server-host charon: 05[MGR] check-in of IKE_SA successful.
21:52:03 server-host tcplogger[1742]: [10.192.233.1:59446->66.171.224.72:80]:
started
21:52:05 server-host tcplogger[1742]: [10.192.233.1:59446->66.171.224.72:80]:
connected
21:52:06 server-host tcplogger[1742]: [10.192.233.1:59446->66.171.224.72:80]:
disconnected
21:52:06 server-host tcplogger[1742]: [10.192.233.1:59446->66.171.224.72:80]:
closed
21:52:17 server-host charon: 15[JOB] got event, queuing job for execution
21:52:17 server-host charon: 15[JOB] next event in 10s 923ms, waiting
21:52:17 server-host charon: 09[MGR] checkout IKE_SA
21:52:17 server-host charon: 09[MGR] IKE_SA mutualrsa[24] successfully checked
out
21:52:17 server-host charon: 09[KNL] querying SAD entry with SPI 0f84d776 (ma
rk 0/0x00000000)
21:52:17 server-host charon: 09[KNL] querying policy 0.0.0.0/0 === 10.192.233.
1/32 out (mark 0/0x00000000)
21:52:28 server-host charon: 15[JOB] got event, queuing job for execution
21:52:28 server-host charon: 15[JOB] next event in 423ms, waiting
21:52:28 server-host charon: 04[MGR] checkout IKE_SA
21:52:28 server-host charon: 04[MGR] IKE_SA mutualrsa[24] successfully checked
out
21:52:28 server-host charon: 04[MGR] checkin IKE_SA mutualrsa[24]
21:52:28 server-host charon: 04[MGR] check-in of IKE_SA successful.
21:52:28 server-host charon: 15[JOB] got event, queuing job for execution
21:52:28 server-host charon: 15[JOB] next event in 4s 641ms, waiting
21:52:28 server-host charon: 02[MGR] checkout IKE_SA
21:52:28 server-host charon: 02[MGR] IKE_SA mutualrsa[24] successfully checked
out
21:52:28 server-host charon: 02[KNL] querying SAD entry with SPI cd5cce16 (ma
rk 0/0x00000000)
21:52:28 server-host charon: 02[KNL] querying policy 10.192.233.1/32 === 0.0.0
.0/0 in (mark 0/0x00000000)
21:52:28 server-host charon: 02[KNL] querying policy 10.192.233.1/32 === 0.0.0
.0/0 fwd (mark 0/0x00000000)
21:57:21 server-host charon: 03[MGR] checkout IKE_SA by message
21:57:21 server-host charon: 03[MGR] IKE_SA mutualrsa[24] successfully checked
out
21:57:21 server-host charon: 03[NET] received packet: from client-host[4500] t
o server-host[4500]
21:57:21 server-host charon: 03[ENC] parsed INFORMATIONAL request 2 [ D ]
21:57:21 server-host charon: 03[IKE] received DELETE for ESP CHILD_SA with SPI
0f84d776
21:57:21 server-host charon: 03[KNL] querying SAD entry with SPI cd5cce16 (ma
rk 0/0x00000000)
21:57:21 server-host charon: 03[KNL] sending XFRM_MSG_GETSA: => 40 bytes @ 0x4
1c72c14
21:57:21 server-host charon: 03[KNL] querying SAD entry with SPI 0f84d776 (ma
rk 0/0x00000000)
21:57:21 server-host charon: 03[KNL] sending XFRM_MSG_GETSA: => 40 bytes @ 0x4
1c72c14
21:57:21 server-host charon: 03[IKE] closing CHILD_SA mutualrsa{12} with SPIs
cd5cce16_i (16914 bytes) 0f84d776_o (1435 bytes) and TS 0.0.0.0/0 === 10.192.2
33.1/32
21:57:21 server-host charon: 03[IKE] sending DELETE for ESP CHILD_SA with SPI
cd5cce16
21:57:21 server-host charon: 03[IKE] CHILD_SA closed
21:57:21 server-host charon: 03[KNL] deleting SAD entry with SPI cd5cce16 (ma
rk 0/0x00000000)
21:57:21 server-host charon: 03[KNL] sending XFRM_MSG_DELSA: => 40 bytes @ 0x4
1c72c7c
21:57:21 server-host charon: 03[KNL] deleted SAD entry with SPI cd5cce16 (mark
0/0x00000000)
21:57:21 server-host charon: 03[KNL] deleting SAD entry with SPI 0f84d776 (ma
rk 0/0x00000000)
21:57:21 server-host charon: 03[KNL] sending XFRM_MSG_DELSA: => 40 bytes @ 0x4
1c72c7c
21:57:21 server-host charon: 03[KNL] deleted SAD entry with SPI 0f84d776 (mark
0/0x00000000)
21:57:21 server-host charon: 03[KNL] deleting policy 0.0.0.0/0 === 10.192.233.
1/32 out (mark 0/0x00000000)
21:57:21 server-host charon: 03[KNL] policy still used by another CHILD_SA, no
t removed
21:57:21 server-host charon: 03[KNL] updating policy 0.0.0.0/0 === 10.192.233.
1/32 out (mark 0/0x00000000)
21:57:21 server-host charon: 03[KNL] sending XFRM_MSG_UPDPOLICY: => 180 bytes
@ 0x41c726fc
21:57:21 server-host charon: 03[KNL] deleting policy 10.192.233.1/32 === 0.0.0
.0/0 in (mark 0/0x00000000)
21:57:21 server-host charon: 03[KNL] policy still used by another CHILD_SA, no
t removed
21:57:21 server-host charon: 03[KNL] updating policy 10.192.233.1/32 === 0.0.0
.0/0 in (mark 0/0x00000000)
21:57:21 server-host charon: 03[KNL] sending XFRM_MSG_UPDPOLICY: => 180 bytes
@ 0x41c726fc
21:57:21 server-host charon: 03[KNL] deleting policy 10.192.233.1/32 === 0.0.0
.0/0 fwd (mark 0/0x00000000)
21:57:21 server-host charon: 03[KNL] policy still used by another CHILD_SA, no
t removed
21:57:21 server-host charon: 03[KNL] updating policy 10.192.233.1/32 === 0.0.0
.0/0 fwd (mark 0/0x00000000)
21:57:21 server-host charon: 03[KNL] sending XFRM_MSG_UPDPOLICY: => 180 bytes
@ 0x41c726fc
21:57:21 server-host charon: 03[KNL] getting a local address in traffic select
or 0.0.0.0/0
21:57:21 server-host charon: 03[KNL] using host %any
21:57:21 server-host charon: 03[KNL] using gwip as nexthop to reach c
lient-host
21:57:21 server-host charon: 03[KNL] server-host is on interface eth0
21:57:21 server-host charon: 03[KNL] deleting policy 0.0.0.0/0 === 10.192.233.
1/32 out (mark 0/0x00000000)
21:57:21 server-host charon: 03[KNL] sending XFRM_MSG_DELPOLICY: => 80 bytes @
0x41c72bf4
21:57:21 server-host charon: 03[KNL] deleting policy 10.192.233.1/32 === 0.0.0
.0/0 in (mark 0/0x00000000)
21:57:21 server-host charon: 03[KNL] sending XFRM_MSG_DELPOLICY: => 80 bytes @
0x41c72bf4
21:57:21 server-host charon: 03[KNL] deleting policy 10.192.233.1/32 === 0.0.0
.0/0 fwd (mark 0/0x00000000)
21:57:21 server-host charon: 03[KNL] getting iface index for eth0
21:57:21 server-host charon: 03[KNL] sending XFRM_MSG_DELPOLICY: => 80 bytes @
0x41c72bf4
21:57:21 server-host charon: 03[CFG] installing trap failed, remote address un
known
21:57:21 server-host charon: 03[ENC] generating INFORMATIONAL response 2 [ D ]
21:57:21 server-host charon: 03[NET] sending packet: from server-host[4500] to
client-host[4500]
21:57:21 server-host charon: 03[MGR] checkin IKE_SA mutualrsa[24]
21:57:21 server-host charon: 03[MGR] check-in of IKE_SA successful.
21:57:59 server-host charon: 06[MGR] checkout IKE_SA by message
21:57:59 server-host charon: 06[MGR] IKE_SA mutualrsa[24] successfully checked
out
21:57:59 server-host charon: 06[NET] received packet: from client-host[4500] t
o server-host[4500]
21:57:59 server-host charon: 06[ENC] parsed CREATE_CHILD_SA request 3 [ SA KE
No ]
21:57:59 server-host charon: 06[MGR] created IKE_SA (unnamed)[25]
21:57:59 server-host charon: 06[IKE] client-host is initiating an IKE_SA
21:57:59 server-host charon: 06[IKE] IKE_SA mutualrsa[25] state change: CREATE
D => CONNECTING
21:57:59 server-host charon: 06[CFG] selecting proposal:
21:57:59 server-host charon: 06[CFG] no acceptable ENCRYPTION_ALGORITHM foun
d
21:57:59 server-host charon: 06[CFG] selecting proposal:
21:57:59 server-host charon: 06[CFG] proposal matches
21:57:59 server-host charon: 06[CFG] received proposals: IKE:3DES_CBC/HMAC_SHA
1_96/PRF_HMAC_SHA1/MODP_1024, IKE:AES_CBC_256/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_
1024, IKE:3DES_CBC/HMAC_SHA2_256_128/PRF_HMAC_SHA2_256/MODP_1024, IKE:AES_CBC_
256/HMAC_SHA2_256_128/PRF_HMAC_SHA2_256/MODP_1024, IKE:3DES_CBC/HMAC_SHA2_384_
192/PRF_HMAC_SHA2_384/MODP_1024, IKE:AES_CBC_256/HMAC_SHA2_384_192/PRF_HMAC_SH
A2_384/MODP_1024
21:57:59 server-host charon: 06[CFG] configured proposals: IKE:AES_CBC_256/HMA
C_SHA1_96/PRF_HMAC_SHA1/MODP_1024, IKE:AES_CBC_128/HMAC_SHA1_96/PRF_HMAC_SHA1/
MODP_2048, IKE:AES_CBC_128/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_1536, IKE:3DES_CBC/
HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_1536, IKE:3DES_CBC/HMAC_SHA1_96/PRF_HMAC_SHA1/
MODP_1024, IKE:3DES_CBC/HMAC_MD5_96/PRF_HMAC_MD5/MODP_1024
21:57:59 server-host charon: 06[CFG] selected proposal: IKE:AES_CBC_256/HMAC_S
HA1_96/PRF_HMAC_SHA1/MODP_1024
21:57:59 server-host charon: 06[LIB] size of DH secret exponent: 1023 bits
21:57:59 server-host charon: 06[IKE] shared Diffie Hellman secret => 128 bytes
@ 0x807e248
21:57:59 server-host charon: 06[IKE] SKEYSEED => 20 bytes @ 0x8075448
21:57:59 server-host charon: 06[IKE] Sk_d secret => 20 bytes @ 0x8075448
21:57:59 server-host charon: 06[IKE] Sk_ai secret => 20 bytes @ 0x8075c48
21:57:59 server-host charon: 06[IKE] Sk_ar secret => 20 bytes @ 0x8075c48
21:57:59 server-host charon: 06[IKE] Sk_ei secret => 32 bytes @ 0x8070eb8
21:57:59 server-host charon: 06[IKE] Sk_er secret => 32 bytes @ 0x8070eb8
21:57:59 server-host charon: 06[IKE] Sk_pi secret => 20 bytes @ 0x807c8f8
21:57:59 server-host charon: 06[IKE] Sk_pr secret => 20 bytes @ 0x807a070
21:57:59 server-host charon: 06[IKE] IKE_SA mutualrsa[24] state change: ESTABL
ISHED => REKEYING
21:57:59 server-host charon: 06[ENC] generating CREATE_CHILD_SA response 3 [ S
A No KE ]
21:57:59 server-host charon: 06[NET] sending packet: from server-host[4500] to
client-host[4500]
21:57:59 server-host charon: 06[MGR] checkin IKE_SA mutualrsa[24]
21:57:59 server-host charon: 06[MGR] check-in of IKE_SA successful.
21:57:59 server-host charon: 03[MGR] checkout IKE_SA by message
21:57:59 server-host charon: 03[MGR] IKE_SA mutualrsa[24] successfully checked
out
21:57:59 server-host charon: 03[NET] received packet: from client-host[4500] t
o server-host[4500]
21:57:59 server-host charon: 03[ENC] parsed INFORMATIONAL request 4 [ D ]
21:57:59 server-host charon: 03[IKE] IKE_SA mutualrsa[25] state change: CONNEC
TING => ESTABLISHED
21:57:59 server-host charon: 03[IKE] scheduling reauthentication in 604252s
21:57:59 server-host charon: 03[IKE] maximum IKE_SA lifetime 604792s
21:57:59 server-host charon: 03[IKE] IKE_SA mutualrsa[25] rekeyed between serv
er-host[server.mydomain]...client-host[C=US, ST=CA, L=Los Angeles, O=My Organi
sation, CN=client.mydomain, E=ras at mydomain]
21:57:59 server-host charon: 03[IKE] rescheduling reauthentication in 603526s
after rekeying, lifetime reduced to 604066s
21:57:59 server-host charon: 03[MGR] checkin IKE_SA mutualrsa[25]
21:57:59 server-host charon: 03[IKE] received DELETE for IKE_SA mutualrsa[24]
21:57:59 server-host charon: 03[IKE] deleting IKE_SA mutualrsa[24] between ser
ver-host[server.mydomain]...client-host[C=US, ST=CA, L=Los Angeles, O=My Organ
isation, CN=client.mydomain, E=ras at mydomain]
21:57:59 server-host charon: 03[IKE] IKE_SA mutualrsa[24] state change: REKEYI
NG => DELETING
21:57:59 server-host charon: 03[IKE] IKE_SA deleted
21:57:59 server-host charon: 03[ENC] generating INFORMATIONAL response 4 [ ]
21:57:59 server-host charon: 03[NET] sending packet: from server-host[4500] to
client-host[4500]
21:57:59 server-host charon: 03[MGR] checkin and destroy IKE_SA mutualrsa[24]
21:57:59 server-host charon: 03[IKE] IKE_SA mutualrsa[24] state change: DELETI
NG => DESTROYING
21:57:59 server-host charon: 03[CFG] lease 10.192.233.1 by 'C=US, ST=CA, L=Los
Angeles, O=My Organisation, CN=client.mydomain, E=ras at mydomain' went offline
21:57:59 server-host charon: 03[MGR] check-in and destroy of IKE_SA successful
21:57:59 server-host charon: 15[JOB] next event in 3s 869ms, waiting
(The client run a ping command to a DNS resolver at 22:03:14)
22:03:14 server-host charon: 06[MGR] checkout IKE_SA by message
22:03:14 server-host charon: 06[MGR] IKE_SA mutualrsa[25] successfully checked
out
22:03:14 server-host charon: 06[NET] received packet: from client-host[4500] t
o server-host[4500]
22:03:14 server-host charon: 06[ENC] parsed CREATE_CHILD_SA request 0 [ SA No
TSi TSr ]
22:03:14 server-host charon: 06[CFG] looking for a child config for 0.0.0.0/0
=== 0.0.0.0/0
22:03:14 server-host charon: 06[CFG] proposing traffic selectors for us:
22:03:14 server-host charon: 06[CFG] 0.0.0.0/0
22:03:14 server-host charon: 06[CFG] proposing traffic selectors for other:
22:03:14 server-host charon: 06[CFG] dynamic
22:03:14 server-host charon: 06[CFG] candidate "mutualrsa" with prio 5+5
22:03:14 server-host charon: 06[CFG] found matching child config "mutualrsa" w
ith prio 10
22:03:14 server-host charon: 06[CFG] selecting proposal:
22:03:14 server-host charon: 06[CFG] proposal matches
22:03:14 server-host charon: 06[CFG] received proposals: ESP:AES_CBC_256/HMAC_
SHA1_96/NO_EXT_SEQ, ESP:3DES_CBC/HMAC_SHA1_96/NO_EXT_SEQ
22:03:14 server-host charon: 06[CFG] configured proposals: ESP:AES_CBC_256/HMA
C_SHA1_96/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_SHA1_96/MODP_2048/NO_EXT_SEQ, ESP:A
ES_CBC_128/HMAC_SHA1_96/MODP_1536/NO_EXT_SEQ, ESP:3DES_CBC/HMAC_SHA1_96/MODP_1
536/NO_EXT_SEQ, ESP:3DES_CBC/HMAC_SHA1_96/MODP_1024/NO_EXT_SEQ, ESP:3DES_CBC/H
MAC_MD5_96/MODP_1024/NO_EXT_SEQ
22:03:14 server-host charon: 06[CFG] selected proposal: ESP:AES_CBC_256/HMAC_S
HA1_96/NO_EXT_SEQ
22:03:14 server-host charon: 06[KNL] getting SPI for reqid {13}
22:03:14 server-host charon: 06[KNL] sending XFRM_MSG_ALLOCSPI: => 244 bytes @
0x43472bb4
22:03:14 server-host charon: 06[KNL] got SPI cedcbe1b for reqid {13}
22:03:14 server-host charon: 06[CFG] selecting traffic selectors for us:
22:03:14 server-host charon: 06[CFG] config: 0.0.0.0/0, received: 0.0.0.0/0 =
> match: 0.0.0.0/0
22:03:14 server-host charon: 06[CFG] selecting traffic selectors for other:
22:03:14 server-host charon: 06[CFG] config: dynamic, received: 0.0.0.0/0 =>
no match
22:03:14 server-host charon: 06[IKE] no acceptable traffic selectors found
22:03:14 server-host charon: 06[IKE] failed to establish CHILD_SA, keeping IKE
_SA
22:03:14 server-host charon: 06[KNL] deleting SAD entry with SPI cedcbe1b (ma
rk 0/0x00000000)
22:03:14 server-host charon: 06[KNL] sending XFRM_MSG_DELSA: => 40 bytes @ 0x4
3472cec
22:03:14 server-host charon: 06[KNL] deleted SAD entry with SPI cedcbe1b (mark
0/0x00000000)
22:03:14 server-host charon: 06[ENC] generating CREATE_CHILD_SA response 0 [ N
(TS_UNACCEPT) ]
22:03:14 server-host charon: 06[NET] sending packet: from server-host[4500] to
client-host[4500]
22:03:14 server-host charon: 06[MGR] checkin IKE_SA mutualrsa[25]
22:03:14 server-host charon: 06[MGR] check-in of IKE_SA successful.
^C
Life is short, stories can be longer.
--
Tianjie Mao
More information about the Users
mailing list