[strongSwan] "the same policy exists for reqid Y" error
agarwalpiyush at gmail.com
agarwalpiyush at gmail.com
Thu May 25 18:42:44 CEST 2017
Anyone? Would greatly appreciate any comment here.
Given the reqid related re-work done in 5.3, I could move to 5.3.5, but I'd
like to understand what is going wrong here so I can confirm my
understanding and rectify any configuration mistakes, if any.
Thanks.
On Wednesday, May 24, 2017 at 3:00:39 PM UTC-7, Piyush Agarwal wrote:
>
> Hi,
> I have a server (1.100.0.5, auto=add) and two clients (1.100.0.9 and
> 1.100.0.13, auto=start).
> All the entities (2 clients and 1 server) have their own self-signed
> certs, but all of them share the same subject DN.
>
> Due to the way things work in our setup, unfortunately there could be a
> queue of events that will lead in multiple (potentially >20) modifications
> to ipsec.conf (and certs). Each of these events is handled by changing
> ipsec.conf and issuing an "ipsec reload". Connections could be added or
> deleted by each of these events.
>
> I have detailed config below. But I am seeing while things work fine with
> a single client, when I bring the setup up with two clients, one of them
> fails with the following error in client logs:
>
> 2605 16[CFG] unable to install policy 1.100.0.9/32 === 1.100.0.5/32 out
> (mark 0/0x00000000) for reqid 2, the same policy for reqid 1 exists
> 2606 16[CFG] unable to install policy 1.100.0.5/32 === 1.100.0.9/32 in
> (mark 0/0x00000000) for reqid 2, the same policy for reqid 1 exists
> 2607 16[CFG] unable to install policy 1.100.0.9/32 === 1.100.0.5/32 out
> (mark 0/0x00000000) for reqid 2, the same policy for reqid 1 exists
> 2608 16[CFG] unable to install policy 1.100.0.5/32 === 1.100.0.9/32 in
> (mark 0/0x00000000) for reqid 2, the same policy for reqid 1 exists
> 2609 16[IKE] unable to install IPsec policies (SPD) in kernel
>
> As a result the server responder reports TS_UNACCEPTABLE.
>
> Why is the client's IPsec SA getting re-established? Is it because the
> server had initiated an IKE_SA_INIT? Is server expected to initiate
> IKE_SA_INIT (despite it having auto=add)? The first ESTABLISHED below is
> with client1 initiating IKE_SA_INIT, but the second one seems to be because
> server initiated it. Please advise. Logs and ipsec.conf follow:
>
> 00[DMN] Starting IKE charon daemon (strongSwan 5.1.2, Linux
> 4.4.0-75-generic, x86_64)
> ....
> 04[IKE] IKE_SA 1.100.0.5[1] state change: CONNECTING => *ESTABLISHED*
> 04[IKE] scheduling rekeying in 3380s
> 04[IKE] maximum IKE_SA lifetime 3560s
> 01[JOB] next event in 3s 993ms, waiting
> 01[JOB] next event in 3s 993ms, waiting
> 04[CFG] selecting proposal:
> 04[CFG] proposal matches
> 04[CFG] received proposals: ESP:AES_GCM_16_256/NO_EXT_SEQ
> 04[CFG] configured proposals: ESP:AES_GCM_16_256/MODP_2048/NO_EXT_SEQ
> 04[CFG] selected proposal: ESP:AES_GCM_16_256/NO_EXT_SEQ
> 04[CFG] selecting traffic selectors for us:
> 04[CFG] config: 1.100.0.9/32, received: 1.100.0.9/32 => match:
> 1.100.0.9/32
> 04[CFG] selecting traffic selectors for other:
> 04[CFG] config: 1.100.0.5/32, received: 1.100.0.5/32 => match:
> 1.100.0.5/32
> 04[CHD] using AES_GCM_16 for encryption
> 04[CHD] adding inbound ESP SA
> 04[CHD] SPI 0xccd1087c, src 1.100.0.5 dst 1.100.0.9
> 04[KNL] adding SAD entry with SPI ccd1087c and reqid {1} (mark
> 0/0x00000000)
> 04[KNL] using encryption algorithm AES_GCM_16 with key size 288
> 04[KNL] using replay window of 32 packets
> 04[CHD] adding outbound ESP SA
> 04[CHD] SPI 0xc2544878, src 1.100.0.9 dst 1.100.0.5
> 04[KNL] adding SAD entry with SPI c2544878 and reqid {1} (mark
> 0/0x00000000)
> 04[KNL] using encryption algorithm AES_GCM_16 with key size 288
> 04[KNL] using replay window of 32 packets
> 04[KNL] adding policy 1.100.0.9/32 === 1.100.0.5/32 out (mark
> 0/0x00000000)
> 04[KNL] adding policy 1.100.0.5/32 === 1.100.0.9/32 in (mark
> 0/0x00000000)
> 04[KNL] policy 1.100.0.9/32 === 1.100.0.5/32 out (mark 0/0x00000000)
> already exists, increasing refcount
> 04[KNL] updating policy 1.100.0.9/32 === 1.100.0.5/32 out (mark
> 0/0x00000000)
> 04[KNL] policy 1.100.0.5/32 === 1.100.0.9/32 in (mark 0/0x00000000)
> already exists, increasing refcount
> 04[KNL] updating policy 1.100.0.5/32 === 1.100.0.9/32 in (mark
> 0/0x00000000)
> 04[IKE] CHILD_SA 1.100.0.5{1} established with SPIs ccd1087c_i c2544878_o
> and TS 1.100.0.9/32 === 1.100.0.5/32
> 04[IKE] peer supports MOBIKE
> 04[IKE] got additional MOBIKE peer address: 169.254.0.90
> 04[IKE] activating new tasks
> 04[IKE] nothing to initiate
> 04[MGR] checkin IKE_SA 1.100.0.5[1]
> 04[MGR] check-in of IKE_SA successful.
> 01[JOB] got event, queuing job for execution
> 01[JOB] next event in 8s 939ms, waiting
> 12[MGR] checkout IKE_SA
> 12[MGR] IKE_SA 1.100.0.5[1] successfully checked out
> 12[MGR] checkin IKE_SA 1.100.0.5[1]
> 12[MGR] check-in of IKE_SA successful.
> 01[JOB] got event, queuing job for execution
> 01[JOB] next event in 47s 66ms, waiting
> 11[MGR] checkout IKE_SA
> 11[MGR] IKE_SA 1.100.0.5[1] successfully checked out
> 11[MGR] checkin IKE_SA 1.100.0.5[1]
> 11[MGR] check-in of IKE_SA successful.
> 02[NET] received packet: from 1.100.0.5[500] to 1.100.0.9[500]
> 02[ENC] parsing header of message
> 02[ENC] parsing HEADER payload, 432 bytes left
> ....
> *10[ENC] parsed IKE_SA_INIT request 0 [ SA KE No N(NATD_S_IP) N(NATD_D_IP)
> ]*
> 10[CFG] looking for an ike config for 1.100.0.9...1.100.0.5
> 10[CFG] candidate: 1.100.0.9...1.100.0.5, prio 3100
> 10[CFG] found matching ike config: 1.100.0.9...1.100.0.5 with prio 3100
> 10[IKE] 1.100.0.5 is initiating an IKE_SA
> 10[IKE] IKE_SA (unnamed)[2] state change: CREATED => CONNECTING
> 10[CFG] selecting proposal:
> 10[CFG] proposal matches
> 10[CFG] received proposals:
> IKE:AES_GCM_16_256/AES_XCBC_96/PRF_AES128_XCBC/MODP_2048
> 10[CFG] configured proposals:
> IKE:AES_GCM_16_256/AES_XCBC_96/PRF_AES128_XCBC/MODP_2048
> 10[CFG] selected proposal: IKE:AES_GCM_16_256/PRF_AES128_XCBC/MODP_2048
> 10[LIB] size of DH secret exponent: 2047 bits
> 10[ENC] added payload of type SECURITY_ASSOCIATION to message
> 10[ENC] added payload of type KEY_EXCHANGE to message
> 10[ENC] added payload of type NONCE to message
> 10[ENC] added payload of type NOTIFY to message
> 10[ENC] added payload of type NOTIFY to message
> 10[IKE] sending cert request for "C=US, ST=CA, L=Mountain View, O=OWCA,
> OU=AgentC, CN=owca.com"
> 10[IKE] sending cert request for "C=US, ST=CA, L=Mountain View, O=OWCA,
> OU=AgentC, CN=owca.com"
> 10[ENC] added payload of type CERTIFICATE_REQUEST to message
> 10[ENC] added payload of type NOTIFY to message
> 10[ENC] added payload of type SECURITY_ASSOCIATION to message
> 10[ENC] added payload of type KEY_EXCHANGE to message
> 10[ENC] added payload of type NONCE to message
> 10[ENC] added payload of type NOTIFY to message
> 10[ENC] added payload of type NOTIFY to message
> 10[ENC] added payload of type CERTIFICATE_REQUEST to message
> 10[ENC] added payload of type NOTIFY to message
> 10[ENC] generating IKE_SA_INIT response 0 [ SA KE No N(NATD_S_IP)
> N(NATD_D_IP) CERTREQ N(MULT_AUTH) ]
> 10[ENC] not encrypting payloads
> ....
> 10[ENC] generating NOTIFY payload finished
> 10[NET] sending packet: from 1.100.0.9[500] to 1.100.0.5[500] (477 bytes)
> 10[MGR] checkin IKE_SA (unnamed)[2]
> 10[MGR] check-in of IKE_SA successful.
> 01[JOB] next event in 29s 999ms, waiting
> 06[NET] sending packet: from 1.100.0.9[500] to 1.100.0.5[500]
> 02[NET] received packet: from 1.100.0.5[4500] to 1.100.0.9[4500]
> 02[ENC] parsing header of message
> 02[ENC] parsing HEADER payload, 1670 bytes left
> ....
> 16[ENC] parsed IKE_AUTH request 1 [ IDi CERT CERTREQ IDr AUTH
> N(USE_TRANSP) SA TSi TSr N(MOBIKE_SUP) N(ADD_4_ADDR) N(MULT_AUTH)
> N(EAP_ONLY) ]
> 16[IKE] received cert request for "C=US, ST=CA, L=Mountain View, O=OWCA,
> OU=AgentC, CN=owca.com"
> 16[IKE] received cert request for unknown ca with keyid
> be:a4:64:e4:0a:8e:87:30:a7:cf:d8:46:c4:ba:44:d1:af:fd:8b:5b
> 16[IKE] received cert request for "C=US, ST=CA, L=Mountain View, O=OWCA,
> OU=AgentC, CN=owca.com"
> 16[IKE] received 1 cert requests for an unknown ca
> 16[ASN] L0 - x509:
> 16[ASN] L1 - tbsCertificate:
> 16[ASN] L2 - DEFAULT v1:
> 16[ASN] L3 - version:
> 16[ASN] X.509v3
> 16[ASN] L2 - serialNumber:
> 16[ASN] L2 - signature:
> 16[ASN] L3 - algorithmIdentifier:
> 16[ASN] L4 - algorithm:
> ....
> 16[IKE] received end entity cert "C=US, ST=CA, L=Mountain View, O=OWCA,
> OU=AgentC, CN=owca.com"
> 16[CFG] looking for peer configs matching 1.100.0.9[C=US, ST=CA,
> L=Mountain View, O=OWCA, OU=AgentC, CN=owca.com]...1.100.0.5[C=US, ST=CA,
> L=Mountain View, O=OWCA, OU=AgentC, CN=owca.com]
> 16[CFG] candidate "1.100.0.5", match: 20/20/3100 (me/other/ike)
> 16[CFG] selected peer config '1.100.0.5'
> 16[CFG] using trusted certificate "C=US, ST=CA, L=Mountain View, O=OWCA,
> OU=AgentC, CN=owca.com"
> 16[IKE] authentication of 'C=US, ST=CA, L=Mountain View, O=OWCA,
> OU=AgentC, CN=owca.com' with RSA signature successful
> 16[IKE] peer supports MOBIKE
> 16[IKE] got additional MOBIKE peer address: 169.254.0.90
> 16[ENC] added payload of type ID_RESPONDER to message
> 16[ENC] added payload of type AUTHENTICATION to message
> 16[IKE] authentication of 'C=US, ST=CA, L=Mountain View, O=OWCA,
> OU=AgentC, CN=owca.com' (myself) with RSA signature successful
> 16[IKE] IKE_SA 1.100.0.5[2] established between 1.100.0.9[C=US, ST=CA,
> L=Mountain View, O=OWCA, OU=AgentC, CN=owca.com]...1.100.0.5[C=US, ST=CA,
> L=Mountain View, O=OWCA, OU=AgentC, CN=owca.com]
> 16[IKE] IKE_SA 1.100.0.5[2] state change: CONNECTING => *ESTABLISHED*
> 16[IKE] scheduling rekeying in 3246s
> 01[JOB] next event in 29s 973ms, waiting
> 16[IKE] maximum IKE_SA lifetime 3426s
> 01[JOB] next event in 29s 973ms, waiting
> 01[JOB] next event in 29s 973ms, waiting
> 16[IKE] sending end entity cert "C=US, ST=CA, L=Mountain View, O=OWCA,
> OU=AgentC, CN=owca.com"
> 16[ENC] added payload of type CERTIFICATE to message
> 16[CFG] looking for a child config for 1.100.0.9/32 === 1.100.0.5/32
> 16[CFG] proposing traffic selectors for us:
> 16[CFG] 1.100.0.9/32
> 16[CFG] proposing traffic selectors for other:
> 16[CFG] 1.100.0.5/32
> 16[CFG] candidate "1.100.0.5" with prio 5+5
> 16[CFG] found matching child config "1.100.0.5" with prio 10
> 16[CFG] selecting proposal:
> 16[CFG] proposal matches
> 16[CFG] received proposals: ESP:AES_GCM_16_256/NO_EXT_SEQ
> 16[CFG] configured proposals: ESP:AES_GCM_16_256/MODP_2048/NO_EXT_SEQ
> 16[CFG] selected proposal: ESP:AES_GCM_16_256/NO_EXT_SEQ
> 16[KNL] getting SPI for reqid {2}
> 16[KNL] got SPI cda54f7c for reqid {2}
> ....
> 16[CFG] selecting traffic selectors for us:
> 16[CFG] config: 1.100.0.9/32, received: 1.100.0.9/32 => match:
> 1.100.0.9/32
> 16[CFG] selecting traffic selectors for other:
> 16[CFG] config: 1.100.0.5/32, received: 1.100.0.5/32 => match:
> 1.100.0.5/32
> 16[CHD] using AES_GCM_16 for encryption
> 16[CHD] adding inbound ESP SA
> 16[CHD] SPI 0xcda54f7c, src 1.100.0.5 dst 1.100.0.9
> 16[KNL] adding SAD entry with SPI cda54f7c and reqid {2} (mark
> 0/0x00000000)
> 16[KNL] using encryption algorithm AES_GCM_16 with key size 288
> 16[KNL] using replay window of 32 packets
> 16[CHD] adding outbound ESP SA
> 16[CHD] SPI 0xcec6ba54, src 1.100.0.9 dst 1.100.0.5
> 16[KNL] adding SAD entry with SPI cec6ba54 and reqid {2} (mark
> 0/0x00000000)
> 16[KNL] using encryption algorithm AES_GCM_16 with key size 288
> 16[KNL] using replay window of 32 packets
> 16[CFG] unable to install policy 1.100.0.9/32 === 1.100.0.5/32 out (mark
> 0/0x00000000) for reqid 2, the same policy for reqid 1 exists
> 16[CFG] unable to install policy 1.100.0.5/32 === 1.100.0.9/32 in (mark
> 0/0x00000000) for reqid 2, the same policy for reqid 1 exists
> 16[CFG] unable to install policy 1.100.0.9/32 === 1.100.0.5/32 out (mark
> 0/0x00000000) for reqid 2, the same policy for reqid 1 exists
> 16[CFG] unable to install policy 1.100.0.5/32 === 1.100.0.9/32 in (mark
> 0/0x00000000) for reqid 2, the same policy for reqid 1 exists
> 16[IKE] unable to install IPsec policies (SPD) in kernel
>
>
>
> IPSEC.confs follow:
>
> *Client1 ipsec.conf:*
> config setup
> uniqueids=no
>
> conn %default
> ikelifetime=60m
> keylife=20m
> rekeymargin=3m
> keyingtries=1
> keyexchange=ikev2
> ike=aes256gcm16-aesxcbc-modp2048!
> esp=aes256gcm16-modp2048!
>
>
> conn 1.100.0.5
> type=transport
> left=1.100.0.9
> leftcert=client1_cert.pem
> leftsendcert=always
> rightcert=server_cert.pem
> right=1.100.0.5
> reauth=no
> dpdaction=restart
> auto=start
>
>
> *Client2 ipsec.conf:*
> config setup
> uniqueids=no
>
> conn %default
> ikelifetime=60m
> keylife=20m
> rekeymargin=3m
> keyingtries=1
> keyexchange=ikev2
> ike=aes256gcm16-aesxcbc-modp2048!
> esp=aes256gcm16-modp2048!
>
>
>
> conn 1.100.0.5
> type=transport
> left=1.100.0.13
> leftcert=client2_cert.pem
> leftsendcert=always
> rightcert=server_cert.pem
> right=1.100.0.5
> reauth=no
> dpdaction=restart
> auto=start
>
>
> *Server ipsec.conf*
> config setup
> uniqueids=no
>
> conn %default
> ikelifetime=60m
> keylife=20m
> rekeymargin=3m
> keyingtries=1
> keyexchange=ikev2
> ike=aes256gcm16-aesxcbc-modp2048!
> esp=aes256gcm16-modp2048!
>
>
> conn 1.100.0.13
> type=transport
> left=1.100.0.5
> leftcert=server_cert.pem
> leftsendcert=always
> rightcert=client1_cert.pem
> right=1.100.0.13
> reauth=no
> dpdaction=restart
> auto=add
>
>
> conn 1.100.0.9
> type=transport
> left=1.100.0.5
> leftcert=server_cert.pem
> leftsendcert=always
> rightcert=client0_cert.pem
> right=1.100.0.9
> reauth=no
> dpdaction=restart
> auto=add
>
> --
> Piyush Agarwal
> Life can only be understood backwards; but it must be lived forwards.
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.strongswan.org/pipermail/users/attachments/20170525/d74900cd/attachment-0001.html>
More information about the Users
mailing list