Issue #2394
IP is not assigned after re-authentication
Description
Steps to reproduce:
1. Establish connection between a client and a server
conn %default keyexchange=ikev2 ike=aes256gcm128-sha512-prfsha512-ecp521,aes256ccm16-sha512-prfsha512-ecp521,aes256ctr-sha512-prfsha512-ecp521! esp=aes256ctr-sha512-ecp521-esn,aes256gcm128-sha512-ecp521-esn,aes256ccm16-sha512-prfsha512-ecp521-esn! keyingtries=%forever rekey=yes reauth=yes lifebytes=34359738368 marginbytes=1073741824 dpdaction=restart dpddelay=25s type=tunnel forceencaps=yes compress=yes mobike=yes authby=ecdsasig # only for debuging the issue ikelifetime=240s rekeyfuzz="200%" keylife=30s margintime=10s closeaction=restart inactivity=120s conn MAS auto=start ...
2. Observe
2: eth0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc pfifo_fast state UP group default qlen 1000 link/ether 54:a0:50:d7:01:a6 brd ff:ff:ff:ff:ff:ff inet 192.168.22.58/24 brd 192.168.22.255 scope global eth0 valid_lft forever preferred_lft forever inet 172.16.1.1/32 scope global eth0 <--- Leased address valid_lft forever preferred_lft forever inet6 fe80::56a0:50ff:fed7:1a6/64 scope link valid_lft forever preferred_lft forever
3. Execute
systemctl restart networking
4. Wait for re-authentication
... Jul 28 12:47:34 11[IKE] <MAS|3> scheduling reauthentication in 222s Jul 28 12:47:34 11[IKE] <MAS|3> maximum IKE_SA lifetime 232s Jul 28 12:47:34 11[IKE] <MAS|3> installing DNS server 172.16.0.1 via resolvconf Jul 28 12:47:34 11[IKE] <MAS|3> installing new virtual IP 172.16.1.1 Jul 28 12:47:34 11[IKE] <MAS|3> CHILD_SA MAS{53} established with SPIs cadb8ff4_i ca53c0a6_o and TS 172.16.1.0/24 === 172.16.0.1/32 Jul 28 12:47:34 11[IKE] <MAS|3> received AUTH_LIFETIME of 19930s, reauthentication already scheduled in 221s Jul 28 12:47:34 11[IKE] <MAS|3> peer supports MOBIKE ...
5. However, the leased IP address (i.e., 172.16.1.1) is not assigned with eth0
2: eth0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc pfifo_fast state UP group default qlen 1000 link/ether 54:a0:50:d7:01:a6 brd ff:ff:ff:ff:ff:ff inet 192.168.22.58/24 brd 192.168.22.255 scope global eth0 valid_lft forever preferred_lft forever inet6 fe80::56a0:50ff:fed7:1a6/64 scope link valid_lft forever preferred_lft forever
Version/kernel information:
ipsec --version Linux strongSwan U5.3.5/K4.4.0-87-generic
History
#1 Updated by Tobias Brunner almost 5 years ago
- Category set to kernel-interface
- Status changed from New to Feedback
3. Execute
[...]
Why? Just as a test? What events does this generate (in terms of Netlink messages, try ip monitor label
).
5. However, the leased IP address (i.e., 172.16.1.1) is not assigned with eth0
[...]
If the kernel-netlink plugin still thinks the IP is installed that's to be expected.
#2 Updated by Oleksandr Kazymyrov almost 5 years ago
3. It is an example to reproduce the issue.
after systemctl restart networking
, ip -ts monitor label
produces:
[2017-08-03T09:36:30.325890] [ADDR]Deleted 2: eth0 inet 192.168.22.58/24 brd 192.168.22.255 scope global eth0 valid_lft forever preferred_lft forever [2017-08-03T09:36:30.325982] [ROUTE]Deleted 192.168.22.0/24 dev eth0 proto kernel scope link src 192.168.22.58 [2017-08-03T09:36:30.326064] [ROUTE]Deleted broadcast 192.168.22.255 dev eth0 table local proto kernel scope link src 192.168.22.58 [2017-08-03T09:36:30.326128] [ROUTE]Deleted broadcast 192.168.22.0 dev eth0 table local proto kernel scope link src 192.168.22.58 [2017-08-03T09:36:30.326206] [ROUTE]Deleted local 192.168.22.58 dev eth0 table local proto kernel scope host src 192.168.22.58 [2017-08-03T09:36:30.326257] [ADDR]Deleted 2: eth0 inet 172.16.1.1/32 scope global eth0 valid_lft forever preferred_lft forever [2017-08-03T09:36:30.326340] [ROUTE]Deleted local 172.16.1.1 dev eth0 table local proto kernel scope host src 172.16.1.1 [2017-08-03T09:36:30.326367] [NEIGH]Deleted 192.168.22.1 dev eth0 lladdr 20:cf:30:b7:d9:ff REACHABLE [2017-08-03T09:36:30.326390] [NEIGH]Deleted 192.168.22.222 dev eth0 lladdr 08:00:27:a9:be:0c REACHABLE [2017-08-03T09:36:30.372613] [LINK]2: eth0: <BROADCAST,MULTICAST> mtu 1500 qdisc pfifo_fast state DOWN group default link/ether 54:a0:50:d7:01:a6 brd ff:ff:ff:ff:ff:ff [2017-08-03T09:36:30.372822] [NEIGH]Deleted ff02::1:ffd7:1a6 dev eth0 lladdr 33:33:ff:d7:01:a6 NOARP [2017-08-03T09:36:30.372854] [NEIGH]Deleted ff02::16 dev eth0 lladdr 33:33:00:00:00:16 NOARP [2017-08-03T09:36:30.372875] [NEIGH]Deleted ff02::2 dev eth0 lladdr 33:33:00:00:00:02 NOARP [2017-08-03T09:36:30.372896] [ROUTE]Deleted fe80::/64 dev eth0 proto kernel metric 256 pref medium [2017-08-03T09:36:30.372919] [ROUTE]Deleted ff00::/8 dev eth0 table local metric 256 pref medium [2017-08-03T09:36:30.372938] [ADDR]Deleted 2: eth0 inet6 fe80::56a0:50ff:fed7:1a6/64 scope link valid_lft forever preferred_lft forever [2017-08-03T09:36:30.372968] [ROUTE]Deleted local fe80::56a0:50ff:fed7:1a6 dev lo table local proto none metric 0 pref medium [2017-08-03T09:36:30.555651] [LINK]2: eth0: <BROADCAST,MULTICAST,UP> mtu 1500 qdisc pfifo_fast state UP group default link/ether 54:a0:50:d7:01:a6 brd ff:ff:ff:ff:ff:ff [2017-08-03T09:36:30.555850] [LINK]2: eth0: <NO-CARRIER,BROADCAST,MULTICAST,UP> mtu 1500 qdisc pfifo_fast state DOWN group default link/ether 54:a0:50:d7:01:a6 brd ff:ff:ff:ff:ff:ff [2017-08-03T09:36:33.382793] [ROUTE]ff00::/8 dev eth0 table local metric 256 pref medium [2017-08-03T09:36:33.382986] [ROUTE]fe80::/64 dev eth0 proto kernel metric 256 pref medium [2017-08-03T09:36:33.383030] [LINK]2: eth0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc pfifo_fast state UP group default link/ether 54:a0:50:d7:01:a6 brd ff:ff:ff:ff:ff:ff [2017-08-03T09:36:33.976685] [ADDR]2: eth0 inet 192.168.22.58/24 brd 192.168.22.255 scope global eth0 valid_lft forever preferred_lft forever [2017-08-03T09:36:33.976866] [ROUTE]local 192.168.22.58 dev eth0 table local proto kernel scope host src 192.168.22.58 [2017-08-03T09:36:33.976959] [ROUTE]broadcast 192.168.22.255 dev eth0 table local proto kernel scope link src 192.168.22.58 [2017-08-03T09:36:33.977039] [ROUTE]192.168.22.0/24 dev eth0 proto kernel scope link src 192.168.22.58 [2017-08-03T09:36:33.977141] [ROUTE]broadcast 192.168.22.0 dev eth0 table local proto kernel scope link src 192.168.22.58 [2017-08-03T09:36:33.978035] [NEIGH]192.168.22.222 dev eth0 lladdr 08:00:27:a9:be:0c REACHABLE [2017-08-03T09:36:33.978553] [ROUTE]default via 192.168.22.1 dev eth0 [2017-08-03T09:36:34.115995] [NEIGH]192.168.22.1 dev eth0 lladdr 20:cf:30:b7:d9:ff REACHABLE [2017-08-03T09:36:34.169784] [LINK]11: wlan1: <NO-CARRIER,BROADCAST,ALLMULTI,PROMISC,NOTRAILERS,UP> mtu 1500 qdisc mq state DOWN group default link/ieee802.11/radiotap ec:22:80:0d:a0:3b brd ff:ff:ff:ff:ff:ff [2017-08-03T09:36:34.436250] [ADDR]2: eth0 inet6 fe80::56a0:50ff:fed7:1a6/64 scope link valid_lft forever preferred_lft forever [2017-08-03T09:36:34.436539] [ROUTE]local fe80::56a0:50ff:fed7:1a6 dev lo table local proto none metric 0 pref medium [2017-08-03T09:37:14.500198] [NEIGH]192.168.22.1 dev eth0 lladdr 20:cf:30:b7:d9:ff STALE [2017-08-03T09:37:26.356229] [NEIGH]192.168.22.1 dev eth0 lladdr 20:cf:30:b7:d9:ff PROBE [2017-08-03T09:37:26.356391] [NEIGH]192.168.22.1 dev eth0 lladdr 20:cf:30:b7:d9:ff REACHABLE [2017-08-03T09:37:49.083456] [ADDR]2: eth0 inet 172.16.1.1/32 scope global eth0 valid_lft forever preferred_lft forever [2017-08-03T09:37:49.083607] [ROUTE]local 172.16.1.1 dev eth0 table local proto kernel scope host src 172.16.1.1 [2017-08-03T09:37:49.165539] [ADDR]Deleted 2: eth0 inet 172.16.1.1/32 scope global eth0 valid_lft forever preferred_lft forever [2017-08-03T09:37:49.165804] [ROUTE]Deleted local 172.16.1.1 dev eth0 table local proto kernel scope host src 172.16.1.1 [2017-08-03T09:37:49.166132] [ADDR]2: eth0 inet 172.16.1.1/32 scope global eth0 valid_lft forever preferred_lft forever [2017-08-03T09:37:49.166213] [ROUTE]local 172.16.1.1 dev eth0 table local proto kernel scope host src 172.16.1.1 [2017-08-03T09:37:49.184269] [ROUTE]172.16.0.1 via 192.168.22.1 dev eth0 table 220 proto static src 172.16.1.1 [2017-08-03T09:37:49.278080] [ADDR]Deleted 2: eth0 inet 172.16.1.1/32 scope global eth0 valid_lft forever preferred_lft forever [2017-08-03T09:37:49.278135] [ROUTE]Deleted local 172.16.1.1 dev eth0 table local proto kernel scope host src 172.16.1.1 [2017-08-03T09:38:06.724200] [NEIGH]192.168.22.1 dev eth0 lladdr 20:cf:30:b7:d9:ff STALE [2017-08-03T09:38:12.292211] [NEIGH]192.168.22.1 dev eth0 lladdr 20:cf:30:b7:d9:ff PROBE [2017-08-03T09:38:12.292405] [NEIGH]192.168.22.1 dev eth0 lladdr 20:cf:30:b7:d9:ff REACHABLE [2017-08-03T09:38:52.548204] [NEIGH]192.168.22.1 dev eth0 lladdr 20:cf:30:b7:d9:ff STALE [2017-08-03T09:39:01.412217] [NEIGH]192.168.22.1 dev eth0 lladdr 20:cf:30:b7:d9:ff PROBE [2017-08-03T09:39:01.412395] [NEIGH]192.168.22.1 dev eth0 lladdr 20:cf:30:b7:d9:ff REACHABLE
and the corresponding strongSwan logs
... Aug 3 09:37:49 04[IKE] <MAS|2> scheduling reauthentication in 92s Aug 3 09:37:49 04[IKE] <MAS|2> maximum IKE_SA lifetime 102s Aug 3 09:37:49 04[IKE] <MAS|2> installing DNS server 172.16.0.1 via resolvconf Aug 3 09:37:49 04[IKE] <MAS|2> installing new virtual IP 172.16.1.1 Aug 3 09:37:49 04[IKE] <MAS|2> CHILD_SA MAS{15} established with SPIs cec291ad_i c74da71f_o and TS 172.16.1.0/24 === 172.16.0.1/32 Aug 3 09:37:49 04[IKE] <MAS|2> received AUTH_LIFETIME of 20284s, reauthentication already scheduled in 91s Aug 3 09:37:49 04[IKE] <MAS|2> peer supports MOBIKE ...
Results of ip address show eth0
2: eth0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc pfifo_fast state UP group default qlen 1000 link/ether 54:a0:50:d7:01:a6 brd ff:ff:ff:ff:ff:ff inet 192.168.22.58/24 brd 192.168.22.255 scope global eth0 valid_lft forever preferred_lft forever inet6 fe80::56a0:50ff:fed7:1a6/64 scope link valid_lft forever preferred_lft forever
#3 Updated by Tobias Brunner almost 5 years ago
Thanks for the event output.
[2017-08-03T09:36:30.325890] [ADDR]Deleted 2: eth0 inet 192.168.22.58/24 brd 192.168.22.255 scope global eth0 valid_lft forever preferred_lft forever [2017-08-03T09:36:30.325982] [ROUTE]Deleted 192.168.22.0/24 dev eth0 proto kernel scope link src 192.168.22.58 [2017-08-03T09:36:30.326064] [ROUTE]Deleted broadcast 192.168.22.255 dev eth0 table local proto kernel scope link src 192.168.22.58 [2017-08-03T09:36:30.326128] [ROUTE]Deleted broadcast 192.168.22.0 dev eth0 table local proto kernel scope link src 192.168.22.58 [2017-08-03T09:36:30.326206] [ROUTE]Deleted local 192.168.22.58 dev eth0 table local proto kernel scope host src 192.168.22.58 [2017-08-03T09:36:30.326257] [ADDR]Deleted 2: eth0 inet 172.16.1.1/32 scope global eth0 valid_lft forever preferred_lft forever [2017-08-03T09:36:30.326340] [ROUTE]Deleted local 172.16.1.1 dev eth0 table local proto kernel scope host src 172.16.1.1 [2017-08-03T09:36:30.326367] [NEIGH]Deleted 192.168.22.1 dev eth0 lladdr 20:cf:30:b7:d9:ff REACHABLE [2017-08-03T09:36:30.326390] [NEIGH]Deleted 192.168.22.222 dev eth0 lladdr 08:00:27:a9:be:0c REACHABLE [2017-08-03T09:36:30.372613] [LINK]2: eth0: <BROADCAST,MULTICAST> mtu 1500 qdisc pfifo_fast state DOWN group default link/ether 54:a0:50:d7:01:a6 brd ff:ff:ff:ff:ff:ff [2017-08-03T09:36:30.372822] [NEIGH]Deleted ff02::1:ffd7:1a6 dev eth0 lladdr 33:33:ff:d7:01:a6 NOARP [2017-08-03T09:36:30.372854] [NEIGH]Deleted ff02::16 dev eth0 lladdr 33:33:00:00:00:16 NOARP [2017-08-03T09:36:30.372875] [NEIGH]Deleted ff02::2 dev eth0 lladdr 33:33:00:00:00:02 NOARP [2017-08-03T09:36:30.372896] [ROUTE]Deleted fe80::/64 dev eth0 proto kernel metric 256 pref medium [2017-08-03T09:36:30.372919] [ROUTE]Deleted ff00::/8 dev eth0 table local metric 256 pref medium [2017-08-03T09:36:30.372938] [ADDR]Deleted 2: eth0 inet6 fe80::56a0:50ff:fed7:1a6/64 scope link valid_lft forever preferred_lft forever [2017-08-03T09:36:30.372968] [ROUTE]Deleted local fe80::56a0:50ff:fed7:1a6 dev lo table local proto none metric 0 pref medium [2017-08-03T09:36:30.555651] [LINK]2: eth0: <BROADCAST,MULTICAST,UP> mtu 1500 qdisc pfifo_fast state UP group default link/ether 54:a0:50:d7:01:a6 brd ff:ff:ff:ff:ff:ff [2017-08-03T09:36:30.555850] [LINK]2: eth0: <NO-CARRIER,BROADCAST,MULTICAST,UP> mtu 1500 qdisc pfifo_fast state DOWN group default link/ether 54:a0:50:d7:01:a6 brd ff:ff:ff:ff:ff:ff
This seems to be the reset, i.e. all addresses and routes are removed (including the virtual IP, interestingly there is no event for the route in table 220).
Then the network connection is reestablished (I guess the delay is due to DHCP):
[2017-08-03T09:36:33.382793] [ROUTE]ff00::/8 dev eth0 table local metric 256 pref medium [2017-08-03T09:36:33.382986] [ROUTE]fe80::/64 dev eth0 proto kernel metric 256 pref medium [2017-08-03T09:36:33.383030] [LINK]2: eth0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc pfifo_fast state UP group default link/ether 54:a0:50:d7:01:a6 brd ff:ff:ff:ff:ff:ff [2017-08-03T09:36:33.976685] [ADDR]2: eth0 inet 192.168.22.58/24 brd 192.168.22.255 scope global eth0 valid_lft forever preferred_lft forever [2017-08-03T09:36:33.976866] [ROUTE]local 192.168.22.58 dev eth0 table local proto kernel scope host src 192.168.22.58 [2017-08-03T09:36:33.976959] [ROUTE]broadcast 192.168.22.255 dev eth0 table local proto kernel scope link src 192.168.22.58 [2017-08-03T09:36:33.977039] [ROUTE]192.168.22.0/24 dev eth0 proto kernel scope link src 192.168.22.58 [2017-08-03T09:36:33.977141] [ROUTE]broadcast 192.168.22.0 dev eth0 table local proto kernel scope link src 192.168.22.58 [2017-08-03T09:36:33.978035] [NEIGH]192.168.22.222 dev eth0 lladdr 08:00:27:a9:be:0c REACHABLE [2017-08-03T09:36:33.978553] [ROUTE]default via 192.168.22.1 dev eth0 [2017-08-03T09:36:34.115995] [NEIGH]192.168.22.1 dev eth0 lladdr 20:cf:30:b7:d9:ff REACHABLE [2017-08-03T09:36:34.169784] [LINK]11: wlan1: <NO-CARRIER,BROADCAST,ALLMULTI,PROMISC,NOTRAILERS,UP> mtu 1500 qdisc mq state DOWN group default link/ieee802.11/radiotap ec:22:80:0d:a0:3b brd ff:ff:ff:ff:ff:ff [2017-08-03T09:36:34.436250] [ADDR]2: eth0 inet6 fe80::56a0:50ff:fed7:1a6/64 scope link valid_lft forever preferred_lft forever [2017-08-03T09:36:34.436539] [ROUTE]local fe80::56a0:50ff:fed7:1a6 dev lo table local proto none metric 0 pref medium
According to the timestamps the following happens when the SA is reestablished:
[2017-08-03T09:37:49.083456] [ADDR]2: eth0 inet 172.16.1.1/32 scope global eth0 valid_lft forever preferred_lft forever [2017-08-03T09:37:49.083607] [ROUTE]local 172.16.1.1 dev eth0 table local proto kernel scope host src 172.16.1.1 [2017-08-03T09:37:49.165539] [ADDR]Deleted 2: eth0 inet 172.16.1.1/32 scope global eth0 valid_lft forever preferred_lft forever [2017-08-03T09:37:49.165804] [ROUTE]Deleted local 172.16.1.1 dev eth0 table local proto kernel scope host src 172.16.1.1 [2017-08-03T09:37:49.166132] [ADDR]2: eth0 inet 172.16.1.1/32 scope global eth0 valid_lft forever preferred_lft forever [2017-08-03T09:37:49.166213] [ROUTE]local 172.16.1.1 dev eth0 table local proto kernel scope host src 172.16.1.1 [2017-08-03T09:37:49.184269] [ROUTE]172.16.0.1 via 192.168.22.1 dev eth0 table 220 proto static src 172.16.1.1 [2017-08-03T09:37:49.278080] [ADDR]Deleted 2: eth0 inet 172.16.1.1/32 scope global eth0 valid_lft forever preferred_lft forever [2017-08-03T09:37:49.278135] [ROUTE]Deleted local 172.16.1.1 dev eth0 table local proto kernel scope host src 172.16.1.1
For some reason the address gets added, then removed, added again, and removed a second time. You could increase the log level for KNL to 2 to get slightly more information when the IP is installed/deleted. Do you use make-before-break reauthentication?
To get a more stable behavior you could perhaps set charon.install_virtual_ip_on = lo in strongswan.conf so the virtual IP is installed on lo
and not the outgoing interface. The code currently does only reinstall routes, but not virtual IPs.
#4 Updated by Oleksandr Kazymyrov almost 5 years ago
DPD before:
Aug 4 14:34:59 19[KNL] received a XFRM_MSG_EXPIRE Aug 4 14:34:59 19[KNL] creating rekey job for CHILD_SA ESP/0xc33457c5/192.168.22.58 Aug 4 14:34:59 19[IKE] <MAS|1> establishing CHILD_SA MAS{1} Aug 4 14:34:59 19[KNL] <MAS|1> got SPI cac1ab8a Aug 4 14:34:59 19[KNL] <MAS|1> got CPI 1787 Aug 4 14:34:59 19[ENC] <MAS|1> generating CREATE_CHILD_SA request 25 [ N(REKEY_SA) N(IPCOMP_SUP) SA No KE TSi TSr ] Aug 4 14:34:59 19[NET] <MAS|1> sending packet: from 192.168.22.58[4500] to 10.246.162.90[4500] (444 bytes) Aug 4 14:34:59 20[NET] <MAS|1> received packet: from 10.246.162.90[4500] to 192.168.22.58[4500] (344 bytes) Aug 4 14:34:59 20[ENC] <MAS|1> parsed CREATE_CHILD_SA response 25 [ N(IPCOMP_SUP) SA No KE TSi TSr ] Aug 4 14:34:59 20[KNL] <MAS|1> adding SAD entry with SPI 00001787 and reqid {1} (mark 0/0x00000000) Aug 4 14:34:59 20[KNL] <MAS|1> using compression algorithm IPCOMP_DEFLATE Aug 4 14:34:59 20[KNL] <MAS|1> adding SAD entry with SPI cac1ab8a and reqid {1} (mark 0/0x00000000) Aug 4 14:34:59 20[KNL] <MAS|1> using encryption algorithm AES_CTR with key size 288 Aug 4 14:34:59 20[KNL] <MAS|1> using integrity algorithm HMAC_SHA2_512_256 with key size 512 Aug 4 14:34:59 20[KNL] <MAS|1> using replay window of 32 packets Aug 4 14:34:59 20[KNL] <MAS|1> using extended sequence numbers (ESN) Aug 4 14:34:59 20[KNL] <MAS|1> adding SAD entry with SPI 0000cb96 and reqid {1} (mark 0/0x00000000) Aug 4 14:34:59 20[KNL] <MAS|1> using compression algorithm IPCOMP_DEFLATE Aug 4 14:34:59 20[KNL] <MAS|1> adding SAD entry with SPI cad23e60 and reqid {1} (mark 0/0x00000000) Aug 4 14:34:59 20[KNL] <MAS|1> using encryption algorithm AES_CTR with key size 288 Aug 4 14:34:59 20[KNL] <MAS|1> using integrity algorithm HMAC_SHA2_512_256 with key size 512 Aug 4 14:34:59 20[KNL] <MAS|1> using replay window of 32 packets Aug 4 14:34:59 20[KNL] <MAS|1> using extended sequence numbers (ESN) Aug 4 14:34:59 20[KNL] <MAS|1> policy 172.16.1.0/24 === 172.16.0.1/32 out (mark 0/0x00000000) already exists, increasing refcount Aug 4 14:34:59 20[KNL] <MAS|1> policy 172.16.0.1/32 === 172.16.1.0/24 in (mark 0/0x00000000) already exists, increasing refcount Aug 4 14:34:59 20[KNL] <MAS|1> policy 172.16.0.1/32 === 172.16.1.0/24 fwd (mark 0/0x00000000) already exists, increasing refcount Aug 4 14:34:59 20[KNL] <MAS|1> policy 172.16.1.0/24 === 172.16.0.1/32 out (mark 0/0x00000000) already exists, increasing refcount Aug 4 14:34:59 20[KNL] <MAS|1> updating policy 172.16.1.0/24 === 172.16.0.1/32 out (mark 0/0x00000000) Aug 4 14:34:59 20[KNL] <MAS|1> policy 172.16.0.1/32 === 172.16.1.0/24 in (mark 0/0x00000000) already exists, increasing refcount Aug 4 14:34:59 20[KNL] <MAS|1> updating policy 172.16.0.1/32 === 172.16.1.0/24 in (mark 0/0x00000000) Aug 4 14:34:59 20[KNL] <MAS|1> policy 172.16.0.1/32 === 172.16.1.0/24 fwd (mark 0/0x00000000) already exists, increasing refcount Aug 4 14:34:59 20[KNL] <MAS|1> updating policy 172.16.0.1/32 === 172.16.1.0/24 fwd (mark 0/0x00000000) Aug 4 14:34:59 20[KNL] <MAS|1> getting a local address in traffic selector 172.16.1.0/24 Aug 4 14:34:59 20[KNL] <MAS|1> no local address found in traffic selector 172.16.1.0/24 Aug 4 14:34:59 20[IKE] <MAS|1> CHILD_SA MAS{12} established with SPIs cac1ab8a_i cad23e60_o and TS 172.16.1.0/24 === 172.16.0.1/32 Aug 4 14:34:59 20[KNL] <MAS|1> querying SAD entry with SPI c33457c5 (mark 0/0x00000000) Aug 4 14:34:59 20[KNL] <MAS|1> querying SAD entry with SPI c08d1db0 (mark 0/0x00000000) Aug 4 14:34:59 20[IKE] <MAS|1> closing CHILD_SA MAS{11} with SPIs c33457c5_i (0 bytes) c08d1db0_o (0 bytes) and TS 172.16.1.0/24 === 172.16.0.1/32 Aug 4 14:34:59 20[IKE] <MAS|1> sending DELETE for ESP CHILD_SA with SPI c33457c5 Aug 4 14:34:59 20[ENC] <MAS|1> generating INFORMATIONAL request 26 [ D ] Aug 4 14:34:59 20[NET] <MAS|1> sending packet: from 192.168.22.58[4500] to 10.246.162.90[4500] (69 bytes) Aug 4 14:34:59 22[NET] <MAS|1> received packet: from 10.246.162.90[4500] to 192.168.22.58[4500] (69 bytes) Aug 4 14:34:59 22[ENC] <MAS|1> parsed INFORMATIONAL response 26 [ D ] Aug 4 14:34:59 22[IKE] <MAS|1> received DELETE for ESP CHILD_SA with SPI c08d1db0 Aug 4 14:34:59 22[IKE] <MAS|1> CHILD_SA closed Aug 4 14:34:59 22[KNL] <MAS|1> deleting policy 172.16.1.0/24 === 172.16.0.1/32 out (mark 0/0x00000000) Aug 4 14:34:59 22[KNL] <MAS|1> policy still used by another CHILD_SA, not removed Aug 4 14:34:59 22[KNL] <MAS|1> deleting policy 172.16.0.1/32 === 172.16.1.0/24 in (mark 0/0x00000000) Aug 4 14:34:59 22[KNL] <MAS|1> policy still used by another CHILD_SA, not removed Aug 4 14:34:59 22[KNL] <MAS|1> deleting policy 172.16.0.1/32 === 172.16.1.0/24 fwd (mark 0/0x00000000) Aug 4 14:34:59 22[KNL] <MAS|1> policy still used by another CHILD_SA, not removed Aug 4 14:34:59 22[KNL] <MAS|1> deleting policy 172.16.1.0/24 === 172.16.0.1/32 out (mark 0/0x00000000) Aug 4 14:34:59 22[KNL] <MAS|1> policy still used by another CHILD_SA, not removed Aug 4 14:34:59 22[KNL] <MAS|1> deleting policy 172.16.0.1/32 === 172.16.1.0/24 in (mark 0/0x00000000) Aug 4 14:34:59 22[KNL] <MAS|1> policy still used by another CHILD_SA, not removed Aug 4 14:34:59 22[KNL] <MAS|1> deleting policy 172.16.0.1/32 === 172.16.1.0/24 fwd (mark 0/0x00000000) Aug 4 14:34:59 22[KNL] <MAS|1> policy still used by another CHILD_SA, not removed Aug 4 14:34:59 22[KNL] <MAS|1> deleting SAD entry with SPI 000057cd (mark 0/0x00000000) Aug 4 14:34:59 22[KNL] <MAS|1> deleted SAD entry with SPI 000057cd (mark 0/0x00000000) Aug 4 14:34:59 22[KNL] <MAS|1> deleting SAD entry with SPI c33457c5 (mark 0/0x00000000) Aug 4 14:34:59 22[KNL] <MAS|1> deleted SAD entry with SPI c33457c5 (mark 0/0x00000000) Aug 4 14:34:59 22[KNL] <MAS|1> deleting SAD entry with SPI 00007526 (mark 0/0x00000000) Aug 4 14:34:59 22[KNL] <MAS|1> deleted SAD entry with SPI 00007526 (mark 0/0x00000000) Aug 4 14:34:59 22[KNL] <MAS|1> deleting SAD entry with SPI c08d1db0 (mark 0/0x00000000) Aug 4 14:34:59 22[KNL] <MAS|1> deleted SAD entry with SPI c08d1db0 (mark 0/0x00000000)
systemctl restart networking
Aug 4 14:35:02 16[IKE] <MAS|1> reauthenticating IKE_SA MAS[1] Aug 4 14:35:02 16[KNL] <MAS|1> 192.168.22.58 is on interface eth0 Aug 4 14:35:02 16[IKE] <MAS|1> installing new virtual IP 172.16.1.1 Aug 4 14:35:02 16[KNL] <MAS|1> virtual IP 172.16.1.1 installed on eth0 Aug 4 14:35:02 16[IKE] <MAS|1> initiating IKE_SA MAS[2] to 10.246.162.90 Aug 4 14:35:02 16[ENC] <MAS|1> generating IKE_SA_INIT request 0 [ SA KE No N(NATD_S_IP) N(NATD_D_IP) N(HASH_ALG) ] Aug 4 14:35:02 16[NET] <MAS|1> sending packet: from 192.168.22.58[4500] to 10.246.162.90[4500] (412 bytes) Aug 4 14:35:02 05[NET] <MAS|2> received packet: from 10.246.162.90[4500] to 192.168.22.58[4500] (409 bytes) Aug 4 14:35:02 05[ENC] <MAS|2> parsed IKE_SA_INIT response 0 [ SA KE No N(NATD_S_IP) N(NATD_D_IP) CERTREQ N(HASH_ALG) N(MULT_AUTH) ] Aug 4 14:35:02 05[IKE] <MAS|2> local host is behind NAT, sending keep alives Aug 4 14:35:02 05[IKE] <MAS|2> remote host is behind NAT ... Aug 4 14:35:02 05[IKE] <MAS|2> establishing CHILD_SA MAS Aug 4 14:35:02 05[KNL] <MAS|2> got SPI cd3b3392 Aug 4 14:35:02 05[KNL] <MAS|2> got CPI 30b5 Aug 4 14:35:02 05[ENC] <MAS|2> generating IKE_AUTH request 1 [ IDi CERT IDr AUTH CPRQ(ADDR DNS) N(IPCOMP_SUP) SA TSi TSr N(MOBIKE_SUP) N(NO_ADD_ADDR) N(MULT_AUTH) N(EAP_ONLY) ] Aug 4 14:35:02 05[NET] <MAS|2> sending packet: from 192.168.22.58[4500] to 10.246.162.90[4500] (1284 bytes) Aug 4 14:35:02 25[NET] <MAS|2> received packet: from 10.246.162.90[4500] to 192.168.22.58[4500] (2394 bytes) ... Aug 4 14:35:02 25[IKE] <MAS|2> scheduling reauthentication in 98s Aug 4 14:35:02 25[IKE] <MAS|2> maximum IKE_SA lifetime 108s Aug 4 14:35:02 25[IKE] <MAS|2> installing DNS server 172.16.0.1 via resolvconf Aug 4 14:35:02 25[KNL] <MAS|2> deleting virtual IP 172.16.1.1 Aug 4 14:35:02 25[KNL] <MAS|2> 192.168.22.58 is on interface eth0 Aug 4 14:35:02 25[IKE] <MAS|2> installing new virtual IP 172.16.1.1 Aug 4 14:35:02 25[KNL] <MAS|2> virtual IP 172.16.1.1 installed on eth0 Aug 4 14:35:02 25[KNL] <MAS|2> adding SAD entry with SPI 000030b5 and reqid {1} (mark 0/0x00000000) Aug 4 14:35:02 25[KNL] <MAS|2> using compression algorithm IPCOMP_DEFLATE Aug 4 14:35:02 25[KNL] <MAS|2> adding SAD entry with SPI cd3b3392 and reqid {1} (mark 0/0x00000000) Aug 4 14:35:02 25[KNL] <MAS|2> using encryption algorithm AES_CTR with key size 288 Aug 4 14:35:02 25[KNL] <MAS|2> using integrity algorithm HMAC_SHA2_512_256 with key size 512 Aug 4 14:35:02 25[KNL] <MAS|2> using replay window of 32 packets Aug 4 14:35:02 25[KNL] <MAS|2> using extended sequence numbers (ESN) Aug 4 14:35:02 25[KNL] <MAS|2> adding SAD entry with SPI 00001b8e and reqid {1} (mark 0/0x00000000) Aug 4 14:35:02 25[KNL] <MAS|2> using compression algorithm IPCOMP_DEFLATE Aug 4 14:35:02 25[KNL] <MAS|2> adding SAD entry with SPI c02a32f8 and reqid {1} (mark 0/0x00000000) Aug 4 14:35:02 25[KNL] <MAS|2> using encryption algorithm AES_CTR with key size 288 Aug 4 14:35:02 25[KNL] <MAS|2> using integrity algorithm HMAC_SHA2_512_256 with key size 512 Aug 4 14:35:02 25[KNL] <MAS|2> using replay window of 32 packets Aug 4 14:35:02 25[KNL] <MAS|2> using extended sequence numbers (ESN) Aug 4 14:35:02 25[KNL] <MAS|2> policy 172.16.1.0/24 === 172.16.0.1/32 out (mark 0/0x00000000) already exists, increasing refcount Aug 4 14:35:02 25[KNL] <MAS|2> policy 172.16.0.1/32 === 172.16.1.0/24 in (mark 0/0x00000000) already exists, increasing refcount Aug 4 14:35:02 25[KNL] <MAS|2> policy 172.16.0.1/32 === 172.16.1.0/24 fwd (mark 0/0x00000000) already exists, increasing refcount Aug 4 14:35:02 25[KNL] <MAS|2> policy 172.16.1.0/24 === 172.16.0.1/32 out (mark 0/0x00000000) already exists, increasing refcount Aug 4 14:35:02 25[KNL] <MAS|2> updating policy 172.16.1.0/24 === 172.16.0.1/32 out (mark 0/0x00000000) Aug 4 14:35:02 25[KNL] <MAS|2> policy 172.16.0.1/32 === 172.16.1.0/24 in (mark 0/0x00000000) already exists, increasing refcount Aug 4 14:35:02 25[KNL] <MAS|2> updating policy 172.16.0.1/32 === 172.16.1.0/24 in (mark 0/0x00000000) Aug 4 14:35:02 25[KNL] <MAS|2> policy 172.16.0.1/32 === 172.16.1.0/24 fwd (mark 0/0x00000000) already exists, increasing refcount Aug 4 14:35:02 25[KNL] <MAS|2> updating policy 172.16.0.1/32 === 172.16.1.0/24 fwd (mark 0/0x00000000) Aug 4 14:35:02 25[KNL] <MAS|2> getting a local address in traffic selector 172.16.1.0/24 Aug 4 14:35:02 25[KNL] <MAS|2> using host 172.16.1.1 Aug 4 14:35:02 25[KNL] <MAS|2> using 192.168.22.1 as nexthop to reach 10.246.162.90/32 Aug 4 14:35:02 25[KNL] <MAS|2> 192.168.22.58 is on interface eth0 Aug 4 14:35:02 25[IKE] <MAS|2> CHILD_SA MAS{13} established with SPIs cd3b3392_i c02a32f8_o and TS 172.16.1.0/24 === 172.16.0.1/32 Aug 4 14:35:02 25[KNL] <MAS|2> 192.168.22.58 is on interface eth0 Aug 4 14:35:02 30[KNL] getting iface index for eth0 Aug 4 14:35:02 25[IKE] <MAS|2> received AUTH_LIFETIME of 20176s, reauthentication already scheduled in 98s Aug 4 14:35:02 25[IKE] <MAS|2> peer supports MOBIKE Aug 4 14:35:02 31[IKE] <MAS|1> deleting IKE_SA MAS[1] between ... Aug 4 14:35:02 31[IKE] <MAS|1> sending DELETE for IKE_SA MAS[1] Aug 4 14:35:02 31[ENC] <MAS|1> generating INFORMATIONAL request 27 [ D ] Aug 4 14:35:02 31[NET] <MAS|1> sending packet: from 192.168.22.58[4500] to 10.246.162.90[4500] (65 bytes) Aug 4 14:35:02 04[NET] <MAS|1> received packet: from 10.246.162.90[4500] to 192.168.22.58[4500] (57 bytes) Aug 4 14:35:02 04[ENC] <MAS|1> parsed INFORMATIONAL response 27 [ ] Aug 4 14:35:02 04[IKE] <MAS|1> IKE_SA deleted Aug 4 14:35:02 04[KNL] <MAS|1> deleting policy 172.16.1.0/24 === 172.16.0.1/32 out (mark 0/0x00000000) Aug 4 14:35:02 04[KNL] <MAS|1> policy still used by another CHILD_SA, not removed Aug 4 14:35:02 04[KNL] <MAS|1> deleting policy 172.16.0.1/32 === 172.16.1.0/24 in (mark 0/0x00000000) Aug 4 14:35:02 04[KNL] <MAS|1> policy still used by another CHILD_SA, not removed Aug 4 14:35:02 04[KNL] <MAS|1> deleting policy 172.16.0.1/32 === 172.16.1.0/24 fwd (mark 0/0x00000000) Aug 4 14:35:02 04[KNL] <MAS|1> policy still used by another CHILD_SA, not removed Aug 4 14:35:02 04[KNL] <MAS|1> deleting policy 172.16.1.0/24 === 172.16.0.1/32 out (mark 0/0x00000000) Aug 4 14:35:02 04[KNL] <MAS|1> policy still used by another CHILD_SA, not removed Aug 4 14:35:02 04[KNL] <MAS|1> deleting policy 172.16.0.1/32 === 172.16.1.0/24 in (mark 0/0x00000000) Aug 4 14:35:02 04[KNL] <MAS|1> policy still used by another CHILD_SA, not removed Aug 4 14:35:02 04[KNL] <MAS|1> deleting policy 172.16.0.1/32 === 172.16.1.0/24 fwd (mark 0/0x00000000) Aug 4 14:35:02 04[KNL] <MAS|1> policy still used by another CHILD_SA, not removed Aug 4 14:35:02 04[KNL] <MAS|1> deleting SAD entry with SPI 00001787 (mark 0/0x00000000) Aug 4 14:35:02 04[KNL] <MAS|1> deleted SAD entry with SPI 00001787 (mark 0/0x00000000) Aug 4 14:35:02 04[KNL] <MAS|1> deleting SAD entry with SPI cac1ab8a (mark 0/0x00000000) Aug 4 14:35:02 04[KNL] <MAS|1> deleted SAD entry with SPI cac1ab8a (mark 0/0x00000000) Aug 4 14:35:02 04[KNL] <MAS|1> deleting SAD entry with SPI 0000cb96 (mark 0/0x00000000) Aug 4 14:35:02 04[KNL] <MAS|1> deleted SAD entry with SPI 0000cb96 (mark 0/0x00000000) Aug 4 14:35:02 04[KNL] <MAS|1> deleting SAD entry with SPI cad23e60 (mark 0/0x00000000) Aug 4 14:35:02 04[KNL] <MAS|1> deleted SAD entry with SPI cad23e60 (mark 0/0x00000000) Aug 4 14:35:02 04[KNL] <MAS|1> deleting virtual IP 172.16.1.1 Aug 4 14:35:04 02[KNL] <MAS|2> querying SAD entry with SPI cd3b3392 (mark 0/0x00000000) Aug 4 14:35:04 02[KNL] <MAS|2> querying SAD entry with SPI c02a32f8 (mark 0/0x00000000)
DPD after:
Aug 4 14:35:05 13[KNL] received a XFRM_MSG_EXPIRE Aug 4 14:35:05 13[KNL] creating rekey job for CHILD_SA ESP/0xcd3b3392/192.168.22.58 Aug 4 14:35:05 13[IKE] <MAS|2> establishing CHILD_SA MAS{1} Aug 4 14:35:05 13[KNL] <MAS|2> got SPI c5cf7528 Aug 4 14:35:05 13[KNL] <MAS|2> got CPI 939c Aug 4 14:35:05 13[ENC] <MAS|2> generating CREATE_CHILD_SA request 2 [ N(REKEY_SA) N(IPCOMP_SUP) SA No KE TSi TSr ] Aug 4 14:35:05 13[NET] <MAS|2> sending packet: from 192.168.22.58[4500] to 10.246.162.90[4500] (444 bytes) Aug 4 14:35:05 15[NET] <MAS|2> received packet: from 10.246.162.90[4500] to 192.168.22.58[4500] (344 bytes) Aug 4 14:35:05 15[ENC] <MAS|2> parsed CREATE_CHILD_SA response 2 [ N(IPCOMP_SUP) SA No KE TSi TSr ] Aug 4 14:35:05 15[KNL] <MAS|2> adding SAD entry with SPI 0000939c and reqid {1} (mark 0/0x00000000) Aug 4 14:35:05 15[KNL] <MAS|2> using compression algorithm IPCOMP_DEFLATE Aug 4 14:35:05 15[KNL] <MAS|2> adding SAD entry with SPI c5cf7528 and reqid {1} (mark 0/0x00000000) Aug 4 14:35:05 15[KNL] <MAS|2> using encryption algorithm AES_CTR with key size 288 Aug 4 14:35:05 15[KNL] <MAS|2> using integrity algorithm HMAC_SHA2_512_256 with key size 512 Aug 4 14:35:05 15[KNL] <MAS|2> using replay window of 32 packets Aug 4 14:35:05 15[KNL] <MAS|2> using extended sequence numbers (ESN) Aug 4 14:35:05 15[KNL] <MAS|2> adding SAD entry with SPI 00009b84 and reqid {1} (mark 0/0x00000000) Aug 4 14:35:05 15[KNL] <MAS|2> using compression algorithm IPCOMP_DEFLATE Aug 4 14:35:05 15[KNL] <MAS|2> adding SAD entry with SPI c4731c8c and reqid {1} (mark 0/0x00000000) Aug 4 14:35:05 15[KNL] <MAS|2> using encryption algorithm AES_CTR with key size 288 Aug 4 14:35:05 15[KNL] <MAS|2> using integrity algorithm HMAC_SHA2_512_256 with key size 512 Aug 4 14:35:05 15[KNL] <MAS|2> using replay window of 32 packets Aug 4 14:35:05 15[KNL] <MAS|2> using extended sequence numbers (ESN) Aug 4 14:35:05 15[KNL] <MAS|2> policy 172.16.1.0/24 === 172.16.0.1/32 out (mark 0/0x00000000) already exists, increasing refcount Aug 4 14:35:05 15[KNL] <MAS|2> policy 172.16.0.1/32 === 172.16.1.0/24 in (mark 0/0x00000000) already exists, increasing refcount Aug 4 14:35:05 15[KNL] <MAS|2> policy 172.16.0.1/32 === 172.16.1.0/24 fwd (mark 0/0x00000000) already exists, increasing refcount Aug 4 14:35:05 15[KNL] <MAS|2> policy 172.16.1.0/24 === 172.16.0.1/32 out (mark 0/0x00000000) already exists, increasing refcount Aug 4 14:35:05 15[KNL] <MAS|2> updating policy 172.16.1.0/24 === 172.16.0.1/32 out (mark 0/0x00000000) Aug 4 14:35:05 15[KNL] <MAS|2> policy 172.16.0.1/32 === 172.16.1.0/24 in (mark 0/0x00000000) already exists, increasing refcount Aug 4 14:35:05 15[KNL] <MAS|2> updating policy 172.16.0.1/32 === 172.16.1.0/24 in (mark 0/0x00000000) Aug 4 14:35:05 15[KNL] <MAS|2> policy 172.16.0.1/32 === 172.16.1.0/24 fwd (mark 0/0x00000000) already exists, increasing refcount Aug 4 14:35:05 15[KNL] <MAS|2> updating policy 172.16.0.1/32 === 172.16.1.0/24 fwd (mark 0/0x00000000) Aug 4 14:35:05 15[KNL] <MAS|2> getting a local address in traffic selector 172.16.1.0/24 Aug 4 14:35:05 15[KNL] <MAS|2> no local address found in traffic selector 172.16.1.0/24 Aug 4 14:35:05 15[IKE] <MAS|2> CHILD_SA MAS{14} established with SPIs c5cf7528_i c4731c8c_o and TS 172.16.1.0/24 === 172.16.0.1/32 Aug 4 14:35:05 15[KNL] <MAS|2> querying SAD entry with SPI cd3b3392 (mark 0/0x00000000) Aug 4 14:35:05 15[KNL] <MAS|2> querying SAD entry with SPI c02a32f8 (mark 0/0x00000000) Aug 4 14:35:05 15[IKE] <MAS|2> closing CHILD_SA MAS{13} with SPIs cd3b3392_i (0 bytes) c02a32f8_o (0 bytes) and TS 172.16.1.0/24 === 172.16.0.1/32 Aug 4 14:35:05 15[IKE] <MAS|2> sending DELETE for ESP CHILD_SA with SPI cd3b3392 Aug 4 14:35:05 15[ENC] <MAS|2> generating INFORMATIONAL request 3 [ D ] Aug 4 14:35:05 15[NET] <MAS|2> sending packet: from 192.168.22.58[4500] to 10.246.162.90[4500] (69 bytes) Aug 4 14:35:05 17[NET] <MAS|2> received packet: from 10.246.162.90[4500] to 192.168.22.58[4500] (69 bytes) Aug 4 14:35:05 17[ENC] <MAS|2> parsed INFORMATIONAL response 3 [ D ] Aug 4 14:35:05 17[IKE] <MAS|2> received DELETE for ESP CHILD_SA with SPI c02a32f8 Aug 4 14:35:05 17[IKE] <MAS|2> CHILD_SA closed Aug 4 14:35:05 17[KNL] <MAS|2> deleting policy 172.16.1.0/24 === 172.16.0.1/32 out (mark 0/0x00000000) Aug 4 14:35:05 17[KNL] <MAS|2> policy still used by another CHILD_SA, not removed Aug 4 14:35:05 17[KNL] <MAS|2> deleting policy 172.16.0.1/32 === 172.16.1.0/24 in (mark 0/0x00000000) Aug 4 14:35:05 17[KNL] <MAS|2> policy still used by another CHILD_SA, not removed Aug 4 14:35:05 17[KNL] <MAS|2> deleting policy 172.16.0.1/32 === 172.16.1.0/24 fwd (mark 0/0x00000000) Aug 4 14:35:05 17[KNL] <MAS|2> policy still used by another CHILD_SA, not removed Aug 4 14:35:05 17[KNL] <MAS|2> deleting policy 172.16.1.0/24 === 172.16.0.1/32 out (mark 0/0x00000000) Aug 4 14:35:05 17[KNL] <MAS|2> policy still used by another CHILD_SA, not removed Aug 4 14:35:05 17[KNL] <MAS|2> deleting policy 172.16.0.1/32 === 172.16.1.0/24 in (mark 0/0x00000000) Aug 4 14:35:05 17[KNL] <MAS|2> policy still used by another CHILD_SA, not removed Aug 4 14:35:05 17[KNL] <MAS|2> deleting policy 172.16.0.1/32 === 172.16.1.0/24 fwd (mark 0/0x00000000) Aug 4 14:35:05 17[KNL] <MAS|2> policy still used by another CHILD_SA, not removed Aug 4 14:35:05 17[KNL] <MAS|2> deleting SAD entry with SPI 000030b5 (mark 0/0x00000000) Aug 4 14:35:05 17[KNL] <MAS|2> deleted SAD entry with SPI 000030b5 (mark 0/0x00000000) Aug 4 14:35:05 17[KNL] <MAS|2> deleting SAD entry with SPI cd3b3392 (mark 0/0x00000000) Aug 4 14:35:05 17[KNL] <MAS|2> deleted SAD entry with SPI cd3b3392 (mark 0/0x00000000) Aug 4 14:35:05 17[KNL] <MAS|2> deleting SAD entry with SPI 00001b8e (mark 0/0x00000000) Aug 4 14:35:05 17[KNL] <MAS|2> deleted SAD entry with SPI 00001b8e (mark 0/0x00000000) Aug 4 14:35:05 17[KNL] <MAS|2> deleting SAD entry with SPI c02a32f8 (mark 0/0x00000000) Aug 4 14:35:05 17[KNL] <MAS|2> deleted SAD entry with SPI c02a32f8 (mark 0/0x00000000)
Do you use make-before-break reauthentication?
Setting make_before_break = no
resolves the isse. However, the IP address will be reinstallaed only after expiration of ikelifetime
. Can this situation be handled by strongSwan prior ikelifetime is ended?
To get a more stable behavior you could perhaps set charon.install_virtual_ip_on = lo ...
Hmm... I have not imagined that virtual IP can be installed in such a way. This configuration fixed the issue permanently even with make_before_break = yes
.
#5 Updated by Tobias Brunner almost 5 years ago
Do you use make-before-break reauthentication?
Setting
make_before_break = no
resolves the isse.
I see. From the log it's clear what happens. First the new SA is initiated and the VIP is copied to it (in theory this increases the refcount, as the VIP is already in use, however, because the VIP was deleted in the kernel, this is like a new install):
Aug 4 14:35:02 16[IKE] <MAS|1> reauthenticating IKE_SA MAS[1] Aug 4 14:35:02 16[KNL] <MAS|1> 192.168.22.58 is on interface eth0 Aug 4 14:35:02 16[IKE] <MAS|1> installing new virtual IP 172.16.1.1 Aug 4 14:35:02 16[KNL] <MAS|1> virtual IP 172.16.1.1 installed on eth0 Aug 4 14:35:02 16[IKE] <MAS|1> initiating IKE_SA MAS[2] to 10.246.162.90
The following is caused by a call to clear_virtual_ips()
followed by adding the actually assigned VIPs (again, this should, in theory, only affect the reference count):
Aug 4 14:35:02 25[KNL] <MAS|2> deleting virtual IP 172.16.1.1 Aug 4 14:35:02 25[KNL] <MAS|2> 192.168.22.58 is on interface eth0 Aug 4 14:35:02 25[IKE] <MAS|2> installing new virtual IP 172.16.1.1 Aug 4 14:35:02 25[KNL] <MAS|2> virtual IP 172.16.1.1 installed on eth0
Later the replaced IKE_SA is deleted, which unfortunately removes the VIP:
Aug 4 14:35:02 04[KNL] <MAS|1> deleting virtual IP 172.16.1.1
However, the IP address will be reinstallaed only after expiration of
ikelifetime
.
Yes, without make-before-break reauthentication the old IKE_SA is deleted first and will not affect the VIP installed by the new IKE_SA later. But in both cases the virtual IP is not reinstalled.
Can this situation be handled by strongSwan prior ikelifetime is ended?
Theoretically, the VIP could be reinstalled if the interface comes up gain but that could be tricky due to race conditions (I'd have to take a close look, though). And...
To get a more stable behavior you could perhaps set charon.install_virtual_ip_on = lo ...
Hmm... I have not imagined that virtual IP can be installed in such a way. This configuration fixed the issue permanently even with
make_before_break = yes
.
...this workaround usually works fine in dynamic environments. Edit: In dynamic environments where the network connectivity changes significantly (e.g. the IP changes, or a switch from one to another interface occurs) the virtual IP would be re-installed automatically on the outbound interface when the source IP address of the CHILD_SA is updated. So this is mainly a problem if interfaces (or even just IPs) disappear and then reappear with the same IPs/routes.