[strongSwan] Problem: "unable to install policy -the same policy for reqid XXXX exists "
Sven Anders
anders at anduras.de
Fri Nov 23 11:03:05 CET 2018
Hello!
We are using strongSwan 5.6.2 on a Linux kernel 4.1.39.
Our problem is, that after some uptime the strongswan rejects connections with
the following message:
charon: 23422[CFG] unable to install policy 10.0.0.0/8 === 192.168.3.67/32 out for reqid 14832, the same policy for reqid 4388 exists
If we restart strongswan, the connections begin to work correctly again.
The installed policy (in this case) is the following:
src 10.0.0.0/8 dst 192.168.3.67/32
dir out priority 379519 ptype main
tmpl src 217.6.20.66 dst 84.160.101.118
proto esp spi 0x0f95ddf2 reqid 4388 mode tunnel
The connections are mainly from iPhones and are using IKEv2.
Any ideas what causes this?
Is there an option to force the replacement of an policy?
I already tried to change "auto=add" to "auto=route", which I found in a description
of a similar problem, but that changed nothing...
Regards
Sven Anders
---8X---------------------------------------------------------------------------------
Here is the configuration:
ipsec.conf:
-----------
config setup
uniqueids=never
charondebug = ike 2, net 2, pts 2, lib 2, tls 2, cfg 3, knl 2
conn rw-base
fragmentation=yes
dpdtimeout=90s
dpddelay=30s
dpdaction=clear
conn rw-config
also=rw-base
reauth=no
rekey=no
ike=aes256-sha2_256-prfsha256-modp1024-modp2048,aes256gcm16-prfsha384-modp3072!
esp=aes256-sha2_256-prfsha256,aes256-sha1,aes256gcm16-modp3072!
leftsubnet=10.0.0.0/8 # Split tunnel config
leftid="vpn.company.net"
leftcert=server.crt
leftsendcert=always # not "never"
left=217.6.20.66
lefthostaccess=yes
rightdns=10.1.3.10, 10.1.3.11
rightsourceip=%static, %dynamic
conn ikev2-pubkey
also=rw-config
keyexchange=ikev2
auto=route
strongswan.conf
---------------
charon { load_modular = yes plugins { include strongswan.d/charon/*.conf } }
include strongswan.d/*.conf
charon {
install_routes = no
install_virtual_ip = no
crypto_test { bench = yes }
plugins {
attr-sql {
database = sqlite:///var/lib/ipsec/ippool.sqlite3
}
attr {
dns = 10.1.3.10, 10.1.3.11
25 = company.local
split-include = 10.0.0.0/8
split-exclude = 0.0.0.0/0
28675 = company.local
}
}
Here is the log file:
---------------------
Nov 23 10:11:39 2101120420063 charon: 23422[IKE] received ESP_TFC_PADDING_NOT_SUPPORTED, not using ESPv3 TFC padding
Nov 23 10:11:39 2101120420063 charon: 23422[IKE] peer supports MOBIKE
Nov 23 10:11:39 2101120420063 charon: 23422[IKE] authentication of 'vpn.company.net' (myself) with RSA signature successful
Nov 23 10:11:39 2101120420063 charon: 23422[IKE] IKE_SA ikev2-pubkey[18259] established between 217.6.20.66[vpn.company.net]...188.238.227
.128[joko.class at company.fi]
Nov 23 10:11:39 2101120420063 charon: 23422[IKE] IKE_SA ikev2-pubkey[18259] state change: CONNECTING => ESTABLISHED
Nov 23 10:11:39 2101120420063 charon: 23422[IKE] sending end entity cert "C=DE, ST=BY, O=Company, CN=vpn.company.net"
Nov 23 10:11:39 2101120420063 charon: 23422[IKE] peer requested virtual IP %any
Nov 23 10:11:39 2101120420063 charon: 23422[CFG] no available address found in pool 'static'
Nov 23 10:11:39 2101120420063 charon: 23422[CFG] acquired new lease for address 192.168.3.67 in pool 'dynamic'
Nov 23 10:11:39 2101120420063 charon: 23422[IKE] assigning virtual IP 192.168.3.67 to peer 'joko.class at company.fi'
Nov 23 10:11:39 2101120420063 charon: 23422[IKE] peer requested virtual IP %any6
Nov 23 10:11:39 2101120420063 charon: 23422[IKE] no virtual IP found for %any6 requested by 'joko.class at company.fi'
Nov 23 10:11:39 2101120420063 charon: 23422[IKE] building INTERNAL_IP4_DNS attribute
Nov 23 10:11:39 2101120420063 charon: 23422[IKE] building INTERNAL_IP4_DNS attribute
Nov 23 10:11:39 2101120420063 charon: 23422[IKE] building (25) attribute
Nov 23 10:11:39 2101120420063 charon: 23422[IKE] building UNITY_SPLITDNS_NAME attribute
Nov 23 10:11:39 2101120420063 charon: 23422[IKE] building INTERNAL_IP4_DNS attribute
Nov 23 10:11:39 2101120420063 charon: 23422[IKE] building INTERNAL_IP4_DNS attribute
Nov 23 10:11:39 2101120420063 charon: 23422[CFG] looking for a child config for 0.0.0.0/0 ::/0 === 0.0.0.0/0 ::/0
Nov 23 10:11:39 2101120420063 charon: 23422[CFG] proposing traffic selectors for us:
Nov 23 10:11:39 2101120420063 charon: 23422[CFG] 10.0.0.0/8
Nov 23 10:11:39 2101120420063 charon: 23422[CFG] proposing traffic selectors for other:
Nov 23 10:11:39 2101120420063 charon: 23422[CFG] 192.168.3.67/32
Nov 23 10:11:39 2101120420063 charon: 23422[CFG] candidate "ikev2-pubkey" with prio 2+2
Nov 23 10:11:39 2101120420063 charon: 23422[CFG] found matching child config "ikev2-pubkey" with prio 4
Nov 23 10:11:39 2101120420063 charon: 23422[CFG] selecting proposal:
Nov 23 10:11:39 2101120420063 charon: 23422[CFG] proposal matches
Nov 23 10:11:39 2101120420063 charon: 23422[CFG] received proposals: ESP:AES_CBC_256/HMAC_SHA2_256_128/NO_EXT_SEQ
Nov 23 10:11:39 2101120420063 charon: 23422[CFG] configured proposals: ESP:AES_CBC_256/HMAC_SHA2_256_128/NO_EXT_SEQ,
ESP:AES_CBC_256/HMAC_SHA1_96/NO_EXT_SEQ, ESP:AES_GCM_16_256/MODP_3072/NO_EXT_SEQ
Nov 23 10:11:39 2101120420063 charon: 23422[CFG] selected proposal: ESP:AES_CBC_256/HMAC_SHA2_256_128/NO_EXT_SEQ
Nov 23 10:11:39 2101120420063 charon: 23422[KNL] got SPI c553c70c
Nov 23 10:11:39 2101120420063 charon: 23422[CFG] selecting traffic selectors for us:
Nov 23 10:11:39 2101120420063 charon: 23422[CFG] config: 10.0.0.0/8, received: 0.0.0.0/0 => match: 10.0.0.0/8
Nov 23 10:11:39 2101120420063 charon: 23422[CFG] config: 10.0.0.0/8, received: ::/0 => no match
Nov 23 10:11:39 2101120420063 charon: 23422[CFG] selecting traffic selectors for other:
Nov 23 10:11:39 2101120420063 charon: 23422[CFG] config: 192.168.3.67/32, received: 0.0.0.0/0 => match: 192.168.3.67/32
Nov 23 10:11:39 2101120420063 charon: 23422[CFG] config: 192.168.3.67/32, received: ::/0 => no match
Nov 23 10:11:39 2101120420063 charon: 23422[KNL] adding SAD entry with SPI c553c70c and reqid {14832}
Nov 23 10:11:39 2101120420063 charon: 23422[KNL] using encryption algorithm AES_CBC with key size 256
Nov 23 10:11:39 2101120420063 charon: 23422[KNL] using integrity algorithm HMAC_SHA2_256_128 with key size 256
Nov 23 10:11:39 2101120420063 charon: 23422[KNL] using replay window of 32 packets
Nov 23 10:11:39 2101120420063 charon: 23422[KNL] adding SAD entry with SPI 0fbd4725 and reqid {14832}
Nov 23 10:11:39 2101120420063 charon: 23422[KNL] using encryption algorithm AES_CBC with key size 256
Nov 23 10:11:39 2101120420063 charon: 23422[KNL] using integrity algorithm HMAC_SHA2_256_128 with key size 256
Nov 23 10:11:39 2101120420063 charon: 23422[KNL] using replay window of 0 packets
Nov 23 10:11:39 2101120420063 charon: 23422[KNL] adding policy 192.168.3.67/32 === 10.0.0.0/8 in [priority 379519, refcount 1]
Nov 23 10:11:39 2101120420063 charon: 23422[KNL] adding policy 192.168.3.67/32 === 10.0.0.0/8 fwd [priority 379519, refcount 1]
Nov 23 10:11:39 2101120420063 charon: 23422[CFG] unable to install policy 10.0.0.0/8 === 192.168.3.67/32 out for reqid 14832, the same policy for
reqid 4388 exists
Nov 23 10:11:39 2101120420063 charon: 23422[IKE] unable to install IPsec policies (SPD) in kernel
Nov 23 10:11:39 2101120420063 charon: 23422[IKE] failed to establish CHILD_SA, keeping IKE_SA
Nov 23 10:11:39 2101120420063 charon: 23422[KNL] deleting policy 10.0.0.0/8 === 192.168.3.67/32 out
Nov 23 10:11:39 2101120420063 charon: 23422[KNL] policy still used by another CHILD_SA, not removed
Nov 23 10:11:39 2101120420063 charon: 23422[KNL] not updating policy 10.0.0.0/8 === 192.168.3.67/32 out [priority 379519, refcount 2]
Nov 23 10:11:39 2101120420063 charon: 23422[KNL] deleting policy 192.168.3.67/32 === 10.0.0.0/8 in
Nov 23 10:11:39 2101120420063 charon: 23422[KNL] deleting policy 192.168.3.67/32 === 10.0.0.0/8 fwd
Nov 23 10:11:39 2101120420063 charon: 23422[KNL] deleting SAD entry with SPI c553c70c
Nov 23 10:11:39 2101120420063 charon: 23422[KNL] deleted SAD entry with SPI c553c70c
Nov 23 10:11:39 2101120420063 charon: 23422[KNL] deleting SAD entry with SPI 0fbd4725
Nov 23 10:11:39 2101120420063 charon: 23422[KNL] deleted SAD entry with SPI 0fbd4725
Nov 23 10:11:39 2101120420063 charon: 23422[ENC] generating IKE_AUTH response 1 [ IDr CERT AUTH CPRP(ADDR DNS DNS (25) U_SPLITDNS DNS DNS)
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) N(TS_UNACCEPT) ]
Nov 23 10:11:39 2101120420063 charon: 23422[ENC] splitting IKE message with length of 2288 bytes into 2 fragments
Nov 23 10:11:39 2101120420063 charon: 23422[ENC] generating IKE_AUTH response 1 [ EF(1/2) ]
Nov 23 10:11:39 2101120420063 charon: 23422[ENC] generating IKE_AUTH response 1 [ EF(2/2) ]
Nov 23 10:11:39 2101120420063 charon: 23422[NET] sending packet: from 217.6.20.66[4500] to 188.238.227.128[15604] (1236 bytes)
Nov 23 10:11:39 2101120420063 charon: 23422[NET] sending packet: from 217.6.20.66[4500] to 188.238.227.128[15604] (1124 bytes)
Nov 23 10:11:39 2101120420063 charon: 23412[NET] sending packet: from 217.6.20.66[4500] to 188.238.227.128[15604]
Nov 23 10:11:39 2101120420063 charon: 23412[NET] sending packet: from 217.6.20.66[4500] to 188.238.227.128[15604]
Nov 23 10:11:39 2101120420063 charon: 23425[NET] received packet: from 80.187.118.120[16385] to 217.6.20.66[4500]
Nov 23 10:11:39 2101120420063 charon: 23425[NET] waiting for data on sockets
Nov 23 10:11:39 2101120420063 charon: 23420[NET] received packet: from 80.187.118.120[16385] to 217.6.20.66[4500] (80 bytes)
Nov 23 10:11:39 2101120420063 charon: 23420[ENC] parsed INFORMATIONAL response 99 [ ]
Nov 23 10:11:39 2101120420063 charon: 23420[IKE] activating new tasks
Nov 23 10:11:39 2101120420063 charon: 23420[IKE] nothing to initiate
Nov 23 10:11:39 2101120420063 charon: 23425[NET] received packet: from 188.238.227.128[15604] to 217.6.20.66[4500]
Nov 23 10:11:39 2101120420063 charon: 23425[NET] waiting for data on sockets
Nov 23 10:11:39 2101120420063 charon: 23415[NET] received packet: from 188.238.227.128[15604] to 217.6.20.66[4500] (80 bytes)
Nov 23 10:11:39 2101120420063 charon: 23415[ENC] parsed INFORMATIONAL request 2 [ D ]
Nov 23 10:11:39 2101120420063 charon: 23415[IKE] received DELETE for IKE_SA ikev2-pubkey[18259]
Nov 23 10:11:39 2101120420063 charon: 23415[IKE] deleting IKE_SA ikev2-pubkey[18259] between
217.6.20.66[vpn.company.net]...188.238.227.128[joko.class at company.fi]
Nov 23 10:11:39 2101120420063 charon: 23415[IKE] IKE_SA ikev2-pubkey[18259] state change: ESTABLISHED => DELETING
Nov 23 10:11:39 2101120420063 charon: 23415[IKE] IKE_SA deleted
Nov 23 10:11:39 2101120420063 charon: 23415[ENC] generating INFORMATIONAL response 2 [ ]
Nov 23 10:11:39 2101120420063 charon: 23415[NET] sending packet: from 217.6.20.66[4500] to 188.238.227.128[15604] (80 bytes)
Nov 23 10:11:39 2101120420063 charon: 23415[IKE] IKE_SA ikev2-pubkey[18259] state change: DELETING => DESTROYING
Nov 23 10:11:39 2101120420063 charon: 23412[NET] sending packet: from 217.6.20.66[4500] to 188.238.227.128[15604]
Nov 23 10:11:39 2101120420063 charon: 23425[NET] received packet: from 80.187.118.120[16385] to 217.6.20.66[4500]
Nov 23 10:11:39 2101120420063 charon: 23425[NET] waiting for data on sockets
Nov 23 10:11:39 2101120420063 charon: 23423[NET] received packet: from 80.187.118.120[16385] to 217.6.20.66[4500] (144 bytes)
Nov 23 10:11:39 2101120420063 charon: 23423[ENC] parsed INFORMATIONAL request 116 [ N(UPD_SA_ADDR) N(NATD_S_IP) N(NATD_D_IP) ]
Nov 23 10:11:39 2101120420063 charon: 23423[ENC] generating INFORMATIONAL response 116 [ N(NATD_S_IP) N(NATD_D_IP) ]
Nov 23 10:11:39 2101120420063 charon: 23423[NET] sending packet: from 217.6.20.66[4500] to 80.187.118.120[16385] (128 bytes)
Nov 23 10:11:39 2101120420063 charon: 23412[NET] sending packet: from 217.6.20.66[4500] to 80.187.118.120[16385]
Nov 23 10:11:40 2101120420063 charon: 23421[KNL] querying policy 192.168.3.24/32 === 10.0.0.0/8 in
Nov 23 10:11:40 2101120420063 charon: 23421[KNL] querying policy 192.168.3.24/32 === 10.0.0.0/8 fwd
Nov 23 10:11:40 2101120420063 charon: 23421[IKE] sending DPD request
Nov 23 10:11:40 2101120420063 charon: 23421[IKE] queueing IKE_DPD task
Nov 23 10:11:40 2101120420063 charon: 23421[IKE] activating new tasks
Status of IKE charon daemon (strongSwan 5.6.2, Linux 4.1.39-core2, i686):
uptime: 1722 minutes, since Nov 22 08:16:13 2018
malloc: sbrk 6156288, mmap 266240, used 5881304, free 274984
worker threads: 11 of 16 idle, 5/0/0/0 working, job queue: 0/0/0/0, scheduled: 61
loaded plugins: charon test-vectors unbound ldap pkcs11 aes des blowfish rc2 sha2 sha3 sha1 md4 md5 mgf1 random nonce x509 revocation constraints
acert pubkey pkcs1 pkcs7 pkcs8 pkcs12 pgp dnskey sshkey dnscert pem openssl fips-prf gmp curve25519 agent chapoly xcbc cmac hmac ctr ccm gcm ntru
newhope bliss curl files sqlite attr attr-sql kernel-netlink socket-default connmark stroke vici updown eap-identity eap-sim eap-aka eap-aka-3gpp
eap-aka-3gpp2 eap-simaka-pseudonym eap-simaka-reauth eap-md5 eap-gtc eap-mschapv2 eap-dynamic eap-radius eap-tls eap-ttls eap-peap eap-tnc
xauth-generic xauth-eap xauth-pam xauth-noauth tnc-imc tnc-imv tnc-tnccs tnccs-20 tnccs-11 tnccs-dynamic dhcp whitelist lookip error-notify certexpire
led addrblock unity counters
--
Sven Anders <anders at anduras.de> () UTF-8 Ribbon Campaign
/\ Support plain text e-mail
ANDURAS intranet security AG
Messestrasse 3 - 94036 Passau - Germany
Web: www.anduras.de - Tel: +49 (0)851-4 90 50-0 - Fax: +49 (0)851-4 90 50-55
Those who would give up essential Liberty, to purchase a little
temporary Safety, deserve neither Liberty nor Safety.
- Benjamin Franklin
More information about the Users
mailing list