[strongSwan] Issue with Debian 10
Jaehong Park
jaehong.park at illumio.com
Mon Mar 8 14:55:33 CET 2021
I am testing Debain 10 + Strongswan and facing an issue.
Test on StrongSwan 5.7.2 as well as the latest 5.9.2.
Debian 10, iproute2-ss190107
Here is My ipsec statusall dump.
Status of IKE charon daemon (strongSwan 5.7.2, Linux 4.19.0-14-amd64, x86_64):
uptime: 2 minutes, since Mar 06 06:58:27 2021
malloc: sbrk 1490944, mmap 0, used 542624, free 948320
worker threads: 27 of 32 idle, 5/0/0/0 working, job queue: 0/0/0/0, scheduled: 5
loaded plugins: charon aes des sha2 sha1 md5 random nonce x509 revocation pubkey pkcs1 pkcs7 pkcs8 pkcs12 sshkey pem openssl curve25519 xcbc hmac attr kernel-netlink socket-default stroke vici updown error-notify counters
Listening IP addresses:
192.168.41.134
fd15:4ba5:5a2b:1002:20c:29ff:fec9:4812
Connections:
4.192-168-41-165.32.0.0.0.0: %any...192.168.41.165 IKEv2, dpddelay=30s
4.192-168-41-165.32.0.0.0.0: local: uses pre-shared key authentication
4.192-168-41-165.32.0.0.0.0: remote: uses pre-shared key authentication
4.192-168-41-165.32.0.0.0.0: child: dynamic === dynamic TRANSPORT, dpdaction=hold
4.192-168-41-171.32.0.0.0.0: %any...192.168.41.171 IKEv2, dpddelay=30s
4.192-168-41-171.32.0.0.0.0: local: uses pre-shared key authentication
4.192-168-41-171.32.0.0.0.0: remote: uses pre-shared key authentication
4.192-168-41-171.32.0.0.0.0: child: dynamic === dynamic TRANSPORT, dpdaction=hold
Routed Connections:
4.192-168-41-171.32.0.0.0.0{2}: ROUTED, TRANSPORT, reqid 2
4.192-168-41-171.32.0.0.0.0{2}: 192.168.41.134/32 === 192.168.41.171/32
4.192-168-41-165.32.0.0.0.0{1}: ROUTED, TRANSPORT, reqid 1
4.192-168-41-165.32.0.0.0.0{1}: 192.168.41.134/32 === 192.168.41.165/32
Security Associations (1 up, 0 connecting):
4.192-168-41-165.32.0.0.0.0[1]: ESTABLISHED 24 seconds ago, 192.168.41.134[192.168.41.134]...192.168.41.165[192.168.41.165]
4.192-168-41-165.32.0.0.0.0[1]: IKEv2 SPIs: b33bd09fad5378b2_i* b38186e382910f98_r, pre-shared key reauthentication in 2 hours
4.192-168-41-165.32.0.0.0.0[1]: IKE proposal: AES_CBC_256/HMAC_SHA2_256_128/PRF_HMAC_SHA2_256/MODP_2048
4.192-168-41-165.32.0.0.0.0{3}: INSTALLED, TRANSPORT, reqid 1, ESP SPIs: c2aaff7b_i cb007cdb_o
4.192-168-41-165.32.0.0.0.0{3}: AES_CBC_256/HMAC_SHA1_96, 192 bytes_i (3 pkts, 21s ago), 192 bytes_o (3 pkts, 21s ago), rekeying in 46 minutes
4.192-168-41-165.32.0.0.0.0{3}: 192.168.41.134/32 === 192.168.41.165/32
now if I stop charon all together, and this is my charon.log
2021-03-06T07:05:21-0800 00[DMN] signal of type SIGINT received. Shutting down
2021-03-06T07:05:21-0800 00[MGR] going to destroy IKE_SA manager and all managed IKE_SA's
2021-03-06T07:05:21-0800 00[MGR] set driveout flags for all stored IKE_SA's
2021-03-06T07:05:21-0800 00[MGR] wait for all threads to leave IKE_SA's
2021-03-06T07:05:21-0800 00[MGR] delete all IKE_SA's
2021-03-06T07:05:21-0800 00[IKE] queueing IKE_DELETE task
2021-03-06T07:05:21-0800 00[IKE] activating new tasks
2021-03-06T07:05:21-0800 00[IKE] activating IKE_DELETE task
2021-03-06T07:05:21-0800 00[IKE] deleting IKE_SA 4.192-168-41-165.32.0.0.0.0[2] between 192.168.41.134[192.168.41.134]...192.168.41.165[192.168.41.165]
2021-03-06T07:05:21-0800 00[ENC] added payload of type DELETE to message
2021-03-06T07:05:21-0800 00[IKE] IKE_SA 4.192-168-41-165.32.0.0.0.0[2] state change: ESTABLISHED => DELETING
2021-03-06T07:05:21-0800 00[IKE] sending DELETE for IKE_SA 4.192-168-41-165.32.0.0.0.0[2]
2021-03-06T07:05:21-0800 00[ENC] order payloads in message
2021-03-06T07:05:21-0800 00[ENC] added payload of type DELETE to message
2021-03-06T07:05:21-0800 00[ENC] generating INFORMATIONAL request 2 [ D ]
2021-03-06T07:05:21-0800 00[ENC] insert payload DELETE into encrypted payload
2021-03-06T07:05:21-0800 00[ENC] generating payload of type HEADER
2021-03-06T07:05:21-0800 00[ENC] generating rule 0 IKE_SPI
2021-03-06T07:05:21-0800 00[ENC] generating rule 1 IKE_SPI
2021-03-06T07:05:21-0800 00[ENC] generating rule 2 U_INT_8
2021-03-06T07:05:21-0800 00[ENC] generating rule 3 U_INT_4
2021-03-06T07:05:21-0800 00[ENC] generating rule 4 U_INT_4
2021-03-06T07:05:21-0800 00[ENC] generating rule 5 U_INT_8
2021-03-06T07:05:21-0800 00[ENC] generating rule 6 RESERVED_BIT
2021-03-06T07:05:21-0800 00[ENC] generating rule 7 RESERVED_BIT
2021-03-06T07:05:21-0800 00[ENC] generating rule 8 FLAG
2021-03-06T07:05:21-0800 00[ENC] generating rule 9 FLAG
2021-03-06T07:05:21-0800 00[ENC] generating rule 10 FLAG
2021-03-06T07:05:21-0800 00[ENC] generating rule 11 FLAG
2021-03-06T07:05:21-0800 00[ENC] generating rule 12 FLAG
2021-03-06T07:05:21-0800 00[ENC] generating rule 13 FLAG
2021-03-06T07:05:21-0800 00[ENC] generating rule 14 U_INT_32
2021-03-06T07:05:21-0800 00[ENC] generating rule 15 HEADER_LENGTH
2021-03-06T07:05:21-0800 00[ENC] generating HEADER payload finished
2021-03-06T07:05:21-0800 00[ENC] generating payload of type DELETE
2021-03-06T07:05:21-0800 00[ENC] generating rule 0 U_INT_8
2021-03-06T07:05:21-0800 00[ENC] generating rule 1 FLAG
2021-03-06T07:05:21-0800 00[ENC] generating rule 2 RESERVED_BIT
2021-03-06T07:05:21-0800 00[ENC] generating rule 3 RESERVED_BIT
2021-03-06T07:05:21-0800 00[ENC] generating rule 4 RESERVED_BIT
2021-03-06T07:05:21-0800 00[ENC] generating rule 5 RESERVED_BIT
2021-03-06T07:05:21-0800 00[ENC] generating rule 6 RESERVED_BIT
2021-03-06T07:05:21-0800 00[ENC] generating rule 7 RESERVED_BIT
2021-03-06T07:05:21-0800 00[ENC] generating rule 8 RESERVED_BIT
2021-03-06T07:05:21-0800 00[ENC] generating rule 9 PAYLOAD_LENGTH
2021-03-06T07:05:21-0800 00[ENC] generating rule 10 U_INT_8
2021-03-06T07:05:21-0800 00[ENC] generating rule 11 U_INT_8
2021-03-06T07:05:21-0800 00[ENC] generating rule 12 U_INT_16
2021-03-06T07:05:21-0800 00[ENC] generating rule 13 CHUNK_DATA
2021-03-06T07:05:21-0800 00[ENC] generating DELETE payload finished
2021-03-06T07:05:21-0800 00[ENC] generated content in encrypted payload
2021-03-06T07:05:21-0800 00[ENC] generating payload of type ENCRYPTED
2021-03-06T07:05:21-0800 00[ENC] generating rule 0 U_INT_8
2021-03-06T07:05:21-0800 00[ENC] generating rule 1 U_INT_8
2021-03-06T07:05:21-0800 00[ENC] generating rule 2 PAYLOAD_LENGTH
2021-03-06T07:05:21-0800 00[ENC] generating rule 3 CHUNK_DATA
2021-03-06T07:05:21-0800 00[ENC] generating ENCRYPTED payload finished
2021-03-06T07:05:21-0800 00[NET] sending packet: from 192.168.41.134[500] to 192.168.41.165[500] (80 bytes)
2021-03-06T07:05:21-0800 00[MGR] destroy all entries
2021-03-06T07:05:21-0800 00[IKE] IKE_SA 4.192-168-41-165.32.0.0.0.0[2] state change: DELETING => DESTROYING
2021-03-06T07:05:21-0800 00[CHD] CHILD_SA 4.192-168-41-165.32.0.0.0.0{4} state change: INSTALLED => DESTROYING
2021-03-06T07:05:21-0800 00[KNL] deleting policy 192.168.41.134/32 === 192.168.41.165/32 out
2021-03-06T07:05:21-0800 00[KNL] policy still used by another CHILD_SA, not removed
2021-03-06T07:05:21-0800 00[KNL] updating policy 192.168.41.134/32 === 192.168.41.165/32 out [priority 367232, refcount 1]
2021-03-06T07:05:21-0800 00[KNL] deleting policy 192.168.41.165/32 === 192.168.41.134/32 in
2021-03-06T07:05:21-0800 00[KNL] policy still used by another CHILD_SA, not removed
2021-03-06T07:05:21-0800 00[KNL] updating policy 192.168.41.165/32 === 192.168.41.134/32 in [priority 367232, refcount 1]
2021-03-06T07:05:21-0800 00[KNL] deleting SAD entry with SPI ccb74d1a
2021-03-06T07:05:21-0800 00[KNL] deleted SAD entry with SPI ccb74d1a
2021-03-06T07:05:21-0800 00[KNL] deleting SAD entry with SPI cc0ef0a7
2021-03-06T07:05:21-0800 00[KNL] deleted SAD entry with SPI cc0ef0a7
2021-03-06T07:05:21-0800 00[CHD] CHILD_SA 4.192-168-41-171.32.0.0.0.0{2} state change: ROUTED => DESTROYING
2021-03-06T07:05:21-0800 00[KNL] deleting policy 192.168.41.134/32 === 192.168.41.171/32 out
2021-03-06T07:05:21-0800 00[KNL] deleting policy 192.168.41.171/32 === 192.168.41.134/32 in
2021-03-06T07:05:21-0800 00[CHD] CHILD_SA 4.192-168-41-165.32.0.0.0.0{1} state change: ROUTED => DESTROYING
2021-03-06T07:05:21-0800 00[KNL] deleting policy 192.168.41.134/32 === 192.168.41.165/32 out
2021-03-06T07:05:21-0800 00[KNL] deleting policy 192.168.41.165/32 === 192.168.41.134/32 in
2021-03-06T07:05:21-0800 04[NET] sending packet: from 192.168.41.134[500] to 192.168.41.165[500]
2021-03-06T07:05:21-0800 01[JOB] next event in 3s 999ms, waiting
2021-03-06T07:05:21-0800 02[JOB] terminated worker thread 02
2021-03-06T07:05:21-0800 03[JOB] terminated worker thread 03
2021-03-06T07:05:21-0800 01[JOB] terminated worker thread 01
2021-03-06T07:05:21-0800 04[JOB] terminated worker thread 04
According to the charon log above, I see it attempt to delete.
However when I dump ip xfrm pol, the policy stays, and will never be removed without manual intervention. Anybody seen this kind of issue in any other platform?
root at debian10:/opt/illumio_ven/bin# ip xfrm pol
src 192.168.41.165/32 dst 192.168.41.134/32
dir in priority 367232 ptype main
tmpl src 0.0.0.0 dst 0.0.0.0
proto esp reqid 1 mode transport
src 192.168.41.134/32 dst 192.168.41.165/32
dir out priority 367232 ptype main
tmpl src 0.0.0.0 dst 0.0.0.0
proto esp reqid 1 mode transport
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.strongswan.org/pipermail/users/attachments/20210308/01a10876/attachment-0001.html>
More information about the Users
mailing list