| Description | This article describes what messages to look for when reviewing logs for FortiGate VPN integration with FortiNAC |
| Scope | FortiNAC-F 7.2, 7.4 & FortiNAC 9.2, 9.4 |
| Solution | Debug enabled: FortinetVPN, RemoteAccess, SyslogServer, SSOManager & PersistentAgent Order of Operations (Summary): Refer to this KB article Technical Tip: Troubleshooting FortiGate VPN integrations
yams.SyslogServer FINER :: 2023-12-15 03:24:25:669 :: #566 :: SyslogServer received: 172.22.1.234 <190>date=2023-12-15,time=03:24:25,devname="LABlabLab",devid="FG4H0ETB1234567",eventtime=1702628665438306385,tz="-0500",logid="0101039947",type="event",subtype="vpn",level="information",vd="root",logdesc="SSL VPN tunnel up",action="tunnel-up",tunneltype="ssl-tunnel",tunnelid=2094876979,remip=89.128.41.7,tunnelip=10.1.250.2,user="ShaiHulude",group="FortiClient MFA",dst_host="N/A",reason="DTLS tunnel established",msg="SSL tunnel established"
yams.FortinetVPN INFO :: 2023-12-15 03:24:25:682 :: #795 :: FortinetVPNPlugin.processLogon Remote user ShaiHulude just received an IP = 10.1.250.2 yams.FortinetVPN FINER :: 2023-12-15 03:24:25:694 :: #795 :: FortinetVPNPlugin.isValidIP found 10.1.250.2 for device 6464 , raDevice = 6419 yams.FortinetVPN FINER :: 2023-12-15 03:24:25:694 :: #795 :: FortinetVPNPlugin.isValidIP checking parent of 6464 yams.FortinetVPN FINER :: 2023-12-15 03:24:25:694 :: #795 :: AbstractRasPlugin.updateConnectionPerformance IPASSIGN found no entry for user ShaiHulude yams.FortinetVPN FINER :: 2023-12-15 03:24:25:694 :: #795 :: AbstractRasPlugin.updateConnectionPerformance IPASSIGN updating entry for key ShaiHulude to ShaiHulude10.1.250.2
yams.FortinetVPN FINER :: 2023-12-15 03:24:25:695 :: #795 :: FortinetVPNPlugin built ProbeObject
Probe IP Address = 10.1.250.2 MAC Address = null Device Id = 6419 Interface Id = 6482 User Name = ShaiHulude Session Id = 1672942581 Time Captured = Fri Dec 15 03:24:25 EST 2023 InetAddress = null
yams.RemoteAccess FINER :: 2023-12-15 03:24:33:705 :: #3525 :: RemoteAccessServer.updateRemoteUser() IP = 10.1.250.2 with MAC 1C:C1:0C:C2:1B:8B yams.RemoteAccess FINER :: 2023-12-15 03:24:33:705 :: #3525 :: RemoteAccessServer.updateRemoteEntry for 10.1.250.2 and 1C:C1:0C:C2:1B:8B yams.RemoteAccess FINER :: 2023-12-15 03:24:33:705 :: #3525 :: RemoteAccessServer.updateRemoteUserInt for device 6419 and client 10.1.250.2 yams.RemoteAccess FINER :: 2023-12-15 03:24:33:705 :: #3525 :: RemoteAccessServer.updateRemoteUserInt setting mac 1C:C1:0C:C2:1B:8B for 10.1.250.2 yams.RemoteAccess FINER :: 2023-12-15 03:24:33:705 :: #3525 :: RemoteAccessServer.updateRemoteUserInt with user ShaiHulude, and mac 1C:C1:0C:C2:1B:8B yams.RemoteAccess FINER :: 2023-12-15 03:24:33:705 :: #3525 :: RemoteAccessServer.connectUserToVPNDevice(): setting vpnClient for 10.1.250.2 yams.RemoteAccess FINER :: 2023-12-15 03:24:33:705 :: #3525 :: RemoteAccessServer found local client 32508 for mac 1C:C1:0C:C2:1B:8B yams.RemoteAccess FINER :: 2023-12-15 03:24:33:705 :: #3525 :: RemoteAccessServer.connectUserToVPNDevice calling getRemoteUser for 10.1.250.2 yams.RemoteAccess INFO :: 2023-12-15 03:24:33:705 :: #3525 :: RemoteAccessServer.getRemoteUser() IP = 10.1.250.2 yams.RemoteAccess INFO :: 2023-12-15 03:24:33:705 :: #3525 :: Probe IP Address = 10.1.250.2 MAC Address = 1C:C1:0C:C2:1B:8B Device Id = 6419 Interface Id = 6482 User Name = ShaiHulude Session Id = 1672942581 Time Captured = Fri Dec 15 03:24:25 EST 2023 InetAddress = null
element = LABLAN-LabLabh.lab port = LABLAN-LabLabh.lab:VPN root_SSL_VPN Client MAC = 1C:C1:0C:C2:1B:8B Client IP = 10.1.250.2
yams.FortinetVPN INFO :: 2023-12-15 03:24:34:738 :: #345 :: Removing restrictions on client, IP = 10.1.250.2 connecting via deviceId = 6419 yams.FortinetVPN FINER :: 2023-12-15 03:24:34:738 :: #345 :: FortinetVPNPlugin.removeRestriction for client 1C:C1:0C:C2:1B:8B 10.1.250.2 yams.FortinetVPN FINER :: 2023-12-15 03:24:34:738 :: #345 :: FortinetVPNPlugin.checkPolicy for client 1C:C1:0C:C2:1B:8B 10.1.250.2
yams.SSOManager FINER :: 2023-12-15 03:24:34:742 :: #345 :: 1C:C1:0C:C2:1B:8B 10.1.250.2 new UserIDMessage ShaiHulude yams.SSOManager FINER :: 2023-12-15 03:24:34:742 :: #345 :: setGroupTags() mac = 1C:C1:0C:C2:1B:8B yams.SSOManager FINER :: 2023-12-15 03:24:34:745 :: #345 :: SSOManager.setGroupTags using elementId 6464 yams.SSOManager FINER :: 2023-12-15 03:24:34:745 :: #345 :: SSOManager.setGroupTags found 1 config models yams.SSOManager FINER :: 2023-12-15 03:24:34:745 :: #345 :: SSOManager.setGroupTags looking up AccessConfig for target device 6464 yams.SSOManager FINER :: 2023-12-15 03:24:34:746 :: #345 :: SSOManager.setGroupTags found AccessConfiguration AccessConfiguration DBID:[10] Version:[9] Name:[ ] Note:[null] Task ID:[null] Logical Network:[VPN-Network] Access Value:[] Access Action:[2] Alias:[false] Send Groups To Firewall:[true] RadiusAttributeGroupId:[null] Tags: [VPN_Auth] Firewall Groups: []
yams.SSOManager FINER :: 2023-12-15 03:24:34:746 :: #345 :: Host matched access configuration VPN-Network yams.SSOManager FINER :: 2023-12-15 03:24:34:754 :: #345 :: getGroups() found a total of 2 member groups yams.SSOManager FINER :: 2023-12-15 03:24:34:754 :: #345 :: SSOManager.setGroupTags found tags [Registered Hosts, VPN Access, VPN_Auth] yams.SSOManager FINER :: 2023-12-15 03:24:34:754 :: #345 :: putMessage() added message for host SHAIHULUDE-LAP B4:45:06:17:AA:49,1C:C1:0C:C2:1B:8B 25946 to messageQueue on agent 172.22.1.234 UserIDMessage[logon, mac=1C:C1:0C:C2:1B:8B, ip=10.1.250.2, user=ShaiHulude, tags=[Registered Hosts, VPN Access, VPN_Auth]] yams.SSOManager FINER :: 2023-12-15 03:24:34:754 :: #808 :: UserAgentSendThread run() agent: 172.22.1.234 message: UserIDMessage[logon, mac=1C:C1:0C:C2:1B:8B, ip=10.1.250.2, user=ShaiHulude, tags=[Registered Hosts, VPN Access, VPN_Auth]] yams.SSOManager FINER :: 2023-12-15 03:24:34:754 :: #345 :: SSOManager.addMessageToQueue put message UserIDMessage[logon, mac=1C:C1:0C:C2:1B:8B, ip=10.1.250.2, user=ShaiHulude, tags=[Registered Hosts, VPN Access, VPN_Auth]] for key 1C:C1:0C:C2:1B:8B yams.SSOManager FINER :: 2023-12-15 03:24:34:754 :: #345 :: testAdapterImpl() added message to queue, size = 9 for agent 172.22.1.234 UserIDMessage[logon, mac=1C:C1:0C:C2:1B:8B, ip=10.1.250.2, user=ShaiHulude, tags=[Registered Hosts, VPN Access, VPN_Auth]] yams.SSOManager FINER :: 2023-12-15 03:24:34:754 :: #345 :: SSOManager.testAdapterImpl done yams.SSOManager INFO :: 2023-12-15 03:24:34:755 :: #808 :: SSOManager.sendMessage sending message to 172.22.1.234 for client 1C:C1:0C:C2:1B:8B, MSG=UserIDMessage[logon, mac=1C:C1:0C:C2:1B:8B, ip=10.1.250.2, user=ShaiHulude, tags=[Registered Hosts, VPN Access, VPN_Auth]]
yams.SyslogServer FINER :: 2023-12-15 05:44:59:589 :: #566 :: SyslogServer received: 172.22.1.234 <190>date=2023-12-15,time=05:44:59,devname=devname="LABlabLab",devid="FG4H0ETB201234567",eventtime=1702626299533138797,tz="-0500",logid="0101039948",type="event",subtype="vpn",level="information",vd="root",logdesc="SSL VPN tunnel down",action="tunnel-down",tunneltype="ssl-tunnel",tunnelid=2094876976,remip=89.128.41.7,tunnelip=10.1.250.2,user="ShaiHulude",group="FortiClient MFA",dst_host="N/A",reason="User requested termination of service",duration=1415,sentbyte=5090436,rcvdbyte=1959359,msg="SSL tunnel shutdown"
yams.SSOManager INFO :: 2023-12-15 05:44:59:635 :: #808 :: SSOManager.sendMessage sending message to 172.22.1.234 for client 1C:C1:0C:C2:1B:8B, MSG=UserIDMessage[logoff, mac=1C:C1:0C:C2:1B:8B, ip=10.1.250.2, user=ShaiHulude, tags=[Registered Hosts, VPN Access, VPN_Auth]]
Related articles: |
