IPSEC Phase1 Timeout

[ddskier]

Everyone,

For some reason two out of my 11 IPv6 VPN tunnels decided to stop working.   I swear I haven't changed anything except to upgrade firmware to 5.0.13 a few weeks back.     The IKE logs seem to indicate a Phase 1 negotiation time out.  I think...   Can anyone else see anything on this DIAG output that could help me figure out why they won't connect?

(IP Address and some of the keying has been masked)

ike 0:VPN2Corp_v6:VPN2Corp_Tun_v6: IPsec SA connect 26 Y:Y:Y:Y::Y->X:X:X:X::X:X:0 ike 0:VPN2Corp_v6:VPN2Corp_Tun_v6: config found ike 0:VPN2Corp_v6: created connection: 0x33101e0 26 Y:Y:Y:Y::Y->X:X:X:X::X:X:500. ike 0:VPN2Corp_v6: IPsec SA connect 26 Y:Y:Y:Y::Y->X:X:X:X::X:X:500 negotiating ike 0:VPN2Corp_v6: no suitable ISAKMP SA, queuing quick-mode request and initiating ISAKMP SA negotiation ike 0:VPN2Corp_v6:20: initiator: main mode is sending 1st message... ike 0:VPN2Corp_v6:20: cookie 63dda0295a3ac566/0000000000000000 ike 0:VPN2Corp_v6:20: out ~~~~~~~~~~~~~~~~~~~~~~~~~~ ike 0:VPN2Corp_v6:20: sent IKE msg (ident_i1send): Y:Y:Y:Y::Y:500->X:X:X:X::X:X:500, len=300, id=63dda0295a3ac566/0000000000000000 ike 0: comes X:X:X:X::X:X:500->Y:Y:Y:Y::Y:500,ifindex=26.... ike 0: IKEv1 exchange=Identity Protection id=309e7b48231b8146/0000000000000000 len=300 ike 0: in ~~~~~~~~~~~~~~~~~~~~~~~~~~ ike 0:309e7b48231b8146/0000000000000000:21: responder: main mode get 1st message... ike 0:309e7b48231b8146/0000000000000000:21: VID RFC 3947 4A131C81070358455C5728F20E95452F ike 0:309e7b48231b8146/0000000000000000:21: VID draft-ietf-ipsec-nat-t-ike-03 7D9419A65310CA6F2C179D9215529D56 ike 0:309e7b48231b8146/0000000000000000:21: VID draft-ietf-ipsec-nat-t-ike-02 CD60464335DF21F87CFDB2FC68B6A448 ike 0:309e7b48231b8146/0000000000000000:21: VID draft-ietf-ipsec-nat-t-ike-02\n 90CB80913EBB696E086381B5EC427B1F ike 0:309e7b48231b8146/0000000000000000:21: VID draft-ietf-ipsec-nat-t-ike-01 16F6CA16E4A4066D83821A0F0AEAA862 ike 0:309e7b48231b8146/0000000000000000:21: VID draft-ietf-ipsec-nat-t-ike-00 4485152D18B6BBCD0BE8A8469579DDCC ike 0:309e7b48231b8146/0000000000000000:21: VID DPD AFCAD71368A1F1C96B8696FC77570100 ike 0:309e7b48231b8146/0000000000000000:21: VID FRAGMENTATION 4048B7D56EBCE88525E7DE7F00D6C2D3 ike 0:309e7b48231b8146/0000000000000000:21: VID FORTIGATE 8299031757A36082C6A621DE00050142 ike 0:309e7b48231b8146/0000000000000000:21: negotiation result ike 0:309e7b48231b8146/0000000000000000:21: proposal id = 1: ike 0:309e7b48231b8146/0000000000000000:21:   protocol id = ISAKMP: ike 0:309e7b48231b8146/0000000000000000:21:      trans_id = KEY_IKE. ike 0:309e7b48231b8146/0000000000000000:21:      encapsulation = IKE/none ike 0:309e7b48231b8146/0000000000000000:21:         type=OAKLEY_ENCRYPT_ALG, val=AES_CBC. ike 0:309e7b48231b8146/0000000000000000:21:         type=OAKLEY_HASH_ALG, val=SHA. ike 0:309e7b48231b8146/0000000000000000:21:         type=AUTH_METHOD, val=RSA_SIG. ike 0:309e7b48231b8146/0000000000000000:21:         type=OAKLEY_GROUP, val=1536. ike 0:309e7b48231b8146/0000000000000000:21: ISAKMP SA lifetime=28800 ike 0:309e7b48231b8146/0000000000000000:21: SA proposal chosen, matched gateway VPN2Corp_v6 ike 0: found VPN2Corp_v6 Y:Y:Y:Y::Y 26 -> X:X:X:X::X:X:500 ike 0:VPN2Corp_v6:21: DPD negotiated ike 0:VPN2Corp_v6:21: peer is FortiGate/FortiOS (v5 b322) ike 0:VPN2Corp_v6:21: selected NAT-T version: RFC 3947 ike 0:VPN2Corp_v6:21: cookie 309e7b48231b8146/080e94773f9c5f77 ike 0:VPN2Corp_v6:21: out ~~~~~~~~~~~~~~~~~~~~~~~~ ike 0:VPN2Corp_v6:21: sent IKE msg (ident_r1send): Y:Y:Y:Y::Y:500->X:X:X:X::X:X:500, len=164, id=309e7b48231b8146/080e94773f9c5f77 ike 0:VPN2Corp_v6:VPN2Corp_Tun_v6: IPsec SA connect 26 Y:Y:Y:Y::Y->X:X:X:X::X:X:0 ike 0:VPN2Corp_v6:VPN2Corp_Tun_v6: using existing connection ike 0:VPN2Corp_v6:VPN2Corp_Tun_v6: config found ike 0:VPN2Corp_v6: request is on the queue ike 0:VPN2Corp_v6:20: out ~~~~~~~~~~~~~~~~~~~~~~~~~~ ike 0:VPN2Corp_v6:20: sent IKE msg (P1_RETRANSMIT): Y:Y:Y:Y::Y:500->X:X:X:X::X:X:500, len=300, id=63dda0295a3ac566/0000000000000000 ike 0: comes X:X:X:X::X:X:500->Y:Y:Y:Y::Y:500,ifindex=26.... ike 0: IKEv1 exchange=Identity Protection id=309e7b48231b8146/0000000000000000 len=300 ike 0: in ~~~~~~~~~~~~~~~~~~~~~~~~~~ ike 0:VPN2Corp_v6:21: retransmission, re-send last message ike 0:VPN2Corp_v6:21: out ~~~~~~~~~~~~~~~~~~~~~~~~ ike 0:VPN2Corp_v6:21: sent IKE msg (retransmit): Y:Y:Y:Y::Y:500->X:X:X:X::X:X:500, len=164, id=309e7b48231b8146/080e94773f9c5f77 ike 0:VPN2Corp_v6:21: out ~~~~~~~~~~~~~~~~~~~~~~~~ ike 0:VPN2Corp_v6:21: sent IKE msg (P1_RETRANSMIT): Y:Y:Y:Y::Y:500->X:X:X:X::X:X:500, len=164, id=309e7b48231b8146/080e94773f9c5f77 ike 0:VPN2Corp_v6:VPN2Corp_Tun_v6: IPsec SA connect 26 Y:Y:Y:Y::Y->X:X:X:X::X:X:0 ike 0:VPN2Corp_v6:VPN2Corp_Tun_v6: using existing connection ike 0:VPN2Corp_v6:VPN2Corp_Tun_v6: config found ike 0:VPN2Corp_v6: request is on the queue ike 0:VPN2Corp_v6:VPN2Corp_Tun_v6: IPsec SA connect 26 Y:Y:Y:Y::Y->X:X:X:X::X:X:0 ike 0:VPN2Corp_v6:VPN2Corp_Tun_v6: using existing connection ike 0:VPN2Corp_v6:VPN2Corp_Tun_v6: config found ike 0:VPN2Corp_v6: request is on the queue ike 0:VPN2Corp_v6:20: negotiation timeout, deleting ike 0:VPN2Corp_v6: schedule auto-negotiate ike 0:VPN2Corp_v6:21: negotiation timeout, deleting ike 0:VPN2Corp_v6: connection expiring due to phase1 down ike 0:VPN2Corp_v6: deleting ike 0:VPN2Corp_v6: flushing ike 0:VPN2Corp_v6: flushed ike 0:VPN2Corp_v6: deleted ike 0:VPN2Corp_v6: auto-negotiate connection ike 0:VPN2Corp_v6: created connection: 0x33101e0 26 Y:Y:Y:Y::Y->X:X:X:X::X:X:500. ike 0:VPN2Corp_v6:22: initiator: main mode is sending 1st message... ike 0:VPN2Corp_v6:22: cookie 5c322ae457493ca9/0000000000000000 ike 0:VPN2Corp_v6:22: out ~~~~~~~~~~~~~~~~~~~~~~~~~~ ike 0:VPN2Corp_v6:22: sent IKE msg (ident_i1send): Y:Y:Y:Y::Y:500->X:X:X:X::X:X:500, len=300, id=5c322ae457493ca9/0000000000000000 ike 0: comes X:X:X:X::X:X:500->Y:Y:Y:Y::Y:500,ifindex=26.... ike 0: IKEv1 exchange=Identity Protection id=a9a7d2844ee466f6/0000000000000000 len=300 ike 0: in ~~~~~~~~~~~~~~~~~~~~~~~~~~ ike 0:a9a7d2844ee466f6/0000000000000000:23: responder: main mode get 1st message... ike 0:a9a7d2844ee466f6/0000000000000000:23: VID RFC 3947 4A131C81070358455C5728F20E95452F ike 0:a9a7d2844ee466f6/0000000000000000:23: VID draft-ietf-ipsec-nat-t-ike-03 7D9419A65310CA6F2C179D9215529D56 ike 0:a9a7d2844ee466f6/0000000000000000:23: VID draft-ietf-ipsec-nat-t-ike-02 CD60464335DF21F87CFDB2FC68B6A448 ike 0:a9a7d2844ee466f6/0000000000000000:23: VID draft-ietf-ipsec-nat-t-ike-02\n 90CB80913EBB696E086381B5EC427B1F ike 0:a9a7d2844ee466f6/0000000000000000:23: VID draft-ietf-ipsec-nat-t-ike-01 16F6CA16E4A4066D83821A0F0AEAA862 ike 0:a9a7d2844ee466f6/0000000000000000:23: VID draft-ietf-ipsec-nat-t-ike-00 4485152D18B6BBCD0BE8A8469579DDCC ike 0:a9a7d2844ee466f6/0000000000000000:23: VID DPD AFCAD71368A1F1C96B8696FC77570100 ike 0:a9a7d2844ee466f6/0000000000000000:23: VID FRAGMENTATION 4048B7D56EBCE88525E7DE7F00D6C2D3 ike 0:a9a7d2844ee466f6/0000000000000000:23: VID FORTIGATE 8299031757A36082C6A621DE00050142 ike 0:a9a7d2844ee466f6/0000000000000000:23: negotiation result ike 0:a9a7d2844ee466f6/0000000000000000:23: proposal id = 1: ike 0:a9a7d2844ee466f6/0000000000000000:23:   protocol id = ISAKMP: ike 0:a9a7d2844ee466f6/0000000000000000:23:      trans_id = KEY_IKE. ike 0:a9a7d2844ee466f6/0000000000000000:23:      encapsulation = IKE/none ike 0:a9a7d2844ee466f6/0000000000000000:23:         type=OAKLEY_ENCRYPT_ALG, val=AES_CBC. ike 0:a9a7d2844ee466f6/0000000000000000:23:         type=OAKLEY_HASH_ALG, val=SHA. ike 0:a9a7d2844ee466f6/0000000000000000:23:         type=AUTH_METHOD, val=RSA_SIG. ike 0:a9a7d2844ee466f6/0000000000000000:23:         type=OAKLEY_GROUP, val=1536. ike 0:a9a7d2844ee466f6/0000000000000000:23: ISAKMP SA lifetime=28800 ike 0:a9a7d2844ee466f6/0000000000000000:23: SA proposal chosen, matched gateway VPN2Corp_v6 ike 0: found VPN2Corp_v6 Y:Y:Y:Y::Y 26 -> X:X:X:X::X:X:500

[ede_pfau]

Hi,

the thread is lost when this FGT is waiting for a response. So the config change probably is with the remote FGT.

What is build 322 again?

[ddskier]

The firmware is 322.

I just don't understand why it suddenly stopped working

Site:

    edit "VPN2Corp_v6"

        set interface "wan1"

        set ip-version 6

        set local-gw6 X:X:X:X::X

        set authmethod rsa-signature

        set proposal aes128-sha1 aes128-md5

        set negotiate-timeout 15

        set send-cert-chain disable

        set remote-gw6 Y:Y:Y:Y::Y

        set rsa-certificate "IPSEC_Cert"

    next

DataCenter:

    edit "Site_VPN_v6"

        set interface "port10"

        set ip-version 6

        set local-gw6 Y:Y:Y:Y::Y

        set authmethod rsa-signature

        set proposal aes128-sha1 aes128-md5

        set negotiate-timeout 15

        set send-cert-chain disable

        set remote-gw6 X:X:X:X::X

        set rsa-certificate "IPSEC_Cert"

    next

[ede_pfau]

Out of the blue, could you raise the 'negotiate-timeout'?

[ddskier]

It is strange the tunnels sometime will connect for a little bit and then go down again.

On the phone with Fortinet Support and they are wondering if Dead Peer Detection is causing the issue.  Had me turn it off, but it didn't seem to change anything.

Just changed the timeout to 30. 

We'll see.

[ddskier]

Seems like the timeout fixed the issue.    I believe there was a choke point out West that was causing traffic to be a little slower and making the VPN timeout.

FYI - I also changed my tunnels over to IKEv2.