On Mon, Aug 14, 2023 at 02:07:12AM +0000, Jason Tubnor wrote: > Hi, > > Testing sec(4) between 2 end points with iperf3, iked has lost the associated > iface for the sec(4) point to point link. Specifically: > > pfkey_sa: unsupported interface
Not sure how this can happen. Have you destroyed and recreated the interface in between? Can you easily reproduce this? I have added a bit more info to the error message, it now also prints the iface id and the errno. It would be useful if you can reproduce it with those. > > Here is the surround log for the event: > > Aug 14 11:30:54 terminator iked[93171]: spi=0x635987a83a22a13e: recv > CREATE_CHILD_SA req 3 peer 4.4.4.2:64893 local 4.4.4.1:4500, 305 bytes, > policy 'policy1' > Aug 14 11:30:54 terminator iked[93171]: spi=0x635987a83a22a13e: send > CREATE_CHILD_SA res 3 peer 4.4.4.2:64893 local 4.4.4.1:4500, 177 bytes, NAT-T > Aug 14 11:30:54 terminator iked[93171]: pfkey_sa: unsupported interface > Aug 14 11:30:54 terminator iked[93171]: spi=0x635987a83a22a13e: > ikev2_log_proposal: ESP #1 ENCR=AES_GCM_16-128 > Aug 14 11:30:54 terminator iked[93171]: spi=0x635987a83a22a13e: > ikev2_log_proposal: ESP #1 ENCR=AES_GCM_16-256 > Aug 14 11:30:54 terminator iked[93171]: spi=0x635987a83a22a13e: > ikev2_log_proposal: ESP #1 ESN=ESN > Aug 14 11:30:54 terminator iked[93171]: spi=0x635987a83a22a13e: > ikev2_log_proposal: ESP #1 ESN=NONE > Aug 14 11:30:54 terminator iked[93171]: spi=0x635987a83a22a13e: > ikev2_log_proposal: ESP #2 ENCR=AES_CBC-256 > Aug 14 11:30:54 terminator iked[93171]: spi=0x635987a83a22a13e: > ikev2_log_proposal: ESP #2 ENCR=AES_CBC-192 > Aug 14 11:30:54 terminator iked[93171]: spi=0x635987a83a22a13e: > ikev2_log_proposal: ESP #2 ENCR=AES_CBC-128 > Aug 14 11:30:54 terminator iked[93171]: spi=0x635987a83a22a13e: > ikev2_log_proposal: ESP #2 INTEGR=HMAC_SHA2_256_128 > Aug 14 11:30:54 terminator iked[93171]: spi=0x635987a83a22a13e: > ikev2_log_proposal: ESP #2 INTEGR=HMAC_SHA2_384_192 > Aug 14 11:30:54 terminator iked[93171]: spi=0x635987a83a22a13e: > ikev2_log_proposal: ESP #2 INTEGR=HMAC_SHA2_512_256 > Aug 14 11:30:54 terminator iked[93171]: spi=0x635987a83a22a13e: > ikev2_log_proposal: ESP #2 INTEGR=HMAC_SHA1_96 > Aug 14 11:30:54 terminator iked[93171]: spi=0x635987a83a22a13e: > ikev2_log_proposal: ESP #2 ESN=ESN > Aug 14 11:30:54 terminator iked[93171]: spi=0x635987a83a22a13e: > ikev2_log_proposal: ESP #2 ESN=NONE > Aug 14 11:30:54 terminator iked[93171]: spi=0x635987a83a22a13e: > ikev2_add_error: NO_PROPOSAL_CHOSEN > Aug 14 11:30:54 terminator iked[93171]: spi=0x635987a83a22a13e: send > CREATE_CHILD_SA res 3 peer 4.4.4.2:64893 local 4.4.4.1:4500, 65 bytes, NAT-T > Aug 14 11:30:54 terminator iked[93171]: spi=0x635987a83a22a13e: deleted 1 > SPI: 0x37249f77 > Aug 14 11:33:04 terminator iked[93171]: spi=0xffb183f53eae6546: recv > IKE_SA_INIT req 0 peer 4.4.4.2:60926 local 4.4.4.1:500, 518 bytes, policy > 'policy2' > Aug 14 11:33:04 terminator iked[93171]: spi=0xffb183f53eae6546: send > IKE_SA_INIT res 0 peer 4.4.4.2:60926 local 4.4.4.1:500, 235 bytes > Aug 14 11:33:04 terminator iked[93171]: spi=0xffb183f53eae6546: recv IKE_AUTH > req 1 peer 4.4.4.2:64893 local 4.4.4.1:4500, 475 bytes, policy 'policy2' > Aug 14 11:33:04 terminator iked[93171]: spi=0xffb183f53eae6546: send IKE_AUTH > res 1 peer 4.4.4.2:64893 local 4.4.4.1:4500, 341 bytes, NAT-T > Aug 14 11:33:04 terminator iked[93171]: pfkey_sa: unsupported interface > Aug 14 11:35:43 terminator iked[93171]: spi=0xffb183f53eae6546: sa_free: > reload > Aug 14 11:37:45 terminator iked[93171]: spi=0x635987a83a22a13e: retransmit 1 > INFORMATIONAL req 6 peer 4.4.4.2:64893 local 4.4.4.1:4500 > Aug 14 11:37:49 terminator iked[93171]: spi=0x635987a83a22a13e: retransmit 2 > INFORMATIONAL req 6 peer 4.4.4.2:64893 local 4.4.4.1:4500 > Aug 14 11:37:57 terminator iked[93171]: spi=0x635987a83a22a13e: retransmit 3 > INFORMATIONAL req 6 peer 4.4.4.2:64893 local 4.4.4.1:4500 > Aug 14 11:38:13 terminator iked[93171]: spi=0x635987a83a22a13e: retransmit 4 > INFORMATIONAL req 6 peer 4.4.4.2:64893 local 4.4.4.1:4500 > Aug 14 11:38:45 terminator iked[93171]: spi=0x635987a83a22a13e: retransmit 5 > INFORMATIONAL req 6 peer 4.4.4.2:64893 local 4.4.4.1:4500 > Aug 14 11:39:04 terminator iked[93171]: spi=0x8e5dc9e7e8a397e0: recv > IKE_SA_INIT req 0 peer 4.4.4.2:63301 local 4.4.4.1:500, 518 bytes, policy > 'policy6' > Aug 14 11:39:04 terminator iked[93171]: spi=0x8e5dc9e7e8a397e0: send > IKE_SA_INIT res 0 peer 4.4.4.2:63301 local 4.4.4.1:500, 235 bytes > Aug 14 11:39:04 terminator iked[93171]: spi=0x8e5dc9e7e8a397e0: recv IKE_AUTH > req 1 peer 4.4.4.2:64893 local 4.4.4.1:4500, 473 bytes, policy 'policy6' > Aug 14 11:39:04 terminator iked[93171]: spi=0x8e5dc9e7e8a397e0: send IKE_AUTH > res 1 peer 4.4.4.2:64893 local 4.4.4.1:4500, 342 bytes, NAT-T > Aug 14 11:39:04 terminator iked[93171]: spi=0x8e5dc9e7e8a397e0: > ikev2_childsa_enable: loaded SPIs: 0xbd533d62, 0xf7d5e5fd (enc aes-128-gcm > esn) > Aug 14 11:39:04 terminator iked[93171]: spi=0x8e5dc9e7e8a397e0: established > peer 4.4.4.2:64893[IPV4/10.56.0.0] local 4.4.4.1:4500[IPV4/4.4.4.1] policy > 'policy5' as responder (enc aes-128-gcm group curve25519 prf hmac-sha2-256) > Aug 14 11:39:49 terminator iked[93171]: spi=0x635987a83a22a13e: sa_free: > retransmit limit reached > > To fix the connection and bring it back online the following had to be > performed (sec30 was the interface for context): > > ifconfig sec30 destroy > ifconfig sec30 create 10.56.2.254/24 10.56.2.1 mtu 1438 up > ikectl reload > > The tunnel from the active peer is eventually negotiated and the connection > resumes. > > /etc/iked.conf: > > ikev2 passive from 4.4.4.1 to 10.56.0.0 peer any srcid 4.4.4.1 dstid > 10.56.0.0 iface sec30 > ikev2 passive from 4.4.4.1 to 10.56.0.1 peer any srcid 4.4.4.1 dstid > 10.56.0.1 iface sec31 > > Happy to provide anything else that might be necessary. > > Thanks, Jason.
