I am not an expert on IPSec and its terminology, so I apologize if I write something inaccurate, but I try to do my best. I have an IPSec s2s tunnel between Palo Alto PA-220 and Mikrotik RB4011 with IKEv2. The RB4011 is behind NAT so it initiates the connection, Palo has a public IP. The tunnel works, but from time to time the rekey of IPSec keys procedure fails. On both devices, the IPSec keys lifetime is configured to one hour. The whole rekey process is going well until Palo removes the old keys. Firstly Palo sends delete message to the Mikrotik, then Palo deletes the keys and sometimes after removing the keys Palo receives delete message from the Mikrotik. When the delete message arrives, Palo no longer has the old keys and they cannot find them. This will cause that Palo aborts the whole connection and negotiates it again. This, of course, causes outages for several minutes. The failure is visible in the following parts of logs. ("x.x.x.x" is the public IP of Palo, "y.y.y.y" is the public IP of Mikrotik).
The Mikrotik logs:
Code: Select all
Dec/04/2020 04:48:14 ipsec IPsec-SA expired: ESP/Tunnel x.x.x.x[4500]->192.168.1.43[4500] spi=0x2114872
Dec/04/2020 04:48:14 ipsec ike2 expire 0xb9ff9cab
Dec/04/2020 04:48:14 ipsec init child rekey
Dec/04/2020 04:48:14 ipsec IPsec-SA expired: ESP/Tunnel 192.168.1.43[4500]->x.x.x.x[4500] spi=0xb9ff9cab
Dec/04/2020 04:48:14 ipsec init child continue
Dec/04/2020 04:48:14 ipsec offering proto: 3
Dec/04/2020 04:48:14 ipsec proposal #1
Dec/04/2020 04:48:14 ipsec enc: aes256-gcm
Dec/04/2020 04:48:14 ipsec dh: ecp256
Dec/04/2020 04:48:14 ipsec adding payload: NONCE
Dec/04/2020 04:48:14 ipsec adding payload: KE
Dec/04/2020 04:48:14 ipsec adding notify: REKEY_SA
Dec/04/2020 04:48:14 ipsec adding payload: SA
Dec/04/2020 04:48:14 ipsec initiator selector: 10.32.0.0/19
Dec/04/2020 04:48:14 ipsec adding payload: TS_I
Dec/04/2020 04:48:14 ipsec responder selector: 10.0.0.0/11
Dec/04/2020 04:48:14 ipsec adding payload: TS_R
Dec/04/2020 04:48:14 ipsec <- ike2 request, exchange: CREATE_CHILD_SA:51 x.x.x.x[4500] 462df566fa0f9585:63413b5a87067e91
Dec/04/2020 04:48:14 ipsec adding payload: ENC
Dec/04/2020 04:48:14 ipsec -> ike2 reply, exchange: CREATE_CHILD_SA:51 x.x.x.x[4500] 462df566fa0f9585:63413b5a87067e91
Dec/04/2020 04:48:14 ipsec payload seen: ENC (276 bytes)
Dec/04/2020 04:48:14 ipsec processing payload: ENC
Dec/04/2020 04:48:14 ipsec payload seen: NOTIFY (8 bytes)
Dec/04/2020 04:48:14 ipsec payload seen: SA (44 bytes)
Dec/04/2020 04:48:14 ipsec payload seen: NONCE (36 bytes)
Dec/04/2020 04:48:14 ipsec payload seen: KE (72 bytes)
Dec/04/2020 04:48:14 ipsec payload seen: TS_I (24 bytes)
Dec/04/2020 04:48:14 ipsec payload seen: TS_R (24 bytes)
Dec/04/2020 04:48:14 ipsec create child: initiator finish
Dec/04/2020 04:48:14 ipsec processing payloads: NOTIFY
Dec/04/2020 04:48:14 ipsec notify: ESP_TFC_PADDING_NOT_SUPPORTED
Dec/04/2020 04:48:14 ipsec peer selected tunnel mode
Dec/04/2020 04:48:14 ipsec processing payload: TS_I
Dec/04/2020 04:48:14 ipsec 10.32.0.0/19
Dec/04/2020 04:48:14 ipsec processing payload: TS_R
Dec/04/2020 04:48:14 ipsec 10.0.0.0/11
Dec/04/2020 04:48:14 ipsec checking: 10.32.0.0/19 <=> 10.0.0.0/11
Dec/04/2020 04:48:14 ipsec processing payload: SA
Dec/04/2020 04:48:14 ipsec IKE Protocol: ESP
Dec/04/2020 04:48:14 ipsec proposal #1
Dec/04/2020 04:48:14 ipsec enc: aes256-gcm
Dec/04/2020 04:48:14 ipsec dh: ecp256
Dec/04/2020 04:48:14 ipsec matched proposal:
Dec/04/2020 04:48:14 ipsec proposal #1
Dec/04/2020 04:48:14 ipsec enc: aes256-gcm
Dec/04/2020 04:48:14 ipsec dh: ecp256
Dec/04/2020 04:48:14 ipsec processing payload: NONCE
Dec/04/2020 04:48:14 ipsec processing payload: KE
Dec/04/2020 04:48:14 ipsec IPsec-SA established: x.x.x.x[4500]->192.168.1.43[4500] spi=0x8663e51
Dec/04/2020 04:48:14 ipsec IPsec-SA established: 192.168.1.43[4500]->x.x.x.x[4500] spi=0xf3d4ffe0
Dec/04/2020 04:48:14 ipsec adding payload: DELETE
Dec/04/2020 04:48:14 ipsec <- ike2 request, exchange: INFORMATIONAL:52 x.x.x.x[4500] 462df566fa0f9585:63413b5a87067e91
Dec/04/2020 04:48:14 ipsec adding payload: ENC
Dec/04/2020 04:48:14 ipsec -> ike2 request, exchange: INFORMATIONAL:1 x.x.x.x[4500] 462df566fa0f9585:63413b5a87067e91
Dec/04/2020 04:48:14 ipsec payload seen: ENC (68 bytes)
Dec/04/2020 04:48:14 ipsec processing payload: ENC
Dec/04/2020 04:48:14 ipsec payload seen: DELETE (12 bytes)
Dec/04/2020 04:48:14 ipsec request collision
Dec/04/2020 04:48:14 ipsec reply notify: TEMPORARY_FAILURE
Dec/04/2020 04:48:14 ipsec adding notify: TEMPORARY_FAILURE
Dec/04/2020 04:48:14 ipsec <- ike2 reply, exchange: INFORMATIONAL:1 x.x.x.x[4500] 462df566fa0f9585:63413b5a87067e91
Dec/04/2020 04:48:14 ipsec adding payload: ENC
Dec/04/2020 04:48:14 ipsec -> ike2 reply, exchange: INFORMATIONAL:52 x.x.x.x[4500] 462df566fa0f9585:63413b5a87067e91
Dec/04/2020 04:48:14 ipsec payload seen: ENC (68 bytes)
Dec/04/2020 04:48:14 ipsec processing payload: ENC
Dec/04/2020 04:48:14 ipsec respond: info
Dec/04/2020 04:48:14 ipsec got reply
Dec/04/2020 04:48:14 ipsec IPsec-SA killing: x.x.x.x[4500]->192.168.1.43[4500] spi=0x2114872
Dec/04/2020 04:48:14 ipsec IPsec-SA killing: 192.168.1.43[4500]->x.x.x.x[4500] spi=0xb9ff9cab
Dec/04/2020 04:50:14 ipsec sending dpd packet
Dec/04/2020 04:50:14 ipsec <- ike2 request, exchange: INFORMATIONAL:53 x.x.x.x[4500] 462df566fa0f9585:63413b5a87067e91
Dec/04/2020 04:50:14 ipsec adding payload: ENC
Dec/04/2020 04:50:19 ipsec dpd: retransmit
Dec/04/2020 04:50:24 ipsec dpd: retransmit
Dec/04/2020 04:50:29 ipsec dpd: retransmit
Dec/04/2020 04:50:34 ipsec dpd: retransmit
Dec/04/2020 04:50:39 ipsec dpd: max retransmit failures reached
Dec/04/2020 04:50:39 ipsec IPsec-SA killing: x.x.x.x[4500]->192.168.1.43[4500] spi=0x8663e51
Dec/04/2020 04:50:39 ipsec IPsec-SA killing: 192.168.1.43[4500]->x.x.x.x[4500] spi=0xf3d4ffe0
Dec/04/2020 04:50:39 ipsec adding payload: DELETE
Dec/04/2020 04:50:39 ipsec <- ike2 request, exchange: INFORMATIONAL:54 x.x.x.x[4500] 462df566fa0f9585:63413b5a87067e91
Dec/04/2020 04:50:39 ipsec adding payload: ENC
Dec/04/2020 04:50:39 ipsec KA remove: 192.168.1.43[4500]->x.x.x.x[4500]
Dec/04/2020 04:50:39 ipsec acquire for policy: 10.32.0.0/19 <=> 10.0.0.0/11
Dec/04/2020 04:50:39 ipsec peer is IKEv2
Dec/04/2020 04:50:39 ipsec ike2 starting for: x.x.x.x
Dec/04/2020 04:50:39 ipsec adding notify: NAT_DETECTION_DESTINATION_IP
Dec/04/2020 04:50:39 ipsec adding notify: NAT_DETECTION_SOURCE_IP
Dec/04/2020 04:50:39 ipsec adding payload: NONCE
Dec/04/2020 04:50:39 ipsec adding payload: KE
Dec/04/2020 04:50:39 ipsec adding payload: SA
Dec/04/2020 04:50:39 ipsec <- ike2 request, exchange: SA_INIT:0 x.x.x.x[4500] 459d037f986c4825:0000000000000000
Dec/04/2020 04:50:39 ipsec -> ike2 reply, exchange: SA_INIT:0 x.x.x.x[4500] 459d037f986c4825:caea62824e5bbe1c
Dec/04/2020 04:50:39 ipsec ike2 initialize recv
Dec/04/2020 04:50:39 ipsec payload seen: SA (48 bytes)
Dec/04/2020 04:50:39 ipsec payload seen: KE (72 bytes)
Dec/04/2020 04:50:39 ipsec payload seen: NONCE (36 bytes)
Dec/04/2020 04:50:39 ipsec payload seen: NOTIFY (28 bytes)
Dec/04/2020 04:50:39 ipsec payload seen: NOTIFY (28 bytes)
Dec/04/2020 04:50:39 ipsec processing payload: NONCE
Dec/04/2020 04:50:39 ipsec processing payload: SA
Dec/04/2020 04:50:39 ipsec IKE Protocol: IKE
Dec/04/2020 04:50:39 ipsec proposal #1
Dec/04/2020 04:50:39 ipsec enc: aes256-cbc
Dec/04/2020 04:50:39 ipsec prf: hmac-sha512
Dec/04/2020 04:50:39 ipsec auth: sha512
Dec/04/2020 04:50:39 ipsec dh: ecp256
Dec/04/2020 04:50:39 ipsec matched proposal:
Dec/04/2020 04:50:39 ipsec proposal #1
Dec/04/2020 04:50:39 ipsec enc: aes256-cbc
Dec/04/2020 04:50:39 ipsec prf: hmac-sha512
Dec/04/2020 04:50:39 ipsec auth: sha512
Dec/04/2020 04:50:39 ipsec dh: ecp256
Dec/04/2020 04:50:39 ipsec processing payload: KE
Dec/04/2020 04:50:39 ipsec processing payloads: NOTIFY
Dec/04/2020 04:50:39 ipsec notify: NAT_DETECTION_SOURCE_IP
Dec/04/2020 04:50:39 ipsec notify: NAT_DETECTION_DESTINATION_IP
Dec/04/2020 04:50:39 ipsec (NAT-T) LOCAL
Dec/04/2020 04:50:39 ipsec KA list add: 192.168.1.43[4500]->x.x.x.x[4500]
Dec/04/2020 04:50:39 ipsec init child for policy: 10.32.0.0/19 <=> 10.0.0.0/11
Dec/04/2020 04:50:39 ipsec init child continue
Dec/04/2020 04:50:39 ipsec offering proto: 3
Dec/04/2020 04:50:39 ipsec proposal #1
Dec/04/2020 04:50:39 ipsec enc: aes256-gcm
Dec/04/2020 04:50:39 ipsec auth: sha512
Dec/04/2020 04:50:39 ipsec ID_I (FQDN): france-vl.vpn.codasip.com
Dec/04/2020 04:50:39 ipsec adding payload: ID_I
Dec/04/2020 04:50:39 ipsec processing payload: NONCE
Dec/04/2020 04:50:39 ipsec adding payload: AUTH
Dec/04/2020 04:50:39 ipsec ID_R (FQDN): czechia-b.vpn.codasip.com
Dec/04/2020 04:50:39 ipsec adding payload: ID_R
Dec/04/2020 04:50:39 ipsec adding notify: INITIAL_CONTACT
Dec/04/2020 04:50:39 ipsec adding payload: SA
Dec/04/2020 04:50:39 ipsec initiator selector: 10.32.0.0/19
Dec/04/2020 04:50:39 ipsec adding payload: TS_I
Dec/04/2020 04:50:39 ipsec responder selector: 10.0.0.0/11
Dec/04/2020 04:50:39 ipsec adding payload: TS_R
Dec/04/2020 04:50:39 ipsec <- ike2 request, exchange: AUTH:1 x.x.x.x[4500] 459d037f986c4825:caea62824e5bbe1c
Dec/04/2020 04:50:39 ipsec adding payload: ENC
Code: Select all
2020-12-04 04:48:13.069 +0100 [PNTF]: { 3: }: ====> IKEv2 CHILD SA NEGOTIATION STARTED AS RESPONDER, rekey; gateway peer-france-vl <====
====> Initiated SA: x.x.x.x[4500]-y.y.y.y[4500] message id:0x00000033 parent SN:472 <====
2020-12-04 04:48:13.069 +0100 [DEBG]: { 3: 16}: TS matching for configured selector tunnel-france-vl:france-vl-to-czechia-brno 10.0.0.0[0]/11-10.32.0.0[0]/19 proto 0
2020-12-04 04:48:13.069 +0100 [DEBG]: { 3: 16}: .. check local TS (num 1, TS0 is not specific) against selector 0:10.0.0.0[0]/11
2020-12-04 04:48:13.069 +0100 [DEBG]: { : 16}: ... TS 0: exact match
2020-12-04 04:48:13.069 +0100 [DEBG]: { 3: 16}: ... result: local TS = 10.0.0.0[0]/11
2020-12-04 04:48:13.069 +0100 [DEBG]: { 3: 16}: .. check remote TS (num 1, TS0 is not specific) against selector 0:10.32.0.0[0]/19
2020-12-04 04:48:13.069 +0100 [DEBG]: { : 16}: ... TS 0: exact match
2020-12-04 04:48:13.069 +0100 [DEBG]: { 3: 16}: ... result: remote TS = 10.32.0.0[0]/19
2020-12-04 04:48:13.069 +0100 [DEBG]: { 3: 16}: TS matching result: TS_l match(=), TS_r match(=) *
2020-12-04 04:48:13.069 +0100 [DEBG]: { 3: 16}: selector chosen tunnel-france-vl:france-vl-to-czechia-brno: tid 16
2020-12-04 04:48:13.069 +0100 [DEBG]: { 3: 16}: see whether there's matching transform
2020-12-04 04:48:13.069 +0100 [DEBG]: { 3: 16}: found same ID. compare attributes
2020-12-04 04:48:13.069 +0100 [DEBG]: { 3: 16}: OK; advance to next of my transform type
2020-12-04 04:48:13.069 +0100 [DEBG]: { 3: 16}: see whether there's matching transform
2020-12-04 04:48:13.069 +0100 [DEBG]: { 3: 16}: found same ID. compare attributes
2020-12-04 04:48:13.069 +0100 [DEBG]: { 3: 16}: OK; advance to next of my transform type
2020-12-04 04:48:13.069 +0100 [DEBG]: { 3: 16}: see whether there's matching transform
2020-12-04 04:48:13.069 +0100 [DEBG]: { 3: 16}: found same ID. compare attributes
2020-12-04 04:48:13.069 +0100 [DEBG]: { 3: 16}: OK; advance to next of my transform type
2020-12-04 04:48:13.069 +0100 [DEBG]: { 3: 16}: success
2020-12-04 04:48:13.069 +0100 [DEBG]: { 3: 16}: see whether there's matching transform
2020-12-04 04:48:13.069 +0100 [DEBG]: { 3: 16}: found same ID. compare attributes
2020-12-04 04:48:13.069 +0100 [DEBG]: { 3: 16}: OK; advance to next of my transform type
2020-12-04 04:48:13.069 +0100 [DEBG]: { 3: 16}: see whether there's matching transform
2020-12-04 04:48:13.069 +0100 [DEBG]: { 3: 16}: found same ID. compare attributes
2020-12-04 04:48:13.069 +0100 [DEBG]: { 3: 16}: OK; advance to next of my transform type
2020-12-04 04:48:13.069 +0100 [DEBG]: { 3: 16}: see whether there's matching transform
2020-12-04 04:48:13.070 +0100 [DEBG]: { 3: 16}: found same ID. compare attributes
2020-12-04 04:48:13.070 +0100 [DEBG]: { 3: 16}: OK; advance to next of my transform type
2020-12-04 04:48:13.070 +0100 [DEBG]: { 3: 16}: success
2020-12-04 04:48:13.083 +0100 [INFO]: { 3: 16}: SADB_UPDATE proto=255 0.0.0.0[4500]=>x.x.x.x[4500] ESP tunl spi 0xF3D4FFE0 auth=NON-AUTH enc=AES256-GCM16/36 lifetime soft 3120/0 hard 3600/0
2020-12-04 04:48:13.084 +0100 [INFO]: { 3: 16}: SADB_ADD proto=255 x.x.x.x[4500]=>y.y.y.y[4500] ESP tunl spi 0x08663E51 auth=NON-AUTH enc=AES256-GCM16/36 lifetime soft 2993/0 hard 3600/0
2020-12-04 04:48:13.084 +0100 [DEBG]: { 3: 16}: sadb ts: port 0:65535 IP 10.0.0.0->10.31.255.255 proto:0 len:16
2020-12-04 04:48:13.084 +0100 [DEBG]: { 3: 16}: sadb ts: port 0:65535 IP 10.32.0.0->10.32.31.255 proto:0 len:16
2020-12-04 04:48:13.084 +0100 [PNTF]: { 3: 16}: ====> IPSEC KEY INSTALLATION SUCCEEDED; tunnel tunnel-france-vl:france-vl-to-czechia-brno <====
====> Installed SA: x.x.x.x[4500]-y.y.y.y[4500] SPI:0xF3D4FFE0/0x08663E51 lifetime 3600 Sec lifesize unlimited <====
2020-12-04 04:48:13.087 +0100 [INFO]: { 3: 16}: SPI F3D4FFE0 inserted by IPSec responder, return 0 0.
2020-12-04 04:48:13.087 +0100 [PNTF]: { 3: 16}: ====> IKEv2 CHILD SA NEGOTIATION SUCCEEDED AS RESPONDER, rekey; tunnel tunnel-france-vl:france-vl-to-czechia-brno <====
====> Established SA: x.x.x.x[4500]-y.y.y.y[4500] message id:0x00000033, SPI:0xF3D4FFE0/0x08663E51 parent SN:472 <====
2020-12-04 04:48:13.088 +0100 [DEBG]: x.x.x.x[4500] - y.y.y.y[4500]:(nil) 1 times of 308 bytes message will be sent over socket 1025
2020-12-04 04:48:13.088 +0100 [INFO]: { 3: }: KA found: x.x.x.x[4500]->y.y.y.y[4500] (in_use=2)
2020-12-04 04:48:13.088 +0100 [INFO]: { 3: 16}: SPI B9FF9CAB removed by keymodify, return 0 0.
2020-12-04 04:48:13.089 +0100 [PNTF]: { 3: 16}: ====> IKEv2 CHILD SA DELETED AS RESPONDER, rekey; tunnel tunnel-france-vl:france-vl-to-czechia-brno <====
====> Deleted SA: x.x.x.x[4500]-y.y.y.y[4500] message id:0x0000001A, SPI:0xB9FF9CAB/0x02114872 parent SN:472 <====
2020-12-04 04:48:13.089 +0100 [INFO]: { 3: }: ikev2_request_initiator_start: SA state ESTABLISHED type 3 caller ikev2_child_delete
2020-12-04 04:48:13.089 +0100 [INFO]: { 3: }: IKEv2 INFO transmit: gateway peer-france-vl, message_id: 0x00000001, type 3 SA state ESTABLISHED
2020-12-04 04:48:13.090 +0100 [DEBG]: x.x.x.x[4500] - y.y.y.y[4500]:(nil) 1 times of 100 bytes message will be sent over socket 1025
2020-12-04 04:48:13.090 +0100 [PNTF]: { 3: 16}: ====> IPSEC KEY DELETED; tunnel tunnel-france-vl:france-vl-to-czechia-brno <====
====> Deleted SA: x.x.x.x[4500]-y.y.y.y[4500] SPI:0xB9FF9CAB/0x02114872 <====
2020-12-04 04:48:13.090 +0100 [INFO]: { 3: 16}: SADB_DELETE proto=255 src=0.0.0.0[0] dst=x.x.x.x[0] ESP spi=0xB9FF9CAB
2020-12-04 04:48:13.090 +0100 [INFO]: { 3: }: KA remove: x.x.x.x[4500]->y.y.y.y[4500]
2020-12-04 04:48:13.091 +0100 [DEBG]: { 3: }: KA tree dump: x.x.x.x[4500]->y.y.y.y[4500] (in_use=2)
2020-12-04 04:48:13.136 +0100 [DEBG]: processing isakmp packet
2020-12-04 04:48:13.136 +0100 [DEBG]: ===
2020-12-04 04:48:13.136 +0100 [DEBG]: 96 bytes message received from y.y.y.y
2020-12-04 04:48:13.137 +0100 [DEBG]: { 3: }: request exch type 37
2020-12-04 04:48:13.137 +0100 [DEBG]: { 3: }: update request message_id 0x34
2020-12-04 04:48:13.137 +0100 [INFO]: { 3: }: received DELETE payload, protocol ESP, num of SPI: 1 IKE SA state ESTABLISHED
2020-12-04 04:48:13.137 +0100 [INFO]: { 3: }: delete proto ESP spi 0x02114872
2020-12-04 04:48:13.137 +0100 [PWRN]: { 3: }: can't find sa for proto ESP spi 0x02114872
2020-12-04 04:48:13.137 +0100 [DEBG]: x.x.x.x[4500] - y.y.y.y[4500]:(nil) 1 times of 100 bytes message will be sent over socket 1025
2020-12-04 04:48:13.138 +0100 [DEBG]: processing isakmp packet
2020-12-04 04:48:13.138 +0100 [DEBG]: ===
2020-12-04 04:48:13.138 +0100 [DEBG]: 304 bytes message received from y.y.y.y
2020-12-04 04:48:13.138 +0100 [DEBG]: { 3: }: response exch type 37
2020-12-04 04:48:13.138 +0100 [DEBG]: { 3: }: update response message_id 0x1
2020-12-04 04:48:13.138 +0100 [PERR]: { 3: }: received Notify payload protocol 0 type 43
2020-12-04 04:48:13.138 +0100 [INFO]: { 3: }: x.x.x.x[4500] - y.y.y.y[4500]:(nil) closing IKEv2 SA peer-france-vl:472, code 18
2020-12-04 04:48:13.138 +0100 [PNTF]: { 3: }: ====> IKEv2 IKE SA NEGOTIATION FAILED AS RESPONDER, non-rekey; gateway peer-france-vl <====
====> Failed SA: x.x.x.x[4500]-y.y.y.y[4500] SPI:462df566fa0f9585:63413b5a87067e91 SN 472 <====
2020-12-04 04:48:13.139 +0100 [DEBG]: { 3: }: SA dying from state ESTABLISHED, caller ikev2_abort
2020-12-04 04:48:13.139 +0100 [DEBG]: { 3: }: keeping retransmit while state changed to DYING, CID 300184, child 0xffe800d700
2020-12-04 04:48:13.139 +0100 [PNTF]: { 3: 16}: ====> IPSEC KEY DELETED; tunnel tunnel-france-vl:france-vl-to-czechia-brno <====
====> Deleted SA: x.x.x.x[4500]-y.y.y.y[4500] SPI:0xF3D4FFE0/0x08663E51 <====
2020-12-04 04:48:13.139 +0100 [INFO]: { 3: 16}: SADB_DELETE proto=255 src=0.0.0.0[0] dst=x.x.x.x[0] ESP spi=0xF3D4FFE0
2020-12-04 04:48:13.139 +0100 [DEBG]: { 3: }: SA deleted: state DYING, caller ikev2_abort
2020-12-04 04:48:13.139 +0100 [DEBG]: { 3: }: stop retransmit for sa 0xffe800d700 (DEAD), CID 300184, child 0xffe800d700
2020-12-04 04:48:13.142 +0100 [INFO]: { 3: 16}: SPI F3D4FFE0 removed by IKE abort, return 0 0.
2020-12-04 04:48:13.142 +0100 [INFO]: { 3: }: KA remove: x.x.x.x[4500]->y.y.y.y[4500]
2020-12-04 04:48:13.142 +0100 [DEBG]: { 3: }: KA tree dump: x.x.x.x[4500]->y.y.y.y[4500] (in_use=1)
2020-12-04 04:48:13.142 +0100 [DEBG]: { 3: }: KA removing this one...
2020-12-04 04:48:17.201 +0100 [DEBG]: { : 16}: keyacquire received: x.x.x.x[0] => 0.0.0.0[0]
2020-12-04 04:48:17.201 +0100 [DEBG]: { 3: }: initiate negotiation to dynamic peer from IKE gateway peer-france-vl is not allowed.
2020-12-04 04:48:25.526 +0100 [DEBG]: { : 16}: keyacquire received: x.x.x.x[0] => 0.0.0.0[0]
2020-12-04 04:48:25.526 +0100 [DEBG]: { 3: }: initiate negotiation to dynamic peer from IKE gateway peer-france-vl is not allowed.
2020-12-04 04:48:31.629 +0100 [DEBG]: { : 16}: keyacquire received: x.x.x.x[0] => 0.0.0.0[0]
2020-12-04 04:48:31.629 +0100 [DEBG]: { 3: }: initiate negotiation to dynamic peer from IKE gateway peer-france-vl is not allowed.
2020-12-04 04:48:37.806 +0100 [DEBG]: { : 16}: keyacquire received: x.x.x.x[0] => 0.0.0.0[0]
2020-12-04 04:48:37.806 +0100 [DEBG]: { 3: }: initiate negotiation to dynamic peer from IKE gateway peer-france-vl is not allowed.
2020-12-04 04:48:43.979 +0100 [DEBG]: { : 16}: keyacquire received: x.x.x.x[0] => 0.0.0.0[0]
2020-12-04 04:48:43.979 +0100 [DEBG]: { 3: }: initiate negotiation to dynamic peer from IKE gateway peer-france-vl is not allowed.
2020-12-04 04:48:50.070 +0100 [DEBG]: { : 16}: keyacquire received: x.x.x.x[0] => 0.0.0.0[0]
2020-12-04 04:48:50.070 +0100 [DEBG]: { 3: }: initiate negotiation to dynamic peer from IKE gateway peer-france-vl is not allowed.
2020-12-04 04:48:55.862 +0100 [DEBG]: { : 16}: keyacquire received: x.x.x.x[0] => 0.0.0.0[0]
2020-12-04 04:48:55.862 +0100 [DEBG]: { 3: }: initiate negotiation to dynamic peer from IKE gateway peer-france-vl is not allowed.
2020-12-04 04:49:01.866 +0100 [DEBG]: { : 16}: keyacquire received: x.x.x.x[0] => 0.0.0.0[0]
2020-12-04 04:49:01.866 +0100 [DEBG]: { 3: }: initiate negotiation to dynamic peer from IKE gateway peer-france-vl is not allowed.
2020-12-04 04:49:08.282 +0100 [DEBG]: { : 16}: keyacquire received: x.x.x.x[0] => 0.0.0.0[0]
2020-12-04 04:49:08.282 +0100 [DEBG]: { 3: }: initiate negotiation to dynamic peer from IKE gateway peer-france-vl is not allowed.
2020-12-04 04:49:14.186 +0100 [DEBG]: { : 16}: keyacquire received: x.x.x.x[0] => 0.0.0.0[0]
2020-12-04 04:49:14.186 +0100 [DEBG]: { 3: }: initiate negotiation to dynamic peer from IKE gateway peer-france-vl is not allowed.
2020-12-04 04:49:23.420 +0100 [DEBG]: { : 16}: keyacquire received: x.x.x.x[0] => 0.0.0.0[0]
2020-12-04 04:49:23.420 +0100 [DEBG]: { 3: }: initiate negotiation to dynamic peer from IKE gateway peer-france-vl is not allowed.
2020-12-04 04:49:29.038 +0100 [DEBG]: { : 16}: keyacquire received: x.x.x.x[0] => 0.0.0.0[0]
2020-12-04 04:49:29.038 +0100 [DEBG]: { 3: }: initiate negotiation to dynamic peer from IKE gateway peer-france-vl is not allowed.
2020-12-04 04:49:35.412 +0100 [DEBG]: { : 16}: keyacquire received: x.x.x.x[0] => 0.0.0.0[0]
2020-12-04 04:49:35.412 +0100 [DEBG]: { 3: }: initiate negotiation to dynamic peer from IKE gateway peer-france-vl is not allowed.
2020-12-04 04:49:42.022 +0100 [DEBG]: { : 16}: keyacquire received: x.x.x.x[0] => 0.0.0.0[0]
2020-12-04 04:49:42.022 +0100 [DEBG]: { 3: }: initiate negotiation to dynamic peer from IKE gateway peer-france-vl is not allowed.
2020-12-04 04:49:48.123 +0100 [DEBG]: { : 16}: keyacquire received: x.x.x.x[0] => 0.0.0.0[0]
2020-12-04 04:49:48.123 +0100 [DEBG]: { 3: }: initiate negotiation to dynamic peer from IKE gateway peer-france-vl is not allowed.
2020-12-04 04:49:53.733 +0100 [DEBG]: { : 16}: keyacquire received: x.x.x.x[0] => 0.0.0.0[0]
2020-12-04 04:49:53.733 +0100 [DEBG]: { 3: }: initiate negotiation to dynamic peer from IKE gateway peer-france-vl is not allowed.
2020-12-04 04:49:59.734 +0100 [DEBG]: { : 16}: keyacquire received: x.x.x.x[0] => 0.0.0.0[0]
2020-12-04 04:49:59.734 +0100 [DEBG]: { 3: }: initiate negotiation to dynamic peer from IKE gateway peer-france-vl is not allowed.
2020-12-04 04:50:06.170 +0100 [DEBG]: { : 16}: keyacquire received: x.x.x.x[0] => 0.0.0.0[0]
2020-12-04 04:50:06.170 +0100 [DEBG]: { 3: }: initiate negotiation to dynamic peer from IKE gateway peer-france-vl is not allowed.
2020-12-04 04:50:12.170 +0100 [DEBG]: { : 16}: keyacquire received: x.x.x.x[0] => 0.0.0.0[0]
2020-12-04 04:50:12.170 +0100 [DEBG]: { 3: }: initiate negotiation to dynamic peer from IKE gateway peer-france-vl is not allowed.
2020-12-04 04:50:13.171 +0100 [DEBG]: processing isakmp packet
2020-12-04 04:50:13.171 +0100 [DEBG]: ===
2020-12-04 04:50:13.171 +0100 [DEBG]: 128 bytes message received from y.y.y.y
2020-12-04 04:50:13.171 +0100 [DEBG]: x.x.x.x[4500] - y.y.y.y[4500]:0x1068f0c0 message to a nonexistent ike_sa
2020-12-04 04:50:18.176 +0100 [DEBG]: processing isakmp packet
2020-12-04 04:50:18.176 +0100 [DEBG]: ===
2020-12-04 04:50:18.176 +0100 [DEBG]: 128 bytes message received from y.y.y.y
2020-12-04 04:50:18.177 +0100 [DEBG]: x.x.x.x[4500] - y.y.y.y[4500]:0x10345570 message to a nonexistent ike_sa
2020-12-04 04:50:18.228 +0100 [DEBG]: { : 16}: keyacquire received: x.x.x.x[0] => 0.0.0.0[0]
2020-12-04 04:50:18.228 +0100 [DEBG]: { 3: }: initiate negotiation to dynamic peer from IKE gateway peer-france-vl is not allowed.
2020-12-04 04:50:23.171 +0100 [DEBG]: processing isakmp packet
2020-12-04 04:50:23.171 +0100 [DEBG]: ===
2020-12-04 04:50:23.171 +0100 [DEBG]: 128 bytes message received from y.y.y.y
2020-12-04 04:50:23.171 +0100 [DEBG]: x.x.x.x[4500] - y.y.y.y[4500]:0x1068f0c0 message to a nonexistent ike_sa
2020-12-04 04:50:24.247 +0100 [DEBG]: { : 16}: keyacquire received: x.x.x.x[0] => 0.0.0.0[0]
2020-12-04 04:50:24.247 +0100 [DEBG]: { 3: }: initiate negotiation to dynamic peer from IKE gateway peer-france-vl is not allowed.
2020-12-04 04:50:28.177 +0100 [DEBG]: processing isakmp packet
2020-12-04 04:50:28.177 +0100 [DEBG]: ===
2020-12-04 04:50:28.177 +0100 [DEBG]: 128 bytes message received from y.y.y.y
2020-12-04 04:50:28.177 +0100 [DEBG]: x.x.x.x[4500] - y.y.y.y[4500]:0x10345570 message to a nonexistent ike_sa
2020-12-04 04:50:30.254 +0100 [DEBG]: { : 16}: keyacquire received: x.x.x.x[0] => 0.0.0.0[0]
2020-12-04 04:50:30.254 +0100 [DEBG]: { 3: }: initiate negotiation to dynamic peer from IKE gateway peer-france-vl is not allowed.
2020-12-04 04:50:33.172 +0100 [DEBG]: processing isakmp packet
2020-12-04 04:50:33.172 +0100 [DEBG]: ===
2020-12-04 04:50:33.172 +0100 [DEBG]: 128 bytes message received from y.y.y.y
2020-12-04 04:50:33.172 +0100 [DEBG]: x.x.x.x[4500] - y.y.y.y[4500]:0x1068f0c0 message to a nonexistent ike_sa
2020-12-04 04:50:36.212 +0100 [DEBG]: { : 16}: keyacquire received: x.x.x.x[0] => 0.0.0.0[0]
2020-12-04 04:50:36.212 +0100 [DEBG]: { 3: }: initiate negotiation to dynamic peer from IKE gateway peer-france-vl is not allowed.
2020-12-04 04:50:38.178 +0100 [DEBG]: processing isakmp packet
2020-12-04 04:50:38.178 +0100 [DEBG]: ===
2020-12-04 04:50:38.178 +0100 [DEBG]: 256 bytes message received from y.y.y.y
2020-12-04 04:50:38.179 +0100 [DEBG]: x.x.x.x[4500] - y.y.y.y[4500]:0x10345570 message to a nonexistent ike_sa
2020-12-04 04:50:38.676 +0100 [DEBG]: processing isakmp packet
2020-12-04 04:50:38.676 +0100 [DEBG]: ===
2020-12-04 04:50:38.676 +0100 [DEBG]: 232 bytes message received from y.y.y.y
2020-12-04 04:50:38.677 +0100 [INFO]: { 3: }: received IKE request y.y.y.y[4500] to x.x.x.x[4500], found IKE gateway peer-france-vl
2020-12-04 04:50:38.677 +0100 [PNTF]: { 3: }: ====> IKEv2 IKE SA NEGOTIATION STARTED AS RESPONDER, non-rekey; gateway peer-france-vl <====
====> Initiated SA: x.x.x.x[4500]-y.y.y.y[4500] SPI:459d037f986c4825:caea62824e5bbe1c SN:473 <====
2020-12-04 04:50:38.677 +0100 [DEBG]: { 3: }: received Notify type NAT_DETECTION_DESTINATION_IP