Stuck on login screen

[Dino Edwards]

I'm having an issue with PWM getting stuck on the login screen after successful login. It just sits there processing and then it eventually times out. The logs indicate successful authentication but it never gets past the login screen. 

Below are the debug logs of the session:

2022-11-16T10:29:57Z, DEBUG, svc.PwmServiceManager, completed initialization of service [PwNotifyService] in 22ms, status=CLOSED

2022-11-16T10:29:57Z, INFO , pwm.PwmApplication, PWM v2.0.4 bfd55fbd open for bidness! (1653ms)

2022-11-16T10:29:57Z, DEBUG, pwm.PwmApplication, buildTime=2022-10-01T22:00:09Z, javaLocale=en, DefaultLocale=en

2022-11-16T10:29:57Z, DEBUG, stored.StoredConfigurationUtil, initialized new random security key

2022-11-16T10:29:57Z, INFO , event.AuditService, audit event: {"instance":"A6E44F8CA3E2EA0","type":"SYSTEM","eventCode":"STARTUP","guid":"7b4b5a96-0823-4c9f-bbea-430350e421ec","timestamp":"2022-11-16T10:29:57Z","narrative":"PWM has started up","xdasTaxonomy":"XDAS_AE_INVOKE_SERVICE","xdasOutcome":"XDAS_OUT_SUCCESS"}

2022-11-16T10:29:57Z, ERROR, pwm.PwmApplication, error retrieving key 'https.selfCert' value from localDB: null

2022-11-16T10:29:58Z, DEBUG, self.SelfCertGenerator, creating self-signed certificate with cn of pwm.domain.tld

2022-11-16T10:29:59Z, INFO , pwm.PwmApplication, successfully exported application https key to keystore file /root/.pwm-workpath/work-pwm-8443/keystore

2022-11-16T10:30:56Z, DEBUG, provider.WatchdogService, starting up LDAP Chai WatchdogWrapper timer thread, 1000ms check frequency

2022-11-16T10:30:56Z, DEBUG, search.UserSearchEngine, {GdU7j} searchID=0 beginning user search process with 1 search jobs, filter: (&(objectClass=person)(|(sAMAccountName=joe.smoe)(cn=joe.smoe)(mail=joe.smoe))) [10.xx.xx.xx]

2022-11-16T10:31:56Z, DEBUG, search.UserSearchEngine, {GdU7j} searchID=0 completed user search process in 1m, intermediate result size=1 [10.xx.xx.xx]

2022-11-16T10:31:56Z, DEBUG, search.UserSearchEngine, {GdU7j} found userDN: CN=Joe Smoe,OU=DOMAIN - Admin,DC=DOMAIN,DC=domain,DC=tld (1m) [10.xx.xx.xx]

2022-11-16T10:31:56Z, DEBUG, auth.LDAPAuthenticationRequest, {GdU7j} authID=0, preparing to authenticate user using authenticationType=AUTHENTICATED using strategy BIND [10.xx.xx.xx]

2022-11-16T10:31:57Z, DEBUG, auth.LDAPAuthenticationRequest, {GdU7j} authID=0, successful ldap authentication for CN=Joe Smoe,OU=DOMAIN - Admin,DC=DOMAIN,DC=domain,DC=tld (default) (88ms) type: AUTHENTICATED, using strategy BIND, using proxy connection: false, returning bind dn: CN=Joe Smoe,OU=DOMAIN - Admin,DC=DOMAIN,DC=domain,DC=tld [10.xx.xx.xx]

2022-11-16T10:31:57Z, INFO , event.AuditService, {GdU7j} audit event: {"perpetratorID":"joe.smoe","perpetratorDN":"CN=Joe Smoe,OU=DOMAIN - Admin,DC=DOMAIN,DC=domain,DC=tld","perpetratorLdapProfile":"default","sourceAddress":"10.xx.xx.xx","sourceHost":"","type":"USER","eventCode":"AUTHENTICATE","guid":"dd1349d9-ec29-49c7-a039-da0227b17f8c","timestamp":"2022-11-16T10:31:57Z","message":"type=AUTHENTICATED, source=LOGIN_FORM","narrative":"joe.smoe (CN=Joe Smoe,OU=DOMAIN - Admin,DC=DOMAIN,DC=domain,DC=tld) has authenticated","xdasTaxonomy":"XDAS_AE_AUTHENTICATE_ACCOUNT","xdasOutcome":"XDAS_OUT_SUCCESS"} [10.xx.xx.xx]

2022-11-16T10:31:57Z, DEBUG, password.PasswordUtility, {GdU7j} testing password policy profile 'default' [10.xx.xx.xx]

2022-11-16T10:31:57Z, DEBUG, permission.UserPermissionUtility, {GdU7j} user CN=Joe Smoe,OU=DOMAIN - Admin,DC=DOMAIN,DC=domain,DC=tld (default) is a match for permission 'UserPermission(type=ldapAllUsers, ldapProfileID=all, ldapQuery=null, ldapBase=null)' (6ms) [10.xx.xx.xx]

2022-11-16T10:31:57Z, DEBUG, password.PasswordUtility, {GdU7j} merged user password policy of 'CN=Joe Smoe,OU=DOMAIN - Admin,DC=DOMAIN,DC=domain,DC=tld' with PWM configured policy: PwmPasswordPolicy: {"policyMap":{"chai.pwrule.repeat.max":"0","chai.pwrule.changeMessage":"","chai.pwrule.upper.min":"0","chai.pwrule.allowUserChange":"true","chai.pwrule.disallowedValues":"password\ntest","password.policy.disallowCurrent":"true","chai.pwrule.allowAdminChange":"true","chai.pwrule.uniqueRequired":"false","password.policy.allowNonAlpha":"true","chai.pwrule.unique.max":"0","chai.pwrule.special.max":"0","chai.pwrule.enforceAtLogin":"false","password.policy.charGroup.regExValues":".*[0-9]\n.*[^A-Za-z0-9]\n.*[A-Z]\n.*[a-z]","chai.pwrule.policyEnabled":"true","chai.pwrule.lower.max":"0","password.policy.checkWordlist":"true","chai.pwrule.upper.max":"0","chai.pwrule.unique.min":"0","chai.pwrule.length.min":"8","password.policy.maximumAlpha":"0","chai.pwrule.numeric.allow":"true","password.policy.minimumNonAlpha":"0","chai.pwrule.challengeResponseEnabled":"false","password.policy.regExMatch":"","chai.pwrule.length.max":"64","password.policy.ADComplexityLevel":"AD2003","password.policy.minimumStrength":"0","chai.pwrule.disallowedAttributes":"givenName\ncn\nsn","password.policy.charGroup.minimumMatch":"0","chai.pwrule.sequentialRepeat.max":"0","password.policy.minimumAlpha":"0","chai.pwrule.lower.min":"0","password.policy.allowMacroInRegexSetting":"true","chai.pwrule.numeric.allowLast":"true","chai.pwrule.numeric.allowFirst":"true","chai.pwrule.special.allow":"true","chai.pwrule.expirationInterval":"0","chai.pwrule.special.min":"0","password.policy.maximumNonAlpha":"0","chai.pwrule.numeric.max":"0","chai.pwrule.ADComplexityMaxViolation":"2","chai.pwrule.numeric.min":"0","chai.pwrule.special.allowFirst":"true","chai.pwrule.special.allowLast":"true","password.policy.maximumConsecutive":"0","chai.pwrule.caseSensitive":"true","chai.pwrule.lifetime.minimimum":"0","password.policy.regExNoMatch":""}} [10.xx.xx.xx]

2022-11-16T10:31:57Z, DEBUG, ldap.UserInfoReader, {GdU7j} completed user password status check for CN=Joe Smoe,OU=DOMAIN - Admin,DC=DOMAIN,DC=domain,DC=tld PasswordStatus.PasswordStatusBuilder(expired=false, preExpired=false, violatesPolicy=false, warnPeriod=false) (6ms) [10.xx.xx.xx]

2022-11-16T10:31:57Z, DEBUG, auth.SessionAuthenticator, {GdU7j} clearing permission cache [10.xx.xx.xx]

2022-11-16T10:31:57Z, DEBUG, servlet.LoginServlet, {GdU7j} rest login succeeded [10.xx.xx.xx]

2022-11-16T10:32:27Z, DEBUG, provider.WatchdogProviderHolder, disconnecting underlying connection: ldap idle timeout detected (PT30.649991S), closing connection id=w1-3

2022-11-16T10:32:27Z, DEBUG, provider.WatchdogProviderHolder, disconnecting underlying connection: ldap idle timeout detected (PT30.436955S), closing connection id=w0-1

[robert...@uwrf.edu]

Here's a question for you ... after you get dumped to the login screen, are you able to manually go to one of the underlying URLs such as (siteurl)/pwm/private/helpdesk   ?  I've been trying to figure out an issue in my development environment that seems to be similar, though I can get to the modules if I put in the appropriate URL after authenticating.

-Robert

[Dino Edwards]

I can't. As soon as I manually try to do it, it takes me back to the login screen. I think it's related to my reverse proxy. PWM seems to have a issue with that. 

[robert...@uwrf.edu]

Interesting ... my PWM install is behind a reverse proxy as well (to invoke MFA for certain modules such as administration or helpdesk).

-Robert

[Dino Edwards]

so after playing around some more, I changed the IP of the PWM container to point to the external IP instead of the proxy that it was previously pointing and that fixed the issue. However, now I'm getting 30 second LDAP queries. 

[Dino Edwards]

Back to the same login issue. After a few hours of not logging in, I'm getting stuck on login. The LDAP queries are taking about 30 seconds. Any ideas?