Project

General

Profile

Issue #3551

Strongswan tasks queue fills up

Added by Mike C 2 months ago. Updated 23 days ago.

Status:
Closed
Priority:
Normal
Category:
configuration
Affected version:
5.8.0
Resolution:
No change required

Description

Hi,

I have a server with strongswan that has an issue to a particular endpoint where sometimes the rekey fails, and subsequent attempts to re-initiate the connection fail. The attempts end up showing as a backlog in the 'ipsec statusall' command. Below is the output, with the 'vpn3*' tunnels being the problem. The other tunnels to different endpoints are working fine.

The tasks queue never seems to be actioned for this tunnel. I had a script that watches for down'd tunnels (i.e. sometimes DPD isn't enough/won't help a connection come back because the other end has issued a delete ike), and it basically does:

ipsec stroke down-nb <vpn>
ipsec stroke up-nb <vpn>

Which normally works perfectly. But at this site the tasks all seem to get stuck in the queue. Sometimes the first item in the queue is CHILD_REKEY, others its CHILD_CREATE such as this example. The only way I can fix this is doing an ipsec restart for strongswan entirely, which isn't ideal as it takes down other tunnels. I've also tried 'ipsec stroke delete <vpn>' but that also fails to delete and the tasks queued just keeps growing.

My issue is this: How can I delete a tunnel in this state without resorting to restarting ipsec entirely? Or, is there a way to simply just clear its task queue? (so the next call to up-nb will hopefully just work and not be stuck waiting in the queue)

Status of IKE charon daemon (strongSwan 5.8.0, Linux 4.14.131, x86_64):
uptime: 34 hours, since Aug 23 20:33:11 2020
malloc: sbrk 2588672, mmap 0, used 1493440, free 1095232
worker threads: 11 of 16 idle, 5/0/0/0 working, job queue: 0/0/0/0, scheduled: 11
loaded plugins: charon aes des rc2 sha2 sha1 md5 random nonce x509 revocation constraints pubkey pkcs1 pgp dnskey sshkey pem openssl af-alg fips-prf gmp curve25519 xcbc hmac ctr gcm attr kernel-netlink resolve
socket-default connmark stroke vici updown xauth-generic unity
Listening IP addresses:
10.b.b.b
35.x.x.x
10.a.a.a
Connections:
vpn1: 35.x.x.x...86.y.y.y IKEv2
vpn1: local: [35.x.x.x] uses pre-shared key authentication
vpn1: remote: [86.y.y.y] uses pre-shared key authentication
vpn1: child: 10.18.0.3/32 === 172.18.1.0/24 TUNNEL
vpn2: 35.x.x.x...66.b.b.b IKEv2, dpddelay=30s
vpn2: local: [35.x.x.x] uses pre-shared key authentication
vpn2: remote: [192.168.2.3] uses pre-shared key authentication
vpn2: child: 10.230.0.0/15 === 172.31.1.0/29 TUNNEL, dpdaction=restart
vpn3a: 35.x.x.x...192.168.38.100 IKEv2, dpddelay=30s
vpn3a: local: [35.x.x.x] uses pre-shared key authentication
vpn3a: remote: [192.168.38.100] uses pre-shared key authentication
vpn3a: child: 10.0.0.32/29 === 192.168.44.0/23 TUNNEL, dpdaction=restart
vpn3b: child: 10.0.0.32/29 === 192.168.46.0/23 TUNNEL, dpdaction=restart
vpn3c: child: 10.0.0.32/29 === 172.16.23.0/24 TUNNEL, dpdaction=restart
vpn3d: child: 10.0.0.32/29 === 172.16.24.0/24 TUNNEL, dpdaction=restart
vpn3e: child: 10.0.0.32/29 === 172.16.25.0/24 TUNNEL, dpdaction=restart
vpn3f: child: 10.0.0.32/29 === 172.16.26.0/24 TUNNEL, dpdaction=restart
Security Associations (2 up, 0 connecting):
vpn224: ESTABLISHED 5 minutes ago, 35.x.x.x[35.x.x.x]...66.b.b.b[192.168.2.3]
vpn224: IKEv2 SPIs: b19f067790fac3b3_i* f55921a37e3712ce_r, pre-shared key reauthentication in 7 hours
vpn224: IKE proposal: AES_CBC_256/HMAC_SHA2_256_128/PRF_HMAC_SHA2_256/MODP_2048
vpn2{395}: INSTALLED, TUNNEL, reqid 62, ESP SPIs: c2eba2b2_i 30149d11_o
vpn2{395}: AES_CBC_256/HMAC_SHA2_256_128, 0 bytes_i, 0 bytes_o, rekeying in 3 hours
vpn2{395}: 10.230.0.0/15 === 172.31.1.0/29
vpn3a19: ESTABLISHED 8 hours ago, 35.x.x.x[35.x.x.x]...192.168.38.100[192.168.38.100]
vpn3a19: IKEv2 SPIs: f2c5087e5b68b85a_i* c349d007a8276a45_r, pre-shared key reauthentication in 4 hours
vpn3a19: IKE proposal: AES_CBC_128/HMAC_SHA2_256_128/PRF_HMAC_SHA2_256/ECP_256
vpn3a19: Tasks queued: CHILD_CREATE CHILD_REKEY IKE_DPD CHILD_CREATE IKE_DPD IKE_DPD CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE
DPD CHILD_CREATE CHILD_DELETE CHILD_DELETE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD CHILD
_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD CHILD_CREATE IKE_DPD IKE_DPD CHIL
D_REKEY IKE_DPD IKE_DPD IKE_DPD IKE_DPD CHILD_CREATE IKE_DPD IKE_DPD CHILD_REKEY CHILD_REKEY CHILD_REKEY IKE_DPD IKE_DPD CHILD_REKEY CHILD_REKEY IKE_DPD CHILD_REKEY IKE_DPD CHILD_CREATE IKE_DPD CHILD_REKEY IKE_D
PD CHILD_REKEY CHILD_REKEY IKE_DPD CHILD_REKEY CHILD_REKEY IKE_DPD CHILD_REKEY CHILD_REKEY IKE_DPD IKE_DPD CHILD_REKEY CHILD_CREATE IKE_DPD CHILD_REKEY IKE_DPD IKE_DPD CHILD_REKEY CHILD_REKEY IKE_DPD IKE_DPD CHI
LD_REKEY IKE_DPD CHILD_CREATE CHILD_REKEY IKE_DPD IKE_DPD IKE_DPD IKE_DPD CHILD_REKEY IKE_DPD CHILD_REKEY IKE_DPD CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD
IKE_DPD CHILD_DELETE CHILD_DELETE CHILD_DELETE CHILD_DELETE IKE_DPD CHILD_CREATE IKE_DPD CHILD_DELETE CHILD_DELETE CHILD_DELETE CHILD_DELETE CHILD_DELETE CHILD_DELETE IKE_DPD IKE_DPD IKE_DPD CHILD_DELETE CHILD

DELETE IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_DELETE CHILD_DELETE IKE_DPD IKE_DPD IKE_DPD CHILD_DELETE CHILD_DELETE CHILD_DELETE CHILD_DELETE CHILD_DELETE CHILD_DELETE IKE_D
PD CHILD_DELETE CHILD_DELETE IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHI
LD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE
DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE C
HILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHI
LD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE
IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE C
HILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IK
E_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE
CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_D
PD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREA
TE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD
IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CR
EATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE
_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD

CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DE
LETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHIL
D_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_
CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_REAUTH IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHIL
D_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_
CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IK
E_DPD IKE_DELETE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_
CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IK
E_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHIL
D_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_D
PD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CH
ILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD
IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE
CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE
DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREAT
E CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DP
D IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CRE
ATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELET
E CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_C
REATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CRE
ATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_D
PD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_C
REATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD
IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD
_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE
_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHI
LD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE IKE_DPD CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DP
D IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD

CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD I
KE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHIL
D_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_
DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CH
ILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHIL
D_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE
IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CH
ILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE
DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE
CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DP
D IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREAT
E CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD I
KE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CRE
ATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE

DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_C
REATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DEL
ETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD
CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_C
REATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE
_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD
_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DP
D IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHI
LD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD I
KE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE C
HILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE

DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE
CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD
IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREA
TE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE
CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CR
EATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREA
TE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DP
D IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CR
EATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD I
KE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_
CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_
DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHIL
D_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DELETE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE CHILD_CREATE IKE_DPD IKE_DPD IKE_DPD IKE_DPD IKE_DPD

History

#1 Updated by Tobias Brunner 2 months ago

  • Status changed from New to Feedback

The tasks queue never seems to be actioned for this tunnel.

Why is that? What does the log say? Are any exchanges done? Or do they fail and the SA is recreated (which will migrate some of the queued tasks)?

ipsec stroke down-nb <vpn>
ipsec stroke up-nb <vpn>

That's not such a good idea because if there already is an IKE_SA this will just queue the creation of another instance of the CHILD_SA i.e. queue a CHILD_CREATE task (basically results in what you see in the status output).

ipsec stroke down-nb does a regular deletion (i.e. queues a delete task, depending on the syntax one for the IKE or the CHILD_SA), so that might just add to the problem.

But at this site the tasks all seem to get stuck in the queue. Sometimes the first item in the queue is CHILD_REKEY, others its CHILD_CREATE such as this example.

Again, read the logs to see what's going on.

I've also tried 'ipsec stroke delete <vpn>' but that also fails to delete and the tasks queued just keeps growing.

That only removes the config, it has no effect on existing SAs (up should fail though if the config isn't available anymore).

How can I delete a tunnel in this state without resorting to restarting ipsec entirely?

With swanctl's --terminate command you have more options (e.g. allows forcing the deletion of an IKE_SA without sending a delete).

Or, is there a way to simply just clear its task queue?

No, there is currently no public API for this. So you better make sure this doesn't happen in the first place.

Have you considered using trap policies (auto=route) so SAs are automatically (re-)created if matching traffic hits those policies? Also note that, depending on the peer implementation, you won't have to create separate CHILD_SAs for multiple remote subnets.

#2 Updated by Mike C 2 months ago

Tobias Brunner wrote:

The tasks queue never seems to be actioned for this tunnel.

Why is that? What does the log say? Are any exchanges done? Or do they fail and the SA is recreated (which will migrate some of the queued tasks)?

I've looked through some logs I have, not the exact same incident as the previous ipsec statusall, but the same outcome (lots of tasks, tunnel never comes back up).

2020-08-21T07:03:39+0000 ipsec 14[KNL] creating rekey job for CHILD_SA ESP/0x5b248dc3/86.y.y.y
2020-08-21T07:03:39+0000 ipsec 14[CFG] <vpn3a|321> proposing traffic selectors for us:
2020-08-21T07:03:39+0000 ipsec 14[CFG] <vpn3a|321>  10.0.0.32/29
2020-08-21T07:03:39+0000 ipsec 14[CFG] <vpn3a|321> proposing traffic selectors for other:
2020-08-21T07:03:39+0000 ipsec 14[CFG] <vpn3a|321>  172.16.23.0/24
2020-08-21T07:03:39+0000 ipsec 14[CFG] <vpn3a|321> configured proposals: ESP:AES_CBC_128/HMAC_SHA2_256_128/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_128/AES_CBC_192/AES_CBC_256/HMAC_SHA2_256_128/HMAC_SHA2_384_192/HMAC_SHA2_512_256/HMAC_SHA1_96/AES_XCBC_96/NO_EXT_SEQ
2020-08-21T07:03:39+0000 ipsec 14[IKE] <vpn3a|321> establishing CHILD_SA vpn3c{188} reqid 30
2020-08-21T07:03:39+0000 ipsec 14[ENC] <vpn3a|321> generating CREATE_CHILD_SA request 25 [ N(REKEY_SA) SA No KE TSi TSr ]
2020-08-21T07:03:39+0000 ipsec 14[NET] <vpn3a|321> sending packet: from 35.x.x.x[4500] to 86.y.y.y[4500] (384 bytes)
2020-08-21T07:03:39+0000 ipsec 13[NET] <vpn3a|321> received packet: from 86.y.y.y[4500] to 35.x.x.x[4500] (288 bytes)
2020-08-21T07:03:39+0000 ipsec 13[ENC] <vpn3a|321> parsed CREATE_CHILD_SA response 25 [ SA No KE TSi TSr N(ESP_TFC_PAD_N) N(NON_FIRST_FRAG) ]
2020-08-21T07:03:39+0000 ipsec 13[IKE] <vpn3a|321> received ESP_TFC_PADDING_NOT_SUPPORTED, not using ESPv3 TFC padding
2020-08-21T07:03:39+0000 ipsec 13[CFG] <vpn3a|321> selecting proposal:
2020-08-21T07:03:39+0000 ipsec 13[CFG] <vpn3a|321>   proposal matches
2020-08-21T07:03:39+0000 ipsec 13[CFG] <vpn3a|321> received proposals: ESP:AES_CBC_128/HMAC_SHA2_256_128/ECP_256/NO_EXT_SEQ
2020-08-21T07:03:39+0000 ipsec 13[CFG] <vpn3a|321> configured proposals: ESP:AES_CBC_128/HMAC_SHA2_256_128/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_128/AES_CBC_192/AES_CBC_256/HMAC_SHA2_256_128/HMAC_SHA2_384_192/HMAC_SHA2_512_256/HMAC_SHA1_96/AES_XCBC_96/NO_EXT_SEQ
2020-08-21T07:03:39+0000 ipsec 13[CFG] <vpn3a|321> selected proposal: ESP:AES_CBC_128/HMAC_SHA2_256_128/ECP_256/NO_EXT_SEQ
2020-08-21T07:03:39+0000 ipsec 13[CFG] <vpn3a|321> selecting traffic selectors for us:
2020-08-21T07:03:39+0000 ipsec 13[CFG] <vpn3a|321>  config: 10.0.0.32/29, received: 10.0.0.32/29 => match: 10.0.0.32/29
2020-08-21T07:03:39+0000 ipsec 13[CFG] <vpn3a|321> selecting traffic selectors for other:
2020-08-21T07:03:39+0000 ipsec 13[CFG] <vpn3a|321>  config: 172.16.23.0/24, received: 172.16.23.0/24 => match: 172.16.23.0/24
2020-08-21T07:03:39+0000 ipsec 13[IKE] <vpn3a|321> inbound CHILD_SA vpn3c{188} established with SPIs cd40f462_i 9ceb0c07_o and TS 10.0.0.32/29 === 172.16.23.0/24
2020-08-21T07:03:39+0000 ipsec 13[IKE] <vpn3a|321> outbound CHILD_SA vpn3c{188} established with SPIs cd40f462_i 9ceb0c07_o and TS 10.0.0.32/29 === 172.16.23.0/24
2020-08-21T07:03:39+0000 ipsec 13[IKE] <vpn3a|321> closing CHILD_SA vpn3c{180} with SPIs c1489365_i (35671 bytes) 5b248dc3_o (40300 bytes) and TS 10.0.0.32/29 === 172.16.23.0/24
2020-08-21T07:03:39+0000 ipsec 13[IKE] <vpn3a|321> sending DELETE for ESP CHILD_SA with SPI c1489365
2020-08-21T07:03:39+0000 ipsec 13[ENC] <vpn3a|321> generating INFORMATIONAL request 26 [ D ]
2020-08-21T07:03:39+0000 ipsec 13[NET] <vpn3a|321> sending packet: from 35.x.x.x[4500] to 86.y.y.y[4500] (80 bytes)
2020-08-21T07:03:39+0000 ipsec 10[NET] <vpn3a|321> received packet: from 86.y.y.y[4500] to 35.x.x.x[4500] (80 bytes)
2020-08-21T07:03:39+0000 ipsec 10[ENC] <vpn3a|321> parsed INFORMATIONAL response 26 [ D ]
2020-08-21T07:03:39+0000 ipsec 10[IKE] <vpn3a|321> received DELETE for ESP CHILD_SA with SPI 5b248dc3
2020-08-21T07:03:39+0000 ipsec 10[IKE] <vpn3a|321> CHILD_SA closed
2020-08-21T07:04:50+0000 ipsec 10[KNL] creating rekey job for CHILD_SA ESP/0xc70e4d36/35.x.x.x
2020-08-21T07:04:50+0000 ipsec 10[CFG] <vpn3a|321> proposing traffic selectors for us:
2020-08-21T07:04:50+0000 ipsec 10[CFG] <vpn3a|321>  10.0.0.32/29
2020-08-21T07:04:50+0000 ipsec 10[CFG] <vpn3a|321> proposing traffic selectors for other:
2020-08-21T07:04:50+0000 ipsec 10[CFG] <vpn3a|321>  172.16.26.0/24
2020-08-21T07:04:50+0000 ipsec 10[CFG] <vpn3a|321> configured proposals: ESP:AES_CBC_128/HMAC_SHA2_256_128/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_128/AES_CBC_192/AES_CBC_256/HMAC_SHA2_256_128/HMAC_SHA2_384_192/HMAC_SHA2_512_256/HMAC_SHA1_96/AES_XCBC_96/NO_EXT_SEQ
2020-08-21T07:04:50+0000 ipsec 10[IKE] <vpn3a|321> establishing CHILD_SA vpn3f{189} reqid 34
2020-08-21T07:04:50+0000 ipsec 10[ENC] <vpn3a|321> generating CREATE_CHILD_SA request 27 [ N(REKEY_SA) SA No KE TSi TSr ]
2020-08-21T07:04:50+0000 ipsec 10[NET] <vpn3a|321> sending packet: from 35.x.x.x[4500] to 86.y.y.y[4500] (384 bytes)
2020-08-21T07:04:50+0000 ipsec 15[NET] <vpn3a|321> received packet: from 86.y.y.y[4500] to 35.x.x.x[4500] (288 bytes)
2020-08-21T07:04:50+0000 ipsec 15[ENC] <vpn3a|321> parsed CREATE_CHILD_SA response 27 [ SA No KE TSi TSr N(ESP_TFC_PAD_N) N(NON_FIRST_FRAG) ]
2020-08-21T07:04:50+0000 ipsec 15[IKE] <vpn3a|321> received ESP_TFC_PADDING_NOT_SUPPORTED, not using ESPv3 TFC padding
2020-08-21T07:04:50+0000 ipsec 15[CFG] <vpn3a|321> selecting proposal:
2020-08-21T07:04:50+0000 ipsec 15[CFG] <vpn3a|321>   proposal matches
2020-08-21T07:04:50+0000 ipsec 15[CFG] <vpn3a|321> received proposals: ESP:AES_CBC_128/HMAC_SHA2_256_128/ECP_256/NO_EXT_SEQ
2020-08-21T07:04:50+0000 ipsec 15[CFG] <vpn3a|321> configured proposals: ESP:AES_CBC_128/HMAC_SHA2_256_128/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_128/AES_CBC_192/AES_CBC_256/HMAC_SHA2_256_128/HMAC_SHA2_384_192/HMAC_SHA2_512_256/HMAC_SHA1_96/AES_XCBC_96/NO_EXT_SEQ
2020-08-21T07:04:50+0000 ipsec 15[CFG] <vpn3a|321> selected proposal: ESP:AES_CBC_128/HMAC_SHA2_256_128/ECP_256/NO_EXT_SEQ
2020-08-21T07:04:50+0000 ipsec 15[CFG] <vpn3a|321> selecting traffic selectors for us:
2020-08-21T07:04:50+0000 ipsec 15[CFG] <vpn3a|321>  config: 10.0.0.32/29, received: 10.0.0.32/29 => match: 10.0.0.32/29
2020-08-21T07:04:50+0000 ipsec 15[CFG] <vpn3a|321> selecting traffic selectors for other:
2020-08-21T07:04:50+0000 ipsec 15[CFG] <vpn3a|321>  config: 172.16.26.0/24, received: 172.16.26.0/24 => match: 172.16.26.0/24
2020-08-21T07:04:50+0000 ipsec 15[IKE] <vpn3a|321> inbound CHILD_SA vpn3f{189} established with SPIs c400ec51_i d395d80a_o and TS 10.0.0.32/29 === 172.16.26.0/24
2020-08-21T07:04:50+0000 ipsec 15[IKE] <vpn3a|321> outbound CHILD_SA vpn3f{189} established with SPIs c400ec51_i d395d80a_o and TS 10.0.0.32/29 === 172.16.26.0/24
2020-08-21T07:04:50+0000 ipsec 15[IKE] <vpn3a|321> closing CHILD_SA vpn3f{179} with SPIs c70e4d36_i (0 bytes) 9b72d187_o (0 bytes) and TS 10.0.0.32/29 === 172.16.26.0/24
2020-08-21T07:04:50+0000 ipsec 15[IKE] <vpn3a|321> sending DELETE for ESP CHILD_SA with SPI c70e4d36
2020-08-21T07:04:50+0000 ipsec 15[ENC] <vpn3a|321> generating INFORMATIONAL request 28 [ D ]
2020-08-21T07:04:50+0000 ipsec 15[NET] <vpn3a|321> sending packet: from 35.x.x.x[4500] to 86.y.y.y[4500] (80 bytes)
2020-08-21T07:04:50+0000 ipsec 05[NET] <vpn3a|321> received packet: from 86.y.y.y[4500] to 35.x.x.x[4500] (80 bytes)
2020-08-21T07:04:50+0000 ipsec 05[ENC] <vpn3a|321> parsed INFORMATIONAL response 28 [ D ]
2020-08-21T07:04:50+0000 ipsec 05[IKE] <vpn3a|321> received DELETE for ESP CHILD_SA with SPI 9b72d187
2020-08-21T07:04:50+0000 ipsec 05[IKE] <vpn3a|321> CHILD_SA closed
2020-08-21T07:05:17+0000 ipsec 13[KNL] creating rekey job for CHILD_SA ESP/0xcfcbeab8/35.x.x.x
2020-08-21T07:05:17+0000 ipsec 13[CFG] <vpn3a|321> proposing traffic selectors for us:
2020-08-21T07:05:17+0000 ipsec 13[CFG] <vpn3a|321>  10.0.0.32/29
2020-08-21T07:05:17+0000 ipsec 13[CFG] <vpn3a|321> proposing traffic selectors for other:
2020-08-21T07:05:17+0000 ipsec 13[CFG] <vpn3a|321>  172.16.24.0/24
2020-08-21T07:05:17+0000 ipsec 13[CFG] <vpn3a|321> configured proposals: ESP:AES_CBC_128/HMAC_SHA2_256_128/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_128/AES_CBC_192/AES_CBC_256/HMAC_SHA2_256_128/HMAC_SHA2_384_192/HMAC_SHA2_512_256/HMAC_SHA1_96/AES_XCBC_96/NO_EXT_SEQ
2020-08-21T07:05:17+0000 ipsec 13[IKE] <vpn3a|321> establishing CHILD_SA vpn3d{190} reqid 32
2020-08-21T07:05:17+0000 ipsec 13[ENC] <vpn3a|321> generating CREATE_CHILD_SA request 29 [ N(REKEY_SA) SA No KE TSi TSr ]
2020-08-21T07:05:17+0000 ipsec 13[NET] <vpn3a|321> sending packet: from 35.x.x.x[4500] to 86.y.y.y[4500] (384 bytes)
2020-08-21T07:05:17+0000 ipsec 08[NET] <vpn3a|321> received packet: from 86.y.y.y[4500] to 35.x.x.x[4500] (288 bytes)
2020-08-21T07:05:17+0000 ipsec 08[ENC] <vpn3a|321> parsed CREATE_CHILD_SA response 29 [ SA No KE TSi TSr N(ESP_TFC_PAD_N) N(NON_FIRST_FRAG) ]
2020-08-21T07:05:17+0000 ipsec 08[IKE] <vpn3a|321> received ESP_TFC_PADDING_NOT_SUPPORTED, not using ESPv3 TFC padding
2020-08-21T07:05:17+0000 ipsec 08[CFG] <vpn3a|321> selecting proposal:
2020-08-21T07:05:17+0000 ipsec 08[CFG] <vpn3a|321>   proposal matches
2020-08-21T07:05:17+0000 ipsec 08[CFG] <vpn3a|321> received proposals: ESP:AES_CBC_128/HMAC_SHA2_256_128/ECP_256/NO_EXT_SEQ
2020-08-21T07:05:17+0000 ipsec 08[CFG] <vpn3a|321> configured proposals: ESP:AES_CBC_128/HMAC_SHA2_256_128/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_128/AES_CBC_192/AES_CBC_256/HMAC_SHA2_256_128/HMAC_SHA2_384_192/HMAC_SHA2_512_256/HMAC_SHA1_96/AES_XCBC_96/NO_EXT_SEQ
2020-08-21T07:05:17+0000 ipsec 08[CFG] <vpn3a|321> selected proposal: ESP:AES_CBC_128/HMAC_SHA2_256_128/ECP_256/NO_EXT_SEQ
2020-08-21T07:05:17+0000 ipsec 08[CFG] <vpn3a|321> selecting traffic selectors for us:
2020-08-21T07:05:17+0000 ipsec 08[CFG] <vpn3a|321>  config: 10.0.0.32/29, received: 10.0.0.32/29 => match: 10.0.0.32/29
2020-08-21T07:05:17+0000 ipsec 08[CFG] <vpn3a|321> selecting traffic selectors for other:
2020-08-21T07:05:17+0000 ipsec 08[CFG] <vpn3a|321>  config: 172.16.24.0/24, received: 172.16.24.0/24 => match: 172.16.24.0/24
2020-08-21T07:05:17+0000 ipsec 08[IKE] <vpn3a|321> inbound CHILD_SA vpn3d{190} established with SPIs cb29c3ec_i 111f1c84_o and TS 10.0.0.32/29 === 172.16.24.0/24
2020-08-21T07:05:17+0000 ipsec 08[IKE] <vpn3a|321> outbound CHILD_SA vpn3d{190} established with SPIs cb29c3ec_i 111f1c84_o and TS 10.0.0.32/29 === 172.16.24.0/24
2020-08-21T07:05:17+0000 ipsec 08[IKE] <vpn3a|321> closing CHILD_SA vpn3d{182} with SPIs cfcbeab8_i (0 bytes) b56027b6_o (0 bytes) and TS 10.0.0.32/29 === 172.16.24.0/24
2020-08-21T07:05:17+0000 ipsec 08[IKE] <vpn3a|321> sending DELETE for ESP CHILD_SA with SPI cfcbeab8
2020-08-21T07:05:17+0000 ipsec 08[ENC] <vpn3a|321> generating INFORMATIONAL request 30 [ D ]
2020-08-21T07:05:17+0000 ipsec 08[NET] <vpn3a|321> sending packet: from 35.x.x.x[4500] to 86.y.y.y[4500] (80 bytes)
2020-08-21T07:05:17+0000 ipsec 07[KNL] creating rekey job for CHILD_SA ESP/0xf25cff17/86.y.y.y
2020-08-21T07:05:17+0000 ipsec 06[NET] <vpn3a|321> received packet: from 86.y.y.y[4500] to 35.x.x.x[4500] (80 bytes)
2020-08-21T07:05:17+0000 ipsec 06[ENC] <vpn3a|321> parsed INFORMATIONAL response 30 [ D ]
2020-08-21T07:05:17+0000 ipsec 06[IKE] <vpn3a|321> received DELETE for ESP CHILD_SA with SPI b56027b6
2020-08-21T07:05:17+0000 ipsec 06[IKE] <vpn3a|321> CHILD_SA closed
2020-08-21T07:05:17+0000 ipsec 06[CFG] <vpn3a|321> proposing traffic selectors for us:
2020-08-21T07:05:17+0000 ipsec 06[CFG] <vpn3a|321>  10.0.0.32/29
2020-08-21T07:05:17+0000 ipsec 06[CFG] <vpn3a|321> proposing traffic selectors for other:
2020-08-21T07:05:17+0000 ipsec 06[CFG] <vpn3a|321>  192.168.44.0/23
2020-08-21T07:05:17+0000 ipsec 06[CFG] <vpn3a|321> configured proposals: ESP:AES_CBC_128/HMAC_SHA2_256_128/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_128/AES_CBC_192/AES_CBC_256/HMAC_SHA2_256_128/HMAC_SHA2_384_192/HMAC_SHA2_512_256/HMAC_SHA1_96/AES_XCBC_96/NO_EXT_SEQ
2020-08-21T07:05:17+0000 ipsec 06[IKE] <vpn3a|321> establishing CHILD_SA vpn3a{191} reqid 33
2020-08-21T07:05:17+0000 ipsec 06[ENC] <vpn3a|321> generating CREATE_CHILD_SA request 31 [ N(REKEY_SA) SA No KE TSi TSr ]
2020-08-21T07:05:17+0000 ipsec 06[NET] <vpn3a|321> sending packet: from 35.x.x.x[4500] to 86.y.y.y[4500] (384 bytes)
2020-08-21T07:05:17+0000 ipsec 11[NET] <vpn3a|321> received packet: from 86.y.y.y[4500] to 35.x.x.x[4500] (288 bytes)
2020-08-21T07:05:17+0000 ipsec 11[ENC] <vpn3a|321> parsed CREATE_CHILD_SA response 31 [ SA No KE TSi TSr N(ESP_TFC_PAD_N) N(NON_FIRST_FRAG) ]
2020-08-21T07:05:17+0000 ipsec 11[IKE] <vpn3a|321> received ESP_TFC_PADDING_NOT_SUPPORTED, not using ESPv3 TFC padding
2020-08-21T07:05:17+0000 ipsec 11[CFG] <vpn3a|321> selecting proposal:
2020-08-21T07:05:17+0000 ipsec 11[CFG] <vpn3a|321>   proposal matches
2020-08-21T07:05:17+0000 ipsec 11[CFG] <vpn3a|321> received proposals: ESP:AES_CBC_128/HMAC_SHA2_256_128/ECP_256/NO_EXT_SEQ
2020-08-21T07:05:17+0000 ipsec 11[CFG] <vpn3a|321> configured proposals: ESP:AES_CBC_128/HMAC_SHA2_256_128/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_128/AES_CBC_192/AES_CBC_256/HMAC_SHA2_256_128/HMAC_SHA2_384_192/HMAC_SHA2_512_256/HMAC_SHA1_96/AES_XCBC_96/NO_EXT_SEQ
2020-08-21T07:05:17+0000 ipsec 11[CFG] <vpn3a|321> selected proposal: ESP:AES_CBC_128/HMAC_SHA2_256_128/ECP_256/NO_EXT_SEQ
2020-08-21T07:05:17+0000 ipsec 11[CFG] <vpn3a|321> selecting traffic selectors for us:
2020-08-21T07:05:17+0000 ipsec 11[CFG] <vpn3a|321>  config: 10.0.0.32/29, received: 10.0.0.32/29 => match: 10.0.0.32/29
2020-08-21T07:05:17+0000 ipsec 11[CFG] <vpn3a|321> selecting traffic selectors for other:
2020-08-21T07:05:17+0000 ipsec 11[CFG] <vpn3a|321>  config: 192.168.44.0/23, received: 192.168.44.0/23 => match: 192.168.44.0/23
2020-08-21T07:05:17+0000 ipsec 11[IKE] <vpn3a|321> inbound CHILD_SA vpn3a{191} established with SPIs c9262137_i 7d9a818b_o and TS 10.0.0.32/29 === 192.168.44.0/23
2020-08-21T07:05:17+0000 ipsec 11[IKE] <vpn3a|321> outbound CHILD_SA vpn3a{191} established with SPIs c9262137_i 7d9a818b_o and TS 10.0.0.32/29 === 192.168.44.0/23
2020-08-21T07:05:17+0000 ipsec 11[IKE] <vpn3a|321> closing CHILD_SA vpn3a{184} with SPIs cb9e1e3f_i (0 bytes) f25cff17_o (0 bytes) and TS 10.0.0.32/29 === 192.168.44.0/23
2020-08-21T07:05:17+0000 ipsec 11[IKE] <vpn3a|321> sending DELETE for ESP CHILD_SA with SPI cb9e1e3f
2020-08-21T07:05:17+0000 ipsec 11[ENC] <vpn3a|321> generating INFORMATIONAL request 32 [ D ]
2020-08-21T07:05:17+0000 ipsec 11[NET] <vpn3a|321> sending packet: from 35.x.x.x[4500] to 86.y.y.y[4500] (80 bytes)
2020-08-21T07:05:17+0000 ipsec 09[NET] <vpn3a|321> received packet: from 86.y.y.y[4500] to 35.x.x.x[4500] (80 bytes)
2020-08-21T07:05:17+0000 ipsec 09[ENC] <vpn3a|321> parsed INFORMATIONAL response 32 [ D ]
2020-08-21T07:05:17+0000 ipsec 09[IKE] <vpn3a|321> received DELETE for ESP CHILD_SA with SPI f25cff17
2020-08-21T07:05:17+0000 ipsec 09[IKE] <vpn3a|321> CHILD_SA closed
2020-08-21T07:05:39+0000 ipsec 13[KNL] creating rekey job for CHILD_SA ESP/0xa0a78933/86.y.y.y
2020-08-21T07:05:39+0000 ipsec 13[CFG] <vpn3a|321> proposing traffic selectors for us:
2020-08-21T07:05:39+0000 ipsec 13[CFG] <vpn3a|321>  10.0.0.32/29
2020-08-21T07:05:39+0000 ipsec 13[CFG] <vpn3a|321> proposing traffic selectors for other:
2020-08-21T07:05:39+0000 ipsec 13[CFG] <vpn3a|321>  192.168.46.0/23
2020-08-21T07:05:39+0000 ipsec 13[CFG] <vpn3a|321> configured proposals: ESP:AES_CBC_128/HMAC_SHA2_256_128/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_128/AES_CBC_192/AES_CBC_256/HMAC_SHA2_256_128/HMAC_SHA2_384_192/HMAC_SHA2_512_256/HMAC_SHA1_96/AES_XCBC_96/NO_EXT_SEQ
2020-08-21T07:05:39+0000 ipsec 13[IKE] <vpn3a|321> establishing CHILD_SA vpn3b{192} reqid 31
2020-08-21T07:05:39+0000 ipsec 13[ENC] <vpn3a|321> generating CREATE_CHILD_SA request 33 [ N(REKEY_SA) SA No KE TSi TSr ]
2020-08-21T07:05:39+0000 ipsec 13[NET] <vpn3a|321> sending packet: from 35.x.x.x[4500] to 86.y.y.y[4500] (384 bytes)
2020-08-21T07:05:39+0000 ipsec 08[NET] <vpn3a|321> received packet: from 86.y.y.y[4500] to 35.x.x.x[4500] (288 bytes)
2020-08-21T07:05:39+0000 ipsec 08[ENC] <vpn3a|321> parsed CREATE_CHILD_SA response 33 [ SA No KE TSi TSr N(ESP_TFC_PAD_N) N(NON_FIRST_FRAG) ]
2020-08-21T07:05:39+0000 ipsec 08[IKE] <vpn3a|321> received ESP_TFC_PADDING_NOT_SUPPORTED, not using ESPv3 TFC padding
2020-08-21T07:05:39+0000 ipsec 08[CFG] <vpn3a|321> selecting proposal:
2020-08-21T07:05:39+0000 ipsec 08[CFG] <vpn3a|321>   proposal matches
2020-08-21T07:05:39+0000 ipsec 08[CFG] <vpn3a|321> received proposals: ESP:AES_CBC_128/HMAC_SHA2_256_128/ECP_256/NO_EXT_SEQ
2020-08-21T07:05:39+0000 ipsec 08[CFG] <vpn3a|321> configured proposals: ESP:AES_CBC_128/HMAC_SHA2_256_128/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_128/AES_CBC_192/AES_CBC_256/HMAC_SHA2_256_128/HMAC_SHA2_384_192/HMAC_SHA2_512_256/HMAC_SHA1_96/AES_XCBC_96/NO_EXT_SEQ
2020-08-21T07:05:39+0000 ipsec 08[CFG] <vpn3a|321> selected proposal: ESP:AES_CBC_128/HMAC_SHA2_256_128/ECP_256/NO_EXT_SEQ
2020-08-21T07:05:39+0000 ipsec 08[CFG] <vpn3a|321> selecting traffic selectors for us:
2020-08-21T07:05:39+0000 ipsec 08[CFG] <vpn3a|321>  config: 10.0.0.32/29, received: 10.0.0.32/29 => match: 10.0.0.32/29
2020-08-21T07:05:39+0000 ipsec 08[CFG] <vpn3a|321> selecting traffic selectors for other:
2020-08-21T07:05:39+0000 ipsec 08[CFG] <vpn3a|321>  config: 192.168.46.0/23, received: 192.168.46.0/23 => match: 192.168.46.0/23
2020-08-21T07:05:39+0000 ipsec 08[IKE] <vpn3a|321> inbound CHILD_SA vpn3b{192} established with SPIs c90a33dd_i 7086f83b_o and TS 10.0.0.32/29 === 192.168.46.0/23
2020-08-21T07:05:39+0000 ipsec 08[IKE] <vpn3a|321> outbound CHILD_SA vpn3b{192} established with SPIs c90a33dd_i 7086f83b_o and TS 10.0.0.32/29 === 192.168.46.0/23
2020-08-21T07:05:39+0000 ipsec 08[IKE] <vpn3a|321> closing CHILD_SA vpn3b{183} with SPIs cccf842c_i (0 bytes) a0a78933_o (0 bytes) and TS 10.0.0.32/29 === 192.168.46.0/23
2020-08-21T07:05:39+0000 ipsec 08[IKE] <vpn3a|321> sending DELETE for ESP CHILD_SA with SPI cccf842c
2020-08-21T07:05:39+0000 ipsec 08[ENC] <vpn3a|321> generating INFORMATIONAL request 34 [ D ]
2020-08-21T07:05:39+0000 ipsec 08[NET] <vpn3a|321> sending packet: from 35.x.x.x[4500] to 86.y.y.y[4500] (80 bytes)
2020-08-21T07:05:39+0000 ipsec 06[NET] <vpn3a|321> received packet: from 86.y.y.y[4500] to 35.x.x.x[4500] (80 bytes)
2020-08-21T07:05:39+0000 ipsec 06[ENC] <vpn3a|321> parsed INFORMATIONAL response 34 [ D ]
2020-08-21T07:05:39+0000 ipsec 06[IKE] <vpn3a|321> received DELETE for ESP CHILD_SA with SPI a0a78933
2020-08-21T07:05:39+0000 ipsec 06[IKE] <vpn3a|321> CHILD_SA closed
2020-08-21T07:05:46+0000 ipsec 07[KNL] creating rekey job for CHILD_SA ESP/0xc0f8651c/35.x.x.x
2020-08-21T07:05:46+0000 ipsec 07[CFG] <vpn3a|321> proposing traffic selectors for us:
2020-08-21T07:05:46+0000 ipsec 07[CFG] <vpn3a|321>  10.0.0.32/29
2020-08-21T07:05:46+0000 ipsec 07[CFG] <vpn3a|321> proposing traffic selectors for other:
2020-08-21T07:05:46+0000 ipsec 07[CFG] <vpn3a|321>  172.16.23.0/24
2020-08-21T07:05:46+0000 ipsec 07[CFG] <vpn3a|321> configured proposals: ESP:AES_CBC_128/HMAC_SHA2_256_128/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_128/AES_CBC_192/AES_CBC_256/HMAC_SHA2_256_128/HMAC_SHA2_384_192/HMAC_SHA2_512_256/HMAC_SHA1_96/AES_XCBC_96/NO_EXT_SEQ
2020-08-21T07:05:46+0000 ipsec 07[IKE] <vpn3a|321> establishing CHILD_SA vpn3c{193} reqid 30
2020-08-21T07:05:46+0000 ipsec 07[ENC] <vpn3a|321> generating CREATE_CHILD_SA request 35 [ N(REKEY_SA) SA No KE TSi TSr ]
*2020-08-21T07:05:46+0000 ipsec 07[ENC] <vpn3a|321> encrypting encrypted payload failed, no IV or padding*
2020-08-21T07:05:46+0000 ipsec Tunnel Down: vpn3c between 35.x.x.x and 86.y.y.y. Network removed: 10.0.0.32/29 and 172.16.23.0/24
2020-08-21T07:05:46+0000 ipsec Tunnel Down: vpn3c between 35.x.x.x and 86.y.y.y. Network removed: 10.0.0.32/29 and 172.16.23.0/24
2020-08-21T07:05:46+0000 ipsec Tunnel Down: vpn3e between 35.x.x.x and 86.y.y.y. Network removed: 10.0.0.32/29 and 172.16.25.0/24
2020-08-21T07:05:46+0000 ipsec Tunnel Down: vpn3c between 35.x.x.x and 86.y.y.y. Network removed: 10.0.0.32/29 and 172.16.23.0/24
2020-08-21T07:05:46+0000 ipsec Tunnel Down: vpn3f between 35.x.x.x and 86.y.y.y. Network removed: 10.0.0.32/29 and 172.16.26.0/24
2020-08-21T07:05:46+0000 ipsec Tunnel Down: vpn3d between 35.x.x.x and 86.y.y.y. Network removed: 10.0.0.32/29 and 172.16.24.0/24
2020-08-21T07:05:46+0000 ipsec Tunnel Down: vpn3a between 35.x.x.x and 86.y.y.y. Network removed: 10.0.0.32/29 and 192.168.44.0/23
2020-08-21T07:05:46+0000 ipsec Tunnel Down: vpn3b between 35.x.x.x and 86.y.y.y. Network removed: 10.0.0.32/29 and 192.168.46.0/23
2020-08-21T07:09:08+0000 ipsec 10[KNL] creating rekey job for CHILD_SA ESP/0xc4855d1c/35.x.x.x
2020-08-21T07:09:20+0000 ipsec 14[KNL] creating rekey job for CHILD_SA ESP/0x0b45c632/86.y.y.y
2020-08-21T07:11:51+0000 ipsec 05[KNL] creating rekey job for CHILD_SA ESP/0xdca12e6b/86.y.y.y
2020-08-21T07:15:28+0000 ipsec 12[KNL] creating rekey job for CHILD_SA ESP/0xc0f52cc3/35.x.x.x
2020-08-21T07:16:08+0000 ipsec 15[KNL] creating rekey job for CHILD_SA ESP/0x70f1d9c9/86.y.y.y
2020-08-21T07:22:11+0000 ipsec 11[KNL] creating delete job for CHILD_SA ESP/0x0b45c632/86.y.y.y
2020-08-21T07:22:11+0000 ipsec 13[KNL] creating delete job for CHILD_SA ESP/0xc0f8651c/35.x.x.x
2020-08-21T07:22:20+0000 ipsec 14[NET] <vpn3a|321> received packet: from 86.y.y.y[4500] to 35.x.x.x[4500] (80 bytes)
2020-08-21T07:22:20+0000 ipsec 14[ENC] <vpn3a|321> parsed INFORMATIONAL request 0 [ D ]
2020-08-21T07:22:20+0000 ipsec 14[IKE] <vpn3a|321> received DELETE for ESP CHILD_SA with SPI 0b45c632
*2020-08-21T07:22:20+0000 ipsec 14[KNL] <vpn3a|321> querying SAD entry with SPI c0f8651c failed: No such process (3)*
2020-08-21T07:22:20+0000 ipsec 14[KNL] <vpn3a|321> querying SAD entry with SPI 0b45c632 failed: No such process (3)
2020-08-21T07:22:20+0000 ipsec 14[IKE] <vpn3a|321> closing CHILD_SA vpn3c{181} with SPIs c0f8651c_i (348019 bytes) 0b45c632_o (403970 bytes) and TS 10.0.0.32/29 === 172.16.23.0/24
2020-08-21T07:22:20+0000 ipsec 14[IKE] <vpn3a|321> sending DELETE for ESP CHILD_SA with SPI c0f8651c
2020-08-21T07:22:20+0000 ipsec 14[IKE] <vpn3a|321> CHILD_SA closed
2020-08-21T07:22:20+0000 ipsec Tunnel Down: vpn3c between 35.x.x.x and 86.y.y.y. Network removed: 10.0.0.32/29 and 172.16.23.0/24
2020-08-21T07:22:20+0000 ipsec 14[ENC] <vpn3a|321> generating INFORMATIONAL response 0 [ D ]
2020-08-21T07:22:20+0000 ipsec 14[NET] <vpn3a|321> sending packet: from 35.x.x.x[4500] to 86.y.y.y[4500] (80 bytes)
2020-08-21T07:26:30+0000 ipsec 13[KNL] creating delete job for CHILD_SA ESP/0xc0f52cc3/35.x.x.x
2020-08-21T07:26:30+0000 ipsec 12[KNL] creating delete job for CHILD_SA ESP/0xdca12e6b/86.y.y.y
2020-08-21T07:26:39+0000 ipsec 07[NET] <vpn3a|321> received packet: from 86.y.y.y[4500] to 35.x.x.x[4500] (80 bytes)
2020-08-21T07:26:39+0000 ipsec 07[ENC] <vpn3a|321> parsed INFORMATIONAL request 1 [ D ]
2020-08-21T07:26:39+0000 ipsec 07[IKE] <vpn3a|321> received DELETE for ESP CHILD_SA with SPI dca12e6b
2020-08-21T07:26:39+0000 ipsec 07[KNL] <vpn3a|321> querying SAD entry with SPI c0f52cc3 failed: No such process (3)
2020-08-21T07:26:39+0000 ipsec 07[KNL] <vpn3a|321> querying SAD entry with SPI dca12e6b failed: No such process (3)
2020-08-21T07:26:39+0000 ipsec 07[IKE] <vpn3a|321> closing CHILD_SA vpn3c{185} with SPIs c0f52cc3_i (3015709 bytes) dca12e6b_o (3608475 bytes) and TS 10.0.0.32/29 === 172.16.23.0/24
2020-08-21T07:26:39+0000 ipsec 07[IKE] <vpn3a|321> sending DELETE for ESP CHILD_SA with SPI c0f52cc3
2020-08-21T07:26:39+0000 ipsec 07[IKE] <vpn3a|321> CHILD_SA closed
2020-08-21T07:26:39+0000 ipsec Tunnel Down: vpn3c between 35.x.x.x and 86.y.y.y. Network removed: 10.0.0.32/29 and 172.16.23.0/24
2020-08-21T07:26:39+0000 ipsec 07[ENC] <vpn3a|321> generating INFORMATIONAL response 1 [ D ]
2020-08-21T07:26:39+0000 ipsec 07[NET] <vpn3a|321> sending packet: from 35.x.x.x[4500] to 86.y.y.y[4500] (80 bytes)
2020-08-21T07:26:50+0000 ipsec 15[KNL] creating delete job for CHILD_SA ESP/0xc4855d1c/35.x.x.x
2020-08-21T07:26:50+0000 ipsec 09[KNL] creating delete job for CHILD_SA ESP/0x70f1d9c9/86.y.y.y
2020-08-21T07:26:51+0000 ipsec 13[KNL] <vpn3a|321> querying SAD entry with SPI c4855d1c failed: No such process (3)
2020-08-21T07:26:59+0000 ipsec 15[NET] <vpn3a|321> received packet: from 86.y.y.y[4500] to 35.x.x.x[4500] (80 bytes)
2020-08-21T07:26:59+0000 ipsec 15[ENC] <vpn3a|321> parsed INFORMATIONAL request 2 [ D ]
2020-08-21T07:26:59+0000 ipsec 15[IKE] <vpn3a|321> received DELETE for ESP CHILD_SA with SPI 70f1d9c9
2020-08-21T07:26:59+0000 ipsec 15[KNL] <vpn3a|321> querying SAD entry with SPI c4855d1c failed: No such process (3)
2020-08-21T07:26:59+0000 ipsec 15[KNL] <vpn3a|321> querying SAD entry with SPI 70f1d9c9 failed: No such process (3)
2020-08-21T07:26:59+0000 ipsec 15[IKE] <vpn3a|321> closing CHILD_SA vpn3e{186} with SPIs c4855d1c_i (0 bytes) 70f1d9c9_o (0 bytes) and TS 10.0.0.32/29 === 172.16.25.0/24
2020-08-21T07:26:59+0000 ipsec 15[IKE] <vpn3a|321> sending DELETE for ESP CHILD_SA with SPI c4855d1c
2020-08-21T07:26:59+0000 ipsec 15[IKE] <vpn3a|321> CHILD_SA closed
2020-08-21T07:26:59+0000 ipsec Tunnel Down: vpn3e between 35.x.x.x and 86.y.y.y. Network removed: 10.0.0.32/29 and 172.16.25.0/24
2020-08-21T07:26:59+0000 ipsec 15[ENC] <vpn3a|321> generating INFORMATIONAL response 2 [ D ]
2020-08-21T07:26:59+0000 ipsec 15[NET] <vpn3a|321> sending packet: from 35.x.x.x[4500] to 86.y.y.y[4500] (80 bytes)
2020-08-21T07:29:26+0000 ipsec 13[CFG] received stroke: terminate 'vpn3e'
2020-08-21T07:29:26+0000 ipsec 13[CFG] no IKE_SA named 'vpn3e' found
2020-08-21T07:29:26+0000 ipsec 08[CFG] received stroke: initiate 'vpn3e'

Before 07:03:39, the last ipsec message was from 06:26, so I think 07:03:39 is a good place to start. At 07:29:26 my script tried to down-nb/up-nb the tunnel to recover it (and after which it continued to do so periodically, I guess snowballing the tasks queue)

I do see some odd logs in the above, namely:

2020-08-21T07:26:51+0000 ipsec 13[KNL] <vpn3a|321> querying SAD entry with SPI c4855d1c failed: No such process (3)
-- I guess that's because the entry was already removed from the kernel previously?

2020-08-21T07:05:46+0000 ipsec 07[ENC] <vpn3a|321> encrypting encrypted payload failed, no IV or padding
-- What would cause this one? PRNG related?

ipsec stroke down-nb <vpn>
ipsec stroke up-nb <vpn>

That's not such a good idea because if there already is an IKE_SA this will just queue the creation of another instance of the CHILD_SA i.e. queue a CHILD_CREATE task (basically results in what you see in the status output).

ipsec stroke down-nb does a regular deletion (i.e. queues a delete task, depending on the syntax one for the IKE or the CHILD_SA), so that might just add to the problem.

Ah ok, yeah that makes sense, yes explains the tasks list growing.

How can I delete a tunnel in this state without resorting to restarting ipsec entirely?

With swanctl's --terminate command you have more options (e.g. allows forcing the deletion of an IKE_SA without sending a delete).

Thank you, I will take a look at swanctl's terminate next time this happens.

Unfortunately the logging wasn't very detailed at the time, I will need to increase the level as well. Assume mgr is the right subsystem to increase logging?

Or, is there a way to simply just clear its task queue?

No, there is currently no public API for this. So you better make sure this doesn't happen in the first place.

Have you considered using trap policies (auto=route) so SAs are automatically (re-)created if matching traffic hits those policies? Also note that, depending on the peer implementation, you won't have to create separate CHILD_SAs for multiple remote subnets.

Re auto=route, I prefer to avoid it and always establish everything straight away, as then I know the tunnel is working straight away, rather than having to wait for user traffic at some stage.

Thank you again for the feedback!

#3 Updated by Tobias Brunner 2 months ago

I do see some odd logs in the above, namely:

2020-08-21T07:26:51+0000 ipsec 13[KNL] <vpn3a|321> querying SAD entry with SPI c4855d1c failed: No such process (3)
-- I guess that's because the entry was already removed from the kernel previously?

Yes, most likely. This can happen if the rekeying can't be completed in time.

2020-08-21T07:05:46+0000 ipsec 07[ENC] <vpn3a|321> encrypting encrypted payload failed, no IV or padding
-- What would cause this one? PRNG related?

Looks like it. Either acquiring the IV (for AES-CBC it is random) or the random padding may have failed (source:src/libcharon/encoding/payloads/encrypted_payload.c#L477). Does this happen repeatedly? What plugin provides the RNG implementation? (Check with ipsec listalgs.)

Unfortunately the logging wasn't very detailed at the time, I will need to increase the level as well. Assume mgr is the right subsystem to increase logging?

Not sure if mgr in particular would help here. Maybe just use the log settings given on HelpRequests (see LoggerConfiguration for details).

Re auto=route, I prefer to avoid it and always establish everything straight away, as then I know the tunnel is working straight away, rather than having to wait for user traffic at some stage.

You could always ping hosts in the remote subnets if you want to initiate/test the tunnel right away. The advantage of using trap policies is that no cleartext traffic leaves your host while no tunnel is established. Of course, if you don't do that and the traffic could be initiated by a remote host, the peer has to use a matching config.

#4 Updated by Mike C 2 months ago

Tobias Brunner wrote:

2020-08-21T07:05:46+0000 ipsec 07[ENC] <vpn3a|321> encrypting encrypted payload failed, no IV or padding
-- What would cause this one? PRNG related?

Looks like it. Either acquiring the IV (for AES-CBC it is random) or the random padding may have failed (source:src/libcharon/encoding/payloads/encrypted_payload.c#L477). Does this happen repeatedly? What plugin provides the RNG implementation? (Check with ipsec listalgs.)

I have seen this encrypted payload failed message a few times in the past, checking my logs it does seem to happen sometimes under some others boxes under my control.

Output from ipsec listalgs:

List of registered IKE algorithms:

encryption: AES_CBC[aes] 3DES_CBC[des] DES_CBC[des] DES_ECB[des] RC2_CBC[rc2] CAST_CBC[openssl] BLOWFISH_CBC[openssl]
NULL[openssl] AES_CTR[af-alg] CAMELLIA_CBC[af-alg] CAMELLIA_CTR[af-alg]
integrity: HMAC_MD5_96[openssl] HMAC_MD5_128[openssl] HMAC_SHA1_96[openssl] HMAC_SHA1_128[openssl]
HMAC_SHA1_160[openssl] HMAC_SHA2_256_128[openssl] HMAC_SHA2_256_256[openssl] HMAC_SHA2_384_192[openssl]
HMAC_SHA2_384_384[openssl] HMAC_SHA2_512_256[openssl] HMAC_SHA2_512_512[openssl] HMAC_SHA2_256_96[af-alg]
AES_XCBC_96[af-alg] CAMELLIA_XCBC_96[af-alg]
aead: AES_GCM_16[openssl] AES_GCM_12[openssl] AES_GCM_8[openssl]
hasher: HASH_SHA1[sha1] HASH_SHA2_224[sha2] HASH_SHA2_256[sha2] HASH_SHA2_384[sha2] HASH_SHA2_512[sha2]
HASH_MD5[md5] HASH_MD4[openssl] HASH_IDENTITY[curve25519]
prf: PRF_KEYED_SHA1[sha1] PRF_HMAC_MD5[openssl] PRF_HMAC_SHA1[openssl] PRF_HMAC_SHA2_256[openssl]
PRF_HMAC_SHA2_384[openssl] PRF_HMAC_SHA2_512[openssl] PRF_AES128_XCBC[af-alg] PRF_CAMELLIA128_XCBC[af-alg]
PRF_FIPS_SHA1_160[fips-prf]
xof:
dh-group: ECP_256[openssl] ECP_384[openssl] ECP_521[openssl] ECP_224[openssl] ECP_192[openssl] ECP_256_BP[openssl]
ECP_384_BP[openssl] ECP_512_BP[openssl] ECP_224_BP[openssl] MODP_3072[openssl] MODP_4096[openssl]
MODP_6144[openssl] MODP_8192[openssl] MODP_2048[openssl] MODP_2048_224[openssl] MODP_2048_256[openssl]
MODP_1536[openssl] MODP_1024[openssl] MODP_1024_160[openssl] MODP_768[openssl] MODP_CUSTOM[openssl]
CURVE_25519[curve25519]
random-gen: RNG_WEAK[openssl] RNG_STRONG[random] RNG_TRUE[random]
nonce-gen: [nonce]

Is there a way to specify which of these RNG should be used by the tunnels?

Re padding, is using PKCS#7 an option, rather than using a RNG?

Also in case it helps:

strongswan.conf:

charon {
load_modular = yes
make_before_break = yes
plugins {
include strongswan.d/charon/*.conf
vici {
socket = unix:///var/run/charon.vici
}

}
syslog {
identifier = ipsec
daemon {
ike_name = yes
cfg = 2
}
}
}

ipsec.conf:

config setup

conn %default
ikelifetime=14400s
keylife=10800s
rekeymargin=600s
keyingtries=%forever
keyexchange=ikev1
authby=secret
ike=aes128-sha256-modp3072,aes128-sha256-modp2048,aes128-sha256-modp1536,aes128-sha256-modp1024,aes128-sha1-modp3072,aes128-sha1-modp2048,aes128-sha1-modp1536,aes128-sha1-modp1024
esp=aes128-sha256-modp3072,aes128-sha256-modp2048,aes128-sha256-modp1536,aes128-sha256-modp1024,aes128-sha1-modp3072,aes128-sha1-modp2048,aes128-sha1-modp1536,aes128-sha1-modp1024
closeaction=none
leftupdown=/etc/ipsec.d/updown
rightupdown=/etc/ipsec.d/updown

conn vpn1
...

conn vpn2
...

conn vpn3a
auto=start
dpdaction=restart
dpddelay=30s
dpdtimeout=90s
esp=aes128-sha256-ecp256!
forceencaps=no
ike=aes128-sha256-ecp256!
ikelifetime=14400s
keyexchange=ikev2
keyingtries=%forever
keylife=3600s
left=35.x.x.x
leftfirewall=no
leftid=
leftsubnet=10.0.0.32/29
margintime=9
rekeymargin=600s
right=86.y.y.y
rightfirewall=no
rightid=
rightsubnet=192.168.44.0/23

conn vpn3b
auto=start
dpdaction=restart
dpddelay=30s
dpdtimeout=90s
esp=aes128-sha256-ecp256!
forceencaps=no
ike=aes128-sha256-ecp256!
ikelifetime=14400s
keyexchange=ikev2
keyingtries=%forever
keylife=3600s
left=35.x.x.x
leftfirewall=no
leftid=
leftsubnet=10.0.0.32/29
margintime=9
rekeymargin=600s
right=86.y.y.y
rightfirewall=no
rightid=
rightsubnet=192.168.46.0/23

conn vpn3c
auto=start
dpdaction=restart
dpddelay=30s
dpdtimeout=90s
esp=aes128-sha256-ecp256!
forceencaps=no
ike=aes128-sha256-ecp256!
ikelifetime=14400s
keyexchange=ikev2
keyingtries=%forever
keylife=3600s
left=35.x.x.x
leftfirewall=no
leftid=
leftsubnet=10.0.0.32/29
margintime=9
rekeymargin=600s
right=86.y.y.y
rightfirewall=no
rightid=
rightsubnet=172.16.23.0/24

conn vpn3d
auto=start
dpdaction=restart
dpddelay=30s
dpdtimeout=90s
esp=aes128-sha256-ecp256!
forceencaps=no
ike=aes128-sha256-ecp256!
ikelifetime=14400s
keyexchange=ikev2
keyingtries=%forever
keylife=3600s
left=35.x.x.x
leftfirewall=no
leftid=
leftsubnet=10.0.0.32/29
margintime=9
rekeymargin=600s
right=86.y.y.y
rightfirewall=no
rightid=
rightsubnet=172.16.24.0/24

conn vpn3e
auto=start
dpdaction=restart
dpddelay=30s
dpdtimeout=90s
esp=aes128-sha256-ecp256!
forceencaps=no
ike=aes128-sha256-ecp256!
ikelifetime=14400s
keyexchange=ikev2
keyingtries=%forever
keylife=3600s
left=35.x.x.x
leftfirewall=no
leftid=
leftsubnet=10.0.0.32/29
margintime=9
rekeymargin=600s
right=86.y.y.y
rightfirewall=no
rightid=
rightsubnet=172.16.25.0/24

conn vpn3f
auto=start
dpdaction=restart
dpddelay=30s
dpdtimeout=90s
esp=aes128-sha256-ecp256!
forceencaps=no
ike=aes128-sha256-ecp256!
ikelifetime=14400s
keyexchange=ikev2
keyingtries=%forever
keylife=3600s
left=35.x.x.x
leftfirewall=no
leftid=
leftsubnet=10.0.0.32/29
margintime=9
rekeymargin=600s
right=86.y.y.y
rightfirewall=no
rightid=
rightsubnet=172.16.26.0/24

#5 Updated by Tobias Brunner 2 months ago

random-gen: RNG_WEAK[openssl] RNG_STRONG[random] RNG_TRUE[random]
nonce-gen: [nonce]

Is there a way to specify which of these RNG should be used by the tunnels?

You could change the plugin order (see PluginLoad). For both IV and padding RNG_WEAK is used, which is provided via openssl plugin here. Depending on the underlying OpenSSL version I don't really see how this could fail (newer versions use a DRBG, which should always be able to return data). With older versions that read directly from /dev/(u)random I suppose there is more possibility for failure.

Re padding, is using PKCS#7 an option, rather than using a RNG?

Well, technically, the padding in IKEv2 does not actually have to be random. But it seemed like the prudent thing to do.

ipsec.conf:

You could simplify the config a lot by using the also keyword.

#6 Updated by Mike C about 2 months ago

Tobias Brunner wrote:

random-gen: RNG_WEAK[openssl] RNG_STRONG[random] RNG_TRUE[random]
nonce-gen: [nonce]

Is there a way to specify which of these RNG should be used by the tunnels?

You could change the plugin order (see PluginLoad). For both IV and padding RNG_WEAK is used, which is provided via openssl plugin here. Depending on the underlying OpenSSL version I don't really see how this could fail (newer versions use a DRBG, which should always be able to return data). With older versions that read directly from /dev/(u)random I suppose there is more possibility for failure.

Thanks, I think this might be it. OpenSSL is 1.0.2u, I will try the 1.1.1 branch and failing that, try a different plugin order.

#7 Updated by Tobias Brunner 23 days ago

  • Category set to configuration
  • Status changed from Feedback to Closed
  • Assignee set to Tobias Brunner
  • Resolution set to No change required

Also available in: Atom PDF