Skip to main content
journeyman
journeyman
New Member
March 4, 2014
Question

debugging ipsec with nat traversal

  • March 4, 2014
  • 5 replies
  • 44483 views
Looking to get ipsec between two FGT60C with a view to running ospf through the tunnel. Hence, interface mode etc. FGT2 is behind a NAT router. I' m new to VPNs. I already configured vpn between FGT1 and nat router, now disabled and extending through the router to FGT2 to suit the above. FGT1 <------(NAT router)--> FGT2 I believe a sufficient config skeleton is in place - ike config (nat traversal enabled both ends), basic policies, static routes. The tunnel looks like it is trying to come up. Currently there is traffic in both directions on UDP:4500 but the tunnel does not come up. In another recent thread Silvia suggested using diag deb appl ike -1 In the same thread enmoc suggests diag deb flow. 1. Given I have end to end connectivity is there any point in using flow? What filter is suggested? diag sni pac already shows the traffic. A sample of the debug is
diag deb appl ike -1  ike 0:to-remote-vpn:15761: sent IKE msg (R-U-THERE): 192.168.x.142:4500->192.168.y.2:4500, len=92  ike 0: comes 192.168.y.2:4500->192.168.x.142:4500,ifindex=8....  ike 0: IKEv1 exchange=Informational id=56aaf214090a1f2a/19936a311a003ea5:97100104 len=92  ike 0: found to-remote-vpn 192.168.x.142 8 -> 192.168.y.2:4500  ike 0:to-remote-vpn:15761: notify msg received: R-U-THERE  ike 0:to-remote-vpn:15761: confirmed nat-t RFC 3947  ike 0:to-remote-vpn:15761: sent IKE msg (R-U-THERE-ACK): 192.168.x.142:4500->192.168.y.2:4500, len=92  ike 0: comes 192.168.y.2:4500->192.168.x.142:4500,ifindex=8....  ike 0: IKEv1 exchange=Informational id=56aaf214090a1f2a/19936a311a003ea5:6e7156ad len=92  ike 0: found to-remote-vpn 192.168.x.142 8 -> 192.168.y.2:4500  ike 0:to-remote-vpn:15761: notify msg received: R-U-THERE-ACK  ike 0:to-remote-vpn: link is idle 8 192.168.x.142->192.168.y.2:4500 dpd=1 seqno=b50e  ike 0:to-remote-vpn:15761: send IKEv1 DPD probe, seqno 46350  ike 0:to-remote-vpn:15761: confirmed nat-t RFC 3947  increment seqno, repeat
The output shows lots of R-U-THERE and R-U-THERE-ACK at both ends continuously but nothing after that. There is also an entry saying " confirmed nat-t RFC3947" which would seem to be a step in the right direction. It seems that both FGT1 and FGT2 are sending R-U-THERE. I have NOT set up port forwarding on the nat router, presumed that FGT2 would bring up the tunnel. 2. What is the next expected step and what might be the config fault stopping it? Is there some other debug I can use to give me a clue or is it already in front of me? Thanks in advance,

    5 replies

    emnoc
    emnoc
    New Member
    March 4, 2014
    Will you have a NAt devices in the middle. Have you inspect it' s allowances for both ike-nat and ESP? I believe your problem is going to lay with that device and you might need to adjust by extending NAT-timeout for udp traffic and port specific 4500/udp. I would start by doing the following; 1st by validation of a phase1 SA on both FGT & IKE traffic is actually moving across your interface. diag vpn ike gateway list if that shows nothing than I would STOP! and execute the following diag debug app ike filter name " your phase1 name" diag debug app ike -1 diag debug enable and in another ssh session; diag sniffer packet wan1 " udp and st port 4500" Replace wan1 with whatever interfaces you have in the phase1-name. You should at this point see udp/4500 traffic that matches the packets sent---> received and received<------sent by the 2 FGT. If the NAT device has a session table for NAT, I would filter on your udp-traffic in that table. And lastly, how does your NAT-router handle ESP? Do you need pinholes for ESP added? Does it conduct ALG function for ESP between vpn pairs? Are you 100% nat transveral is enable for BOTH parties? What IKE keepalives intervals that youare you using?
    journeyman
    journeymanAuthor
    New Member
    March 5, 2014
    I posted this query because when I checked VPN > IPsec Monitor at each end, the link status showed down; this is why I thought I had a problem. (In my test VPN to the NAT router the status was up at the corresponding stage). But now it seems it was working all along, and the messages in the debug above are dead peer detection messages? - I had already run diag deb sni pac with useful filters and seen traffic on UDP:4500 in both directions at both FGT units. - I had already run diag deb appl ike -1 and posted the results above. Today I have run diag vpn ike gateway and useful data is returned, showing uptime on the tunnel of almost a day. Today I also added local and remote IP addresses in Network > interface and I can ping the remote tunnel IP address. I did not do this yesterday because I thought I already had a problem to solve. So if I can ping the remote interface I guess all is well so far. Thanks for the diag vpn ike gateway tip, that showed me I had something working already.
    journeyman
    journeymanAuthor
    New Member
    April 10, 2014
    We have this working nicely now in a hub configuration. There are multiple ipsec tunnels at FGT1 and each tunnel traverses a nat router to terminate at FGTn. note that the nat router is a 3G device. OSPF running, failover works very nicely. Now one particular tunnel has failed and won' t come up. This tunnel was previously fully working. The 3G side appears to be fine. We see continuous connection attempts. Using diag deb ike gateway list at each end, the remote has three " attempted sessions" (don' t know the correct terminology) and the hub has one. Using diag deb app ike -1, we see interesting stuff. I' ve posted fragments below, hopefully neither too little nor too much At the remote end, two entries stand out to me are " embyonic limit 4 reached, deleting <spi>" and " retransmission, ignored since still generating response" . At the hub, the interesting entry is " <spi> malformed or expired" Also at the remote end we appear to have interwoven spi? Any tips on what is happening, any further debug I can do, how to fix it and how to prevent it in future? Hub diags:
    HUB # diag vpn ike gate list  #working tunnels deleted  vd: root/0  name: ipsec-to-nat  version: 1  interface: internal4 8  addr: <hub-ip>:500 -> <outside-ip>:500  created: 0s ago  ISAKMP SA: created 1/1  IPsec SA: created 0/0      id/spi: 28619 e44c5adb56156e10/6cc78d9f1418f462    direction: responder    status: connecting, state 5, started 0s ago    ike 0:ipsec-to-nat:28629: confirmed nat-t RFC 3947  ike 0:ipsec-to-nat:28629: sent IKE msg (P1_RETRANSMIT): <hub-ip>:4500-><outside-ip>:4500, len=108  ike 0:ipsec-to-nat: link fail 8 <hub-ip>-><outside-ip>:4500 dpd=1  ike 0:ipsec-to-nat: DPD fail 8 <hub-ip>-><outside-ip>:4500 send failure, resetting ...  ike 0:ipsec-to-nat: deleting  ike 0:ipsec-to-nat: flushing   ike 0:ipsec-to-nat: flushed   ike 0:ipsec-to-nat: reset NAT-T  ike 0:ipsec-to-nat: deleted  ike 0:ipsec-to-nat: created DPD triggered connection: 0x134b270 8 <hub-ip>-><outside-ip>:500.  ike 0:ipsec-to-nat: new connection.  ike 0:ipsec-to-nat:28630: initiator: main mode is sending 1st message...  ike 0:ipsec-to-nat:28630: cookie 7d5703885010591d/0000000000000000  ike 0:ipsec-to-nat:28630: sent IKE msg (ident_i1send): <hub-ip>:500-><outside-ip>:500, len=224  ike 0: comes <outside-ip>:500-><hub-ip>:500,ifindex=8....  ike 0: IKEv1 exchange=Identity Protection id=7d5703885010591d/aafdeb97af484be9 len=144  ike 0: found ipsec-to-nat <hub-ip> 8 -> <outside-ip>:500  ike 0:ipsec-to-nat:28630: initiator: main mode get 1st response...  ike 0:ipsec-to-nat:28630: VID RFC 3947 4A131C81070358455C5728F20E95452F  ike 0:ipsec-to-nat:28630: VID DPD AFCAD71368A1F1C96B8696FC77570100  ike 0:ipsec-to-nat:28630: DPD negotiated  ike 0:ipsec-to-nat:28630: VID unknown (16): 8299031757A36082C6A621DE00040290  ike 0:ipsec-to-nat:28630: selected NAT-T version: RFC 3947  ike 0:ipsec-to-nat:28630: negotiation result  ike 0:ipsec-to-nat:28630: proposal id = 1:  ike 0:ipsec-to-nat:28630:   protocol id = ISAKMP:  ike 0:ipsec-to-nat:28630:      trans_id = KEY_IKE.  ike 0:ipsec-to-nat:28630:      encapsulation = IKE/none  ike 0:ipsec-to-nat:28630:         type=OAKLEY_ENCRYPT_ALG, val=AES_CBC.  ike 0:ipsec-to-nat:28630:         type=OAKLEY_HASH_ALG, val=SHA.  ike 0:ipsec-to-nat:28630:         type=AUTH_METHOD, val=PRESHARED_KEY.  ike 0:ipsec-to-nat:28630:         type=OAKLEY_GROUP, val=1024.  ike 0:ipsec-to-nat:28630: ISKAMP SA lifetime=28800  ike 0:ipsec-to-nat:28630: sent IKE msg (ident_i2send): <hub-ip>:500-><outside-ip>:500, len=228  ike 0: comes <outside-ip>:500-><hub-ip>:500,ifindex=8....  ike 0: IKEv1 exchange=Identity Protection id=7d5703885010591d/aafdeb97af484be9 len=228  ike 0: found ipsec-to-nat <hub-ip> 8 -> <outside-ip>:500  ike 0:ipsec-to-nat:28630: initiator: main mode get 2nd response...  ike 0:ipsec-to-nat:28630: NAT detected: PEER  ike 0:ipsec-to-nat:28630: NAT-T float port 4500  ike 0:ipsec-to-nat:28630: add initial-contact  ike 0:ipsec-to-nat:28630: confirmed nat-t RFC 3947  ike 0:ipsec-to-nat:28630: sent IKE msg (ident_i3send): <hub-ip>:4500-><outside-ip>:4500, len=108  ike shrank heap by 126976 bytes  ike 0:ipsec-to-nat:28630: confirmed nat-t RFC 3947  ike 0:ipsec-to-nat:28630: sent IKE msg (P1_RETRANSMIT): <hub-ip>:4500-><outside-ip>:4500, len=108  ike 0: comes <outside-ip>:500-><hub-ip>:500,ifindex=8....  ike 0: IKEv1 exchange=Identity Protection id=44b4e444ea8dd807/24654d00a98bcfba len=228  ike 0: found ipsec-to-nat <hub-ip> 8 -> <outside-ip>:4500  ike 0:ipsec-to-nat: ISAKMP SA SPI 44b4e444ea8dd807/24654d00a98bcfba  malformed or expired  ike 0:ipsec-to-nat: link fail 8 <hub-ip>-><outside-ip>:4500 dpd=1
    Remote site diags: 
    NAT # diag vpn ike gate list  vd: root/0  name: ipsec-to-hub  version: 1  interface: wan2 5  addr: <inside-ip>:500 -> <hub-ip>:500  created: 136859s ago  IKE SA: created 3/26181  IPsec SA: created 0/0    id/spi: 26552 e44c5adb56156e10/6cc78d9f1418f462    direction: initiator    status: connecting, state 5, started 1s ago      id/spi: 26551 511ad132d6706fc3/e5e6bc9cdf773331    direction: initiator    status: connecting, state 5, started 11s ago      id/spi: 26550 85807024c14a4b35/9557ac0ef3bf3061    direction: responder    status: connecting, state 5, started 16s ago    ike 0: comes <hub-ip>:500-><inside-ip>:500,ifindex=5....  ike 0: IKEv1 exchange=Identity Protection id=44b4e444ea8dd807/0000000000000000 len=224  ike 0: in 44B4E444EA8DD807<hex>  ike 0:ipsec-to-hub:26562: retransmission, ignored since still generating response  ike 0:ipsec-to-hub:26562: cookie 44b4e444ea8dd807/24654d00a98bcfba  ike 0:ipsec-to-hub:26562: out 44B4E444EA8DD80724654D00A98BCFBA<hex>  ike 0:ipsec-to-hub:26562: sent IKE msg (ident_r1send): <inside-ip>:500-><hub-ip>:500, len=144, id=44b4e444ea8dd807/24654d00a98bcfba  ike 0: comes <hub-ip>:500-><inside-ip>:500,ifindex=5....  ike 0: IKEv1 exchange=Identity Protection id=44b4e444ea8dd807/24654d00a98bcfba len=228  ike 0: in 44B4E444EA8DD80724654D00A98BCFBA<hex>  ike 0:ipsec-to-hub:26562: responder:main mode get 2nd message...  ike 0:ipsec-to-hub:26562: NAT detected: ME   ike 0:ipsec-to-hub:26562: out 44B4E444EA8DD80724654D00A98BCFBA<hex>  ike 0:ipsec-to-hub:26562: sent IKE msg (ident_r2send): <inside-ip>:500-><hub-ip>:500, len=228, id=44b4e444ea8dd807/24654d00a98bcfba  ike 0:ipsec-to-hub:26562: ISAKMP SA 44b4e444ea8dd807/24654d00a98bcfba key 16:40358CAA2A9192DB60525865D7510D4C  ike 0: comes <hub-ip>:500-><inside-ip>:500,ifindex=5....  ike 0: IKEv1 exchange=Identity Protection id=7d5703885010591d/0000000000000000 len=224  ike 0: in 7D5703885010591D<hex>  ike 0: found ipsec-to-hub <inside-ip> 5 -> <hub-ip>:500  ike 0:ipsec-to-hub:26563: responder: main mode get 1st message...  ike 0:ipsec-to-hub:26563: VID RFC 3947 4A131C81070358455C5728F20E95452F  ike 0:ipsec-to-hub:26563: VID draft-ietf-ipsec-nat-t-ike-03 7D9419A65310CA6F2C179D9215529D56  ike 0:ipsec-to-hub:26563: VID draft-ietf-ipsec-nat-t-ike-02 CD60464335DF21F87CFDB2FC68B6A448  ike 0:ipsec-to-hub:26563: VID draft-ietf-ipsec-nat-t-ike-02\n 90CB80913EBB696E086381B5EC427B1F  ike 0:ipsec-to-hub:26563: VID draft-ietf-ipsec-nat-t-ike-01 16F6CA16E4A4066D83821A0F0AEAA862  ike 0:ipsec-to-hub:26563: VID draft-ietf-ipsec-nat-t-ike-00 4485152D18B6BBCD0BE8A8469579DDCC  ike 0:ipsec-to-hub:26563: VID DPD AFCAD71368A1F1C96B8696FC77570100  ike 0:ipsec-to-hub:26563: negotiation result  ike 0:ipsec-to-hub:26563: proposal id = 1:  ike 0:ipsec-to-hub:26563:   protocol id = ISAKMP:  ike 0:ipsec-to-hub:26563:      trans_id = KEY_IKE.  ike 0:ipsec-to-hub:26563:      encapsulation = IKE/none  ike 0:ipsec-to-hub:26563:         type=OAKLEY_ENCRYPT_ALG, val=AES_CBC.  ike 0:ipsec-to-hub:26563:         type=OAKLEY_HASH_ALG, val=SHA.  ike 0:ipsec-to-hub:26563:         type=AUTH_METHOD, val=PRESHARED_KEY.  ike 0:ipsec-to-hub:26563:         type=OAKLEY_GROUP, val=1024.  ike 0:ipsec-to-hub:26563: ISKAMP SA lifetime=28800  ike 0:ipsec-to-hub:26563: selected NAT-T version: RFC 3947  ike 0:ipsec-to-hub:26560: embryonic limit 4 reached, deleting 8705e6c9fc0a815e/5ff1a64967564542  ike 0:ipsec-to-hub: schedule auto-negotiate  ike 0:ipsec-to-hub:26563: cookie 7d5703885010591d/aafdeb97af484be9  ike 0:ipsec-to-hub:26563: out 7D5703885010591DAAFDEB97AF484BE9<hex>  ike 0:ipsec-to-hub:26563: sent IKE msg (ident_r1send): <inside-ip>:500-><hub-ip>:500, len=144, id=7d5703885010591d/aafdeb97af484be9  ike 0: comes <hub-ip>:500-><inside-ip>:500,ifindex=5....  ike 0: IKEv1 exchange=Identity Protection id=7d5703885010591d/aafdeb97af484be9 len=228  ike 0: in 7D5703885010591DAAFDEB97AF484BE9<hex>  ike 0:ipsec-to-hub:26563: responder:main mode get 2nd message...  ike 0:ipsec-to-hub:26563: NAT detected: ME   ike 0:ipsec-to-hub:26563: out 7D5703885010591DAAFDEB97AF484BE9<hex>  ike 0:ipsec-to-hub:26563: sent IKE msg (ident_r2send): <inside-ip>:500-><hub-ip>:500, len=228, id=7d5703885010591d/aafdeb97af484be9  ike 0:ipsec-to-hub:26563: ISAKMP SA 7d5703885010591d/aafdeb97af484be9 key 16:5667E7A4AC0477454DA5E088387DE686  ike 0:ipsec-to-hub:26562: out 44B4E444EA8DD80724654D00A98BCFBA<hex>  ike 0:ipsec-to-hub:26562: sent IKE msg (P1_RETRANSMIT): <inside-ip>:500-><hub-ip>:500, len=228, id=44b4e444ea8dd807/24654d00a98bcfba  ike 0: comes <hub-ip>:500-><inside-ip>:500,ifindex=5....  ike 0: IKEv1 exchange=Identity Protection id=94d5a88922c4e072/0000000000000000 len=224  ike 0: in 94D5A88922C4E072<hex>  ike 0: found ipsec-to-hub <inside-ip> 5 -> <hub-ip>:500  ike 0:ipsec-to-hub:26564: responder: main mode get 1st message...  ike 0:ipsec-to-hub:26564: VID RFC 3947 4A131C81070358455C5728F20E95452F  ike 0:ipsec-to-hub:26564: VID draft-ietf-ipsec-nat-t-ike-03 7D9419A65310CA6F2C179D9215529D56  ike 0:ipsec-to-hub:26564: VID draft-ietf-ipsec-nat-t-ike-02 CD60464335DF21F87CFDB2FC68B6A448  ike 0:ipsec-to-hub:26564: VID draft-ietf-ipsec-nat-t-ike-02\n 90CB80913EBB696E086381B5EC427B1F  ike 0:ipsec-to-hub:26564: VID draft-ietf-ipsec-nat-t-ike-01 16F6CA16E4A4066D83821A0F0AEAA862  ike 0:ipsec-to-hub:26564: VID draft-ietf-ipsec-nat-t-ike-00 4485152D18B6BBCD0BE8A8469579DDCC  ike 0:ipsec-to-hub:26564: VID DPD AFCAD71368A1F1C96B8696FC77570100  ike 0:ipsec-to-hub:26564: negotiation result  ike 0:ipsec-to-hub:26564: proposal id = 1:  ike 0:ipsec-to-hub:26564:   protocol id = ISAKMP:  ike 0:ipsec-to-hub:26564:      trans_id = KEY_IKE.  ike 0:ipsec-to-hub:26564:      encapsulation = IKE/none  ike 0:ipsec-to-hub:26564:         type=OAKLEY_ENCRYPT_ALG, val=AES_CBC.  ike 0:ipsec-to-hub:26564:         type=OAKLEY_HASH_ALG, val=SHA.  ike 0:ipsec-to-hub:26564:         type=AUTH_METHOD, val=PRESHARED_KEY.  ike 0:ipsec-to-hub:26564:         type=OAKLEY_GROUP, val=1024.  ike 0:ipsec-to-hub:26564: ISKAMP SA lifetime=28800  ike 0:ipsec-to-hub:26564: selected NAT-T version: RFC 3947  ike 0:ipsec-to-hub:26561: embryonic limit 4 reached, deleting f33907ca1f3ab9e9/28f8b238220013fb  ike 0:ipsec-to-hub: schedule auto-negotiate
    End of diags, EOM.
    emnoc
    emnoc
    New Member
    April 10, 2014
    My 1st thoughts are the following message; ike 0:ipsec-to-nat: ISAKMP SA SPI 44b4e444ea8dd807/24654d00a98bcfba malformed or expired This seems to indicate a bad PSK. Have you triple check the PSK? Also have you double check the device(s) doing the NAT? If you look at the debug you will see the remote-site is NOT doing IKE with NAT-T. What I would do to validate this is what I stated earlier. diag sniffer packet wan1 " udp and port 4500" Do this on both units and reset the VPN. If NAT is working you should see something on both sides with dport =4500
    journeyman
    journeymanAuthor
    New Member
    April 11, 2014
    Thanks emnoc. Fixed. All incoming traffic to the remote is blocked by the nat device. This was deliberate to not leave ports open (" elegance" :)). The basis was that the remote would initiate and so far it has worked every time (6 spokes up since the tunnels were created). But for some reason the hub is now initiating the UDP4500 traffic and this is obviously doomed. The solution is to add a port forward for UDP4500 to the nat device and the tunnel comes up straight away. Other than adding the port forward, I don' t believe it is possible to make the hub purely a responder (ipsec interface mode, main mode)? I didn' t need to reset the vpns but I believe that I would have used these commands, is this correct (from another reply by you)? diag vpn ike gateway clear name <phase 1 name here> diag vpn tunnel reset " namehere" PS. the PSK was fine, but to be sure I entered it in clear text on the CLI and then did a text compare before and after on the encoded value. Both ends matched before and after. Thanks again.
    Terms & ConditionsAccessibility statement