debugging ipsec with nat traversal

journeyman · ‎03-03-2014

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,

emnoc · ‎03-03-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?

PCNSE

NSE

StrongSwan

journeyman · ‎03-04-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 · ‎04-09-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 · ‎04-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

PCNSE

NSE

StrongSwan

journeyman · ‎04-10-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.

debugging ipsec with nat traversal

Nominate a Forum Post for Knowledge Article Creation