Support Forum
The Forums are a place to find answers on a range of Fortinet products from peers and product experts.
koup
New Contributor

Unstable IPSec tunnel between Fortigate and OpnSense

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

 

 

 

7 REPLIES 7
kaman
Staff
Staff

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
SuperUser

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
AEK
koup
New Contributor

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

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.

Regards,

Jerry
koup

The lifetime settings match, I did check this more than once ;) 

I think that the problem is with OpnSense, I did capture another log, see below. But I don't know how to fix that.

koup
New Contributor

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

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-Even...

 

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...

Hope it helps.

AEK
AEK
Announcements

Select Forum Responses to become Knowledge Articles!

Select the “Nominate to Knowledge Base” button to recommend a forum post to become a knowledge article.

Labels
Top Kudoed Authors