unable to re-create CHILD_SA when it goes down due to inactivity #2199

lafibre · 2024-04-05T09:06:18Z

lafibre
Apr 5, 2024

Hello all!

I've encountered an issue with phase 2 re-establishment.

System server side :

OS: Slackware
strongSwan version(s): U5.9.14/K4.19.227
Tested/confirmed with the latest version: yes

System client side :

OS: debian 12.4
strongSwan version(s):U5.9.8/K6.1.0-12-amd64

The issue
Previously, I was using strongSwan version 5.9.4, and everything was working perfectly. However, after upgrading to version 5.9.11, I encountered an issue which I will describe shortly. I then upgraded to version 5.9.14, but unfortunately, the problem persisted. When reverting back to version 5.9.4, the issue disappeared.

I made no changes to configuration files between tests with different versions.

The problem occurs with the following simple configuration, used as the server side:

conn simpleconn
	keyexchange=ikev2
	left=%defaultroute
	right=a.b.c.d
	dpdaction = clear
	dpddelay = 30s
	dpdtimeout = 10s
	authby = psk
	leftsubnet=192.168.0.32/32
	rightsubnet=192.168.156.2/32
	esp=aes256-sha512-modp8192
	ike=aes256-sha256-modp8192
	lifetime = 60m
        inactivity = 1m
	ikelifetime = 180m
	auto = route

When I start the tunnel from scratch:
The IKE_SA is establishing and CHILD_SA also.
ipsec status command shows:

     1114811[182]: ESTABLISHED 1 second ago, a.b.c.d[a.b.c.d]...e.f.g.h[e.f.g.h]
     1114811{1168}:  INSTALLED, TUNNEL, reqid 2, ESP in UDP SPIs: cd0143c3_i c5f33358_o
     1114811{1168}:   192.168.0.32/32 === 192.168.156.2/32

Due to inactivity, CHILD_SA will close normally:

1114811[182]: ESTABLISHED 2 minutes ago, a.b.c.d[a.b.c.d]]...e.f.g.h[e.f.g.h]
However, if I create activity on the client side to re-open phase-2 with ping -I 192.168.156.2 192.168.0.32, the CHILD_SA fails with the following error message:

Apr  5 10:40:17.+0200 SAS-01-019-997 ipsec: 07[IKE] unable to install inbound and outbound IPsec SA (SAD) in kernel                                      
Apr  5 10:40:17.+0200 SAS-01-019-997 ipsec: 07[IKE] failed to establish CHILD_SA, keeping IKE_SA

However, if I force down and up the complete connection, I encounter no problem.

I've checked all configuration default values changed in versions' change logs, but I couldn't find what might be causing this problem.

Thank by advance to your helps

Answered by tobiasbrunner

Apr 8, 2024

It could be the key derivation that fails due to an OpenSSL issue with modp8192 that was discussed in #1255.

View full answer

tobiasbrunner · 2024-04-05T09:25:35Z

tobiasbrunner
Apr 5, 2024
Maintainer

Apr 5 10:40:17.+0200 SAS-01-019-997 ipsec: 07[IKE] unable to install inbound and outbound IPsec SA (SAD) in kernel

Any error messages before that? This doesn't really tell us what failed in the kernel (try increasing the log level for knl) or possibly during the key derivation (log level for chd could be increased to see more about that).

1 reply

lafibre Apr 8, 2024
Author

Sorry for my late answer. I'll try to do this to get more informations. Thanks

lafibre · 2024-04-08T07:55:28Z

lafibre
Apr 8, 2024
Author

Hi,
I had set debug level to 3 for knl and chd
please find below the complete exchanges :

First establishment

Apr  8 09:42:55.+0200 SAS-01-019-997 ipsec: 04[ENC] generating IKE_SA_INIT response 0 [ SA KE No N(NATD_S_IP) N(NATD_D_IP) CERTREQ N(FRAG_SUP) N(HASH_ALG) N(CHDLESS_SUP) N(MULT_AUTH) ] 
Apr  8 09:43:05.+0200 SAS-01-019-997 ipsec: 05[ENC] parsed IKE_AUTH request 1 [ IDi N(INIT_CONTACT) IDr AUTH SA TSi TSr N(MOBIKE_SUP) N(ADD_4_ADDR) N(MULT_AUTH) N(EAP_ONLY) N(MSG_ID_SYN_SUP) ] 
Apr  8 09:43:05.+0200 SAS-01-019-997 ipsec: 05[CFG] looking for peer configs matching a.b.c.d[1114811]...e.f.g.h[e.f.g.h] 
Apr  8 09:43:05.+0200 SAS-01-019-997 ipsec: 05[CFG] selected peer config '1114811' 
Apr  8 09:43:05.+0200 SAS-01-019-997 ipsec: 05[IKE] authentication of 'e.f.g.h' with pre-shared key successful 
Apr  8 09:43:05.+0200 SAS-01-019-997 ipsec: 05[IKE] peer supports MOBIKE 
Apr  8 09:43:05.+0200 SAS-01-019-997 ipsec: 05[IKE] authentication of '1114811' (myself) with pre-shared key 
Apr  8 09:43:05.+0200 SAS-01-019-997 ipsec: 05[IKE] IKE_SA 1114811[1] established between a.b.c.d[1114811]...e.f.g.h[e.f.g.h] 
Apr  8 09:43:05.+0200 SAS-01-019-997 ipsec: 05[IKE] scheduling reauthentication in 10007s 
Apr  8 09:43:05.+0200 SAS-01-019-997 ipsec: 05[IKE] maximum IKE_SA lifetime 10547s 
Apr  8 09:43:05.+0200 SAS-01-019-997 ipsec: 05[CFG] selected proposal: ESP:AES_CBC_256/HMAC_SHA2_512_256/NO_EXT_SEQ 
Apr  8 09:43:05.+0200 SAS-01-019-997 ipsec: 05[KNL] got SPI c40b8a48 
Apr  8 09:43:05.+0200 SAS-01-019-997 ipsec: 05[CHD] CHILD_SA 1114811{1} state change: CREATED => INSTALLING 
Apr  8 09:43:05.+0200 SAS-01-019-997 ipsec: 05[CHD]   using AES_CBC for encryption 
Apr  8 09:43:05.+0200 SAS-01-019-997 ipsec: 05[CHD]   using HMAC_SHA2_512_256 for integrity 
Apr  8 09:43:05.+0200 SAS-01-019-997 ipsec: 05[CHD] adding inbound ESP SA 
Apr  8 09:43:05.+0200 SAS-01-019-997 ipsec: 05[CHD]   SPI 0xc40b8a48, src e.f.g.h dst a.b.c.d 
Apr  8 09:43:05.+0200 SAS-01-019-997 ipsec: 05[KNL] adding SAD entry with SPI c40b8a48 and reqid {1} 
Apr  8 09:43:05.+0200 SAS-01-019-997 ipsec: 05[KNL]   using encryption algorithm AES_CBC with key size 256 
Apr  8 09:43:05.+0200 SAS-01-019-997 ipsec: 05[KNL]   using integrity algorithm HMAC_SHA2_512_256 with key size 512 
Apr  8 09:43:05.+0200 SAS-01-019-997 ipsec: 05[KNL]   using replay window of 32 packets 
Apr  8 09:43:05.+0200 SAS-01-019-997 ipsec: 05[KNL]   HW offload: no 
Apr  8 09:43:05.+0200 SAS-01-019-997 ipsec: 05[CHD] adding outbound ESP SA 
Apr  8 09:43:05.+0200 SAS-01-019-997 ipsec: 05[CHD]   SPI 0xc7cf1315, src a.b.c.d dst e.f.g.h 
Apr  8 09:43:05.+0200 SAS-01-019-997 ipsec: 05[KNL] adding SAD entry with SPI c7cf1315 and reqid {1} 
Apr  8 09:43:05.+0200 SAS-01-019-997 ipsec: 05[KNL]   using encryption algorithm AES_CBC with key size 256 
Apr  8 09:43:05.+0200 SAS-01-019-997 ipsec: 05[KNL]   using integrity algorithm HMAC_SHA2_512_256 with key size 512 
Apr  8 09:43:05.+0200 SAS-01-019-997 ipsec: 05[KNL]   using replay window of 0 packets 
Apr  8 09:43:05.+0200 SAS-01-019-997 ipsec: 05[KNL]   HW offload: no 
Apr  8 09:43:05.+0200 SAS-01-019-997 ipsec: 05[KNL] adding policy 192.168.156.2/32 === 192.168.0.32/32 in [priority 367231, refcount 1] 
Apr  8 09:43:05.+0200 SAS-01-019-997 ipsec: 05[KNL] adding policy 192.168.156.2/32 === 192.168.0.32/32 fwd [priority 367231, refcount 1] 
Apr  8 09:43:05.+0200 SAS-01-019-997 ipsec: 05[KNL] adding policy 192.168.0.32/32 === 192.168.156.2/32 out [priority 367231, refcount 1] 
Apr  8 09:43:05.+0200 SAS-01-019-997 ipsec: 05[KNL] getting a local address in traffic selector 192.168.0.32/32 
Apr  8 09:43:05.+0200 SAS-01-019-997 ipsec: 05[KNL] no local address found in traffic selector 192.168.0.32/32 
Apr  8 09:43:05.+0200 SAS-01-019-997 ipsec: 05[IKE] CHILD_SA 1114811{1} established with SPIs c40b8a48_i c7cf1315_o and TS 192.168.0.32/32 === 192.168.156.2/32 
Apr  8 09:43:05.+0200 SAS-01-019-997 ipsec: 05[CHD] CHILD_SA 1114811{1} state change: INSTALLING => INSTALLED 
Apr  8 09:43:05.+0200 SAS-01-019-997 ipsec: 05[KNL] querying SAD entry with SPI c40b8a48 
Apr  8 09:43:05.+0200 SAS-01-019-997 ipsec: 05[KNL] querying SAD entry with SPI c7cf1315 
Apr  8 09:43:05.+0200 SAS-01-019-997 ipsec: 05[KNL] getting iface name for index 8 
Apr  8 09:43:05.+0200 SAS-01-019-997 ipsec: 05[KNL] using (ip gateway) as nexthop and eth3 as dev to reach e.f.g.h/32 
Apr  8 09:43:05.+0200 SAS-01-019-997 ipsec: 05[ENC] generating IKE_AUTH response 1 [ IDr AUTH SA TSi TSr N(MOBIKE_SUP) N(ADD_4_ADDR) N(ADD_4_ADDR) N(ADD_4_ADDR) N(ADD_4_ADDR) N(ADD_4_ADDR) N(ADD_4_ADDR) N(ADD_4_ADDR) N(ADD_4_ADDR) ]

At this point all is warking

deleting CHILD_SA dur to inactivity :

Apr  8 09:43:35.+0200 SAS-01-019-997 ipsec: 12[KNL] querying policy 192.168.156.2/32 === 192.168.0.32/32 in 
Apr  8 09:43:35.+0200 SAS-01-019-997 ipsec: 12[KNL] querying policy 192.168.156.2/32 === 192.168.0.32/32 fwd 
Apr  8 09:43:35.+0200 SAS-01-019-997 ipsec: 12[KNL] querying policy 192.168.0.32/32 === 192.168.156.2/32 out 
Apr  8 09:43:35.+0200 SAS-01-019-997 ipsec: 12[KNL] querying SAD entry with SPI c40b8a48 
Apr  8 09:43:35.+0200 SAS-01-019-997 ipsec: 12[KNL] querying SAD entry with SPI c7cf1315 
Apr  8 09:43:35.+0200 SAS-01-019-997 ipsec: 12[IKE] closing CHILD_SA 1114811{1} with SPIs c40b8a48_i (0 bytes) c7cf1315_o (0 bytes) and TS 192.168.0.32/32 === 192.168.156.2/32 
Apr  8 09:43:35.+0200 SAS-01-019-997 ipsec: 12[IKE] sending DELETE for ESP CHILD_SA with SPI c40b8a48 
Apr  8 09:43:35.+0200 SAS-01-019-997 ipsec: 12[CHD] CHILD_SA 1114811{1} state change: INSTALLED => DELETING 
Apr  8 09:43:35.+0200 SAS-01-019-997 ipsec: 12[ENC] generating INFORMATIONAL request 0 [ D ] 
Apr  8 09:43:35.+0200 SAS-01-019-997 ipsec: 15[ENC] parsed INFORMATIONAL response 0 [ D ] 
Apr  8 09:43:35.+0200 SAS-01-019-997 ipsec: 15[IKE] received DELETE for ESP CHILD_SA with SPI c7cf1315 
Apr  8 09:43:35.+0200 SAS-01-019-997 ipsec: 15[IKE] CHILD_SA closed 
Apr  8 09:43:35.+0200 SAS-01-019-997 ipsec: 15[CHD] CHILD_SA 1114811{1} state change: DELETING => DELETED 
Apr  8 09:43:35.+0200 SAS-01-019-997 ipsec: 15[KNL] querying SAD entry with SPI c40b8a48 
Apr  8 09:43:35.+0200 SAS-01-019-997 ipsec: 15[KNL] querying SAD entry with SPI c7cf1315 
Apr  8 09:43:35.+0200 SAS-01-019-997 ipsec: 15[CHD] CHILD_SA 1114811{1} state change: DELETED => DESTROYING 
Apr  8 09:43:35.+0200 SAS-01-019-997 ipsec: 15[KNL] deleting policy 192.168.0.32/32 === 192.168.156.2/32 out 
Apr  8 09:43:35.+0200 SAS-01-019-997 ipsec: 15[KNL] deleting policy 192.168.156.2/32 === 192.168.0.32/32 in 
Apr  8 09:43:35.+0200 SAS-01-019-997 ipsec: 15[KNL] deleting policy 192.168.156.2/32 === 192.168.0.32/32 fwd 
Apr  8 09:43:35.+0200 SAS-01-019-997 ipsec: 15[KNL] deleting SAD entry with SPI c40b8a48 
Apr  8 09:43:35.+0200 SAS-01-019-997 ipsec: 15[KNL] deleted SAD entry with SPI c40b8a48 
Apr  8 09:43:35.+0200 SAS-01-019-997 ipsec: 15[KNL] deleting SAD entry with SPI c7cf1315 
Apr  8 09:43:35.+0200 SAS-01-019-997 ipsec: 15[KNL] deleted SAD entry with SPI c7cf1315

new request for phase 2 :

Apr  8 09:43:53.+0200 SAS-01-019-997 ipsec: 09[ENC] parsed CREATE_CHILD_SA request 2 [ EF(1/2) ] 
Apr  8 09:43:53.+0200 SAS-01-019-997 ipsec: 09[ENC] received fragment #1 of 2, waiting for complete IKE message 
Apr  8 09:43:53.+0200 SAS-01-019-997 ipsec: 06[ENC] parsed CREATE_CHILD_SA request 2 [ EF(2/2) ] 
Apr  8 09:43:53.+0200 SAS-01-019-997 ipsec: 06[ENC] received fragment #2 of 2, reassembled fragmented IKE message (1424 bytes) 
Apr  8 09:43:53.+0200 SAS-01-019-997 ipsec: 06[ENC] parsed CREATE_CHILD_SA request 2 [ SA No KE TSi TSr ] 
Apr  8 09:44:03.+0200 SAS-01-019-997 ipsec: 06[CFG] selected proposal: ESP:AES_CBC_256/HMAC_SHA2_512_256/MODP_8192/NO_EXT_SEQ 
Apr  8 09:44:03.+0200 SAS-01-019-997 ipsec: 06[KNL] got SPI cb94aa65 
Apr  8 09:44:03.+0200 SAS-01-019-997 ipsec: 06[CHD] CHILD_SA 1114811{2} state change: CREATED => INSTALLING 
Apr  8 09:44:03.+0200 SAS-01-019-997 ipsec: 06[CHD]   using AES_CBC for encryption 
Apr  8 09:44:03.+0200 SAS-01-019-997 ipsec: 06[CHD]   using HMAC_SHA2_512_256 for integrity 
Apr  8 09:44:13.+0200 SAS-01-019-997 ipsec: 06[IKE] unable to install inbound and outbound IPsec SA (SAD) in kernel 
Apr  8 09:44:13.+0200 SAS-01-019-997 ipsec: 06[IKE] failed to establish CHILD_SA, keeping IKE_SA 
Apr  8 09:44:13.+0200 SAS-01-019-997 ipsec: 06[CHD] CHILD_SA 1114811{2} state change: INSTALLING => DESTROYING 
Apr  8 09:44:13.+0200 SAS-01-019-997 ipsec: 06[KNL] deleting policy 192.168.156.2/32 === 192.168.0.32/32 in 
Apr  8 09:44:13.+0200 SAS-01-019-997 ipsec: 06[KNL] deleting policy 192.168.156.2/32 === 192.168.0.32/32 in failed, not found 
Apr  8 09:44:13.+0200 SAS-01-019-997 ipsec: 06[KNL] deleting policy 192.168.156.2/32 === 192.168.0.32/32 fwd 
Apr  8 09:44:13.+0200 SAS-01-019-997 ipsec: 06[KNL] deleting policy 192.168.156.2/32 === 192.168.0.32/32 fwd failed, not found 
Apr  8 09:44:13.+0200 SAS-01-019-997 ipsec: 06[KNL] deleting SAD entry with SPI cb94aa65 
Apr  8 09:44:13.+0200 SAS-01-019-997 ipsec: 06[KNL] deleted SAD entry with SPI cb94aa65 
Apr  8 09:44:13.+0200 SAS-01-019-997 ipsec: 06[ENC] generating CREATE_CHILD_SA response 2 [ N(NO_PROP) ] 
Apr  8 09:44:13.+0200 SAS-01-019-997 ipsec: 10[IKE] received retransmit of request with ID 2, retransmitting response 
Apr  8 09:44:13.+0200 SAS-01-019-997 ipsec: 08[IKE] received message ID 2, expected 3, ignored 
Apr  8 09:44:13.+0200 SAS-01-019-997 ipsec: 07[IKE] received retransmit of request with ID 2, retransmitting response 
Apr  8 09:44:13.+0200 SAS-01-019-997 ipsec: 05[IKE] received message ID 2, expected 3, ignored

I can't see more reason of unestablishement ...

2 replies

tobiasbrunner Apr 8, 2024
Maintainer

It could be the key derivation that fails due to an OpenSSL issue with modp8192 that was discussed in #1255.

Answer selected by lafibre

lafibre Apr 9, 2024
Author

Hum Interesting,
I also tried changing ciphers simultaneously during my tests.
You might be right! I'll rollback and test again.

"I have searched a lot for 'unable to install inbound and outbound IPsec SA,' but I have never come across this post."
Thanks !

lafibre · 2024-04-08T10:37:01Z

lafibre
Apr 8, 2024
Author

I am now able to resolve the issue. To achieve this, I removed the 'NLM_F_DUMP' from the 'nlmsg_flags' flag in the netlink communication between libcharon and the kernel. I removed line 1865 in 'src/libcharon/plugins/kernel_netlink/kernel_netlink_net.c' (hdr->nlmsg_flags |= NLM_F_DUMP;).

I believe this issue may be related to my specific routing configuration, which includes numerous routing policy rules, a default route not located in the main routing table, and the use of conntrack mark.

Could someone please explain clearly what occurred?"

1 reply

tobiasbrunner Apr 8, 2024
Maintainer

That doesn't really make sense as that flag doesn't affect the installation of the negotiated SA at all. It's also set in versions way older than 5.9.4, which you claim works.

lafibre · 2024-04-16T16:24:14Z

lafibre
Apr 16, 2024
Author

It could be the key derivation that fails due to an OpenSSL issue with modp8192 that was discussed in #1255.
It was my finally my issue.

Thanks @tobiasbrunner !!

0 replies

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

unable to re-create CHILD_SA when it goes down due to inactivity #2199

{{title}}

Replies: 4 comments 4 replies

{{title}}

{{title}}

{{title}}

{{title}}

{{title}}

{{title}}

{{title}}

{{title}}

Select a reply

unable to re-create CHILD_SA when it goes down due to inactivity #2199

lafibre Apr 5, 2024

Replies: 4 comments · 4 replies

tobiasbrunner Apr 5, 2024 Maintainer

lafibre Apr 8, 2024 Author

lafibre Apr 8, 2024 Author

tobiasbrunner Apr 8, 2024 Maintainer

lafibre Apr 9, 2024 Author

lafibre Apr 8, 2024 Author

tobiasbrunner Apr 8, 2024 Maintainer

lafibre Apr 16, 2024 Author

lafibre
Apr 5, 2024

Replies: 4 comments 4 replies

tobiasbrunner
Apr 5, 2024
Maintainer

lafibre Apr 8, 2024
Author

lafibre
Apr 8, 2024
Author

tobiasbrunner Apr 8, 2024
Maintainer

lafibre Apr 9, 2024
Author

lafibre
Apr 8, 2024
Author

tobiasbrunner Apr 8, 2024
Maintainer

lafibre
Apr 16, 2024
Author