Troubleshooting Tip: NTLM authentication (FSSO fallback)

[tthrilok]

Description

This article explains basic things to check if the NTLM authentication fails.

Scope

FortiGate.

Solution

When the user is accessing any website, if the user is not part of the domain but the intention is to make the user authenticate with the FSSO agent on the AD, it is possible to set up the NTLM as the backup in the policy.

See Technical Tip: How to use NTLM as fallback for FSSO authentication.

Set up the NTLM, but if the authentication is not successful, perform the following basic checks:

1. Check if the user traffic is matching the policy where the FSSO and NTLM are enabled by using the debug flow.
2. The user traffic will match the policy. However, the NTLM authentication triggered will not be visible.

Use the following debug commands:

diagnose debug reset

diagnose debug application authd -1

diagnose debug enable

After running the above commands, initiate the traffic and then stop the debug using the following commands:

diagnose debug disable

diagnose debug reset

The output will be visible as follows:

[authd_http_wait_req:2293]: src 10.131.7.138 flag 00010000
[authd_http_read_http_message:493]: called
[authd_http_is_full_http_message:443]: called
[authd_http_on_method_get:5558]: src 10.131.7.138 flag 00010000
[authd_http_check_local_portal:1837]: src 10.131.7.138 flag 00010000
[authd_http_send_https_redir:4566]: src 10.131.7.138 flag 00010000
[authd_http_prepare_javascript_redir:3875]:http://10.131.4.136:1000/fgtauth?07050b8b9dcdf58e<----- Firewall redirecting the user to an auth page with the Token.

If the redirection shown above is visible, it means the firewall is sending the authentication redirection. However, if the NTLM is still not visible, make sure there is a TCP port 1000/1003 open from the user network to the firewall IP in case there are any firewalls between the user network and the FortiGate firewall.

TCP port 1000 is used for HTTP, and TCP port 1003 for HTTPS (which are standard ports, if these ports are customized, it is necessary to check accordingly).

3. The username and password passed but authentication failed.

Run the following debug processes on the firewall:

diagnose debug reset

diagnose debug application authd 8256

diagnose debug enable

After running the commands above, start sending the traffic. Once the username and password have been provided, stop the debug processes:

diagnose debug disable

diagnose debug reset

 Below is a sample output:

FG80EP-1 # fsae_io_ctx_process_msg[TEST]: received heartbeat 100005
fsae_io_ctx_process_msg[TEST]: received heartbeat 100006
fsae_send_ntlm_msg[TEST]: tag 0x88, seq 1678185000, msg "TlRMTVNTUAABAAAAB4IIogAAAAAAAAAAAAAAAAAAAAAKAGFKAAAADw=="
_process_ntlm_msg[TEST]: tag 0x89, seq 1678185000, msg "TlRMTVNTUAACAAAADgAOADgAAAAFgomi75eXesLF058AAAAAAAAAAKoAqgBGAAAACgA5OAAAAA9FAFgAQQBNAFAATABFAAIADgBFAFgAQGgBUAEEAQwBIAFkATwBOAC0ASwBWAE0AMAA5AAQAFgBlAHgAYQBtAHAAbABlAC4AYwBvAG0AAwAyAHQAYQBjAGgAeQBvAG4ALQBrAHYAbQAwADkALgBlAHgAYQBtAHAAbABlAC4AYwBvAG0ABQAWAGUAeABhAG0AcABsAGUALgBjAG8AbQAHAAgAAqDseN1a2QEAAAAA"
fsae_send_ntlm_msg[TEST]: tag 0x8a, seq 1678185000, msg "TlRMTVNTUAADAAAAGAAYAH4AAABaAVoBlgAAAAAAAABYAAAADgAOAFgAAAAYABgAZgAAAAAAAADwAQAABYKIogoAYUoAAAAP+9zA0geuXhQFt9W6qjpBPXQAaAByAGkAbABvAGsATwBYAFkARwBFAE4ALQBLAFYATQAwADkAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAkPieSiUngNkkx5ZWa6TGNwEBAAAAAAAAAqDseN1a2QFrTDKHrw8+7gAAAAACAA4ARQBYAEEATQBQAEwARQABABoAVABBAEMASABZAE8ATgAtAEsAVgBNADAAOQAEABYAZQB4AGEAbQBwAGwAZQAuAGMAbwBtAAMAMgB0AGEAYwBoAHkAbwBuAC0AawB2AG0AMAA5AC4AZQB4AGEAbQBwAGwAZQAuAGMAbwBtAAUAFgBlAHgAYQBtAHAAbABlAC4AYwBvAG0ABwAIAAKg7HjdWtkBBgAEAAIAAAAIADAAMAAAAAAAAAABAAAAACAAADjMoeB9E8m0E573vzyp10AjrCUN8grfCgAQAAAAAAAAAAAAAAAAAAAAAAAJACwASABUAFQAUAAvADEAMAAuADEAMwAxAC4ANAAuADEAMwA2ADoAMQAwADAAMAAAAAAAAAAAAA=="
_process_ntlm_result[TEST]: tag 0x8b, seq 1678185000, result 1, user THRILOK, domain EXAMPLE, groups "CN=THRILOK,CN=USERS,DC=EXAMPLE,DC=COM+CN=DOMAIN USERS,CN=USERS,DC=EXAMPLE,DC=COM+CN=USERS,CN=BUILTIN,DC=EXAMPLE,DC=COM"

'process_ntlm_result' should be visible, which means the result of the NTLM authentication with the username and group info that we received from the FSSO agent.

In lab case: username is THRILOK, the group info and DN shared by the FSSO agent are:

CN=THRILOK,CN=USERS,DC=EXAMPLE,DC=COM <----- User DN.

CN=DOMAIN USERS,CN=USERS,DC=EXAMPLE,DC=COM <----- Group DN.

CN=USERS,CN=BUILTIN,DC=EXAMPLE,DC=COM <----- Group DN.

If the 'fsae_send_ntlm_msg' message is visible, it means the firewall is not able to send the authentication challenge request to the FSSO agent. In this case:

Verify if 'Support NTLM authentication' is enabled in the FSSO CA agent in the AD server. 

In the debug output, TEST is visible:

_process_ntlm_msg[TEST]

fsae_send_ntlm_msg[TEST]

_process_ntlm_result[TEST]

In all of the debug output lines above, [TEST] is visible, which means the FSSO agent configuration on the firewall. In this example, the FSSO agent is configured on the firewall with the name TEST.

Validating the name of the FSSO agent from the debugs will be useful in cases where there are multiple FSSO agents configured on the firewall, and if the firewall is sending the authentication for the wrong agent. If that is the case, in the policy, it is possible to define the FSSO agent to which the NTLM authentication should be performed, as shown below:

configure firewall policy

    edit 1

        set ntlm enable
        set fsso-agent-for-ntlm "TEST" <----- 'TEST' is in lab FSSO agent name, it is possible to define as per the agent name.

    end

4. If the wrong group info is more visible than expected, go to the FSSO CA agent in the AD server and collect the logs from the agent.

Make sure that the logging level is 'debug' before the logs are taken to ensure it is possible to view detailed info:

03/20/2023 07:49:00 [ 6092] Package Name: NTLM
03/20/2023 07:49:00 [ 6092] AcceptSecurityContext result = 0x00000000
03/20/2023 07:49:00 [ 6092] NTLM auth passed
03/20/2023 07:49:00 [ 6092] user:thrilok
03/20/2023 07:49:00 [ 6092] workstation:OXYGEN-KVM09
03/20/2023 07:49:00 [ 6092] Domain name not specified by user, try current domain:EXAMPLE.
03/20/2023 07:49:00 [ 6092] ldaplib::ldap_search_s, the number of entries: 1
03/20/2023 07:49:00 [ 6092] DN:CN=thrilok,CN=Users,DC=example,DC=com
03/20/2023 07:49:00 [ 6092] found user CN=thrilok,CN=Users,DC=example,DC=com in the directory, checking group membership...
03/20/2023 07:49:00 [ 6092] member:CN=Group Policy Creator Owners,CN=Users,DC=example,DC=com
03/20/2023 07:49:00 [ 6092] member:CN=Domain Admins,CN=Users,DC=example,DC=com
03/20/2023 07:49:00 [ 6092] member:CN=Enterprise Admins,CN=Users,DC=example,DC=com
03/20/2023 07:49:00 [ 6092] member:CN=Schema Admins,CN=Users,DC=example,DC=com
03/20/2023 07:49:00 [ 6092] member:CN=Remote Desktop Users,CN=Builtin,DC=example,DC=com
03/20/2023 07:49:00 [ 6092] member:CN=Administrators,CN=Builtin,DC=example,DC=com
03/20/2023 07:49:00 [ 6092] primarygroupID:S-1-5-21-1137974602-3057445812-1867554962-513
03/20/2023 07:49:00 [ 6092] ldaplib::ldap_search_s, the number of entries: 1
03/20/2023 07:49:00 [ 6092] DN:CN=Domain Users,CN=Users,DC=example,DC=com
03/20/2023 07:49:00 [ 6092] check member for group: CN=Domain Users,CN=Users,DC=example,DC=com
03/20/2023 07:49:00 [ 6092] member:CN=Users,CN=Builtin,DC=example,DC=com
03/20/2023 07:49:00 [ 6092] check member for group: CN=Administrators,CN=Builtin,DC=example,DC=com
03/20/2023 07:49:00 [ 6092] check member for group: CN=Remote Desktop Users,CN=Builtin,DC=example,DC=com
03/20/2023 07:49:00 [ 6092] check member for group: CN=Schema Admins,CN=Users,DC=example,DC=com
03/20/2023 07:49:00 [ 6092] member:CN=Denied RODC Password Replication Group,CN=Users,DC=example,DC=com
03/20/2023 07:49:00 [ 6092] check member for group: CN=Enterprise Admins,CN=Users,DC=example,DC=com
03/20/2023 07:49:00 [ 6092] member:CN=Denied RODC Password Replication Group,CN=Users,DC=example,DC=com
03/20/2023 07:49:00 [ 6092] member:CN=Administrators,CN=Builtin,DC=example,DC=com
03/20/2023 07:49:00 [ 6092] check member for group: CN=Domain Admins,CN=Users,DC=example,DC=com
03/20/2023 07:49:00 [ 6092] member:CN=Denied RODC Password Replication Group,CN=Users,DC=example,DC=com
03/20/2023 07:49:00 [ 6092] member:CN=Administrators,CN=Builtin,DC=example,DC=com
03/20/2023 07:49:00 [ 6092] check member for group: CN=Group Policy Creator Owners,CN=Users,DC=example,DC=com
03/20/2023 07:49:00 [ 6092] member:CN=Denied RODC Password Replication Group,CN=Users,DC=example,DC=com
03/20/2023 07:49:00 [ 6092] check member for group: CN=Users,CN=Builtin,DC=example,DC=com
03/20/2023 07:49:00 [ 6092] check member for group: CN=Denied RODC Password Replication Group,CN=Users,DC=example,DC=com
03/20/2023 07:49:00 [ 6092] lookup group info for EXAMPLE\thrilok from DC=example,DC=com
03/20/2023 07:49:00 [ 6092] LDAP server not set for domain: EXAMPLE:DC=example,DC=com.
03/20/2023 07:49:00 [ 6092] ad_user_get_groups_str2_s():CN=thrilok,CN=Users,DC=example,DC=com+CN=Users,DC=example,DC=com+CN=Domain Users,CN=Users,DC=example,DC=com+CN=Administrators,CN=Builtin,DC=example,DC=com+CN=Remote Desktop Users,CN=Builtin,DC=example,DC=com+CN=Schema Admins,CN=Users,DC=example,DC=com+CN=Enterprise Admins,CN=Users,DC=example,DC=com+CN=Domain Admins,CN=Users,DC=example,DC=com+CN=Group Policy Creator Owners,CN=Users,DC=example,DC=com+CN=Users,CN=Builtin,DC=example,DC=com+CN=Denied RODC Password Replication Group,CN=Users,DC=example,DC=com
03/20/2023 07:49:00 [ 6092] all groups:CN=thrilok,CN=Users,DC=example,DC=com+CN=Users,DC=example,DC=com+CN=Domain Users,CN=Users,DC=example,DC=com+CN=Administrators,CN=Builtin,DC=example,DC=com+CN=Remote Desktop Users,CN=Builtin,DC=example,DC=com+CN=Schema Admins,CN=Users,DC=example,DC=com+CN=Enterprise Admins,CN=Users,DC=example,DC=com+CN=Domain Admins,CN=Users,DC=example,DC=com+CN=Group Policy Creator Owners,CN=Users,DC=example,DC=com+CN=Users,CN=Builtin,DC=example,DC=com+CN=Denied RODC Password Replication Group,CN=Users,DC=example,DC=com
03/20/2023 07:49:00 [ 6092] sent groups:CN=thrilok,CN=Users,DC=example,DC=com+CN=Domain Users,CN=Users,DC=example,DC=com+CN=Users,CN=Builtin,DC=example,DC=com  <<<<<< Agent found the above groups which the user is matching based on LDAP query 
03/20/2023 07:49:00 [ 6092] send NTLM_RESULT_MSG, len:176 count:5 <----- NTLM result message is send to firewall.
03/20/2023 07:49:00 [ 6092] send_to_FGT() called:sock:1688 sendbuf:ba192940 sendlen:176

If groups are not matching properly in the FSSO agent as well, it is necessary to verify the groups which are the user part of at the AD end.