Dialup VPN interface keep flapping

[peterchan]

Dear All,

Facing this issue since yesterday, tried tuned the keylife value but did not help.

We received a lot of tunnel interface up / down alarm from one Fortigate generated every 10 mins.

Checked the vpn uptime is reset which mean the vpn is really down and then up again.

This Fortigate A is on one of the branch and connected to the HQ Fortigate B using 40D with 4G sim.

Fortigate B connected around 10 Fortigate with same profile and setting but only this face the issue.

By running the diag debug application ike -1, there is no any error.

The only thing we found is the local addr change trigger the the SNMP trap.

Below is the debug log of Fortigate A:

[The hostname and IP has been modified to 192.168.1.1 & 192.168.10.10 for security, the IP 0.0.0.0 is original from the log ] 

ike 0:VPN_Branch_1: local-addr change 192.168.1.1 -> 0.0.0.0 ike 0:VPN_Branch_1: deleting ike 0:VPN_Branch_1: flushing ike 0:VPN_Branch_1: deleting IPsec SA with SPI a19ae9cd ike 0:VPN_Branch_1:VPN_Branch_1_0: deleted IPsec SA with SPI a19ae9cd, SA count: 0 ike 0:VPN_Branch_1: sending SNMP tunnel DOWN trap for VPN_Branch_1_0 ike 0:VPN_Branch_1:318: send IPsec SA delete, spi 4036b8ce ike 0:VPN_Branch_1:318: enc ike 0:VPN_Branch_1:318: out ike 0:VPN_Branch_1:318: sent IKE msg (IPsec SA_DELETE-NOTIFY): 192.168.1.1:500->192.168.10.10:500, len=76, id= ike 0:VPN_Branch_1:VPN_Branch_1_0: sending SNMP tunnel DOWN trap ike 0:VPN_Branch_1: flushed ike 0:VPN_Branch_1:318: send IKE SA delete  ike 0:VPN_Branch_1:318: enc ike 0:VPN_Branch_1:318: out ike 0:VPN_Branch_1:318: sent IKE msg (ISAKMP SA DELETE-NOTIFY): 192.168.1.1:500->192.168.10.10:500, len=92, id=1e79aacbb6ea0d8b/f367bd65e66601ea:5d3d9298 ike 0:VPN_Branch_1: deleted ike 0:VPN_Branch_1: set oper down ike 0:VPN_Branch_1: oif 27 ike 0: policy 57 action is DENY, ignoring ike 0:IPsec-1_1: schedule auto-negotiate ike 0:VPN_Branch_1: not negotiable ike config update done ike 0:VPN_Branch_1: carrier down ike 0: unknown SPI 4036b8ce 27 192.168.10.10:0->192.168.1.1 ike 0: cache rebuild done ike change cfg 0 interface 1 router 0 certs 0 ike config update start ike 0: HA syncing disabled ike 0:VPN_Branch_1: local-addr change 0.0.0.0 -> 192.168.1.1 ike 0:VPN_Branch_1: oif 27 ike 0: policy 57 action is DENY, ignoring ike 0:VPN_Branch_1: schedule auto-negotiate ike config update done ike 0:VPN_Branch_1: cached as static-ddns ike 0: cache rebuild done ike 0:VPN_Branch_1: auto-negotiate connection ike 0:VPN_Branch_1: created connection: 0x5387620 27 192.168.1.1->192.168.10.10:500. ike 0:VPN_Branch_1:319: initiator: aggressive mode is sending 1st message... ike 0:VPN_Branch_1:319: cookie da3660fdaba4ad4b/0000000000000000 ike 0:VPN_Branch_1:319: out ike 0:VPN_Branch_1:319: sent IKE msg (agg_i1send): 192.168.1.1:500->192.168.10.10:500, len=594, id=da3660fdaba4ad4b/0000000000000000 ike 0: comes 192.168.10.10:500->192.168.1.1:500,ifindex=27.... ike 0: IKEv1 exchange=Aggressive id= len=550 ike 0: in ike 0:VPN_Branch_1:319: initiator: aggressive mode get 1st response... ike 0:VPN_Branch_1:319: VID RFC 3947  ike 0:VPN_Branch_1:319: VID DPD  ike 0:VPN_Branch_1:319: DPD negotiated ike 0:VPN_Branch_1:319: VID FORTIGATE  ike 0:VPN_Branch_1:319: peer is FortiGate/FortiOS (v0 b0) ike 0:VPN_Branch_1:319: VID FRAGMENTATION  ike 0:VPN_Branch_1:319: VID FRAGMENTATION  ike 0:VPN_Branch_1:319: received peer identifier FQDN '14' ike 0:VPN_Branch_1:319: negotiation result ike 0:VPN_Branch_1:319: proposal id = 1: ike 0:VPN_Branch_1:319: protocol id = ISAKMP: ike 0:VPN_Branch_1:319: trans_id = KEY_IKE. ike 0:VPN_Branch_1:319: encapsulation = IKE/none ike 0:VPN_Branch_1:319: type=OAKLEY_ENCRYPT_ALG, val=AES_CBC, key-len=128 ike 0:VPN_Branch_1:319: type=OAKLEY_HASH_ALG, val=SHA. ike 0:VPN_Branch_1:319: type=AUTH_METHOD, val=PRESHARED_KEY. ike 0:VPN_Branch_1:319: type=OAKLEY_GROUP, val=MODP2048. ike 0:VPN_Branch_1:319: ISAKMP SA lifetime=28800 ike 0:VPN_Branch_1:319: received NAT-D payload type 20 ike 0:VPN_Branch_1:319: received NAT-D payload type 20 ike 0:VPN_Branch_1:319: selected NAT-T version: RFC 3947 ike 0:VPN_Branch_1:319: NAT not detected ike 0:VPN_Branch_1:319: ISAKMP SA  key 16: ike 0:VPN_Branch_1:319: PSK authentication succeeded ike 0:VPN_Branch_1:319: authentication OK ike 0:VPN_Branch_1:319: add INITIAL-CONTACT ike 0:VPN_Branch_1:319: enc ike 0:VPN_Branch_1:319: out ike 0:VPN_Branch_1:319: sent IKE msg (agg_i2send): 192.168.1.1:500->192.168.10.10:500, len=140, id= ike 0:VPN_Branch_1:319: established IKE SA  ike 0:VPN_Branch_1: set oper up ike 0:VPN_Branch_1: schedule auto-negotiate ike 0:VPN_Branch_1:319: no pending Quick-Mode negotiations ike 0:VPN_Branch_1: carrier up ike 0:VPN_Branch_1:VPN_Branch_1_0: IPsec SA connect 27 192.168.1.1->192.168.10.10:0 ike 0:VPN_Branch_1:VPN_Branch_1_0: using existing connection ike 0:VPN_Branch_1:VPN_Branch_1_0: config found ike 0:VPN_Branch_1:VPN_Branch_1_0: IPsec SA connect 27 192.168.1.1->192.168.10.10:500 negotiating ike 0:VPN_Branch_1:319: cookie  ike 0:VPN_Branch_1:319:VPN_Branch_1_0:1699: initiator selectors 0 0:0.0.0.0/0.0.0.0:0:0->0:0.0.0.0/0.0.0.0:0:0 ike 0:VPN_Branch_1:319: enc ike 0:VPN_Branch_1:319: out ike 0:VPN_Branch_1:319: sent IKE msg (quick_i1send): 192.168.1.1:500->192.168.10.10:500, len=428, id= ike 0: comes 192.168.10.10:500->192.168.1.1:500,ifindex=27.... ike 0: IKEv1 exchange=Quick id= len=428 ike 0: in ike 0:VPN_Branch_1:319: dec ike 0:VPN_Branch_1:319:VPN_Branch_1_0:1699: responder selectors 0:0.0.0.0/0.0.0.0:0->0:0.0.0.0/0.0.0.0:0 ike 0:VPN_Branch_1:319:VPN_Branch_1_0:1699: my proposal: ike 0:VPN_Branch_1:319:VPN_Branch_1_0:1699: proposal id = 1: ike 0:VPN_Branch_1:319:VPN_Branch_1_0:1699: protocol id = IPSEC_ESP: ike 0:VPN_Branch_1:319:VPN_Branch_1_0:1699: PFS DH group = 14 ike 0:VPN_Branch_1:319:VPN_Branch_1_0:1699: trans_id = ESP_AES_CBC (key_len = 128) ike 0:VPN_Branch_1:319:VPN_Branch_1_0:1699: encapsulation = ENCAPSULATION_MODE_TUNNEL ike 0:VPN_Branch_1:319:VPN_Branch_1_0:1699: type = AUTH_ALG, val=SHA1 ike 0:VPN_Branch_1:319:VPN_Branch_1_0:1699: incoming proposal: ike 0:VPN_Branch_1:319:VPN_Branch_1_0:1699: proposal id = 1: ike 0:VPN_Branch_1:319:VPN_Branch_1_0:1699: protocol id = IPSEC_ESP: ike 0:VPN_Branch_1:319:VPN_Branch_1_0:1699: PFS DH group = 14 ike 0:VPN_Branch_1:319:VPN_Branch_1_0:1699: trans_id = ESP_AES_CBC (key_len = 128) ike 0:VPN_Branch_1:319:VPN_Branch_1_0:1699: encapsulation = ENCAPSULATION_MODE_TUNNEL ike 0:VPN_Branch_1:319:VPN_Branch_1_0:1699: type = AUTH_ALG, val=SHA1 ike 0:VPN_Branch_1: schedule auto-negotiate ike 0:VPN_Branch_1:319:VPN_Branch_1_0:1699: replay protection enabled ike 0:VPN_Branch_1:319:VPN_Branch_1_0:1699: SA life soft seconds=1771. ike 0:VPN_Branch_1:319:VPN_Branch_1_0:1699: SA life hard seconds=1800. ike 0:VPN_Branch_1:319:VPN_Branch_1_0:1699: IPsec SA selectors #src=1 #dst=1 ike 0:VPN_Branch_1:319:VPN_Branch_1_0:1699: src 0 4 0:0.0.0.0/0.0.0.0:0 ike 0:VPN_Branch_1:319:VPN_Branch_1_0:1699: dst 0 4 0:0.0.0.0/0.0.0.0:0 ike 0:VPN_Branch_1:319:VPN_Branch_1_0:1699: add IPsec SA: SPIs= ike 0:VPN_Branch_1:319:VPN_Branch_1_0:1699: IPsec SA dec spi 4036b8d0 key 16: ike 0:VPN_Branch_1:319:VPN_Branch_1_0:1699: IPsec SA enc spi a19aea3c key 16: ike 0:VPN_Branch_1:319:VPN_Branch_1_0:1699: added IPsec SA: SPIs= ike 0:VPN_Branch_1:319:VPN_Branch_1_0:1699: sending SNMP tunnel UP trap ike 0:VPN_Branch_1:319: enc ike 0:VPN_Branch_1:319: out ike 0:VPN_Branch_1:319: sent IKE msg (quick_i2send): 192.168.1.1:500->192.168.10.10:500, len=60, id= ike shrank heap by 106496 bytes

On HQ Fortigate B, the debug logs are also no error message and only mentioned received p1 notify type INITIAL-CONTACT

As you can see the logs, the Fortigate detected the address change to 0.0.0.0 and flushed the tunnel which trigger the SNMP.

But then it change back the IP from 0.0.0.0 to the correct VPN IP.

I do not understand why it have such behavior.

Is there any miss-configuration? 

[rc179]

So what happend with this?