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: > > Okay here we go: > > -- - 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 [email protected]. 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.
[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::[email protected], 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::[email protected], 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::[email protected], 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::[email protected], 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::[email protected], 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::[email protected], 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::[email protected], 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::[email protected], 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::[email protected], 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::[email protected], 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::[email protected], 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::[email protected], 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::[email protected], 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::[email protected], 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::[email protected], 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::[email protected], 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::[email protected], 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::[email protected], 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::[email protected], 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::[email protected], 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::[email protected], 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::[email protected], 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::[email protected], 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::[email protected], 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::[email protected], 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::[email protected], 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::[email protected], 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::[email protected], 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::[email protected], 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::[email protected], 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::[email protected], 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::[email protected], 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::[email protected], 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::[email protected], 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::[email protected], 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::[email protected], 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::[email protected], 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::[email protected], 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::[email protected], 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::[email protected], 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[[email protected]]], [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::[email protected], 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[[email protected]]], [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::[email protected], 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] WHAT: TGT-1-m1OvNexzDT0TCLKwxse0mpxFBx1Y7LG4MUxYuvA9TL3XkqUZZU-login.psd401.net [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::[email protected], 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::[email protected], 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::[email protected], 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::[email protected], 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::[email protected], 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::[email protected], 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::[email protected], 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::[email protected], 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::[email protected], 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::[email protected], 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] >
