[strongSwan] No matching CHILD_SA config found - but it's right there

[Chris Linstruth]

Hey all -

Pulling my hair out here. Have this one tunnel that is hanging on rekeying. Both sides were stuck on REKEYING. They eventually re-authed the outer IKE tunnel and came up again. This is ongoing with traffic stopping at each rekey for random amounts of time.

I can’t find anything wrong. Do not know why the 203.0.113.121 side is returning INVALID_ID when the “Phase 2” is right there.

Any pointers graciously accepted. Thanks.

Oct 30 18:06:43 pfSense_2.4.4 charon: 06[NET] <con4000|55> received packet: from 198.51.100.49[500] to 203.0.113.121[500] (460 bytes)
Oct 30 18:06:43 pfSense_2.4.4 charon: 06[ENC] <con4000|55> parsed QUICK_MODE request 3072107701 [ HASH SA No KE ID ID ]
Oct 30 18:06:43 pfSense_2.4.4 charon: 06[CFG] <con4000|55> looking for a child config for 192.168.14.0/24|/0 === 192.168.16.0/24|/0
Oct 30 18:06:43 pfSense_2.4.4 charon: 06[IKE] <con4000|55> no matching CHILD_SA config found
Oct 30 18:06:43 pfSense_2.4.4 charon: 06[IKE] <con4000|55> queueing INFORMATIONAL task
Oct 30 18:06:43 pfSense_2.4.4 charon: 06[IKE] <con4000|55> activating new tasks
Oct 30 18:06:43 pfSense_2.4.4 charon: 06[IKE] <con4000|55> activating INFORMATIONAL task
Oct 30 18:06:43 pfSense_2.4.4 charon: 06[ENC] <con4000|55> generating INFORMATIONAL_V1 request 3147423319 [ HASH N(INVAL_ID) ]
Oct 30 18:06:43 pfSense_2.4.4 charon: 06[NET] <con4000|55> sending packet: from 203.0.113.121[500] to 198.51.100.49[500] (92 bytes)
Oct 30 18:06:43 pfSense_2.4.4 charon: 06[IKE] <con4000|55> activating new tasks
Oct 30 18:06:43 pfSense_2.4.4 charon: 06[IKE] <con4000|55> nothing to initiate

IT'S RIGHT THERE:

$ ipsec statusall con4000

Status of IKE charon daemon (strongSwan 5.6.3, FreeBSD 11.2-RELEASE-p3, amd64):
uptime: 2 days, since Oct 27 22:44:06 2018
worker threads: 11 of 16 idle, 5/0/0/0 working, job queue: 0/0/0/0, scheduled: 10
loaded plugins: charon unbound aes des blowfish rc2 sha2 sha1 md4 md5 random nonce x509 revocation constraints pubkey pkcs1 pkcs7 pkcs8 pkcs12 pgp dnskey sshkey ipseckey pem openssl fips-prf curve25519 xcbc cmac hmac curl attr kernel-pfkey kernel-pfroute resolve socket-default stroke vici updown eap-identity eap-sim eap-md5 eap-mschapv2 eap-dynamic eap-radius eap-tls eap-ttls eap-peap xauth-generic xauth-eap whitelist addrblock counters
Listening IP addresses:
203.0.113.121
192.168.14.1
172.16.14.1
Connections:
con4000: 203.0.113.121...198.51.100.49 IKEv1, dpddelay=10s
con4000: local: [203.0.113.121] uses pre-shared key authentication
con4000: remote: [198.51.100.49] uses pre-shared key authentication
con4000: child: 192.168.14.0/24|/0 === 192.168.16.0/24|/0 TUNNEL, dpdaction=restart
Routed Connections:
con4000{552}: ROUTED, TUNNEL, reqid 1
con4000{552}: 192.168.14.0/24|/0 === 192.168.16.0/24|/0
Security Associations (3 up, 0 connecting):
con4000[55]: ESTABLISHED 4 hours ago, 203.0.113.121[203.0.113.121]...198.51.100.49[198.51.100.49]
con4000[55]: IKEv1 SPIs: 6dd2d30fcec4ee45_i* 0007aac07d503b24_r, pre-shared key reauthentication in 2 hours
con4000[55]: IKE proposal: AES_CBC_256/HMAC_SHA2_256_128/PRF_HMAC_SHA2_256/MODP_1024
con4000[55]: Tasks queued: INFORMATIONAL
con4000[55]: Tasks active: QUICK_MODE

This side:

conn con4000
fragmentation = yes
keyexchange = ikev1
reauth = yes
forceencaps = no
mobike = no

rekey = yes
installpolicy = yes
type = tunnel
dpdaction = restart
dpddelay = 10s
dpdtimeout = 60s
auto = route
left = 203.0.113.121
right = 198.51.100.49
leftid = 203.0.113.121
ikelifetime = 28800s
lifetime = 3600s
ike = aes256-sha256-modp1024!
esp = aes256-sha256-modp2048!
leftauth = psk
rightauth = psk
rightid = 198.51.100.49
aggressive = no
rightsubnet = 192.168.16.0/24
leftsubnet = 192.168.14.0/24

Other Side:

conn con1000
fragmentation = yes
keyexchange = ikev1
reauth = yes
forceencaps = no
mobike = no

rekey = yes
installpolicy = yes
type = tunnel
dpdaction = restart
dpddelay = 10s
dpdtimeout = 60s
auto = route
left = 198.51.100.49
right = 203.0.113.121
leftid = 198.51.100.49
ikelifetime = 28800s
lifetime = 3600s
ike = aes256-sha256-modp1024!
esp = aes256-sha256-modp2048!
leftauth = psk
rightauth = psk
rightid = 203.0.113.121
aggressive = no
rightsubnet = 192.168.14.0/24
leftsubnet = 192.168.16.0/24

[Tobias Brunner]

Hi Chris,

Post by Chris Linstruth
Oct 30 18:06:43 pfSense_2.4.4 charon: 06[NET] <con4000|55> received packet: from 198.51.100.49[500] to 203.0.113.121[500] (460 bytes)
Oct 30 18:06:43 pfSense_2.4.4 charon: 06[ENC] <con4000|55> parsed QUICK_MODE request 3072107701 [ HASH SA No KE ID ID ]
Oct 30 18:06:43 pfSense_2.4.4 charon: 06[CFG] <con4000|55> looking for a child config for 192.168.14.0/24|/0 === 192.168.16.0/24|/0
Oct 30 18:06:43 pfSense_2.4.4 charon: 06[IKE] <con4000|55> no matching CHILD_SA config found
Oct 30 18:06:43 pfSense_2.4.4 charon: 06[IKE] <con4000|55> queueing INFORMATIONAL task
Oct 30 18:06:43 pfSense_2.4.4 charon: 06[IKE] <con4000|55> activating new tasks
Oct 30 18:06:43 pfSense_2.4.4 charon: 06[IKE] <con4000|55> activating INFORMATIONAL task
Oct 30 18:06:43 pfSense_2.4.4 charon: 06[ENC] <con4000|55> generating INFORMATIONAL_V1 request 3147423319 [ HASH N(INVAL_ID) ]
Oct 30 18:06:43 pfSense_2.4.4 charon: 06[NET] <con4000|55> sending packet: from 203.0.113.121[500] to 198.51.100.49[500] (92 bytes)
Oct 30 18:06:43 pfSense_2.4.4 charon: 06[IKE] <con4000|55> activating new tasks
Oct 30 18:06:43 pfSense_2.4.4 charon: 06[IKE] <con4000|55> nothing to initiate

Not necessarily. The peer_cfg_t object referenced by the active IKE_SA
might not contain the required child_cfg_t object anymore.

This can happen if the `ipsec reload` command is used while the IKE_SA
was already established. This command first removes and then re-adds
all configs defined in ipsec.conf. So first all child_cfg_t objects
with a specific name are deleted from all (globally shared) peer_cfg_t
objects. Which means the object that the established IKE_SA references
won't have any child_cfg_t objects in it anymore. Then a new peer_cfg_t
object is added (because the stroke plugin removed the old one from its
list after removing all the associated child_cfg_t objects), while the
active IKE_SA continues to have a reference to the object. So the
connection listed in the statusall output (under Connections) might
refer to a different object albeit with the same name. However, that's
not relevant to the IKE_SA, which only operates on it's current
peer_cfg_t object (see #129 [1] for the very old ticket that describes
this).

The vici/swanctl configuration backend avoids this issue by replacing
the child_cfg_t objects in existing peer_cfg_t objects atomically with
those of the new config and not touching child_cfg_t objects in replaced
peer_cfg_t objects. The deprecated stroke plugin doesn't do that
because of the limited interface between the starter daemon and the
plugin. But if the config of the active connection (or %default) has
not changed, this problem can be avoided by using `ipsec update` to
reload the config as that only affects modified configs.

Regards,
Tobias

[1] https://wiki.strongswan.org/issues/129