[strongSwan] Lots of reconnections for a rekey/reauth, and packet drops
Hoggins!
hoggins at radiom.fr
Fri Dec 1 17:21:07 CET 2017
So after a bit of configuration cleaning as suggested by Tobias, both
nodes have been restarted, and I still experience oddities.
The former "/bin/sh ipsec not found" error was due to an issue in the
lookup $PATH as my StrongSwan installation on NODE1 is in /usr/local.
Anyway, I just had to symlink /usr/local/bin/ipsec to /usr/local, and
the error was gone.
But I still have my NODE1 reconnecting several times on NODE2 when
reauthenticating, and I can't figure out why.
Here are the logs on NODE1 (I filtered only "charon" entries) :
Dec 1 17:01:17 yomama charon: 05[IKE] reauthenticating IKE_SA
net-net[1]
Dec 1 17:01:17 yomama charon: 05[IKE] initiating IKE_SA net-net[2]
to 1.2.3.4
Dec 1 17:01:17 yomama charon: 05[ENC] generating IKE_SA_INIT
request 0 [ SA KE No N(NATD_S_IP) N(NATD_D_IP) N(FRAG_SUP)
N(HASH_ALG) N(REDIR_SUP) ]
Dec 1 17:01:17 yomama charon: 05[NET] sending packet: from
192.168.1.72[4500] to 1.2.3.4[4500] (384 bytes)
Dec 1 17:01:17 yomama charon: 16[NET] received packet: from
1.2.3.4[4500] to 192.168.1.72[4500] (242 bytes)
Dec 1 17:01:17 yomama charon: 16[ENC] parsed IKE_SA_INIT response 0
[ SA KE No N(NATD_S_IP) N(NATD_D_IP) N(FRAG_SUP) N(HASH_ALG)
N(MULT_AUTH) ]
Dec 1 17:01:17 yomama charon: 16[IKE] local host is behind NAT,
sending keep alives
Dec 1 17:01:17 yomama charon: 16[IKE] authentication of
'netnetYomama' (myself) with pre-shared key
Dec 1 17:01:17 yomama charon: 16[IKE] establishing CHILD_SA net-net{5}
Dec 1 17:01:17 yomama charon: 16[ENC] generating IKE_AUTH request 1
[ IDi IDr AUTH SA TSi TSr N(MULT_AUTH) N(EAP_ONLY) N(MSG_ID_SYN_SUP) ]
Dec 1 17:01:17 yomama charon: 16[NET] sending packet: from
192.168.1.72[4500] to 1.2.3.4[4500] (368 bytes)
Dec 1 17:01:17 yomama charon: 13[NET] received packet: from
1.2.3.4[4500] to 192.168.1.72[4500] (80 bytes)
Dec 1 17:01:17 yomama charon: 13[ENC] parsed INFORMATIONAL request
4 [ D ]
Dec 1 17:01:17 yomama charon: 13[IKE] received DELETE for IKE_SA
net-net[1]
Dec 1 17:01:17 yomama charon: 13[IKE] deleting IKE_SA net-net[1]
between 192.168.1.72[netnetYomama]...1.2.3.4[1.2.3.4]
Dec 1 17:01:17 yomama charon: 13[IKE] restarting CHILD_SA net-net
Dec 1 17:01:17 yomama charon: 13[IKE] initiating IKE_SA net-net[3]
to 1.2.3.4
Dec 1 17:01:17 yomama charon: 13[ENC] generating IKE_SA_INIT
request 0 [ SA KE No N(NATD_S_IP) N(NATD_D_IP) N(FRAG_SUP)
N(HASH_ALG) N(REDIR_SUP) ]
Dec 1 17:01:17 yomama charon: 13[NET] sending packet: from
192.168.1.72[4500] to 1.2.3.4[4500] (384 bytes)
Dec 1 17:01:17 yomama charon: 13[IKE] IKE_SA deleted
Dec 1 17:01:17 yomama charon: 13[ENC] generating INFORMATIONAL
response 4 [ ]
Dec 1 17:01:17 yomama charon: 13[NET] sending packet: from
192.168.1.72[4500] to 1.2.3.4[4500] (80 bytes)
Dec 1 17:01:17 yomama charon: 10[NET] received packet: from
1.2.3.4[4500] to 192.168.1.72[4500] (242 bytes)
Dec 1 17:01:17 yomama charon: 10[ENC] parsed IKE_SA_INIT response 0
[ SA KE No N(NATD_S_IP) N(NATD_D_IP) N(FRAG_SUP) N(HASH_ALG)
N(MULT_AUTH) ]
Dec 1 17:01:17 yomama charon: 15[NET] received packet: from
1.2.3.4[4500] to 192.168.1.72[4500] (272 bytes)
Dec 1 17:01:17 yomama charon: 15[ENC] parsed IKE_AUTH response 1 [
IDr AUTH SA TSi TSr N(AUTH_LFT) ]
Dec 1 17:01:17 yomama charon: 15[IKE] authentication of '1.2.3.4'
with pre-shared key successful
Dec 1 17:01:17 yomama charon: 15[IKE] IKE_SA net-net[2] established
between 192.168.1.72[netnetYomama]...1.2.3.4[1.2.3.4]
Dec 1 17:01:17 yomama charon: 15[IKE] scheduling reauthentication
in 3242s
Dec 1 17:01:17 yomama charon: 15[IKE] maximum IKE_SA lifetime 3422s
Dec 1 17:01:17 yomama charon: 10[IKE] local host is behind NAT,
sending keep alives
Dec 1 17:01:17 yomama charon: 10[IKE] authentication of
'netnetYomama' (myself) with pre-shared key
Dec 1 17:01:17 yomama charon: 10[IKE] establishing CHILD_SA
net-net{6} reqid 1
Dec 1 17:01:17 yomama charon: 15[IKE] CHILD_SA net-net{5}
established with SPIs c19e0c89_i cbceddfd_o and TS 192.168.22.0/24
192.168.35.0/24 === 192.168.33.0/24 192.168.55.0/24 192.168.66.0/24
Dec 1 17:01:17 yomama charon: 10[ENC] generating IKE_AUTH request 1
[ IDi N(INIT_CONTACT) IDr AUTH SA TSi TSr N(MULT_AUTH) N(EAP_ONLY)
N(MSG_ID_SYN_SUP) ]
Dec 1 17:01:17 yomama charon: 15[IKE] received AUTH_LIFETIME of
3403s, scheduling reauthentication in 3223s
Dec 1 17:01:17 yomama charon: 10[NET] sending packet: from
192.168.1.72[4500] to 1.2.3.4[4500] (368 bytes)
Dec 1 17:01:17 yomama charon: 15[IKE] peer certificate successfully
verified
Dec 1 17:01:17 yomama charon: 05[NET] received packet: from
1.2.3.4[4500] to 192.168.1.72[4500] (80 bytes)
Dec 1 17:01:17 yomama charon: 05[ENC] parsed INFORMATIONAL request
0 [ D ]
Dec 1 17:01:17 yomama charon: 05[IKE] received DELETE for IKE_SA
net-net[2]
Dec 1 17:01:17 yomama charon: 05[IKE] deleting IKE_SA net-net[2]
between 192.168.1.72[netnetYomama]...1.2.3.4[1.2.3.4]
Dec 1 17:01:17 yomama charon: 05[IKE] IKE_SA deleted
Dec 1 17:01:17 yomama charon: 05[ENC] generating INFORMATIONAL
response 0 [ ]
Dec 1 17:01:17 yomama charon: 05[NET] sending packet: from
192.168.1.72[4500] to 1.2.3.4[4500] (80 bytes)
Dec 1 17:01:17 yomama charon: 09[NET] received packet: from
1.2.3.4[4500] to 192.168.1.72[4500] (272 bytes)
Dec 1 17:01:17 yomama charon: 09[ENC] parsed IKE_AUTH response 1 [
IDr AUTH SA TSi TSr N(AUTH_LFT) ]
Dec 1 17:01:17 yomama charon: 09[IKE] authentication of '1.2.3.4'
with pre-shared key successful
Dec 1 17:01:17 yomama charon: 09[IKE] IKE_SA net-net[3] established
between 192.168.1.72[netnetYomama]...1.2.3.4[1.2.3.4]
Dec 1 17:01:17 yomama charon: 09[IKE] scheduling reauthentication
in 3257s
Dec 1 17:01:17 yomama charon: 09[IKE] maximum IKE_SA lifetime 3437s
Dec 1 17:01:17 yomama charon: 09[IKE] CHILD_SA net-net{6}
established with SPIs c3c614c0_i c97c96af_o and TS 192.168.22.0/24
192.168.35.0/24 === 192.168.33.0/24 192.168.55.0/24 192.168.66.0/24
Dec 1 17:01:17 yomama charon: 09[IKE] received AUTH_LIFETIME of
3304s, scheduling reauthentication in 3124s
... and on NODE2 at the same time :
Dec 1 17:01:17 webfront-1 charon[8235]: 11[NET] received packet:
from 4.3.2.1[34534] to 1.2.3.4[4500] (384 bytes)
Dec 1 17:01:17 webfront-1 charon[8235]: 11[ENC] parsed IKE_SA_INIT
request 0 [ SA KE No N(NATD_S_IP) N(NATD_D_IP) N(FRAG_SUP)
N(HASH_ALG) N(REDIR_SUP) ]
Dec 1 17:01:17 webfront-1 charon[8235]: 11[IKE] 4.3.2.1 is
initiating an IKE_SA
Dec 1 17:01:17 webfront-1 charon[8235]: 11[IKE] remote host is
behind NAT
Dec 1 17:01:17 webfront-1 charon[8235]: 11[ENC] generating
IKE_SA_INIT response 0 [ SA KE No N(NATD_S_IP) N(NATD_D_IP)
N(FRAG_SUP) N(HASH_ALG) N(MULT_AUTH) ]
Dec 1 17:01:17 webfront-1 charon[8235]: 11[NET] sending packet:
from 1.2.3.4[4500] to 4.3.2.1[34534] (242 bytes)
Dec 1 17:01:17 webfront-1 charon[8235]: 12[NET] received packet:
from 4.3.2.1[34534] to 1.2.3.4[4500] (368 bytes)
Dec 1 17:01:17 webfront-1 charon[8235]: 12[ENC] parsed IKE_AUTH
request 1 [ IDi IDr AUTH SA TSi TSr N(MULT_AUTH) N(EAP_ONLY)
N(MSG_ID_SYN_SUP) ]
Dec 1 17:01:17 webfront-1 charon[8235]: 12[CFG] looking for peer
configs matching 1.2.3.4[1.2.3.4]...4.3.2.1[netnetYomama]
Dec 1 17:01:17 webfront-1 charon[8235]: 12[CFG] selected peer
config 'net-net'
Dec 1 17:01:17 webfront-1 charon[8235]: 12[IKE] authentication of
'netnetYomama' with pre-shared key successful
Dec 1 17:01:17 webfront-1 charon[8235]: 12[IKE] authentication of
'1.2.3.4' (myself) with pre-shared key
Dec 1 17:01:17 webfront-1 charon[8235]: 12[IKE] IKE_SA
net-net[1701] established between
1.2.3.4[1.2.3.4]...4.3.2.1[netnetYomama]
Dec 1 17:01:17 webfront-1 charon[8235]: 12[IKE] scheduling
reauthentication in 3403s
Dec 1 17:01:17 webfront-1 charon[8235]: 12[IKE] maximum IKE_SA
lifetime 3583s
Dec 1 17:01:17 webfront-1 charon[8235]: 12[CFG] detected duplicate
IKE_SA for 'netnetYomama', triggering delete for old IKE_SA
Dec 1 17:01:17 webfront-1 charon[8235]: 07[IKE] deleting IKE_SA
net-net[1678] between 1.2.3.4[1.2.3.4]...4.3.2.1[netnetYomama]
Dec 1 17:01:17 webfront-1 charon[8235]: 07[IKE] sending DELETE for
IKE_SA net-net[1678]
Dec 1 17:01:17 webfront-1 charon[8235]: 07[ENC] generating
INFORMATIONAL request 4 [ D ]
Dec 1 17:01:17 webfront-1 charon[8235]: 07[NET] sending packet:
from 1.2.3.4[4500] to 4.3.2.1[34534] (80 bytes)
Dec 1 17:01:17 webfront-1 charon[8235]: 12[IKE] CHILD_SA
net-net{2718} established with SPIs cbceddfd_i c19e0c89_o and TS
192.168.33.0/24 192.168.55.0/24 192.168.66.0/24 === 192.168.22.0/24
192.168.35.0/24
Dec 1 17:01:17 webfront-1 charon[8235]: 05[NET] received packet:
from 4.3.2.1[34534] to 1.2.3.4[4500] (384 bytes)
Dec 1 17:01:17 webfront-1 charon[8235]: 16[NET] received packet:
from 4.3.2.1[34534] to 1.2.3.4[4500] (80 bytes)
Dec 1 17:01:17 webfront-1 charon[8235]: 12[ENC] generating IKE_AUTH
response 1 [ IDr AUTH SA TSi TSr N(AUTH_LFT) ]
Dec 1 17:01:17 webfront-1 charon[8235]: 12[NET] sending packet:
from 1.2.3.4[4500] to 4.3.2.1[34534] (272 bytes)
Dec 1 17:01:17 webfront-1 charon[8235]: 05[ENC] parsed IKE_SA_INIT
request 0 [ SA KE No N(NATD_S_IP) N(NATD_D_IP) N(FRAG_SUP)
N(HASH_ALG) N(REDIR_SUP) ]
Dec 1 17:01:17 webfront-1 charon[8235]: 05[IKE] 4.3.2.1 is
initiating an IKE_SA
Dec 1 17:01:17 webfront-1 charon[8235]: 05[IKE] remote host is
behind NAT
Dec 1 17:01:17 webfront-1 charon[8235]: 05[ENC] generating
IKE_SA_INIT response 0 [ SA KE No N(NATD_S_IP) N(NATD_D_IP)
N(FRAG_SUP) N(HASH_ALG) N(MULT_AUTH) ]
Dec 1 17:01:17 webfront-1 charon[8235]: 05[NET] sending packet:
from 1.2.3.4[4500] to 4.3.2.1[34534] (242 bytes)
Dec 1 17:01:17 webfront-1 charon[8235]: 16[ENC] parsed
INFORMATIONAL response 4 [ ]
Dec 1 17:01:17 webfront-1 charon[8235]: 16[CFG] got a response on a
duplicate IKE_SA for 'netnetYomama', deleting new IKE_SA
Dec 1 17:01:17 webfront-1 charon[8235]: 16[IKE] IKE_SA deleted
Dec 1 17:01:17 webfront-1 charon[8235]: 06[IKE] deleting IKE_SA
net-net[1701] between 1.2.3.4[1.2.3.4]...4.3.2.1[netnetYomama]
Dec 1 17:01:17 webfront-1 charon[8235]: 03[NET] received packet:
from 4.3.2.1[34534] to 1.2.3.4[4500] (368 bytes)
Dec 1 17:01:17 webfront-1 charon[8235]: 06[IKE] sending DELETE for
IKE_SA net-net[1701]
Dec 1 17:01:17 webfront-1 charon[8235]: 03[ENC] parsed IKE_AUTH
request 1 [ IDi N(INIT_CONTACT) IDr AUTH SA TSi TSr N(MULT_AUTH)
N(EAP_ONLY) N(MSG_ID_SYN_SUP) ]
Dec 1 17:01:17 webfront-1 charon[8235]: 03[CFG] looking for peer
configs matching 1.2.3.4[1.2.3.4]...4.3.2.1[netnetYomama]
Dec 1 17:01:17 webfront-1 charon[8235]: 03[CFG] selected peer
config 'net-net'
Dec 1 17:01:17 webfront-1 charon[8235]: 03[IKE] authentication of
'netnetYomama' with pre-shared key successful
Dec 1 17:01:17 webfront-1 charon[8235]: 03[IKE] authentication of
'1.2.3.4' (myself) with pre-shared key
Dec 1 17:01:17 webfront-1 charon[8235]: 06[ENC] generating
INFORMATIONAL request 0 [ D ]
Dec 1 17:01:17 webfront-1 charon[8235]: 06[NET] sending packet:
from 1.2.3.4[4500] to 4.3.2.1[34534] (80 bytes)
Dec 1 17:01:17 webfront-1 charon[8235]: 03[IKE] destroying
duplicate IKE_SA for peer 'netnetYomama', received INITIAL_CONTACT
Dec 1 17:01:17 webfront-1 charon[8235]: 03[IKE] IKE_SA
net-net[1702] established between
1.2.3.4[1.2.3.4]...4.3.2.1[netnetYomama]
Dec 1 17:01:17 webfront-1 charon[8235]: 03[IKE] scheduling
reauthentication in 3304s
Dec 1 17:01:17 webfront-1 charon[8235]: 03[IKE] maximum IKE_SA
lifetime 3484s
Dec 1 17:01:17 webfront-1 charon[8235]: 03[IKE] CHILD_SA
net-net{2719} established with SPIs c97c96af_i c3c614c0_o and TS
192.168.33.0/24 192.168.55.0/24 192.168.66.0/24 === 192.168.22.0/24
192.168.35.0/24
Dec 1 17:01:17 webfront-1 charon[8235]: 03[ENC] generating IKE_AUTH
response 1 [ IDr AUTH SA TSi TSr N(AUTH_LFT) ]
Dec 1 17:01:17 webfront-1 charon[8235]: 03[NET] sending packet:
from 1.2.3.4[4500] to 4.3.2.1[34534] (272 bytes)
Can you see something ?
Thanks !
Hoggins!
Le 01/12/2017 à 10:50, Hoggins! a écrit :
> Hello Tobias,
>
> Le 30/11/2017 à 18:16, Tobias Brunner a écrit :
>> Hi,
>>
>> Combining reauthentication with closeaction=restart is a bad idea. Note
>> that reauth=no does not disable reauthentication if the other peer has
>> reauth=yes configured, see [1].
> Yes, I removed the reauth=no option. It had been kept here because it
> was a "good" option to avoid packet losses when reauthenticating, but
> then we discovered the "make_before_break" that had seemed to solve our
> problems.
> And reading the "closeaction" documentation shows that adding it to our
> configuration was not our smartest move : I guess that our client tried
> to restart the connection when it received a legit CLOSE action, as it's
> the normal behavior when renewing, but then there was two parallel
> attempts, which is not a good thing and might have caused our problem.
>
> I just applied these new settings and restarted StrongSwan, I'll keep
> you posted.
>
> Thanks !
>
>> Regards,
>> Tobias
>>
>> [1]
>> https://wiki.strongswan.org/projects/strongswan/wiki/ExpiryRekey#IKEv2-Responder-Behavior
>>
>>
>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 191 bytes
Desc: OpenPGP digital signature
URL: <http://lists.strongswan.org/pipermail/users/attachments/20171201/1ea37546/attachment-0001.sig>
More information about the Users
mailing list