VMware PKS login for LDAP/AD users is failing intermittently
search cancel

VMware PKS login for LDAP/AD users is failing intermittently

book

Article ID: 345540

calendar_today

Updated On:

Products

VMware

Issue/Introduction

Symptoms:
  • PKS login for LDAP/AD users is failing with an error similar to:
Error: Post https://sjc1-caas-uaa.sdi.trendnet.org:8443/oauth/token: net/http: request canceled (Client.Timeout exceeded while awaiting headers)
  • Issue seems to be intermittent and resolving automatically after some time.
  • In the /var/vcap/sys/log/uaa/uaa.log file on PKS API vm, you see the entries similar to:

[2019-03-22 10:13:04.205] uaa - 26265 [https-jsse-nio-8443-exec-10] .... DEBUG --- NestedLdapAuthoritiesPopulator: Search aborted, max depth reached, for roles for user 'CN=group1,OU=Groups,OU=DCS,dc=vclass,dc=local', DN = 'CN=group2,OU=Groups,OU=DCS,dc=vclass,dc=local', with filter member={0} in search base 'dc=vclass,dc=local'
[2019-03-22 10:13:04.205] uaa - 26265 [https-jsse-nio-8443-exec-10] .... DEBUG --- NestedLdapAuthoritiesPopulator: Roles from LDAP search:1.[Key:spring.security.ldap.dn Values:CN=group1,OU=Groups,OU=DCS,dc=vclass,dc=local; ]  
[2019-03-22 10:13:03.119] uaa - 26265 [http-nio-35684-exec-4] .... DEBUG --- FilterChainProxy: /healthz has an empty filter list
.
.
[2019-03-22 10:11:07.168] uaa - 26265 [pool-2-thread-1] .... DEBUG --- JdbcTemplate: Executing SQL query [select count(*) from users]
[2019-03-22 10:11:03.061] uaa - 26265 [http-nio-35684-exec-2] .... DEBUG --- FilterChainProxy: /healthz has an empty filter list
[2019-03-22 10:11:02.169] uaa - 26265 [pool-2-thread-1] .... DEBUG --- JdbcTemplate: Executing SQL query [select count(*) from oauth_client_details]
[2019-03-22 10:11:02.168] uaa - 26265 [pool-2-thread-1] .... DEBUG --- JdbcTemplate: Executing SQL query [select count(*) from users]
[2019-03-22 10:10:57.169] uaa - 26265 [pool-2-thread-1] .... DEBUG --- JdbcTemplate: Executing SQL query [select count(*) from oauth_client_details]
[2019-03-22 10:10:57.168] uaa - 26265 [pool-2-thread-1] .... DEBUG --- JdbcTemplate: Executing SQL query [select count(*) from users]
[2019-03-22 10:10:53.152] uaa - 26265 [https-jsse-nio-8443-exec-10] .... DEBUG --- SpringSecurityLdapTemplate: No attribute value found for 'spring.security.ldap.dn'
[2019-03-22 10:10:53.152] uaa - 26265 [https-jsse-nio-8443-exec-10] .... DEBUG --- SpringSecurityLdapTemplate: No attribute value found for 'spring.security.ldap.dn'
[2019-03-22 10:10:53.152] uaa - 26265 [https-jsse-nio-8443-exec-10] .... DEBUG --- SpringSecurityLdapTemplate: No attribute value found for 'spring.security.ldap.dn'
[2019-03-22 10:10:53.152] uaa - 26265 [https-jsse-nio-8443-exec-10] .... DEBUG --- SpringSecurityLdapTemplate: No attribute value found for 'spring.security.ldap.dn'
[2019-03-22 10:10:53.148] uaa - 26265 [https-jsse-nio-8443-exec-10] .... DEBUG --- SpringSecurityLdapTemplate: Using filter: member=cn=Test User,OU=Admins,OU=Users,dc=vclass,dc=local
[2019-03-22 10:10:53.148] uaa - 26265 [https-jsse-nio-8443-exec-10] .... DEBUG --- NestedLdapAuthoritiesPopulator: Searching for roles for user 'test_user', DN = 'cn=Test User,OU=Admins,OU=Users,dc=vclass,dc=local', with filter member={0} in search base 'dc=vclass,dc=local'
[2019-03-22 10:10:53.148] uaa - 26265 [https-jsse-nio-8443-exec-10] .... DEBUG --- DefaultLdapAuthoritiesPopulator: Getting authorities for user cn=Test User,OU=Admins,OU=Users,dc=vclass,dc=local
[2019-03-22 10:10:53.148] uaa - 26265 [https-jsse-nio-8443-exec-10] .... DEBUG --- BindAuthenticator: Retrieving attributes...
[2019-03-22 10:10:53.142] uaa - 26265 [https-jsse-nio-8443-exec-10] .... DEBUG --- BindAuthenticator: Attempting to bind as cn=Test User,OU=Admins,OU=Users,dc=vclass,dc=local
[2019-03-22 10:08:42.994] uaa - 26265 [http-nio-35684-exec-8] .... DEBUG --- FilterChainProxy: /healthz has an empty filter list
[2019-03-22 10:08:42.169] uaa - 26265 [pool-2-thread-1] .... DEBUG --- JdbcTemplate: Executing SQL query [select count(*) from oauth_client_details]
[2019-03-22 10:08:42.168] uaa - 26265 [pool-2-thread-1] .... DEBUG --- JdbcTemplate: Executing SQL query [select count(*) from users]
[2019-03-22 10:08:41.544] uaa - 26265 [https-jsse-nio-8443-exec-10] .... DEBUG --- SpringSecurityLdapTemplate: Found DN: CN=Test User,OU=Admins,OU=Users,dc=vclass,dc=local
[2019-03-22 10:08:41.544] uaa - 26265 [https-jsse-nio-8443-exec-10] .... DEBUG --- SpringSecurityLdapTemplate: Searching for entry under DN '', base = 'dc=vclass,dc=local', filter = 'sAMAccountName={0}'
[2019-03-22 10:08:41.540] uaa - 26265 [https-jsse-nio-8443-exec-10] .... DEBUG --- ProviderManager: Authentication attempt using org.springframework.security.ldap.authentication.LdapAuthenticationProvider
[2019-03-22 10:08:41.540] uaa - 26265 [https-jsse-nio-8443-exec-10] .... DEBUG --- ChainedAuthenticationManager: Attempting chained authentication of org.springframework.security.authentication.UsernamePasswordAuthenticationToken@508164f4: Principal: test_user; Credentials: [PROTECTED]; Authenticated: false; Details: remoteAddress=LDAP_IP, clientId=pks_cli; Not granted any authorities with manager:org.springframework.security.authentication.ProviderManager@7871355c required:null
[2019-03-22 10:08:41.540] uaa - 26265 [https-jsse-nio-8443-exec-10] .... DEBUG --- ChainedAuthenticationManager: Attempting chained authentication of org.springframework.security.authentication.UsernamePasswordAuthenticationToken@508164f4: Principal: test_user; Credentials: [PROTECTED]; Authenticated: false; Details: remoteAddress=LDAP_IP, clientId=pks_cli; Not granted any authorities with manager:org.cloudfoundry.identity.uaa.authentication.manager.DynamicLdapAuthenticationManager@51313b0a required:ifPreviousFalse
[2019-03-22 10:08:41.540] uaa - 26265 [https-jsse-nio-8443-exec-10] .... DEBUG --- ChainedAuthenticationManager: Chained Authentication status of org.springframework.security.authentication.UsernamePasswordAuthenticationToken@508164f4: Principal: test_user; Credentials: [PROTECTED]; Authenticated: false; Details: remoteAddress=LDAP_IP, clientId=pks_cli; Not granted any authorities with manager:org.cloudfoundry.identity.uaa.authentication.manager.ChainedAuthenticationManager$AuthenticationManagerConfiguration@324c350; Authenticated:false
[2019-03-22 10:08:41.540] uaa - 26265 [https-jsse-nio-8443-exec-10] .... DEBUG --- ChainedAuthenticationManager: Chained authentication exception:Bad credentials at:org.cloudfoundry.identity.uaa.authentication.manager.AuthzAuthenticationManager.authenticate(AuthzAuthenticationManager.java:136)
[2019-03-22 10:08:41.540] uaa - 26265 [https-jsse-nio-8443-exec-10] ....  INFO --- Audit: PrincipalAuthenticationFailure ('null'): principal=test_user, origin=[LDAP_IP], identityZoneId=[uaa]
[2019-03-22 10:08:41.540] uaa - 26265 [https-jsse-nio-8443-exec-10] ....  INFO --- Audit: UserNotFound (''): principal=HQt7aKON4WYK7GqSK5YSvzWdLyg=, origin=[remoteAddress=LDAP_IP, clientId=pks_cli], identityZoneId=[uaa]
[2019-03-22 10:08:41.540] uaa - 26265 [https-jsse-nio-8443-exec-10] .... DEBUG --- AuthzAuthenticationManager: No user named 'test_user' was found for origin:uaa
[2019-03-22 10:08:41.540] uaa - 26265 [https-jsse-nio-8443-exec-10] .... DEBUG --- JdbcTemplate: Executing prepared SQL statement [select id,username,password,email,givenName,familyName,created,lastModified,authorities,origin,external_id,verified,identity_zone_id,salt,passwd_lastmodified,phoneNumber,legacy_verification_behavior,passwd_change_required,last_logon_success_time,previous_logon_success_time from users where username = ? and active=? and origin=? and identity_zone_id=?]


Environment

VMware PKS 1.x

Cause

This issue occurs when the LDAP search takes long time and aborted at last.Typically we see long delays when uaa is doing an ldap search.By default uaa will follow referrals and sometimes there is a referred DC that is taking too long to respond.

Resolution

To resolve this issue, investigate why the referrals are taking too long to return the search results. 


Workaround:

To work around this issue, disable the referrals by selecting the Ignore referrals and return partial result option for LDAP Referrals under UAA section in PKS Tile, and apply changes from Ops Manager.


Powered by Wolken Software