CAS 5.0.5 - LDAP check out validation failure results in failed authentication

[Carlos Fernandez]

Good afternoon,

We recently upgraded to CAS 5.0.5 in production and have now run into an issue where CAS fails to authenticate users. It seems that whenever CAS fails the authentication attempt when tries to check out a connection from the LDAP pool and Ldaptive fails the checkout validation. This seems to affect attribute release as well -- some of our applications depend on specific attributes to be sent through validation but they're failing intermittently. An excerpt from the log file follows:

---8<---
2017-07-10 12:26:33,172 WARN [org.ldaptive.pool.BlockingConnectionPool] - <connection failed check out validation: org.ldaptive.pool.AbstractConnectionPool$DefaultPooledConnectionProxy@3b167a90>
2017-07-10 12:26:33,173 ERROR [org.apereo.cas.authentication.PolicyBasedAuthenticationManager] - <LdapAuthenticationHandler: Unexpected LDAP error  (Details: Validation of connection failed)>
2017-07-10 12:26:33,174 WARN [org.apereo.cas.authentication.PolicyBasedAuthenticationManager] - <Authentication has failed. Credentials may be incorrect or CAS cannot find authentication handler that supports [ea685774] of type [UsernamePasswordCredential], which suggests a configuration problem.>
2017-07-10 12:26:33,175 INFO [org.apereo.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - <Audit trail record BEGIN
=============================================================
WHO: ea685774
WHAT: Supplied credentials: [ea685774]
ACTION: AUTHENTICATION_FAILED
APPLICATION: CAS
WHEN: Mon Jul 10 12:26:33 EDT 2017
CLIENT IP ADDRESS: 129.68.65.149
SERVER IP ADDRESS: unknown
=============================================================

>
---8<---

I guess we didn't run into this issue in testing because there we couldn't generate enough load to trigger it. What's the consensus on using the validateOnCheckout option? Should I disable it? Or perhaps I'm barking up the wrong tree here?

The relevant CAS properties here (comments and all) are:

---8<---
cas.authn.ldap[0].type=DIRECT
cas.authn.ldap[0].ldapUrl=ldaps://axldap.sju.edu
cas.authn.ldap[0].useSsl=true
cas.authn.ldap[0].useStartTls=false
cas.authn.ldap[0].connectTimeout=5000
cas.authn.ldap[0].baseDn=ou=people,o=sju.edu
# cas.authn.ldap[0].userFilter=uid={user}
# cas.authn.ldap[0].subtreeSearch=true
# cas.authn.ldap[0].usePasswordPolicy=true
# cas.authn.ldap[0].bindDn=cn=Directory Manager
# cas.authn.ldap[0].bindCredential=trolololo
# cas.authn.ldap[0].poolPassivator=NONE|CLOSE|BIND
cas.authn.ldap[0].poolPassivator=CLOSE
cas.authn.ldap[0].enhanceWithEntryResolver=true
cas.authn.ldap[0].dnFormat=uid=%s,ou=people,o=sju.edu
cas.authn.ldap[0].principalAttributeId=uid
#cas.authn.ldap[0].principalAttributePassword=
cas.authn.ldap[0].principalAttributeList=uid,mail,displayName,givenName,sn,employeeNumber,udcid,pswUserName,employeeType,departmentNumber
cas.authn.ldap[0].allowMultiplePrincipalAttributeValues=true
#cas.authn.ldap[0].additionalAttributes=
#cas.authn.ldap[0].credentialCriteria=
# cas.authn.ldap[0].saslMechanism=GSSAPI|DIGEST_MD5|CRAM_MD5|EXTERNAL
# cas.authn.ldap[0].saslMechanism=CRAM_MD5
# cas.authn.ldap[0].saslRealm=SJU.EDU
# cas.authn.ldap[0].saslAuthorizationId=
# cas.authn.ldap[0].saslMutualAuth=
# cas.authn.ldap[0].saslQualityOfProtection=
# cas.authn.ldap[0].saslSecurityStrength=
cas.authn.ldap[0].trustCertificates=file:/etc/cas/credentials/axldap.crt
cas.authn.ldap[0].sslConfig=certificateTrust
#cas.authn.ldap[0].keystore=
#cas.authn.ldap[0].keystorePassword=
#cas.authn.ldap[0].keystoreType=JKS|JCEKS|PKCS12
cas.authn.ldap[0].minPoolSize=10
cas.authn.ldap[0].maxPoolSize=200
#cas.authn.ldap[0].validateOnCheckout=true
#cas.authn.ldap[0].validatePeriodically=true
#cas.authn.ldap[0].validatePeriod=60
cas.authn.ldap[0].failFast=false
cas.authn.ldap[0].idleTime=300
cas.authn.ldap[0].prunePeriod=300
cas.authn.ldap[0].blockWaitTime=300
# cas.authn.ldap[0].providerClass=org.ldaptive.provider.unboundid.UnboundIDProvider
cas.authn.ldap[0].allowMultipleDns=false
# cas.authn.ldap[0].passwordEncoder.type=NONE|DEFAULT|STANDARD|BCRYPT
# cas.authn.ldap[0].passwordEncoder.type=DEFAULT
# cas.authn.ldap[0].passwordEncoder.characterEncoding=UTF-8
# cas.authn.ldap[0].passwordEncoder.encodingAlgorithm=
# cas.authn.ldap[0].passwordEncoder.secret=
# cas.authn.ldap[0].passwordEncoder.strength=16
#cas.authn.ldap[0].principalTransformation.suffix=
#cas.authn.ldap[0].principalTransformation.caseConversion=NONE|UPPERCASE|LOWERCASE
#cas.authn.ldap[0].principalTransformation.prefix=
cas.authn.ldap[0].passwordPolicy.enabled=false
# cas.authn.ldap[0].passwordPolicy.policyAttributes.accountLocked=javax.security.auth.login.AccountLockedException
# cas.authn.ldap[0].passwordPolicy.loginFailures=5
# cas.authn.ldap[0].passwordPolicy.warningAttributeValue=
# cas.authn.ldap[0].passwordPolicy.warningAttributeName=
# cas.authn.ldap[0].passwordPolicy.displayWarningOnMatch=true
# cas.authn.ldap[0].passwordPolicy.warnAll=true
# cas.authn.ldap[0].passwordPolicy.warningDays=30
---8<---

Thanks in advance for any advice that you can provide.

Best regards,
--
Carlos M. Fernández
Enterprise Systems Manager
Saint Joseph’s University
Philadelphia PA 19131
T: +1 610 660 1501

[Carlos Fernandez]

I'm attaching the debug log files here.

I also found this:

2017-07-10 13:03:14,955 WARN [org.apereo.cas.authentication.LdapAuthenticationHandler] - <The principal id attribute [uid] is not found. CAS cannot construct the final authenticated principal if it's unable to locate the attribute that is designated as the principal id. Attributes available on the LDAP entry are [[]]. Since principal id attribute is not available, CAS will fallback to construct the principal based on the provided user id: cfernand>
2017-07-10 13:03:14,955 DEBUG [org.apereo.cas.authentication.LdapAuthenticationHandler] - <Created LDAP principal for id cfernand and 1 attributes>
2017-07-10 13:03:14,956 INFO [org.apereo.cas.authentication.PolicyBasedAuthenticationManager] - <LdapAuthenticationHandler successfully authenticated cfernand>

So it says there are no attributes in the LDAP response, however LDAP is configured to retrieve attributes and CAS intermittently releases attributes with this same exact configuration. What gives?

Best regards,
--
Carlos M. Fernández
Enterprise Systems Manager
Saint Joseph’s University
Philadelphia PA 19131
T: +1 610 660 1501

​

 caslogs.zip

​

[Tim McLaughlin]

This is great -- I don't have DEBUG logging turned on, but I am seeing the behavior where CAS 5 (I'm on 5.0.3) gets the "principal id attribute not available" message.

 

In our case, it seems to work just fine for some amount of time after a tomcat restart, and then at some point (I'm doing some testing to see if I can nail down the timing), this message begins.

 

I'm not seeing this in our Test or Dev deployments, but usage of those is very small compared to Production, so I'm assuming this is tied to load or the number of principals created or something...

 

Tim

--
- CAS gitter chatroom: https://gitter.im/apereo/cas
- CAS mailing list guidelines: https://apereo.github.io/cas/Mailing-Lists.html
- CAS documentation website: https://apereo.github.io/cas
- CAS project website: https://github.com/apereo/cas
---
You received this message because you are subscribed to the Google Groups "CAS Community" group.
To unsubscribe from this group and stop receiving emails from it, send an email to cas-user+u...@apereo.org.
To view this discussion on the web visit https://groups.google.com/a/apereo.org/d/msgid/cas-user/CAE7KU87POUxTJHYGGC29e%3DkFWM2q94PNXtGV2vMF0fia075x5w%40mail.gmail.com.

[Carlos Fernandez]

Tim,

Knowing that the same issue happens elsewhere makes me feel much better about my sanity. Now to figure out why it happens. I have an inkling that ldaptive is causing this, returning a failure when a connection fails validation on checkout instead of passivating it and retrying with another connection.

Best regards,
--
Carlos M. Fernández
Enterprise Systems Manager
Saint Joseph’s University
Philadelphia PA 19131
T: +1 610 660 1501

To unsubscribe from this group and stop receiving emails from it, send an email to cas-user+unsubscribe@apereo.org.

To view this discussion on the web visit https://groups.google.com/a/apereo.org/d/msgid/cas-user/CAE7KU87POUxTJHYGGC29e%3DkFWM2q94PNXtGV2vMF0fia075x5w%40mail.gmail.com.

--
- CAS gitter chatroom: https://gitter.im/apereo/cas
- CAS mailing list guidelines: https://apereo.github.io/cas/Mailing-Lists.html
- CAS documentation website: https://apereo.github.io/cas
- CAS project website: https://github.com/apereo/cas
---
You received this message because you are subscribed to the Google Groups "CAS Community" group.

To unsubscribe from this group and stop receiving emails from it, send an email to cas-user+unsubscribe@apereo.org.
To view this discussion on the web visit https://groups.google.com/a/apereo.org/d/msgid/cas-user/68D97E0C-9811-4821-B741-3E463132A1A7%40wwu.edu.

[Carlos Fernandez]

I found a thread in the Google group for ldaptive that describes a scenario similar to ours. Could anyone confirm that it's related?

https://groups.google.com/forum/#!topic/ldaptive/6pF-36w2gyI

Best regards,
--
Carlos M. Fernández
Enterprise Systems Manager
Saint Joseph’s University
Philadelphia PA 19131
T: +1 610 660 1501

To unsubscribe from this group and stop receiving emails from it, send an email to cas-user+u...@apereo.org.

To view this discussion on the web visit https://groups.google.com/a/apereo.org/d/msgid/cas-user/CAE7KU87POUxTJHYGGC29e%3DkFWM2q94PNXtGV2vMF0fia075x5w%40mail.gmail.com.

--
- CAS gitter chatroom: https://gitter.im/apereo/cas
- CAS mailing list guidelines: https://apereo.github.io/cas/Mailing-Lists.html
- CAS documentation website: https://apereo.github.io/cas
- CAS project website: https://github.com/apereo/cas
---
You received this message because you are subscribed to the Google Groups "CAS Community" group.

To unsubscribe from this group and stop receiving emails from it, send an email to cas-user+u...@apereo.org.

[Carlos Fernandez]

OK, now I have something that tells me that I should not be seeing this issue.

According to https://groups.google.com/d/topic/jasig-cas-user/4uXY5b38q5o, this issue was reported in https://github.com/apereo/cas/issues/2443 and fixed in https://github.com/apereo/cas/commit/50d2bec8d33aa03fd7ed9ac1846f108bc90e128c for the 5.0.4 release provided I use a passivator (if I read it correctly). I specified the CLOSE passivator in the config, but we're still seeing the same behavior in 5.0.5 as reported earlier in the Github issue. Very confusing.

Best regards,
--
Carlos M. Fernández
Enterprise Systems Manager
Saint Joseph’s University
Philadelphia PA 19131
T: +1 610 660 1501

[Tim McLaughlin]

I'm checking this out now.  I'm on 5.0.3 so I'll rebuild with 5.0.7 and see if we still see the issue...

 

I've added:

cas.authn.ldap[0].poolPassivator=CLOSE

To view this discussion on the web visit https://groups.google.com/a/apereo.org/d/msgid/cas-user/CAE7KU87xd5oSOx0WuudYeVEAYAOg07m_aTgRj%2Bd%3D5OYSEZMxVA%40mail.gmail.com.

[Carlos Fernandez]

Welp, I seem to have hit a wall.

The fix described in https://github.com/apereo/cas/commit/50d2bec8d33aa03fd7ed9ac1846f108bc90e128c applies specifically to the BIND pool passivator. All along I have been using the CLOSE passivator for a reason that I had discovered early on when putting my overlay together but had forgotten. So now in our test instance I decided to change it to BIND and see where it goes. And it goes nowhere very very fast.

2017-07-10 16:05:57,754 WARN [org.springframework.boot.context.embedded.AnnotationConfigEmbeddedWebApplicationContext] - <Exception encountered during context initialization - cancelling refresh attempt: org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'ldapAuthenticationConfiguration': Invocation of init method failed; nested exception is java.lang.NullPointerException>
2017-07-10 16:05:57,800 WARN [org.apereo.cas.services.ServiceRegistryConfigWatcher] - <Directory key is no longer valid. Quitting watcher service>
10-Jul-2017 16:05:57.819 SEVERE [localhost-startStop-1] org.apache.catalina.core.ContainerBase.addChildInternal ContainerBase.addChild: start:
 org.apache.catalina.LifecycleException: Failed to start component [StandardEngine[Catalina].StandardHost[localhost].StandardContext[/cas]]

... blah ...
Caused by: org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'ldapAuthenticationConfiguration': Invocation of init method failed; nested exception is java.lang.NullPointerException
... blah ...
Caused by: java.lang.NullPointerException
... blah ...

The simple reason behind this is that I have not specified bind credentials in my LDAP configuration since we use Direct Bind -- all of our user accounts reside within the same OU. But the BIND passivator requires those credentials, and therefore chokes on the lack of credentials.

So apparently there is still an issue with ldaptive connection validation on checkout, and the workaround is to abandon Direct Bind. Dammit.

Best regards,
--
Carlos M. Fernández
Enterprise Systems Manager
Saint Joseph’s University
Philadelphia PA 19131
T: +1 610 660 1501

To unsubscribe from this group and stop receiving emails from it, send an email to cas-user+unsubscribe@apereo.org.

To view this discussion on the web visit https://groups.google.com/a/apereo.org/d/msgid/cas-user/CAE7KU87POUxTJHYGGC29e%3DkFWM2q94PNXtGV2vMF0fia075x5w%40mail.gmail.com.

--

- CAS gitter chatroom: https://gitter.im/apereo/cas
- CAS mailing list guidelines: https://apereo.github.io/cas/Mailing-Lists.html
- CAS documentation website: https://apereo.github.io/cas
- CAS project website: https://github.com/apereo/cas
---
You received this message because you are subscribed to the Google Groups "CAS Community" group.

To unsubscribe from this group and stop receiving emails from it, send an email to cas-user+unsubscribe@apereo.org.

To view this discussion on the web visit https://groups.google.com/a/apereo.org/d/msgid/cas-user/68D97E0C-9811-4821-B741-3E463132A1A7%40wwu.edu.

--
- CAS gitter chatroom: https://gitter.im/apereo/cas
- CAS mailing list guidelines: https://apereo.github.io/cas/Mailing-Lists.html
- CAS documentation website: https://apereo.github.io/cas
- CAS project website: https://github.com/apereo/cas
---
You received this message because you are subscribed to the Google Groups "CAS Community" group.

To unsubscribe from this group and stop receiving emails from it, send an email to cas-user+unsubscribe@apereo.org.

To view this discussion on the web visit https://groups.google.com/a/apereo.org/d/msgid/cas-user/CAE7KU87xd5oSOx0WuudYeVEAYAOg07m_aTgRj%2Bd%3D5OYSEZMxVA%40mail.gmail.com.

--
- CAS gitter chatroom: https://gitter.im/apereo/cas
- CAS mailing list guidelines: https://apereo.github.io/cas/Mailing-Lists.html
- CAS documentation website: https://apereo.github.io/cas
- CAS project website: https://github.com/apereo/cas
---
You received this message because you are subscribed to the Google Groups "CAS Community" group.

To unsubscribe from this group and stop receiving emails from it, send an email to cas-user+unsubscribe@apereo.org.
To view this discussion on the web visit https://groups.google.com/a/apereo.org/d/msgid/cas-user/DB3261E4-3A86-4C13-9743-102E3F2C475C%40wwu.edu.

[Daniel Fisher]

On Mon, Jul 10, 2017 at 12:44 PM, Carlos Fernandez <cfer...@sju.edu> wrote:

2017-07-10 12:26:33,172 WARN [org.ldaptive.pool.BlockingConnectionPool] - <connection failed check out validation: org.ldaptive.pool.AbstractConnectionPool$DefaultPooledConnectionProxy@3b167a90>

Some debug logs for org.ldaptive may shed some light on this. Or take a look at your LDAP logs to see why validation is failing.

--Daniel Fisher

 

[Carlos Fernandez]

I included a link to the logs here: https://drive.google.com/a/sju.edu/file/d/0B-j8Pz4AXloHczFURXdhaGYwU1E/view?usp=drive_web

Basically it looks like this:

---8<---
2017-07-10 13:02:40,170 DEBUG [org.apereo.cas.authentication.LdapAuthenticationHandler] - <Attempting LDAP authentication for jb617017>
2017-07-10 13:02:40,171 DEBUG [org.ldaptive.auth.FormatDnResolver] - <Formatting DN for jb617017 with uid=%s,ou=people,o=sju.edu>
2017-07-10 13:02:40,171 DEBUG [org.ldaptive.auth.Authenticator] - <authenticate dn=uid=jb617017,ou=people,o=sju.edu with request=[org.ldaptive.auth.AuthenticationRequest@1587638954::user=[org.ldaptive.auth.User@1520364966::identifier=jb617017, context=null], returnAttributes=[udcid, uid, employeeType, mail, displayName, givenName, departmentNumber, pswUserName, sn, employeeNumber]]>
2017-07-10 13:02:40,171 DEBUG [org.ldaptive.auth.PooledBindAuthenticationHandler] - <authenticate criteria=[org.ldaptive.auth.AuthenticationCriteria@530348177::dn=uid=jb617017,ou=people,o=sju.edu, authenticationRequest=[org.ldaptive.auth.AuthenticationRequest@2074611074::user=[org.ldaptive.auth.User@1520364966::identifier=jb617017, context=null], returnAttributes=[udcid, uid, employeeType, mail, displayName, givenName, departmentNumber, pswUserName, sn, employeeNumber, udcid, uid, employeeType, mail, displayName, givenName, departmentNumber, pswUserName, sn, employeeNumber]]]>
2017-07-10 13:02:40,171 DEBUG [org.ldaptive.SearchOperation] - <execute request=[org.ldaptive.SearchRequest@600881066::baseDn=, searchFilter=[org.ldaptive.SearchFilter@1642584434::filter=(objectClass=*), parameters={}], returnAttributes=[1.1], searchScope=OBJECT, timeLimit=PT0S, sizeLimit=1, derefAliases=null, typesOnly=false, binaryAttributes=null, sortBehavior=UNORDERED, searchEntryHandlers=null, searchReferenceHandlers=null, controls=null, referralHandler=null, intermediateResponseHandlers=null] with connection=[org.ldaptive.DefaultConnectionFactory$DefaultConnection@1236378265::config=[org.ldaptive.ConnectionConfig@2142472158::ldapUrl=ldaps://axldap.sju.edu, connectTimeout=PT1H23M20S, responseTimeout=null, sslConfig=[org.ldaptive.ssl.SslConfig@1154240951::credentialConfig=[org.ldaptive.ssl.X509CredentialConfig@-747746929::trustCertificates=file:/etc/cas/credentials/axldap.crt, authenticationCertificate=null, authenticationKey=null], trustManagers=null, enabledCipherSuites=null, enabledProtocols=null, handshakeCompletedListeners=null], useSSL=true, useStartTLS=false, connectionInitializer=null, connectionStrategy=org.ldaptive.DefaultConnectionStrategy@22c0dfad], providerConnectionFactory=[org.ldaptive.provider.jndi.JndiConnectionFactory@412312959::metadata=[ldapUrl=ldaps://axldap.sju.edu, count=1], environment={java.naming.ldap.factory.socket=org.ldaptive.ssl.ThreadLocalTLSSocketFactory, com.sun.jndi.ldap.connect.timeout=5000000, java.naming.ldap.version=3, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory, java.naming.security.protocol=ssl}, classLoader=null, providerConfig=[org.ldaptive.provider.jndi.JndiProviderConfig@2080218308::operationExceptionResultCodes=[PROTOCOL_ERROR, SERVER_DOWN], properties={}, controlProcessor=org.ldaptive.provider.ControlProcessor@5d1a2be5, environment=null, tracePackets=null, removeDnUrls=true, searchIgnoreResultCodes=[TIME_LIMIT_EXCEEDED, SIZE_LIMIT_EXCEEDED, PARTIAL_RESULTS], classLoader=null, sslSocketFactory=null, hostnameVerifier=null]], providerConnection=org.ldaptive.provider.jndi.JndiConnection@7983aa5c]>
2017-07-10 13:02:40,182 DEBUG [org.ldaptive.SearchOperation] - <execute response=[org.ldaptive.Response@2058915982::result=[org.ldaptive.SearchResult@-1951941189::entries=[[dn=[], responseControls=null, messageId=-1]], references=[]], resultCode=SUCCESS, message=null, matchedDn=null, responseControls=null, referralURLs=null, messageId=-1] for request=[org.ldaptive.SearchRequest@600881066::baseDn=, searchFilter=[org.ldaptive.SearchFilter@1642584434::filter=(objectClass=*), parameters={}], returnAttributes=[1.1], searchScope=OBJECT, timeLimit=PT0S, sizeLimit=1, derefAliases=null, typesOnly=false, binaryAttributes=null, sortBehavior=UNORDERED, searchEntryHandlers=null, searchReferenceHandlers=null, controls=null, referralHandler=null, intermediateResponseHandlers=null] with connection=[org.ldaptive.DefaultConnectionFactory$DefaultConnection@1236378265::config=[org.ldaptive.ConnectionConfig@2142472158::ldapUrl=ldaps://axldap.sju.edu, connectTimeout=PT1H23M20S, responseTimeout=null, sslConfig=[org.ldaptive.ssl.SslConfig@1154240951::credentialConfig=[org.ldaptive.ssl.X509CredentialConfig@-747746929::trustCertificates=file:/etc/cas/credentials/axldap.crt, authenticationCertificate=null, authenticationKey=null], trustManagers=null, enabledCipherSuites=null, enabledProtocols=null, handshakeCompletedListeners=null], useSSL=true, useStartTLS=false, connectionInitializer=null, connectionStrategy=org.ldaptive.DefaultConnectionStrategy@22c0dfad], providerConnectionFactory=[org.ldaptive.provider.jndi.JndiConnectionFactory@412312959::metadata=[ldapUrl=ldaps://axldap.sju.edu, count=1], environment={java.naming.ldap.factory.socket=org.ldaptive.ssl.ThreadLocalTLSSocketFactory, com.sun.jndi.ldap.connect.timeout=5000000, java.naming.ldap.version=3, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory, java.naming.security.protocol=ssl}, classLoader=null, providerConfig=[org.ldaptive.provider.jndi.JndiProviderConfig@2080218308::operationExceptionResultCodes=[PROTOCOL_ERROR, SERVER_DOWN], properties={}, controlProcessor=org.ldaptive.provider.ControlProcessor@5d1a2be5, environment=null, tracePackets=null, removeDnUrls=true, searchIgnoreResultCodes=[TIME_LIMIT_EXCEEDED, SIZE_LIMIT_EXCEEDED, PARTIAL_RESULTS], classLoader=null, sslSocketFactory=null, hostnameVerifier=null]], providerConnection=org.ldaptive.provider.jndi.JndiConnection@7983aa5c]>
2017-07-10 13:02:40,182 DEBUG [org.ldaptive.BindOperation] - <execute request=[org.ldaptive.BindRequest@1840527521::bindDn=uid=jb617017,ou=people,o=sju.edu, saslConfig=null, controls=[[org.ldaptive.control.PasswordPolicyControl@-350057371::criticality=false, timeBeforeExpiration=0, graceAuthNsRemaining=0, error=null]], referralHandler=null, intermediateResponseHandlers=null] with connection=[org.ldaptive.DefaultConnectionFactory$DefaultConnection@1236378265::config=[org.ldaptive.ConnectionConfig@2142472158::ldapUrl=ldaps://axldap.sju.edu, connectTimeout=PT1H23M20S, responseTimeout=null, sslConfig=[org.ldaptive.ssl.SslConfig@1154240951::credentialConfig=[org.ldaptive.ssl.X509CredentialConfig@-747746929::trustCertificates=file:/etc/cas/credentials/axldap.crt, authenticationCertificate=null, authenticationKey=null], trustManagers=null, enabledCipherSuites=null, enabledProtocols=null, handshakeCompletedListeners=null], useSSL=true, useStartTLS=false, connectionInitializer=null, connectionStrategy=org.ldaptive.DefaultConnectionStrategy@22c0dfad], providerConnectionFactory=[org.ldaptive.provider.jndi.JndiConnectionFactory@412312959::metadata=[ldapUrl=ldaps://axldap.sju.edu, count=1], environment={java.naming.ldap.factory.socket=org.ldaptive.ssl.ThreadLocalTLSSocketFactory, com.sun.jndi.ldap.connect.timeout=5000000, java.naming.ldap.version=3, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory, java.naming.security.protocol=ssl}, classLoader=null, providerConfig=[org.ldaptive.provider.jndi.JndiProviderConfig@2080218308::operationExceptionResultCodes=[PROTOCOL_ERROR, SERVER_DOWN], properties={}, controlProcessor=org.ldaptive.provider.ControlProcessor@5d1a2be5, environment=null, tracePackets=null, removeDnUrls=true, searchIgnoreResultCodes=[TIME_LIMIT_EXCEEDED, SIZE_LIMIT_EXCEEDED, PARTIAL_RESULTS], classLoader=null, sslSocketFactory=null, hostnameVerifier=null]], providerConnection=org.ldaptive.provider.jndi.JndiConnection@7983aa5c]>
2017-07-10 13:02:40,189 DEBUG [org.ldaptive.BindOperation] - <execute response=[org.ldaptive.Response@1635611633::result=null, resultCode=SUCCESS, message=null, matchedDn=null, responseControls=[[org.ldaptive.control.PasswordPolicyControl@-350057371::criticality=false, timeBeforeExpiration=0, graceAuthNsRemaining=0, error=null]], referralURLs=null, messageId=-1] for request=[org.ldaptive.BindRequest@1840527521::bindDn=uid=jb617017,ou=people,o=sju.edu, saslConfig=null, controls=[[org.ldaptive.control.PasswordPolicyControl@-350057371::criticality=false, timeBeforeExpiration=0, graceAuthNsRemaining=0, error=null]], referralHandler=null, intermediateResponseHandlers=null] with connection=[org.ldaptive.DefaultConnectionFactory$DefaultConnection@1236378265::config=[org.ldaptive.ConnectionConfig@2142472158::ldapUrl=ldaps://axldap.sju.edu, connectTimeout=PT1H23M20S, responseTimeout=null, sslConfig=[org.ldaptive.ssl.SslConfig@1154240951::credentialConfig=[org.ldaptive.ssl.X509CredentialConfig@-747746929::trustCertificates=file:/etc/cas/credentials/axldap.crt, authenticationCertificate=null, authenticationKey=null], trustManagers=null, enabledCipherSuites=null, enabledProtocols=null, handshakeCompletedListeners=null], useSSL=true, useStartTLS=false, connectionInitializer=null, connectionStrategy=org.ldaptive.DefaultConnectionStrategy@22c0dfad], providerConnectionFactory=[org.ldaptive.provider.jndi.JndiConnectionFactory@412312959::metadata=[ldapUrl=ldaps://axldap.sju.edu, count=1], environment={java.naming.ldap.factory.socket=org.ldaptive.ssl.ThreadLocalTLSSocketFactory, com.sun.jndi.ldap.connect.timeout=5000000, java.naming.ldap.version=3, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory, java.naming.security.protocol=ssl}, classLoader=null, providerConfig=[org.ldaptive.provider.jndi.JndiProviderConfig@2080218308::operationExceptionResultCodes=[PROTOCOL_ERROR, SERVER_DOWN], properties={}, controlProcessor=org.ldaptive.provider.ControlProcessor@5d1a2be5, environment=null, tracePackets=null, removeDnUrls=true, searchIgnoreResultCodes=[TIME_LIMIT_EXCEEDED, SIZE_LIMIT_EXCEEDED, PARTIAL_RESULTS], classLoader=null, sslSocketFactory=null, hostnameVerifier=null]], providerConnection=org.ldaptive.provider.jndi.JndiConnection@7983aa5c]>
2017-07-10 13:02:40,189 DEBUG [org.ldaptive.auth.PooledBindAuthenticationHandler] - <authenticate response=[org.ldaptive.auth.AuthenticationHandlerResponse@88667336::connection=[org.ldaptive.DefaultConnectionFactory$DefaultConnection@1236378265::config=[org.ldaptive.ConnectionConfig@2142472158::ldapUrl=ldaps://axldap.sju.edu, connectTimeout=PT1H23M20S, responseTimeout=null, sslConfig=[org.ldaptive.ssl.SslConfig@1154240951::credentialConfig=[org.ldaptive.ssl.X509CredentialConfig@-747746929::trustCertificates=file:/etc/cas/credentials/axldap.crt, authenticationCertificate=null, authenticationKey=null], trustManagers=null, enabledCipherSuites=null, enabledProtocols=null, handshakeCompletedListeners=null], useSSL=true, useStartTLS=false, connectionInitializer=null, connectionStrategy=org.ldaptive.DefaultConnectionStrategy@22c0dfad], providerConnectionFactory=[org.ldaptive.provider.jndi.JndiConnectionFactory@412312959::metadata=[ldapUrl=ldaps://axldap.sju.edu, count=1], environment={java.naming.ldap.factory.socket=org.ldaptive.ssl.ThreadLocalTLSSocketFactory, com.sun.jndi.ldap.connect.timeout=5000000, java.naming.ldap.version=3, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory, java.naming.security.protocol=ssl}, classLoader=null, providerConfig=[org.ldaptive.provider.jndi.JndiProviderConfig@2080218308::operationExceptionResultCodes=[PROTOCOL_ERROR, SERVER_DOWN], properties={}, controlProcessor=org.ldaptive.provider.ControlProcessor@5d1a2be5, environment=null, tracePackets=null, removeDnUrls=true, searchIgnoreResultCodes=[TIME_LIMIT_EXCEEDED, SIZE_LIMIT_EXCEEDED, PARTIAL_RESULTS], classLoader=null, sslSocketFactory=null, hostnameVerifier=null]], providerConnection=org.ldaptive.provider.jndi.JndiConnection@7983aa5c], result=true, resultCode=SUCCESS, message=null, controls=[[org.ldaptive.control.PasswordPolicyControl@-350057371::criticality=false, timeBeforeExpiration=0, graceAuthNsRemaining=0, error=null]]] for criteria=[org.ldaptive.auth.AuthenticationCriteria@530348177::dn=uid=jb617017,ou=people,o=sju.edu, authenticationRequest=[org.ldaptive.auth.AuthenticationRequest@2074611074::user=[org.ldaptive.auth.User@1520364966::identifier=jb617017, context=null], returnAttributes=[udcid, uid, employeeType, mail, displayName, givenName, departmentNumber, pswUserName, sn, employeeNumber, udcid, uid, employeeType, mail, displayName, givenName, departmentNumber, pswUserName, sn, employeeNumber]]]>
2017-07-10 13:02:40,189 DEBUG [org.ldaptive.auth.PooledSearchEntryResolver] - <resolve criteria=[org.ldaptive.auth.AuthenticationCriteria@530348177::dn=uid=jb617017,ou=people,o=sju.edu, authenticationRequest=[org.ldaptive.auth.AuthenticationRequest@2074611074::user=[org.ldaptive.auth.User@1520364966::identifier=jb617017, context=null], returnAttributes=[udcid, uid, employeeType, mail, displayName, givenName, departmentNumber, pswUserName, sn, employeeNumber, udcid, uid, employeeType, mail, displayName, givenName, departmentNumber, pswUserName, sn, employeeNumber]]]>
2017-07-10 13:02:40,190 DEBUG [org.ldaptive.SearchOperation] - <execute request=[org.ldaptive.SearchRequest@600881066::baseDn=, searchFilter=[org.ldaptive.SearchFilter@1642584434::filter=(objectClass=*), parameters={}], returnAttributes=[1.1], searchScope=OBJECT, timeLimit=PT0S, sizeLimit=1, derefAliases=null, typesOnly=false, binaryAttributes=null, sortBehavior=UNORDERED, searchEntryHandlers=null, searchReferenceHandlers=null, controls=null, referralHandler=null, intermediateResponseHandlers=null] with connection=[org.ldaptive.DefaultConnectionFactory$DefaultConnection@716181532::config=[org.ldaptive.ConnectionConfig@1003104271::ldapUrl=ldaps://axldap.sju.edu, connectTimeout=PT1H23M20S, responseTimeout=null, sslConfig=[org.ldaptive.ssl.SslConfig@2004319975::credentialConfig=[org.ldaptive.ssl.X509CredentialConfig@-747746929::trustCertificates=file:/etc/cas/credentials/axldap.crt, authenticationCertificate=null, authenticationKey=null], trustManagers=null, enabledCipherSuites=null, enabledProtocols=null, handshakeCompletedListeners=null], useSSL=true, useStartTLS=false, connectionInitializer=null, connectionStrategy=org.ldaptive.DefaultConnectionStrategy@7d9f6903], providerConnectionFactory=[org.ldaptive.provider.jndi.JndiConnectionFactory@1060322508::metadata=[ldapUrl=ldaps://axldap.sju.edu, count=1], environment={java.naming.ldap.factory.socket=org.ldaptive.ssl.ThreadLocalTLSSocketFactory, com.sun.jndi.ldap.connect.timeout=5000000, java.naming.ldap.version=3, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory, java.naming.security.protocol=ssl}, classLoader=null, providerConfig=[org.ldaptive.provider.jndi.JndiProviderConfig@1431560565::operationExceptionResultCodes=[PROTOCOL_ERROR, SERVER_DOWN], properties={}, controlProcessor=org.ldaptive.provider.ControlProcessor@191f3d7e, environment=null, tracePackets=null, removeDnUrls=true, searchIgnoreResultCodes=[TIME_LIMIT_EXCEEDED, SIZE_LIMIT_EXCEEDED, PARTIAL_RESULTS], classLoader=null, sslSocketFactory=null, hostnameVerifier=null]], providerConnection=null]>
2017-07-10 13:02:40,190 DEBUG [org.ldaptive.pool.SearchValidator] - <validation failed for search request [org.ldaptive.SearchRequest@600881066::baseDn=, searchFilter=[org.ldaptive.SearchFilter@1642584434::filter=(objectClass=*), parameters={}], returnAttributes=[1.1], searchScope=OBJECT, timeLimit=PT0S, sizeLimit=1, derefAliases=null, typesOnly=false, binaryAttributes=null, sortBehavior=UNORDERED, searchEntryHandlers=null, searchReferenceHandlers=null, controls=null, referralHandler=null, intermediateResponseHandlers=null]>
java.lang.IllegalStateException: Connection is not open
    at org.ldaptive.DefaultConnectionFactory$DefaultConnection.getProviderConnection(DefaultConnectionFactory.java:244) ~[ldaptive-1.2.0.jar:?]
    at org.ldaptive.SearchOperation.executeSearch(SearchOperation.java:103) ~[ldaptive-1.2.0.jar:?]
    at org.ldaptive.SearchOperation.invoke(SearchOperation.java:85) ~[ldaptive-1.2.0.jar:?]
    at org.ldaptive.SearchOperation.invoke(SearchOperation.java:15) ~[ldaptive-1.2.0.jar:?]
    at org.ldaptive.AbstractOperation.execute(AbstractOperation.java:126) ~[ldaptive-1.2.0.jar:?]
    at org.ldaptive.pool.SearchValidator.validate(SearchValidator.java:82) ~[ldaptive-1.2.0.jar:?]
    at org.ldaptive.pool.SearchValidator.validate(SearchValidator.java:20) ~[ldaptive-1.2.0.jar:?]
    at org.ldaptive.pool.AbstractPool.validate(AbstractPool.java:210) ~[ldaptive-1.2.0.jar:?]
    at org.ldaptive.pool.AbstractConnectionPool.activateAndValidateConnection(AbstractConnectionPool.java:630) ~[ldaptive-1.2.0.jar:?]
    at org.ldaptive.pool.BlockingConnectionPool.getConnection(BlockingConnectionPool.java:151) ~[ldaptive-1.2.0.jar:?]
    at org.ldaptive.pool.PooledConnectionFactory.getConnection(PooledConnectionFactory.java:68) ~[ldaptive-1.2.0.jar:?]
    at org.ldaptive.auth.PooledSearchEntryResolver.performLdapSearch(PooledSearchEntryResolver.java:60) ~[ldaptive-1.2.0.jar:?]
    at org.ldaptive.auth.AbstractSearchEntryResolver.resolve(AbstractSearchEntryResolver.java:321) ~[ldaptive-1.2.0.jar:?]
    at org.ldaptive.auth.Authenticator.resolveEntry(Authenticator.java:393) ~[ldaptive-1.2.0.jar:?]
    at org.ldaptive.auth.Authenticator.authenticate(Authenticator.java:259) ~[ldaptive-1.2.0.jar:?]
...
2017-07-10 13:02:40,190 WARN [org.ldaptive.pool.BlockingConnectionPool] - <connection failed check out validation: org.ldaptive.pool.AbstractConnectionPool$DefaultPooledConnectionProxy@2ab0ee23>
2017-07-10 13:02:40,190 DEBUG [org.ldaptive.pool.BlockingConnectionPool] - <attempt to remove unknown available connection: org.ldaptive.pool.AbstractConnectionPool$DefaultPooledConnectionProxy@2ab0ee23>
2017-07-10 13:02:40,190 INFO [org.ldaptive.pool.BlockingConnectionPool] - <destroyed connection: org.ldaptive.pool.AbstractConnectionPool$DefaultPooledConnectionProxy@2ab0ee23>
2017-07-10 13:02:40,190 DEBUG [org.ldaptive.auth.Authenticator] - <entry resolution failed for resolver=[org.ldaptive.auth.PooledSearchEntryResolver@525244463::factory=[org.ldaptive.pool.PooledConnectionFactory@960299606::pool=[org.ldaptive.pool.BlockingConnectionPool@1932465229::name=null, poolConfig=[org.ldaptive.pool.PoolConfig@322642843::minPoolSize=10, maxPoolSize=200, validateOnCheckIn=false, validateOnCheckOut=true, validatePeriodically=true, validatePeriod=PT5M], activator=null, passivator=org.ldaptive.pool.ClosePassivator@785f5e33, validator=[org.ldaptive.pool.SearchValidator@698469596::searchRequest=[org.ldaptive.SearchRequest@600881066::baseDn=, searchFilter=[org.ldaptive.SearchFilter@1642584434::filter=(objectClass=*), parameters={}], returnAttributes=[1.1], searchScope=OBJECT, timeLimit=PT0S, sizeLimit=1, derefAliases=null, typesOnly=false, binaryAttributes=null, sortBehavior=UNORDERED, searchEntryHandlers=null, searchReferenceHandlers=null, controls=null, referralHandler=null, intermediateResponseHandlers=null]] pruneStrategy=[org.ldaptive.pool.IdlePruneStrategy@572991705::prunePeriod=PT5M, idleTime=PT5M], connectOnCreate=true, connectionFactory=[org.ldaptive.DefaultConnectionFactory@1749737725::provider=org.ldaptive.provider.jndi.JndiProvider@6a669501, config=[org.ldaptive.ConnectionConfig@1003104271::ldapUrl=ldaps://axldap.sju.edu, connectTimeout=PT1H23M20S, responseTimeout=null, sslConfig=[org.ldaptive.ssl.SslConfig@2004319975::credentialConfig=[org.ldaptive.ssl.X509CredentialConfig@-747746929::trustCertificates=file:/etc/cas/credentials/axldap.crt, authenticationCertificate=null, authenticationKey=null], trustManagers=null, enabledCipherSuites=null, enabledProtocols=null, handshakeCompletedListeners=null], useSSL=true, useStartTLS=false, connectionInitializer=null, connectionStrategy=org.ldaptive.DefaultConnectionStrategy@7d9f6903]], initialized=true, availableCount=6, activeCount=0]], baseDn=ou=people,o=sju.edu, userFilter=null, userFilterParameters=null, allowMultipleEntries=false, subtreeSearch=true, derefAliases=null, referralHandler=null, searchEntryHandlers=null]>
org.ldaptive.pool.ValidationException: Validation of connection failed
    at org.ldaptive.pool.AbstractConnectionPool.activateAndValidateConnection(AbstractConnectionPool.java:633) ~[ldaptive-1.2.0.jar:?]
    at org.ldaptive.pool.BlockingConnectionPool.getConnection(BlockingConnectionPool.java:151) ~[ldaptive-1.2.0.jar:?]
    at org.ldaptive.pool.PooledConnectionFactory.getConnection(PooledConnectionFactory.java:68) ~[ldaptive-1.2.0.jar:?]
    at org.ldaptive.auth.PooledSearchEntryResolver.performLdapSearch(PooledSearchEntryResolver.java:60) ~[ldaptive-1.2.0.jar:?]
    at org.ldaptive.auth.AbstractSearchEntryResolver.resolve(AbstractSearchEntryResolver.java:321) ~[ldaptive-1.2.0.jar:?]
    at org.ldaptive.auth.Authenticator.resolveEntry(Authenticator.java:393) ~[ldaptive-1.2.0.jar:?]
    at org.ldaptive.auth.Authenticator.authenticate(Authenticator.java:259) ~[ldaptive-1.2.0.jar:?]
    at org.ldaptive.auth.Authenticator.authenticate(Authenticator.java:224) ~[ldaptive-1.2.0.jar:?]
...

---8<---

The LDAP server isn't mine, and the fellow who manages it was out of the office today. I'll ask him to check tomorrow.

Best regards,
--
Carlos M. Fernández
Enterprise Systems Manager
Saint Joseph’s University
Philadelphia PA 19131
T: +1 610 660 1501

--

- CAS gitter chatroom: https://gitter.im/apereo/cas
- CAS mailing list guidelines: https://apereo.github.io/cas/Mailing-Lists.html
- CAS documentation website: https://apereo.github.io/cas
- CAS project website: https://github.com/apereo/cas
---
You received this message because you are subscribed to the Google Groups "CAS Community" group.
To unsubscribe from this group and stop receiving emails from it, send an email to cas-user+unsubscribe@apereo.org.

To view this discussion on the web visit https://groups.google.com/a/apereo.org/d/msgid/cas-user/CAFC6YwR5m2%2BAFZMwx8H8UYpsYUGHMwxq7G9km0jWE9HYGWm-dQ%40mail.gmail.com.

[Carlos Fernandez]

Follow-up: I bit the bullet and changed the LDAP handler type to AUTHENTICATED, stuffed it with the bind DN used by another application, and set the pool passivator to BIND. Now all authentication attempts and attribute resolutions work properly.

Best regards,
--
Carlos M. Fernández
Enterprise Systems Manager
Saint Joseph’s University
Philadelphia PA 19131
T: +1 610 660 1501

To unsubscribe from this group and stop receiving emails from it, send an email to cas-user+u...@apereo.org.

[Tom Poage]

> On Jul 10, 2017, at 1:02 PM, Tim McLaughlin <Tim.McL...@wwu.edu> wrote:
>
> I'm checking this out now. I'm on 5.0.3 so I'll rebuild with 5.0.7 and see if we still see the issue...
>
> I've added:
> cas.authn.ldap[0].poolPassivator=CLOSE

Does this break connection pooling by presumably closing a connection when done (vs. BIND)?

Tom.

[Tim McLaughlin]

I was waiting to report so that I could see how it fared over time, but I have also had success going to 5.0.7 (was on 5.0.3) and using the poolPassivator = BIND setting.  We were already using the bindDN as our users are spread across OUs.

 

Thanks much for finding the issue reports that led to this fix!

 

Tim

 

From: <cas-...@apereo.org> on behalf of Carlos Fernandez <cfer...@sju.edu>

Reply-To: "cas-...@apereo.org" <cas-...@apereo.org>
Date: Monday, July 10, 2017 at 21:37
To: "cas-...@apereo.org" <cas-...@apereo.org>

To view this discussion on the web visit https://groups.google.com/a/apereo.org/d/msgid/cas-user/CAE7KU84cY_krQ3y0YENoHChu4Hzc73ZcKvoX6DiOR7vR9uZesA%40mail.gmail.com.

[Tim McLaughlin]

I ended up going with poolPassivator=BIND, based on the findings of Carlos Fernandez in the thread.
Apparently as long as you are using a bindDn and bindCredential (as opposed to direct authentication) this works. I can confirm that it seems to have cleared up the issue we had been seeing.

Tim

--
- CAS gitter chatroom: https://gitter.im/apereo/cas
- CAS mailing list guidelines: https://apereo.github.io/cas/Mailing-Lists.html
- CAS documentation website: https://apereo.github.io/cas
- CAS project website: https://github.com/apereo/cas
---
You received this message because you are subscribed to the Google Groups "CAS Community" group.
To unsubscribe from this group and stop receiving emails from it, send an email to cas-user+u...@apereo.org.

To view this discussion on the web visit https://groups.google.com/a/apereo.org/d/msgid/cas-user/86005518-0AC5-41E2-BC89-9D04EA672604%40ucdavis.edu.

[Daniel Fisher]

On Mon, Jul 10, 2017 at 6:21 PM, Carlos Fernandez <cfer...@sju.edu> wrote:

2017-07-10 13:02:40,171 DEBUG [org.ldaptive.auth.PooledBindAuthenticationHandler] - <authenticate criteria=[org.ldaptive.auth.AuthenticationCriteria@530348177::dn=uid=jb617017,ou=people,o=sju.edu, authenticationRequest=[org.ldaptive.auth.AuthenticationRequest@2074611074::user=[org.ldaptive.auth.User@1520364966::identifier=jb617017, context=null], returnAttributes=[udcid, uid, employeeType, mail, displayName, givenName, departmentNumber, pswUserName, sn, employeeNumber, udcid, uid, employeeType, mail, displayName, givenName, departmentNumber, pswUserName, sn, employeeNumber]]]>

Did you list all these attributes twice or is CAS duplicating them?

  

2017-07-10 13:02:40,182 DEBUG [org.ldaptive.SearchOperation] - <execute response=[org.ldaptive.Response@2058915982::result=[org.ldaptive.SearchResult@-1951941189::entries=[[dn=[], responseControls=null, messageId=-1]], references=[]], resultCode=SUCCESS, message=null, matchedDn=null, responseControls=null, referralURLs=null, messageId=-1] for request=[org.ldaptive.SearchRequest@600881066::baseDn=, searchFilter=[org.ldaptive.SearchFilter@1642584434::filter=(objectClass=*), parameters={}], returnAttributes=[1.1], searchScope=OBJECT, timeLimit=PT0S, sizeLimit=1, derefAliases=null, typesOnly=false, binaryAttributes=null, sortBehavior=UNORDERED, searchEntryHandlers=null, searchReferenceHandlers=null, controls=null, referralHandler=null, intermediateResponseHandlers=null]

Here's the successful connection validation.

 

2017-07-10 13:02:40,189 DEBUG [org.ldaptive.BindOperation] - <execute response=[org.ldaptive.Response@1635611633::result=null, resultCode=SUCCESS, message=null, matchedDn=null, responseControls=[[org.ldaptive.control.PasswordPolicyControl@-350057371::criticality=false, timeBeforeExpiration=0, graceAuthNsRemaining=0, error=null]], referralURLs=null, messageId=-1] for request=[org.ldaptive.BindRequest@1840527521::bindDn=uid=jb617017,ou=people,o=sju.edu, saslConfig=null, controls=[[org.ldaptive.control.PasswordPolicyControl@-350057371::criticality=false, timeBeforeExpiration=0, graceAuthNsRemaining=0, error=null]], referralHandler=null, intermediateResponseHandlers=null] with connection=[org.ldaptive.DefaultConnectionFactory$DefaultConnection@1236378265::config=[org.ldaptive.ConnectionConfig@2142472158::ldapUrl=ldaps://axldap.sju.edu, connectTimeout=PT1H23M20S, responseTimeout=null, sslConfig=[org.ldaptive.ssl.SslConfig@1154240951::credentialConfig=[org.ldaptive.ssl.X509CredentialConfig@-747746929::trustCertificates=file:/etc/cas/credentials/axldap.crt, authenticationCertificate=null, authenticationKey=null], trustManagers=null, enabledCipherSuites=null, enabledProtocols=null, handshakeCompletedListeners=null], useSSL=true, useStartTLS=false, connectionInitializer=null, connectionStrategy=org.ldaptive.DefaultConnectionStrategy@22c0dfad], providerConnectionFactory=[org.ldaptive.provider.jndi.JndiConnectionFactory@412312959::metadata=[ldapUrl=ldaps://axldap.sju.edu, count=1], environment={java.naming.ldap.factory.socket=org.ldaptive.ssl.ThreadLocalTLSSocketFactory, com.sun.jndi.ldap.connect.timeout=5000000, java.naming.ldap.version=3, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory, java.naming.security.protocol=ssl}, classLoader=null, providerConfig=[org.ldaptive.provider.jndi.JndiProviderConfig@2080218308::operationExceptionResultCodes=[PROTOCOL_ERROR, SERVER_DOWN], properties={}, controlProcessor=org.ldaptive.provider.ControlProcessor@5d1a2be5, environment=null, tracePackets=null, removeDnUrls=true, searchIgnoreResultCodes=[TIME_LIMIT_EXCEEDED, SIZE_LIMIT_EXCEEDED, PARTIAL_RESULTS], classLoader=null, sslSocketFactory=null, hostnameVerifier=null]], providerConnection=org.ldaptive.provider.jndi.JndiConnection@7983aa5c]>

Here's the successful bind. Although a connectTimeout of PT1H23M20S is either a configuration mistake or a CAS parsing bug.

 

2017-07-10 13:02:40,189 DEBUG [org.ldaptive.auth.PooledSearchEntryResolver] - <resolve criteria=[org.ldaptive.auth.AuthenticationCriteria@530348177::dn=uid=jb617017,ou=people,o=sju.edu, authenticationRequest=[org.ldaptive.auth.AuthenticationRequest@2074611074::user=[org.ldaptive.auth.User@1520364966::identifier=jb617017, context=null], returnAttributes=[udcid, uid, employeeType, mail, displayName, givenName, departmentNumber, pswUserName, sn, employeeNumber, udcid, uid, employeeType, mail, displayName, givenName, departmentNumber, pswUserName, sn, employeeNumber]]]>

I'm confused why this search entry resolver is running. Perhaps it's configuration mistake, perhaps CAS is leveraging the DN resolver in a way I don't understand.

 

java.lang.IllegalStateException: Connection is not open

Here's the connection validation failing, presumably because of the close passivator. There's definitely some strange stuff going on here. I see you changed your config and got it working, however it should be possible to get the behavior you want with the direct authenticator. You should probably file a feature request and ask for an anonymous bind to be performed when using the BIND option with no bindDN property.

--Daniel Fisher

[Carlos Fernandez]

Thanks for the input, Daniel.

> Did you list all these attributes twice or is CAS duplicating them?

I specified them only once in the CAS properties file. I don't know why it's duplicating them either.

> Although a connectTimeout of PT1H23M20S is either a configuration mistake or a CAS parsing bug.

I used the default connectTimeout of 5000 (milliseconds, I hope? the oficial docs don't specify [1]). I should probably change that to the notation expected by ldaptive.

> You should probably file a feature request and ask for an anonymous bind to be performed when using the BIND option with no bindDN property.

I will. Thanks!

[1] https://apereo.github.io/cas/5.0.x/installation/Configuration-Properties.html#ldap-authentication

Best regards,
--
Carlos M. Fernández
Enterprise Systems Manager
Saint Joseph’s University
Philadelphia PA 19131
T: +1 610 660 1501

--
- CAS gitter chatroom: https://gitter.im/apereo/cas
- CAS mailing list guidelines: https://apereo.github.io/cas/Mailing-Lists.html
- CAS documentation website: https://apereo.github.io/cas
- CAS project website: https://github.com/apereo/cas
---
You received this message because you are subscribed to the Google Groups "CAS Community" group.
To unsubscribe from this group and stop receiving emails from it, send an email to cas-user+unsubscribe@apereo.org.

To view this discussion on the web visit https://groups.google.com/a/apereo.org/d/msgid/cas-user/CAFC6YwT_kcCFzykj0cqWq9XnQw%3DCqN_%3DTG%3D87rPOzfr_D0ZU4A%40mail.gmail.com.