ipsec issue after firmware upgrade and apply HA at hub end

[journeyman]

FGT60C is a hub with 8 ipsec interface tunnels (all FGT60C). These were working fine but after upgrading from 4.1.4 to 4.3.18 and simultaneously applying HA, all ipsec tunnels are unstable. All remotes are already running 4.3.18. All tunnels establish and fail continuously (our syslog shows many interface was turned up|down messages). All tunnels were up immediately prior to the firmware and HA change. NAT rules etc which have previously been an issue seem OK, no lost packets (afaik) etc.

phase1-interface and phase2-interface configurations have been crosschecked OK. PSK has been reset and is correct (seen in line 45 of remote debug below).

The remote debug shows authentication success, the hub debug does not. Is this perhaps part of the issue? For that matter, the debug output seems a bit different even though both devices are running 4.3.18.

Otherwise. any suggestion for next step to diagnose?

Thanks in advance

Debug from a remote site:

001 # diag deb app ike -1
002 # diag deb en
003 ike 0: comes hub-ip:500->my-ip:500,ifindex=5....
004 ike 0: IKEv1 exchange=Identity Protection id=e24237b7f7d82b54/0000000000000000 len=244
005 ike 0: in lots-of-hex
006 ike 0:ipsec-at-remote:5207: responder: main mode get 1st message...
007 ike 0:ipsec-at-remote:5207: VID RFC 3947 4A131C81070358455C5728F20E95452F
008 ike 0:ipsec-at-remote:5207: VID draft-ietf-ipsec-nat-t-ike-03 7D9419A65310CA6F2C179D9215529D56
009 ike 0:ipsec-at-remote:5207: VID draft-ietf-ipsec-nat-t-ike-02 CD60464335DF21F87CFDB2FC68B6A448
010 ike 0:ipsec-at-remote:5207: VID draft-ietf-ipsec-nat-t-ike-02\n 90CB80913EBB696E086381B5EC427B1F
011 ike 0:ipsec-at-remote:5207: VID draft-ietf-ipsec-nat-t-ike-01 16F6CA16E4A4066D83821A0F0AEAA862
012 ike 0:ipsec-at-remote:5207: VID draft-ietf-ipsec-nat-t-ike-00 4485152D18B6BBCD0BE8A8469579DDCC
013 ike 0:ipsec-at-remote:5207: VID DPD AFCAD71368A1F1C96B8696FC77570100
014 ike 0:ipsec-at-remote:5207: DPD negotiated
015 ike 0:ipsec-at-remote:5207: VID FORTIGATE 8299031757A36082C6A621DE000402B1
016 ike 0:ipsec-at-remote:5207: peer is FortiGate/FortiOS (v4 b689)
017 ike 0:ipsec-at-remote:5207: negotiation result
018 ike 0:ipsec-at-remote:5207: proposal id = 1:
019 ike 0:ipsec-at-remote:5207: protocol id = ISAKMP:
020 ike 0:ipsec-at-remote:5207: trans_id = KEY_IKE.
021 ike 0:ipsec-at-remote:5207: encapsulation = IKE/none
022 ike 0:ipsec-at-remote:5207: type=OAKLEY_ENCRYPT_ALG, val=AES_CBC.
023 ike 0:ipsec-at-remote:5207: type=OAKLEY_HASH_ALG, val=SHA.
024 ike 0:ipsec-at-remote:5207: type=AUTH_METHOD, val=PRESHARED_KEY.
025 ike 0:ipsec-at-remote:5207: type=OAKLEY_GROUP, val=1024.
026 ike 0:ipsec-at-remote:5207: ISKAMP SA lifetime=28800
027 ike 0:ipsec-at-remote:5207: selected NAT-T version: RFC 3947
028 ike 0:ipsec-at-remote:5207: cookie e24237b7f7d82b54/05958ceab9c7cb69
029 ike 0:ipsec-at-remote:5207: out lots-of-hex
030 ike 0:ipsec-at-remote:5207: sent IKE msg (ident_r1send): my-ip:500->hub-ip:500, len=144, id=e24237b7f7d82b54/05958ceab9c7cb69
031 ike 0: comes hub-ip:500->my-ip:500,ifindex=5....
032 ike 0: IKEv1 exchange=Identity Protection id=e24237b7f7d82b54/05958ceab9c7cb69 len=228
033 ike 0: in lots-of-hex
034 ike 0:ipsec-at-remote:5207: responder:main mode get 2nd message...
035 ike 0:ipsec-at-remote:5207: NAT detected: ME 
036 ike 0:ipsec-at-remote:5207: out lots-of-hex
037 ike 0:ipsec-at-remote:5207: sent IKE msg (ident_r2send): my-ip:500->hub-ip:500, len=228, id=e24237b7f7d82b54/05958ceab9c7cb69
038 ike 0:ipsec-at-remote:5207: ISAKMP SA e24237b7f7d82b54/05958ceab9c7cb69 key 16:C9C7F81FED3D466E35FCD4A0EAB97E7A
039 ike 0: comes hub-ip:4500->my-ip:4500,ifindex=5....
040 ike 0: IKEv1 exchange=Identity Protection id=e24237b7f7d82b54/05958ceab9c7cb69 len=108
041 ike 0: in lots-of-hex
042 ike 0:ipsec-at-remote:5207: responder: main mode get 3rd message...
043 ike 0:ipsec-at-remote:5207: dec E24237B7F7D82B5405958CEAB9C7CB6905100201000000000000006C080000140200000069707365632D746F2D6368770B0000187701753AA31881780512AC6B84CD46DC21F1AAB40000001C0000000101106002E24237B7F7D82B5405958CEAB9C7CB699F89A58D863BFD07
044 ike 0:ipsec-at-remote:5207: received notify type 24578
045 ike 0:ipsec-at-remote:5207: PSK authentication succeeded
046 ike 0:ipsec-at-remote:5207: authentication OK
047 ike 0:ipsec-at-remote:5207: enc lots-of-hex
048 ike 0:ipsec-at-remote:5207: port change 500 -> 4500
049 ike 0:ipsec-at-remote:5207: out lots-of-hex
050 ike 0:ipsec-at-remote:5207: sent IKE msg (ident_r3send): my-ip:4500->hub-ip:4500, len=76, id=e24237b7f7d82b54/05958ceab9c7cb69
051 ike 0:ipsec-at-remote:5207: established IKE SA e24237b7f7d82b54/05958ceab9c7cb69
052 ike 0:ipsec-at-remote:5207: processing INITIAL-CONTACT
053 ike 0:ipsec-at-remote: flushing 
054 ike 0:ipsec-at-remote: flushed 
055 ike 0:ipsec-at-remote:5207: processed INITIAL-CONTACT
056 ike 0:ipsec-at-remote: set oper up
057 ike 0:ipsec-at-remote: schedule auto-negotiate
058 ike 0:ipsec-at-remote:5207: no pending Quick-Mode negotiations
059 ike 0:ipsec-at-remote:ipsec-at-remote-p2: IPsec SA connect 5 my-ip->hub-ip:4500
060 ike 0:ipsec-at-remote:ipsec-at-remote-p2: using existing connection
061 ike 0:ipsec-at-remote:ipsec-at-remote-p2: config found
062 ike 0:ipsec-at-remote:ipsec-at-remote-p2: IPsec SA connect 5 my-ip->hub-ip:4500 negotiating
063 ike 0:ipsec-at-remote: carrier up
064 ike 0:ipsec-at-remote:5207: cookie e24237b7f7d82b54/05958ceab9c7cb69:6eab0c3a
065 ike 0:ipsec-at-remote:5207:ipsec-at-remote-p2:628914: natt flags 0x23, encmode 1->3
066 ike 0:ipsec-at-remote:5207:ipsec-at-remote-p2:628914: 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
067 ike 0:ipsec-at-remote:5207: enc lots-of-hex
068 ike 0:ipsec-at-remote:5207: out lots-of-hex
069 ike 0:ipsec-at-remote:5207: sent IKE msg (quick_i1send): my-ip:4500->hub-ip:4500, len=300, id=e24237b7f7d82b54/05958ceab9c7cb69:6eab0c3a
070 ike 0:ipsec-at-remote:5207: out lots-of-hex
071 ike 0:ipsec-at-remote:5207: sent IKE msg (P2_RETRANSMIT): my-ip:4500->hub-ip:4500, len=300, id=e24237b7f7d82b54/05958ceab9c7cb69:6eab0c3a
072 ike 0:ipsec-at-remote: link is idle 5 my-ip->hub-ip:4500 dpd=1 seqno=530cf
073 ike 0:ipsec-at-remote:5207: send IKEv1 DPD probe, seqno 340175
074 ike 0:ipsec-at-remote:5207: enc lots-of-hex
075 ike 0:ipsec-at-remote:5207: out lots-of-hex
076 ike 0:ipsec-at-remote:5207: sent IKE msg (R-U-THERE): my-ip:4500->hub-ip:4500, len=92, id=e24237b7f7d82b54/05958ceab9c7cb69:da5ac04c
077 ike 0:ipsec-at-remote:5207: out lots-of-hex
078 ike 0:ipsec-at-remote:5207: sent IKE msg (P2_RETRANSMIT): my-ip:4500->hub-ip:4500, len=300, id=e24237b7f7d82b54/05958ceab9c7cb69:6eab0c3a
079 ike 0:ipsec-at-remote:ipsec-at-remote-p2: IPsec SA connect 5 my-ip->hub-ip:4500
080 ike 0:ipsec-at-remote:ipsec-at-remote-p2: using existing connection
081 ike 0:ipsec-at-remote:ipsec-at-remote-p2: config found
082 ike 0: comes hub-ip:4500->my-ip:4500,ifindex=5....
083 ike 0: IKEv1 exchange=Identity Protection id=e24237b7f7d82b54/05958ceab9c7cb69 len=108
084 ike 0: in lots-of-hex
085 ike 0:ipsec-at-remote:5207: retransmission, re-send last message
086 ike 0:ipsec-at-remote:5207: out lots-of-hex
087 ike 0:ipsec-at-remote:5207: sent IKE msg (retransmit): my-ip:4500->hub-ip:4500, len=76, id=e24237b7f7d82b54/05958ceab9c7cb69
088 ike 0:ipsec-at-remote:ipsec-at-remote-p2: IPsec SA connect 5 my-ip->hub-ip:4500
089 ike 0:ipsec-at-remote:ipsec-at-remote-p2: using existing connection
090 ike 0:ipsec-at-remote:ipsec-at-remote-p2: config found
091 ike 0:ipsec-at-remote: link is idle 5 my-ip->hub-ip:4500 dpd=1 seqno=530cf
092 ike 0:ipsec-at-remote:5207: send IKEv1 DPD probe, seqno 340175
093 ike 0:ipsec-at-remote:5207: enc lots-of-hex
094 ike 0:ipsec-at-remote:5207: out lots-of-hex
095 ike 0:ipsec-at-remote:5207: sent IKE msg (R-U-THERE): my-ip:4500->hub-ip:4500, len=92, id=e24237b7f7d82b54/05958ceab9c7cb69:27ffdb1b
096 ike 0:ipsec-at-remote:ipsec-at-remote-p2: IPsec SA connect 5 my-ip->hub-ip:4500
097 ike 0:ipsec-at-remote:ipsec-at-remote-p2: using existing connection
098 ike 0:ipsec-at-remote:ipsec-at-remote-p2: config found
099 ike 0:ipsec-at-remote:5207: out lots-of-hex
100 ike 0:ipsec-at-remote:5207: sent IKE msg (P2_RETRANSMIT): my-ip:4500->hub-ip:4500, len=300, id=e24237b7f7d82b54/05958ceab9c7cb69:6eab0c3a
101 ike 0:ipsec-at-remote: link is idle 5 my-ip->hub-ip:4500 dpd=1 seqno=530cf
102 ike 0:ipsec-at-remote:5207: send IKEv1 DPD probe, seqno 340175
103 ike 0:ipsec-at-remote:5207: enc lots-of-hex
104 ike 0:ipsec-at-remote:5207: out lots-of-hex
105 ike 0:ipsec-at-remote:5207: sent IKE msg (R-U-THERE): my-ip:4500->hub-ip:4500, len=92, id=e24237b7f7d82b54/05958ceab9c7cb69:afd2468c
106 ike 0: comes hub-ip:4500->my-ip:4500,ifindex=5....
107 ike 0: IKEv1 exchange=Identity Protection id=e24237b7f7d82b54/05958ceab9c7cb69 len=108
108 ike 0: in lots-of-hex
109 ike 0:ipsec-at-remote:5207: retransmission, re-send last message
110 ike 0:ipsec-at-remote:5207: out lots-of-hex
111 ike 0:ipsec-at-remote:5207: sent IKE msg (retransmit): my-ip:4500->hub-ip:4500, len=76, id=e24237b7f7d82b54/05958ceab9c7cb69
112 ike 0:ipsec-at-remote:ipsec-at-remote-p2: IPsec SA connect 5 my-ip->hub-ip:4500
113 ike 0:ipsec-at-remote:ipsec-at-remote-p2: using existing connection
114 ike 0:ipsec-at-remote:ipsec-at-remote-p2: config found
115 ike 0:ipsec-at-remote: carrier down
116 ike 0:ipsec-at-remote: set oper down
117 ike 0:ipsec-at-remote: deleting
118 ike 0:ipsec-at-remote: flushing 
119 ike 0:ipsec-at-remote: flushed 
120 ike 0:ipsec-at-remote:5207: send ISAKMP delete e24237b7f7d82b54/05958ceab9c7cb69
121 ike 0:ipsec-at-remote:5207: enc lots-of-hex
122 ike 0:ipsec-at-remote:5207: out lots-of-hex
123 ike 0:ipsec-at-remote:5207: sent IKE msg (ISKAMP SA DELETE-NOTIFY): my-ip:4500->hub-ip:4500, len=92, id=e24237b7f7d82b54/05958ceab9c7cb69:94c120a8
124 ike 0:ipsec-at-remote: reset NAT-T
125 ike 0:ipsec-at-remote: deleted
126 ike 0:ipsec-at-remote: schedule auto-negotiate
127 ike 0:ipsec-at-remote: link fail 5 my-ip->hub-ip:4500 dpd=1
128 ike 0:ipsec-at-remote: ignoring since port is not 500
129 ike 0:ipsec-at-remote: reset NAT-T settings
130 ike shrank heap by 131072 bytes
131 ike 0:ipsec-at-remote: auto-negotiate connection
132 ike 0:ipsec-at-remote: created connection: 0x1d2a260 5 my-ip->hub-ip:500.
133 ike 0:ipsec-at-remote:5208: initiator: main mode is sending 1st message...
134 ike 0:ipsec-at-remote:5208: cookie 20a7e7d08c993331/0000000000000000
135 ike 0:ipsec-at-remote:5208: out lots-of-hex
136 ike 0:ipsec-at-remote:5208: sent IKE msg (ident_i1send): my-ip:500->hub-ip:500, len=244, id=20a7e7d08c993331/0000000000000000
137 ike 0:ipsec-at-remote:5208: out lots-of-hex
138 ike 0:ipsec-at-remote:5208: sent IKE msg (P1_RETRANSMIT): my-ip:500->hub-ip:500, len=244, id=20a7e7d08c993331/0000000000000000
139 ike 0: comes hub-ip:500->my-ip:500,ifindex=5....
140 ike 0: IKEv1 exchange=Identity Protection id=ada75449e872ca9a/0000000000000000 len=244
141 ike 0: in lots-of-hex
142 ike 0: found ipsec-at-remote my-ip 5 -> hub-ip:500
143 ike 0:ipsec-at-remote:5209: responder: main mode get 1st message...

Debug from the hub site - note, no mention of psk success

001 # diag vpn ike log-filter list 
002 vd: any
003 name: ipsec-at-hub
004 interface: any
005 IPv4 source: any
006 IPv4 dest: rem-nat-ip
007 IPv6 source: any
008 IPv6 dest: any
009 source port: any
010 dest port: any
011 
012 # diag deb app ike -1
013 # diag deb en
014 
015 
016 ike 0: comes rem-nat-ip:500->hub-ip:500,ifindex=8....
017 ike 0: IKEv1 exchange=Identity Protection id=0e28555e25dd2dd9/ab80a5ace2a1c17e len=144
018 ike 0: in lots-of-hex
019 ike 0:ipsec-at-hub:9054: initiator: main mode get 1st response...
020 ike 0:ipsec-at-hub:9054: VID RFC 3947 4A131C81070358455C5728F20E95452F
021 ike 0:ipsec-at-hub:9054: VID DPD AFCAD71368A1F1C96B8696FC77570100
022 ike 0:ipsec-at-hub:9054: DPD negotiated
023 ike 0:ipsec-at-hub:9054: VID FORTIGATE 8299031757A36082C6A621DE000402B1
024 ike 0:ipsec-at-hub:9054: peer is FortiGate/FortiOS (v4 b689)
025 ike 0:ipsec-at-hub:9054: selected NAT-T version: RFC 3947
026 ike 0:ipsec-at-hub:9054: negotiation result
027 ike 0:ipsec-at-hub:9054: proposal id = 1:
028 ike 0:ipsec-at-hub:9054:   protocol id = ISAKMP:
029 ike 0:ipsec-at-hub:9054:      trans_id = KEY_IKE.
030 ike 0:ipsec-at-hub:9054:      encapsulation = IKE/none
031 ike 0:ipsec-at-hub:9054:         type=OAKLEY_ENCRYPT_ALG, val=AES_CBC.
032 ike 0:ipsec-at-hub:9054:         type=OAKLEY_HASH_ALG, val=SHA.
033 ike 0:ipsec-at-hub:9054:         type=AUTH_METHOD, val=PRESHARED_KEY.
034 ike 0:ipsec-at-hub:9054:         type=OAKLEY_GROUP, val=1024.
035 ike 0:ipsec-at-hub:9054: ISKAMP SA lifetime=28800
036 ike 0:ipsec-at-hub:9054: out lots-of-hex
037 ike 0:ipsec-at-hub:9054: sent IKE msg (ident_i2send): hub-ip:500->rem-nat-ip:500, len=228, id=0e28555e25dd2dd9/ab80a5ace2a1c17e
038 ike 0: comes rem-nat-ip:500->hub-ip:500,ifindex=8....
039 ike 0: IKEv1 exchange=Identity Protection id=0e28555e25dd2dd9/ab80a5ace2a1c17e len=144
040 ike 0: in lots-of-hex
041 ike 0:ipsec-at-hub:9054: retransmission, re-send last message
042 ike 0:ipsec-at-hub:9054: out lots-of-hex
043 ike 0:ipsec-at-hub:9054: sent IKE msg (retransmit): hub-ip:500->rem-nat-ip:500, len=228, id=0e28555e25dd2dd9/ab80a5ace2a1c17e
044 ike 0: comes rem-nat-ip:500->hub-ip:500,ifindex=8....
045 ike 0: IKEv1 exchange=Identity Protection id=0e28555e25dd2dd9/ab80a5ace2a1c17e len=228
046 ike 0: in lots-of-hex
047 ike 0:ipsec-at-hub:9054: initiator: main mode get 2nd response...
048 ike 0:ipsec-at-hub:9054: NAT detected: PEER
049 ike 0:ipsec-at-hub:9054: NAT-T float port 4500
050 ike 0:ipsec-at-hub:9054: ISAKMP SA 0e28555e25dd2dd9/ab80a5ace2a1c17e key 16:D002ADFCCECD76D00CADE8B465395119
051 ike 0:ipsec-at-hub:9054: add INITIAL-CONTACT
052 ike 0:ipsec-at-hub:9054: enc lots-of-hex
053 ike 0:ipsec-at-hub:9054: out lots-of-hex
054 ike 0:ipsec-at-hub:9054: sent IKE msg (ident_i3send): hub-ip:4500->rem-nat-ip:4500, len=108, id=0e28555e25dd2dd9/ab80a5ace2a1c17e
055 ike 0: comes rem-nat-ip:500->hub-ip:500,ifindex=8....
056 ike 0: IKEv1 exchange=Identity Protection id=0e28555e25dd2dd9/ab80a5ace2a1c17e len=228
057 ike 0: in lots-of-hex
058 ike 0:ipsec-at-hub:9054: retransmission, re-send last message
059 ike 0:ipsec-at-hub:9054: out lots-of-hex
060 ike 0:ipsec-at-hub:9054: sent IKE msg (retransmit): hub-ip:4500->rem-nat-ip:4500, len=108, id=0e28555e25dd2dd9/ab80a5ace2a1c17e
061 ike 0:ipsec-at-hub:9054: out lots-of-hex
062 ike 0:ipsec-at-hub:9054: sent IKE msg (P1_RETRANSMIT): hub-ip:4500->rem-nat-ip:4500, len=108, id=0e28555e25dd2dd9/ab80a5ace2a1c17e
063 ike shrank heap by 122880 bytes
064 ike 0:ipsec-at-hub: NAT keep-alive 8 hub-ip->rem-nat-ip:4500.
065 ike 0:ipsec-at-hub:9054: negotiation timeout, deleting
066 ike 0:ipsec-at-hub: connection expiring due to phase1 down
067 ike 0:ipsec-at-hub: deleting
068 ike 0:ipsec-at-hub: flushing 
069 ike 0:ipsec-at-hub: flushed 
070 ike 0:ipsec-at-hub: reset NAT-T
071 ike 0:ipsec-at-hub: deleted
072 ike 0:ipsec-at-hub: schedule auto-negotiate
073 ike 0:ipsec-at-hub:9069: initiator: main mode is sending 1st message...
074 ike 0:ipsec-at-hub:9069: cookie da08c6777fc5160d/0000000000000000
075 ike 0:ipsec-at-hub:9069: out lots-of-hex
076 ike 0:ipsec-at-hub:9069: sent IKE msg (ident_i1send): hub-ip:500->rem-nat-ip:500, len=244, id=da08c6777fc5160d/0000000000000000
077 ike 0: comes rem-nat-ip:4500->hub-ip:500,ifindex=8....
078 ike 0:ipsec-at-hub:9069: out lots-of-hex
079 ike 0:ipsec-at-hub:9069: sent IKE msg (P1_RETRANSMIT): hub-ip:500->rem-nat-ip:500, len=244, id=da08c6777fc5160d/0000000000000000
080 ike 0: comes rem-nat-ip:4500->hub-ip:500,ifindex=8....
081 ike 0: comes rem-nat-ip:4500->hub-ip:500,ifindex=8....
082 ike 0:ipsec-at-hub:9069: out lots-of-hex
083 ike 0:ipsec-at-hub:9069: sent IKE msg (P1_RETRANSMIT): hub-ip:500->rem-nat-ip:500, len=244, id=da08c6777fc5160d/0000000000000000
084 ike 0:ipsec-at-hub:9069: negotiation timeout, deleting
085 ike 0:ipsec-at-hub: connection expiring due to phase1 down
086 ike 0:ipsec-at-hub: deleting
087 ike 0:ipsec-at-hub: flushing 
088 ike 0:ipsec-at-hub: flushed 
089 ike 0:ipsec-at-hub: deleted
090 ike 0:ipsec-at-hub: schedule auto-negotiate
091 ike 0:ipsec-at-hub:9085: initiator: main mode is sending 1st message...
092 ike 0:ipsec-at-hub:9085: cookie f7b7009c1f709f12/0000000000000000
093 ike 0:ipsec-at-hub:9085: out lots-of-hex
094 ike 0:ipsec-at-hub:9085: sent IKE msg (ident_i1send): hub-ip:500->rem-nat-ip:500, len=244, id=f7b7009c1f709f12/0000000000000000
095 ike 0:ipsec-at-hub:9085: out lots-of-hex
096 ike 0:ipsec-at-hub:9085: sent IKE msg (P1_RETRANSMIT): hub-ip:500->rem-nat-ip:500, len=244, id=f7b7009c1f709f12/0000000000000000
097 ike 0:ipsec-at-hub:9085: out lots-of-hex
098 ike 0:ipsec-at-hub:9085: sent IKE msg (P1_RETRANSMIT): hub-ip:500->rem-nat-ip:500, len=244, id=f7b7009c1f709f12/0000000000000000

Any suggestions

[ede_pfau]

What I can spot:

- on hub side, "carrier down" (73)

- on remote side, timeout of phase1 and no auto-negotiation.

Phase1 auto-neg is set either in the phase1-interface section or in 'conf system global'.

The 'carrier down' msg might indicate a flaky line. How probable is that?

[journeyman]

Thanks for your reply.

Most settings have been left at default including auto-negotiate. The cli manual shows the default is enable?

As far as I know nothing has been set in system global.

I compared configurations using a simple show and not show full.

We have a simple, minimal configuration with values set for interface, local-gw, local-id, dhgrp, proposal and psksecret off the top of my head (currently no access to configs). We use nat traversal but default is enabled etc.

Regarding carrier down, could this be a HA related issue? During the upgrade we had a single unit powered and running the final config (4.3.18, HA enabled); the tunnels weren't stable in this condition (prior to the HA cluster forming).

We have a very similar site-to-site vpn configured elsewhere that is working fine (different transport but FGT configs similar without the HA).

The WAN link is a frame relay into a telco private network. the 8 remote ends are all 3G. It's pretty solid. The LAN link from the FGT to the CPE router is via a cheap unmanaged switch. I have full control of the CPE router. It was all working fine moments prior to the upgrade. The LAN lead from the primary HA unit was in use prior to the upgrade. See also my reply to emnoc.

[emnoc]

My 1st comment, if you upgraded to 4.1.x to 4.3.18 than that's not the proper upgrade flow. I don't have the release notes in front of me but I would suggest you read those. I believe you nee dto be in a 4.0 mr2 or even a earlier 4.0 mr3 build

Next on the side that shows nothing in a debug have  you tried a "diag sniffer packet wan1 " host< remote spoke address > and port 500 or 4500 "

e.g assuming wan1 is in the interface

[I

diag  sniffer packet  wan1 "host 1.1.1.1 and port 500 or 4500"

or

diag  sniffer packet  wan1 "host 1.1.1.1 and port 500 or 4500  or proto 50"

Do you see any ike packets ? Do you see any ESP packets ?

I would start from  that point and rebuild the vpn-cfgs.

[journeyman]

Thanks for your reply also.

The upgrade was performed per the upgrade path doco, viz.:

Take new unit (hardware generation matches existing, ultimately HA slave), format device and load old 4.1.4, load existing config, then upgrade 4.1.4 > 4.2.15 > 4.3.11 > 4.3.18 (intermediate versions from memory). Console messages monitored during each upgrade (nothing interesting). Then the HA config was applied as master.

Existing unit shutdown from console and new unit placed into service. Everything working except ipsec.

Take existing unit, remove LAN leads, factory reset, load 4.3.18, factory reset for caution, change to interface mode, make changes to suit HA, configure as HA slave, connect heartbeat interfaces, wait til console says sync successful, wait some more, swap HA priority so existing unit should be HA master, reconnect interfaces, verify failback.

End result, existing unit is master of a HA cluster, new unit now the slave and the firmware upgrade per the book.

Re packet sniffing, short answer yes. Sniffing has been run, primarily to verify the sent/received at each end matches which is the case, using:

diag sni pac <interface> 'host <remote-ip>' 4 0 a

The only traffic matching <interface> and <remote-ip> is the ipsec traffic so don't need to be more specific.

There is continuous packet flow observed on UDP 500 and UDP 4500. The output isn't posted (can do) since it seems OK to me and figured the ike debug would be more useful (and for brevity). As mentioned each end matches using a visual check / packet count (nothing missing). In a previous ipsec thread ede mentions that ESP is only visible on the ppp interface and needs to sniff the any interface to see it?

It would be nice to avoid having to rebuild the vpn configurations if at all possible - but it isn't working now...

[emnoc]

I doubt you have to go and reuild the vpns, but have you  gather ph1 and ph2 statistics and compated local<> remote?

e.g ( from both sides)

diag vpn ike gate

diag vpn tunnel

Ken

[journeyman]

Lots of diagnostics but no resolution. Suggestions for continuing diagnostics welcome.

Settings

phase1-interface settings are default except for : interface, dhgrp, proposal, psk, remote-gw.

localid was set as simple text string, neither fqdn nor ip; has been removed; auto-negotiate is enabled by default.

phase2-interface settings are default except for: phase1name, dhgrp, proposal.

Only one combination is set in each proposal.

No global auto-negotiate setting found.

Packet sniffer

Packet sniffing with verbosity 6 and then fgt2eth and combined with mergecap. In a three minute period there are 101 packets with zero loss. Summary of all packets:

UDP port  | hub originate | remote originate
500-500   |       17      |        34
4500-500  |        -      |         3
4500-4500 |       10      |        37

Wireshark dissectors complain that the 4500->500 packets have isakmp.length "bogus, length is 0, should be at least 28", but I've seen these packets before on working tunnels.

VPN diagnostics

Using diag vpn ike gate list and diag vpn tunnel list show two distinct phases, results below for one tunnel both ends. Note that the hub gateway list output shows 4500-500, not 4500-4500

Hub end showing both phases

# diag vpn ike gateway list name ipsec-at-hub
vd: root/0
name: ipsec-at-hub
version: 1
interface: internal4 8
addr: hub-ip:500 -> rem-nat-ip:500
created: 29s ago
IKE SA: created 1/1
IPsec SA: created 0/0

  id/spi: 125946 c99da1215d72bdef/0000000000000000
  direction: responder
  status: connecting, state 3, started 29s ago

# diag vpn tunnel list name ipsec-at-hub
list ipsec tunnel by names in vd 0
------------------------------------------------------
name=ipsec-at-hub ver=1 serial=3 hub-ip:0->rem-nat-ip:0 lgwy=dyn tun=intf mode=auto bound_if=8
proxyid_num=1 child_num=0 refcnt=6 ilast=9 olast=9
stat: rxp=0 txp=0 rxb=0 txb=0
dpd: mode=active on=0 idle=5000ms retry=3 count=0 seqno=0
natt: mode=none draft=0 interval=0 remote_port=0
proxyid=ipsec-at-hub-p2 proto=0 sa=0 ref=1 auto_negotiate=0 serial=1 
  src: 0:0.0.0.0/0.0.0.0:0
  dst: 0:0.0.0.0/0.0.0.0:0

# diag vpn ike gateway list name ipsec-at-hub
vd: root/0
name: ipsec-at-hub
version: 1
interface: internal4 8
addr: hub-ip:4500 -> rem-nat-ip:500
created: 23s ago
IKE SA: created 1/1
IPsec SA: created 0/0

  id/spi: 125960 02dab0a9af15ac14/8b8cd3ea381f9a82
  direction: responder
  status: connecting, state 7, started 23s ago

# diag vpn tunnel list name ipsec-at-hub
list ipsec tunnel by names in vd 0
------------------------------------------------------
name=ipsec-at-hub ver=1 serial=3 hub-ip:4500->rem-nat-ip:4500 lgwy=dyn tun=intf mode=auto bound_if=8
proxyid_num=1 child_num=0 refcnt=7 ilast=28 olast=8
stat: rxp=0 txp=0 rxb=0 txb=0
dpd: mode=active on=0 idle=5000ms retry=3 count=0 seqno=0
natt: mode=keepalive draft=32 interval=10 remote_port=4500
proxyid=ipsec-at-hub-p2 proto=0 sa=0 ref=1 auto_negotiate=0 serial=1
  src: 0:0.0.0.0/0.0.0.0:0
  dst: 0:0.0.0.0/0.0.0.0:0Remote end showing both phases

# diag vpn ike gateway list name ipsec-at-remote
vd: root/0
name: ipsec-at-remote
version: 1
interface: wan2 5
addr: my-ip:500 -> hub-ip:500
created: 1s ago
IKE SA: created 2/2
IPsec SA: created 0/0

  id/spi: 20678 02dab0a9af15ac14/8b8cd3ea381f9a82
  direction: responder
  status: connecting, state 3, started 1s ago

  id/spi: 20677 2d6806218aa4643b/0000000000000000
  direction: responder
  status: connecting, state 3, started 1s ago

# diag vpn tunnel list name ipsec-at-remote
list all ipsec tunnel in vd 0
------------------------------------------------------
name=ipsec-at-remote ver=1 serial=1 my-ip:0->hub-ip:0 lgwy=dyn tun=intf mode=auto bound_if=5
proxyid_num=1 child_num=0 refcnt=8 ilast=4 olast=4
stat: rxp=0 txp=0 rxb=0 txb=0
dpd: mode=active on=0 idle=5000ms retry=3 count=0 seqno=343794
natt: mode=none draft=0 interval=0 remote_port=0
proxyid=ipsec-at-remote-p2 proto=0 sa=0 ref=1 auto_negotiate=0 serial=1 
  src: 0:0.0.0.0/0.0.0.0:0
  dst: 0:0.0.0.0/0.0.0.0:0

# diag vpn ike gateway list name ipsec-at-remote
vd: root/0
name: ipsec-at-remote
version: 1
interface: wan2 5
addr: my-ip:4500 -> hub-ip:4500
created: 30s ago
IKE SA: created 1/2  established 1/1  time 19010/19010/19010 ms
IPsec SA: created 1/1

  id/spi: 20678 02dab0a9af15ac14/8b8cd3ea381f9a82
  direction: responder
  status: established 29-10s ago = 19010ms
  proposal: aes128-sha1
  key: 683dcc65337afe6f-cbb772567361d43e
  lifetime/rekey: 28800/28519
  DPD sent/recv: 00053ef3/00000000

# diag vpn tunnel list name ipsec-at-remote
list all ipsec tunnel in vd 0
------------------------------------------------------
name=ipsec-at-remote ver=1 serial=1 my-ip:4500->hub-ip:4500 lgwy=dyn tun=intf mode=auto bound_if=5
proxyid_num=1 child_num=0 refcnt=10 ilast=2 olast=3
stat: rxp=0 txp=0 rxb=0 txb=0
dpd: mode=active on=1 idle=5000ms retry=3 count=2 seqno=343795
natt: mode=keepalive draft=32 interval=10 remote_port=4500
proxyid=ipsec-at-remote-p2 proto=0 sa=0 ref=1 auto_negotiate=0 serial=1 
  src: 0:0.0.0.0/0.0.0.0:0
  dst: 0:0.0.0.0/0.0.0.0:0

 edit: attempted html table changed to code

[emnoc]

Did you do a diag vpn tunnel and post the output?

Are these vpn policy or route based?

Can you  post cfg ph1 & 2 or a hub  and spoke? ( hint: each spoke should be built the same as the  hub with the local/remote address be different  & same for the  phase2 cfg src/dst subnet being reverse  )

Did you check my  howto t-shoot  ipsec vpns?

http://socpuppet.blogspot.com/2013/10/site-2-site-routed-vpn-trouble-shooting.html

[ede_pfau]

Phase2 doesn't come up. That's why phase1 SA times out ultimately...

Have you checked that NAT-T is enabled on both hub and spokes? Traffic seems to go through a NAT router, not a modem.

If necessary please post the full config for phase1 and phase2, both sides. Hide remote IPs etc. as appropriate. Use 'show full' so that the defaults are shown as well.

[journeyman]

Thanks for your replies gentlemen.

@emnoc - I have spent quite a bit of time with your trouble shooting guide, happy to cross check again and post. I find ipsec trouble shooting difficult, I find it difficult to recognise what's right.

Can you please clarify the command output you'd like to see as there's a fairly large tree below diag vpn tunnel; I guessed you were after diag vpn tunnel list posted above.

The vpns are route based - they exist purely to allow ospf where we couldn't otherwise route.

Will post configs (currently at home..)

@ede - Nat-t is enabled both ends, I did a visual line-by-line comparison on full configs this morning, I will post sanitised. I've been focusing on ph1 since I perceive there's more going on there, haven't looked at ph2 full.

The path is FGT-hub > LAN (unmanaged switch) > our wan interface router > telco frame relay > telco "private network" > 3G router > LAN (patch lead direct) > FGT-remote.

The 3G router is pretty simple and is where we NAT with port forwarding rules. The wan router advertises the LAN subnet into the "private network" cloud. I'm pretty confident of the rules at both the wan router and the 3G routers but will recheck those as well (wireshark merge > compare indicates that no packets were lost so I figured all was well in that regard).

I'm a bit worried about your comment re "carrier down". Not so much from the telco side, more the LAN at the hub end. Any possible issues with HA on a dumb LAN segment do you think?

The WAN link carries a simulated voice channel to an unrelated site - if there was any problem with the wan link it would be very obvious (plenty of bandwidth for all purposes).