[strongSwan] Windows StrongSwan cannot establish CHILD_SA due to CREATE_CHILD_SA kicks in every outbound packet.

Sat Nov 28 18:16:06 CET 2015

Hi.

I am trying to connect StrongSwan Windows client to Cisco ASA, and facing following two issues.
(In Linux, there is no such issue.)

1. CREATE_CHILD_SA kicks in right away after Windows StrongSwan finished IKE negotiation.
2. Every single outbound packet attempt, strongswan creates schedules CREATE_CHILD_SA instead of sending ESP packet after CHILD_SA established one time.

Because of these issues, I cannot send any of outbound ESP packet.

Here is the snapshot of swanctl -l

4.0.0.66-151-147-21.0: #2, ESTABLISHED, IKEv2, 06713a37598878a6:342ccff4d5739063
  local  ‘client1.test.io' @ 172.16.115.240
  remote 'C=US, O=Hxxx, CN=SGW' @ 66.151.147.21
  AES_CBC-256/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_1024
  established 49s ago, rekeying in 14310s, reauth in 82284s
  active:  CHILD_CREATE
  child_1: #6, reqid 1, INSTALLED, TUNNEL-in-UDP, ESP:AES_CBC-256/HMAC_SHA1_96
    installed 48s ago, rekeying in 3264s, expires in 3916s
    in  ce117294,      0 bytes,     0 packets
    out be8f068b,      0 bytes,     0 packets
    local  172.16.115.240/32
    remote 192.168.10.0/24

And key value of configuration of some parameter. (the rest are set to default).

Type: IKEv2
Mode : Tunnel
start_action: trap
vips: 0.0.0.0/0
remote_ts : 192.168.10.0/24
local_ts : dynamic.

And This is the capture of relevant charon log.

2015-11-28T08:42:56 12[IKE] initiating IKE_SA 4.0.0.66.151.147.21.0[2] to 66.151.147.21
2015-11-28T08:42:56 12[ENC] generating IKE_SA_INIT request 0 [ SA KE No N(NATD_S_IP) N(NATD_D_IP) N(HASH_ALG) ]
2015-11-28T08:42:56 12[NET] sending packet: from 172.16.115.240[500] to 66.151.147.21[500] (320 bytes)
2015-11-28T08:42:56 08[NET] received packet: from 66.151.147.21[500] to 172.16.115.240[500] (44 bytes)
2015-11-28T08:42:56 08[ENC] parsed IKE_SA_INIT response 0 [ N(COOKIE) ]
2015-11-28T08:42:56 08[IKE] initiating IKE_SA 4.0.0.66.151.147.21.0[2] to 66.151.147.21
2015-11-28T08:42:56 08[ENC] generating IKE_SA_INIT request 0 [ N(COOKIE) SA KE No N(NATD_S_IP) N(NATD_D_IP) N(HASH_ALG) ]
2015-11-28T08:42:56 08[NET] sending packet: from 172.16.115.240[500] to 66.151.147.21[500] (336 bytes)
2015-11-28T08:42:56 09[NET] received packet: from 66.151.147.21[500] to 172.16.115.240[500] (522 bytes)
2015-11-28T08:42:56 09[ENC] parsed IKE_SA_INIT response 0 [ SA KE No V V V N(NATD_S_IP) N(NATD_D_IP) CERTREQ V ]
2015-11-28T08:42:56 09[IKE] local host is behind NAT, sending keep alives
2015-11-28T08:42:56 09[IKE] received cert request for "C=US, O=Ixx, CN=CiscoASA"
2015-11-28T08:42:56 09[IKE] received 2 cert requests for an unknown ca
2015-11-28T08:42:56 09[IKE] sending cert request for "C=US, O=Ixx, CN=CiscoASA"
2015-11-28T08:42:56 09[IKE] authentication of 'client1.test.io' (myself) with RSA signature successful
2015-11-28T08:42:56 09[IKE] sending end entity cert "C=US, O=Hxx, CN=CLIENT1"
2015-11-28T08:42:56 09[IKE] establishing CHILD_SA child_a25_a26
2015-11-28T08:42:56 09[ENC] generating IKE_AUTH request 1 [ IDi CERT CERTREQ IDr AUTH SA TSi TSr N(EAP_ONLY) ]
2015-11-28T08:42:56 09[NET] sending packet: from 172.16.115.240[4500] to 66.151.147.21[4500] (988 bytes)
2015-11-28T08:42:56 13[NET] received packet: from 66.151.147.21[4500] to 172.16.115.240[4500] (940 bytes)
2015-11-28T08:42:56 13[ENC] parsed IKE_AUTH response 1 [ V IDr CERT AUTH SA TSi TSr N(ESP_TFC_PAD_N) N(NON_FIRST_FRAG) ]
2015-11-28T08:42:56 13[IKE] received end entity cert "C=US, O=Hxx, CN=SGW"
2015-11-28T08:42:56 13[CFG]   using certificate "C=US, O=Hxx, CN=SGW"
2015-11-28T08:42:56 13[CFG]   using trusted ca certificate "C=US, O=Ixx, CN=CiscoASA"
2015-11-28T08:42:56 13[CFG]   reached self-signed root ca with a path length of 0
2015-11-28T08:42:56 13[IKE] authentication of 'C=US, O=Hxx, CN=SGW' with RSA signature successful
2015-11-28T08:42:56 13[IKE] IKE_SA 4.0.0.66.151.147.21.0[2] established between 172.16.115.240[client1.test.io]...66.151.147.21[C=US, O=Hxx, CN=SGW]
2015-11-28T08:42:56 13[IKE] scheduling rekeying in 14359s
2015-11-28T08:42:56 13[IKE] scheduling reauthentication in 82333s
2015-11-28T08:42:56 13[IKE] maximum IKE_SA lifetime 22999s
2015-11-28T08:42:56 13[IKE] received ESP_TFC_PADDING_NOT_SUPPORTED, not using ESPv3 TFC padding
2015-11-28T08:42:56 13[KNL] setting WFP SA SPI failed: 0x80320035
2015-11-28T08:42:56 13[IKE] unable to install IPsec policies (SPD) in kernel
2015-11-28T08:42:56 13[IKE] failed to establish CHILD_SA, keeping IKE_SA
2015-11-28T08:42:56 13[IKE] sending DELETE for ESP CHILD_SA with SPI cef5a6bf
2015-11-28T08:42:56 13[ENC] generating INFORMATIONAL request 2 [ D ]
2015-11-28T08:42:56 13[NET] sending packet: from 172.16.115.240[4500] to 66.151.147.21[4500] (76 bytes)
2015-11-28T08:42:57 16[NET] received packet: from 66.151.147.21[4500] to 172.16.115.240[4500] (76 bytes)
2015-11-28T08:42:57 16[ENC] parsed INFORMATIONAL response 2 [ D ]
2015-11-28T08:42:57 17[KNL] creating acquire job for policy 172.16.115.240/32[icmp/8] === 192.168.10.2/32[icmp/0] with reqid {1}
2015-11-28T08:42:57 14[IKE] establishing CHILD_SA child_a25_a26{1}
2015-11-28T08:42:57 14[ENC] generating CREATE_CHILD_SA request 3 [ SA No TSi TSr ]
2015-11-28T08:42:57 14[NET] sending packet: from 172.16.115.240[4500] to 66.151.147.21[4500] (236 bytes)
2015-11-28T08:42:58 17[KNL] creating acquire job for policy 172.16.115.240/32[icmp/8] === 192.168.10.2/32[icmp/0] with reqid {1}
2015-11-28T08:42:58 06[CFG] ignoring acquire, connection attempt pending
2015-11-28T08:42:59 17[KNL] creating acquire job for policy 172.16.115.240/32[icmp/8] === 192.168.10.2/32[icmp/0] with reqid {1}
2015-11-28T08:42:59 08[CFG] ignoring acquire, connection attempt pending
2015-11-28T08:43:00 17[KNL] creating acquire job for policy 172.16.115.240/32[icmp/8] === 192.168.10.2/32[icmp/0] with reqid {1}
2015-11-28T08:43:00 12[CFG] ignoring acquire, connection attempt pending
2015-11-28T08:43:01 09[IKE] retransmit 1 of request with message ID 3
2015-11-28T08:43:01 09[NET] sending packet: from 172.16.115.240[4500] to 66.151.147.21[4500] (236 bytes)
2015-11-28T08:43:01 17[KNL] creating acquire job for policy 172.16.115.240/32[icmp/8] === 192.168.10.2/32[icmp/0] with reqid {1}
2015-11-28T08:43:01 05[CFG] ignoring acquire, connection attempt pending
2015-11-28T08:43:01 10[NET] received packet: from 66.151.147.21[4500] to 172.16.115.240[4500] (236 bytes)
2015-11-28T08:43:01 10[ENC] parsed CREATE_CHILD_SA response 3 [ SA No TSi TSr ]
2015-11-28T08:43:01 10[IKE] CHILD_SA child_a25_a26{6} established with SPIs ce117294_i be8f068b_o and TS 172.16.115.240/32 === 192.168.10.0/24
2015-11-28T08:43:02 17[KNL] creating acquire job for policy 172.16.115.240/32[icmp/8] === 192.168.10.2/32[icmp/0] with reqid {1}
2015-11-28T08:43:02 13[IKE] establishing CHILD_SA child_a25_a26{1}
2015-11-28T08:43:02 13[ENC] generating CREATE_CHILD_SA request 4 [ SA No TSi TSr ]
2015-11-28T08:43:02 13[NET] sending packet: from 172.16.115.240[4500] to 66.151.147.21[4500] (236 bytes)
2015-11-28T08:43:03 17[KNL] creating acquire job for policy 172.16.115.240/32[icmp/8] === 192.168.10.2/32[icmp/0] with reqid {1}
2015-11-28T08:43:03 14[CFG] ignoring acquire, connection attempt pending
2015-11-28T08:43:04 17[KNL] creating acquire job for policy 172.16.115.240/32[icmp/8] === 192.168.10.2/32[icmp/0] with reqid {1}
2015-11-28T08:43:04 12[CFG] ignoring acquire, connection attempt pending
2015-11-28T08:43:06 10[IKE] retransmit 1 of request with message ID 4
2015-11-28T08:43:06 10[NET] sending packet: from 172.16.115.240[4500] to 66.151.147.21[4500] (236 bytes)
2015-11-28T08:43:13 13[IKE] retransmit 2 of request with message ID 4
2015-11-28T08:43:13 13[NET] sending packet: from 172.16.115.240[4500] to 66.151.147.21[4500] (236 bytes)
2015-11-28T08:43:26 12[IKE] retransmit 3 of request with message ID 4
2015-11-28T08:43:26 12[NET] sending packet: from 172.16.115.240[4500] to 66.151.147.21[4500] (236 bytes)
2015-11-28T08:43:46 08[IKE] sending keep alive to 66.151.147.21[4500]
2015-11-28T08:43:50 16[IKE] retransmit 4 of request with message ID 4
2015-11-28T08:43:50 16[NET] sending packet: from 172.16.115.240[4500] to 66.151.147.21[4500] (236 bytes)
2015-11-28T08:43:52 17[KNL] creating acquire job for policy 172.16.115.240/32[icmp/8] === 192.168.10.2/32[icmp/0] with reqid {1}
2015-11-28T08:43:52 14[CFG] ignoring acquire, connection attempt pending
2015-11-28T08:43:53 17[KNL] creating acquire job for policy 172.16.115.240/32[icmp/8] === 192.168.10.2/32[icmp/0] with reqid {1}
2015-11-28T08:43:53 12[CFG] ignoring acquire, connection attempt pending
2015-11-28T08:43:54 17[KNL] creating acquire job for policy 172.16.115.240/32[icmp/8] === 192.168.10.2/32[icmp/0] with reqid {1}
2015-11-28T08:43:54 10[CFG] ignoring acquire, connection attempt pending
2015-11-28T08:44:10 16[IKE] sending keep alive to 66.151.147.21[4500]
2015-11-28T08:44:30 14[IKE] sending keep alive to 66.151.147.21[4500]
2015-11-28T08:44:32 12[IKE] retransmit 5 of request with message ID 4
2015-11-28T08:44:32 12[NET] sending packet: from 172.16.115.240[4500] to 66.151.147.21[4500] (236 bytes)
2015-11-28T08:44:52 10[IKE] sending keep alive to 66.151.147.21[4500]
2015-11-28T08:45:12 11[IKE] sending keep alive to 66.151.147.21[4500]
2015-11-28T08:45:32 06[IKE] sending keep alive to 66.151.147.21[4500]
2015-11-28T08:45:47 15[IKE] giving up after 5 retransmits
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.strongswan.org/pipermail/users/attachments/20151128/35c414eb/attachment-0001.html>