Project

General

Profile

Issue #1439

Updated by Tobias Brunner over 9 years ago

Hi

This Reauthentication failure is seen only on my customised setup. But still, the basic ikev2/ikev1 works fine here.

Reauthentication fails arbitrarily after 3 or 4 successful reauths. But it works fine without load-tester.
Rekeying is always fine.

Responder: syslog error message:
<pre>
Apr 27 14:18:40 cavium-NCD charon: 14[IKE] initiator did not reauthenticate as requested
Apr 27 14:18:40 cavium-NCD charon: 14[IKE] IKE_SA rw[2] will timeout in 3 seconds
Apr 27 14:18:40 cavium-NCD charon: 05[NET] received packet: from 192.168.10.2[500] to 192.168.10.1[500] (76 bytes)
Apr 27 14:18:40 cavium-NCD charon: 05[ENC] parsed INFORMATIONAL request 2 [ D ]
Apr 27 14:18:40 cavium-NCD charon: 05[IKE] received DELETE for IKE_SA rw[2]
Apr 27 14:18:40 cavium-NCD charon: 05[IKE] deleting IKE_SA rw[2] between 192.168.10.1[CN=srv, OU=load-test, O=strongSwan]...192.168.10.2[CN=c2-r1, OU=load-test, O=strongSwan]
Apr 27 14:18:40 cavium-NCD charon: 05[IKE] IKE_SA deleted
Apr 27 14:18:40 cavium-NCD vpn: - CN=c2-r1, OU=load-test, O=strongSwan 10.3.10.1/32 == 192.168.10.2 -- 192.168.10.1 == 10.1.0.0/16
Apr 27 14:18:40 cavium-NCD charon: 05[ENC] generating INFORMATIONAL response 2 [ ]
Apr 27 14:18:40 cavium-NCD charon: 05[NET] sending packet: from 192.168.10.1[500] to 192.168.10.2[500] (76 bytes)
Apr 27 14:18:40 cavium-NCD charon: 15[NET] received packet: from 192.168.10.2[500] to 192.168.10.1[500] (320 bytes)
Apr 27 14:18:40 cavium-NCD charon: 15[ENC] parsed IKE_SA_INIT request 0 [ SA KE No N(NATD_S_IP) N(NATD_D_IP) N(HASH_ALG) ]
Apr 27 14:18:40 cavium-NCD charon: 15[IKE] 192.168.10.2 is initiating an IKE_SA
Apr 27 14:18:40 cavium-NCD charon: 15[IKE] sending cert request for "CN=srv, OU=load-test, O=strongSwan"
Apr 27 14:18:40 cavium-NCD charon: 15[IKE] sending cert request for "CN=srv, OU=load-test, O=strongSwan"
Apr 27 14:18:40 cavium-NCD charon: 15[ENC] generating IKE_SA_INIT response 0 [ SA KE No N(NATD_S_IP) N(NATD_D_IP) CERTREQ N(HASH_ALG) N(MULT_AUTH) ]
Apr 27 14:18:40 cavium-NCD charon: 15[NET] sending packet: from 192.168.10.1[500] to 192.168.10.2[500] (373 bytes)
Apr 27 14:18:40 cavium-NCD charon: 07[NET] received packet: from 192.168.10.2[500] to 192.168.10.1[500] (1068 bytes)
Apr 27 14:18:40 cavium-NCD charon: 07[ENC] parsed IKE_AUTH request 1 [ IDi CERT CERTREQ IDr AUTH CPRQ(ADDR) N(ESP_TFC_PAD_N) SA TSi TSr N(MULT_AUTH) N(EAP_ONLY) ]
Apr 27 14:18:40 cavium-NCD charon: 07[IKE] received cert request for "CN=srv, OU=load-test, O=strongSwan"
Apr 27 14:18:40 cavium-NCD charon: 07[IKE] received cert request for "CN=srv, OU=load-test, O=strongSwan"
Apr 27 14:18:40 cavium-NCD charon: 07[IKE] received end entity cert "CN=c2-r1, OU=load-test, O=strongSwan"
Apr 27 14:18:40 cavium-NCD charon: 07[CFG] looking for peer configs matching 192.168.10.1[CN=srv, OU=load-test, O=strongSwan]...192.168.10.2[CN=c2-r1, OU=load-test, O=strongSwan]
Apr 27 14:18:40 cavium-NCD charon: 07[CFG] selected peer config 'rw'
Apr 27 14:18:40 cavium-NCD charon: 07[CFG] using certificate "CN=c2-r1, OU=load-test, O=strongSwan"
Apr 27 14:18:40 cavium-NCD charon: 07[CFG] using trusted ca certificate "CN=srv, OU=load-test, O=strongSwan"
Apr 27 14:18:40 cavium-NCD charon: 07[CFG] checking certificate status of "CN=c2-r1, OU=load-test, O=strongSwan"
Apr 27 14:18:40 cavium-NCD charon: 07[CFG] certificate status is not available
Apr 27 14:18:40 cavium-NCD charon: 07[CFG] reached self-signed root ca with a path length of 0
Apr 27 14:18:40 cavium-NCD charon: 07[IKE] authentication of 'CN=c2-r1, OU=load-test, O=strongSwan' with RSA_EMSA_PKCS1_SHA256 successful
Apr 27 14:18:40 cavium-NCD charon: 07[IKE] received ESP_TFC_PADDING_NOT_SUPPORTED, not using ESPv3 TFC padding
Apr 27 14:18:40 cavium-NCD charon: 07[IKE] authentication of 'CN=srv, OU=load-test, O=strongSwan' (myself) with RSA_EMSA_PKCS1_SHA256 successful
Apr 27 14:18:40 cavium-NCD charon: 07[IKE] IKE_SA rw[3] established between 192.168.10.1[CN=srv, OU=load-test, O=strongSwan]...192.168.10.2[CN=c2-r1, OU=load-test, O=strongSwan]
Apr 27 14:18:40 cavium-NCD charon: 07[IKE] scheduling reauthentication in 117s
Apr 27 14:18:40 cavium-NCD charon: 07[IKE] maximum IKE_SA lifetime 120s
Apr 27 14:18:40 cavium-NCD charon: 07[IKE] sending end entity cert "CN=srv, OU=load-test, O=strongSwan"
Apr 27 14:18:40 cavium-NCD charon: 07[IKE] peer requested virtual IP 10.3.10.1
Apr 27 14:18:40 cavium-NCD charon: 07[CFG] reassigning online lease to 'CN=c2-r1, OU=load-test, O=strongSwan'
Apr 27 14:18:40 cavium-NCD charon: 07[IKE] assigning virtual IP 10.3.10.1 to peer 'CN=c2-r1, OU=load-test, O=strongSwan'
Apr 27 14:18:40 cavium-NCD charon: 07[KNL] unable to add policy: File exists (17)
Apr 27 14:18:40 cavium-NCD charon: 07[KNL] unable to add policy 10.3.10.1/32 === 10.1.0.0/16 in
Apr 27 14:18:40 cavium-NCD charon: 07[KNL] error sending to PF_KEY socket: Operation not permitted
Apr 27 14:18:40 cavium-NCD charon: 07[KNL] unable to update policy 10.3.10.1/32 === 10.1.0.0/16 in
Apr 27 14:18:40 cavium-NCD charon: 07[IKE] unable to install IPsec policies (SPD) in kernel
Apr 27 14:18:40 cavium-NCD charon: 07[IKE] failed to establish CHILD_SA, keeping IKE_SA
Apr 27 14:18:40 cavium-NCD kernel: [164821.583744] policy handle failed to be found
Apr 27 14:18:40 cavium-NCD charon: 07[KNL] error sending to PF_KEY socket: Operation not permitted
Apr 27 14:18:40 cavium-NCD charon: 07[KNL] unable to update policy 10.3.10.1/32 === 10.1.0.0/16 in
Apr 27 14:18:40 cavium-NCD kernel: [164821.587752] policy handle failed to be found
Apr 27 14:18:40 cavium-NCD charon: 07[KNL] unable to delete policy 10.3.10.1/32 === 10.1.0.0/16 in: No such file or directory (2)
Apr 27 14:18:40 cavium-NCD kernel: [164821.591786] policy handle failed to be found
Apr 27 14:18:40 cavium-NCD charon: 07[ENC] generating IKE_AUTH response 1 [ IDr CERT AUTH CPRP(ADDR) N(AUTH_LFT) N(TS_UNACCEPT) ]
Apr 27 14:18:40 cavium-NCD charon: 07[NET] sending packet: from 192.168.10.1[500] to 192.168.10.2[500] (828 bytes)
</pre>



Initiator: error syslog:
<pre>


Apr 27 14:18:46 ubnt-113 charon: 27[IKE] reauthenticating IKE_SA load-test[2]
Apr 27 14:18:46 ubnt-113 charon: 27[IKE] deleting IKE_SA load-test[2] between 192.168.10.2[CN=c2-r1, OU=load-test, O=strongSwan]...192.168.10.1[CN=srv, OU=load-test, O=strongSwan]
Apr 27 14:18:46 ubnt-113 charon: 27[IKE] sending DELETE for IKE_SA load-test[2]
Apr 27 14:18:46 ubnt-113 charon: 27[ENC] generating INFORMATIONAL request 2 [ D ]
Apr 27 14:18:46 ubnt-113 charon: 27[NET] sending packet: from 192.168.10.2[500] to 192.168.10.1[500] (76 bytes)
Apr 27 14:18:46 ubnt-113 charon: 29[NET] received packet: from 192.168.10.1[500] to 192.168.10.2[500] (76 bytes)
Apr 27 14:18:46 ubnt-113 charon: 29[ENC] parsed INFORMATIONAL response 2 [ ]
Apr 27 14:18:46 ubnt-113 charon: 29[IKE] IKE_SA deleted
Apr 27 14:18:46 ubnt-113 charon: 29[IKE] installing new virtual IP 10.3.10.1
Apr 27 14:18:46 ubnt-113 charon: 29[IKE] restarting CHILD_SA load-test
Apr 27 14:18:46 ubnt-113 charon: 29[IKE] initiating IKE_SA load-test[3] to 192.168.10.1
Apr 27 14:18:46 ubnt-113 charon: 29[ENC] generating IKE_SA_INIT request 0 [ SA KE No N(NATD_S_IP) N(NATD_D_IP) N(HASH_ALG) ]
Apr 27 14:18:46 ubnt-113 charon: 29[NET] sending packet: from 192.168.10.2[500] to 192.168.10.1[500] (320 bytes)
Apr 27 14:18:46 ubnt-113 charon: 30[NET] received packet: from 192.168.10.1[500] to 192.168.10.2[500] (373 bytes)
Apr 27 14:18:46 ubnt-113 charon: 30[ENC] parsed IKE_SA_INIT response 0 [ SA KE No N(NATD_S_IP) N(NATD_D_IP) CERTREQ N(HASH_ALG) N(MULT_AUTH) ]
Apr 27 14:18:46 ubnt-113 charon: 30[IKE] received cert request for "CN=srv, OU=load-test, O=strongSwan"
Apr 27 14:18:46 ubnt-113 charon: 30[IKE] received cert request for "CN=srv, OU=load-test, O=strongSwan"
Apr 27 14:18:46 ubnt-113 charon: 30[IKE] sending cert request for "CN=srv, OU=load-test, O=strongSwan"
Apr 27 14:18:46 ubnt-113 charon: 30[IKE] sending cert request for "CN=srv, OU=load-test, O=strongSwan"
Apr 27 14:18:46 ubnt-113 charon: 30[IKE] authentication of 'CN=c2-r1, OU=load-test, O=strongSwan' (myself) with RSA_EMSA_PKCS1_SHA256 successful
Apr 27 14:18:46 ubnt-113 charon: 30[IKE] sending end entity cert "CN=c2-r1, OU=load-test, O=strongSwan"
Apr 27 14:18:46 ubnt-113 charon: 30[IKE] establishing CHILD_SA load-test{2}
Apr 27 14:18:46 ubnt-113 charon: 30[ENC] generating IKE_AUTH request 1 [ IDi CERT CERTREQ IDr AUTH CPRQ(ADDR) N(ESP_TFC_PAD_N) SA TSi TSr N(MULT_AUTH) N(EAP_ONLY) ]
Apr 27 14:18:46 ubnt-113 charon: 30[NET] sending packet: from 192.168.10.2[500] to 192.168.10.1[500] (1068 bytes)
Apr 27 14:18:46 ubnt-113 charon: 14[NET] received packet: from 192.168.10.1[500] to 192.168.10.2[500] (828 bytes)
Apr 27 14:18:46 ubnt-113 charon: 14[ENC] parsed IKE_AUTH response 1 [ IDr CERT AUTH CPRP(ADDR) N(AUTH_LFT) N(TS_UNACCEPT) ]
Apr 27 14:18:46 ubnt-113 charon: 14[IKE] received end entity cert "CN=srv, OU=load-test, O=strongSwan"
Apr 27 14:18:46 ubnt-113 charon: 14[CFG] using trusted certificate "CN=srv, OU=load-test, O=strongSwan"
Apr 27 14:18:46 ubnt-113 charon: 14[IKE] authentication of 'CN=srv, OU=load-test, O=strongSwan' with RSA_EMSA_PKCS1_SHA256 successful
Apr 27 14:18:46 ubnt-113 charon: 14[IKE] IKE_SA load-test[3] established between 192.168.10.2[CN=c2-r1, OU=load-test, O=strongSwan]...192.168.10.1[CN=srv, OU=load-test, O=strongSwan]
Apr 27 14:18:46 ubnt-113 charon: 14[IKE] installing new virtual IP 10.3.10.1
Apr 27 14:18:46 ubnt-113 charon: 14[IKE] received TS_UNACCEPTABLE notify, no CHILD_SA built
Apr 27 14:18:46 ubnt-113 charon: 14[IKE] failed to establish CHILD_SA, keeping IKE_SA
Apr 27 14:18:46 ubnt-113 charon: 14[IKE] received AUTH_LIFETIME of 117s, scheduling reauthentication in 117s
</pre>



Responder ipsec.conf:
<pre>
# /etc/ipsec.conf - strongSwan IPsec configuration file

config setup
uniqueids=never
conn %default
ikelifetime=120s
keylife=5000s
rekeymargin=3s
keyingtries=1
keyexchange=ikev2
mobike=no
leftfirewall=yes
leftid="CN=srv, OU=load-test, O=strongSwan"
rightid=%any
leftcert=responder_cert.pem
authby=pubkey
type=tunnel
auto=add
conn rw
left=192.168.10.1
leftsubnet=10.1.10.0/16
right=%any
rightsourceip=10.3.10.1/16
leftsourceip=10.1.10.1/16
auto=add
</pre>


Initiator strongswan.conf:
<pre>
charon {
load = aes des sha1 sha2 md5 pem pkcs1 gmp random nonce x509 curl revocation hmac xcbc stroke kernel-netlink socket-default updown load-tester
reuse_ikesa = no
threads = 32
plugins {
load-tester {
enable = yes
initiators = 1
iterations = 1
delay = 1000
responder = 192.168.10.1
initiator_tsr = 0.0.0.0/0
responder_tsr = 10.1.10.1/24
responder_tsi = 10.3.10.1/16
proposal = aes128-sha1-modp1024
initiator_auth = pubkey
responder_auth = pubkey
request_virtual_ip = yes
ike_rekey = 0
child_rekey = 5000
delete_after_established = no
shutdown_when_complete = no
}
}

}
</pre>


Seems to be some timing issue in responder side. Please share if any information on this.
Let me know if any options to play with timing parameters.

Thanks
Sudheer

Back