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

Created on ‎01-21-2025 05:51 AM

IPSEC phase 1 SA lifetime not honouring configured setting of 28800

hi

 

I am trying to figure out why our fortigate configuration is not honouring the phase 1 lifetime setting of 28800s (8hrs)

Over the weekend I started monitoring the tunnel with pingplotter and noticed a clear pattern as to when the phase 1 rekey happens.

the rekey would start the process after 7hrs 38min, not the 8hrs as configured on the fortigate.

the other thing thats happening is that during this time, network connectivity between the fortigate and azure is down for about 45-60s.

using pingplotter i can see a clear pattern with this and that the rekey happens every 7hrs38min 

(excluding full tunnel drops) causing network connectivity issues along the way.

 

here are the time stamps from pingplotter showing phase1 rekey.
the tunnel drop timestamp indicates that the full tunnel went down.


17/01 - 15:43
17/01 - 23:20 + 7hrs 37min
18/01 - 06:58 + 7hrs 18min (tunnel drop)
18/01 - 14:36 + 7hrs 38min
18/01 - 22:14 + 7hrs 38min
19/01 - 05:52 + 7hrs 38min
19/01 - 13:29 + 7hrs 37min
19/01 - 21:07 + 7hrs 38min
20/01 - 04:45 + 7hrs 38min
20/01 - 12:23 + 7hrs 38min
20/01 - 20:01 + 7hrs 38min (tunnel drop)
21/01 - 03:39 + 7hrs 38min
21/01 - 11:17 + 7hrs 38min

 

as you can see, a distinct pattern is visible.
i have cross checked all these times with app errors, tasks/schedules, fortigate logs etc and they all match up.

 

so my question is...

does anybody know how or why the phase 1 lifetime setting is not working as expected? is this a bug?

7hrs38min is a very random time but its consistent. Also weird that during this time we lose network connectivity.


has anybody seen/come across something like this before?

 

i have raised a ticket with support and waiting for a reply

 

fortigate details

Fortigate 1800F

v7.2.9 build 1688

 

 

cheers,

 

Labels:
1341
0 Kudos
14 REPLIES 14
pminarik
Staff
Staff
In response to RogerDingoDing

Created on ‎01-24-2025 07:22 AM

I don't see MTU as a likely issue. You seem to be using PSK-based auth and the maximum payload size seen in the debugs so far is 388 bytes, which is very very far from MTU issue territory. MTU would be more likely if certificate-based authentication were involved (regular cert-auth or an EAP method involving certificates)

 

Policy MSS settings isn't relevant here. 1: This is UDP packets, 2 policy applies to other traffic being tunneled ("data channel"), this is control traffic between the two tunnel endpoints.

[ corrections always welcome ]
267
RogerDingoDing
New Contributor
In response to pminarik

Created on ‎01-24-2025 07:57 AM

ok thanks for confirming.

 

ill try and get more debug logs and a wireshark capture ... see whats in there.

 

ill update once i got more info

 

cheers

265
0 Kudos
RogerDingoDing
New Contributor
In response to pminarik

Created on ‎01-22-2025 03:29 AM Edited on ‎01-22-2025 03:53 AM

sorry double post

447
0 Kudos
RogerDingoDing
New Contributor

Created on ‎02-05-2025 04:18 AM Edited on ‎02-05-2025 04:19 AM

hi,

I managed to grab a wireshark capture from the diagnostics option in the GUI. The capture was targeting the Azure IP, however there was nothing there to indicate any network issues between the 2 locations. No drops or anything to indicate a timeout issue.

 

most of the capture contains this ESP protocol info.

 

 

1 0.000000 FORTIGATEIP AZUREIP ESP 138 ESP (SPI=0x4fac85ac)
2 0.084981 FORTIGATEIP AZUREIP ESP 826 ESP (SPI=0x4fac85ac)
3 0.084989 FORTIGATEIP AZUREIP ESP 730 ESP (SPI=0x4fac85ac)
4 0.084993 FORTIGATEIP AZUREIP ESP 810 ESP (SPI=0x4fac85ac)
5 0.084997 FORTIGATEIP AZUREIP ESP 858 ESP (SPI=0x4fac85ac)
6 0.085001 FORTIGATEIP AZUREIP ESP 826 ESP (SPI=0x4fac85ac)

 


theres an occasional warning in the ESP packets that mentions the following. 

 

Encapsulating Security Payload

ESP SPI: 0x4fac85ac (1336706476)

ESP Sequence: 1725441

[Expected SN: 1724730 (711 SNs missing)]

[Expert Info (Warning/Sequence): Wrong Sequence Number for SPI 4fac85ac - 711 missing]

[Wrong Sequence Number for SPI 4fac85ac - 711 missing]

[Severity level: Warning]

[Group: Sequence]

[Previous Frame: 5921]

 

 

the only other info in the capture that is different to the above is this

 

 

5787	74.918812	AZUREIP	FORTIGATEIP	ISAKMP	362	CREATE_CHILD_SA MID=02 Initiator Request
5874	75.918826	AZUREIP	FORTIGATEIP	ISAKMP	362	CREATE_CHILD_SA MID=02 Initiator Request
5922	76.926868	AZUREIP	FORTIGATEIP	ISAKMP	362	CREATE_CHILD_SA MID=02 Initiator Request
6159	79.938075	AZUREIP	FORTIGATEIP	ISAKMP	362	CREATE_CHILD_SA MID=02 Initiator Request
6597	86.945831	AZUREIP	FORTIGATEIP	ISAKMP	362	CREATE_CHILD_SA MID=02 Initiator Request
7599	100.956426	AZUREIP	FORTIGATEIP	ISAKMP	362	CREATE_CHILD_SA MID=02 Initiator Request
14239	181.661070	FORTIGATEIP	AZUREIP	ISAKMP	122	INFORMATIONAL MID=16 Responder Request
14460	182.855993	AZUREIP	FORTIGATEIP	ISAKMP	430	IKE_SA_INIT MID=00 Initiator Request
14461	182.856582	FORTIGATEIP	AZUREIP	ISAKMP	274	IKE_SA_INIT MID=00 Responder Response
14462	182.861951	AZUREIP	FORTIGATEIP	ISAKMP	266	IKE_AUTH MID=01 Initiator Request
14463	182.862558	FORTIGATEIP	AZUREIP	ISAKMP	266	IKE_AUTH MID=01 Responder Response
14622	184.663714	FORTIGATEIP	AZUREIP	ISAKMP	122	INFORMATIONAL MID=16 Responder Request
15197	190.668750	FORTIGATEIP	AZUREIP	ISAKMP	122	INFORMATIONAL MID=16 Responder Request
16234	202.668321	FORTIGATEIP	AZUREIP	ISAKMP	122	INFORMATIONAL MID=16 Responder Request
17870	226.670918	FORTIGATEIP	AZUREIP	ISAKMP	122	INFORMATIONAL MID=16 Responder Request
21839	274.669037	FORTIGATEIP	AZUREIP	ISAKMP	122	INFORMATIONAL MID=16 Responder Request

 

 

as i said, no mention of any IKE SA timeout errors in the packet capture. Is there a way to configure the packet capture to grab more indepth info? 


Following advise from fortinet support we made the following changes our IPsec tunnel.

 

  • enable PFS for phase 2, group 19
  • enable PFS in azure, set as ECP256
  • change DPD settings, set as retry count 6, interval 15s

 

these change seem to have made a difference in terms of the length of the network drop.. it is now down for 30s instead of 60s during the rekey phase.

 

the error negotiation of IKE SA failed due to retry timeout is still happening.

 

heres the latest debug log from today.

 

 

Fortigate # 2025-02-05 10:52:59.099430 ike shrank heap by 159744 bytes
2025-02-05 10:54:46.988125 ike 0:IPSECTUNNEL: HA IPsec send ESP seqno=f30000, num=1
2025-02-05 10:56:48.225776 ike 0:IPSECTUNNEL: link is idle 0 FORTIGATEIP->AZUREIP:0 dpd=2 seqno=7 rr=0
2025-02-05 10:56:48.225817 ike 0:IPSECTUNNEL:4119: send IKEv2 DPD probe, seqno 7
2025-02-05 10:56:48.225859 ike 0:IPSECTUNNEL:15626: sending NOTIFY msg
2025-02-05 10:56:48.225871 ike 0:IPSECTUNNEL:4119:15626: send informational
2025-02-05 10:56:48.225889 ike 0:IPSECTUNNEL:4119: enc 0F0E0D0C0Bdfdfdf0A0908070605040302010F
2025-02-05 10:56:48.225931 ike 0:IPSECTUNNEL:4119: out F57DAFA69F19718B6D41A0080dfdfd343434fjkj9F44BD62E2025000000001000000050000000344BA3D960FD81258F6DF45CD53C5BDD2CF7F3FA3D360
6FB30B26CADAFF6F1C62602429A68789EF7E933FAFFD6C4F989FE
2025-02-05 10:56:48.225958 ike 0:IPSECTUNNEL:4119: sent IKE msg (INFORMATIONAL): FORTIGATEIP:500->AZUREIP:500, len=80, vrf=0, id=f57dafa69f19718b/6d41a008
09f44bd6:00000010
2025-02-05 10:56:49.335175 ike 0: comes AZUREIP:500->FORTIGATEIP:500,ifindex=35,vrf=0....
2025-02-05 10:56:49.335214 ike 0: IKEv2 exchange=SA_INIT id=5a54cf6ff8006108/0000000000000000 len=388
2025-02-05 10:56:49.335252 ike 0: in 5A54CF6FF80061080000000000000000212022080000000000000184220000300000002C010100040300000C0100000C800E0100030000080300000C030000080
200000500000008040000022800008800020000959D5CC7C546889A79D168B0A84BDC3CC4664DGESG0F347ACBE9AFCCEBEBF46A60A28678227E6B95A26EBDCBFA3264A97E9D7E20A543433BE346BBFAC77BB5C848A82
38D41E4A44A2D62BC69C612301F5F7172E9AE29E3293610BD9E8C7A4118872DEB8F89DD33886C34209B17CCF1B432181FE2975558D7537E79A5873D37DF888660046C29000034E580EF2148CAC1F49263D5893F875
CC405967B4B6A24C01CE4073F9A215332F358DC9D53A4BD0DC45F8E7952E218E218290000DDGH1C00004004317BE95A8185508B28F07D9BE6E33912AD6C010A2B00001C00004005BCFCF63B0FB087CF6AE067D96CB
C443EAD1CBE3E2B0000181E2B51690599D333HJ1C7D7C96FCBFB587E461000000092B000014FB1DE3CDF341B7EA16B7E5BE0855F1200000001801528BBBC00696121849AB9A1C5B2A5100000002
2025-02-05 10:56:49.335280 ike 0:5a54cf6ff8006108/0000000000000000:5115: responder received SA_INIT msg
2025-02-05 10:56:49.335295 ike 0:5a54cf6ff8006108/0000000000000000:5115: received notify type NAT_DETECTION_SOURCE_IP
2025-02-05 10:56:49.335305 ike 0:5a54cf6ff8006108/0000000000000000:5115: received notify type NAT_DETECTION_DESTINATION_IP
2025-02-05 10:56:49.335314 ike 0:5a54cf6ff8006108/0000000000000000:5115: VID MS NT5 ISAKMPOAKLEY 1E2B51690HKLYRXBJ15991C7D7C96FCBFB587E46100000009
2025-02-05 10:56:49.335323 ike 0:5a54cf6ff8006108/0000000000000000:5115: VID unknown (16): FB1DE3CDF3FHJ4DDA41B7EA16B7E5BE0855F120
2025-02-05 10:56:49.335332 ike 0:5a54cf6ff8006108/0000000000000000:5115: VID unknown (20): 01528BBBC4560069612UKYD11331849AB9A1C5B2A5100000002
2025-02-05 10:56:49.335343 ike 0:5a54cf6ff8006108/0000000000000000:5115: incoming proposal:
2025-02-05 10:56:49.335357 ike 0:5a54cf6ff8006108/0000000000000000:5115: proposal id = 1:
2025-02-05 10:56:49.335364 ike 0:5a54cf6ff8006108/0000000000000000:5115:   protocol = IKEv2:
2025-02-05 10:56:49.335370 ike 0:5a54cf6ff8006108/0000000000000000:5115:      encapsulation = IKEv2/none
2025-02-05 10:56:49.335377 ike 0:5a54cf6ff8006108/0000000000000000:5115:         type=ENCR, val=AES_CBC (key_len = 256)
2025-02-05 10:56:49.335385 ike 0:5a54cf6ff8006108/0000000000000000:5115:         type=INTEGR, val=AUTH_HMAC_SHA2_256_128
2025-02-05 10:56:49.335391 ike 0:5a54cf6ff8006108/0000000000000000:5115:         type=PRF, val=PRF_HMAC_SHA2_256
2025-02-05 10:56:49.335399 ike 0:5a54cf6ff8006108/0000000000000000:5115:         type=DH_GROUP, val=MODP1024.
2025-02-05 10:56:49.335413 ike 0:5a54cf6ff8006108/0000000000000000:5115: matched proposal id 1
2025-02-05 10:56:49.335423 ike 0:5a54cf6ff8006108/0000000000000000:5115: proposal id = 1:
2025-02-05 10:56:49.335430 ike 0:5a54cf6ff8006108/0000000000000000:5115:   protocol = IKEv2:
2025-02-05 10:56:49.335437 ike 0:5a54cf6ff8006108/0000000000000000:5115:      encapsulation = IKEv2/none
2025-02-05 10:56:49.335443 ike 0:5a54cf6ff8006108/0000000000000000:5115:         type=ENCR, val=AES_CBC (key_len = 256)
2025-02-05 10:56:49.335450 ike 0:5a54cf6ff8006108/0000000000000000:5115:         type=INTEGR, val=AUTH_HMAC_SHA2_256_128
2025-02-05 10:56:49.335457 ike 0:5a54cf6ff8006108/0000000000000000:5115:         type=PRF, val=PRF_HMAC_SHA2_256
2025-02-05 10:56:49.335464 ike 0:5a54cf6ff8006108/0000000000000000:5115:         type=DH_GROUP, val=MODP1024.
2025-02-05 10:56:49.335470 ike 0:5a54cf6ff8006108/0000000000000000:5115: lifetime=28800
2025-02-05 10:56:49.335479 ike 0:5a54cf6ff8006108/0000000000000000:5115: SA proposal chosen, matched gateway IPSECTUNNEL
2025-02-05 10:56:49.335495 ike 0: found IPSECTUNNEL FORTIGATEIP 0 -> AZUREIP:500
2025-02-05 10:56:49.335502 ike 0:IPSECTUNNEL tunnel is on loopback intf, reset oif 35 to 0
2025-02-05 10:56:49.335510 ike 0:IPSECTUNNEL: HA state master(2)
2025-02-05 10:56:49.335521 ike 0:IPSECTUNNEL:5115: processing notify type NAT_DETECTION_SOURCE_IP
2025-02-05 10:56:49.335545 ike 0:IPSECTUNNEL:5115: ignoring unauthenticated notify payload (NAT_DETECTION_SOURCE_IP)
2025-02-05 10:56:49.335557 ike 0:IPSECTUNNEL:5115: processing notify type NAT_DETECTION_DESTINATION_IP
2025-02-05 10:56:49.335567 ike 0:IPSECTUNNEL:5115: ignoring unauthenticated notify payload (NAT_DETECTION_DESTINATION_IP)
2025-02-05 10:56:49.335588 ike 0:IPSECTUNNEL:5115: responder preparing SA_INIT msg
2025-02-05 10:56:49.335606 ike 0:IPSECTUNNEL:5115: generate DH public value request queued
2025-02-05 10:56:49.335619 ike 0:IPSECTUNNEL:5115: responder preparing SA_INIT msg
2025-02-05 10:56:49.335631 ike 0:IPSECTUNNEL:5115: compute DH shared secret request queued
2025-02-05 10:56:49.335724 ike 0:IPSECTUNNEL:5115: responder preparing SA_INIT msg
2025-02-05 10:56:49.335735 ike 0:IPSECTUNNEL:5115: out 5A54CF6FF8006108EE598C4E534566F4F1A92120222000000000000000E8220000300000002C010100040300000C0100000C800E0100030
0000802000005030000080300000C000000080400000228000088000200002922AB1A5196BC4C7CA5798DAE13JLLEE1A50B598AB45AC8EE9C2800F98C0989930C7E03BAEFA3498C54C3E4FA4B5324DB5F3295FAB064
B44574B5F6B63706E4338B7273BD95FCA222AC4569E4A9EFDC5DF877C2F97EE3EA930BBF5DDCCE35B3027EC0432392238B612DEF0580790F52DD7578D77F2ECB69E7C014DA918C9B56973C900000014BBAD6D4
11587B2CBA42D33A5CCB20663
2025-02-05 10:56:49.335768 ike 0:IPSECTUNNEL:5115: sent IKE msg (SA_INIT_RESPONSE): FORTIGATEIP:500->AZUREIP:500, len=232, vrf=0, id=5a54cf6ff8006108/ee59
8c4e56f4f1a9
2025-02-05 10:56:49.335816 ike 0:IPSECTUNNEL:5115: IKE SA 5a54cf6f466f8006108/ee598c4e56f4f1a9 SK_ei 32:29D732527316644546EE82D7AEB799C9D000ECCA33E497F5489C41CF8A364BA158A2
083
2025-02-05 10:56:49.335826 ike 0:IPSECTUNNEL:5115: IKE SA 5a5455cf6ff8006108/ee598c4e56f664f1a9 SK_er 32:1ED8CD2646343FC9A95A12008634280AF299685E3163FAB9255ADBE24EB8BBD6B
47C
2025-02-05 10:56:49.335833 ike 0:IPSECTUNNEL:5115: IKE SA 5a54cf6ff668006108/ee598c4e5666f4f1a9 SK_ai 32:CEAD9740BF6256C0993A07A5B0F292F937B52B29E3867403F92695C69A17D
EB4
2025-02-05 10:56:49.335839 ike 0:IPSECTUNNEL:5115: IKE SA 5a54cf666ff8006108/ee598c4e5666f4f1a9 SK_ar 32:63E7C9D81114E2AFWYW9A8B043A3A9F233F9AB4943A4AAD50999C0F15E59DC5F
D44
2025-02-05 10:56:49.341056 ike 0: comes AZUREIP:500->FORTIGATEIP:500,ifindex=35,vrf=0....
2025-02-05 10:56:49.341070 ike 0: IKEv2 exchange=AUTH id=5a54cf6ff803406108/ee598c4e53436f4f1a9:00000001 len=224
2025-02-05 10:56:49.341082 ike 0: in 5A54CF6FF8006108EE598sC4E56F4F1A92E20230800000001000000E0230000C46BEDEE47749A562237688FDC7409F4D26A912951E0FB3B20561F916A339FD22E3
4F4F608A4320826A808702D3BC755BC2A92728C32B16D5956C558CF4EE940ss401903FCB438C39A1D13C836EF7D82303B1586B52333s1E47ED3A709462D0266E0C3077D29100F26489BDA6C3F4CCCA919AB3439C08E58
7F916621C0DA44033B12B9124E41FF0BA06D34FF217E4034C45E638126D7E88D20B03FD29E3FB8816657917727E80394D03A7CE7E5514F9C4D25A2080DEBCDD131103CF07EA2983266045404755
2025-02-05 10:56:49.341091 ike 0:IPSECTUNNEL: HA state master(2)
2025-02-05 10:56:49.341115 ike 0:IPSECTUNNEL:5115: dec 5A54CF6FF8006108EE598C4E56F466F1A92E20230800000001000000B023000004270066000C01000000145AD8A0210000280200000096C
48BFBE5C7FA54E2FB9A6AE9F390EB24B429972819EC38D3FD9994022EE4FE22C00002C00000028010304038A65CA880300000C0100000C874300E0100030000080300000C00000008050000002D000018010000000
70000100000FFFF00000000FFFFFFFF0220000018010000000700001000200FFFF000000200FFFFFFFF
2025-02-05 10:56:49.341125 ike 0:IPSECTUNNEL:5115: responder received AUTH msg
2025-02-05 10:56:49.341141 ike 0:IPSECTUNNEL:5115: peer identifier IPV4_ADDR AZUREIP
2025-02-05 10:56:49.341161 ike 0:IPSECTUNNEL:5115: auth verify done
2025-02-05 10:56:49.341172 ike 0:IPSECTUNNEL:5115: responder AUTH continuation
2025-02-05 10:56:49.341178 ike 0:IPSECTUNNEL:5115: authentication succeeded
2025-02-05 10:56:49.341195 ike 0:IPSECTUNNEL:5115: responder creating new child
2025-02-05 10:56:49.341210 ike 0:IPSECTUNNEL:5115:15627: peer proposal:
2025-02-05 10:56:49.341216 ike 0:IPSECTUNNEL:5115:15627: TSi_0 0:0.0.0.0-255.255.255.255:0
2025-02-05 10:56:49.341222 ike 0:IPSECTUNNEL:5115:15627: TSr_0 0:0.0.0.0-255.255.255.255:0
2025-02-05 10:56:49.341233 ike 0:IPSECTUNNEL:5115:IPSECTUNNEL:15627: comparing selectors
2025-02-05 10:56:49.341239 ike 0:IPSECTUNNEL:5115:IPSECTUNNEL:15627: matched by rfc-rule-2
2025-02-05 10:56:49.341245 ike 0:IPSECTUNNEL:5115:IPSECTUNNEL:15627: phase2 matched by subset
2025-02-05 10:56:49.341251 ike 0:IPSECTUNNEL:5115:IPSECTUNNEL:15627: accepted proposal:
2025-02-05 10:56:49.341256 ike 0:IPSECTUNNEL:5115:IPSECTUNNEL:15627: TSi_0 0:0.0.0.0-255.255.255.255:0
2025-02-05 10:56:49.341262 ike 0:IPSECTUNNEL:5115:IPSECTUNNEL:15627: TSr_0 0:0.0.0.0-255.255.255.255:0
2025-02-05 10:56:49.341267 ike 0:IPSECTUNNEL:5115:IPSECTUNNEL:15627: autokey
2025-02-05 10:56:49.341276 ike 0:IPSECTUNNEL:5115:IPSECTUNNEL:15627: incoming child SA proposal:
2025-02-05 10:56:49.341285 ike 0:IPSECTUNNEL:5115:IPSECTUNNEL:15627: proposal id = 1:
2025-02-05 10:56:49.341289 ike 0:IPSECTUNNEL:5115:IPSECTUNNEL:15627:   protocol = ESP:
2025-02-05 10:56:49.341294 ike 0:IPSECTUNNEL:5115:IPSECTUNNEL:15627:      encapsulation = TUNNEL
2025-02-05 10:56:49.341299 ike 0:IPSECTUNNEL:5115:IPSECTUNNEL:15627:         type=ENCR, val=AES_CBC (key_len = 256)
2025-02-05 10:56:49.341305 ike 0:IPSECTUNNEL:5115:IPSECTUNNEL:15627:         type=INTEGR, val=SHA256
2025-02-05 10:56:49.341310 ike 0:IPSECTUNNEL:5115:IPSECTUNNEL:15627:         type=ESN, val=NO
2025-02-05 10:56:49.341315 ike 0:IPSECTUNNEL:5115:IPSECTUNNEL:15627:         PFS is disabled
2025-02-05 10:56:49.341321 ike 0:IPSECTUNNEL:5115:IPSECTUNNEL:15627: matched proposal id 1
2025-02-05 10:56:49.341325 ike 0:IPSECTUNNEL:5115:IPSECTUNNEL:15627: proposal id = 1:
2025-02-05 10:56:49.341330 ike 0:IPSECTUNNEL:5115:IPSECTUNNEL:15627:   protocol = ESP:
2025-02-05 10:56:49.341335 ike 0:IPSECTUNNEL:5115:IPSECTUNNEL:15627:      encapsulation = TUNNEL
2025-02-05 10:56:49.341340 ike 0:IPSECTUNNEL:5115:IPSECTUNNEL:15627:         type=ENCR, val=AES_CBC (key_len = 256)
2025-02-05 10:56:49.341345 ike 0:IPSECTUNNEL:5115:IPSECTUNNEL:15627:         type=INTEGR, val=SHA256
2025-02-05 10:56:49.341350 ike 0:IPSECTUNNEL:5115:IPSECTUNNEL:15627:         type=ESN, val=NO
2025-02-05 10:56:49.341361 ike 0:IPSECTUNNEL:5115:IPSECTUNNEL:15627:         PFS is disabled
2025-02-05 10:56:49.341367 ike 0:IPSECTUNNEL:5115:IPSECTUNNEL:15627: lifetime=3600
2025-02-05 10:56:49.341384 ike 0:IPSECTUNNEL:5115: responder preparing AUTH msg
2025-02-05 10:56:49.341392 ike 0:IPSECTUNNEL:5115: established IKE SA 5a54cf336ff8006108/ee598544e56f4f1a9
2025-02-05 10:56:49.341408 ike 0:IPSECTUNNEL:5115: check peer route: if_addr4_rcvd=0, if_addr6_rcvd=0, mode_cfg=0
2025-02-05 10:56:49.341415 ike 0:IPSECTUNNEL: HA send IKE connection add FORTIGATEIP->AZUREIP
2025-02-05 10:56:49.341425 ike 0:IPSECTUNNEL:5115: HA send IKE SA add 5a54cf346ff8006108/ee598c4545e56f4f1a9
2025-02-05 10:56:49.341433 ike 0:IPSECTUNNEL: schedule auto-negotiate
2025-02-05 10:56:49.341449 ike 0:IPSECTUNNEL:5115:IPSECTUNNEL:15627: set sa life soft seconds=3331.
2025-02-05 10:56:49.341454 ike 0:IPSECTUNNEL:5115:IPSECTUNNEL:15627: set sa life hard seconds=3600.
2025-02-05 10:56:49.341468 ike 0:IPSECTUNNEL:5115:IPSECTUNNEL:15627: IPsec SA selectors #src=1 #dst=1
2025-02-05 10:56:49.341475 ike 0:IPSECTUNNEL:5115:IPSECTUNNEL:15627: src 0 7 0:0.0.0.0-255.255.255.255:0
2025-02-05 10:56:49.341486 ike 0:IPSECTUNNEL:5115:IPSECTUNNEL:15627: dst 0 7 0:0.0.0.0-255.255.255.255:0
2025-02-05 10:56:49.341491 ike 0:IPSECTUNNEL:5115:IPSECTUNNEL:15627: add IPsec SA: SPIs=ddfeadfe/8a65ca88
2025-02-05 10:56:49.341496 ike 0:IPSECTUNNEL:5115:IPSECTUNNEL:15627: IPsec SA dec spi ddfeadfe key 32:374DABB354B76A865545C6A3B169331D7E82C005C8A10B6DE3EFAC2E14E5
80408AB3 auth 32:9E3988B87A163BC78CE04A9A0B128246533161ECD5848BC1CC1254D3E08482C5
2025-02-05 10:56:49.341502 ike 0:IPSECTUNNEL:5115:IPSECTUNNEL:15627: IPsec SA enc spi 8a65ca88 key 32:60A4037D8540B36952E07FE57454594C79B1F8E1461A9E4631495446A5C1
38FA0340 auth 32:C0D87C38BB6853104E9F4473395AD762C683309C44FC4375B703733F69C6B829
2025-02-05 10:56:49.341577 ike 0:IPSECTUNNEL:5115:IPSECTUNNEL:15627: added IPsec SA: SPIs=ddfeadfe/8a65ca88
2025-02-05 10:56:49.341597 ike 0:IPSECTUNNEL: HA send IKE connection add FORTIGATEIP->AZUREIP
2025-02-05 10:56:49.341605 ike 0:IPSECTUNNEL:5115: HA send IKE SA add 5a54cf6ff8006108/ee598c4e56f4f1a9
2025-02-05 10:56:49.341611 ike 0:IPSECTUNNEL: HA send IKEv2 message ID update send/recv=0/2
2025-02-05 10:56:49.341620 ike 0:IPSECTUNNEL:5115: enc 2700000C0100000040FD20C42100045750280200000065807240C0A516CE96B0A6F17B2D84A9733F92881DD5F55CEA6A224E4897A25F2C0
0002C0000002801030403DDFEADFE0300000C0100000C800E01000300000803045430000C00000008050000002D0220001801000000070000100000FFFF00000000FFFFFFFF0000001801000000070000100000FFFF0
0000000FFFFFFFF0F0E0D0C0B0A0908070605040302010F
2025-02-05 10:56:49.341647 ike 0:IPSECTUNNEL:5115: out 5A54CF6FF8006108EE598C4E56F4F1A92E20232000000001000000E0240000C4DAEE19CBA9E9E99E5AA5512563F8B836D88947E67A7
C5ABC53DE07B68F1AC34DA60E39609A3F9457F981DE5ADFB431834C2C1738ACADDAE6A207DA8AEC72CD72CA33E314823B1E84E1C63BD78ADB8D419428DFBAFF3AA5CFDF2AE88EFC536B6EF573E4C286A044FBC4FCE
68D4DCF6EC92187C9CE4EC11C443AA01960BA130256A4EAD2EA128D560710FAA0CED6DC62782776C7B1D97CC292A7677C0398722ACFAB19233F41A3EE2D26C2748542D889F02E61E66345E01407AFED916C80BEF3C2C5B
F889DB141
2025-02-05 10:56:49.341672 ike 0:IPSECTUNNEL:5115: sent IKE msg (AUTH_RESPONSE): FORTIGATEIP:500->AZUREIP:500, len=224, vrf=0, id=5a54cf6ff8332006108/ee598c4
e56f4f1a9:00000001
2025-02-05 10:56:49.344490 ike 0:IPSECTUNNEL: HA IPsec send ESP seqno=1138a4c, num=2
2025-02-05 10:56:49.345761 ike 0:IPSECTUNNEL: link is idle 0 FORTIGATEIP->AZUREIP:0 dpd=2 seqno=8 rr=0
2025-02-05 10:56:51.234380 ike 0:IPSECTUNNEL:4119: out F57DAFA69F133367899718B6D41A00809F44BD62E2025000000001000000050000000344BA3D960FD81258F6DF45C45453C5BDD2CF7F3FA3D360
6FB30B26CADAFF6F1C62602429A68789EF7E933FAFFD6C4F989FE
2025-02-05 10:56:51.234420 ike 0:IPSECTUNNEL:4119: sent IKE msg (RETRANSMIT_INFORMATIONAL): FORTIGATEIP:500->AZUREIP:500, len=80, vrf=0, id=f57dafa4469f1971
8b/6d41a00809f44bd6:00000010
2025-02-05 10:56:57.230978 ike 0:IPSECTUNNEL:4119: out F57DAFA69F19718B6D41A008045799F44BD62E2025000000001000000050000000344BA3D960FD81258F6DF45CD53C5BDD2CF7F3FA3D360
6FB30B26CADAFF6F1C62602429A68789EF7E933FAFFD6C4F989FE
2025-02-05 10:56:57.231019 ike 0:IPSECTUNNEL:4119: sent IKE msg (RETRANSMIT_INFORMATIONAL): FORTIGATEIP:500->AZUREIP:500, len=80, vrf=0, id=f57dafa6954f1971
8b/6d41a00809f44bd6:00000010
2025-02-05 10:57:09.227271 ike 0:IPSECTUNNEL:4119: out F57DAFA69F19718B6D41A00809F44BD62E2025000000001000000050000000344BA3D960FD81258F6DF45CD53C5BDD2CF7F3FA3D360
6FB30B26CADAFF6F1C62602429A68789EF7E933FAFFD6C4F989FE
2025-02-05 10:57:09.227326 ike 0:IPSECTUNNEL:4119: sent IKE msg (RETRANSMIT_INFORMATIONAL): FORTIGATEIP:500->AZUREIP:500, len=80, vrf=0, id=f57dafa4469f1971
8b/6d41a00809f44bd6:00000010
2025-02-05 10:57:33.233982 ike 0:IPSECTUNNEL:4119: out F57DAFA69F19718B6D41A00342809F44BD62E20250000000015000000050000000344BA3D960FD81258F6DF45CD53C5BDD2CF7F3FA3D360
6FB30B26CADAFF6F1C62602429A68783349EF7E933FAFFD6C4F989FE
2025-02-05 10:57:33.234040 ike 0:IPSECTUNNEL:4119: sent IKE msg (RETRANSMIT_INFORMATIONAL): FORTIGATEIP:500->AZUREIP:500, len=80, vrf=0, id=f57dafa5569f1971
8b/6d41a00809f44bd6:00000010
2025-02-05 10:58:21.234603 ike 0:IPSECTUNNEL:4119: f57dafdf69f19718b/6d41a0080df9f44bd6 negotiation of IKE SA failed due to retry timeout
2025-02-05 10:58:21.234645 ike 0:IPSECTUNNEL:4119: expiring IKE SA f57dafaa69f19718b/6d41a0a0809f44bd6
2025-02-05 10:58:21.234681 ike 0:IPSECTUNNEL:4119: HA send IKE SA del f57dafa69fa19718b/6d41a0080a9f44bd6
2025-02-05 10:58:21.234701 ike 0:IPSECTUNNEL: deleting IPsec SA with SPI f9aab906
2025-02-05 10:58:21.234759 ike 0:IPSECTUNNEL:IPSECTUNNEL: deleted IPsec SA with SPI f9aab906, SA count: 1
2025-02-05 10:58:21.234794 ike 0:IPSECTUNNEL:4119:15634: send informational
2025-02-05 10:58:21.234811 ike 0:IPSECTUNNEL:4119: enc 0000000801d3340000000706050403020107
2025-02-05 10:58:21.234854 ike 0:IPSECTUNNEL:4119: out F57DAFA69F19718B6D41A008DF3409F44BD62E20250000000010000000502A00003471D9AC75651C147B55A434GFDA8355A771621429F51495E8
DCC734E4598334451EB57260F7FE2E052567C01CD9DACB2A0E0FEAF5
2025-02-05 10:58:21.234881 ike 0:IPSECTUNNEL:4119: sent IKE msg (INFORMATIONAL): FORTIGATEIP:500->AZUREIP:500, len=80, vrf=0, id=f57dafa6349f19718b/6d4134a008
09f44bd6:00000010
2025-02-05 10:58:21.234902 ike 0:IPSECTUNNEL: schedule auto-negotiate
2025-02-05 10:58:39.782591 ike shrank heap by 159744 bytes

 


anything stand out to you or is it the same as before?

 

 

cheers,

208
0 Kudos
RogerDingoDing
New Contributor

Created on ‎02-12-2025 12:39 PM

we found the root cause of our issues.


the IPsec tunnel was configured with a 'loopback interface', and for whatever reason this was causing the timeout errors and network drops. (further investigation into this will be happening)

 

Once I discovered that we were having a large amount of malformed packets during the ike rekey phase it got us wondering what could be causing this... something on the network most likely.
So at a whim and advice from a 3rd party who suggested we change interface for the tunnel to the WAN port.

We made the change today and can confirm that during the latest rekey phase there was no network drop, the debug logs are clean (no IKE SA timeout errors) and the wireshark captures also look much cleaner. 

 

now that the loopback was identified, i had something else to investigate.
came across this article where the background describes the behaviour we were experiencing.

Site-to-Site IPsec VPN cannot establish i... - Fortinet Community

 

Background:

FortiOS IKE (IPsec phase1) and ESP (IPsec phase2) are separate sessions when nat-traversal is not enforced, therefore when IPsec VPN is bound to a loopback interface and there are redundant ISPs (ECMP), then by design IKE and ESP traffic could be asymmetric and follow different paths where inbound and outbound IKE traffic could be routed over different interfaces, on some implementations this asymmetric behavior could cause VPN tunnel fails to establish.

 

also found this 
Best practice when IPSec VPN is bound to ... - Fortinet Community

 

So based on both these articles and the settings that they mention, its highly possible that we had missing configuration for an ipsec tunnel with a loopback interface.
we have also reached out to the ISP to confirm that everything is correct on their end as well.

further investigation will continue into this as we will want to have the loopback interface working correctly.

 

time to celebrate!

 

150
0 Kudos
Announcements
Check out our Community Chatter Blog! Click here to get involved
Labels
Top Kudoed Authors
View all
Broad. Integrated. Automated.

The Fortinet Security Fabric brings together the concepts of convergence and consolidation to provide comprehensive cybersecurity protection for all users, devices, and applications and across all network edges.

Social Media
Security Research
Company
News & Articles
Contact Us

Copyright 2025 Fortinet, Inc. All Rights Reserved.