Troubleshooting Tip: Fortigate LDAP

[ckumar_FTNT]

Description
This article describes the LDAP most common problems and presents troubleshooting tips.

Solution
To test the LDAP object and see if it's working properly, the following CLI command can be used :

#FGT# diagnose test authserver ldap <LDAP server_name> <username> <password>

Where:
 <LDAP server_name> is the name of LDAP object on FortiGate (not actual LDAP server name!)

For username/password, use any from the AD. However, it is recommended (at least at the first stage) to test credentials used in the LDAP object itself.
If this credentials will fail then any other will fail as well as the FortiGate will not be able to bind to the LDAP server.

CLI Example:

#FGT# diagnose test authserver ldap LDAP_SERVER user1 password

Advanced troubleshooting:

To get more information regarding the reason of authentication failure, run the following commands from the CLI :

FGT# diagnose debug enable
FGT# diagnose debug application fnbamd 255

To stop this debug type :

FGT# diagnose debug application fnbamd 0

Then run an LDAP authentication test :

FGT# diag test authserver ldap AD_LDAP user1 password

Advanced troubleshooting:

FGT_MASTER (root) # diag test authserver ldap AD_LDAP user1 password
[2274] handle_req-Rcvd auth req 237259201 for user1 in AD_LDAP opt=0000001b prot=0
[398] __compose_group_list_from_req-Group 'AD_LDAP'
[614] fnbamd_pop3_start-user1
[1042] __fnbamd_cfg_get_ldap_list_by_server-Loading LDAP server 'AD_LDAP'
[1662] fnbamd_ldap_init-search filter is: sAMAccountName=user1                                   <----- Username and base DN for LDAP search
[1671] fnbamd_ldap_init-search base is: dc=test,dc=local
[1019] __fnbamd_ldap_dns_cb-Resolved AD_LDAP(idx 0) to 192.168.1.10
[1087] __fnbamd_ldap_dns_cb-Still connecting.
[557] create_auth_session-Total 1 server(s) to try
[969] __ldap_connect-tcps_connect(192.168.1.10) is established.
[843] __ldap_rxtx-state 3(Admin Binding)                                                         <----- Admin bind
[204] __ldap_build_bind_req-Binding to 'Administrator'
[925] fnbamd_ldap_send-sending 32 bytes to 192.168.1.10
[937] fnbamd_ldap_send-Request is sent. ID 1
[843] __ldap_rxtx-state 4(Admin Bind resp)
[968] __fnbamd_ldap_read-Read 8
[1074] fnbamd_ldap_recv-Leftover 2
[968] __fnbamd_ldap_read-Read 14
[1148] fnbamd_ldap_recv-Response len: 16, svr: 192.168.1.10
[829] fnbamd_ldap_parse_response-Got one MESSAGE. ID:1, type:bind
[864] fnbamd_ldap_parse_response-ret=0                                                           <----- Admin bind succesful
[910] __ldap_rxtx-Change state to 'DN search'
[843] __ldap_rxtx-state 11(DN search)
[592] fnbamd_ldap_build_dn_search_req-base:'dc=test,dc=local' filter:sAMAccountName=user1        <----- Starting next step
[925] fnbamd_ldap_send-sending 75 bytes to 192.168.1.10
[937] fnbamd_ldap_send-Request is sent. ID 2
[843] __ldap_rxtx-state 12(DN search resp)
[968] __fnbamd_ldap_read-Read 8
[1074] fnbamd_ldap_recv-Leftover 2
[968] __fnbamd_ldap_read-Read 52
[1148] fnbamd_ldap_recv-Response len: 54, svr: 192.168.1.10
[829] fnbamd_ldap_parse_response-Got one MESSAGE. ID:2, type:search-entry
[864] fnbamd_ldap_parse_response-ret=0
[1180] __fnbamd_ldap_dn_entry-Get DN 'CN=user1,CN=Users,DC=TEST,DC=LOCAL'
[91] ldap_dn_list_add-added CN=user1,CN=Users,DC=TEST,DC=LOCAL

[910] __ldap_rxtx-Change state to 'User Binding'
[843] __ldap_rxtx-state 5(User Binding)
[437] fnbamd_ldap_build_userbind_req-Trying DN 'CN=user1,CN=Users,DC=TEST,DC=LOCAL'
[204] __ldap_build_bind_req-Binding to 'CN=user1,CN=Users,DC=TEST,DC=LOCAL'
[925] fnbamd_ldap_send-sending 91 bytes to 192.168.1.10
[937] fnbamd_ldap_send-Request is sent. ID 3
[843] __ldap_rxtx-state 6(User Bind resp)
[968] __fnbamd_ldap_read-Read 8
[1074] fnbamd_ldap_recv-Leftover 2
[968] __fnbamd_ldap_read-Read 14
[1148] fnbamd_ldap_recv-Response len: 16, svr: 192.168.1.10
[829] fnbamd_ldap_parse_response-Got one MESSAGE. ID:3, type:bind
[864] fnbamd_ldap_parse_response-ret=0
[910] __ldap_rxtx-Change state to 'Attr query'
[843] __ldap_rxtx-state 7(Attr query)
[490] fnbamd_ldap_build_attr_search_req-Adding attr 'memberOf'
[502] fnbamd_ldap_build_attr_search_req-base:'CN=user1,CN=Users,DC=TEST,DC=LOCAL' filter:cn=*
[925] fnbamd_ldap_send-sending 113 bytes to 192.168.1.10
[937] fnbamd_ldap_send-Request is sent. ID 4
[843] __ldap_rxtx-state 8(Attr query resp)
[968] __fnbamd_ldap_read-Read 8
[1074] fnbamd_ldap_recv-Leftover 2
[968] __fnbamd_ldap_read-Read 290
[1148] fnbamd_ldap_recv-Response len: 292, svr: 192.168.1.10
[829] fnbamd_ldap_parse_response-Got one MESSAGE. ID:4, type:search-entry
[864] fnbamd_ldap_parse_response-ret=0
[553] __get_member_of_groups-Get the memberOf groups.
[519] __retrieve_group_values-Get the memberOf groups.
[530] __retrieve_group_values- attr='memberOf', found 3 values
[91] ldap_dn_list_add-added CN=GROUP1,CN=Users,DC=TEST,DC=LOCAL
[539] __retrieve_group_values-val[0]='CN=GROUP1,CN=Users,DC=TEST,DC=LOCAL'
[91] ldap_dn_list_add-added CN=GROUP2,CN=Users,DC=TEST,DC=LOCAL
[539] __retrieve_group_values-val[1]='CN=GROUP2,CN=Users,DC=TEST,DC=LOCAL'
[91] ldap_dn_list_add-added CN=GROUP3,CN=Users,DC=TEST,DC=LOCAL
[539] __retrieve_group_values-val[2]='CN=GROUP3,CN=Users,DC=TEST,DC=LOCAL'
[1148] fnbamd_ldap_recv-Response len: 16, svr: 192.168.1.10
[829] fnbamd_ldap_parse_response-Got one MESSAGE. ID:4, type:search-result
[864] fnbamd_ldap_parse_response-ret=0
[1260] __fnbamd_ldap_attr_next-Entering CHKPRIMARYGRP state
[910] __ldap_rxtx-Change state to 'Primary group query'
[843] __ldap_rxtx-state 13(Primary group query)
[526] fnbamd_ldap_build_primary_grp_search_req-starting primary group check...
...
[925] fnbamd_ldap_send-sending 121 bytes to 192.168.1.10
[937] fnbamd_ldap_send-Request is sent. ID 5
[843] __ldap_rxtx-state 14(Primary group query resp)
[968] __fnbamd_ldap_read-Read 8
[1074] fnbamd_ldap_recv-Leftover 2
[968] __fnbamd_ldap_read-Read 110
[1148] fnbamd_ldap_recv-Response len: 112, svr: 192.168.1.10
[829] fnbamd_ldap_parse_response-Got one MESSAGE. ID:5, type:search-entry
[864] fnbamd_ldap_parse_response-ret=0
[91] ldap_dn_list_add-added CN=Domain Users,CN=Users,DC=TEST,DC=LOCAL
[470] __get_one_group-group: CN=Domain Users,CN=Users,DC=TEST,DC=LOCAL
….

[1386] __fnbamd_ldap_primary_grp_next-Auth accepted
[910] __ldap_rxtx-Change state to 'Done'
[843] __ldap_rxtx-state 23(Done)
[925] fnbamd_ldap_send-sending 7 bytes to 192.168.1.10
[937] fnbamd_ldap_send-Request is sent. ID 6
[753] __ldap_stop-svr 'AD_LDAP'
[53] ldap_dn_list_del_all-Del CN=user1,CN=Users,DC=TEST,DC=LOCAL
[3064] fnbamd_ldap_result-Result for ldap svr 192.168.1.10 is SUCCESS
…..

LDAP Common Problems:

Incorrect Admin Bind

FGT_MASTER (root) # diag test authserver ldap AD_LDAP user1 password
[2274] handle_req-Rcvd auth req 237259384 for user1 in AD_LDAP opt=0000001b prot=0
[398] __compose_group_list_from_req-Group 'AD_LDAP'
[614] fnbamd_pop3_start-user1
[1042] __fnbamd_cfg_get_ldap_list_by_server-Loading LDAP server 'AD_LDAP'
[1662] fnbamd_ldap_init-search filter is: sAMAccountName=user1
[1671] fnbamd_ldap_init-search base is: dc=test,dc=local
[1019] __fnbamd_ldap_dns_cb-Resolved AD_LDAP(idx 0) to 192.168.1.10
[1087] __fnbamd_ldap_dns_cb-Still connecting.
[557] create_auth_session-Total 1 server(s) to try
[969] __ldap_connect-tcps_connect(192.168.1.10) is established.
[843] __ldap_rxtx-state 3(Admin Binding)
[204] __ldap_build_bind_req-Binding to 'Administrator'
[925] fnbamd_ldap_send-sending 27 bytes to 192.168.1.10
[937] fnbamd_ldap_send-Request is sent. ID 1
[843] __ldap_rxtx-state 4(Admin Bind resp)
...
[1148] fnbamd_ldap_recv-Response len: 104, svr: 192.168.1.10
[829] fnbamd_ldap_parse_response-Got one MESSAGE. ID:1, type:bind
[851] fnbamd_ldap_parse_response-Error 49(80090308: LdapErr: DSID-0C09042A, comment: AcceptSecurityContext error, data 52e, v3839)   <----- LDAP error for invalid credentials
[864] fnbamd_ldap_parse_response-ret=49
[753] __ldap_stop-svr 'AD_LDAP'
[182] fnbamd_comm_send_result-Sending result 1 (error 0, nid 0) for req 237259384
authenticate 'user1' against 'AD_LDAP' failed!

In order to check the bind name, the following windows commands are useful:

#dsquery user -name <admin full user name>
#dsquery user -samid <admin login name>
#Check the Admin password

User Not Found:

… <output ommited> ...
[592] fnbamd_ldap_build_dn_search_req-base:'dc=test,dc=local' filter:sAMAccountName=user1        <----- User account
[925] fnbamd_ldap_send-sending 73 bytes to 192.168.1.10
[937] fnbamd_ldap_send-Request is sent. ID 2
[843] __ldap_rxtx-state 12(DN search resp)
[968] __fnbamd_ldap_read-Read 8
[1074] fnbamd_ldap_recv-Leftover 2
[968] __fnbamd_ldap_read-Read 78
[1148] fnbamd_ldap_recv-Response len: 80, svr: 192.168.1.10
...
[829] fnbamd_ldap_parse_response-Got one MESSAGE. ID:2, type:search-result
[864] fnbamd_ldap_parse_response-ret=0
[1198] __fnbamd_ldap_dn_next-No DN is found.                                                     <----- Unable to locate user DN
….
[753] __ldap_stop-svr 'AD_LDAP'
[182] fnbamd_comm_send_result-Sending result 1 (error 0, nid 0) for req 237259385
authenticate 'user1' against 'AD_LDAP' failed!

In case the user is not found, check the following:

- If common Name Identifier is “sAMAccountName”, try to use the login name
- If it is “cn”, try the user full-name
- Double check the user full DN by performing the following windows command:

#dsquery user -name <full-user-name>

Incorrect User Password:

...<output ommited>...
[910] __ldap_rxtx-Change state to 'User Binding'
[843] __ldap_rxtx-state 5(User Binding)
[437] fnbamd_ldap_build_userbind_req-Trying DN 'CN=user1,CN=Users,DC=test,DC=LOCAL'
[204] __ldap_build_bind_req-Binding to 'CN=user1,CN=Users,DC=test,DC=LOCAL'
[925] fnbamd_ldap_send-sending 90 bytes to 192.168.1.10
...
[1148] fnbamd_ldap_recv-Response len: 104, svr: 192.168.1.10
[829] fnbamd_ldap_parse_response-Got one MESSAGE. ID:3, type:bind
[851] fnbamd_ldap_parse_response-Error 49(80090308: LdapErr: DSID-0C09042A, comment: AcceptSecurityContext error, data 52e, v3839)    <----- Invalid credentials
[864] fnbamd_ldap_parse_response-ret=49
[910] __ldap_rxtx-Change state to 'Done'
[843] __ldap_rxtx-state 23(Done)
[925] fnbamd_ldap_send-sending 7 bytes to 192.168.1.10
[937] fnbamd_ldap_send-Request is sent. ID 4
[753] __ldap_stop-svr 'AD_LDAP'
[53] ldap_dn_list_del_all-Del CN=user1,CN=Users,DC=test,DC=LOCAL
[182] fnbamd_comm_send_result-Sending result 1 (error 0, nid 0) for req 237259387
authenticate 'user1' against 'AD_LDAP' failed!

Groups Not Found:

The following error indicates that no user group information has been found during the LDAP resonse based on the configured attribute (memberOf is the default value)

get_member_of_groups-attr=<attribute_name> found 0 values

Password Expired.

… <output ommited> ...
[764] fnbamd_ldap_parse_response-Got one MESSAGE. ID:2, type:search-result
[799] fnbamd_ldap_parse_response-ret=0
[882] __ldap_rxtx-Change state to 'User Binding'
[815] __ldap_rxtx-state 5(User Binding)
[437] fnbamd_ldap_build_userbind_req-Trying DN 'CN=user1,DC=test,DC=LOCAL'
[204] __ldap_build_bind_req-Binding to 'CN=user1,DC=test,DC=LOCAL'
[860] fnbamd_ldap_send-sending 116 bytes to 192.168.1.182
. . .
[764] fnbamd_ldap_parse_response-Got one MESSAGE. ID:3, type:bind
[786] fnbamd_ldap_parse_response-Error 49(80090308: LdapErr: DSID-0C090453, comment: AcceptSecurityContext error, data 532, v3839) <----- Logon failure: the specified account password has expired.     
[799] fnbamd_ldap_parse_response-ret=49
[882] __ldap_rxtx-Change state to 'Done'
[815] __ldap_rxtx-state 21(Done)
[860] fnbamd_ldap_send-sending 7 bytes to 192.168.1.182
[872] fnbamd_ldap_send-Request is sent. ID 4
[725] __ldap_stop-svr 'AD_LDAP'
[53] ldap_dn_list_del_all-Del CN=user1,DC=test,DC=LOCAL
[181] fnbamd_comm_send_result-Sending result 1 (error 0, nid 0) for req 300967187
authenticate 'user1' against 'AD_LDAP' failed!                                                                                     <-----