Kemp Support, how can we help?

The latest application delivery knowledge and expertise at your fingertips.

  1. Kemp Support
  2. Knowledge Base
  3. SSO / ESP

How to troubleshoot LDAP ESP Authentication issues using the SSOMGR Debug traces

Updated: 

This article explains some examples of the LDAP SSO logs when using the Edge Security Pack (ESP).

1. Enable SSO Debug Traces

2. SSO Domain Health-check

3. Authentication Form Fill Out

4. LDAP Authentication with Permitted Group Check

1. Enable SSO Debug Traces

To enable the SSOMGR debug traces, navigate to Logging Options > System Logs Files > Debug Options > Enable SSOMGR Debug Traces.

2. SSO Domain Health-check

The LoadMaster performs regular health-checks to the LDAP endpoint. If these fail, the Virtual Service alarms with a Security down error.

The user that is set on the LDAP endpoint setup is used to perform a bind request to the LDAP servers that have been set. In this example, the LDAP server is 10.1.155.10 and the user is administrator@foxworld.loc. 

In the server's response, highlighted below, rc=0 means that the credentials used are correct and the bind request is successful. rc=49 means that the credentials used are wrong.

Jun 22 10:42:28 LB100 ssomgr: #12849# baseUserName: basename=|administrator|
Jun 22 10:42:28 LB100 ssomgr: #12849# >> do_sso_ldap_check(Foxworld.loc,administrator@foxworld.loc(administrator)[1])
Jun 22 10:42:28 LB100 ssomgr: #12849# sso_cfg: [Domain:Foxworld.loc] [Server:10.1.155.10] [METH:128] [auth_type:0]
Jun 22 10:42:28 LB100 ssomgr: #12849# >>> ldap_map_auth_for_dual_factor: auth_type in: 0
Jun 22 10:42:28 LB100 ssomgr: #12849# <<< ldap_map_auth_for_dual_factor: auth_type out: 0, server: 10.1.155.10
Jun 22 10:42:28 LB100 ssomgr: #12849# do_sso_ldap_check: ldap_urls=|ldap://10.1.155.10|
Jun 22 10:42:28 LB100 ssomgr: #12849# do_sso_ldap_check: ldap timeout is 5
Jun 22 10:42:28 LB100 ssomgr: #12849# baseUserName: basename=|administrator|
Jun 22 10:42:28 LB100 ssomgr: #12849# do_sso_ldap_check: bind(,administrator@foxworld.loc,...): rc=0
Jun 22 10:42:28 LB100 ssomgr: #12849# >>>group_processing: started group processing for do_sso_ldap_check
Jun 22 10:42:28 LB100 ssomgr: #12849# >>> ldap_need_steering_groups: vid=(null)
Jun 22 10:42:28 LB100 ssomgr: #12849# group_processing: chk_sids = 0, chk_allowed_groups = 0, chk_steering_groups = 0
Jun 22 10:42:28 LB100 ssomgr: #12849# <<<group_processing: completed group processing for do_sso_ldap_check, groupOK=1
Jun 22 10:42:28 LB100 ssomgr: #12849# << do_sso_ldap_check: bindrc:0 groupOK:1

3. Authentication Form Fill Out

The LoadMaster detects the username that has been entered.

The LoadMaster then attempts to extract a domain to match on the set SSO domains (if alternative SSO domains are assigned). If the user did not enter a domain the LoadMaster reverts to the default set SSO domain. In this example, Foxworld.loc.

The LoadMaster then checks if the username needs to be normalized. The SSO domain in this example has the setting Principalname set so the LoadMaster turns the username rschoepfel to rschoepfel@foxworld.loc.

For more information on normalization, review the following article: Logon Format Normalization

Jun 22 11:02:22 LB100 ssomgr: #853# 0000 00000000 00000000 ........
Jun 22 11:02:22 LB100 ssomgr: #853# Auth_form user rschoepfel
Jun 22 11:02:22 LB100 ssomgr: #853# >>>get_domain
Jun 22 11:02:22 LB100 ssomgr: #853# >>>get_domain_from_user
Jun 22 11:02:22 LB100 ssomgr: #853# get_domain_from_user: no domain to extract from [rschoepfel]
Jun 22 11:02:22 LB100 ssomgr: #853# get_domain: client domain not provided, proceed with default domain [FOXWORLD.LOC] for VS[20]
Jun 22 11:02:22 LB100 ssomgr: #853# >>>get_domain
Jun 22 11:02:22 LB100 ssomgr: #853# >>>get_domain_from_user
Jun 22 11:02:22 LB100 ssomgr: #853# get_domain_from_user: no domain to extract from [rschoepfel]
Jun 22 11:02:22 LB100 ssomgr: #853# get_domain: client domain not provided, proceed with default domain [FOXWORLD.LOC] for VS[20]
Jun 22 11:02:22 LB100 ssomgr: #853# normalize_user: user:|rschoepfel|; nd1:|(null)|; nd2:|(null)|; logonfmt:1 phase:1
Jun 22 11:02:22 LB100 ssomgr: #853# normalize_user: Logon Format : Principalname
Jun 22 11:02:22 LB100 ssomgr: #853# normalize_user: normalized user: |rschoepfel@Foxworld.loc|

4. LDAP Authentication with Permitted Group Check

The authorization for a user works in the same principle as the health check mentioned above. A bind request is sent with the credentials and when it is successful the rc=0 is returned.

Jun 22 11:02:22 LB100 ssomgr: #13353# >> do_sso_ldap_check(Foxworld.loc,rschoepfel@Foxworld.loc(rschoepfel)[1])

In combination with Permitted Groups, a group check is performed before the credentials bind request is done. The user entered in the LDAP endpoint setting must have the required permission to request a group membership for a different user (we request an Admin User).

For each group-check an additional LDAP endpoint health check is performed.

Jun 22 11:02:22 LB100 ssomgr: #13353# sso_cfg: [Domain:Foxworld.loc] [Server:10.1.155.10] [METH:128] [auth_type:0]
Jun 22 11:02:22 LB100 ssomgr: #13353# >>> ldap_map_auth_for_dual_factor: auth_type in: 0
Jun 22 11:02:22 LB100 ssomgr: #13353# <<< ldap_map_auth_for_dual_factor: auth_type out: 0, server: 10.1.155.10
Jun 22 11:02:22 LB100 ssomgr: #13353# do_sso_ldap_check: ldap_urls=|ldap://10.1.155.10|
Jun 22 11:02:22 LB100 ssomgr: #13353# do_sso_ldap_check: ldap timeout is 5
Jun 22 11:02:22 LB100 ssomgr: #13353# baseUserName: basename=|administrator|
Jun 22 11:02:22 LB100 ssomgr: #13353# do_sso_ldap_check: bind(,administrator@foxworld.loc,...): rc=0

In this example, there are two groups set on the Virtual Service (EMEAteam;APACteam).

The LoadMaster checks with the LDAP server if the listed groups exist on the server.

Jun 22 11:02:22 LB100 ssomgr: #13353# >>>group_processing: started group processing for do_sso_ldap_check
Jun 22 11:02:22 LB100 ssomgr: #13353# >>> ldap_need_steering_groups: vid=20
Jun 22 11:02:22 LB100 ssomgr: #13353# group_processing: chk_sids = 0, chk_allowed_groups = 1, chk_steering_groups = 0
Jun 22 11:02:22 LB100 ssomgr: #13353# domain=|Foxworld.loc| baseDN=|dc=Foxworld,dc=loc|
Jun 22 11:02:22 LB100 ssomgr: #13353# getGroupFilter: >> basedn=|dc=Foxworld,dc=loc| vid=|20|
Jun 22 11:02:22 LB100 ssomgr: #13353# getGroupDN: >> basedn=|dc=Foxworld,dc=loc| groupname=|APACteam|
Jun 22 11:02:22 LB100 ssomgr: #13353# getGroupDN: filter=|(&(objectClass=group)(cn=APACteam))|
Jun 22 11:02:22 LB100 ssomgr: #13353# getGroupDN: ldap_result(): rc2=100 (search-entry)
Jun 22 11:02:22 LB100 ssomgr: #13353# getGroupDN: groupdn=|CN=APACteam,CN=Users,DC=foxworld,DC=loc|
Jun 22 11:02:22 LB100 ssomgr: #13353# getGroupDN: ldap_result(): rc=0
Jun 22 11:02:22 LB100 ssomgr: #13353# getGroupDN: <<< - rc=0
Jun 22 11:02:22 LB100 ssomgr: #13353# getGroupDN: >> basedn=|dc=Foxworld,dc=loc| groupname=|EMEAteam|
Jun 22 11:02:22 LB100 ssomgr: #13353# getGroupDN: filter=|(&(objectClass=group)(cn=EMEAteam))|
Jun 22 11:02:22 LB100 ssomgr: #13353# getGroupDN: ldap_result(): rc2=100 (search-entry)
Jun 22 11:02:22 LB100 ssomgr: #13353# getGroupDN: groupdn=|CN=EMEAteam,CN=Users,DC=foxworld,DC=loc|
Jun 22 11:02:22 LB100 ssomgr: #13353# getGroupDN: ldap_result(): rc=0
Jun 22 11:02:22 LB100 ssomgr: #13353# getGroupDN: <<< - rc=0

Based on this information, the membership request is done, determining if the user is part of any of the groups the LDAP has confirmed exist on its database.

Jun 22 11:02:22 LB100 ssomgr: #13353# getGroupFilter: << vid=|20| groupfilter=|(|(memberOf=CN=APACteam,CN=Users,DC=foxworld,DC=loc)(memberOf=CN=EMEAteam,CN=Users,DC=foxworld,DC=loc))|
Jun 22 11:02:22 LB100 ssomgr: #13353# do_check_group: attrs[0]=|userprincipalname| filter=|(&(samAccountType=805306368)(|(memberOf=CN=APACteam,CN=Users,DC=foxworld,DC=loc)(memberOf=CN=EMEAteam,CN=Users,DC=foxworld,DC=loc))(userprincipalname=rschoepfel@Foxworld.loc))| tout:5
Jun 22 11:02:22 LB100 ssomgr: #13353# do_check_group: ldap_search_ext(): rc=0
Jun 22 11:02:22 LB100 ssomgr: #13353# do_check_group: ldap_result(): rc2=101 (search-result)
Jun 22 11:02:22 LB100 ssomgr: #13353# do_check_group: ldap_msg: msgid=4 type=100 (search-entry)
Jun 22 11:02:22 LB100 ssomgr: #13353# do_check_group: userPrincipalName=|rschoepfel@foxworld.loc|
Jun 22 11:02:22 LB100 ssomgr: #13353# do_check_group: user in group(s)
Jun 22 11:02:22 LB100 ssomgr: #13353# group_processing: Granted access - user in approved groups for VS [20]
Jun 22 11:02:22 LB100 ssomgr: #13353# <<<group_processing: completed group processing for do_sso_ldap_check, groupOK=1

Logs like this are also possible, to deny the access if the user is not part of the group or the LDAP endpoint user does not have sufficient rights.

Jun 22 11:35:46 LB100 ssomgr: #2859# group_processing: Blocked access - user not in approved groups for VS [20]
Jun 22 11:35:46 LB100 ssomgr: #2859# <<<group_processing: completed group processing for do_sso_ldap_check, groupOK=0
Jun 22 11:35:46 LB100 ssomgr: #2859# << do_sso_ldap_check: bindrc:50 groupOK:0
Jun 22 11:35:46 LB100 ssomgr: #2859# Couldn't bind: [FOXWORLD.LOC] [10.1.155.10]: 50, Insufficient access

Granted Access means the membership of the user has been confirmed.

Jun 22 11:02:22 LB100 ssomgr: #13353# baseUserName: basename=|rschoepfel|
Jun 22 11:02:22 LB100 ssomgr: #13353# do_sso_ldap_check: bind(rschoepfel@Foxworld.loc): rc=0,msgid=5
Jun 22 11:02:22 LB100 ssomgr: #13353# domain=|Foxworld.loc| baseDN=|dc=Foxworld,dc=loc|
Jun 22 11:02:22 LB100 ssomgr: #13353# do_sso_ldap_check: Attempt attribute retrieval for [rschoepfel@Foxworld.loc]
Jun 22 11:02:22 LB100 ssomgr: #13353# do_sso_ldap_check: ldap_search_ext(ld,dc=Foxworld,dc=loc,,(userprincipalname=rschoepfel@Foxworld.loc)): rc=0
Jun 22 11:02:22 LB100 ssomgr: #13353# get_attributes: ldap_count_messages(): 1
Jun 22 11:02:22 LB100 ssomgr: #13353# get_attributes: ldap_count_entries(): 1
Jun 22 11:02:22 LB100 ssomgr: #13353# get_attributes: ldap_result(): rc=100
Jun 22 11:02:22 LB100 ssomgr: #13353# get_attributes: ldap_first_message(): msg=0x7fc7b800a270 msgtype=100
Jun 22 11:02:22 LB100 ssomgr: #13353# get_attributes: samAccountName=|rschoepfel|
Jun 22 11:02:22 LB100 ssomgr: #13353# get_attributes: userPrincipalName=|rschoepfel@foxworld.loc|
Jun 22 11:02:22 LB100 ssomgr: #13353# get_attributes: ldap_result(): rc=0
Jun 22 11:02:22 LB100 ssomgr: #13353# get_attributes: ldap_count_messages(): 1
Jun 22 11:02:22 LB100 ssomgr: #13353# get_attributes: ldap_count_entries(): 0
Jun 22 11:02:22 LB100 ssomgr: #13353# get_attributes: ldap_result(): rc=101
Jun 22 11:02:22 LB100 ssomgr: #13353# do_sso_ldap_check: attributes retrieved userPrincipleName:rschoepfel@foxworld.loc, samAccountName:rschoepfel
Jun 22 11:02:22 LB100 ssomgr: #13353# << do_sso_ldap_check: bindrc:0 groupOK:1

The provided username and password match on the LDAP server so the authentication was successful.

As mentioned above, rc=49 means that the credentials were incorrect or on older firmware before 7.2.x and that the password may have expired. Below is a link for a list of LDAP Return codes.

LDAP Return Codes

 

Comments

Avatar

jcarpenter

How do I access the SSOMGR logs?

0
Avatar

Bill DeCastro

SSOMGR logs can be seen in the System Message File. This can be accessed by navigating to System Configuration > Logging Options > System Log Files > System Message File.

0
In this document