CAS 4.2.x Password Policy Active Directory (ldaptive)
335 views
Skip to first unread message
Brandon Martin
Oct 25, 2016, 9:51:24 AM10/25/16
to CAS Community
Greetings,
After a little bit of work I was able to get successful AD authentication on CAS 4.2.6. Yay!
I've implemented the password enforcement configs from here: https://apereo.github.io/cas/4.2.x/installation/LDAP-Authentication.html
I'm not seeing any changes, possibly I'm missing a config. When I set a user to needs password reset in AD (PasswordExpired AD Attribute), I simply get "AUTHENTICATION_FAILED" in the response.
In the ldaptive logs, I see this: [LDAP: error code 49 - 80090308: LdapErr: DSID-0C0903CF, comment: AcceptSecurityContext error, data 773, v2580]
I also see the user's dn, and attributes in the log.
Looking up error code 49, it's an invalid credentials response.
We have our own in house developed password reset tool, so CAS just needs to be able to display the errors with a button to navigate to the reset tool. I have the casMustChangePassView.jsp where I'd add our button.
One thing that comes to mind is if CAS/ldaptive doesn't know what attributes to read from AD to determine the password policy errors, but I'm unsure what they would be looking for/need.
DeployerConfigContext.xml
<alias name="ldapPasswordPolicyConfiguration" alias="passwordPolicyConfiguration" />
<bean id="ldapAuthenticationHandler"
class="org.jasig.cas.authentication.LdapAuthenticationHandler"
p:principalIdAttribute="sAMAccountName"
p:passwordPolicyConfiguration-ref="passwordPolicyConfiguration"
c:authenticator-ref="authenticator" >
<property name="principalAttributeMap">
<map>
<entry key="sAMAccountName" value="uid"/>
<entry key="displayName" value="displayName"/>
<entry key="mail" value="mail"/>
<entry key="memberOf" value="memberOf"/>
<entry key="employeeId" value="distinguishedName"/>
<entry key="sn" value="sn"/>
<entry key="givenName" value="givenName"/>
<entry key="telephoneNumber" value="telephoneNumber"/>
</map>
</property>
</bean>
<ldaptive:bind-search-authenticator id="authenticator"
ldapUrl="${ldap.url}"
baseDn="${ldap.baseDn}"
userFilter="${ldap.searchFilter}"
bindDn="${ldap.managerDn}"
bindCredential="${ldap.managerPassword}"
allowMultipleDns="${ldap.allowMultipleDns:false}"
connectTimeout="${ldap.connectTimeout}"
validateOnCheckOut="${ldap.pool.validateOnCheckout}"
failFastInitialize="true"
blockWaitTime="${ldap.pool.blockWaitTime}"
idleTime="${ldap.pool.idleTime}"
maxPoolSize="${ldap.pool.maxSize}"
minPoolSize="${ldap.pool.minSize}"
validatePeriodically="${ldap.pool.validatePeriodically}"
validatePeriod="${ldap.pool.validatePeriod}"
prunePeriod="${ldap.pool.prunePeriod}"
useSSL="${ldap.use.ssl:false}"
subtreeSearch="true"
useStartTLS="${ldap.useStartTLS}"
usePasswordPolicy="${ldap.usePpolicy:true}" />
cas.properties:
password.policy.warningDays=30
# URL to which the user will be redirected to change the password.
password.policy.url=https://iforgot.psd401.net/forgot
# password.policy.warn.attribute.name=attributeName
password.policy.warn.attribute.value=attributeValue
password.policy.warn.display.matched=true
ldap.usePpolicy=true
Let me know if I should post the full ldaptive logs
Misagh Moayyed
Oct 25, 2016, 2:48:00 PM10/25/16
to CAS Community
Share CAS logs please, at DEBUG.
Brandon Martin
Oct 25, 2016, 5:13:10 PM10/25/16
to CAS Community
Okay here we go:
Following the logs, I successfully authenticate, then change the attribute PasswordExpired = True in AD, where another attempt at login fails.
[INFO] Scanning for projects...
[INFO]
[INFO] ------------------------------------------------------------------------
[INFO] Building cas-overlay 1.0
[INFO] ------------------------------------------------------------------------
[INFO]
[INFO] --- maven-clean-plugin:2.5:clean (default-clean) @ cas-overlay ---
[INFO] Deleting /cas-overlay/target
[INFO]
[INFO] --- maven-resources-plugin:2.6:resources (default-resources) @ cas-overlay ---
[INFO] Using 'UTF-8' encoding to copy filtered resources.
[INFO] skip non existing resourceDirectory /cas-overlay/src/main/resources
[INFO]
[INFO] --- maven-compiler-plugin:3.3:compile (default-compile) @ cas-overlay ---
[INFO] No sources to compile
[INFO]
[INFO] --- maven-resources-plugin:2.6:testResources (default-testResources) @ cas-overlay ---
[INFO] Using 'UTF-8' encoding to copy filtered resources.
[INFO] skip non existing resourceDirectory /cas-overlay/src/test/resources
[INFO]
[INFO] --- maven-compiler-plugin:3.3:testCompile (default-testCompile) @ cas-overlay ---
[INFO] No sources to compile
[INFO]
[INFO] --- maven-surefire-plugin:2.12.4:test (default-test) @ cas-overlay ---
[INFO] No tests to run.
[INFO]
[INFO] --- maven-war-plugin:2.6:war (default-war) @ cas-overlay ---
[INFO] Packaging webapp
[INFO] Assembling webapp [cas-overlay] in [/cas-overlay/target/cas]
[INFO] Processing war project
[INFO] Copying webapp resources [/cas-overlay/src/main/webapp]
[INFO] Processing overlay [ id org.jasig.cas:cas-server-webapp]
[INFO] Webapp assembled in [2636 msecs]
[INFO] Building war: /cas-overlay/target/cas.war
[INFO]
[INFO] >>> jetty-maven-plugin:9.3.6.v20151106:run-forked (default-cli) > test-compile @ cas-overlay >>>
[INFO]
[INFO] --- maven-resources-plugin:2.6:resources (default-resources) @ cas-overlay ---
[INFO] Using 'UTF-8' encoding to copy filtered resources.
[INFO] skip non existing resourceDirectory /cas-overlay/src/main/resources
[INFO]
[INFO] --- maven-compiler-plugin:3.3:compile (default-compile) @ cas-overlay ---
[INFO] No sources to compile
[INFO]
[INFO] --- maven-resources-plugin:2.6:testResources (default-testResources) @ cas-overlay ---
[INFO] Using 'UTF-8' encoding to copy filtered resources.
[INFO] skip non existing resourceDirectory /cas-overlay/src/test/resources
[INFO]
[INFO] --- maven-compiler-plugin:3.3:testCompile (default-testCompile) @ cas-overlay ---
[INFO] No sources to compile
[INFO]
[INFO] <<< jetty-maven-plugin:9.3.6.v20151106:run-forked (default-cli) < test-compile @ cas-overlay <<<
[INFO]
[INFO] --- jetty-maven-plugin:9.3.6.v20151106:run-forked (default-cli) @ cas-overlay ---
[INFO] Logging initialized @14540ms
[INFO] Configuring Jetty for project: cas-overlay
[INFO] webAppSourceDirectory not set. Trying src/main/webapp
[INFO] Reload Mechanic: automatic
[INFO] Classes directory /cas-overlay/target/classes does not exist
[INFO] Context path = /cas
[INFO] Tmp directory = /cas-overlay/target/tmp
[INFO] Web defaults = org/eclipse/jetty/webapp/webdefault.xml
[INFO] Web overrides = /cas-overlay/etc/jetty/web.xml
[INFO] Dependent war artifact org.jasig.cas:cas-server-webapp:war:4.2.6
[INFO] web.xml file = null
[INFO] Webapp directory = /cas-overlay/src/main/webapp
SLF4J: Class path contains multiple SLF4J bindings.
SLF4J: Found binding in [jar:file:/root/.m2/repository/org/apache/logging/log4j/log4j-slf4j-impl/2.6.2/log4j-slf4j-impl-2.6.2.jar!/org/slf4j/impl/StaticLoggerBinder.class]
SLF4J: Found binding in [jar:file:/cas-overlay/target/tmp/cas-server-webapp-4_2_6_war1/WEB-INF/lib/cas-server-core-logging-4.2.6.jar!/org/slf4j/impl/StaticLoggerBinder.class]
SLF4J: Found binding in [jar:file:/cas-overlay/target/tmp/cas-server-webapp-4_2_6_war1/WEB-INF/lib/log4j-slf4j-impl-2.6.2.jar!/org/slf4j/impl/StaticLoggerBinder.class]
SLF4J: See http://www.slf4j.org/codes.html#multiple_bindings for an explanation.
SLF4J: Actual binding is of type [org.apache.logging.slf4j.Log4jLoggerFactory]
ERROR StatusLogger No log4j2 configuration file found. Using default configuration: logging only errors to the console.
[INFO] Quickstart generating
[INFO] Started o.e.j.m.p.JettyWebAppContext@3c0e00a8{/cas,[file:///cas-overlay/src/main/webapp/, file:///cas-overlay/target/tmp/cas-server-webapp-4_2_6_war1/],AVAILABLE}{file:///cas-overlay/src/main/webapp/}
[INFO] Stopped o.e.j.m.p.JettyWebAppContext@3c0e00a8{/cas,file:///cas-overlay/src/main/webapp/,UNAVAILABLE}{file:///cas-overlay/src/main/webapp/}
[INFO] Forked process starting
[STDOUT] Listening for transport dt_socket at address: 5000
[STDERR] 2016-10-25 20:58:24.025:INFO::main: Logging initialized @13271ms
[STDERR] 2016-10-25 20:58:24.404:INFO:oejmp.Starter:main: Started Jetty Server
[STDERR] 2016-10-25 20:58:24.412:INFO:oejs.Server:main: jetty-9.3.6.v20151106
[STDERR] SLF4J: Class path contains multiple SLF4J bindings.
[STDERR] SLF4J: Found binding in [jar:file:/root/.m2/repository/org/apache/logging/log4j/log4j-slf4j-impl/2.6.2/log4j-slf4j-impl-2.6.2.jar!/org/slf4j/impl/StaticLoggerBinder.class]
[STDERR] SLF4J: Found binding in [jar:file:/cas-overlay/target/tmp/cas-server-webapp-4_2_6_war1/WEB-INF/lib/cas-server-core-logging-4.2.6.jar!/org/slf4j/impl/StaticLoggerBinder.class]
[STDERR] SLF4J: Found binding in [jar:file:/cas-overlay/target/tmp/cas-server-webapp-4_2_6_war1/WEB-INF/lib/log4j-slf4j-impl-2.6.2.jar!/org/slf4j/impl/StaticLoggerBinder.class]
[STDERR] SLF4J: See http://www.slf4j.org/codes.html#multiple_bindings for an explanation.
[STDERR] SLF4J: Actual binding is of type [org.apache.logging.slf4j.Log4jLoggerFactory]
[STDERR] 2016-10-25 20:58:27.656:INFO:/cas:main: 2 Spring WebApplicationInitializers detected on classpath
[STDOUT] 2016-10-25 20:58:27,686 INFO [org.jasig.cas.support.saml.SamlServletContextListener] - <Starting up servlet application context...>
[STDOUT] 2016-10-25 20:58:27,691 INFO [org.jasig.cas.support.saml.SamlGoogleAppsServletContextListener] - <Starting up servlet application context...>
[STDOUT] 2016-10-25 20:58:27,786 INFO [org.jasig.cas.CasEnvironmentContextListener] - <
[STDOUT] ******************** Welcome to CAS *******************
[STDOUT] CAS Version: 4.2.6
[STDOUT] Build Date/Time: 2016-09-28T12:16:24.000Z
[STDOUT] Java Home: /opt/jdk1.8.0_65/jre
[STDOUT] Java Vendor: Oracle Corporation
[STDOUT] Java Version: 1.8.0_65
[STDOUT] OS Architecture: amd64
[STDOUT] OS Name: Linux
[STDOUT] OS Version: 4.4.20-moby
[STDOUT] *******************************************************
[STDOUT] >
[STDERR] 2016-10-25 20:58:27.845:INFO:/cas:main: Initializing Spring root WebApplicationContext
[STDOUT] 2016-10-25 20:58:33,824 WARN [org.jasig.cas.util.NoOpCipherExecutor] - <[org.jasig.cas.util.NoOpCipherExecutor] does no encryption and may NOT be safe in a production environment. Consider using other choices, such as [org.jasig.cas.util.BaseStringCipherExecutor] that handle encryption, signing and verification of all appropriate values.>
[STDOUT] 2016-10-25 20:58:34,634 INFO [org.jasig.cas.services.DefaultServicesManagerImpl] - <Loaded 2 services from JsonServiceRegistryDao.>
[STDOUT] 2016-10-25 20:58:34,953 INFO [org.jasig.cas.services.DefaultServicesManagerImpl] - <Services manager will reload service definitions every 60 seconds>
[STDOUT] 2016-10-25 20:58:36,848 DEBUG [org.ldaptive.pool.BlockingConnectionPool] - <beginning pool initialization for [org.ldaptive.pool.BlockingConnectionPool@365212068::name=search-pool, poolConfig=[org.ldaptive.pool.PoolConfig@874079440::minPoolSize=3, maxPoolSize=10, validateOnCheckIn=false, validateOnCheckOut=false, validatePeriodically=true, validatePeriod=300], activator=null, passivator=null, validator=[org.ldaptive.pool.SearchValidator@1370856792::searchRequest=[org.ldaptive.SearchRequest@6117248::baseDn=, searchFilter=[org.ldaptive.SearchFilter@1642584434::filter=(objectClass=*), parameters={}], returnAttributes=[1.1], searchScope=OBJECT, timeLimit=0, 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@3522572::prunePeriod=300, idleTime=600], connectOnCreate=true, connectionFactory=[org.ldaptive.DefaultConnectionFactory@1826086004::provider=org.ldaptive.provider.jndi.JndiProvider@6d695ec4, config=[org.ldaptive.ConnectionConfig@542467430::ldapUrl=ldap://xxx.xx.xx.xx, connectTimeout=3000, responseTimeout=-1, sslConfig=null, useSSL=false, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@240055488::bindDn=admin...@peninsula.wednet.edu, bindSaslConfig=null, bindControls=null]]], initialized=false, availableCount=0, activeCount=0]>
[STDOUT] 2016-10-25 20:58:36,866 DEBUG [org.ldaptive.pool.BlockingConnectionPool] - <checking connection pool size >= 3 for [org.ldaptive.pool.BlockingConnectionPool@365212068::name=search-pool, poolConfig=[org.ldaptive.pool.PoolConfig@874079440::minPoolSize=3, maxPoolSize=10, validateOnCheckIn=false, validateOnCheckOut=false, validatePeriodically=true, validatePeriod=300], activator=null, passivator=null, validator=[org.ldaptive.pool.SearchValidator@1370856792::searchRequest=[org.ldaptive.SearchRequest@6117248::baseDn=, searchFilter=[org.ldaptive.SearchFilter@1642584434::filter=(objectClass=*), parameters={}], returnAttributes=[1.1], searchScope=OBJECT, timeLimit=0, 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@3522572::prunePeriod=300, idleTime=600], connectOnCreate=true, connectionFactory=[org.ldaptive.DefaultConnectionFactory@1826086004::provider=org.ldaptive.provider.jndi.JndiProvider@6d695ec4, config=[org.ldaptive.ConnectionConfig@542467430::ldapUrl=ldap://xxx.xx.xx.xx, connectTimeout=3000, responseTimeout=-1, sslConfig=null, useSSL=false, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@240055488::bindDn=admin...@peninsula.wednet.edu, bindSaslConfig=null, bindControls=null]]], initialized=false, availableCount=0, activeCount=0]>
[STDOUT] 2016-10-25 20:58:36,953 DEBUG [org.ldaptive.BindOperation] - <execute request=[org.ldaptive.BindRequest@870869323::bindDn=admin...@peninsula.wednet.edu, saslConfig=null, controls=null, referralHandler=null, intermediateResponseHandlers=null] with connection=[org.ldaptive.DefaultConnectionFactory$DefaultConnection@1338446903::config=[org.ldaptive.ConnectionConfig@542467430::ldapUrl=ldap://xxx.xx.xx.xx, connectTimeout=3000, responseTimeout=-1, sslConfig=null, useSSL=false, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@240055488::bindDn=admin...@peninsula.wednet.edu, bindSaslConfig=null, bindControls=null]], providerConnectionFactory=[org.ldaptive.provider.jndi.JndiConnectionFactory@1975607158::metadata=[ldapUrl=ldap://xxx.xx.xx.xx, count=1], environment={com.sun.jndi.ldap.connect.timeout=3000, java.naming.ldap.version=3, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory}, providerConfig=[org.ldaptive.provider.jndi.JndiProviderConfig@1662417126::operationExceptionResultCodes=[PROTOCOL_ERROR, SERVER_DOWN], properties={}, connectionStrategy=org.ldaptive.provider.DefaultConnectionStrategy@1344f7fe, controlProcessor=org.ldaptive.provider.ControlProcessor@64d53f0d, environment=null, tracePackets=null, removeDnUrls=true, searchIgnoreResultCodes=[TIME_LIMIT_EXCEEDED, SIZE_LIMIT_EXCEEDED, PARTIAL_RESULTS], sslSocketFactory=null, hostnameVerifier=null]], providerConnection=org.ldaptive.provider.jndi.JndiConnection@1b10f60e]>
[STDOUT] 2016-10-25 20:58:36,986 DEBUG [org.ldaptive.BindOperation] - <execute response=[org.ldaptive.Response@548828006::result=null, resultCode=SUCCESS, message=null, matchedDn=null, responseControls=null, referralURLs=null, messageId=-1] for request=[org.ldaptive.BindRequest@870869323::bindDn=admin...@peninsula.wednet.edu, saslConfig=null, controls=null, referralHandler=null, intermediateResponseHandlers=null] with connection=[org.ldaptive.DefaultConnectionFactory$DefaultConnection@1338446903::config=[org.ldaptive.ConnectionConfig@542467430::ldapUrl=ldap://xxx.xx.xx.xx, connectTimeout=3000, responseTimeout=-1, sslConfig=null, useSSL=false, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@240055488::bindDn=admin...@peninsula.wednet.edu, bindSaslConfig=null, bindControls=null]], providerConnectionFactory=[org.ldaptive.provider.jndi.JndiConnectionFactory@1975607158::metadata=[ldapUrl=ldap://xxx.xx.xx.xx, count=1], environment={com.sun.jndi.ldap.connect.timeout=3000, java.naming.ldap.version=3, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory}, providerConfig=[org.ldaptive.provider.jndi.JndiProviderConfig@1662417126::operationExceptionResultCodes=[PROTOCOL_ERROR, SERVER_DOWN], properties={}, connectionStrategy=org.ldaptive.provider.DefaultConnectionStrategy@1344f7fe, controlProcessor=org.ldaptive.provider.ControlProcessor@64d53f0d, environment=null, tracePackets=null, removeDnUrls=true, searchIgnoreResultCodes=[TIME_LIMIT_EXCEEDED, SIZE_LIMIT_EXCEEDED, PARTIAL_RESULTS], sslSocketFactory=null, hostnameVerifier=null]], providerConnection=org.ldaptive.provider.jndi.JndiConnection@1b10f60e]>
[STDOUT] 2016-10-25 20:58:36,995 INFO [org.ldaptive.pool.BlockingConnectionPool] - <added available connection: org.ldaptive.pool.AbstractConnectionPool$DefaultPooledConnectionProxy@4fc7f23e>
[STDOUT] 2016-10-25 20:58:37,015 DEBUG [org.ldaptive.BindOperation] - <execute request=[org.ldaptive.BindRequest@1474657733::bindDn=admin...@peninsula.wednet.edu, saslConfig=null, controls=null, referralHandler=null, intermediateResponseHandlers=null] with connection=[org.ldaptive.DefaultConnectionFactory$DefaultConnection@1538955593::config=[org.ldaptive.ConnectionConfig@542467430::ldapUrl=ldap://xxx.xx.xx.xx, connectTimeout=3000, responseTimeout=-1, sslConfig=null, useSSL=false, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@240055488::bindDn=admin...@peninsula.wednet.edu, bindSaslConfig=null, bindControls=null]], providerConnectionFactory=[org.ldaptive.provider.jndi.JndiConnectionFactory@342907384::metadata=[ldapUrl=ldap://xxx.xx.xx.xx, count=1], environment={com.sun.jndi.ldap.connect.timeout=3000, java.naming.ldap.version=3, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory}, providerConfig=[org.ldaptive.provider.jndi.JndiProviderConfig@1662417126::operationExceptionResultCodes=[PROTOCOL_ERROR, SERVER_DOWN], properties={}, connectionStrategy=org.ldaptive.provider.DefaultConnectionStrategy@1344f7fe, controlProcessor=org.ldaptive.provider.ControlProcessor@64d53f0d, environment=null, tracePackets=null, removeDnUrls=true, searchIgnoreResultCodes=[TIME_LIMIT_EXCEEDED, SIZE_LIMIT_EXCEEDED, PARTIAL_RESULTS], sslSocketFactory=null, hostnameVerifier=null]], providerConnection=org.ldaptive.provider.jndi.JndiConnection@744fb110]>
[STDOUT] 2016-10-25 20:58:37,032 DEBUG [org.ldaptive.BindOperation] - <execute response=[org.ldaptive.Response@137945353::result=null, resultCode=SUCCESS, message=null, matchedDn=null, responseControls=null, referralURLs=null, messageId=-1] for request=[org.ldaptive.BindRequest@1474657733::bindDn=admin...@peninsula.wednet.edu, saslConfig=null, controls=null, referralHandler=null, intermediateResponseHandlers=null] with connection=[org.ldaptive.DefaultConnectionFactory$DefaultConnection@1538955593::config=[org.ldaptive.ConnectionConfig@542467430::ldapUrl=ldap://xxx.xx.xx.xx, connectTimeout=3000, responseTimeout=-1, sslConfig=null, useSSL=false, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@240055488::bindDn=admin...@peninsula.wednet.edu, bindSaslConfig=null, bindControls=null]], providerConnectionFactory=[org.ldaptive.provider.jndi.JndiConnectionFactory@342907384::metadata=[ldapUrl=ldap://xxx.xx.xx.xx, count=1], environment={com.sun.jndi.ldap.connect.timeout=3000, java.naming.ldap.version=3, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory}, providerConfig=[org.ldaptive.provider.jndi.JndiProviderConfig@1662417126::operationExceptionResultCodes=[PROTOCOL_ERROR, SERVER_DOWN], properties={}, connectionStrategy=org.ldaptive.provider.DefaultConnectionStrategy@1344f7fe, controlProcessor=org.ldaptive.provider.ControlProcessor@64d53f0d, environment=null, tracePackets=null, removeDnUrls=true, searchIgnoreResultCodes=[TIME_LIMIT_EXCEEDED, SIZE_LIMIT_EXCEEDED, PARTIAL_RESULTS], sslSocketFactory=null, hostnameVerifier=null]], providerConnection=org.ldaptive.provider.jndi.JndiConnection@744fb110]>
[STDOUT] 2016-10-25 20:58:37,036 INFO [org.ldaptive.pool.BlockingConnectionPool] - <added available connection: org.ldaptive.pool.AbstractConnectionPool$DefaultPooledConnectionProxy@5bbb7750>
[STDOUT] 2016-10-25 20:58:37,057 DEBUG [org.ldaptive.BindOperation] - <execute request=[org.ldaptive.BindRequest@122110358::bindDn=admin...@peninsula.wednet.edu, saslConfig=null, controls=null, referralHandler=null, intermediateResponseHandlers=null] with connection=[org.ldaptive.DefaultConnectionFactory$DefaultConnection@300836639::config=[org.ldaptive.ConnectionConfig@542467430::ldapUrl=ldap://xxx.xx.xx.xx, connectTimeout=3000, responseTimeout=-1, sslConfig=null, useSSL=false, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@240055488::bindDn=admin...@peninsula.wednet.edu, bindSaslConfig=null, bindControls=null]], providerConnectionFactory=[org.ldaptive.provider.jndi.JndiConnectionFactory@404787971::metadata=[ldapUrl=ldap://xxx.xx.xx.xx, count=1], environment={com.sun.jndi.ldap.connect.timeout=3000, java.naming.ldap.version=3, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory}, providerConfig=[org.ldaptive.provider.jndi.JndiProviderConfig@1662417126::operationExceptionResultCodes=[PROTOCOL_ERROR, SERVER_DOWN], properties={}, connectionStrategy=org.ldaptive.provider.DefaultConnectionStrategy@1344f7fe, controlProcessor=org.ldaptive.provider.ControlProcessor@64d53f0d, environment=null, tracePackets=null, removeDnUrls=true, searchIgnoreResultCodes=[TIME_LIMIT_EXCEEDED, SIZE_LIMIT_EXCEEDED, PARTIAL_RESULTS], sslSocketFactory=null, hostnameVerifier=null]], providerConnection=org.ldaptive.provider.jndi.JndiConnection@57df09a7]>
[STDOUT] 2016-10-25 20:58:37,075 DEBUG [org.ldaptive.BindOperation] - <execute response=[org.ldaptive.Response@1789503803::result=null, resultCode=SUCCESS, message=null, matchedDn=null, responseControls=null, referralURLs=null, messageId=-1] for request=[org.ldaptive.BindRequest@122110358::bindDn=admin...@peninsula.wednet.edu, saslConfig=null, controls=null, referralHandler=null, intermediateResponseHandlers=null] with connection=[org.ldaptive.DefaultConnectionFactory$DefaultConnection@300836639::config=[org.ldaptive.ConnectionConfig@542467430::ldapUrl=ldap://xxx.xx.xx.xx, connectTimeout=3000, responseTimeout=-1, sslConfig=null, useSSL=false, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@240055488::bindDn=admin...@peninsula.wednet.edu, bindSaslConfig=null, bindControls=null]], providerConnectionFactory=[org.ldaptive.provider.jndi.JndiConnectionFactory@404787971::metadata=[ldapUrl=ldap://xxx.xx.xx.xx, count=1], environment={com.sun.jndi.ldap.connect.timeout=3000, java.naming.ldap.version=3, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory}, providerConfig=[org.ldaptive.provider.jndi.JndiProviderConfig@1662417126::operationExceptionResultCodes=[PROTOCOL_ERROR, SERVER_DOWN], properties={}, connectionStrategy=org.ldaptive.provider.DefaultConnectionStrategy@1344f7fe, controlProcessor=org.ldaptive.provider.ControlProcessor@64d53f0d, environment=null, tracePackets=null, removeDnUrls=true, searchIgnoreResultCodes=[TIME_LIMIT_EXCEEDED, SIZE_LIMIT_EXCEEDED, PARTIAL_RESULTS], sslSocketFactory=null, hostnameVerifier=null]], providerConnection=org.ldaptive.provider.jndi.JndiConnection@57df09a7]>
[STDOUT] 2016-10-25 20:58:37,081 INFO [org.ldaptive.pool.BlockingConnectionPool] - <added available connection: org.ldaptive.pool.AbstractConnectionPool$DefaultPooledConnectionProxy@11ef4526>
[STDOUT] 2016-10-25 20:58:37,082 DEBUG [org.ldaptive.pool.BlockingConnectionPool] - <initialized available queue: [org.ldaptive.pool.Queue@136183278::queueType=LIFO, queue=[org.ldaptive.pool.AbstractConnectionPool$DefaultPooledConnectionProxy@11ef4526, org.ldaptive.pool.AbstractConnectionPool$DefaultPooledConnectionProxy@5bbb7750, org.ldaptive.pool.AbstractConnectionPool$DefaultPooledConnectionProxy@4fc7f23e]]>
[STDOUT] 2016-10-25 20:58:37,092 DEBUG [org.ldaptive.pool.BlockingConnectionPool] - <prune pool task scheduled for [org.ldaptive.pool.BlockingConnectionPool@365212068::name=search-pool, poolConfig=[org.ldaptive.pool.PoolConfig@874079440::minPoolSize=3, maxPoolSize=10, validateOnCheckIn=false, validateOnCheckOut=false, validatePeriodically=true, validatePeriod=300], activator=null, passivator=null, validator=[org.ldaptive.pool.SearchValidator@1370856792::searchRequest=[org.ldaptive.SearchRequest@6117248::baseDn=, searchFilter=[org.ldaptive.SearchFilter@1642584434::filter=(objectClass=*), parameters={}], returnAttributes=[1.1], searchScope=OBJECT, timeLimit=0, 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@3522572::prunePeriod=300, idleTime=600], connectOnCreate=true, connectionFactory=[org.ldaptive.DefaultConnectionFactory@1826086004::provider=org.ldaptive.provider.jndi.JndiProvider@6d695ec4, config=[org.ldaptive.ConnectionConfig@542467430::ldapUrl=ldap://xxx.xx.xx.xx, connectTimeout=3000, responseTimeout=-1, sslConfig=null, useSSL=false, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@240055488::bindDn=admin...@peninsula.wednet.edu, bindSaslConfig=null, bindControls=null]]], initialized=false, availableCount=3, activeCount=0]>
[STDOUT] 2016-10-25 20:58:37,111 DEBUG [org.ldaptive.pool.BlockingConnectionPool] - <validate pool task scheduled for [org.ldaptive.pool.BlockingConnectionPool@365212068::name=search-pool, poolConfig=[org.ldaptive.pool.PoolConfig@874079440::minPoolSize=3, maxPoolSize=10, validateOnCheckIn=false, validateOnCheckOut=false, validatePeriodically=true, validatePeriod=300], activator=null, passivator=null, validator=[org.ldaptive.pool.SearchValidator@1370856792::searchRequest=[org.ldaptive.SearchRequest@6117248::baseDn=, searchFilter=[org.ldaptive.SearchFilter@1642584434::filter=(objectClass=*), parameters={}], returnAttributes=[1.1], searchScope=OBJECT, timeLimit=0, 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@3522572::prunePeriod=300, idleTime=600], connectOnCreate=true, connectionFactory=[org.ldaptive.DefaultConnectionFactory@1826086004::provider=org.ldaptive.provider.jndi.JndiProvider@6d695ec4, config=[org.ldaptive.ConnectionConfig@542467430::ldapUrl=ldap://xxx.xx.xx.xx, connectTimeout=3000, responseTimeout=-1, sslConfig=null, useSSL=false, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@240055488::bindDn=admin...@peninsula.wednet.edu, bindSaslConfig=null, bindControls=null]]], initialized=false, availableCount=3, activeCount=0]>
[STDOUT] 2016-10-25 20:58:37,119 INFO [org.ldaptive.pool.BlockingConnectionPool] - <pool initialized [org.ldaptive.pool.BlockingConnectionPool@365212068::name=search-pool, poolConfig=[org.ldaptive.pool.PoolConfig@874079440::minPoolSize=3, maxPoolSize=10, validateOnCheckIn=false, validateOnCheckOut=false, validatePeriodically=true, validatePeriod=300], activator=null, passivator=null, validator=[org.ldaptive.pool.SearchValidator@1370856792::searchRequest=[org.ldaptive.SearchRequest@6117248::baseDn=, searchFilter=[org.ldaptive.SearchFilter@1642584434::filter=(objectClass=*), parameters={}], returnAttributes=[1.1], searchScope=OBJECT, timeLimit=0, 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@3522572::prunePeriod=300, idleTime=600], connectOnCreate=true, connectionFactory=[org.ldaptive.DefaultConnectionFactory@1826086004::provider=org.ldaptive.provider.jndi.JndiProvider@6d695ec4, config=[org.ldaptive.ConnectionConfig@542467430::ldapUrl=ldap://xxx.xx.xx.xx, connectTimeout=3000, responseTimeout=-1, sslConfig=null, useSSL=false, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@240055488::bindDn=admin...@peninsula.wednet.edu, bindSaslConfig=null, bindControls=null]]], initialized=true, availableCount=3, activeCount=0]>
[STDOUT] 2016-10-25 20:58:37,367 DEBUG [org.ldaptive.pool.BlockingConnectionPool] - <beginning pool initialization for [org.ldaptive.pool.BlockingConnectionPool@1980783296::name=bind-pool, poolConfig=[org.ldaptive.pool.PoolConfig@906341142::minPoolSize=3, maxPoolSize=10, validateOnCheckIn=false, validateOnCheckOut=false, validatePeriodically=true, validatePeriod=300], activator=null, passivator=null, validator=[org.ldaptive.pool.SearchValidator@818618939::searchRequest=[org.ldaptive.SearchRequest@6117248::baseDn=, searchFilter=[org.ldaptive.SearchFilter@1642584434::filter=(objectClass=*), parameters={}], returnAttributes=[1.1], searchScope=OBJECT, timeLimit=0, 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@617662116::prunePeriod=300, idleTime=600], connectOnCreate=true, connectionFactory=[org.ldaptive.DefaultConnectionFactory@1357008548::provider=org.ldaptive.provider.jndi.JndiProvider@4ba402b5, config=[org.ldaptive.ConnectionConfig@571943680::ldapUrl=ldap://xxx.xx.xx.xx, connectTimeout=3000, responseTimeout=-1, sslConfig=null, useSSL=false, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@13642752::bindDn=admin...@peninsula.wednet.edu, bindSaslConfig=null, bindControls=null]]], initialized=false, availableCount=0, activeCount=0]>
[STDOUT] 2016-10-25 20:58:37,373 DEBUG [org.ldaptive.pool.BlockingConnectionPool] - <checking connection pool size >= 3 for [org.ldaptive.pool.BlockingConnectionPool@1980783296::name=bind-pool, poolConfig=[org.ldaptive.pool.PoolConfig@906341142::minPoolSize=3, maxPoolSize=10, validateOnCheckIn=false, validateOnCheckOut=false, validatePeriodically=true, validatePeriod=300], activator=null, passivator=null, validator=[org.ldaptive.pool.SearchValidator@818618939::searchRequest=[org.ldaptive.SearchRequest@6117248::baseDn=, searchFilter=[org.ldaptive.SearchFilter@1642584434::filter=(objectClass=*), parameters={}], returnAttributes=[1.1], searchScope=OBJECT, timeLimit=0, 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@617662116::prunePeriod=300, idleTime=600], connectOnCreate=true, connectionFactory=[org.ldaptive.DefaultConnectionFactory@1357008548::provider=org.ldaptive.provider.jndi.JndiProvider@4ba402b5, config=[org.ldaptive.ConnectionConfig@571943680::ldapUrl=ldap://xxx.xx.xx.xx, connectTimeout=3000, responseTimeout=-1, sslConfig=null, useSSL=false, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@13642752::bindDn=admin...@peninsula.wednet.edu, bindSaslConfig=null, bindControls=null]]], initialized=false, availableCount=0, activeCount=0]>
[STDOUT] 2016-10-25 20:58:37,394 DEBUG [org.ldaptive.BindOperation] - <execute request=[org.ldaptive.BindRequest@1107678672::bindDn=admin...@peninsula.wednet.edu, saslConfig=null, controls=null, referralHandler=null, intermediateResponseHandlers=null] with connection=[org.ldaptive.DefaultConnectionFactory$DefaultConnection@702531215::config=[org.ldaptive.ConnectionConfig@571943680::ldapUrl=ldap://xxx.xx.xx.xx, connectTimeout=3000, responseTimeout=-1, sslConfig=null, useSSL=false, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@13642752::bindDn=admin...@peninsula.wednet.edu, bindSaslConfig=null, bindControls=null]], providerConnectionFactory=[org.ldaptive.provider.jndi.JndiConnectionFactory@839624607::metadata=[ldapUrl=ldap://xxx.xx.xx.xx, count=1], environment={com.sun.jndi.ldap.connect.timeout=3000, java.naming.ldap.version=3, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory}, providerConfig=[org.ldaptive.provider.jndi.JndiProviderConfig@859450866::operationExceptionResultCodes=[PROTOCOL_ERROR, SERVER_DOWN], properties={}, connectionStrategy=org.ldaptive.provider.DefaultConnectionStrategy@1344f7fe, controlProcessor=org.ldaptive.provider.ControlProcessor@5ffdd510, environment=null, tracePackets=null, removeDnUrls=true, searchIgnoreResultCodes=[TIME_LIMIT_EXCEEDED, SIZE_LIMIT_EXCEEDED, PARTIAL_RESULTS], sslSocketFactory=null, hostnameVerifier=null]], providerConnection=org.ldaptive.provider.jndi.JndiConnection@8c18bde]>
[STDOUT] 2016-10-25 20:58:37,412 DEBUG [org.ldaptive.BindOperation] - <execute response=[org.ldaptive.Response@1729753606::result=null, resultCode=SUCCESS, message=null, matchedDn=null, responseControls=null, referralURLs=null, messageId=-1] for request=[org.ldaptive.BindRequest@1107678672::bindDn=admin...@peninsula.wednet.edu, saslConfig=null, controls=null, referralHandler=null, intermediateResponseHandlers=null] with connection=[org.ldaptive.DefaultConnectionFactory$DefaultConnection@702531215::config=[org.ldaptive.ConnectionConfig@571943680::ldapUrl=ldap://xxx.xx.xx.xx, connectTimeout=3000, responseTimeout=-1, sslConfig=null, useSSL=false, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@13642752::bindDn=admin...@peninsula.wednet.edu, bindSaslConfig=null, bindControls=null]], providerConnectionFactory=[org.ldaptive.provider.jndi.JndiConnectionFactory@839624607::metadata=[ldapUrl=ldap://xxx.xx.xx.xx, count=1], environment={com.sun.jndi.ldap.connect.timeout=3000, java.naming.ldap.version=3, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory}, providerConfig=[org.ldaptive.provider.jndi.JndiProviderConfig@859450866::operationExceptionResultCodes=[PROTOCOL_ERROR, SERVER_DOWN], properties={}, connectionStrategy=org.ldaptive.provider.DefaultConnectionStrategy@1344f7fe, controlProcessor=org.ldaptive.provider.ControlProcessor@5ffdd510, environment=null, tracePackets=null, removeDnUrls=true, searchIgnoreResultCodes=[TIME_LIMIT_EXCEEDED, SIZE_LIMIT_EXCEEDED, PARTIAL_RESULTS], sslSocketFactory=null, hostnameVerifier=null]], providerConnection=org.ldaptive.provider.jndi.JndiConnection@8c18bde]>
[STDOUT] 2016-10-25 20:58:37,419 INFO [org.ldaptive.pool.BlockingConnectionPool] - <added available connection: org.ldaptive.pool.AbstractConnectionPool$DefaultPooledConnectionProxy@29e0a496>
[STDOUT] 2016-10-25 20:58:37,441 DEBUG [org.ldaptive.BindOperation] - <execute request=[org.ldaptive.BindRequest@95295146::bindDn=admin...@peninsula.wednet.edu, saslConfig=null, controls=null, referralHandler=null, intermediateResponseHandlers=null] with connection=[org.ldaptive.DefaultConnectionFactory$DefaultConnection@877266522::config=[org.ldaptive.ConnectionConfig@571943680::ldapUrl=ldap://xxx.xx.xx.xx, connectTimeout=3000, responseTimeout=-1, sslConfig=null, useSSL=false, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@13642752::bindDn=admin...@peninsula.wednet.edu, bindSaslConfig=null, bindControls=null]], providerConnectionFactory=[org.ldaptive.provider.jndi.JndiConnectionFactory@810673270::metadata=[ldapUrl=ldap://xxx.xx.xx.xx, count=1], environment={com.sun.jndi.ldap.connect.timeout=3000, java.naming.ldap.version=3, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory}, providerConfig=[org.ldaptive.provider.jndi.JndiProviderConfig@859450866::operationExceptionResultCodes=[PROTOCOL_ERROR, SERVER_DOWN], properties={}, connectionStrategy=org.ldaptive.provider.DefaultConnectionStrategy@1344f7fe, controlProcessor=org.ldaptive.provider.ControlProcessor@5ffdd510, environment=null, tracePackets=null, removeDnUrls=true, searchIgnoreResultCodes=[TIME_LIMIT_EXCEEDED, SIZE_LIMIT_EXCEEDED, PARTIAL_RESULTS], sslSocketFactory=null, hostnameVerifier=null]], providerConnection=org.ldaptive.provider.jndi.JndiConnection@1870b9b8]>
[STDOUT] 2016-10-25 20:58:37,473 DEBUG [org.ldaptive.BindOperation] - <execute response=[org.ldaptive.Response@1839130458::result=null, resultCode=SUCCESS, message=null, matchedDn=null, responseControls=null, referralURLs=null, messageId=-1] for request=[org.ldaptive.BindRequest@95295146::bindDn=admin...@peninsula.wednet.edu, saslConfig=null, controls=null, referralHandler=null, intermediateResponseHandlers=null] with connection=[org.ldaptive.DefaultConnectionFactory$DefaultConnection@877266522::config=[org.ldaptive.ConnectionConfig@571943680::ldapUrl=ldap://xxx.xx.xx.xx, connectTimeout=3000, responseTimeout=-1, sslConfig=null, useSSL=false, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@13642752::bindDn=admin...@peninsula.wednet.edu, bindSaslConfig=null, bindControls=null]], providerConnectionFactory=[org.ldaptive.provider.jndi.JndiConnectionFactory@810673270::metadata=[ldapUrl=ldap://xxx.xx.xx.xx, count=1], environment={com.sun.jndi.ldap.connect.timeout=3000, java.naming.ldap.version=3, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory}, providerConfig=[org.ldaptive.provider.jndi.JndiProviderConfig@859450866::operationExceptionResultCodes=[PROTOCOL_ERROR, SERVER_DOWN], properties={}, connectionStrategy=org.ldaptive.provider.DefaultConnectionStrategy@1344f7fe, controlProcessor=org.ldaptive.provider.ControlProcessor@5ffdd510, environment=null, tracePackets=null, removeDnUrls=true, searchIgnoreResultCodes=[TIME_LIMIT_EXCEEDED, SIZE_LIMIT_EXCEEDED, PARTIAL_RESULTS], sslSocketFactory=null, hostnameVerifier=null]], providerConnection=org.ldaptive.provider.jndi.JndiConnection@1870b9b8]>
[STDOUT] 2016-10-25 20:58:37,474 INFO [org.ldaptive.pool.BlockingConnectionPool] - <added available connection: org.ldaptive.pool.AbstractConnectionPool$DefaultPooledConnectionProxy@344ae461>
[STDOUT] 2016-10-25 20:58:37,783 DEBUG [org.ldaptive.BindOperation] - <execute request=[org.ldaptive.BindRequest@159536229::bindDn=admin...@peninsula.wednet.edu, saslConfig=null, controls=null, referralHandler=null, intermediateResponseHandlers=null] with connection=[org.ldaptive.DefaultConnectionFactory$DefaultConnection@919561079::config=[org.ldaptive.ConnectionConfig@571943680::ldapUrl=ldap://xxx.xx.xx.xx, connectTimeout=3000, responseTimeout=-1, sslConfig=null, useSSL=false, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@13642752::bindDn=admin...@peninsula.wednet.edu, bindSaslConfig=null, bindControls=null]], providerConnectionFactory=[org.ldaptive.provider.jndi.JndiConnectionFactory@737128815::metadata=[ldapUrl=ldap://xxx.xx.xx.xx, count=1], environment={com.sun.jndi.ldap.connect.timeout=3000, java.naming.ldap.version=3, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory}, providerConfig=[org.ldaptive.provider.jndi.JndiProviderConfig@859450866::operationExceptionResultCodes=[PROTOCOL_ERROR, SERVER_DOWN], properties={}, connectionStrategy=org.ldaptive.provider.DefaultConnectionStrategy@1344f7fe, controlProcessor=org.ldaptive.provider.ControlProcessor@5ffdd510, environment=null, tracePackets=null, removeDnUrls=true, searchIgnoreResultCodes=[TIME_LIMIT_EXCEEDED, SIZE_LIMIT_EXCEEDED, PARTIAL_RESULTS], sslSocketFactory=null, hostnameVerifier=null]], providerConnection=org.ldaptive.provider.jndi.JndiConnection@3151277f]>
[STDOUT] 2016-10-25 20:58:37,799 DEBUG [org.ldaptive.BindOperation] - <execute response=[org.ldaptive.Response@720075852::result=null, resultCode=SUCCESS, message=null, matchedDn=null, responseControls=null, referralURLs=null, messageId=-1] for request=[org.ldaptive.BindRequest@159536229::bindDn=admin...@peninsula.wednet.edu, saslConfig=null, controls=null, referralHandler=null, intermediateResponseHandlers=null] with connection=[org.ldaptive.DefaultConnectionFactory$DefaultConnection@919561079::config=[org.ldaptive.ConnectionConfig@571943680::ldapUrl=ldap://xxx.xx.xx.xx, connectTimeout=3000, responseTimeout=-1, sslConfig=null, useSSL=false, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@13642752::bindDn=admin...@peninsula.wednet.edu, bindSaslConfig=null, bindControls=null]], providerConnectionFactory=[org.ldaptive.provider.jndi.JndiConnectionFactory@737128815::metadata=[ldapUrl=ldap://xxx.xx.xx.xx, count=1], environment={com.sun.jndi.ldap.connect.timeout=3000, java.naming.ldap.version=3, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory}, providerConfig=[org.ldaptive.provider.jndi.JndiProviderConfig@859450866::operationExceptionResultCodes=[PROTOCOL_ERROR, SERVER_DOWN], properties={}, connectionStrategy=org.ldaptive.provider.DefaultConnectionStrategy@1344f7fe, controlProcessor=org.ldaptive.provider.ControlProcessor@5ffdd510, environment=null, tracePackets=null, removeDnUrls=true, searchIgnoreResultCodes=[TIME_LIMIT_EXCEEDED, SIZE_LIMIT_EXCEEDED, PARTIAL_RESULTS], sslSocketFactory=null, hostnameVerifier=null]], providerConnection=org.ldaptive.provider.jndi.JndiConnection@3151277f]>
[STDOUT] 2016-10-25 20:58:37,801 INFO [org.ldaptive.pool.BlockingConnectionPool] - <added available connection: org.ldaptive.pool.AbstractConnectionPool$DefaultPooledConnectionProxy@36d0417e>
[STDOUT] 2016-10-25 20:58:37,802 DEBUG [org.ldaptive.pool.BlockingConnectionPool] - <initialized available queue: [org.ldaptive.pool.Queue@1743939261::queueType=LIFO, queue=[org.ldaptive.pool.AbstractConnectionPool$DefaultPooledConnectionProxy@36d0417e, org.ldaptive.pool.AbstractConnectionPool$DefaultPooledConnectionProxy@344ae461, org.ldaptive.pool.AbstractConnectionPool$DefaultPooledConnectionProxy@29e0a496]]>
[STDOUT] 2016-10-25 20:58:37,805 DEBUG [org.ldaptive.pool.BlockingConnectionPool] - <prune pool task scheduled for [org.ldaptive.pool.BlockingConnectionPool@1980783296::name=bind-pool, poolConfig=[org.ldaptive.pool.PoolConfig@906341142::minPoolSize=3, maxPoolSize=10, validateOnCheckIn=false, validateOnCheckOut=false, validatePeriodically=true, validatePeriod=300], activator=null, passivator=null, validator=[org.ldaptive.pool.SearchValidator@818618939::searchRequest=[org.ldaptive.SearchRequest@6117248::baseDn=, searchFilter=[org.ldaptive.SearchFilter@1642584434::filter=(objectClass=*), parameters={}], returnAttributes=[1.1], searchScope=OBJECT, timeLimit=0, 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@617662116::prunePeriod=300, idleTime=600], connectOnCreate=true, connectionFactory=[org.ldaptive.DefaultConnectionFactory@1357008548::provider=org.ldaptive.provider.jndi.JndiProvider@4ba402b5, config=[org.ldaptive.ConnectionConfig@571943680::ldapUrl=ldap://xxx.xx.xx.xx, connectTimeout=3000, responseTimeout=-1, sslConfig=null, useSSL=false, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@13642752::bindDn=admin...@peninsula.wednet.edu, bindSaslConfig=null, bindControls=null]]], initialized=false, availableCount=3, activeCount=0]>
[STDOUT] 2016-10-25 20:58:37,809 DEBUG [org.ldaptive.pool.BlockingConnectionPool] - <validate pool task scheduled for [org.ldaptive.pool.BlockingConnectionPool@1980783296::name=bind-pool, poolConfig=[org.ldaptive.pool.PoolConfig@906341142::minPoolSize=3, maxPoolSize=10, validateOnCheckIn=false, validateOnCheckOut=false, validatePeriodically=true, validatePeriod=300], activator=null, passivator=null, validator=[org.ldaptive.pool.SearchValidator@818618939::searchRequest=[org.ldaptive.SearchRequest@6117248::baseDn=, searchFilter=[org.ldaptive.SearchFilter@1642584434::filter=(objectClass=*), parameters={}], returnAttributes=[1.1], searchScope=OBJECT, timeLimit=0, 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@617662116::prunePeriod=300, idleTime=600], connectOnCreate=true, connectionFactory=[org.ldaptive.DefaultConnectionFactory@1357008548::provider=org.ldaptive.provider.jndi.JndiProvider@4ba402b5, config=[org.ldaptive.ConnectionConfig@571943680::ldapUrl=ldap://xxx.xx.xx.xx, connectTimeout=3000, responseTimeout=-1, sslConfig=null, useSSL=false, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@13642752::bindDn=admin...@peninsula.wednet.edu, bindSaslConfig=null, bindControls=null]]], initialized=false, availableCount=3, activeCount=0]>
[STDOUT] 2016-10-25 20:58:37,817 INFO [org.ldaptive.pool.BlockingConnectionPool] - <pool initialized [org.ldaptive.pool.BlockingConnectionPool@1980783296::name=bind-pool, poolConfig=[org.ldaptive.pool.PoolConfig@906341142::minPoolSize=3, maxPoolSize=10, validateOnCheckIn=false, validateOnCheckOut=false, validatePeriodically=true, validatePeriod=300], activator=null, passivator=null, validator=[org.ldaptive.pool.SearchValidator@818618939::searchRequest=[org.ldaptive.SearchRequest@6117248::baseDn=, searchFilter=[org.ldaptive.SearchFilter@1642584434::filter=(objectClass=*), parameters={}], returnAttributes=[1.1], searchScope=OBJECT, timeLimit=0, 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@617662116::prunePeriod=300, idleTime=600], connectOnCreate=true, connectionFactory=[org.ldaptive.DefaultConnectionFactory@1357008548::provider=org.ldaptive.provider.jndi.JndiProvider@4ba402b5, config=[org.ldaptive.ConnectionConfig@571943680::ldapUrl=ldap://xxx.xx.xx.xx, connectTimeout=3000, responseTimeout=-1, sslConfig=null, useSSL=false, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@13642752::bindDn=admin...@peninsula.wednet.edu, bindSaslConfig=null, bindControls=null]]], initialized=true, availableCount=3, activeCount=0]>
[STDOUT] 2016-10-25 20:58:38,608 INFO [org.jasig.cas.support.saml.SamlGoogleAppsServletContextListener] - <Initializing SamlGoogleAppsServletContextListener root application context>
[STDOUT] 2016-10-25 20:58:38,632 INFO [org.jasig.cas.support.saml.SamlGoogleAppsServletContextListener] - <Initialized SamlGoogleAppsServletContextListener root application context successfully>
[STDOUT] 2016-10-25 20:58:38,632 INFO [org.jasig.cas.support.saml.SamlGoogleAppsServletContextListener] - <Initializing SamlGoogleAppsServletContextListener servlet application context>
[STDOUT] 2016-10-25 20:58:38,633 INFO [org.jasig.cas.support.saml.SamlGoogleAppsServletContextListener] - <Initialized SamlGoogleAppsServletContextListener servlet application context successfully>
[STDOUT] 2016-10-25 20:58:45,146 INFO [org.jasig.cas.support.saml.SamlServletContextListener] - <Initializing SamlServletContextListener root application context>
[STDOUT] 2016-10-25 20:58:45,149 INFO [org.jasig.cas.support.saml.SamlServletContextListener] - <Initialized SamlServletContextListener root application context successfully>
[STDOUT] 2016-10-25 20:58:45,152 INFO [org.jasig.cas.support.saml.SamlServletContextListener] - <Initializing SamlServletContextListener servlet application context>
[STDOUT] 2016-10-25 20:58:46,984 ERROR [org.jasig.cas.support.saml.SamlServletContextListener] - <Error creating bean with name 'handlerMappingC' defined in ServletContext resource [/WEB-INF/spring-configuration/applicationContext.xml]: Initialization of bean failed; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'metricsController' defined in ServletContext resource [/WEB-INF/spring-configuration/applicationContext.xml]: Invocation of init method failed; nested exception is javax.servlet.ServletException: Couldn't find a MetricRegistry instance.>
[STDOUT] org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'handlerMappingC' defined in ServletContext resource [/WEB-INF/spring-configuration/applicationContext.xml]: Initialization of bean failed; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'metricsController' defined in ServletContext resource [/WEB-INF/spring-configuration/applicationContext.xml]: Invocation of init method failed; nested exception is javax.servlet.ServletException: Couldn't find a MetricRegistry instance.
[STDOUT] at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:553) ~[spring-beans-4.2.8.RELEASE.jar:4.2.8.RELEASE]
[STDOUT] at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:482) ~[spring-beans-4.2.8.RELEASE.jar:4.2.8.RELEASE]
[STDOUT] at org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:306) ~[spring-beans-4.2.8.RELEASE.jar:4.2.8.RELEASE]
[STDOUT] at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:230) ~[spring-beans-4.2.8.RELEASE.jar:4.2.8.RELEASE]
[STDOUT] at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:302) ~[spring-beans-4.2.8.RELEASE.jar:4.2.8.RELEASE]
[STDOUT] at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:202) ~[spring-beans-4.2.8.RELEASE.jar:4.2.8.RELEASE]
[STDOUT] at org.springframework.context.support.AbstractApplicationContext.getBean(AbstractApplicationContext.java:1060) ~[spring-context-4.2.8.RELEASE.jar:4.2.8.RELEASE]
[STDOUT] at org.jasig.cas.web.AbstractServletContextInitializer.getCasServletHandlerMapping(AbstractServletContextInitializer.java:194) ~[cas-server-core-web-4.2.6.jar:4.2.6]
[STDOUT] at org.jasig.cas.web.AbstractServletContextInitializer.addControllerToCasServletHandlerMapping(AbstractServletContextInitializer.java:206) ~[cas-server-core-web-4.2.6.jar:4.2.6]
[STDOUT] at org.jasig.cas.support.saml.SamlServletContextListener.initializeServletApplicationContext(SamlServletContextListener.java:60) ~[cas-server-support-saml-4.2.6.jar:4.2.6]
[STDOUT] at org.jasig.cas.web.AbstractServletContextInitializer.setApplicationContext(AbstractServletContextInitializer.java:111) ~[cas-server-core-web-4.2.6.jar:4.2.6]
[STDOUT] at org.springframework.context.support.ApplicationContextAwareProcessor.invokeAwareInterfaces(ApplicationContextAwareProcessor.java:119) ~[spring-context-4.2.8.RELEASE.jar:4.2.8.RELEASE]
[STDOUT] at org.springframework.context.support.ApplicationContextAwareProcessor.postProcessBeforeInitialization(ApplicationContextAwareProcessor.java:94) ~[spring-context-4.2.8.RELEASE.jar:4.2.8.RELEASE]
[STDOUT] at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.applyBeanPostProcessorsBeforeInitialization(AbstractAutowireCapableBeanFactory.java:408) ~[spring-beans-4.2.8.RELEASE.jar:4.2.8.RELEASE]
[STDOUT] at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1574) ~[spring-beans-4.2.8.RELEASE.jar:4.2.8.RELEASE]
[STDOUT] at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:545) ~[spring-beans-4.2.8.RELEASE.jar:4.2.8.RELEASE]
[STDOUT] at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:482) ~[spring-beans-4.2.8.RELEASE.jar:4.2.8.RELEASE]
[STDOUT] at org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:306) ~[spring-beans-4.2.8.RELEASE.jar:4.2.8.RELEASE]
[STDOUT] at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:230) ~[spring-beans-4.2.8.RELEASE.jar:4.2.8.RELEASE]
[STDOUT] at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:302) ~[spring-beans-4.2.8.RELEASE.jar:4.2.8.RELEASE]
[STDOUT] at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:197) ~[spring-beans-4.2.8.RELEASE.jar:4.2.8.RELEASE]
[STDOUT] at org.springframework.beans.factory.support.DefaultListableBeanFactory.preInstantiateSingletons(DefaultListableBeanFactory.java:778) ~[spring-beans-4.2.8.RELEASE.jar:4.2.8.RELEASE]
[STDOUT] at org.springframework.context.support.AbstractApplicationContext.finishBeanFactoryInitialization(AbstractApplicationContext.java:839) ~[spring-context-4.2.8.RELEASE.jar:4.2.8.RELEASE]
[STDOUT] at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:538) ~[spring-context-4.2.8.RELEASE.jar:4.2.8.RELEASE]
[STDOUT] at org.springframework.web.context.ContextLoader.configureAndRefreshWebApplicationContext(ContextLoader.java:444) ~[spring-web-4.2.8.RELEASE.jar:4.2.8.RELEASE]
[STDOUT] at org.springframework.web.context.ContextLoader.initWebApplicationContext(ContextLoader.java:326) ~[spring-web-4.2.8.RELEASE.jar:4.2.8.RELEASE]
[STDOUT] at org.springframework.web.context.ContextLoaderListener.contextInitialized(ContextLoaderListener.java:107) ~[spring-web-4.2.8.RELEASE.jar:4.2.8.RELEASE]
[STDOUT] at org.eclipse.jetty.server.handler.ContextHandler.callContextInitialized(ContextHandler.java:835) ~[?:?]
[STDOUT] at org.eclipse.jetty.servlet.ServletContextHandler.callContextInitialized(ServletContextHandler.java:530) ~[?:?]
[STDOUT] at org.eclipse.jetty.server.handler.ContextHandler.startContext(ContextHandler.java:808) ~[?:?]
[STDOUT] at org.eclipse.jetty.servlet.ServletContextHandler.startContext(ServletContextHandler.java:342) ~[?:?]
[STDOUT] at org.eclipse.jetty.webapp.WebAppContext.startWebapp(WebAppContext.java:1379) ~[?:?]
[STDOUT] at org.eclipse.jetty.maven.plugin.JettyWebAppContext.startWebapp(JettyWebAppContext.java:323) ~[?:?]
[STDOUT] at org.eclipse.jetty.webapp.WebAppContext.startContext(WebAppContext.java:1341) ~[?:?]
[STDOUT] at org.eclipse.jetty.server.handler.ContextHandler.doStart(ContextHandler.java:772) ~[?:?]
[STDOUT] at org.eclipse.jetty.servlet.ServletContextHandler.doStart(ServletContextHandler.java:259) ~[?:?]
[STDOUT] at org.eclipse.jetty.webapp.WebAppContext.doStart(WebAppContext.java:517) ~[?:?]
[STDOUT] at org.eclipse.jetty.maven.plugin.JettyWebAppContext.doStart(JettyWebAppContext.java:398) ~[?:?]
[STDOUT] at org.eclipse.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:68) ~[?:?]
[STDOUT] at org.eclipse.jetty.util.component.ContainerLifeCycle.start(ContainerLifeCycle.java:132) ~[?:?]
[STDOUT] at org.eclipse.jetty.util.component.ContainerLifeCycle.doStart(ContainerLifeCycle.java:114) ~[?:?]
[STDOUT] at org.eclipse.jetty.server.handler.AbstractHandler.doStart(AbstractHandler.java:61) ~[?:?]
[STDOUT] at org.eclipse.jetty.server.handler.ContextHandlerCollection.doStart(ContextHandlerCollection.java:161) ~[?:?]
[STDOUT] at org.eclipse.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:68) ~[?:?]
[STDOUT] at org.eclipse.jetty.util.component.ContainerLifeCycle.start(ContainerLifeCycle.java:132) ~[?:?]
[STDOUT] at org.eclipse.jetty.util.component.ContainerLifeCycle.doStart(ContainerLifeCycle.java:114) ~[?:?]
[STDOUT] at org.eclipse.jetty.server.handler.AbstractHandler.doStart(AbstractHandler.java:61) ~[?:?]
[STDOUT] at org.eclipse.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:68) ~[?:?]
[STDOUT] at org.eclipse.jetty.util.component.ContainerLifeCycle.start(ContainerLifeCycle.java:132) ~[?:?]
[STDOUT] at org.eclipse.jetty.server.Server.start(Server.java:405) ~[?:?]
[STDOUT] at org.eclipse.jetty.util.component.ContainerLifeCycle.doStart(ContainerLifeCycle.java:106) ~[?:?]
[STDOUT] at org.eclipse.jetty.server.handler.AbstractHandler.doStart(AbstractHandler.java:61) ~[?:?]
[STDOUT] at org.eclipse.jetty.server.Server.doStart(Server.java:372) ~[?:?]
[STDOUT] at org.eclipse.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:68) ~[?:?]
[STDOUT] at org.eclipse.jetty.maven.plugin.Starter.run(Starter.java:370) ~[?:?]
[STDOUT] at org.eclipse.jetty.maven.plugin.Starter.main(Starter.java:468) ~[?:?]
[STDOUT] Caused by: org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'metricsController' defined in ServletContext resource [/WEB-INF/spring-configuration/applicationContext.xml]: Invocation of init method failed; nested exception is javax.servlet.ServletException: Couldn't find a MetricRegistry instance.
[STDOUT] at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1582) ~[spring-beans-4.2.8.RELEASE.jar:4.2.8.RELEASE]
[STDOUT] at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:545) ~[spring-beans-4.2.8.RELEASE.jar:4.2.8.RELEASE]
[STDOUT] at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:482) ~[spring-beans-4.2.8.RELEASE.jar:4.2.8.RELEASE]
[STDOUT] at org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:306) ~[spring-beans-4.2.8.RELEASE.jar:4.2.8.RELEASE]
[STDOUT] at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:230) ~[spring-beans-4.2.8.RELEASE.jar:4.2.8.RELEASE]
[STDOUT] at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:302) ~[spring-beans-4.2.8.RELEASE.jar:4.2.8.RELEASE]
[STDOUT] at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:197) ~[spring-beans-4.2.8.RELEASE.jar:4.2.8.RELEASE]
[STDOUT] at org.springframework.context.support.AbstractApplicationContext.getBean(AbstractApplicationContext.java:1054) ~[spring-context-4.2.8.RELEASE.jar:4.2.8.RELEASE]
[STDOUT] at org.springframework.web.servlet.handler.AbstractUrlHandlerMapping.registerHandler(AbstractUrlHandlerMapping.java:313) ~[spring-webmvc-4.2.8.RELEASE.jar:4.2.8.RELEASE]
[STDOUT] at org.springframework.web.servlet.handler.SimpleUrlHandlerMapping.registerHandlers(SimpleUrlHandlerMapping.java:128) ~[spring-webmvc-4.2.8.RELEASE.jar:4.2.8.RELEASE]
[STDOUT] at org.springframework.web.servlet.handler.SimpleUrlHandlerMapping.initApplicationContext(SimpleUrlHandlerMapping.java:103) ~[spring-webmvc-4.2.8.RELEASE.jar:4.2.8.RELEASE]
[STDOUT] at org.springframework.context.support.ApplicationObjectSupport.initApplicationContext(ApplicationObjectSupport.java:120) ~[spring-context-4.2.8.RELEASE.jar:4.2.8.RELEASE]
[STDOUT] at org.springframework.web.context.support.WebApplicationObjectSupport.initApplicationContext(WebApplicationObjectSupport.java:76) ~[spring-web-4.2.8.RELEASE.jar:4.2.8.RELEASE]
[STDOUT] at org.springframework.context.support.ApplicationObjectSupport.setApplicationContext(ApplicationObjectSupport.java:74) ~[spring-context-4.2.8.RELEASE.jar:4.2.8.RELEASE]
[STDOUT] at org.springframework.context.support.ApplicationContextAwareProcessor.invokeAwareInterfaces(ApplicationContextAwareProcessor.java:119) ~[spring-context-4.2.8.RELEASE.jar:4.2.8.RELEASE]
[STDOUT] at org.springframework.context.support.ApplicationContextAwareProcessor.postProcessBeforeInitialization(ApplicationContextAwareProcessor.java:94) ~[spring-context-4.2.8.RELEASE.jar:4.2.8.RELEASE]
[STDOUT] at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.applyBeanPostProcessorsBeforeInitialization(AbstractAutowireCapableBeanFactory.java:408) ~[spring-beans-4.2.8.RELEASE.jar:4.2.8.RELEASE]
[STDOUT] at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1574) ~[spring-beans-4.2.8.RELEASE.jar:4.2.8.RELEASE]
[STDOUT] at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:545) ~[spring-beans-4.2.8.RELEASE.jar:4.2.8.RELEASE]
[STDOUT] ... 55 more
[STDOUT] Caused by: javax.servlet.ServletException: Couldn't find a MetricRegistry instance.
[STDOUT] at com.codahale.metrics.servlets.MetricsServlet.init(MetricsServlet.java:139) ~[metrics-servlets-3.1.2.jar:3.1.2]
[STDOUT] at org.springframework.web.servlet.mvc.ServletWrappingController.afterPropertiesSet(ServletWrappingController.java:140) ~[spring-webmvc-4.2.8.RELEASE.jar:4.2.8.RELEASE]
[STDOUT] at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.invokeInitMethods(AbstractAutowireCapableBeanFactory.java:1641) ~[spring-beans-4.2.8.RELEASE.jar:4.2.8.RELEASE]
[STDOUT] at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1578) ~[spring-beans-4.2.8.RELEASE.jar:4.2.8.RELEASE]
[STDOUT] at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:545) ~[spring-beans-4.2.8.RELEASE.jar:4.2.8.RELEASE]
[STDOUT] at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:482) ~[spring-beans-4.2.8.RELEASE.jar:4.2.8.RELEASE]
[STDOUT] at org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:306) ~[spring-beans-4.2.8.RELEASE.jar:4.2.8.RELEASE]
[STDOUT] at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:230) ~[spring-beans-4.2.8.RELEASE.jar:4.2.8.RELEASE]
[STDOUT] at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:302) ~[spring-beans-4.2.8.RELEASE.jar:4.2.8.RELEASE]
[STDOUT] at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:197) ~[spring-beans-4.2.8.RELEASE.jar:4.2.8.RELEASE]
[STDOUT] at org.springframework.context.support.AbstractApplicationContext.getBean(AbstractApplicationContext.java:1054) ~[spring-context-4.2.8.RELEASE.jar:4.2.8.RELEASE]
[STDOUT] at org.springframework.web.servlet.handler.AbstractUrlHandlerMapping.registerHandler(AbstractUrlHandlerMapping.java:313) ~[spring-webmvc-4.2.8.RELEASE.jar:4.2.8.RELEASE]
[STDOUT] at org.springframework.web.servlet.handler.SimpleUrlHandlerMapping.registerHandlers(SimpleUrlHandlerMapping.java:128) ~[spring-webmvc-4.2.8.RELEASE.jar:4.2.8.RELEASE]
[STDOUT] at org.springframework.web.servlet.handler.SimpleUrlHandlerMapping.initApplicationContext(SimpleUrlHandlerMapping.java:103) ~[spring-webmvc-4.2.8.RELEASE.jar:4.2.8.RELEASE]
[STDOUT] at org.springframework.context.support.ApplicationObjectSupport.initApplicationContext(ApplicationObjectSupport.java:120) ~[spring-context-4.2.8.RELEASE.jar:4.2.8.RELEASE]
[STDOUT] at org.springframework.web.context.support.WebApplicationObjectSupport.initApplicationContext(WebApplicationObjectSupport.java:76) ~[spring-web-4.2.8.RELEASE.jar:4.2.8.RELEASE]
[STDOUT] at org.springframework.context.support.ApplicationObjectSupport.setApplicationContext(ApplicationObjectSupport.java:74) ~[spring-context-4.2.8.RELEASE.jar:4.2.8.RELEASE]
[STDOUT] at org.springframework.context.support.ApplicationContextAwareProcessor.invokeAwareInterfaces(ApplicationContextAwareProcessor.java:119) ~[spring-context-4.2.8.RELEASE.jar:4.2.8.RELEASE]
[STDOUT] at org.springframework.context.support.ApplicationContextAwareProcessor.postProcessBeforeInitialization(ApplicationContextAwareProcessor.java:94) ~[spring-context-4.2.8.RELEASE.jar:4.2.8.RELEASE]
[STDOUT] at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.applyBeanPostProcessorsBeforeInitialization(AbstractAutowireCapableBeanFactory.java:408) ~[spring-beans-4.2.8.RELEASE.jar:4.2.8.RELEASE]
[STDOUT] at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1574) ~[spring-beans-4.2.8.RELEASE.jar:4.2.8.RELEASE]
[STDOUT] at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:545) ~[spring-beans-4.2.8.RELEASE.jar:4.2.8.RELEASE]
[STDOUT] ... 55 more
[STDOUT] 2016-10-25 20:58:49,180 INFO [org.jasig.cas.ticket.registry.TicketRegistryCleaner] - <Preparing to schedule job to clean up after tickets...>
[STDOUT] 2016-10-25 20:58:49,180 INFO [org.jasig.cas.ticket.registry.TicketRegistryCleaner] - <TicketRegistryCleaner will clean tickets every 2 minutes>
[STDOUT] 2016-10-25 20:58:52,689 INFO [org.jasig.cas.support.saml.OpenSamlConfigBean] - <Initializing OpenSaml configuration...>
[STDOUT] 2016-10-25 20:58:59,829 INFO [org.jasig.cas.CasEnvironmentContextListener] - <[jetty/9.3.6.v20151106] has loaded the CAS servlet application context: Root WebApplicationContext: startup date [Tue Oct 25 20:58:27 UTC 2016]; root of context hierarchy>
[STDERR] 2016-10-25 20:59:00.084:INFO:/cas:main: Initializing Spring FrameworkServlet 'cas'
[STDERR] 2016-10-25 20:59:02.299:INFO:oejsh.ContextHandler:main: Started o.e.j.m.p.JettyWebAppContext@65d6b83b{/cas,[file:///cas-overlay/src/main/webapp/, file:///cas-overlay/target/tmp/cas-server-webapp-4_2_6_war1/],AVAILABLE}
[STDERR] 2016-10-25 20:59:02.320:INFO:oejs.ServerConnector:main: Started ServerConnector@3f9167f7{HTTP/1.1,[http/1.1]}{0.0.0.0:8080}
[STDERR] 2016-10-25 20:59:02.329:INFO:oejus.SslContextFactory:main: x509=X509@579847d7(tomcat,h=[],w=[]) for SslContextFactory@156b3428(file:///etc/cas/jetty/thekeystore,file:///etc/cas/jetty/thekeystore)
[STDERR] 2016-10-25 20:59:02.443:INFO:oejs.ServerConnector:main: Started ServerConnector@7abe70f7{SSL,[ssl, http/1.1]}{0.0.0.0:8443}
[STDOUT] -DQ5WLBKUQ1WV
[STDERR] 2016-10-25 20:59:02.444:INFO:oejs.Server:main: Started @51694ms
[STDOUT] 2016-10-25 20:59:09,247 INFO [org.jasig.cas.ticket.registry.TicketRegistryCleaner] - <Beginning ticket cleanup...>
[STDOUT] 2016-10-25 20:59:09,251 INFO [org.jasig.cas.ticket.registry.TicketRegistryCleaner] - <0 expired tickets found and removed.>
[STDOUT] 2016-10-25 20:59:50,013 INFO [org.jasig.cas.services.DefaultServicesManagerImpl] - <Reloading registered services.>
[STDOUT] 2016-10-25 20:59:50,077 INFO [org.jasig.cas.services.DefaultServicesManagerImpl] - <Loaded 2 services from JsonServiceRegistryDao.>
[STDOUT] 2016-10-25 21:00:36,178 INFO [org.jasig.cas.web.flow.InitialFlowSetupAction] - <Setting path for cookies for warn cookie generator to: /cas/ >
[STDOUT] 2016-10-25 21:00:36,178 INFO [org.jasig.cas.web.flow.InitialFlowSetupAction] - <Setting path for cookies for TGC cookie generator to: /cas/ >
[STDOUT] 2016-10-25 21:00:45,432 DEBUG [org.ldaptive.auth.PooledSearchDnResolver] - <resolve user=username>
[STDOUT] 2016-10-25 21:00:45,440 DEBUG [org.ldaptive.auth.PooledSearchDnResolver] - <searching for DN using userFilter>
[STDOUT] 2016-10-25 21:00:45,458 DEBUG [org.ldaptive.SearchOperation] - <execute request=[org.ldaptive.SearchRequest@1737167252::baseDn=ou=Users,ou=PSD,dc=Peninsula,dc=wednet,dc=edu, searchFilter=[org.ldaptive.SearchFilter@1615263833::filter=(sAMAccountName={user}), parameters={user=username}], returnAttributes=[1.1], searchScope=SUBTREE, timeLimit=0, sizeLimit=0, derefAliases=null, typesOnly=false, binaryAttributes=null, sortBehavior=UNORDERED, searchEntryHandlers=null, searchReferenceHandlers=null, controls=null, referralHandler=null, intermediateResponseHandlers=null] with connection=[org.ldaptive.DefaultConnectionFactory$DefaultConnection@300836639::config=[org.ldaptive.ConnectionConfig@542467430::ldapUrl=ldap://xxx.xx.xx.xx, connectTimeout=3000, responseTimeout=-1, sslConfig=null, useSSL=false, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@240055488::bindDn=admin...@peninsula.wednet.edu, bindSaslConfig=null, bindControls=null]], providerConnectionFactory=[org.ldaptive.provider.jndi.JndiConnectionFactory@404787971::metadata=[ldapUrl=ldap://xxx.xx.xx.xx, count=1], environment={com.sun.jndi.ldap.connect.timeout=3000, java.naming.ldap.version=3, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory}, providerConfig=[org.ldaptive.provider.jndi.JndiProviderConfig@1662417126::operationExceptionResultCodes=[PROTOCOL_ERROR, SERVER_DOWN], properties={}, connectionStrategy=org.ldaptive.provider.DefaultConnectionStrategy@1344f7fe, controlProcessor=org.ldaptive.provider.ControlProcessor@64d53f0d, environment=null, tracePackets=null, removeDnUrls=true, searchIgnoreResultCodes=[TIME_LIMIT_EXCEEDED, SIZE_LIMIT_EXCEEDED, PARTIAL_RESULTS], sslSocketFactory=null, hostnameVerifier=null]], providerConnection=org.ldaptive.provider.jndi.JndiConnection@57df09a7]>
[STDOUT] 2016-10-25 21:00:45,545 DEBUG [org.ldaptive.SearchOperation] - <execute response=[org.ldaptive.Response@985439959::result=[org.ldaptive.SearchResult@878591910::entries=[[dn=(correctDN)[], responseControls=null, messageId=-1]], references=[]], resultCode=SUCCESS, message=null, matchedDn=null, responseControls=null, referralURLs=null, messageId=-1] for request=[org.ldaptive.SearchRequest@1737167252::baseDn=ou=Users,ou=PSD,dc=Peninsula,dc=wednet,dc=edu, searchFilter=[org.ldaptive.SearchFilter@1615263833::filter=(sAMAccountName={user}), parameters={user=username}], returnAttributes=[1.1], searchScope=SUBTREE, timeLimit=0, sizeLimit=0, derefAliases=null, typesOnly=false, binaryAttributes=null, sortBehavior=UNORDERED, searchEntryHandlers=null, searchReferenceHandlers=null, controls=null, referralHandler=null, intermediateResponseHandlers=null] with connection=[org.ldaptive.DefaultConnectionFactory$DefaultConnection@300836639::config=[org.ldaptive.ConnectionConfig@542467430::ldapUrl=ldap://xxx.xx.xx.xx, connectTimeout=3000, responseTimeout=-1, sslConfig=null, useSSL=false, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@240055488::bindDn=admin...@peninsula.wednet.edu, bindSaslConfig=null, bindControls=null]], providerConnectionFactory=[org.ldaptive.provider.jndi.JndiConnectionFactory@404787971::metadata=[ldapUrl=ldap://xxx.xx.xx.xx, count=1], environment={com.sun.jndi.ldap.connect.timeout=3000, java.naming.ldap.version=3, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory}, providerConfig=[org.ldaptive.provider.jndi.JndiProviderConfig@1662417126::operationExceptionResultCodes=[PROTOCOL_ERROR, SERVER_DOWN], properties={}, connectionStrategy=org.ldaptive.provider.DefaultConnectionStrategy@1344f7fe, controlProcessor=org.ldaptive.provider.ControlProcessor@64d53f0d, environment=null, tracePackets=null, removeDnUrls=true, searchIgnoreResultCodes=[TIME_LIMIT_EXCEEDED, SIZE_LIMIT_EXCEEDED, PARTIAL_RESULTS], sslSocketFactory=null, hostnameVerifier=null]], providerConnection=org.ldaptive.provider.jndi.JndiConnection@57df09a7]>
[STDOUT] 2016-10-25 21:00:45,551 DEBUG [org.ldaptive.auth.PooledSearchDnResolver] - <resolved dn=(correctDN) for user=username>
[STDOUT] 2016-10-25 21:00:45,556 DEBUG [org.ldaptive.auth.Authenticator] - <authenticate dn=(correctDN) with request=[org.ldaptive.auth.AuthenticationRequest@1916764681::user=username, retAttrs=[telephoneNumber, mail, sAMAccountName, displayName, givenName, employeeId, memberOf, sn, passwordExpired]]>
[STDOUT] 2016-10-25 21:00:45,562 DEBUG [org.ldaptive.auth.PooledBindAuthenticationHandler] - <authenticate criteria=[org.ldaptive.auth.AuthenticationCriteria@1515358531::dn=(correctDN), authenticationRequest=[org.ldaptive.auth.AuthenticationRequest@1916764681::user=username, retAttrs=[telephoneNumber, mail, sAMAccountName, displayName, givenName, employeeId, memberOf, sn, passwordExpired]]]>
[STDOUT] 2016-10-25 21:00:45,569 DEBUG [org.ldaptive.BindOperation] - <execute request=[org.ldaptive.BindRequest@1468837640::binddn=(correctDN), 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@919561079::config=[org.ldaptive.ConnectionConfig@571943680::ldapUrl=ldap://xxx.xx.xx.xx, connectTimeout=3000, responseTimeout=-1, sslConfig=null, useSSL=false, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@13642752::bindDn=admin...@peninsula.wednet.edu, bindSaslConfig=null, bindControls=null]], providerConnectionFactory=[org.ldaptive.provider.jndi.JndiConnectionFactory@737128815::metadata=[ldapUrl=ldap://xxx.xx.xx.xx, count=1], environment={com.sun.jndi.ldap.connect.timeout=3000, java.naming.ldap.version=3, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory}, providerConfig=[org.ldaptive.provider.jndi.JndiProviderConfig@859450866::operationExceptionResultCodes=[PROTOCOL_ERROR, SERVER_DOWN], properties={}, connectionStrategy=org.ldaptive.provider.DefaultConnectionStrategy@1344f7fe, controlProcessor=org.ldaptive.provider.ControlProcessor@5ffdd510, environment=null, tracePackets=null, removeDnUrls=true, searchIgnoreResultCodes=[TIME_LIMIT_EXCEEDED, SIZE_LIMIT_EXCEEDED, PARTIAL_RESULTS], sslSocketFactory=null, hostnameVerifier=null]], providerConnection=org.ldaptive.provider.jndi.JndiConnection@3151277f]>
[STDOUT] 2016-10-25 21:00:45,604 DEBUG [org.ldaptive.BindOperation] - <execute response=[org.ldaptive.Response@121187832::result=null, resultCode=SUCCESS, message=null, matchedDn=null, responseControls=null, referralURLs=null, messageId=-1] for request=[org.ldaptive.BindRequest@1468837640::binddn=(correctDN), 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@919561079::config=[org.ldaptive.ConnectionConfig@571943680::ldapUrl=ldap://xxx.xx.xx.xx, connectTimeout=3000, responseTimeout=-1, sslConfig=null, useSSL=false, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@13642752::bindDn=admin...@peninsula.wednet.edu, bindSaslConfig=null, bindControls=null]], providerConnectionFactory=[org.ldaptive.provider.jndi.JndiConnectionFactory@737128815::metadata=[ldapUrl=ldap://xxx.xx.xx.xx, count=1], environment={com.sun.jndi.ldap.connect.timeout=3000, java.naming.ldap.version=3, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory}, providerConfig=[org.ldaptive.provider.jndi.JndiProviderConfig@859450866::operationExceptionResultCodes=[PROTOCOL_ERROR, SERVER_DOWN], properties={}, connectionStrategy=org.ldaptive.provider.DefaultConnectionStrategy@1344f7fe, controlProcessor=org.ldaptive.provider.ControlProcessor@5ffdd510, environment=null, tracePackets=null, removeDnUrls=true, searchIgnoreResultCodes=[TIME_LIMIT_EXCEEDED, SIZE_LIMIT_EXCEEDED, PARTIAL_RESULTS], sslSocketFactory=null, hostnameVerifier=null]], providerConnection=org.ldaptive.provider.jndi.JndiConnection@3151277f]>
[STDOUT] 2016-10-25 21:00:45,612 DEBUG [org.ldaptive.auth.PooledBindAuthenticationHandler] - <authenticate response=[org.ldaptive.auth.AuthenticationHandlerResponse@1232053453::connection=[org.ldaptive.DefaultConnectionFactory$DefaultConnection@919561079::config=[org.ldaptive.ConnectionConfig@571943680::ldapUrl=ldap://xxx.xx.xx.xx, connectTimeout=3000, responseTimeout=-1, sslConfig=null, useSSL=false, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@13642752::bindDn=admin...@peninsula.wednet.edu, bindSaslConfig=null, bindControls=null]], providerConnectionFactory=[org.ldaptive.provider.jndi.JndiConnectionFactory@737128815::metadata=[ldapUrl=ldap://xxx.xx.xx.xx, count=1], environment={com.sun.jndi.ldap.connect.timeout=3000, java.naming.ldap.version=3, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory}, providerConfig=[org.ldaptive.provider.jndi.JndiProviderConfig@859450866::operationExceptionResultCodes=[PROTOCOL_ERROR, SERVER_DOWN], properties={}, connectionStrategy=org.ldaptive.provider.DefaultConnectionStrategy@1344f7fe, controlProcessor=org.ldaptive.provider.ControlProcessor@5ffdd510, environment=null, tracePackets=null, removeDnUrls=true, searchIgnoreResultCodes=[TIME_LIMIT_EXCEEDED, SIZE_LIMIT_EXCEEDED, PARTIAL_RESULTS], sslSocketFactory=null, hostnameVerifier=null]], providerConnection=org.ldaptive.provider.jndi.JndiConnection@3151277f], result=true, resultCode=SUCCESS, message=null, controls=null] for criteria=[org.ldaptive.auth.AuthenticationCriteria@1515358531::dn=(correctDN), authenticationRequest=[org.ldaptive.auth.AuthenticationRequest@1916764681::user=username, retAttrs=[telephoneNumber, mail, sAMAccountName, displayName, givenName, employeeId, memberOf, sn, passwordExpired]]]>
[STDOUT] 2016-10-25 21:00:45,647 DEBUG [org.ldaptive.auth.SearchEntryResolver] - <resolve criteria=[org.ldaptive.auth.AuthenticationCriteria@1515358531::dn=(correctDN), authenticationRequest=[org.ldaptive.auth.AuthenticationRequest@1916764681::user=username, retAttrs=[telephoneNumber, mail, sAMAccountName, displayName, givenName, employeeId, memberOf, sn, passwordExpired]]]>
[STDOUT] 2016-10-25 21:00:45,651 DEBUG [org.ldaptive.SearchOperation] - <execute request=[org.ldaptive.SearchRequest@-1249778521::basedn=(correctDN), searchFilter=[org.ldaptive.SearchFilter@1642584434::filter=(objectClass=*), parameters={}], returnAttributes=[telephoneNumber, mail, sAMAccountName, displayName, givenName, employeeId, memberOf, sn, passwordExpired], searchScope=OBJECT, timeLimit=0, sizeLimit=0, derefAliases=null, typesOnly=false, binaryAttributes=null, sortBehavior=UNORDERED, searchEntryHandlers=null, searchReferenceHandlers=null, controls=null, referralHandler=null, intermediateResponseHandlers=null] with connection=[org.ldaptive.DefaultConnectionFactory$DefaultConnection@919561079::config=[org.ldaptive.ConnectionConfig@571943680::ldapUrl=ldap://xxx.xx.xx.xx, connectTimeout=3000, responseTimeout=-1, sslConfig=null, useSSL=false, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@13642752::bindDn=admin...@peninsula.wednet.edu, bindSaslConfig=null, bindControls=null]], providerConnectionFactory=[org.ldaptive.provider.jndi.JndiConnectionFactory@737128815::metadata=[ldapUrl=ldap://xxx.xx.xx.xx, count=1], environment={com.sun.jndi.ldap.connect.timeout=3000, java.naming.ldap.version=3, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory}, providerConfig=[org.ldaptive.provider.jndi.JndiProviderConfig@859450866::operationExceptionResultCodes=[PROTOCOL_ERROR, SERVER_DOWN], properties={}, connectionStrategy=org.ldaptive.provider.DefaultConnectionStrategy@1344f7fe, controlProcessor=org.ldaptive.provider.ControlProcessor@5ffdd510, environment=null, tracePackets=null, removeDnUrls=true, searchIgnoreResultCodes=[TIME_LIMIT_EXCEEDED, SIZE_LIMIT_EXCEEDED, PARTIAL_RESULTS], sslSocketFactory=null, hostnameVerifier=null]], providerConnection=org.ldaptive.provider.jndi.JndiConnection@3151277f]>
[STDOUT] 2016-10-25 21:00:45,750 DEBUG [org.ldaptive.SearchOperation] - <execute response=[org.ldaptive.Response@1867647831::result=[org.ldaptive.SearchResult@-634618133::entries=[[dn=(correctDN)[[mail[user...@psd401.net]], [givenName[BRANDON]], [displayName[MARTIN, BRANDON]], [memberOf[]], [sAMAccountName[username]]], responseControls=null, messageId=-1]], references=[]], resultCode=SUCCESS, message=null, matchedDn=null, responseControls=null, referralURLs=null, messageId=-1] for request=[org.ldaptive.SearchRequest@-1249778521::basedn=(correctDN), searchFilter=[org.ldaptive.SearchFilter@1642584434::filter=(objectClass=*), parameters={}], returnAttributes=[telephoneNumber, mail, sAMAccountName, displayName, givenName, employeeId, memberOf, sn, passwordExpired], searchScope=OBJECT, timeLimit=0, sizeLimit=0, derefAliases=null, typesOnly=false, binaryAttributes=null, sortBehavior=UNORDERED, searchEntryHandlers=null, searchReferenceHandlers=null, controls=null, referralHandler=null, intermediateResponseHandlers=null] with connection=[org.ldaptive.DefaultConnectionFactory$DefaultConnection@919561079::config=[org.ldaptive.ConnectionConfig@571943680::ldapUrl=ldap://xxx.xx.xx.xx, connectTimeout=3000, responseTimeout=-1, sslConfig=null, useSSL=false, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@13642752::bindDn=admin...@peninsula.wednet.edu, bindSaslConfig=null, bindControls=null]], providerConnectionFactory=[org.ldaptive.provider.jndi.JndiConnectionFactory@737128815::metadata=[ldapUrl=ldap://xxx.xx.xx.xx, count=1], environment={com.sun.jndi.ldap.connect.timeout=3000, java.naming.ldap.version=3, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory}, providerConfig=[org.ldaptive.provider.jndi.JndiProviderConfig@859450866::operationExceptionResultCodes=[PROTOCOL_ERROR, SERVER_DOWN], properties={}, connectionStrategy=org.ldaptive.provider.DefaultConnectionStrategy@1344f7fe, controlProcessor=org.ldaptive.provider.ControlProcessor@5ffdd510, environment=null, tracePackets=null, removeDnUrls=true, searchIgnoreResultCodes=[TIME_LIMIT_EXCEEDED, SIZE_LIMIT_EXCEEDED, PARTIAL_RESULTS], sslSocketFactory=null, hostnameVerifier=null]], providerConnection=org.ldaptive.provider.jndi.JndiConnection@3151277f]>
[STDOUT] 2016-10-25 21:00:45,770 DEBUG [org.ldaptive.auth.SearchEntryResolver] - <resolved result=[org.ldaptive.SearchResult@-634618133::entries=[[dn=(correctDN)[[mail[user...@psd401.net]], [givenName[BRANDON]], [displayName[MARTIN, BRANDON]], [memberOf[]], [sn[MARTIN]], [employeeID[MARTIBRA000]], [sAMAccountName[username]]], responseControls=null, messageId=-1]], references=[]] for criteria=[org.ldaptive.auth.AuthenticationCriteria@1515358531::dn=(correctDN), authenticationRequest=[org.ldaptive.auth.AuthenticationRequest@1916764681::user=username, retAttrs=[telephoneNumber, mail, sAMAccountName, displayName, givenName, employeeId, memberOf, sn, passwordExpired]]]>
[STDOUT] 2016-10-25 21:00:45,772 INFO [org.ldaptive.auth.Authenticator] - <Authentication succeeded for dn: CN=Martin\, Brandon L,OU=TSD,OU=Staff,OU=Users,OU=PSD,DC=Peninsula,DC=wednet,DC=edu>
[STDOUT] 2016-10-25 21:00:45,775 DEBUG [org.ldaptive.auth.Authenticator] - <authenticate response=[org.ldaptive.auth.AuthenticationHandlerResponse@1232053453::connection=[org.ldaptive.DefaultConnectionFactory$DefaultConnection@919561079::config=[org.ldaptive.ConnectionConfig@571943680::ldapUrl=ldap://xxx.xx.xx.xx, connectTimeout=3000, responseTimeout=-1, sslConfig=null, useSSL=false, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@13642752::bindDn=admin...@peninsula.wednet.edu, bindSaslConfig=null, bindControls=null]], providerConnectionFactory=[org.ldaptive.provider.jndi.JndiConnectionFactory@737128815::metadata=[ldapUrl=ldap://xxx.xx.xx.xx, count=1], environment={com.sun.jndi.ldap.connect.timeout=3000, java.naming.ldap.version=3, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory}, providerConfig=[org.ldaptive.provider.jndi.JndiProviderConfig@859450866::operationExceptionResultCodes=[PROTOCOL_ERROR, SERVER_DOWN], properties={}, connectionStrategy=org.ldaptive.provider.DefaultConnectionStrategy@1344f7fe, controlProcessor=org.ldaptive.provider.ControlProcessor@5ffdd510, environment=null, tracePackets=null, removeDnUrls=true, searchIgnoreResultCodes=[TIME_LIMIT_EXCEEDED, SIZE_LIMIT_EXCEEDED, PARTIAL_RESULTS], sslSocketFactory=null, hostnameVerifier=null]], providerConnection=org.ldaptive.provider.jndi.JndiConnection@3151277f], result=true, resultCode=SUCCESS, message=null, controls=null] for dn=(correctDN) with request=[org.ldaptive.auth.AuthenticationRequest@1916764681::user=username, retAttrs=[telephoneNumber, mail, sAMAccountName, displayName, givenName, employeeId, memberOf, sn, passwordExpired]]>
[STDOUT] 2016-10-25 21:00:45,788 INFO [org.jasig.cas.authentication.PolicyBasedAuthenticationManager] - <LdapAuthenticationHandler successfully authenticated username>
[STDOUT] 2016-10-25 21:00:45,801 INFO [org.jasig.cas.authentication.PolicyBasedAuthenticationManager] - <Authenticated username with credentials [username].>
[STDOUT] 2016-10-25 21:00:45,824 INFO [org.jasig.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - <Audit trail record BEGIN
[STDOUT] =============================================================
[STDOUT] WHO: username
[STDOUT] WHAT: Supplied credentials: [username]
[STDOUT] ACTION: AUTHENTICATION_SUCCESS
[STDOUT] APPLICATION: CAS
[STDOUT] WHEN: Tue Oct 25 21:00:45 UTC 2016
[STDOUT] CLIENT IP ADDRESS: 172.17.0.1
[STDOUT] SERVER IP ADDRESS: 172.17.0.3
[STDOUT] =============================================================
[STDOUT]
[STDOUT] >
[STDOUT] 2016-10-25 21:00:45,938 INFO [org.jasig.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - <Audit trail record BEGIN
[STDOUT] =============================================================
[STDOUT] WHO: audit:unknown
[STDOUT] ACTION: TICKET_GRANTING_TICKET_CREATED
[STDOUT] APPLICATION: CAS
[STDOUT] WHEN: Tue Oct 25 21:00:45 UTC 2016
[STDOUT] CLIENT IP ADDRESS: 172.17.0.1
[STDOUT] SERVER IP ADDRESS: 172.17.0.3
[STDOUT] =============================================================
[STDOUT]
[STDOUT] >
[STDOUT] 2016-10-25 21:00:49,950 INFO [org.jasig.cas.services.DefaultServicesManagerImpl] - <Reloading registered services.>
[STDOUT] 2016-10-25 21:00:49,961 INFO [org.jasig.cas.services.DefaultServicesManagerImpl] - <Loaded 2 services from JsonServiceRegistryDao.>
[STDOUT] 2016-10-25 21:01:09,189 INFO [org.jasig.cas.ticket.registry.TicketRegistryCleaner] - <Beginning ticket cleanup...>
[STDOUT] 2016-10-25 21:01:09,190 INFO [org.jasig.cas.ticket.registry.TicketRegistryCleaner] - <0 expired tickets found and removed.>
[STDOUT] 2016-10-25 21:01:27,996 DEBUG [org.ldaptive.auth.PooledSearchDnResolver] - <resolve user=username>
[STDOUT] 2016-10-25 21:01:27,998 DEBUG [org.ldaptive.auth.PooledSearchDnResolver] - <searching for DN using userFilter>
[STDOUT] 2016-10-25 21:01:28,000 DEBUG [org.ldaptive.SearchOperation] - <execute request=[org.ldaptive.SearchRequest@1737167252::baseDn=ou=Users,ou=PSD,dc=Peninsula,dc=wednet,dc=edu, searchFilter=[org.ldaptive.SearchFilter@1615263833::filter=(sAMAccountName={user}), parameters={user=username}], returnAttributes=[1.1], searchScope=SUBTREE, timeLimit=0, sizeLimit=0, derefAliases=null, typesOnly=false, binaryAttributes=null, sortBehavior=UNORDERED, searchEntryHandlers=null, searchReferenceHandlers=null, controls=null, referralHandler=null, intermediateResponseHandlers=null] with connection=[org.ldaptive.DefaultConnectionFactory$DefaultConnection@300836639::config=[org.ldaptive.ConnectionConfig@542467430::ldapUrl=ldap://xxx.xx.xx.xx, connectTimeout=3000, responseTimeout=-1, sslConfig=null, useSSL=false, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@240055488::bindDn=admin...@peninsula.wednet.edu, bindSaslConfig=null, bindControls=null]], providerConnectionFactory=[org.ldaptive.provider.jndi.JndiConnectionFactory@404787971::metadata=[ldapUrl=ldap://xxx.xx.xx.xx, count=1], environment={com.sun.jndi.ldap.connect.timeout=3000, java.naming.ldap.version=3, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory}, providerConfig=[org.ldaptive.provider.jndi.JndiProviderConfig@1662417126::operationExceptionResultCodes=[PROTOCOL_ERROR, SERVER_DOWN], properties={}, connectionStrategy=org.ldaptive.provider.DefaultConnectionStrategy@1344f7fe, controlProcessor=org.ldaptive.provider.ControlProcessor@64d53f0d, environment=null, tracePackets=null, removeDnUrls=true, searchIgnoreResultCodes=[TIME_LIMIT_EXCEEDED, SIZE_LIMIT_EXCEEDED, PARTIAL_RESULTS], sslSocketFactory=null, hostnameVerifier=null]], providerConnection=org.ldaptive.provider.jndi.JndiConnection@57df09a7]>
[STDOUT] 2016-10-25 21:01:28,028 DEBUG [org.ldaptive.SearchOperation] - <execute response=[org.ldaptive.Response@81511301::result=[org.ldaptive.SearchResult@878591910::entries=[[dn=(correctDN)[], responseControls=null, messageId=-1]], references=[]], resultCode=SUCCESS, message=null, matchedDn=null, responseControls=null, referralURLs=null, messageId=-1] for request=[org.ldaptive.SearchRequest@1737167252::baseDn=ou=Users,ou=PSD,dc=Peninsula,dc=wednet,dc=edu, searchFilter=[org.ldaptive.SearchFilter@1615263833::filter=(sAMAccountName={user}), parameters={user=username}], returnAttributes=[1.1], searchScope=SUBTREE, timeLimit=0, sizeLimit=0, derefAliases=null, typesOnly=false, binaryAttributes=null, sortBehavior=UNORDERED, searchEntryHandlers=null, searchReferenceHandlers=null, controls=null, referralHandler=null, intermediateResponseHandlers=null] with connection=[org.ldaptive.DefaultConnectionFactory$DefaultConnection@300836639::config=[org.ldaptive.ConnectionConfig@542467430::ldapUrl=ldap://xxx.xx.xx.xx, connectTimeout=3000, responseTimeout=-1, sslConfig=null, useSSL=false, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@240055488::bindDn=admin...@peninsula.wednet.edu, bindSaslConfig=null, bindControls=null]], providerConnectionFactory=[org.ldaptive.provider.jndi.JndiConnectionFactory@404787971::metadata=[ldapUrl=ldap://xxx.xx.xx.xx, count=1], environment={com.sun.jndi.ldap.connect.timeout=3000, java.naming.ldap.version=3, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory}, providerConfig=[org.ldaptive.provider.jndi.JndiProviderConfig@1662417126::operationExceptionResultCodes=[PROTOCOL_ERROR, SERVER_DOWN], properties={}, connectionStrategy=org.ldaptive.provider.DefaultConnectionStrategy@1344f7fe, controlProcessor=org.ldaptive.provider.ControlProcessor@64d53f0d, environment=null, tracePackets=null, removeDnUrls=true, searchIgnoreResultCodes=[TIME_LIMIT_EXCEEDED, SIZE_LIMIT_EXCEEDED, PARTIAL_RESULTS], sslSocketFactory=null, hostnameVerifier=null]], providerConnection=org.ldaptive.provider.jndi.JndiConnection@57df09a7]>
[STDOUT] 2016-10-25 21:01:28,034 DEBUG [org.ldaptive.auth.PooledSearchDnResolver] - <resolved dn=(correctDN) for user=username>
[STDOUT] 2016-10-25 21:01:28,040 DEBUG [org.ldaptive.auth.Authenticator] - <authenticate dn=(correctDN) with request=[org.ldaptive.auth.AuthenticationRequest@14960582::user=username, retAttrs=[telephoneNumber, mail, sAMAccountName, displayName, givenName, employeeId, memberOf, sn, passwordExpired]]>
[STDOUT] 2016-10-25 21:01:28,052 DEBUG [org.ldaptive.auth.PooledBindAuthenticationHandler] - <authenticate criteria=[org.ldaptive.auth.AuthenticationCriteria@1172752830::dn=(correctDN), authenticationRequest=[org.ldaptive.auth.AuthenticationRequest@14960582::user=username, retAttrs=[telephoneNumber, mail, sAMAccountName, displayName, givenName, employeeId, memberOf, sn, passwordExpired]]]>
[STDOUT] 2016-10-25 21:01:28,053 DEBUG [org.ldaptive.BindOperation] - <execute request=[org.ldaptive.BindRequest@787751976::binddn=(correctDN), 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@919561079::config=[org.ldaptive.ConnectionConfig@571943680::ldapUrl=ldap://xxx.xx.xx.xx, connectTimeout=3000, responseTimeout=-1, sslConfig=null, useSSL=false, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@13642752::bindDn=admin...@peninsula.wednet.edu, bindSaslConfig=null, bindControls=null]], providerConnectionFactory=[org.ldaptive.provider.jndi.JndiConnectionFactory@737128815::metadata=[ldapUrl=ldap://xxx.xx.xx.xx, count=1], environment={com.sun.jndi.ldap.connect.timeout=3000, java.naming.ldap.version=3, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory}, providerConfig=[org.ldaptive.provider.jndi.JndiProviderConfig@859450866::operationExceptionResultCodes=[PROTOCOL_ERROR, SERVER_DOWN], properties={}, connectionStrategy=org.ldaptive.provider.DefaultConnectionStrategy@1344f7fe, controlProcessor=org.ldaptive.provider.ControlProcessor@5ffdd510, environment=null, tracePackets=null, removeDnUrls=true, searchIgnoreResultCodes=[TIME_LIMIT_EXCEEDED, SIZE_LIMIT_EXCEEDED, PARTIAL_RESULTS], sslSocketFactory=null, hostnameVerifier=null]], providerConnection=org.ldaptive.provider.jndi.JndiConnection@3151277f]>
[STDOUT] 2016-10-25 21:01:28,411 DEBUG [org.ldaptive.auth.PooledBindAuthenticationHandler] - <authenticate response=[org.ldaptive.auth.AuthenticationHandlerResponse@1206179199::connection=[org.ldaptive.DefaultConnectionFactory$DefaultConnection@919561079::config=[org.ldaptive.ConnectionConfig@571943680::ldapUrl=ldap://xxx.xx.xx.xx, connectTimeout=3000, responseTimeout=-1, sslConfig=null, useSSL=false, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@13642752::bindDn=admin...@peninsula.wednet.edu, bindSaslConfig=null, bindControls=null]], providerConnectionFactory=[org.ldaptive.provider.jndi.JndiConnectionFactory@737128815::metadata=[ldapUrl=ldap://xxx.xx.xx.xx, count=1], environment={com.sun.jndi.ldap.connect.timeout=3000, java.naming.ldap.version=3, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory}, providerConfig=[org.ldaptive.provider.jndi.JndiProviderConfig@859450866::operationExceptionResultCodes=[PROTOCOL_ERROR, SERVER_DOWN], properties={}, connectionStrategy=org.ldaptive.provider.DefaultConnectionStrategy@1344f7fe, controlProcessor=org.ldaptive.provider.ControlProcessor@5ffdd510, environment=null, tracePackets=null, removeDnUrls=true, searchIgnoreResultCodes=[TIME_LIMIT_EXCEEDED, SIZE_LIMIT_EXCEEDED, PARTIAL_RESULTS], sslSocketFactory=null, hostnameVerifier=null]], providerConnection=org.ldaptive.provider.jndi.JndiConnection@3151277f], result=false, resultCode=INVALID_CREDENTIALS, message=javax.naming.AuthenticationException: [LDAP: error code 49 - 80090308: LdapErr: DSID-0C0903CF, comment: AcceptSecurityContext error, data 773, v2580], controls=null] for criteria=[org.ldaptive.auth.AuthenticationCriteria@1172752830::dn=(correctDN), authenticationRequest=[org.ldaptive.auth.AuthenticationRequest@14960582::user=username, retAttrs=[telephoneNumber, mail, sAMAccountName, displayName, givenName, employeeId, memberOf, sn, passwordExpired]]]>
[STDOUT] 2016-10-25 21:01:28,419 INFO [org.ldaptive.auth.Authenticator] - <Authentication failed for dn: CN=Martin\, Brandon L,OU=TSD,OU=Staff,OU=Users,OU=PSD,DC=Peninsula,DC=wednet,DC=edu>
[STDOUT] 2016-10-25 21:01:28,420 DEBUG [org.ldaptive.auth.Authenticator] - <authenticate response=[org.ldaptive.auth.AuthenticationHandlerResponse@1206179199::connection=[org.ldaptive.DefaultConnectionFactory$DefaultConnection@919561079::config=[org.ldaptive.ConnectionConfig@571943680::ldapUrl=ldap://xxx.xx.xx.xx, connectTimeout=3000, responseTimeout=-1, sslConfig=null, useSSL=false, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@13642752::bindDn=admin...@peninsula.wednet.edu, bindSaslConfig=null, bindControls=null]], providerConnectionFactory=[org.ldaptive.provider.jndi.JndiConnectionFactory@737128815::metadata=[ldapUrl=ldap://xxx.xx.xx.xx, count=1], environment={com.sun.jndi.ldap.connect.timeout=3000, java.naming.ldap.version=3, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory}, providerConfig=[org.ldaptive.provider.jndi.JndiProviderConfig@859450866::operationExceptionResultCodes=[PROTOCOL_ERROR, SERVER_DOWN], properties={}, connectionStrategy=org.ldaptive.provider.DefaultConnectionStrategy@1344f7fe, controlProcessor=org.ldaptive.provider.ControlProcessor@5ffdd510, environment=null, tracePackets=null, removeDnUrls=true, searchIgnoreResultCodes=[TIME_LIMIT_EXCEEDED, SIZE_LIMIT_EXCEEDED, PARTIAL_RESULTS], sslSocketFactory=null, hostnameVerifier=null]], providerConnection=org.ldaptive.provider.jndi.JndiConnection@3151277f], result=false, resultCode=INVALID_CREDENTIALS, message=javax.naming.AuthenticationException: [LDAP: error code 49 - 80090308: LdapErr: DSID-0C0903CF, comment: AcceptSecurityContext error, data 773, v2580], controls=null] for dn=(correctDN) with request=[org.ldaptive.auth.AuthenticationRequest@14960582::user=username, retAttrs=[telephoneNumber, mail, sAMAccountName, displayName, givenName, employeeId, memberOf, sn, passwordExpired]]>
[STDOUT] 2016-10-25 21:01:28,424 INFO [org.jasig.cas.authentication.PolicyBasedAuthenticationManager] - <LdapAuthenticationHandler failed authenticating username>
[STDOUT] 2016-10-25 21:01:28,428 INFO [org.jasig.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - <Audit trail record BEGIN
[STDOUT] =============================================================
[STDOUT] WHO: username
[STDOUT] WHAT: Supplied credentials: [username]
[STDOUT] ACTION: AUTHENTICATION_FAILED
[STDOUT] APPLICATION: CAS
[STDOUT] WHEN: Tue Oct 25 21:01:28 UTC 2016
[STDOUT] CLIENT IP ADDRESS: 172.17.0.1
[STDOUT] SERVER IP ADDRESS: 172.17.0.3
[STDOUT] =============================================================
[STDOUT]
[STDOUT] >
[STDOUT] 2016-10-25 21:01:42,338 DEBUG [org.ldaptive.auth.PooledSearchDnResolver] - <resolve user=username>
[STDOUT] 2016-10-25 21:01:42,339 DEBUG [org.ldaptive.auth.PooledSearchDnResolver] - <searching for DN using userFilter>
[STDOUT] 2016-10-25 21:01:42,341 DEBUG [org.ldaptive.SearchOperation] - <execute request=[org.ldaptive.SearchRequest@1737167252::baseDn=ou=Users,ou=PSD,dc=Peninsula,dc=wednet,dc=edu, searchFilter=[org.ldaptive.SearchFilter@1615263833::filter=(sAMAccountName={user}), parameters={user=username}], returnAttributes=[1.1], searchScope=SUBTREE, timeLimit=0, sizeLimit=0, derefAliases=null, typesOnly=false, binaryAttributes=null, sortBehavior=UNORDERED, searchEntryHandlers=null, searchReferenceHandlers=null, controls=null, referralHandler=null, intermediateResponseHandlers=null] with connection=[org.ldaptive.DefaultConnectionFactory$DefaultConnection@300836639::config=[org.ldaptive.ConnectionConfig@542467430::ldapUrl=ldap://xxx.xx.xx.xx, connectTimeout=3000, responseTimeout=-1, sslConfig=null, useSSL=false, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@240055488::bindDn=admin...@peninsula.wednet.edu, bindSaslConfig=null, bindControls=null]], providerConnectionFactory=[org.ldaptive.provider.jndi.JndiConnectionFactory@404787971::metadata=[ldapUrl=ldap://xxx.xx.xx.xx, count=1], environment={com.sun.jndi.ldap.connect.timeout=3000, java.naming.ldap.version=3, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory}, providerConfig=[org.ldaptive.provider.jndi.JndiProviderConfig@1662417126::operationExceptionResultCodes=[PROTOCOL_ERROR, SERVER_DOWN], properties={}, connectionStrategy=org.ldaptive.provider.DefaultConnectionStrategy@1344f7fe, controlProcessor=org.ldaptive.provider.ControlProcessor@64d53f0d, environment=null, tracePackets=null, removeDnUrls=true, searchIgnoreResultCodes=[TIME_LIMIT_EXCEEDED, SIZE_LIMIT_EXCEEDED, PARTIAL_RESULTS], sslSocketFactory=null, hostnameVerifier=null]], providerConnection=org.ldaptive.provider.jndi.JndiConnection@57df09a7]>
[STDOUT] 2016-10-25 21:01:42,383 DEBUG [org.ldaptive.SearchOperation] - <execute response=[org.ldaptive.Response@1842253550::result=[org.ldaptive.SearchResult@878591910::entries=[[dn=(correctDN)[], responseControls=null, messageId=-1]], references=[]], resultCode=SUCCESS, message=null, matchedDn=null, responseControls=null, referralURLs=null, messageId=-1] for request=[org.ldaptive.SearchRequest@1737167252::baseDn=ou=Users,ou=PSD,dc=Peninsula,dc=wednet,dc=edu, searchFilter=[org.ldaptive.SearchFilter@1615263833::filter=(sAMAccountName={user}), parameters={user=username}], returnAttributes=[1.1], searchScope=SUBTREE, timeLimit=0, sizeLimit=0, derefAliases=null, typesOnly=false, binaryAttributes=null, sortBehavior=UNORDERED, searchEntryHandlers=null, searchReferenceHandlers=null, controls=null, referralHandler=null, intermediateResponseHandlers=null] with connection=[org.ldaptive.DefaultConnectionFactory$DefaultConnection@300836639::config=[org.ldaptive.ConnectionConfig@542467430::ldapUrl=ldap://xxx.xx.xx.xx, connectTimeout=3000, responseTimeout=-1, sslConfig=null, useSSL=false, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@240055488::bindDn=admin...@peninsula.wednet.edu, bindSaslConfig=null, bindControls=null]], providerConnectionFactory=[org.ldaptive.provider.jndi.JndiConnectionFactory@404787971::metadata=[ldapUrl=ldap://xxx.xx.xx.xx, count=1], environment={com.sun.jndi.ldap.connect.timeout=3000, java.naming.ldap.version=3, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory}, providerConfig=[org.ldaptive.provider.jndi.JndiProviderConfig@1662417126::operationExceptionResultCodes=[PROTOCOL_ERROR, SERVER_DOWN], properties={}, connectionStrategy=org.ldaptive.provider.DefaultConnectionStrategy@1344f7fe, controlProcessor=org.ldaptive.provider.ControlProcessor@64d53f0d, environment=null, tracePackets=null, removeDnUrls=true, searchIgnoreResultCodes=[TIME_LIMIT_EXCEEDED, SIZE_LIMIT_EXCEEDED, PARTIAL_RESULTS], sslSocketFactory=null, hostnameVerifier=null]], providerConnection=org.ldaptive.provider.jndi.JndiConnection@57df09a7]>
[STDOUT] 2016-10-25 21:01:42,384 DEBUG [org.ldaptive.auth.PooledSearchDnResolver] - <resolved dn=(correctDN) for user=username>
[STDOUT] 2016-10-25 21:01:42,385 DEBUG [org.ldaptive.auth.Authenticator] - <authenticate dn=(correctDN) with request=[org.ldaptive.auth.AuthenticationRequest@131937946::user=username, retAttrs=[telephoneNumber, mail, sAMAccountName, displayName, givenName, employeeId, memberOf, sn, passwordExpired]]>
[STDOUT] 2016-10-25 21:01:42,386 DEBUG [org.ldaptive.auth.PooledBindAuthenticationHandler] - <authenticate criteria=[org.ldaptive.auth.AuthenticationCriteria@118379843::dn=(correctDN), authenticationRequest=[org.ldaptive.auth.AuthenticationRequest@131937946::user=username, retAttrs=[telephoneNumber, mail, sAMAccountName, displayName, givenName, employeeId, memberOf, sn, passwordExpired]]]>
[STDOUT] 2016-10-25 21:01:42,388 DEBUG [org.ldaptive.BindOperation] - <execute request=[org.ldaptive.BindRequest@1652278718::binddn=(correctDN), 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@919561079::config=[org.ldaptive.ConnectionConfig@571943680::ldapUrl=ldap://xxx.xx.xx.xx, connectTimeout=3000, responseTimeout=-1, sslConfig=null, useSSL=false, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@13642752::bindDn=admin...@peninsula.wednet.edu, bindSaslConfig=null, bindControls=null]], providerConnectionFactory=[org.ldaptive.provider.jndi.JndiConnectionFactory@737128815::metadata=[ldapUrl=ldap://xxx.xx.xx.xx, count=1], environment={com.sun.jndi.ldap.connect.timeout=3000, java.naming.ldap.version=3, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory}, providerConfig=[org.ldaptive.provider.jndi.JndiProviderConfig@859450866::operationExceptionResultCodes=[PROTOCOL_ERROR, SERVER_DOWN], properties={}, connectionStrategy=org.ldaptive.provider.DefaultConnectionStrategy@1344f7fe, controlProcessor=org.ldaptive.provider.ControlProcessor@5ffdd510, environment=null, tracePackets=null, removeDnUrls=true, searchIgnoreResultCodes=[TIME_LIMIT_EXCEEDED, SIZE_LIMIT_EXCEEDED, PARTIAL_RESULTS], sslSocketFactory=null, hostnameVerifier=null]], providerConnection=org.ldaptive.provider.jndi.JndiConnection@3151277f]>
[STDOUT] 2016-10-25 21:01:42,555 DEBUG [org.ldaptive.auth.PooledBindAuthenticationHandler] - <authenticate response=[org.ldaptive.auth.AuthenticationHandlerResponse@2077990625::connection=[org.ldaptive.DefaultConnectionFactory$DefaultConnection@919561079::config=[org.ldaptive.ConnectionConfig@571943680::ldapUrl=ldap://xxx.xx.xx.xx, connectTimeout=3000, responseTimeout=-1, sslConfig=null, useSSL=false, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@13642752::bindDn=admin...@peninsula.wednet.edu, bindSaslConfig=null, bindControls=null]], providerConnectionFactory=[org.ldaptive.provider.jndi.JndiConnectionFactory@737128815::metadata=[ldapUrl=ldap://xxx.xx.xx.xx, count=1], environment={com.sun.jndi.ldap.connect.timeout=3000, java.naming.ldap.version=3, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory}, providerConfig=[org.ldaptive.provider.jndi.JndiProviderConfig@859450866::operationExceptionResultCodes=[PROTOCOL_ERROR, SERVER_DOWN], properties={}, connectionStrategy=org.ldaptive.provider.DefaultConnectionStrategy@1344f7fe, controlProcessor=org.ldaptive.provider.ControlProcessor@5ffdd510, environment=null, tracePackets=null, removeDnUrls=true, searchIgnoreResultCodes=[TIME_LIMIT_EXCEEDED, SIZE_LIMIT_EXCEEDED, PARTIAL_RESULTS], sslSocketFactory=null, hostnameVerifier=null]], providerConnection=org.ldaptive.provider.jndi.JndiConnection@3151277f], result=false, resultCode=INVALID_CREDENTIALS, message=javax.naming.AuthenticationException: [LDAP: error code 49 - 80090308: LdapErr: DSID-0C0903CF, comment: AcceptSecurityContext error, data 773, v2580], controls=null] for criteria=[org.ldaptive.auth.AuthenticationCriteria@118379843::dn=(correctDN), authenticationRequest=[org.ldaptive.auth.AuthenticationRequest@131937946::user=username, retAttrs=[telephoneNumber, mail, sAMAccountName, displayName, givenName, employeeId, memberOf, sn, passwordExpired]]]>
[STDOUT] 2016-10-25 21:01:42,556 INFO [org.ldaptive.auth.Authenticator] - <Authentication failed for dn: CN=Martin\, Brandon L,OU=TSD,OU=Staff,OU=Users,OU=PSD,DC=Peninsula,DC=wednet,DC=edu>
[STDOUT] 2016-10-25 21:01:42,557 DEBUG [org.ldaptive.auth.Authenticator] - <authenticate response=[org.ldaptive.auth.AuthenticationHandlerResponse@2077990625::connection=[org.ldaptive.DefaultConnectionFactory$DefaultConnection@919561079::config=[org.ldaptive.ConnectionConfig@571943680::ldapUrl=ldap://xxx.xx.xx.xx, connectTimeout=3000, responseTimeout=-1, sslConfig=null, useSSL=false, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@13642752::bindDn=admin...@peninsula.wednet.edu, bindSaslConfig=null, bindControls=null]], providerConnectionFactory=[org.ldaptive.provider.jndi.JndiConnectionFactory@737128815::metadata=[ldapUrl=ldap://xxx.xx.xx.xx, count=1], environment={com.sun.jndi.ldap.connect.timeout=3000, java.naming.ldap.version=3, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory}, providerConfig=[org.ldaptive.provider.jndi.JndiProviderConfig@859450866::operationExceptionResultCodes=[PROTOCOL_ERROR, SERVER_DOWN], properties={}, connectionStrategy=org.ldaptive.provider.DefaultConnectionStrategy@1344f7fe, controlProcessor=org.ldaptive.provider.ControlProcessor@5ffdd510, environment=null, tracePackets=null, removeDnUrls=true, searchIgnoreResultCodes=[TIME_LIMIT_EXCEEDED, SIZE_LIMIT_EXCEEDED, PARTIAL_RESULTS], sslSocketFactory=null, hostnameVerifier=null]], providerConnection=org.ldaptive.provider.jndi.JndiConnection@3151277f], result=false, resultCode=INVALID_CREDENTIALS, message=javax.naming.AuthenticationException: [LDAP: error code 49 - 80090308: LdapErr: DSID-0C0903CF, comment: AcceptSecurityContext error, data 773, v2580], controls=null] for dn=(correctDN) with request=[org.ldaptive.auth.AuthenticationRequest@131937946::user=username, retAttrs=[telephoneNumber, mail, sAMAccountName, displayName, givenName, employeeId, memberOf, sn, passwordExpired]]>
[STDOUT] 2016-10-25 21:01:42,558 INFO [org.jasig.cas.authentication.PolicyBasedAuthenticationManager] - <LdapAuthenticationHandler failed authenticating username>
[STDOUT] 2016-10-25 21:01:42,560 INFO [org.jasig.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - <Audit trail record BEGIN
[STDOUT] =============================================================
[STDOUT] WHO: username
[STDOUT] WHAT: Supplied credentials: [username]
[STDOUT] ACTION: AUTHENTICATION_FAILED
[STDOUT] APPLICATION: CAS
[STDOUT] WHEN: Tue Oct 25 21:01:42 UTC 2016
[STDOUT] CLIENT IP ADDRESS: 172.17.0.1
[STDOUT] SERVER IP ADDRESS: 172.17.0.3
[STDOUT] =============================================================
[STDOUT]
[STDOUT] >
I realize the error about 'metricsController' is a non issue.
Brandon Martin
Oct 25, 2016, 5:19:22 PM10/25/16
to CAS Community
It seems the logs were stripped. Here's a file instead:
I see that it says it can't find my log4j2.xml file, I have it in my overlay but it must be in the wrong place. Currently I'm adding it to /etc/cas
On Tuesday, October 25, 2016 at 2:13:10 PM UTC-7, Brandon Martin wrote:
On Tuesday, October 25, 2016 at 2:13:10 PM UTC-7, Brandon Martin wrote:
Okay here we go:
Misagh Moayyed
Oct 25, 2016, 5:25:42 PM10/25/16
to CAS Community
You should set org.jasig.cas to DEBUG and that will get you more info.
Also, I’d have to defer to Daniel, but I believe in order for AD account states to be recognized, you need to switch to the ad-authenticator which should activate the right component that processes and reports back the account state back to CAS in a way that can be intercepted by the login process.
--
Misagh
Misagh
--
- 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/c5369bf5-dafc-437b-b949-9676ae402314%40apereo.org.
Brandon Martin
Oct 25, 2016, 5:32:27 PM10/25/16
to CAS Community, mmoa...@unicon.net
Thank you for the feedback, I'm looking at the documentation here: https://apereo.github.io/cas/4.2.x/installation/LDAP-Authentication.html#configuration-1
It states bind-search-authenticator, I will try the standard ad-authenticator.
Brandon Martin
Oct 25, 2016, 6:21:41 PM10/25/16
to CAS Community, mmoa...@unicon.net
This worked! Thank you!
I had tried the ad-authenticator while trying to setup AD binding, but now that I can authenticate to AD I hadn't tried this.
Thank you for your time! I'm not the best at CAS, but I am subscribed to this group and will contribute to the best of my abilities.
Reply all
Reply to author
Forward
0 new messages