FortiGate
FortiGate Next Generation Firewall utilizes purpose-built security processors and threat intelligence security services from FortiGuard labs to deliver top-rated protection and high performance, including encrypted traffic.
kjohri
Staff
Staff
Article Id 274643
Description

 

This article explains the ikev2 debug output in FortiGate.

 

Scope

 

FortiGate, IPsec.

 

Solution

 

While troubleshooting the tunnel down issue, apply the below commands to take the debugs on both FortiGate:

 

di vpn ike log-filter clear

di vpn ike log-filter <att name> <att value> 

diag debug app ike -1
diag debug enable

Unlike ikev1 there is no phase 1 or phase 2; ikev2 has only two initial phases of negotiation:

SA_INIT Exchange
IKE_AUTH Exchange

 

SA_INIT is the same as ikev1 main mode first four packets. IKE_AUTH constitutes the authentication, identity, and quick mode packets in ikev1.


Here is a configuration for reference:


config vpn ipsec phase1-interface
    edit "Test"
         set interface "port2"
         set ike-version 2
         set peertype any
         set net-device disable
         set proposal aes256-sha256
         set comments "VPN: Test (Created by VPN wizard)"
         set dhgrp 5
         set remote-gw 10.5.50.239
         set psksecret ENC 3cw+QeCl2/gJ+vgGIPnuib/Do15qSONAfS31hUMy23SiYRfuhXyarpYwVf6tMi6SfHRLJZgiu7wns3LeuK9ukJJeB9NxPdbP7UjHN+XSvibx1gpNUG9d7kmfRI7Uw9mia6anQC0LHiXDOYCF+J1iqQNBLN/S9Lm3wApanrHdBt43mtUYfjlgtWQ59w4QzERFy92nVw==
    next
end

config vpn ipsec phase2-interface
    edit "Test"
        set phase1name "Test"
        set proposal aes256-sha256
        set pfs disable
        set comments "VPN: Test (Created by VPN wizard)"
        set src-addr-type name
        set dst-addr-type name
        set keylifeseconds 3600
        set src-name "Test_local"
        set dst-name "Test_remote"
    next
end

10.5.59.170 Initiator
10.5.50.239 Responder


Debugs from the initiator:

 

ike config update start <----- Config change, this might not be seen in general cases but as soon as the tunnel is created/updated it should be the first log that should appear in IKE debug.
ike ike_embryonic_conn_limit = 10000
ike ikecrypt DH multi-process disabled
ike 0: sync=no FGCP:disabled role:master, FGSP:disabled id:0 slave-add-routes:disabled
ike 0:Test: update
ike 0:Test: deleting
ike 0:Test: deleted
ike 0:Test: schedule auto-negotiate
ike 0:port2: add interface
ike 0:Test: local-addr 10.5.59.170
ike 0:Test: oif 4, vrf 0
ike 0:Test: schedule auto-negotiate
ike config update done
ike 0: cache rebuild start
ike 0:Test: local:10.5.59.170, remote:10.5.50.239
ike 0:Test: cached as static-ddns.
ike 0: cache rebuild done
ike 0:Test: auto-negotiate connection
ike 0:Test: created connection: 0x11fa2a50 4 10.5.59.170->10.5.50.239:500.
ike 0:Test:Test: chosen to populate IKE_SA traffic-selectors
ike 0:Test:Test: initialize health-check selector
ike 0:Test: no suitable IKE_SA, queuing CHILD_SA request and initiating IKE_SA negotiation
ike 0:Test:216: create NAT-D hash local 10.5.59.170/500 remote 10.5.50.239/500
ike 0:Test:26: out FC1028E1FAA803970000000000000000212022080000000000000178220000300000002C010100040300000C0100000C800E01000300000802000005030000080300000C0000000804000005280000C800050000D2D7DE9BB94471BA39B80ACBEE6A759492CC60B29AF8C6E73D3D143B2843D38EC474B4512662CD5B39EBE5B3B33323DFC60340CCCD91F5678747CF78E522BBE6E3FC6C737EE8910BE3C5E2B2E26A99DA5E8553E771E71E91455EA2877D36257EACDAC26778B5B05BCCCA73FD62FD454425F6B9E594F8016C4F9AE739FCA923C368261FF2FD63A9C098816A2942B2B5BB732DD82418EA9186AC16788CFA43C0184285B69A6EDF986655BA3ED428C3E3B0966154141DF9ED656BFFCA0DE5F30D3929000024ECF842F87E313A28472C009857B53F039632D19118039CA6C89F31B647D3A9342900001C000040042DD8D76139FA18BC28EFB6A245A68BC7BA4D7E1E2900001C00004005313FE8353E54F17715CFDC9D5981F8619E94EB2F000000080000402E
ike 0:Test:26: sent IKE msg (SA_INIT): 10.5.59.170:500->10.5.50.239:500, len=376, vrf=0, id=fc1028e1faa80397/0000000000000000 - <----- Initiator prepares and sends the SA INIT request.

ike 0: comes 10.5.50.239:500->10.5.59.170:500,ifindex=4,vrf=0.... <-----Peer sends the response to the INIT request on UDP port 500.

ike 0: IKEv2 exchange=SA_INIT_RESPONSE id=a2b905601b67a7ba/6773907a7b14fcc0 len=360
ike 0: in A2B905601B67A7BA6773907A7B14FCC0212022200000000000000168220000300000002C010100040300000C0100000C800E0100
0300000802000005030000080300000C0000000804000005280000C800050000FC9B4EA922B7B881085EBC2B4212EB72C1E02740E9DD705751
47D7D36C6B7F7248751BBF92210CA80D6523143C85C8574203B85DF17E5DC6AC9BFCC17424F4DABF377666B4C661408893651DE3CC02788AE8
38D9F42677BF4573BF5B426E609D0FF5C95BB881E5DE3CE2B27D9F9D3B8B9428281D1A386D8D4DDBB6AFACDD83C9923EAD483CD90B3E4AAC0B
530B97565C55C2BB6C5FE5302CCFC2AACE647E9FF4EB26E16DADC0D39C047BAD99D1608BE2DB7ED17A14992FC165935C1CD945BCBE29000014
C56FB761393070F51B52B274737B417D2900001C00004004957B660047DF978FC7C872B72AB03F43EBCA05C02900001C00004005D684768674
66C7C7A92E381EE5181AE25CC7AF90000000080000402E
ike 0:Test:210: initiator received SA_INIT response
ike 0:Test:210: processing notify type NAT_DETECTION_SOURCE_IP <- Initiator checks if it is behind a natting device or not by calculating the hash of its source IP, and source port and matching it with the hash received from the peer side for the destination IP and destination port. If the hash matches the source is not behind the natting device, if it differs source is behind a natting device.
ike 0:Test:210: processing NAT-D payload
ike 0:Test:210: NAT not detected <- Source is not behind the NAT device (If NAT-T is detected the later communication will happen at 4500 port).
ike 0:Test:210: process NAT-D
ike 0:Test:210: processing notify type NAT_DETECTION_DESTINATION_IP <- Initiator checks whether the destination is behind the natting device by performing a hash on destination IP and destination port and checks if it is the same which is sent by the peer.
ike 0:Test:210: processing NAT-D payload
ike 0:Test:210: NAT not detected <- Peer is not behind the natting device.
ike 0:Test:210: process NAT-D
ike 0:Test:210: processing notify type FRAGMENTATION_SUPPORTED
ike 0:Test:210: incoming proposal: <- Proposals received by the peer.
ike 0:Test:210: proposal id = 1:
ike 0:Test:210: protocol = IKEv2:
ike 0:Test:210: encapsulation = IKEv2/none
ike 0:Test:210: type=ENCR, val=AES_CBC (key_len = 256)
ike 0:Test:210: type=INTEGR, val=AUTH_HMAC_SHA2_256_128
ike 0:Test:210: type=PRF, val=PRF_HMAC_SHA2_256
ike 0:Test:210: type=DH_GROUP, val=MODP1536.
ike 0:Test:210: matched proposal id 1<- Proposal matched by the source.
ike 0:Test:210: proposal id = 1:
ike 0:Test:210: protocol = IKEv2:
ike 0:Test:210: encapsulation = IKEv2/none
ike 0:Test:210: type=ENCR, val=AES_CBC (key_len = 256)
ike 0:Test:210: type=INTEGR, val=AUTH_HMAC_SHA2_256_128
ike 0:Test:210: type=PRF, val=PRF_HMAC_SHA2_256
ike 0:Test:210: type=DH_GROUP, val=MODP1536.
ike 0:Test:210: lifetime=86400
ike 0:Test:210: IKE SA a2b905601b67a7ba/6773907a7b14fcc0 SK_ei 32:82975A9562A51C8B4503D4F9B244463147A020D103C9745D
E69EA2C65F63BB7F
ike 0:Test:210: IKE SA a2b905601b67a7ba/6773907a7b14fcc0 SK_er 32:3E3229427B5255ADF3A3F44DAF9CC01446BB6D8B6CA7D39B
067BFBC1C30D1841
ike 0:Test:210: IKE SA a2b905601b67a7ba/6773907a7b14fcc0 SK_ai 32:A0C66F6977869D9B5269DB3EAA24FA56103AB106CE7CB308
AF0E486C301453C2
ike 0:Test:210: IKE SA a2b905601b67a7ba/6773907a7b14fcc0 SK_ar 32:F0A8AA8FAA974DA0A60DDEB9D508083C6CD3ED2EA5B7C95F
5DA789FF4C97A001
+++++++++++++++++++++++++++++++++++++++ SA INIT completes here +++++++++++++++++++++++++++++++++++++++++++++++++
ike 0:Test:210: initiator preparing AUTH msg <- Initiator now prepares the IKE_AUTH packet.
ike 0:Test:210: sending INITIAL-CONTACT
ike 0:Test:210: enc 2900000C010000000A053BAA27000008000040002900002802000000AABDEE9FB7B88AFCE0A36E0DBCC971CBE8C54F
42B185CB6932A87EADAA01F86721000008000040242C00002C0000002801030403E759B6F10300000C0100000C800E0100030000080300000C
00000008050000002D00001801000000070000100000FFFF0A4500000A450FFF0000001801000000070000100000FFFFAC1F8000AC1F8FFF0F
0E0D0C0B0A0908070605040302010F
ike 0:Test:210: out A2B905601B67A7BA6773907A7B14FCC02E20230800000001000000F0230000D4CB97251D5B54686F248EC81AFD12C7
0373FCA7B72827B7FEF0F3E501D8122ABCFFA69DC69E88CAA53772D13691361CA59FF21D38A82023EE2BEFEDED8FF7D00FBB7BEAA84E058F78
B079C8CAD3ED89D8DEE21FB31A282202E11DD85ABDAFF49D954C23C994435C823CAC87CD9E67F3800679E0B1DF490433EE530EFEAF4F7A2F03
FB67294AFAB0F1CC3A092F9D2BD73D30546E2D36EB8082FC38284255D96F4E8F7DB14C1261E0FB030F444ADCD286F1921B58EB8606B241FBA9
DCA3B4C73B16E4DFCC54EB6ED28822E278DE20F4C0C4
ike 0:Test:210: sent IKE msg (AUTH): 10.5.59.170:500->10.5.50.239:500, len=240, vrf=0, id=a2b905601b67a7ba/6773907
a7b14fcc0:00000001 <- -Initiator sends the AUTH packet encrypted (port is 500. If NAT-T was detected it would have switched to 4500).
ike 0: comes 10.5.50.239:500->10.5.59.170:500,ifindex=4,vrf=0.... <- Peer responds to the AUTH request.
ike 0: IKEv2 exchange=AUTH_RESPONSE id=a2b905601b67a7ba/6773907a7b14fcc0:00000001 len=224
ike 0: in A2B905601B67A7BA6773907A7B14FCC02E20232000000001000000E0240000C497D656A12C00D45B31CA5B073EE44AD6713B9D91
DCB7FF742968649C38F8E5129CC899EC2817E7F7E7915F2E13FFF6B2ACEB6F6000AC9B20B6889F5E69042964F1D92F4341EED08DA49F8B65FB
1EE96DD8CCF108C1D2299D80B3D1BD275F1BE8793C8D85B28CFD23D4EE8508863C2CDBBD49E1C35116039C66190B3F7960EECA92E748B5FD8D
D97F2A5EBF5EFEAAF4D63941AEA79A5DA59448DE014B0242D9E61C8352B242A1AB1C3389C3538365096BAF71F4B63ABE66D036F7654ABFCDD6
F6
ike 0:Test:210: dec A2B905601B67A7BA6773907A7B14FCC02E20232000000001000000B8240000042700000C010000000A0532EF290000
28020000009ACD86E06D69DD26AF3493B9A0D7AE8D761CD6F9F2E6181D7EB98B92EAB2BC2121000008000040242C00002C0000002801030403
94FC73050300000C0100000C800E0100030000080300000C00000008050000002D00001801000000070000100000FFFF0A4500000A450FFF00
00001801000000070000100000FFFFAC1F8000AC1F8FFF
ike 0:Test:210: initiator received AUTH msg
ike 0:Test:210: peer identifier IPV4_ADDR 10.5.50.239 <- Identity send by the peer side. The peer identifier is used to distinguish one peer from another in a network. Options available on FortiGate are auto, fqdn, user-fqdn, keyid, address.
ike 0:Test:210: auth verify done
ike 0:Test:210: initiator AUTH continuation
ike 0:Test:210: authentication succeeded <- Authentication is successful.
ike 0:Test:210: processing notify type MESSAGE_ID_SYNC_SUPPORTED
ike 0:Test:210: established IKE SA a2b905601b67a7ba/6773907a7b14fcc0
ike 0:Test:210: check peer route: if_addr4_rcvd=0, if_addr6_rcvd=0, mode_cfg=0
ike 0:Test: set oper up
ike 0:Test: schedule auto-negotiate
ike 0:Test:210:59: peer proposal: <- SA Proposals sent by peer include traffic selectors, encryption, authentication, pfs, encapsulation.
ike 0:Test:210:59: TSr_0 0:172.31.128.0-172.31.143.255:0
ike 0:Test:210:59: TSi_0 0:10.69.0.0-10.69.15.255:0
ike 0:Test:210:Test:59: comparing selectors
ike 0:Test:210:Test:59: matched by rfc-rule-2
ike 0:Test:210:Test:59: phase2 matched by subset
ike 0:Test:210:Test:59: accepted proposal:
ike 0:Test:210:Test:59: TSr_0 0:172.31.128.0-172.31.143.255:0
ike 0:Test:210:Test:59: TSi_0 0:10.69.0.0-10.69.15.255:0
ike 0:Test:210:Test:59: autokey
ike 0:Test:210:Test:59: incoming child SA proposal:
ike 0:Test:210:Test:59: proposal id = 1:
ike 0:Test:210:Test:59: protocol = ESP:
ike 0:Test:210:Test:59: encapsulation = TUNNEL
ike 0:Test:210:Test:59: type=ENCR, val=AES_CBC (key_len = 256)
ike 0:Test:210:Test:59: type=INTEGR, val=SHA256
ike 0:Test:210:Test:59: type=ESN, val=NO
ike 0:Test:210:Test:59: PFS is disabled
ike 0:Test:210:Test:59: matched proposal id 1 <- -Initiator found a matching SA proposal.
ike 0:Test:210:Test:59: proposal id = 1:
ike 0:Test:210:Test:59: protocol = ESP:
ike 0:Test:210:Test:59: encapsulation = TUNNEL
ike 0:Test:210:Test:59: type=ENCR, val=AES_CBC (key_len = 256)
ike 0:Test:210:Test:59: type=INTEGR, val=SHA256
ike 0:Test:210:Test:59: type=ESN, val=NO
ike 0:Test:210:Test:59: PFS is disabled
ike 0:Test:210:Test:59: lifetime=3600
ike 0:Test:210:Test:59: replay protection enabled
ike 0:Test:210:Test:59: set sa life soft seconds=3298.
ike 0:Test:210:Test:59: set sa life hard seconds=3600.
ike 0:Test:210:Test:59: IPsec SA selectors #src=1 #dst=1
ike 0:Test:210:Test:59: src 0 7 0:10.69.0.0-10.69.15.255:0
ike 0:Test:210:Test:59: dst 0 7 0:172.31.128.0-172.31.143.255:0
ike 0:Test:210:Test:59: add IPsec SA: SPIs=e759b6f1/94fc7305 <- IPsec SA is now established.
ike 0:Test:210:Test:59: IPsec SA dec spi e759b6f1 key 32:706F986851E677739BFFFCEB1D23D21C428FCC5E706413C8324511D3D
55680F9 auth 32:DF5C6B4F1ED65FBB61B26EF68EA63C333BF1222AF9BB01228013F8C989AAE9E8
ike 0:Test:210:Test:59: IPsec SA enc spi 94fc7305 key 32:898B0BA65042072857575494F9F594137740D41F5F921003B85430432
F082A48 auth 32:1113EA2E7A7F7DD3FAD22EDA5AC4275B973318444316816BAFD9B80C4837BBD2
ike 0:Test:210:Test:59: added IPsec SA: SPIs=e759b6f1/94fc7305
ike 0:Test:210:Test:59: sending SNMP tunnel UP trap <- ikev2 tunnel is up.

 

Related articles:

Technical Tip: Understanding IPsec (iked) debug logs
Technical Tip: How to use local-ID type IP address other than the IP addresses configured in the int...
Troubleshooting Tip: IPsec VPNs tunnels