Help
FortiNAC-F
FortiNAC-F is a zero-trust network access solution that provides users with enhanced visibility into the Internet of Things (IoT) devices on their enterprise networks. For legacy FortiNAC articles prior to FortiNAC-F 7.2, see FortiNAC.
khoffman
Staff
Staff

Created on ‎05-20-2024 11:55 AM Edited on ‎05-22-2024 09:51 PM By Moderator

Article Id 316105

Troubleshooting Tip: FortiNAC and FortiGate VPN IPSec log example

Description This article describes what messages to look for when reviewing logs for FortiGate VPN IPSec integration with FortiNAC.
Scope FortiNAC-F 7.2, 7.4 & FortiNAC 9.4.
Solution

In this article, the following debug outputs were enabled to generate verbose logging: Fortinet VPN, RemoteAccess, Syslog server, SSOManager & PersistentAgent.
Below is an example of what to look for in FortiNAC output.master logs during a successful IPsec VPN connection. 

Username = Arrakis
VPN IP address = 172.21.252.2
FortiGate IP = 10.20.30.40
Using the Security Fabric (Dynamic Address Tags) 

 

  1. The user establishes a VPN connection and a syslog message is sent to FortiNAC. 

 

yams.FortinetVPN FINER :: 2024-04-12 08:33:24:964 :: #543 :: Sender = 10.20.30.40
Message content = <189>date=2024-04-12,time=08:33:25,devname="HUSAFG-2-Backup",
devid="FG6H1ETB19876543",eventtime=1712946805644839245,tz="-1000",

logid="0101037129",type="event",subtype="vpn",level="notice",
vd="root",logdesc="Progress IPsec phase 2",msg="progress IPsec phase 2",action="negotiate",remip=50.113.16.93,locip=72.235.186.130,remport=4500,
locport=4500,outintf="x2",cookies="d9a0d93dd91b3583/72610844589fe7cf",

user="Testing",group="N/A",useralt="N/A",xauthuser="Arrakis",
xauthgroup="FortiNAC_RADIUS",assignip=172.21.252.2,

vpntunnel="FortiNAC_VPN",status="success",init="remote",
mode="quick",dir="inbound",stage=2,role="responder",result="DONE",advpnsc=0

 

  1. The Syslog message is parsed by FortiNAC and the VPN IP address to check if the VPN IP address is 'managed'.

 

yams INFO :: 2024-04-12 08:33:25:012 :: #543 :: parseStr parsed FG6H1ETB19876543
yams INFO :: 2024-04-12 08:33:25:012 :: #543 :: parseStr parsed 0101037129
yams INFO :: 2024-04-12 08:33:25:012 :: #543 :: parseStr parsed root
yams INFO :: 2024-04-12 08:33:25:012 :: #543 :: parseStr parsed 50.113.16.93
yams INFO :: 2024-04-12 08:33:25:012 :: #543 :: parseStr parsed Arrakis
yams INFO :: 2024-04-12 08:33:25:012 :: #543 :: parseStr parsed 172.21.252.2
yams.FortinetVPN FINER :: 2024-04-12 08:33:25:012 :: #543 :: Parsed IPSec login message into event devId = FG6H1ETB19876543, logId = 0101037129, vdom = root,

tunnelType = IPS, tunnelId = null, localIP = 50.113.16.93, tunnelIP = 172.21.252.2, user = Arrakis
yams.FortinetVPN INFO :: 2024-04-12 08:33:25:012 ::

#543 :: FortinetVPNPlugin.processLogon Remote user Arrakis just received an IP = 172.21.252.2
yams.FortinetVPN FINER :: 2024-04-12 08:33:25:019 ::

#543 :: FortinetVPNPlugin.isValidIP found 172.21.252.2 for device 2260 , raDevice = 2183
yams.FortinetVPN FINER :: 2024-04-12 08:33:25:019 :: #543 :: FortinetVPNPlugin.isValidIP checking parent of 2260

 

  1. A ProbeObject is created to track the active VPN session. 

 

yams.FortinetVPN FINER :: 2024-04-12 08:33:25:019 :: #543 :: FortinetVPNPlugin built ProbeObject
Probe
IP Address = 172.21.252.2
MAC Address = null
Device Id = 2183
Interface Id = 2262
User Name = Arrakis
Session Id = -1811563072
Time Captured = Fri Apr 12 08:33:25 EST 2024
InetAddress = null

  1. The agent communicates, providing IP to MAC resolution. 

yams.RemoteAccess FINER :: 2024-04-12 08:33:30:539 ::

#910 :: RemoteAccessServer.updateRemoteUser() IP = 172.21.252.2 with MAC A8:7E:EA:B2:66:7D
yams.RemoteAccess FINER :: 2024-04-12 08:33:30:539 ::

#910 :: RemoteAccessServer.updateRemoteEntry for 172.21.252.2 and A8:7E:EA:B2:66:7D
yams.RemoteAccess FINER :: 2024-04-12 08:33:30:539 :: #910 :: RemoteAccessServer.updateRemoteUserInt for device 2183 and client 172.21.252.2
yams.RemoteAccess FINER :: 2024-04-12 08:33:30:539 :: #910 :: RemoteAccessServer.updateRemoteUserInt setting mac A8:7E:EA:B2:66:7D for 172.21.252.2
yams.RemoteAccess FINER :: 2024-04-12 08:33:30:540 :: #910 :: RemoteAccessServer.updateRemoteUserInt with user Arrakis, and mac A8:7E:EA:B2:66:7D
yams.RemoteAccess FINER :: 2024-04-12 08:33:30:540 :: #910 :: RemoteAccessServer.connectUserToVPNDevice(): setting vpnClient for 172.21.252.2
yams.RemoteAccess FINER :: 2024-04-12 08:33:30:540 ::
#910 :: RemoteAccessServer found local client 2403 for mac A8:7E:EA:B2:66:7D
yams.RemoteAccess FINER :: 2024-04-12 08:33:30:540 ::
#910 :: RemoteAccessServer.connectUserToVPNDevice(): changing client IP from to 172.21.252.2
yams.RemoteAccess FINER :: 2024-04-12 08:33:30:540 ::
#910 :: updateIPToMAC ip = 172.21.252.2 MAC = A8:7E:EA:B2:66:7D
yams.DynamicClient INFO :: 2024-04-12 08:33:30:542 ::
#910 :: update client: mac = A8:7E:EA:B2:66:7D old ip = new ip = 172.21.252.2
yams.SSOManager FINER :: 2024-04-12 08:33:30:542 ::
#1025 :: SSOManager.logoffAdapter for A8:7E:EA:B2:66:7D
yams.SSOManager FINER :: 2024-04-12 08:33:30:542 ::
#1025 :: SSOManager.hasMessageFor queue size = 1
yams.RemoteAccess FINER :: 2024-04-12 08:33:30:542 ::
#910 :: RemoteAccessServer.connectUserToVPNDevice setting IP address for client A8:7E:EA:B2:66:7D to 172.21.252.2
yams.SSOManager FINER :: 2024-04-12 08:33:30:542 :: #1025 :: SSOManager.validateAdapterIP checking IP for client A8:7E:EA:B2:66:7D
yams.RemoteAccess FINER :: 2024-04-12 08:33:30:542 :: #910 :: RemoteAccessServer.connectUserToVPNDevice calling getRemoteUser for 172.21.252.2
yams.RemoteAccess INFO :: 2024-04-12 08:33:30:542 :: #910 :: RemoteAccessServer.getRemoteUser() IP = 172.21.252.2
yams.RemoteAccess INFO :: 2024-04-12 08:33:30:542 :: #910 :: Probe
IP Address = 172.21.252.2
MAC Address = A8:7E:EA:B2:66:7D
Device Id = 2183
Interface Id = 2262
User Name = Arrakis
Session Id = -1811563072
Time Captured = Fri Apr 12 08:33:25 EST 2024
InetAddress = null

  1. The user is logged on to the host and shown as online and connected to the VPN interface in FortiNAC. 

 

yams.RemoteAccess FINER :: 2024-04-12 08:33:30:542 :: #910 :: RemoteAccessServer.connectUserToVPNDevice logging in remote user Arrakis

yams.RemoteAccess FINER :: 2024-04-12 08:33:30:548 :: #910 :: loginUser User Arrakis successfully logged into A8:7E:EA:B2:66:7D

  1. The host is evaluated for a matching Network Access Policy and a Dynamic address tag is sent to the firewall.


yams.RemoteAccess FINER :: 2024-04-12 08:33:30:548 :: #910 :: RemoteAccessServer.connectUserToVPNDevice calling BridgeManager.switchVlan for A8:7E:EA:B2:66:7D 172.21.252.2
yams.RemoteAccess INFO :: 2024-04-12 08:33:30:549 :: #1207 :: RemoteAccessServer.getRemoteUser() IP = 172.21.252.2
yams.RemoteAccess INFO :: 2024-04-12 08:33:30:549 :: #1207 :: Probe
IP Address = 172.21.252.2
MAC Address = A8:7E:EA:B2:66:7D
Device Id = 2183
Interface Id = 2262
User Name = Arrakis
Session Id = -1811563072
Time Captured = Fri Apr 12 08:33:25 EST 2024
InetAddress = null

yams.SSOManager FINER :: 2024-04-12 08:33:30:890 :: #319 :: SSOManager.addMessageToQueue put message UserIDMessage[logon, mac=A8:7E:EA:B2:66:7D, ip=172.21.252.2, user=Arrakis,

tags=[VPN_AUTH]] for key A8:7E:EA:B2:66:7D, queue size = 2
yams.SSOManager FINER :: 2024-04-12 08:33:30:890 ::
#319 :: testAdapterImpl() added logon message to queue, size = 2 for agent 10.20.30.40
UserIDMessage[logon, mac=A8:7E:EA:B2:66:7D, ip=172.21.252.2, user=Arrakis, tags=[VPN_AUTH]

yams.SSOManager FINER :: 2024-04-12 08:33:36:353 :: #4347599 :: sendDynamicAddressUpdate(10.20.30.40) commands = [Command [command=update, vdom=root, addresses=[Address [uuid=VPN_AUTH, type=ip, tag_properties=null, values=[172.21.252.2, 172.21.252.1]]]]]
yams.SSOManager INFO :: 2024-04-12 08:33:36:354 :: #4347599 :: sendDynamicAddressUpdate(10.20.30.40)

json = {"command_version":2,"commands":[{"command":"update","vdom":"root","addresses":[{"uuid":"VPN_AUTH","type":"ip","values":["172.21.252.2","172.21.252.1"]}]}],"serial":"FNVXCATM23005555","device_type":"fortinac"}

  1. The user disconnects from the VPN connection and a syslog message is sent to FortiNAC. 

    yams.FortinetVPN FINER :: 2024-04-12 09:23:37:830 :: #543 :: FortinetVpnPlugin.VPNSyslogListener.unsolicited()
    yams.FortinetVPN FINER :: 2024-04-12 09:23:37:830 :: #543 :: Sender = 10.20.30.40
    Message content = <189>date=2024-04-12,time=09:23:38,devname="FGT-Primary",devid="FG6H1ET123456789",eventtime=1712945678232698558,
    tz="-1000",logid="0101037134",type="event",subtype="VPN",
    level="notice",vd="root",logdesc="IPsec phase 1 SA deleted",msg="delete IPsec phase 1 SA",action="delete_phase1_sa",remip=98.150.225.1,
    locip=72.235.186.130,remport=4500,locport=4500,outintf="x2",
    cookies="b40e3a9820f1430c/e75bba3c0a223402",user="Testing",group="N/A",useralt="N/A",
    xauthuser="ShaiHulude.",xauthgroup="FortiNAC_RADIUS",
    assignip=172.21.252.2,vpntunnel="FortiNAC_VPN_0",advpnsc=0
    yams.FortinetVPN FINER :: 2024-04-12 09:23:37:852 :: #543 :: FortinetVpnPlugin.VPNSyslogListener checking SSLLogout
    yams.FortinetVPN FINER :: 2024-04-12 09:23:37:852 :: #543 :: FortinetVpnPlugin.parseSyslog parsing msg using regex
    .*<\d+>date=.+devid="(\S+?)".+logid="(\d+?)".+subtype="vpn".+vd="(\S+?)".+action="tunnel-down".+tunneltype="(\S+?)".+tunnelid=(\d+?).+remip=((?:\d{1,3}\.*){4}).+tunnelip=((?:\d{1,3}\.*){4}).+user="(\S+?)".+
    yams.FortinetVPN FINER :: 2024-04-12 09:23:37:859 :: #543 :: FortinetVpnPlugin.VPNSyslogListener checking IPSLogout
    yams.FortinetVPN FINER :: 2024-04-12 09:23:37:859 :: #543 :: FortinetVpnPlugin.parseSyslog parsing msg using regex
    .*<\d+>date=.+devid="(\S+?)".+logid="(\d+?)".+subtype="vpn".+vd="(\S+?)".+action="delete_phase1_sa".+remip=((?:\d{1,3}\.*){4}).+xauthuser="(\S+?)".+assignip=((?:\d{1,3}\.*){4}).+
    yams INFO :: 2024-04-12 09:23:37:859 :: #543 :: parseStr parsed FG6H1ET123456789
    yams INFO :: 2024-04-12 09:23:37:859 :: #543 :: parseStr parsed 0101037134
    yams INFO :: 2024-04-12 09:23:37:859 :: #543 :: parseStr parsed root
    yams INFO :: 2024-04-12 09:23:37:860 :: #543 :: parseStr parsed 98.150.225.1
    yams INFO :: 2024-04-12 09:23:37:860 :: #543 :: parseStr parsed ShaiHulude.
    yams INFO :: 2024-04-12 09:23:37:860 :: #543 :: parseStr parsed 172.21.252.2
    yams.FortinetVPN FINER :: 2024-04-12 09:23:37:860 :: #543 :: Parsed IPSec logout message into event devId = FG6H1ET123456789, logId = 0101037134, vdom = root, tunnelType = IPS, tunnelId = null, localIP = 98.150.225.1, tunnelIP = 172.21.252.2, user = ShaiHulude.
    yams.FortinetVPN FINER :: 2024-04-12 09:23:37:860 :: #543 :: tunnel IP that was freed up = 172.21.252.2

  2. An update is sent to the firewall removing the VPN IP address from the Dynamic Address Tag.

    yams.SSOManager FINER :: 2024-04-12 09:23:44:313 :: #4347599 :: SSOManager.processDynamicAddresses using addrs [172.21.252.2] for tag VPN_AUTH
    yams.SSOManager FINER :: 2024-04-12 09:23:44:313 :: #4347599 :: SSOManager.processDynamicAddresses removing IP 172.21.252.2 for mac A8:7E:EA:B2:66:7D
    yams.SSOManager FINER :: 2024-04-12 09:23:44:313 :: #4347599 :: SSOManager.remMessageFromQueue found no message for key A8:7E:EA:B2:66:7D, queue size = 0
    yams.SSOManager FINER :: 2024-04-12 09:23:44:313 :: #4347599 :: sendDynamicAddressUpdate(10.20.30.40) command = update vdom = root map = {VPN_AUTH=[]}
    yams.SSOManager FINER :: 2024-04-12 09:23:44:313 :: #4347599 :: sendDynamicAddressUpdate(10.20.30.40) commands = [Command [command=update, vdom=root, addresses=[Address [uuid=VPN_AUTH, type=ip, tag_properties=null, values=[]]]]]
    yams.SSOManager INFO :: 2024-04-12 09:23:44:316 :: #4347599 :: sendDynamicAddressUpdate(10.20.30.40) json = {"command_version":2,"commands":[{"command":"update","vdom":"root","addresses":[{"uuid":"VPN_AUTH","type":"ip","values":[]}]}],"serial":"FNVXCATM23000555","device_type":"fortinac"}
    yams.SecurityFabricManager FINER :: 2024-04-12 09:23:44:316 :: #4347599 :: execute() ip = 10.20.30.40
344
0 Kudos
Submit Article Idea
Broad. Integrated. Automated.

The Fortinet Security Fabric brings together the concepts of convergence and consolidation to provide comprehensive cybersecurity protection for all users, devices, and applications and across all network edges.

Social Media
Security Research
Company
News & Articles
Contact Us

Copyright 2024 Fortinet, Inc. All Rights Reserved.