Skip to main content
bvagadia
Staff
Staff
November 24, 2021

Troubleshooting Tip: ADVPN debugging

  • November 24, 2021
  • 0 replies
  • 13882 views
Description This article describes how to capture debug outputs in ADVPN when the shortcuts between Spokes are not established, despite the tunnel being up.
Scope FortiOS.
Solution

If the connectivity between Hub and Spoke is as expected, capture IKE debug logs to further analyze the details for the ADVPN shortcut.

 

diag.jpg

 

HUB:

 

Hub.jpg

 

2024-11-29 09:06:17.664997 ike V=root:0: shortcut Hub_1:10.9.11.9510.9.11.95:0 to Hub_2:10.9.10.111:0 for 192.168.123.22->192.168.133.1 0 2024-11-29 09:06:17.665767 ike 0 ike_ui_admin_caps_trigger sport 2048, dport 0, proto 1, iif 25 2024-11-29 09:06:17.666301 ike V=root:0 send shortcut-offer to Hub_1 2024-11-29 09:06:17.666736 ike 0:Hub_1:58: enc 917CA6352F2BFADA4C2C93144219611A0810050136541FDA000000F40B000024C926F6B6478F1CC2560D13AA99CA3794A3AD3E9FABD6197C68FF628F BC41CBD3000000B40000000001007DFBEFBEADDE000000000100000000010004C0A87B1600030004C0A88501000700408E9D36EF852F9ACD64DEE18EF717E9737C79178487D51C2140CF9C29ADFD6DD3A12552F 29F97EEDCC247E03EC2921BC97487BAC7AA08C81C7355FA32BE5C29AD000B000101000000000C0001000100000010000100000000000D00040A090A6F000F000200006D69001600020800206300170002000000 0000180001010000000019000419000000 2024-11-29 09:06:17.669441 ike 0:Hub_1:58: out 917CA6352F2BFADA4C2C93144219611A0810050136541FDA000000FC88973EA636F84C030A4729204A87A1CC42163A9507975A6E42A6FBFFFD508C79 48338B9A0573B4894884FDCBFCB1E61B4A1B3CF2D899C49FECC939D70E31246CD5DA17B19F478301D0EE73DF01E4D0C40521C6C2016934136865DD6FF0A055A9AF8C231C6144E6ED32AE725C1645E146C1C3B5E FB81AEA8727E569AC099A4BEB4473061623F0869B54BA96AC2D9B73AD2795131CD84419D521A109048A44815C8D28D1D811BD708A4E4836B2BDC71565AE87750E5024BAE274660D881A75E3E7F3BA546DF7651D FB81AEA8727E569AC099A4BEB4473061623F0869B54BA96AC2D9B73AD2795131CD84419D521A109048A44815C8D28D1D811BD708A4E4836B2BDC71565AE87750E5024BAE274660D881A75E3E7F3BA546DF7651D 04DBE72B29C53C8A8868346D942A3F06BA71BB5206DD9C9DEB 2024-11-29 09:06:17.672196 ike V=root:0:Hub_1:58: sent IKE msg (SHORTCUT-OFFER): 10.9.11.33:500->10.9.11.95:500, len=252, vrf=0, id=917ca6352f2bfada/4c2c93144219611a:3 6541fda 2024-11-29 09:06:17.688432 ike V=root:0: comes 10.9.11.95:500->10.9.11.33:500,ifindex=4,vrf=0,len=300.... 2024-11-29 09:06:17.689057 ike V=root:0: IKEv1 exchange=Informational id=917ca6352f2bfada/4c2c93144219611a:b6ff971f len=300 vrf=0 2024-11-29 09:06:17.689763 ike 0: in 917CA6352F2BFADA4C2C93144219611A08100501B6FF971F0000012CF24F4D1AAFA181052A82B477D1988DEFAF39EA062E4C4579357C7EDE48C2FA23DB55E1B1EC 2EDEF0A4814E4C3468397263F111633C97A7CD78DEF098DE07B649F948763195A46B2EB7F9705AB2CBF3F3E8037B946539E30749082B05BE08DAD41B1F7366E818B9CEA8FDBCC0E7B90F8C248036D51DD4D06DB F14B85399D1D47915E8B596593F09331B7F0BF19321CAB684E562E5D5AE6D5A84AACCCC8281E1E212B86F47F4CA50BEAA17EC5FB6A652EB4568549AC923110ED29285B7377C4E92AC429402E40881DB324661DF 618FD4583B7CBB73820292E90F14E088F8198D7B0A570F04A84346E716BDE1377BED6F6E47BEE004C4C9A7EBB03A34FBC1F2C1A6FC0A125D4B438854999633746D435A64 2024-11-29 09:06:17.692896 ike 0:Hub_1:58: dec 917CA6352F2BFADA4C2C93144219611A08100501B6FF971F0000012C0B000024F268065FF88942DA02628005339742AC9B07DA49B0353F516009CA81 94F04D1E000000E81100000001007DFCB7C3AF335A6C8531200000000008001009DA6D185F230DA40000000000000000001B0024000000000000000000000000000000000000000000000000000000000000000 00000000000010004C0A87B1600030004C0A88501000500040A090B5F00160002080000000017000200000000000700408E9D36EF852F9ACD64DEE18EF717E9737C79178487D51C2140CF9C29ADFD6DD3A12552 F29F97EEDCC247E03EC2921BC97487BAC7AA08C81C7355FA32BE5C29AD000B000101000000000C000100000000001000010000000000110001000000000012000100000000AABAD403 2024-11-29 09:06:17.696054 ike V=root:0:Hub_1:58: notify msg received: SHORTCUT-QUERY 2024-11-29 09:06:17.696554 ike V=root:0:Hub_1: recv shortcut-query 3568377414430999479 09da6d185f230da4/0000000000000000 10.9.11.95 192.168.123.22:2048->192.168.133.1: 0 0 psk 64 ppk 0 ttl 32 nat 0 ver 1 mode 0 network-id 0 2024-11-29 09:06:17.698312 ike V=root:0:Hub_1: forward shortcut-reply 3568377414430999479 09da6d185f230da4/bb726c34209edd6d 10.9.10.111 to 192.168.123.22 0 psk 64 ppk 0 ttl 31 ver 1 mode 0 ext-mapping 10.9.10.111:0 2024-11-29 09:06:17.699459 ike 0:Hub_1:58: enc 917CA6352F2BFADA4C2C93144219611A081005015302AC3A000001300B0000240EEA06533F43A78E71ADD502AC2F68A17E1DFB4A2E9A2F48E3608729 61A20618002300F00000000001007DFDB7C3AF335A6C85311F00000000010004C0A8850100030004C0A87B16000500040A090A6F000D00040A090A6F000F0002000000040008001009DA6D185F230DA4BB726C3 4209EDD6D001B0024000000000000000000000000000000000000000000000000000000000000000000000000000700408E9D36EF852F9ACD64DEE18EF717E9737C79178487D51C2140CF9C29ADFD6DD3A12552 F29F97EEDCC247E03EC2921BC97487BAC7AA08C81C7355FA32BE5C29AD000B000101000000000C0001000000000010000100000000001100010000000000130001000000000014000100000000 2024-11-29 09:06:17.702659 ike 0:Hub_1:58: out 917CA6352F2BFADA4C2C93144219611A081005015302AC3A0000013CBFA07556456001DE9E5585DA24EC153A656C69D7178680C3BB4470DCDDA2E82B 886E4881BB22ED0AB92D344BE246AEEF68EE10C117C8172D40260DC7A6D54AC767F721932C481CC9310C3D5EABCF5B32C90D282E7353CDACCF7D5BA7ECB83E1FACFF3E784CDCE64EAC04F21522511FDFF53C40F 41A3E17F1F99B3794AE168F102B3D2D5AAA4160BDC0E135E8552CD14812DE45AB2AFA6D75D2AB7F75063B0D12DD962D207F012EB97B0430CB728EE4368554E59AC7B9DEB678109A0D8032ABDA32003B880A4B79 8B01A6EA4F57AB998A98EDAAEDD03943CD12720880175DF6AD635A56C4B184939F6F5E1966A576EAA63A2D58866C69A3D78E21ED88F70B891F9EADF611623BE6534F7DC5248B4D69D9DBC9B9415F5C601645A0E C59644267E7 2024-11-29 09:06:17.705945 ike V=root:0:Hub_1:58: sent IKE msg (SHORTCUT-REPLY): 10.9.11.33:500->10.9.11.95:500, len=316, vrf=0, id=917ca6352f2bfada/4c2c93144219611a:5 302ac3a 2024-11-29 09:06:27.662888 ike :shrank heap by 159744 bytes​

 

Capture the debug output on the spoke to collect the shortcut negotiation:

 

FGT SDW 1 # diagnose debug reset FGT SDW 1 # diagnose vpn ike log-filter clear FGT SDW 1 # diagnose vpn ike log-filter mdst-addr4 x.x.x.x y.y.y.y FGT SDW 1 # diagnose debug application ike -1 FGT SDW 1 # diagnose debug console timestamp enable FGT SDW 1 # diagnose debug enable


Starting from FortiOS 7.4.1, the log filter commands have been changed (see Troubleshooting Tip: IPsec Tunnel (debugging IKE)).

 

diagnose vpn ike log filter mrem-addr4 x.x.x.x y.y.y.y

 

The above IKE debug command on Spoke-1 is filtered for multiple IP addresses (mrem-addr4):

  • ISP1 IP address of the Hub (x.x.x.x).
  • ISP1 IP address of Spoke-2 (y.y.y.y).

 

It allows capturing the shortcut negotiation between Spoke1↔Hub as well as the shortcut tunnel establishment between Spoke-1<->Spoke-2.

Next, trigger the shortcut by sending traffic from the Spoke-1 source to the Spoke-2 destination.

 

Wait for 15 seconds and then stop the debugging: 

 

diagnose debug reset

 

Verify and view whether packets are being forwarded via the created shortcut:

 

diagnose sniffer packet any "host <destination_ip> and icmp" 4 0 l | grep <tunnel-interface-name>

 

Verify whether the new connected route via the shortcut is installed in the routing table:

 

get router info routing-table all

 

The command below will list the shortcut created and the parent IPsec tunnel.

 

get vpn ipsec tunnel summary