Unstable IPSec tunnel between OpnSense and Fortigate

Started by cybermcm, December 28, 2024, 10:30:21 PM

Previous topic - Next topic
Print
Go Down Pages1
User actions
December 28, 2024, 10:30:21 PM Last Edit: January 04, 2025, 01:42:15 PM by cybermcm
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.

I can probably catch the Fortigate log next time it happens.
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.


Code Select
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
December 29, 2024, 09:45:05 PM #1 Last Edit: January 04, 2025, 01:42:24 PM by cybermcm
Update: 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.

Code Select
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
January 04, 2025, 01:42:55 PM #2
January 06, 2025, 06:32:12 PM #3
I had an annoying issue where a tunnel worked for 48h and then it just "gave up" even though there was traffic trying to flow from both sides [other end is a Cisco ASA but I don't manage it so can't say much more than that].
I set "Start action: Trap+Start" on both child SAs and that seems to have helped, has been up for nearly 90h now.
Print
Go Up Pages1
User actions