Skip to main content
koup
koup
Visitor III
January 4, 2025
Solved

Unstable IPSec tunnel between Fortigate and OpnSense

  • January 4, 2025
  • 4 replies
  • 8266 views

Cross posting with https://forum.opnsense.org/index.php?topic=44897.0 due to the reason I still found no answer or clue

I have a S2S IPSec tunnel between an Opnsense (24.7.11) and a Fortigate 60F (current FortiOS) device. Establishing a connection is working, but after some time (Phase 2 rekeying?) the tunnel sometimes breaks and comes back way later without any action on both sides. I captured a log trace (no debug) on the OpnSense side, see below. Both configs are correct in my point of view.

Any ideas, is a debug log necessary and if yes, there are a lot of logging options with IPSec, which one?
I'm no VPN or network expert, so please excuse if this is an easy mistake on my side.

 

 

 

2024-12-28T22:13:46	3	Informational	charon	82877	14[IKE] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|3> CHILD_SA closed	 2024-12-28T22:13:46	3	Informational	charon	82877	14[IKE] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|3> received DELETE for ESP CHILD_SA with SPI e8e6a428	 2024-12-28T22:13:46	3	Informational	charon	82877	14[ENC] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|3> parsed INFORMATIONAL response 3 [ D ]	 2024-12-28T22:13:46	3	Informational	charon	82877	14[NET] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|3> received packet: from xx.xx.xx.xxx[500] to yyy.yy.yy.yy[500] (77 bytes)	 2024-12-28T22:13:46	3	Informational	charon	82877	14[NET] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|3> sending packet: from yyy.yy.yy.yy[500] to xx.xx.xx.xxx[500] (69 bytes)	 2024-12-28T22:13:46	3	Informational	charon	82877	14[ENC] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|3> generating INFORMATIONAL request 3 [ D ]	 2024-12-28T22:13:46	3	Informational	charon	82877	14[IKE] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|3> sending DELETE for ESP CHILD_SA with SPI c944a6f1	 2024-12-28T22:13:46	3	Informational	charon	82877	14[IKE] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|3> closing CHILD_SA 38ecc2d4-7b62-4bae-a3a1-58ac8e93bc9f{10} with SPIs c944a6f1_i (120834 bytes) e8e6a428_o (0 bytes) and TS 192.168.10.0/24 === 192.168.169.0/24	 2024-12-28T22:13:46	3	Informational	charon	82877	14[IKE] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|3> outbound CHILD_SA 38ecc2d4-7b62-4bae-a3a1-58ac8e93bc9f{11} established with SPIs cd6dbc5f_i e8e6a429_o and TS 192.168.10.0/24 === 192.168.169.0/24	 2024-12-28T22:13:46	3	Informational	charon	82877	14[IKE] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|3> inbound CHILD_SA 38ecc2d4-7b62-4bae-a3a1-58ac8e93bc9f{11} established with SPIs cd6dbc5f_i e8e6a429_o and TS 192.168.10.0/24 === 192.168.169.0/24	 2024-12-28T22:13:46	3	Informational	charon	82877	14[CFG] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|3> selected proposal: ESP:AES_GCM_16_256/MODP_2048/NO_EXT_SEQ	 2024-12-28T22:13:46	3	Informational	charon	82877	14[ENC] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|3> parsed CREATE_CHILD_SA response 2 [ SA No KE TSi TSr ]	 2024-12-28T22:13:46	3	Informational	charon	82877	14[NET] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|3> received packet: from xx.xx.xx.xxx[500] to yyy.yy.yy.yy[500] (441 bytes)	 2024-12-28T22:13:46	3	Informational	charon	82877	14[NET] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|3> sending packet: from yyy.yy.yy.yy[500] to xx.xx.xx.xxx[500] (469 bytes)	 2024-12-28T22:13:46	3	Informational	charon	82877	14[ENC] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|3> generating CREATE_CHILD_SA request 2 [ N(REKEY_SA) N(ESP_TFC_PAD_N) SA No KE TSi TSr ]	 2024-12-28T22:13:46	3	Informational	charon	82877	14[IKE] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|3> establishing CHILD_SA 38ecc2d4-7b62-4bae-a3a1-58ac8e93bc9f{11} reqid 1	 2024-12-28T22:13:46	3	Informational	charon	82877	14[KNL] creating rekey job for CHILD_SA ESP/0xc944a6f1/yyy.yy.yy.yy	 2024-12-28T21:18:56	20	Notice	charon	40648	[UPDOWN] received up-client event for reqid 1	 2024-12-28T21:18:56	3	Informational	charon	82877	14[IKE] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|3> CHILD_SA 38ecc2d4-7b62-4bae-a3a1-58ac8e93bc9f{10} established with SPIs c944a6f1_i e8e6a428_o and TS 192.168.10.0/24 === 192.168.169.0/24	 2024-12-28T21:18:56	3	Informational	charon	82877	14[CFG] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|3> selected proposal: ESP:AES_GCM_16_256/NO_EXT_SEQ	 2024-12-28T21:18:56	3	Informational	charon	82877	14[IKE] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|3> maximum IKE_SA lifetime 29223s	 2024-12-28T21:18:56	3	Informational	charon	82877	14[IKE] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|3> scheduling rekeying in 26343s	 2024-12-28T21:18:56	3	Informational	charon	82877	14[IKE] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|3> IKE_SA a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5[3] established between yyy.yy.yy.yy[yyyyy.yyyyy.yyy]...xx.xx.xx.xxx[xxxxx.xxxx.xx]	 2024-12-28T21:18:56	3	Informational	charon	82877	14[IKE] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|3> authentication of 'xxxxx.xxxx.xx' with pre-shared key successful	 2024-12-28T21:18:56	3	Informational	charon	82877	14[ENC] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|3> parsed IKE_AUTH response 1 [ IDr AUTH N(MSG_ID_SYN_SUP) SA TSi TSr ]	 2024-12-28T21:18:56	3	Informational	charon	82877	14[NET] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|3> received packet: from xx.xx.xx.xxx[500] to yyy.yy.yy.yy[500] (251 bytes)	 2024-12-28T21:18:56	3	Informational	charon	82877	14[NET] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|3> sending packet: from yyy.yy.yy.yy[500] to xx.xx.xx.xxx[500] (295 bytes)	 2024-12-28T21:18:56	3	Informational	charon	82877	14[ENC] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|3> generating IKE_AUTH request 1 [ IDi N(INIT_CONTACT) IDr AUTH N(ESP_TFC_PAD_N) SA TSi TSr N(EAP_ONLY) N(MSG_ID_SYN_SUP) ]	 2024-12-28T21:18:56	3	Informational	charon	82877	14[IKE] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|3> establishing CHILD_SA 38ecc2d4-7b62-4bae-a3a1-58ac8e93bc9f{10} reqid 1	 2024-12-28T21:18:56	3	Informational	charon	82877	14[IKE] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|3> authentication of 'yyyyy.yyyyy.yyy' (myself) with pre-shared key	 2024-12-28T21:18:56	3	Informational	charon	82877	14[CFG] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|3> selected proposal: IKE:AES_GCM_16_256/PRF_HMAC_SHA2_512/MODP_2048	 2024-12-28T21:18:56	3	Informational	charon	82877	14[ENC] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|3> parsed IKE_SA_INIT response 0 [ SA KE No N(NATD_S_IP) N(NATD_D_IP) N(FRAG_SUP) ]	 2024-12-28T21:18:56	3	Informational	charon	82877	14[NET] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|3> received packet: from xx.xx.xx.xxx[500] to yyy.yy.yy.yy[500] (416 bytes)	 2024-12-28T21:18:56	3	Informational	charon	82877	14[NET] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|3> sending packet: from yyy.yy.yy.yy[500] to xx.xx.xx.xxx[500] (456 bytes)	 2024-12-28T21:18:56	3	Informational	charon	82877	14[IKE] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|3> retransmit 1 of request with message ID 0	 2024-12-28T21:18:52	3	Informational	charon	82877	14[NET] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|3> sending packet: from yyy.yy.yy.yy[500] to xx.xx.xx.xxx[500] (456 bytes)	 2024-12-28T21:18:52	3	Informational	charon	82877	14[ENC] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|3> generating IKE_SA_INIT request 0 [ SA KE No N(NATD_S_IP) N(NATD_D_IP) N(FRAG_SUP) N(HASH_ALG) N(REDIR_SUP) ]	 2024-12-28T21:18:52	3	Informational	charon	82877	14[IKE] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|3> initiating IKE_SA a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5[3] to xx.xx.xx.xxx	 2024-12-28T21:18:52	3	Informational	charon	82877	09[KNL] creating acquire job for policy yyy.yy.yy.yy/32 === xx.xx.xx.xxx/32 with reqid {1}	 2024-12-28T21:18:50	3	Informational	charon	82877	14[KNL] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|2> unable to delete SAD entry with SPI cfcc902c: No such process (3)	 2024-12-28T21:18:50	3	Informational	charon	82877	14[IKE] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|2> giving up after 5 retransmits	 2024-12-28T21:17:34	3	Informational	charon	82877	14[NET] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|2> sending packet: from yyy.yy.yy.yy[500] to xx.xx.xx.xxx[500] (469 bytes)	 2024-12-28T21:17:34	3	Informational	charon	82877	14[IKE] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|2> retransmit 5 of request with message ID 4	 2024-12-28T21:17:08	3	Informational	charon	82877	10[KNL] creating rekey job for CHILD_SA ESP/0xc18c99e0/yyy.yy.yy.yy	 2024-12-28T21:16:52	3	Informational	charon	82877	10[NET] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|2> sending packet: from yyy.yy.yy.yy[500] to xx.xx.xx.xxx[500] (469 bytes)	 2024-12-28T21:16:52	3	Informational	charon	82877	10[IKE] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|2> retransmit 4 of request with message ID 4	 2024-12-28T21:16:29	3	Informational	charon	82877	10[NET] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|2> sending packet: from yyy.yy.yy.yy[500] to xx.xx.xx.xxx[500] (469 bytes)	 2024-12-28T21:16:29	3	Informational	charon	82877	10[IKE] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|2> retransmit 3 of request with message ID 4	 2024-12-28T21:16:16	3	Informational	charon	82877	10[NET] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|2> sending packet: from yyy.yy.yy.yy[500] to xx.xx.xx.xxx[500] (469 bytes)	 2024-12-28T21:16:16	3	Informational	charon	82877	10[IKE] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|2> retransmit 2 of request with message ID 4	 2024-12-28T21:16:09	3	Informational	charon	82877	10[NET] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|2> sending packet: from yyy.yy.yy.yy[500] to xx.xx.xx.xxx[500] (469 bytes)	 2024-12-28T21:16:09	3	Informational	charon	82877	10[IKE] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|2> retransmit 1 of request with message ID 4	 2024-12-28T21:16:05	3	Informational	charon	82877	10[NET] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|2> sending packet: from yyy.yy.yy.yy[500] to xx.xx.xx.xxx[500] (469 bytes)	 2024-12-28T21:16:05	3	Informational	charon	82877	10[ENC] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|2> generating CREATE_CHILD_SA request 4 [ N(REKEY_SA) N(ESP_TFC_PAD_N) SA No KE TSi TSr ]	 2024-12-28T21:16:05	3	Informational	charon	82877	10[IKE] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|2> establishing CHILD_SA 38ecc2d4-7b62-4bae-a3a1-58ac8e93bc9f{9} reqid 1	 2024-12-28T21:16:05	3	Informational	charon	82877	10[KNL] creating rekey job for CHILD_SA ESP/0xe8e6a426/xx.xx.xx.xxx	 2024-12-28T20:17:59	3	Informational	charon	82877	10[NET] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|2> sending packet: from yyy.yy.yy.yy[500] to xx.xx.xx.xxx[500] (69 bytes)	 2024-12-28T20:17:59	3	Informational	charon	82877	10[ENC] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|2> generating CREATE_CHILD_SA response 0 [ N(NO_CHILD_SA) ]	 2024-12-28T20:17:59	3	Informational	charon	82877	10[IKE] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|2> unable to rekey, ESP CHILD_SA with SPI e8e6a424 not found	 2024-12-28T20:17:59	3	Informational	charon	82877	10[ENC] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|2> parsed CREATE_CHILD_SA request 0 [ N(REKEY_SA) SA No KE TSi TSr ]	 2024-12-28T20:17:59	3	Informational	charon	82877	10[NET] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|2> received packet: from xx.xx.xx.xxx[500] to yyy.yy.yy.yy[500] (453 bytes)	 2024-12-28T20:17:54	3	Informational	charon	82877	10[IKE] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|2> CHILD_SA closed	 2024-12-28T20:17:54	3	Informational	charon	82877	10[IKE] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|2> received DELETE for ESP CHILD_SA with SPI e8e6a424	 2024-12-28T20:17:54	3	Informational	charon	82877	10[ENC] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|2> parsed INFORMATIONAL response 3 [ D ]	 2024-12-28T20:17:54	3	Informational	charon	82877	10[NET] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|2> received packet: from xx.xx.xx.xxx[500] to yyy.yy.yy.yy[500] (77 bytes)	 2024-12-28T20:17:54	3	Informational	charon	82877	10[NET] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|2> sending packet: from yyy.yy.yy.yy[500] to xx.xx.xx.xxx[500] (69 bytes)	 2024-12-28T20:17:54	3	Informational	charon	82877	10[ENC] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|2> generating INFORMATIONAL request 3 [ D ]	 2024-12-28T20:17:54	3	Informational	charon	82877	10[IKE] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|2> sending DELETE for ESP CHILD_SA with SPI c2e49130	 2024-12-28T20:17:54	3	Informational	charon	82877	10[IKE] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|2> closing CHILD_SA 38ecc2d4-7b62-4bae-a3a1-58ac8e93bc9f{7} with SPIs c2e49130_i (120860 bytes) e8e6a424_o (0 bytes) and TS 192.168.10.0/24 === 192.168.169.0/24	 2024-12-28T20:17:54	3	Informational	charon	82877	10[IKE] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|2> outbound CHILD_SA 38ecc2d4-7b62-4bae-a3a1-58ac8e93bc9f{8} established with SPIs c18c99e0_i e8e6a426_o and TS 192.168.10.0/24 === 192.168.169.0/24	 2024-12-28T20:17:54	3	Informational	charon	82877	10[IKE] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|2> inbound CHILD_SA 38ecc2d4-7b62-4bae-a3a1-58ac8e93bc9f{8} established with SPIs c18c99e0_i e8e6a426_o and TS 192.168.10.0/24 === 192.168.169.0/24	 2024-12-28T20:17:54	3	Informational	charon	82877	10[CFG] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|2> selected proposal: ESP:AES_GCM_16_256/MODP_2048/NO_EXT_SEQ	 2024-12-28T20:17:54	3	Informational	charon	82877	10[ENC] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|2> parsed CREATE_CHILD_SA response 2 [ SA No KE TSi TSr ]	 2024-12-28T20:17:54	3	Informational	charon	82877	10[NET] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|2> received packet: from xx.xx.xx.xxx[500] to yyy.yy.yy.yy[500] (441 bytes)	 2024-12-28T20:17:54	3	Informational	charon	82877	10[NET] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|2> sending packet: from yyy.yy.yy.yy[500] to xx.xx.xx.xxx[500] (469 bytes)	 2024-12-28T20:17:54	3	Informational	charon	82877	10[ENC] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|2> generating CREATE_CHILD_SA request 2 [ N(REKEY_SA) N(ESP_TFC_PAD_N) SA No KE TSi TSr ]	 2024-12-28T20:17:54	3	Informational	charon	82877	10[IKE] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|2> establishing CHILD_SA 38ecc2d4-7b62-4bae-a3a1-58ac8e93bc9f{8} reqid 1	 2024-12-28T20:17:54	3	Informational	charon	82877	05[KNL] creating rekey job for CHILD_SA ESP/0xc2e49130/yyy.yy.yy.yy

 

 

 

I did capture the debug log from the Fortigate side. There was a second VPN tunnel connection in the log file, I tried to clean up the log as good as possible. Maybe a hint in there?
During the capture, the tunnel went up again without any changes on both sides.

 

 

ike V=root:0: comes yyy.yyy.yyy.yy:500->xx.xx.xx.xxx:500,ifindex=5,vrf=0,len=65.... ike V=root:0: IKEv2 exchange=INFORMATIONAL_RESPONSE id=8b79c9b890913093/b8eae4473c0f280c:0000055f len=65 ike 0: in 8B79C9B890913093B8EAE4473C0F280C2E2025280000055F00000041000000252B6F3DC4FFE009C836B28EE993C0B3A6F74666DC169E00A0D21A009E4627107FA4 ike V=root:0: unknown SPI e8e6a44f 5 yyy.yy.yy.yy:0->xx.xx.xx.xxx ike V=root:0:: send HA sync query conn scope=3 mode=4 ike V=root:0: unknown SPI e8e6a44f 5 yyy.yy.yy.yy:0->xx.xx.xx.xxx ike V=root:0:: send HA sync query conn scope=3 mode=4 ike V=root:0: unknown SPI e8e6a44f 5 yyy.yy.yy.yy:0->xx.xx.xx.xxx ike V=root:0:: send HA sync query conn scope=3 mode=4 ike V=root:0: unknown SPI e8e6a44f 5 yyy.yy.yy.yy:0->xx.xx.xx.xxx ike V=root:0:: send HA sync query conn scope=3 mode=4 ike V=root:0: unknown SPI e8e6a44f 5 yyy.yy.yy.yy:0->xx.xx.xx.xxx ike V=root:0:: send HA sync query conn scope=3 mode=4 ike V=root:0: unknown SPI e8e6a44f 5 yyy.yy.yy.yy:0->xx.xx.xx.xxx ike V=root:0:: send HA sync query conn scope=3 mode=4 ike V=root:0: comes yyy.yyy.yyy.yy:500->xx.xx.xx.xxx:500,ifindex=5,vrf=0,len=65.... ike V=root:0: IKEv2 exchange=INFORMATIONAL id=8b79c9b890913093/b8eae4473c0f280c:000004d8 len=65 ike 0: in 8B79C9B890913093B8EAE4473C0F280C2E202508000004D80000004100000025B369463700A681393EB60A786B5EBA04956DFC3DFDCD2D8FC4DE42C0B320AE49ED ike :shrank heap by 159744 bytes ike V=root:0: unknown SPI e8e6a44f 5 yyy.yy.yy.yy:0->xx.xx.xx.xxx ike V=root:0:: send HA sync query conn scope=3 mode=4 ike V=root:0: unknown SPI e8e6a44f 5 yyy.yy.yy.yy:0->xx.xx.xx.xxx ike V=root:0:: send HA sync query conn scope=3 mode=4 ike V=root:0: unknown SPI e8e6a44f 5 yyy.yy.yy.yy:0->xx.xx.xx.xxx ike V=root:0:: send HA sync query conn scope=3 mode=4 ike V=root:0: unknown SPI e8e6a44f 5 yyy.yy.yy.yy:0->xx.xx.xx.xxx ike V=root:0:: send HA sync query conn scope=3 mode=4 ike V=root:0: comes yyy.yy.yy.yy:500->xx.xx.xx.xxx:500,ifindex=5,vrf=0,len=456.... ike V=root:0: IKEv2 exchange=SA_INIT id=ce13113404bcd448/0000000000000000 len=456 ike 0: in CE13113404BCD44800000000000000002120220800000000000001C82200002800000024010100030300000C01000014800E01000300000802000007000000080400000E28000108000E0000DC45753108B4B2BF1E0119462ACF7EC02A56779D93CEDDF3712C87D1F636D096A34DE6590FB5A90BD23BAFD82DBAC96D6F914480C3070D69E8FF16992B853C94977A029A8E16FC8E99ABEE39FAFB0CF4FAB5D5A5B48AB0FF631667914EFEB6360C159DCD44EFEACA96B55809E295003B55E9E49E1A7104F7A4ADDF7039E6FC4DBC0180A7F4E43B455E9D87AD868C692660F1BF7E00558BCB7DF159D4A9CCE029DE4081B41DEE09471937F5CDBE5E06E5F3EA1C954403AEFDA77E5148E38FA72179E483F3FC1A01A5D1F8AF33FC90791490CF1A7DDDA8F565E99470B89BD48D1748C2E3630EDC6064E81114DDF9F9DF0154A0CAB4CA29432BB035D0D4EF03048729000024323FD388A59CB881AF296486170B94B131F7473B926EEAC62EB91B52B0CD09832900001C00004004DDE6F3B40A1388289EC3B8E46C1A16095CAFAA362900001C00004005EC405F0532DC186FBEDE0C9A7B2B7993BB25E905290000080000402E290000100000402F00020003000400050000000800004016 ike V=root:0:ce13113404bcd448/0000000000000000:424: responder received SA_INIT msg ike V=root:0:ce13113404bcd448/0000000000000000:424: received notify type NAT_DETECTION_SOURCE_IP ike V=root:0:ce13113404bcd448/0000000000000000:424: received notify type NAT_DETECTION_DESTINATION_IP ike V=root:0:ce13113404bcd448/0000000000000000:424: received notify type FRAGMENTATION_SUPPORTED ike V=root:0:ce13113404bcd448/0000000000000000:424: received notify type SIGNATURE_HASH_ALGORITHMS ike V=root:0:ce13113404bcd448/0000000000000000:424: received notify type 16406 ike V=root:0:ce13113404bcd448/0000000000000000:424: ignoring unauthenticated notify payload (16406) ike V=root:0:ce13113404bcd448/0000000000000000:424: incoming proposal: ike V=root:0:ce13113404bcd448/0000000000000000:424: proposal id = 1: ike V=root:0:ce13113404bcd448/0000000000000000:424:   protocol = IKEv2: ike V=root:0:ce13113404bcd448/0000000000000000:424:      encapsulation = IKEv2/none ike V=root:0:ce13113404bcd448/0000000000000000:424:         type=ENCR, val=AES_GCM_16 (key_len = 256) ike V=root:0:ce13113404bcd448/0000000000000000:424:         type=PRF, val=PRF_HMAC_SHA2_512 ike V=root:0:ce13113404bcd448/0000000000000000:424:         type=DH_GROUP, val=MODP2048. ike V=root:0: cache rebuild start ike V=root:0:xxxx_yyyy: sending DNS request for remote peer yyyyyyyy.yyyyyy.yyy ike V=root:0: send IPv4 DNS query : yyyyyyyy.yyyyyy.yyy ike V=root:0: cache rebuild done ike V=root:0:ce13113404bcd448/0000000000000000:424: no proposal chosen ike V=root:Negotiate SA Error: [11895] ike V=root:0: DNS response received for remote gateway yyyyyyyy.yyyyyy.yyy ike V=root:0: DNS yyyyyyyy.yyyyyy.yyy -> yyy.yy.yy.yy ike V=root:0:xxxx_yyyy: 'yyyyyyyy.yyyyyy.yyy' resolved to yyy.yy.yy.yy ike V=root:0:xxxx_yyyy: set remote-gw yyy.yy.yy.yy ike V=root:0: comes yyy.yy.yy.yy:500->xx.xx.xx.xxx:500,ifindex=5,vrf=0,len=456.... ike V=root:0: IKEv2 exchange=SA_INIT id=ce13113404bcd448/0000000000000000 len=456 ike 0: in CE13113404BCD44800000000000000002120220800000000000001C82200002800000024010100030300000C01000014800E01000300000802000007000000080400000E28000108000E0000DC45753108B4B2BF1E0119462ACF7EC02A56779D93CEDDF3712C87D1F636D096A34DE6590FB5A90BD23BAFD82DBAC96D6F914480C3070D69E8FF16992B853C94977A029A8E16FC8E99ABEE39FAFB0CF4FAB5D5A5B48AB0FF631667914EFEB6360C159DCD44EFEACA96B55809E295003B55E9E49E1A7104F7A4ADDF7039E6FC4DBC0180A7F4E43B455E9D87AD868C692660F1BF7E00558BCB7DF159D4A9CCE029DE4081B41DEE09471937F5CDBE5E06E5F3EA1C954403AEFDA77E5148E38FA72179E483F3FC1A01A5D1F8AF33FC90791490CF1A7DDDA8F565E99470B89BD48D1748C2E3630EDC6064E81114DDF9F9DF0154A0CAB4CA29432BB035D0D4EF03048729000024323FD388A59CB881AF296486170B94B131F7473B926EEAC62EB91B52B0CD09832900001C00004004DDE6F3B40A1388289EC3B8E46C1A16095CAFAA362900001C00004005EC405F0532DC186FBEDE0C9A7B2B7993BB25E905290000080000402E290000100000402F00020003000400050000000800004016 ike V=root:0:ce13113404bcd448/0000000000000000:425: responder received SA_INIT msg ike V=root:0:ce13113404bcd448/0000000000000000:425: received notify type NAT_DETECTION_SOURCE_IP ike V=root:0:ce13113404bcd448/0000000000000000:425: received notify type NAT_DETECTION_DESTINATION_IP ike V=root:0:ce13113404bcd448/0000000000000000:425: received notify type FRAGMENTATION_SUPPORTED ike V=root:0:ce13113404bcd448/0000000000000000:425: received notify type SIGNATURE_HASH_ALGORITHMS ike V=root:0:ce13113404bcd448/0000000000000000:425: received notify type 16406 ike V=root:0:ce13113404bcd448/0000000000000000:425: ignoring unauthenticated notify payload (16406) ike V=root:0:ce13113404bcd448/0000000000000000:425: incoming proposal: ike V=root:0:ce13113404bcd448/0000000000000000:425: proposal id = 1: ike V=root:0:ce13113404bcd448/0000000000000000:425:   protocol = IKEv2: ike V=root:0:ce13113404bcd448/0000000000000000:425:      encapsulation = IKEv2/none ike V=root:0:ce13113404bcd448/0000000000000000:425:         type=ENCR, val=AES_GCM_16 (key_len = 256) ike V=root:0:ce13113404bcd448/0000000000000000:425:         type=PRF, val=PRF_HMAC_SHA2_512 ike V=root:0:ce13113404bcd448/0000000000000000:425:         type=DH_GROUP, val=MODP2048. ike V=root:0: cache rebuild start ike V=root:0:xxxx_yyyy: local:xx.xx.xx.xxx, remote:yyy.yy.yy.yy ike V=root:0:xxxx_yyyy: cached as static-ddns. ike V=root:0: cache rebuild done ike V=root:0:ce13113404bcd448/0000000000000000:425: matched proposal id 1 ike V=root:0:ce13113404bcd448/0000000000000000:425: proposal id = 1: ike V=root:0:ce13113404bcd448/0000000000000000:425:   protocol = IKEv2: ike V=root:0:ce13113404bcd448/0000000000000000:425:      encapsulation = IKEv2/none ike V=root:0:ce13113404bcd448/0000000000000000:425:         type=ENCR, val=AES_GCM_16 (key_len = 256) ike V=root:0:ce13113404bcd448/0000000000000000:425:         type=INTEGR, val=NONE ike V=root:0:ce13113404bcd448/0000000000000000:425:         type=PRF, val=PRF_HMAC_SHA2_512 ike V=root:0:ce13113404bcd448/0000000000000000:425:         type=DH_GROUP, val=MODP2048. ike V=root:0:ce13113404bcd448/0000000000000000:425: lifetime=28800 ike V=root:0:ce13113404bcd448/0000000000000000:425: SA proposal chosen, matched gateway xxxx_yyyy ike V=root:0:xxxx_yyyy:xxxx_yyyy: created connection: 0x9b88680 5 xx.xx.xx.xxx->yyy.yy.yy.yy:500. ike V=root:0:xxxx_yyyy:425: processing notify type NAT_DETECTION_SOURCE_IP ike V=root:0:xxxx_yyyy:425: processing NAT-D payload ike V=root:0:xxxx_yyyy:425: NAT not detected ike V=root:0:xxxx_yyyy:425: process NAT-D ike V=root:0:xxxx_yyyy:425: processing notify type NAT_DETECTION_DESTINATION_IP ike V=root:0:xxxx_yyyy:425: processing NAT-D payload ike V=root:0:xxxx_yyyy:425: NAT not detected ike V=root:0:xxxx_yyyy:425: process NAT-D ike V=root:0:xxxx_yyyy:425: processing notify type FRAGMENTATION_SUPPORTED ike V=root:0:xxxx_yyyy:425: processing notify type SIGNATURE_HASH_ALGORITHMS ike V=root:0:xxxx_yyyy:425: responder preparing SA_INIT msg ike V=root:0:xxxx_yyyy:425: create NAT-D hash local xx.xx.xx.xxx/500 remote yyy.yy.yy.yy/500 ike 0:xxxx_yyyy:425: out CE13113404BCD44892FD77E016634BD52120222000000000000001A02200002800000024010100030300000C01000014800E01000300000802000007000000080400000E28000108000E00006D680EFF097280F720E80B94384D0DAD9BCE81FAECA826147D580C0ED71E9E71EF879934144AE8A70341A84F44315FCD06226577A629DE0CD919EDAAA921DE7F28DDF04F54085E2E3E54569464189B9A83C3B44EFBD40E3FCDE4367D6D3C8590BB8A7BA35BDC6EA93DD53C0B3B8AD6681FC477656BAB46A1EB4C018BEE2ECCE8642FDD377599873E4D09ACF8DFE25D90F6A5BD40F750FB28B8898D25388AB6D1E0169E497858BC1A6B30610672DDDC3996DB7D4F10119D816B1BDA43B45480E74D25AA3B5333E4829CC4ED223198A162563A5BDBBFFC5C08B153DDDB85043B974C8139573C53020144793685B2096E1FA9A2323A84248EEC33395163C393CFBB29000014C5258202F40D0720062590DC2BF8A4BC2900001C000040047CDE7052253BE12E3E2569F9772D6A895AED1B112900001C00004005D42D8954D36B114D2FA36CCD0B73E3E999C454D6000000080000402E ike V=root:0:xxxx_yyyy:425: sent IKE msg (SA_INIT_RESPONSE): xx.xx.xx.xxx:500->yyy.yy.yy.yy:500, len=416, vrf=0, id=ce13113404bcd448/92fd77e016634bd5, oif=5 ike 0:xxxx_yyyy:425: IKE SA ce13113404bcd448/92fd77e016634bd5 SK_ei 36:88A28258A68BA7DA1CD8085A9DE2A361E43DBE648A34B667181E580FFA20CED8401D5190 ike 0:xxxx_yyyy:425: IKE SA ce13113404bcd448/92fd77e016634bd5 SK_er 36:EFD1FC8AAB18D24C7CFA332B17C6BBE028FBD9BF68CF0FDC44842C7E82704F7136C1FF3E ike V=root:0: comes yyy.yy.yy.yy:500->xx.xx.xx.xxx:500,ifindex=5,vrf=0,len=295.... ike V=root:0: IKEv2 exchange=AUTH id=ce13113404bcd448/92fd77e016634bd5:00000001 len=295 ike 0: in CE13113404BCD44892FD77E016634BD52E20230800000001000001272300010BE03AE2F6876ECBB0E4441605B3C94C11CFABFCFC853ABEFC27AD88DFB9A484100F94F783FA09C87E26C2623A35FEC01D1F6A2F30EDCCFEB85640B5BD1D7E67E1E02D04ADAB3849AA1F162A18E4A02C5B7E8E89ED994363B3314996384CB9D2F57315B1F8ADB936BDE688D0F542E3035D020C904C0D51AF35DF54E131F458105EB64C1B5615E0F2BE032265CC3BC29910321F6F5006E7C0C593C0B9CAFA298B522E5C4CF8C8380FF0D2DFFC8DF0740D569E053E3A9A1ADD35B6EDE12F7C48CE4EEB785CF26CDD7705FA5807D5178523B7D119165EC339D620D0EE5329CFBD43203C2B70B95989E4E3445D23480ACD8B1AF85823369FFEEB941712E3D2DCEDCC0599FD6F5955EF2B ike 0:xxxx_yyyy:425: dec CE13113404BCD44892FD77E016634BD52E202308000000010000010E230000042900001C0200000063796265726D636D2E6475636B646E732E6F72672400000800004000270000160200000072656D6F74652E6B6F75702E61742900004802000000C4F6D080205DACBFFDB1933FFD07CE3AD5FE21177FA436EE2EC064DD66AC534E837E09376E4F19835379461CADDE0D81A8652F5B173C35E3357E17516436B950210000080000400A2C0000240000002001030402CE30389F0300000C01000014800E010000000008050000002D00001801000000070000100000FFFFC0A80A00C0A80AFF2900001801000000070000100000FFFFC0A8A900C0A8A9FF29000008000040210000000800004024 ike V=root:0:xxxx_yyyy:425: responder received AUTH msg ike V=root:0:xxxx_yyyy:425: processing notify type INITIAL_CONTACT ike V=root:0:xxxx_yyyy:425: processing notify type ESP_TFC_PADDING_NOT_SUPPORTED ike V=root:0:xxxx_yyyy:425: processing notify type EAP_ONLY_AUTHENTICATION ike V=root:0:xxxx_yyyy:425: processing notify type MESSAGE_ID_SYNC_SUPPORTED ike V=root:0:xxxx_yyyy:425: received peer identifier FQDN 'yyyyyyyy.yyyyyy.yyy' ike V=root:0:xxxx_yyyy:425: auth verify done ike V=root:0:xxxx_yyyy:425: responder AUTH continuation ike V=root:0:xxxx_yyyy:425: authentication succeeded ike V=root:0:xxxx_yyyy:425: responder creating new child ike V=root:0:xxxx_yyyy:425:19595: peer proposal: ike V=root:0:xxxx_yyyy:425:19595: TSi_0 0:192.168.10.0-192.168.10.255:0 ike V=root:0:xxxx_yyyy:425:19595: TSr_0 0:192.168.169.0-192.168.169.255:0 ike V=root:0:xxxx_yyyy:425:xxxx_yyyy:19595: comparing selectors ike V=root:0:xxxx_yyyy:425:xxxx_yyyy:19595: matched by rfc-rule-2 ike V=root:0:xxxx_yyyy:425:xxxx_yyyy:19595: phase2 matched by subset ike V=root:0:xxxx_yyyy:425:xxxx_yyyy:19595: accepted proposal: ike V=root:0:xxxx_yyyy:425:xxxx_yyyy:19595: TSi_0 0:192.168.10.0-192.168.10.255:0 ike V=root:0:xxxx_yyyy:425:xxxx_yyyy:19595: TSr_0 0:192.168.169.0-192.168.169.255:0 ike V=root:0:xxxx_yyyy:425:xxxx_yyyy:19595: autokey ike V=root:0:xxxx_yyyy:425:xxxx_yyyy:19595: incoming child SA proposal: ike V=root:0:xxxx_yyyy:425:xxxx_yyyy:19595: proposal id = 1: ike V=root:0:xxxx_yyyy:425:xxxx_yyyy:19595:   protocol = ESP: ike V=root:0:xxxx_yyyy:425:xxxx_yyyy:19595:      encapsulation = TUNNEL ike V=root:0:xxxx_yyyy:425:xxxx_yyyy:19595:         type=ENCR, val=AES_GCM_16 (key_len = 256) ike V=root:0:xxxx_yyyy:425:xxxx_yyyy:19595:         type=ESN, val=NO ike V=root:0:xxxx_yyyy:425:xxxx_yyyy:19595:         PFS is disabled ike V=root:0:xxxx_yyyy:425:xxxx_yyyy:19595: matched proposal id 1 ike V=root:0:xxxx_yyyy:425:xxxx_yyyy:19595: proposal id = 1: ike V=root:0:xxxx_yyyy:425:xxxx_yyyy:19595:   protocol = ESP: ike V=root:0:xxxx_yyyy:425:xxxx_yyyy:19595:      encapsulation = TUNNEL ike V=root:0:xxxx_yyyy:425:xxxx_yyyy:19595:         type=ENCR, val=AES_GCM_16 (key_len = 256) ike V=root:0:xxxx_yyyy:425:xxxx_yyyy:19595:         type=INTEGR, val=AUTH_NONE ike V=root:0:xxxx_yyyy:425:xxxx_yyyy:19595:         type=ESN, val=NO ike V=root:0:xxxx_yyyy:425:xxxx_yyyy:19595:         PFS is disabled ike V=root:0:xxxx_yyyy:425:xxxx_yyyy:19595: lifetime=3600 ike V=root:0:xxxx_yyyy:425: responder preparing AUTH msg ike V=root:0:xxxx_yyyy:425: established IKE SA ce13113404bcd448/92fd77e016634bd5 ike V=root:0:xxxx_yyyy:425: check peer route: if_addr4_rcvd=0, if_addr6_rcvd=0, mode_cfg=0 ike V=root:0:xxxx_yyyy:425: processing INITIAL-CONTACT ike V=root:0:xxxx_yyyy: flushing ike V=root:0:xxxx_yyyy: flushed ike V=root:0:xxxx_yyyy:425: processed INITIAL-CONTACT ike V=root:0:xxxx_yyyy: set oper up ike V=root:0:xxxx_yyyy:425:xxxx_yyyy:19595: set sa life soft seconds=3328. ike V=root:0:xxxx_yyyy:425:xxxx_yyyy:19595: set sa life hard seconds=3600. ike V=root:0:xxxx_yyyy:425:xxxx_yyyy:19595: IPsec SA selectors #src=1 #dst=1 ike V=root:0:xxxx_yyyy:425:xxxx_yyyy:19595: src 0 7 0:192.168.169.0-192.168.169.255:0 ike V=root:0:xxxx_yyyy:425:xxxx_yyyy:19595: dst 0 7 0:192.168.10.0-192.168.10.255:0 ike V=root:0:xxxx_yyyy:425:xxxx_yyyy:19595: add IPsec SA: SPIs=e8e6a451/ce30389f ike 0:xxxx_yyyy:425:xxxx_yyyy:19595: IPsec SA dec spi e8e6a451 key 36:F005C9651CF3BA3FE6672EF023B1FB9747CE5C1FF062DE7CEBDA6252331CC9C7A9B0AA34 auth 0: ike 0:xxxx_yyyy:425:xxxx_yyyy:19595: IPsec SA enc spi ce30389f key 36:0A7D4B7CBFC8FCD38D09F9025A9A9147F3092562F16046AACA49704EBBD8F6ADDDDCC22F auth 0: ike V=root:0:xxxx_yyyy:425:xxxx_yyyy:19595: added IPsec SA: SPIs=e8e6a451/ce30389f ike V=root:0:xxxx_yyyy:425:xxxx_yyyy:19595: sending SNMP tunnel UP trap ike V=root:0:xxxx_yyyy: static tunnel up event 0.0.0.0 (dev=24) ike V=root:0:xxxx_yyyy: static tunnel up event :: (dev=24) ike 0:xxxx_yyyy:425: enc 270000160200000072656D6F74652E6B6F75702E617429000048020000009F292A1510A4E5BE9F8264B8CE6429A113748AE5B789EA884346DFD1278F2664D62C2AACE7C875C6DFDD477C1FC30D0F237C58F86F6C90059368D57053BEC30521000008000040242C0000240000002001030402E8E6A4510300000C01000014800E010000000008050000002D00001801000000070000100000FFFFC0A80A00C0A80AFF0000001801000000070000100000FFFFC0A8A900C0A8A9FF080706050403020108 ike 0:xxxx_yyyy:425: out CE13113404BCD44892FD77E016634BD52E20232000000001000000FB240000DF01ED8B0202DB9C1B82111CC473ED46F7AA8A15A2C7A8A246EA92BA2916CCBFA3FD67D6617FCC9C7F7EDA785BEC254901FAE52DE358AA360ED33010BE36A6297B387EE05DAB7F1C81DCDF268F08068D560BC8C2A40E644FFA3E11C0B6C341F827830C93951C85A73B1CC181A96628E5F9F0133E7574F2BA595E8E73FE8ECE22C3D0F81F77F524D7AAA99296775053B205B110B51F3EC4C2B81D6EF8D473EFBB07638C3F804AA3CD1100A89329FB2B71C5089325520F6667E1DAAE97014C2E3B487C55882C46BB2FAF0016A229FBCA36DB10E318BF67B58B53716FC8 ike V=root:0:xxxx_yyyy:425: sent IKE msg (AUTH_RESPONSE): xx.xx.xx.xxx:500->yyy.yy.yy.yy:500, len=251, vrf=0, id=ce13113404bcd448/92fd77e016634bd5:00000001, oif=5 ike :shrank heap by 114688 bytes ike V=root:0: comes yyy.yyy.yyy.yy:500->xx.xx.xx.xxx:500,ifindex=5,vrf=0,len=65.... ike V=root:0: IKEv2 exchange=INFORMATIONAL_RESPONSE id=8b79c9b890913093/b8eae4473c0f280c:00000560 len=65 ike 0: in 8B79C9B890913093B8EAE4473C0F280C2E202528000005600000004100000025117C81344801C6B83D7C60976852C4FB0DF6E6D09036A638137341D9EB8EF22737

 

 

 

Best answer by koup

Got solved by a hint in the OpnSense forum:

Phase 2: set "Start action: Trap+Start" and now tunnel stays up (I sometimes lose one ping on re-keying, but that is OK)

4 replies

kaman
Staff
kaman
Staff
January 4, 2025

Hi koup,

The IKE debug logs provided are operational, but they do not help in identifying the root cause of the issue.

Please run the below commands during the time of issue and attach the output:

diagnose debug reset
diagnose debug application Ike -1
diagnose vpn ike log filter rem-addr4 <Remote IP-address>
diagnose debug enable

Regards,
Aman

    AEK
    SuperUser
    AEK
    SuperUser
    January 4, 2025

    Here are some steps I suggest for troubleshooting.

    1. Make sure time is synchronized between the two firewalls (for correct log aggregation)
    2. Make sure rekeying time is the same on both firewalls
    3. Enable timestamp in FGT IKE debug logs so you can aggregate easily the logs of the two firewalls
    4. Once the tunnel breaks check if the time correspond to the rekey time. In case it occurs at the rekey time then you may have the evidence of the root cause

    On the other hand, I sometimes see asic offload can cause some problems for IPsec, so you still can try disable it, just to see if it helps.

    config system global
      set ipsec-asic-offload disable
    end

    config vpn ipsec phase1-interface
      edit phase-1-name
        set npu-offload disable
      end
    end

     

    AEK
    koup
    koupAuthor
    Visitor III
    January 4, 2025

    Thanks for hint. I'll wait for the next hickup and post the debug log, then I'll try your config changes to see if it changes anything.
    The strange thing is that it didn't happen since I posted these messages, still waiting for it

    dingjerry_FTNT
    Staff
    dingjerry_FTNT
    Staff
    January 5, 2025

    Hi @koup ,

     

    On FGT, in IPSec VPN phase2, please make sure enable "keepalive" and "auto-negotiate" settings.  Please also make sure the remote VPN peer has the same functions enabled in phase2.

     

    On FGT, the phase1 lifetime is 28800 seconds and the phase2 lifetime is 3600 seconds. Please make sure the remote peer is matching to the lifetime timers.

    koup
    koupAuthor
    Visitor III
    January 5, 2025

    Today there was a small hick up and I managed to capture a debug log. I have to add that the downtime when the connection breaks is always different. This time only minutes, sometimes its hours.

     

    Log Fortigate:

    ike V=root:0: unknown SPI 55d18a0a 5 xxx.xx.xx.xxx:0->yy.yy.yy.yyy ike V=root:0: unknown SPI 55d18a0a 5 xxx.xx.xx.xxx:0->yy.yy.yy.yyy ike V=root:0: unknown SPI 55d18a0a 5 xxx.xx.xx.xxx:0->yy.yy.yy.yyy ike V=root:0: unknown SPI 55d18a0a 5 xxx.xx.xx.xxx:0->yy.yy.yy.yyy ike V=root:0: unknown SPI 55d18a0a 5 xxx.xx.xx.xxx:0->yy.yy.yy.yyy ike V=root:0: unknown SPI 55d18a0a 5 xxx.xx.xx.xxx:0->yy.yy.yy.yyy ike V=root:0: unknown SPI 55d18a0a 5 xxx.xx.xx.xxx:0->yy.yy.yy.yyy ike V=root:0: unknown SPI 55d18a0a 5 xxx.xx.xx.xxx:0->yy.yy.yy.yyy ike V=root:0: unknown SPI 55d18a0a 5 xxx.xx.xx.xxx:0->yy.yy.yy.yyy ike V=root:0: unknown SPI 55d18a0a 5 xxx.xx.xx.xxx:0->yy.yy.yy.yyy ike V=root:0: unknown SPI 55d18a0a 5 xxx.xx.xx.xxx:0->yy.yy.yy.yyy ike V=root:0: unknown SPI 55d18a0a 5 xxx.xx.xx.xxx:0->yy.yy.yy.yyy ike V=root:0: comes xxx.xx.xx.xxx:500->yy.yy.yy.yyy:500,ifindex=5,vrf=0,len=456.... ike V=root:0: IKEv2 exchange=SA_INIT id=56064d6e839a3194/0000000000000000 len=456 ike 0: in 56064D6E839A319400000000000000002120220800000000000001C82200002800000024010100030300000C01000014800E01000300000802000007000000080400000E28000108000E0000C0E75AB89E13E7D4969F7FF00411C98D0DC31539E43101EE4749EBDFDEA802B8B83A2EF1DAF5670B0D6CCB8DFBD5CB5BA8B37519E9105F1C9D5663D15FD4ADDB243B7A75951D81A19D843143126494B9DD049F35EBB67890576CF749DC2CD6B0C9AB9EAFB5DF55B30B05FC90E00384DBE95827FDBC8C17FBB06746EE14BFD7133F29B90CB4D343AEEEDEADFEB8E35C116CB71A730E7C11A70D5EA15ED8B60E4AEC11CBB167FF797F577AF19317688D3D3C531833ADB8687DC7CC469460AC01BBE15EBAC0733EB2B3A6EA63D33D7F061016898FD6D2E4007AF1333F717E3FC0DECE0931D9587B6998DCB1D5028A7328FE7C5B804C8CC7CCCE18CA7CCBB57BB45829000024331FD5B15AC2BEF38760D7E163C119F0982C61065DED5F36DCDB43B498D9FF1C2900001C00004004838A2296B466D5C10ABB9715B92CDCFC5999A7C62900001C00004005D89406A208CF189CAE6329F4AE67702238820759290000080000402E290000100000402F00020003000400050000000800004016 ike V=root:0:56064d6e839a3194/0000000000000000:82: responder received SA_INIT msg ike V=root:0:56064d6e839a3194/0000000000000000:82: received notify type NAT_DETECTION_SOURCE_IP ike V=root:0:56064d6e839a3194/0000000000000000:82: received notify type NAT_DETECTION_DESTINATION_IP ike V=root:0:56064d6e839a3194/0000000000000000:82: received notify type FRAGMENTATION_SUPPORTED ike V=root:0:56064d6e839a3194/0000000000000000:82: received notify type SIGNATURE_HASH_ALGORITHMS ike V=root:0:56064d6e839a3194/0000000000000000:82: received notify type 16406 ike V=root:0:56064d6e839a3194/0000000000000000:82: ignoring unauthenticated notify payload (16406) ike V=root:0:56064d6e839a3194/0000000000000000:82: incoming proposal: ike V=root:0:56064d6e839a3194/0000000000000000:82: proposal id = 1: ike V=root:0:56064d6e839a3194/0000000000000000:82:   protocol = IKEv2: ike V=root:0:56064d6e839a3194/0000000000000000:82:      encapsulation = IKEv2/none ike V=root:0:56064d6e839a3194/0000000000000000:82:         type=ENCR, val=AES_GCM_16 (key_len = 256) ike V=root:0:56064d6e839a3194/0000000000000000:82:         type=PRF, val=PRF_HMAC_SHA2_512 ike V=root:0:56064d6e839a3194/0000000000000000:82:         type=DH_GROUP, val=MODP2048. ike V=root:0:56064d6e839a3194/0000000000000000:82: matched proposal id 1 ike V=root:0:56064d6e839a3194/0000000000000000:82: proposal id = 1: ike V=root:0:56064d6e839a3194/0000000000000000:82:   protocol = IKEv2: ike V=root:0:56064d6e839a3194/0000000000000000:82:      encapsulation = IKEv2/none ike V=root:0:56064d6e839a3194/0000000000000000:82:         type=ENCR, val=AES_GCM_16 (key_len = 256) ike V=root:0:56064d6e839a3194/0000000000000000:82:         type=INTEGR, val=NONE ike V=root:0:56064d6e839a3194/0000000000000000:82:         type=PRF, val=PRF_HMAC_SHA2_512 ike V=root:0:56064d6e839a3194/0000000000000000:82:         type=DH_GROUP, val=MODP2048. ike V=root:0:56064d6e839a3194/0000000000000000:82: lifetime=28800 ike V=root:0:56064d6e839a3194/0000000000000000:82: SA proposal chosen, matched gateway yyyy_mm ike V=root:0:yyyy_mm:yyyy_mm: created connection: 0x9a2b270 5 yy.yy.yy.yyy->xxx.xx.xx.xxx:500. ike V=root:0:yyyy_mm:82: processing notify type NAT_DETECTION_SOURCE_IP ike V=root:0:yyyy_mm:82: processing NAT-D payload ike V=root:0:yyyy_mm:82: NAT not detected  ike V=root:0:yyyy_mm:82: process NAT-D ike V=root:0:yyyy_mm:82: processing notify type NAT_DETECTION_DESTINATION_IP ike V=root:0:yyyy_mm:82: processing NAT-D payload ike V=root:0:yyyy_mm:82: NAT not detected  ike V=root:0:yyyy_mm:82: process NAT-D ike V=root:0:yyyy_mm:82: processing notify type FRAGMENTATION_SUPPORTED ike V=root:0:yyyy_mm:82: processing notify type SIGNATURE_HASH_ALGORITHMS ike V=root:0:yyyy_mm:82: responder preparing SA_INIT msg ike V=root:0:yyyy_mm:82: create NAT-D hash local yy.yy.yy.yyy/500 remote xxx.xx.xx.xxx/500 ike 0:yyyy_mm:82: out 56064D6E839A3194856B52A6F79728172120222000000000000001A02200002800000024010100030300000C01000014800E01000300000802000007000000080400000E28000108000E000009BB569FA525C3D4809FB709D7A78F2B2F1881561B682729E0E622DA6463EAE983C2FCC59D08D7A2B6B694A1AA42E4D7D7ED279166A32BF248AB7222C66DC07C2C4B04586A58B4D7F3C59BFAF6E184CCB61D261CCDD072E876450C463F707BC8BE660FC85AC7F4B550119ECEA9268B3C2D5E9082A1BB197D379719769AFD0E22FBC8D27725043EAC2B6004E68FB0FE76F009A0802368864B44A68BCAA8068D04079D276DFD70572A11B4F9D2EF6034651AAC43193D6DA876E714FB7140E5C7ED88C6B0F014F456C2B8FC1F3AFEAB78858660514F4057A26D5B212F473B214C421107F9B6F16DC39C9ACD44FCF1D8AE91FAEA4403D64D776D77833B35B2673C4429000014E4BB39D70E0108D4DF220AE06E8A48002900001C000040046E1F6C99101FA3013FA44B7E136560962BD6A21C2900001C000040050D4E3A01D7FDDE48B9B09E3B9E6A9F02E64DF274000000080000402E ike V=root:0:yyyy_mm:82: sent IKE msg (SA_INIT_RESPONSE): yy.yy.yy.yyy:500->xxx.xx.xx.xxx:500, len=416, vrf=0, id=56064d6e839a3194/856b52a6f7972817, oif=5 ike 0:yyyy_mm:82: IKE SA 56064d6e839a3194/856b52a6f7972817 SK_ei 36:3534A6DC7A9D0C6559C1401E1AC53A0CD82F3D779163CF42A3A8E3012C7D69FFA4B979F1 ike 0:yyyy_mm:82: IKE SA 56064d6e839a3194/856b52a6f7972817 SK_er 36:763AAC19B2D4B7D30B534AC418E0FD73D48DF156663FEB9F696AD99024248B1DFA13DE3E ike V=root:0: comes xxx.xx.xx.xxx:500->yy.yy.yy.yyy:500,ifindex=5,vrf=0,len=295.... ike V=root:0: IKEv2 exchange=AUTH id=56064d6e839a3194/856b52a6f7972817:00000001 len=295 ike 0: in 56064D6E839A3194856B52A6F79728172E20230800000001000001272300010B45D6702A175AD036968AABDE086261B08C34B0C5AEBAF5BFF73039ABAD0A7E336FA3870FA9E620538CA73C8A6EEB7724E14C4C7CEBC285ABB2AC83881BC2BE7211728920DED497B5DA0FD639715D0FE2E4B37E88251DA7094AFB39A9D48CF2EA120CDD3F7CC153F6657829E59CAFACA017FBE30BA4120390569628CC722544397A74A32A75034D133FCE146528B464A6FC0C254E9800CA374363CEEEBCDE74FED362FE8FCFE71230AF4EE9B44B1B236F8E4EC964B0FBF61AD23B624F8C8AA057A289704162F2BCB055FFE5E31D22C3F719B2C42C5836E485939D507577E1D886A6C66949E88BA33404711B23FF6A53EC003FB471035CEA40FE4237BAD7AA21CAB6DCB80E881A7C ike 0:yyyy_mm:82: dec 56064D6E839A3194856B52A6F79728172E202308000000010000010E230000042900001C0200000063796265726D636D2E6475636B646E732E6F72672400000800004000270000160200000072656D6F74652E6B6F75702E617429000048020000004BE1664199ADB2BF299E387B7AA322899B9273AE315C1B355D390737488E308A7BE8A45662645467E3BD714E57ECB87D51D9C173672D2966775B60D42C5A6EC2210000080000400A2C0000240000002001030402CBC9EA9B0300000C01000014800E010000000008050000002D00001801000000070000100000FFFFC0A80A00C0A80AFF2900001801000000070000100000FFFFC0A8A900C0A8A9FF29000008000040210000000800004024 ike V=root:0:yyyy_mm:82: responder received AUTH msg ike V=root:0:yyyy_mm:82: processing notify type INITIAL_CONTACT ike V=root:0:yyyy_mm:82: processing notify type ESP_TFC_PADDING_NOT_SUPPORTED ike V=root:0:yyyy_mm:82: processing notify type EAP_ONLY_AUTHENTICATION ike V=root:0:yyyy_mm:82: processing notify type MESSAGE_ID_SYNC_SUPPORTED ike V=root:0:yyyy_mm:82: received peer identifier FQDN 'xxxxxxxx.xxxxxxx.org' ike V=root:0:yyyy_mm:82: auth verify done ike V=root:0:yyyy_mm:82: responder AUTH continuation ike V=root:0:yyyy_mm:82: authentication succeeded ike V=root:0:yyyy_mm:82: responder creating new child ike V=root:0:yyyy_mm:82:6459: peer proposal: ike V=root:0:yyyy_mm:82:6459: TSi_0 0:192.168.10.0-192.168.10.255:0 ike V=root:0:yyyy_mm:82:6459: TSr_0 0:192.168.169.0-192.168.169.255:0 ike V=root:0:yyyy_mm:82:yyyy_mm:6459: comparing selectors ike V=root:0:yyyy_mm:82:yyyy_mm:6459: matched by rfc-rule-2 ike V=root:0:yyyy_mm:82:yyyy_mm:6459: phase2 matched by subset ike V=root:0:yyyy_mm:82:yyyy_mm:6459: accepted proposal: ike V=root:0:yyyy_mm:82:yyyy_mm:6459: TSi_0 0:192.168.10.0-192.168.10.255:0 ike V=root:0:yyyy_mm:82:yyyy_mm:6459: TSr_0 0:192.168.169.0-192.168.169.255:0 ike V=root:0:yyyy_mm:82:yyyy_mm:6459: autokey ike V=root:0:yyyy_mm:82:yyyy_mm:6459: incoming child SA proposal: ike V=root:0:yyyy_mm:82:yyyy_mm:6459: proposal id = 1: ike V=root:0:yyyy_mm:82:yyyy_mm:6459:   protocol = ESP: ike V=root:0:yyyy_mm:82:yyyy_mm:6459:      encapsulation = TUNNEL ike V=root:0:yyyy_mm:82:yyyy_mm:6459:         type=ENCR, val=AES_GCM_16 (key_len = 256) ike V=root:0:yyyy_mm:82:yyyy_mm:6459:         type=ESN, val=NO ike V=root:0:yyyy_mm:82:yyyy_mm:6459:         PFS is disabled ike V=root:0:yyyy_mm:82:yyyy_mm:6459: matched proposal id 1 ike V=root:0:yyyy_mm:82:yyyy_mm:6459: proposal id = 1: ike V=root:0:yyyy_mm:82:yyyy_mm:6459:   protocol = ESP: ike V=root:0:yyyy_mm:82:yyyy_mm:6459:      encapsulation = TUNNEL ike V=root:0:yyyy_mm:82:yyyy_mm:6459:         type=ENCR, val=AES_GCM_16 (key_len = 256) ike V=root:0:yyyy_mm:82:yyyy_mm:6459:         type=INTEGR, val=AUTH_NONE ike V=root:0:yyyy_mm:82:yyyy_mm:6459:         type=ESN, val=NO ike V=root:0:yyyy_mm:82:yyyy_mm:6459:         PFS is disabled ike V=root:0:yyyy_mm:82:yyyy_mm:6459: lifetime=3600 ike V=root:0:yyyy_mm:82: responder preparing AUTH msg ike V=root:0:yyyy_mm:82: established IKE SA 56064d6e839a3194/856b52a6f7972817 ike V=root:0:yyyy_mm:82: check peer route: if_addr4_rcvd=0, if_addr6_rcvd=0, mode_cfg=0 ike V=root:0:yyyy_mm:82: processing INITIAL-CONTACT ike V=root:0:yyyy_mm: flushing  ike V=root:0:yyyy_mm: flushed  ike V=root:0:yyyy_mm:82: processed INITIAL-CONTACT ike V=root:0:yyyy_mm:82:yyyy_mm:6459: set sa life soft seconds=3330. ike V=root:0:yyyy_mm:82:yyyy_mm:6459: set sa life hard seconds=3600. ike V=root:0:yyyy_mm:82:yyyy_mm:6459: IPsec SA selectors #src=1 #dst=1 ike V=root:0:yyyy_mm:82:yyyy_mm:6459: src 0 7 0:192.168.169.0-192.168.169.255:0 ike V=root:0:yyyy_mm:82:yyyy_mm:6459: dst 0 7 0:192.168.10.0-192.168.10.255:0 ike V=root:0:yyyy_mm:82:yyyy_mm:6459: add IPsec SA: SPIs=55d18a0c/cbc9ea9b ike 0:yyyy_mm:82:yyyy_mm:6459: IPsec SA dec spi 55d18a0c key 36:2D6A0F808D0067B44EE5D66F8E40F5D9DCC1F8DB208A0D7DE67796D59FF3C0AFAC480525 auth 0: ike 0:yyyy_mm:82:yyyy_mm:6459: IPsec SA enc spi cbc9ea9b key 36:54F4590FCA2AC278ECABC546E9D2B2441EB3BB33F9F58CE698A9FA85E845476C9E358094 auth 0: ike V=root:0:yyyy_mm:82:yyyy_mm:6459: added IPsec SA: SPIs=55d18a0c/cbc9ea9b ike V=root:0:yyyy_mm:82:yyyy_mm:6459: sending SNMP tunnel UP trap ike V=root:0:yyyy_mm: static tunnel up event 0.0.0.0 (dev=24) ike V=root:0:yyyy_mm: static tunnel up event :: (dev=24) ike 0:yyyy_mm:82: enc 270000160200000072656D6F74652E6B6F75702E61742900004802000000D32DAC56203CD9D1C40538A284EF0302F565C694816896526EB3CACA7B94F7EA48179EC73373A8ED8A80A5595D7F65DB592135E256DEB555F477AA381BB1C26821000008000040242C000024000000200103040255D18A0C0300000C01000014800E010000000008050000002D00001801000000070000100000FFFFC0A80A00C0A80AFF0000001801000000070000100000FFFFC0A8A900C0A8A9FF080706050403020108 ike 0:yyyy_mm:82: out 56064D6E839A3194856B52A6F79728172E20232000000001000000FB240000DFA55C8017AF6D63D8494E8004994D1ADA8AE04B021449ADEF9624EFA4A3F807D4A555DB979407F4A1414F412751CA5DE2524AF6F13085D12D37B407FCB4F0B2554D6CA5036EE42455CA37661611636BE3C9BD3FD3FA39631FD24B391AE25E81457649E742A43283C607CA42E58332CB3E89E27FC82C8A1C446A6F8367B2BD8671BF43DBCFE56E198F88809EB6E4EC5540C783185C2460B6EF9202C2A2ABC3E899DAED91CF8B50C76F173F252CE82DBCB801BDDDFA28F7BAC23A1546D01DA5A35F7D17F0EC9ADBB3A13C03CEF74BE017C2D8B1D6571DA8CB16B7AB7D ike V=root:0:yyyy_mm:82: sent IKE msg (AUTH_RESPONSE): yy.yy.yy.yyy:500->xxx.xx.xx.xxx:500, len=251, vrf=0, id=56064d6e839a3194/856b52a6f7972817:00000001, oif=5 ike :shrank heap by 126976 bytes ike :shrank heap by 4096 bytes

     

    Log OpnSense:

    2025-01-05T08:33:24	20	Notice	charon	25162	[UPDOWN] received up-client event for reqid 2	 2025-01-05T08:33:24	3	Informational	charon	36361	06[IKE] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|1680> CHILD_SA 38ecc2d4-7b62-4bae-a3a1-58ac8e93bc9f{114} established with SPIs cbc9ea9b_i 55d18a0c_o and TS 192.168.10.0/24 === 192.168.169.0/24	 2025-01-05T08:33:24	3	Informational	charon	36361	06[CFG] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|1680> selected proposal: ESP:AES_GCM_16_256/NO_EXT_SEQ	 2025-01-05T08:33:24	3	Informational	charon	36361	06[IKE] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|1680> maximum IKE_SA lifetime 30342s	 2025-01-05T08:33:24	3	Informational	charon	36361	06[IKE] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|1680> scheduling rekeying in 27462s	 2025-01-05T08:33:24	3	Informational	charon	36361	06[IKE] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|1680> IKE_SA a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5[1680] established between xxx.xx.xx.xxx[xxxxxxxx.xxxxxxxx.org]...yy.yy.yy.yyy[remote.yyyy.yy]	 2025-01-05T08:33:24	3	Informational	charon	36361	06[IKE] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|1680> authentication of 'remote.yyyy.yy' with pre-shared key successful	 2025-01-05T08:33:24	3	Informational	charon	36361	06[ENC] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|1680> parsed IKE_AUTH response 1 [ IDr AUTH N(MSG_ID_SYN_SUP) SA TSi TSr ]	 2025-01-05T08:33:24	3	Informational	charon	36361	06[NET] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|1680> received packet: from yy.yy.yy.yyy[500] to xxx.xx.xx.xxx[500] (251 bytes)	 2025-01-05T08:33:24	3	Informational	charon	36361	06[NET] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|1680> sending packet: from xxx.xx.xx.xxx[500] to yy.yy.yy.yyy[500] (295 bytes)	 2025-01-05T08:33:24	3	Informational	charon	36361	06[ENC] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|1680> generating IKE_AUTH request 1 [ IDi N(INIT_CONTACT) IDr AUTH N(ESP_TFC_PAD_N) SA TSi TSr N(EAP_ONLY) N(MSG_ID_SYN_SUP) ]	 2025-01-05T08:33:24	3	Informational	charon	36361	06[IKE] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|1680> establishing CHILD_SA 38ecc2d4-7b62-4bae-a3a1-58ac8e93bc9f{114} reqid 2	 2025-01-05T08:33:24	3	Informational	charon	36361	06[IKE] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|1680> authentication of 'xxxxxxxx.xxxxxxxx.org' (myself) with pre-shared key	 2025-01-05T08:33:24	3	Informational	charon	36361	06[CFG] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|1680> selected proposal: IKE:AES_GCM_16_256/PRF_HMAC_SHA2_512/MODP_2048	 2025-01-05T08:33:24	3	Informational	charon	36361	06[ENC] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|1680> parsed IKE_SA_INIT response 0 [ SA KE No N(NATD_S_IP) N(NATD_D_IP) N(FRAG_SUP) ]	 2025-01-05T08:33:24	3	Informational	charon	36361	06[NET] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|1680> received packet: from yy.yy.yy.yyy[500] to xxx.xx.xx.xxx[500] (416 bytes)	 2025-01-05T08:33:24	3	Informational	charon	36361	06[NET] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|1680> sending packet: from xxx.xx.xx.xxx[500] to yy.yy.yy.yyy[500] (456 bytes)	 2025-01-05T08:33:24	3	Informational	charon	36361	06[ENC] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|1680> generating IKE_SA_INIT request 0 [ SA KE No N(NATD_S_IP) N(NATD_D_IP) N(FRAG_SUP) N(HASH_ALG) N(REDIR_SUP) ]	 2025-01-05T08:33:24	3	Informational	charon	36361	06[IKE] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|1680> initiating IKE_SA a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5[1680] to yy.yy.yy.yyy	 2025-01-05T08:33:24	3	Informational	charon	36361	06[KNL] creating acquire job for policy 188.22.84.55/32 === yy.yy.yy.yyy/32 with reqid {2}	 2025-01-05T08:33:20	3	Informational	charon	36361	06[KNL] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|1679> unable to delete SAD entry with SPI c18f912c: No such process (3)	 2025-01-05T08:33:20	3	Informational	charon	36361	06[IKE] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|1679> giving up after 5 retransmits	 2025-01-05T08:32:05	3	Informational	charon	36361	16[NET] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|1679> sending packet: from xxx.xx.xx.xxx[500] to yy.yy.yy.yyy[500] (469 bytes)	 2025-01-05T08:32:05	3	Informational	charon	36361	16[IKE] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|1679> retransmit 5 of request with message ID 6	 2025-01-05T08:31:57	3	Informational	charon	36361	16[KNL] creating rekey job for CHILD_SA ESP/0x55d18a0a/yy.yy.yy.yyy	 2025-01-05T08:31:23	3	Informational	charon	36361	16[NET] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|1679> sending packet: from xxx.xx.xx.xxx[500] to yy.yy.yy.yyy[500] (469 bytes)	 2025-01-05T08:31:23	3	Informational	charon	36361	16[IKE] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|1679> retransmit 4 of request with message ID 6	 2025-01-05T08:30:59	3	Informational	charon	36361	08[NET] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|1679> sending packet: from xxx.xx.xx.xxx[500] to yy.yy.yy.yyy[500] (469 bytes)	 2025-01-05T08:30:59	3	Informational	charon	36361	08[IKE] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|1679> retransmit 3 of request with message ID 6	 2025-01-05T08:30:46	3	Informational	charon	36361	08[NET] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|1679> sending packet: from xxx.xx.xx.xxx[500] to yy.yy.yy.yyy[500] (469 bytes)	 2025-01-05T08:30:46	3	Informational	charon	36361	08[IKE] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|1679> retransmit 2 of request with message ID 6	 2025-01-05T08:30:39	3	Informational	charon	36361	08[NET] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|1679> sending packet: from xxx.xx.xx.xxx[500] to yy.yy.yy.yyy[500] (469 bytes)	 2025-01-05T08:30:39	3	Informational	charon	36361	08[IKE] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|1679> retransmit 1 of request with message ID 6	 2025-01-05T08:30:35	3	Informational	charon	36361	08[NET] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|1679> sending packet: from xxx.xx.xx.xxx[500] to yy.yy.yy.yyy[500] (469 bytes)	 2025-01-05T08:30:35	3	Informational	charon	36361	08[ENC] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|1679> generating CREATE_CHILD_SA request 6 [ N(REKEY_SA) N(ESP_TFC_PAD_N) SA No KE TSi TSr ]	 2025-01-05T08:30:35	3	Informational	charon	36361	08[IKE] <a075e27f-ad8d-4e7a-bd35-2f5c5ea0cee5|1679> establishing CHILD_SA 38ecc2d4-7b62-4bae-a3a1-58ac8e93bc9f{113} reqid 2	 2025-01-05T08:30:35	3	Informational	charon	36361	13[KNL] creating rekey job for CHILD_SA ESP/0xc7cd53a6/xxx.xx.xx.xxx

     

    AEK
    SuperUser
    AEK
    SuperUser
    January 5, 2025

    Unfortunately we don't see timestamp in FGT logs. Try to enable them so you can correlate the logs with OPNsense logs.

     

    On the other hand, "unknown SPI" message that you see on FGT should mean that there was a rekeying from OPNsense but not from FGT side. This lead to FGT doesn't recognize the new SPI (Security Parameter Index) recreated by the rekey action.

    https://community.fortinet.com/t5/FortiGate/Technical-Tip-Explanation-of-Unknown-SPI-message-in-Event-log/ta-p/190530

     

    The question remains why OPNsense is rekeying before the rekey time is reached.

     

    May be you can try another IPsec software instead of OPNsense, like strongSwan, just to see if the behavior is the same.

    https://community.fortinet.com/t5/FortiGate/Technical-Tip-FortiGate-Site-to-Site-VPN-with-Strongswan-on/ta-p/275092

    Hope it helps.

    AEK
    koup
    koupAuthor
    Visitor III
    January 7, 2025

    Thanks for your answer. OpnSense uses strongSwan as far as I know.
    Out of curiosity, I tried the old IPSec legacy mode (historically this section was for racoon IPsec which was also supported by StrongSwan but now deprecated and the new MVC connections) and discovered that it is stable with this mode. I think I've to continue this issue with the OpnSense community since this seems OpnSense related

      koup
      koupAuthorAnswer
      Visitor III
      January 9, 2025

      Got solved by a hint in the OpnSense forum:

      Phase 2: set "Start action: Trap+Start" and now tunnel stays up (I sometimes lose one ping on re-keying, but that is OK)

        Terms & ConditionsAccessibility statement