[Swan] SA lifetime too short, less than configured
Ivan Kuznetsov
kia at solvo.ru
Fri May 14 12:55:56 UTC 2021
Hi Paul
No, config lines are not ignored. Here is status output, it shows
'ike_life: 86400s' and 'ipsec_life: 28800s' implemented
[root at vpn3 ipsec.d]# ipsec auto --status | grep bkp/0x2
000 "bkp/0x2":
172.16.80.0/20===11.22.33.44<11.22.33.44>...55.66.77.88<55.66.77.88>===10.1.102.0/24;
erouted; eroute owner: #94673
000 "bkp/0x2": oriented; my_ip=unset; their_ip=unset;
my_updown=ipsec _updown;
000 "bkp/0x2": xauth us:none, xauth them:none, my_username=[any];
their_username=[any]
000 "bkp/0x2": our auth:secret, their auth:secret
000 "bkp/0x2": modecfg info: us:none, them:none, modecfg policy:push,
dns:unset, domains:unset, banner:unset, cat:unset;
000 "bkp/0x2": policy_label:unset;
000 "bkp/0x2": ike_life: 86400s; ipsec_life: 28800s; replay_window:
32; rekey_margin: 300s; rekey_fuzz: 100%; keyingtries: 3;
000 "bkp/0x2": retransmit-interval: 500ms; retransmit-timeout: 60s;
000 "bkp/0x2": initial-contact:yes; cisco-unity:no;
fake-strongswan:no; send-vendorid:no; send-no-esp-tfc:no;
000 "bkp/0x2": policy:
PSK+ENCRYPT+TUNNEL+PFS+UP+IKEV2_ALLOW+SAREF_TRACK+IKE_FRAG_ALLOW+ESN_NO;
000 "bkp/0x2": v2-auth-hash-policy: none;
000 "bkp/0x2": conn_prio: 20,24; interface: bond0.5; metric: 0; mtu:
unset; sa_prio:auto; sa_tfc:none;
000 "bkp/0x2": nflog-group: unset; mark: unset; vti-iface:unset;
vti-routing:no; vti-shared:no; nic-offload:auto;
000 "bkp/0x2": our idtype: ID_IPV4_ADDR; our id=11.22.33.44; their
idtype: ID_IPV4_ADDR; their id=55.66.77.88
000 "bkp/0x2": dpd: action:hold; delay:0; timeout:0; nat-t:
encaps:auto; nat_keepalive:yes; ikev1_natt:both
000 "bkp/0x2": newest ISAKMP SA: #94672; newest IPsec SA: #94673;
000 "bkp/0x2": aliases: bkp
000 "bkp/0x2": IKEv2 algorithm newest: AES_CBC_256-HMAC_SHA2_256-MODP2048
000 "bkp/0x2": ESP algorithm newest: AES_CBC_256-HMAC_SHA2_256_128;
pfsgroup=<Phase1>
000 #94672: "bkp/0x2":500 STATE_PARENT_I3 (PARENT SA established);
EVENT_SA_REKEY in 79663s; newest ISAKMP; idle;
Here is log (grep'ed by 'bkp/0x2' too):
May 14 09:09:26.961678: added connection description "bkp/0x1"
May 14 09:09:26.961850: added connection description "bkp/0x2"
May 14 09:09:26.962022: added connection description "bkp/0x3"
May 14 09:09:26.962146: added connection description "bkp/0x4"
May 14 09:09:45.765182: "bkp/0x2" #94267: initiating IKEv2 IKE SA
May 14 09:09:45.765214: "bkp/0x2": local IKE proposals (IKE SA initiator
selecting KE):
May 14 09:09:45.765223: "bkp/0x2":
1:IKE=AES_GCM_C_256-HMAC_SHA2_512+HMAC_SHA2_256-NONE-MODP2048+MODP3072+MODP4096+MODP8192+ECP_256+ECP_384+ECP_521+CURVE25519
May 14 09:09:45.765229: "bkp/0x2":
2:IKE=AES_GCM_C_128-HMAC_SHA2_512+HMAC_SHA2_256-NONE-MODP2048+MODP3072+MODP4096+MODP8192+ECP_256+ECP_384+ECP_521+CURVE25519
May 14 09:09:45.765235: "bkp/0x2":
3:IKE=AES_CBC_256-HMAC_SHA2_512+HMAC_SHA2_256-HMAC_SHA2_512_256+HMAC_SHA2_256_128-MODP2048+MODP3072+MODP4096+MODP8192+ECP_256+ECP_384+ECP_521+CURVE25519
May 14 09:09:45.765241: "bkp/0x2":
4:IKE=AES_CBC_128-HMAC_SHA2_512+HMAC_SHA2_256-HMAC_SHA2_512_256+HMAC_SHA2_256_128-MODP2048+MODP3072+MODP4096+MODP8192+ECP_256+ECP_384+ECP_521+CURVE25519
May 14 09:09:45.766146: "bkp/0x2" #94267: STATE_PARENT_I1: sent v2I1,
expected v2R1
May 14 09:09:45.805238: "bkp/0x2" #94267: sending INITIAL_CONTACT
May 14 09:09:45.805354: "bkp/0x2": local ESP/AH proposals (IKE SA
initiator emitting ESP/AH proposals):
May 14 09:09:45.805365: "bkp/0x2": 1:ESP=AES_GCM_C_256-NONE-NONE-DISABLED
May 14 09:09:45.805370: "bkp/0x2": 2:ESP=AES_GCM_C_128-NONE-NONE-DISABLED
May 14 09:09:45.805375: "bkp/0x2":
3:ESP=AES_CBC_256-HMAC_SHA2_512_256+HMAC_SHA2_256_128-NONE-DISABLED
May 14 09:09:45.805380: "bkp/0x2":
4:ESP=AES_CBC_128-HMAC_SHA2_512_256+HMAC_SHA2_256_128-NONE-DISABLED
May 14 09:09:45.805415: "bkp/0x2" #94268: STATE_PARENT_I2: sent v2I2,
expected v2R2 {auth=IKEv2 cipher=AES_CBC_256 integ=HMAC_SHA2_256_128
prf=HMAC_SHA2_256 group=MODP2048}
May 14 09:09:45.842717: "bkp/0x2" #94268: IKEv2 mode peer ID is
ID_IPV4_ADDR: '55.66.77.88'
May 14 09:09:45.842836: "bkp/0x2" #94268: Authenticated using authby=secret
May 14 09:09:45.873138: "bkp/0x2" #94268: negotiated connection
[172.16.80.0-172.16.95.255:0-65535 0] -> [10.1.102.0-10.1.102.255:0-65535 0]
May 14 09:09:45.873173: "bkp/0x2" #94268: STATE_V2_IPSEC_I: IPsec SA
established tunnel mode {ESP=>0x2c052ce7 <0xa8985bfa
xfrm=AES_CBC_256-HMAC_SHA2_256_128 NATOA=none NATD=none DPD=passive}
May 14 10:17:15.373003: "bkp/0x2" #94268: deleting other state #94268
(STATE_CHILDSA_DEL) aged 4049.567s and NOT sending notification
May 14 10:17:15.393644: "bkp/0x2" #94267: deleting state
(STATE_IKESA_DEL) aged 4049.628s and NOT sending notification
May 14 10:17:15.393727: "bkp/0x2" #94267: deleting IKE SA but connection
is supposed to remain up; schedule EVENT_REVIVE_CONNS
May 14 10:17:15.393939: "bkp/0x2": initiating connection which received
a Delete/Notify but must remain up per local policy
May 14 10:17:15.394011: "bkp/0x2" #94344: initiating IKEv2 IKE SA
May 14 10:17:15.395556: "bkp/0x2" #94344: STATE_PARENT_I1: sent v2I1,
expected v2R1
May 14 10:17:15.435288: "bkp/0x2" #94344: sending INITIAL_CONTACT
May 14 10:17:15.435418: "bkp/0x2" #94345: STATE_PARENT_I2: sent v2I2,
expected v2R2 {auth=IKEv2 cipher=AES_CBC_256 integ=HMAC_SHA2_256_128
prf=HMAC_SHA2_256 group=MODP2048}
May 14 10:17:15.472627: "bkp/0x2" #94345: IKEv2 mode peer ID is
ID_IPV4_ADDR: '55.66.77.88'
May 14 10:17:15.472730: "bkp/0x2" #94345: Authenticated using authby=secret
May 14 10:17:15.480988: "bkp/0x2" #94345: negotiated connection
[172.16.80.0-172.16.95.255:0-65535 0] -> [10.1.102.0-10.1.102.255:0-65535 0]
May 14 10:17:15.481004: "bkp/0x2" #94345: STATE_V2_IPSEC_I: IPsec SA
established tunnel mode {ESP=>0x7c43602b <0x229a1b14
xfrm=AES_CBC_256-HMAC_SHA2_256_128 NATOA=none NATD=none DPD=passive}
May 14 11:09:06.248788: "bkp/0x2" #94345: deleting other state #94345
(STATE_CHILDSA_DEL) aged 3110.813s and NOT sending notification
May 14 11:09:06.257425: "bkp/0x2" #94344: deleting state
(STATE_IKESA_DEL) aged 3110.863s and NOT sending notification
May 14 11:09:06.257479: "bkp/0x2" #94344: deleting IKE SA but connection
is supposed to remain up; schedule EVENT_REVIVE_CONNS
May 14 11:09:06.257584: "bkp/0x2": initiating connection which received
a Delete/Notify but must remain up per local policy
May 14 11:09:06.257621: "bkp/0x2" #94406: initiating IKEv2 IKE SA
May 14 11:09:06.258423: "bkp/0x2" #94406: STATE_PARENT_I1: sent v2I1,
expected v2R1
May 14 11:09:06.297743: "bkp/0x2" #94406: sending INITIAL_CONTACT
May 14 11:09:06.297895: "bkp/0x2" #94407: STATE_PARENT_I2: sent v2I2,
expected v2R2 {auth=IKEv2 cipher=AES_CBC_256 integ=HMAC_SHA2_256_128
prf=HMAC_SHA2_256 group=MODP2048}
May 14 11:09:06.335092: "bkp/0x2" #94407: IKEv2 mode peer ID is
ID_IPV4_ADDR: '55.66.77.88'
May 14 11:09:06.335208: "bkp/0x2" #94407: Authenticated using authby=secret
May 14 11:09:06.344054: "bkp/0x2" #94407: negotiated connection
[172.16.80.0-172.16.95.255:0-65535 0] -> [10.1.102.0-10.1.102.255:0-65535 0]
May 14 11:09:06.344073: "bkp/0x2" #94407: STATE_V2_IPSEC_I: IPsec SA
established tunnel mode {ESP=>0x03f2c7bd <0xfb8a1abc
xfrm=AES_CBC_256-HMAC_SHA2_256_128 NATOA=none NATD=none DPD=passive}
May 14 11:42:01.679896: "bkp/0x2" #94407: deleting other state #94407
(STATE_CHILDSA_DEL) aged 1975.382s and NOT sending notification
May 14 11:42:01.688602: "bkp/0x2" #94406: deleting state
(STATE_IKESA_DEL) aged 1975.430s and NOT sending notification
May 14 11:42:01.688648: "bkp/0x2" #94406: deleting IKE SA but connection
is supposed to remain up; schedule EVENT_REVIVE_CONNS
May 14 11:42:01.688746: "bkp/0x2": initiating connection which received
a Delete/Notify but must remain up per local policy
May 14 11:42:01.688783: "bkp/0x2" #94484: initiating IKEv2 IKE SA
May 14 11:42:01.689662: "bkp/0x2" #94484: STATE_PARENT_I1: sent v2I1,
expected v2R1
May 14 11:42:01.728796: "bkp/0x2" #94484: sending INITIAL_CONTACT
May 14 11:42:01.728933: "bkp/0x2" #94485: STATE_PARENT_I2: sent v2I2,
expected v2R2 {auth=IKEv2 cipher=AES_CBC_256 integ=HMAC_SHA2_256_128
prf=HMAC_SHA2_256 group=MODP2048}
May 14 11:42:01.765982: "bkp/0x2" #94485: IKEv2 mode peer ID is
ID_IPV4_ADDR: '55.66.77.88'
May 14 11:42:01.766085: "bkp/0x2" #94485: Authenticated using authby=secret
May 14 11:42:01.775101: "bkp/0x2" #94485: negotiated connection
[172.16.80.0-172.16.95.255:0-65535 0] -> [10.1.102.0-10.1.102.255:0-65535 0]
May 14 11:42:01.775123: "bkp/0x2" #94485: STATE_V2_IPSEC_I: IPsec SA
established tunnel mode {ESP=>0x05505a16 <0xaae8487c
xfrm=AES_CBC_256-HMAC_SHA2_256_128 NATOA=none NATD=none DPD=passive}
May 14 11:47:08.277952: "bkp/0x2" #94484: received duplicate
INFORMATIONAL message request (Message ID 9); retransmitting response
May 14 12:42:01.800669: "bkp/0x2" #94485: deleting other state #94485
(STATE_CHILDSA_DEL) aged 3600.071s and NOT sending notification
May 14 12:42:01.809408: "bkp/0x2" #94484: deleting state
(STATE_IKESA_DEL) aged 3600.120s and NOT sending notification
May 14 12:42:01.809451: "bkp/0x2" #94484: deleting IKE SA but connection
is supposed to remain up; schedule EVENT_REVIVE_CONNS
May 14 12:42:01.809543: "bkp/0x2": initiating connection which received
a Delete/Notify but must remain up per local policy
May 14 12:42:01.809578: "bkp/0x2" #94561: initiating IKEv2 IKE SA
May 14 12:42:01.810478: "bkp/0x2" #94561: STATE_PARENT_I1: sent v2I1,
expected v2R1
May 14 12:42:01.849643: "bkp/0x2" #94561: sending INITIAL_CONTACT
May 14 12:42:01.849803: "bkp/0x2" #94562: STATE_PARENT_I2: sent v2I2,
expected v2R2 {auth=IKEv2 cipher=AES_CBC_256 integ=HMAC_SHA2_256_128
prf=HMAC_SHA2_256 group=MODP2048}
May 14 12:42:01.886922: "bkp/0x2" #94562: IKEv2 mode peer ID is
ID_IPV4_ADDR: '55.66.77.88'
May 14 12:42:01.887031: "bkp/0x2" #94562: Authenticated using authby=secret
May 14 12:42:01.896422: "bkp/0x2" #94562: negotiated connection
[172.16.80.0-172.16.95.255:0-65535 0] -> [10.1.102.0-10.1.102.255:0-65535 0]
May 14 12:42:01.896442: "bkp/0x2" #94562: STATE_V2_IPSEC_I: IPsec SA
established tunnel mode {ESP=>0xd4e799d0 <0xe0be8f7e
xfrm=AES_CBC_256-HMAC_SHA2_256_128 NATOA=none NATD=none DPD=passive}
May 14 13:30:01.525511: "bkp/0x2" #94562: deleting other state #94562
(STATE_CHILDSA_DEL) aged 2879.675s and NOT sending notification
May 14 13:30:01.534942: "bkp/0x2" #94561: deleting state
(STATE_IKESA_DEL) aged 2879.725s and NOT sending notification
May 14 13:30:01.534995: "bkp/0x2" #94561: deleting IKE SA but connection
is supposed to remain up; schedule EVENT_REVIVE_CONNS
May 14 13:30:01.535098: "bkp/0x2": initiating connection which received
a Delete/Notify but must remain up per local policy
May 14 13:30:01.535136: "bkp/0x2" #94628: initiating IKEv2 IKE SA
May 14 13:30:01.535996: "bkp/0x2" #94628: STATE_PARENT_I1: sent v2I1,
expected v2R1
May 14 13:30:01.575206: "bkp/0x2" #94628: sending INITIAL_CONTACT
May 14 13:30:01.575343: "bkp/0x2" #94629: STATE_PARENT_I2: sent v2I2,
expected v2R2 {auth=IKEv2 cipher=AES_CBC_256 integ=HMAC_SHA2_256_128
prf=HMAC_SHA2_256 group=MODP2048}
May 14 13:30:01.612611: "bkp/0x2" #94629: IKEv2 mode peer ID is
ID_IPV4_ADDR: '55.66.77.88'
May 14 13:30:01.612716: "bkp/0x2" #94629: Authenticated using authby=secret
May 14 13:30:01.621267: "bkp/0x2" #94629: negotiated connection
[172.16.80.0-172.16.95.255:0-65535 0] -> [10.1.102.0-10.1.102.255:0-65535 0]
May 14 13:30:01.621283: "bkp/0x2" #94629: STATE_V2_IPSEC_I: IPsec SA
established tunnel mode {ESP=>0x77334e93 <0xd5474f6f
xfrm=AES_CBC_256-HMAC_SHA2_256_128 NATOA=none NATD=none DPD=passive}
May 14 13:46:52.558578: "bkp/0x2" #94628: received duplicate
INFORMATIONAL message request (Message ID 32); retransmitting response
May 14 14:00:01.944278: "bkp/0x2" #94629: deleting other state #94629
(STATE_CHILDSA_DEL) aged 1800.369s and NOT sending notification
May 14 14:00:01.953181: "bkp/0x2" #94628: deleting state
(STATE_IKESA_DEL) aged 1800.418s and NOT sending notification
May 14 14:00:01.953235: "bkp/0x2" #94628: deleting IKE SA but connection
is supposed to remain up; schedule EVENT_REVIVE_CONNS
May 14 14:00:01.953334: "bkp/0x2": initiating connection which received
a Delete/Notify but must remain up per local policy
May 14 14:00:01.953376: "bkp/0x2" #94672: initiating IKEv2 IKE SA
May 14 14:00:01.954247: "bkp/0x2" #94672: STATE_PARENT_I1: sent v2I1,
expected v2R1
May 14 14:00:02.005553: "bkp/0x2" #94672: sending INITIAL_CONTACT
May 14 14:00:02.005687: "bkp/0x2" #94673: STATE_PARENT_I2: sent v2I2,
expected v2R2 {auth=IKEv2 cipher=AES_CBC_256 integ=HMAC_SHA2_256_128
prf=HMAC_SHA2_256 group=MODP2048}
May 14 14:00:02.042487: "bkp/0x2" #94673: IKEv2 mode peer ID is
ID_IPV4_ADDR: '55.66.77.88'
May 14 14:00:02.042589: "bkp/0x2" #94673: Authenticated using authby=secret
May 14 14:00:02.051502: "bkp/0x2" #94673: negotiated connection
[172.16.80.0-172.16.95.255:0-65535 0] -> [10.1.102.0-10.1.102.255:0-65535 0]
May 14 14:00:02.051522: "bkp/0x2" #94673: STATE_V2_IPSEC_I: IPsec SA
established tunnel mode {ESP=>0xc2f3aa1d <0x5e50bde1
xfrm=AES_CBC_256-HMAC_SHA2_256_128 NATOA=none NATD=none DPD=passive}
14.05.2021 14:51, Paul Wouters пишет:
> If you have those empty lines in your config, perhaps that is causing the lines to be ignored ?
>
> Otherwise, show us the logs from the rekey event? It should tell us why.
>
> Sent from my iPhone
>
>> On May 14, 2021, at 03:46, Ivan Kuznetsov <kia at solvo.ru> wrote:
>>
>> Hello
>>
>> We use libreswan 3.32 under Linux and have a IPsec peer recently upgraded their Cisco ASA. Tunnel was migrated to IKEv2. All works fine except the libreswan side restarts ISAKMP too often, mostly after 1h. ESP is restarted too. Settings for lifetime are 24h for phase 1 and 8h for phase 2 on both sides. rekeymargin has default value (300s)
>>
>> Why libreswan drops ISAKMP SA regardless of explicit settings?
>>
>> Libreswan configuration:
>>
>> conn bkp
>> type=tunnel
>> auto=start
>> authby=secret
>> left=11.22.33.44
>> leftsubnet=172.16.80.0/20
>> right=55.66.77.88
>> rightsubnets=10.1.208.0/28,10.1.102.0/24,10.1.100.22/32,10.1.104.0/29
>>
>> ikev2=yes
>> ikelifetime=24h
>> initial-contact=yes
>>
>> phase2=esp
>> salifetime=8h
>> # BKP's Cisco ASA has stranges regarding DH groups on phase2
>> # pfs=no
>>
>> rekey=yes
>> rekeymargin=5m
>> keyingtries=3
>>
>> fragmentation=yes
>> # BKP's Cisco ASA has nonstadard DPD
>> # dpddelay=30
>> # dpdtimeout=120
>> # dpdaction=restart
>>
>>
>> Libreswan log is attached
>>
>> --
>> Regards, Ivan Kuznetsov
>> SOLVO ltd
>> <bkp.log>
>> _______________________________________________
>> Swan mailing list
>> Swan at lists.libreswan.org
>> https://lists.libreswan.org/mailman/listinfo/swan
--
Regards, Ivan Kuznetsov
SOLVO ltd
More information about the Swan
mailing list