Skip to content

Instantly share code, notes, and snippets.

@zoran995
Last active May 15, 2020 16:11
Show Gist options
  • Star 0 You must be signed in to star a gist
  • Fork 0 You must be signed in to fork a gist
  • Save zoran995/d377057af44bc4dfcc5ff666845a66f0 to your computer and use it in GitHub Desktop.
Save zoran995/d377057af44bc4dfcc5ff666845a66f0 to your computer and use it in GitHub Desktop.
cas
2020-05-15 16:21:32,516 INFO [org.apereo.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - Audit trail record BEGIN
=============================================================
WHO: audit:unknown
WHAT: [event=success,timestamp=Fri May 15 16:21:32 CEST 2020,source=RankedAuthenticationProviderWebflowEventResolver]
ACTION: AUTHENTICATION_EVENT_TRIGGERED
APPLICATION: CAS
WHEN: Fri May 15 16:21:32 CEST 2020
CLIENT IP ADDRESS: 0:0:0:0:0:0:0:1
SERVER IP ADDRESS: 0:0:0:0:0:0:0:1
=============================================================
2020-05-15 16:21:40,147 INFO [org.apereo.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - Audit trail record BEGIN
=============================================================
WHO: testadmin
WHAT: Supplied credentials: [UsernamePasswordCredential(username=testadmin)]
ACTION: AUTHENTICATION_SUCCESS
APPLICATION: CAS
WHEN: Fri May 15 16:21:40 CEST 2020
CLIENT IP ADDRESS: 0:0:0:0:0:0:0:1
SERVER IP ADDRESS: 0:0:0:0:0:0:0:1
=============================================================
2020-05-15 16:21:40,148 INFO [org.apereo.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - Audit trail record BEGIN
=============================================================
WHO: testadmin
WHAT: [result=Service Access Granted,service=https://localhost:8443/geonetwork/sig...,principal=SimplePrincipal(id=testadmin, attributes={}),requiredAttributes={}]
ACTION: SERVICE_ACCESS_ENFORCEMENT_TRIGGERED
APPLICATION: CAS
WHEN: Fri May 15 16:21:40 CEST 2020
CLIENT IP ADDRESS: 0:0:0:0:0:0:0:1
SERVER IP ADDRESS: 0:0:0:0:0:0:0:1
=============================================================
2020-05-15 16:21:40,153 INFO [org.apereo.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - Audit trail record BEGIN
=============================================================
WHO: testadmin
WHAT: [result=Service Access Granted,service=https://localhost:8443/geonetwork/sig...,principal=SimplePrincipal(id=testadmin, attributes={}),requiredAttributes={}]
ACTION: SERVICE_ACCESS_ENFORCEMENT_TRIGGERED
APPLICATION: CAS
WHEN: Fri May 15 16:21:40 CEST 2020
CLIENT IP ADDRESS: 0:0:0:0:0:0:0:1
SERVER IP ADDRESS: 0:0:0:0:0:0:0:1
=============================================================
2020-05-15 16:21:40,153 INFO [org.apereo.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - Audit trail record BEGIN
=============================================================
WHO: testadmin
WHAT: TGT-5-********************************************************u4mti7MGrhQGIS-kokeza
ACTION: TICKET_GRANTING_TICKET_CREATED
APPLICATION: CAS
WHEN: Fri May 15 16:21:40 CEST 2020
CLIENT IP ADDRESS: 0:0:0:0:0:0:0:1
SERVER IP ADDRESS: 0:0:0:0:0:0:0:1
=============================================================
2020-05-15 16:21:40,157 INFO [org.apereo.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - Audit trail record BEGIN
=============================================================
WHO: testadmin
WHAT: [result=Service Access Granted,service=https://localhost:8443/geonetwork/sig...,requiredAttributes={}]
ACTION: SERVICE_ACCESS_ENFORCEMENT_TRIGGERED
APPLICATION: CAS
WHEN: Fri May 15 16:21:40 CEST 2020
CLIENT IP ADDRESS: 0:0:0:0:0:0:0:1
SERVER IP ADDRESS: 0:0:0:0:0:0:0:1
=============================================================
2020-05-15 16:21:40,162 INFO [org.apereo.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - Audit trail record BEGIN
=============================================================
WHO: testadmin
WHAT: ST-4-IMGr5Flo9FHSKhba9BVWucPyuW0GIS-kokeza for https://localhost:8443/geonetwork/signin-cas
ACTION: SERVICE_TICKET_CREATED
APPLICATION: CAS
WHEN: Fri May 15 16:21:40 CEST 2020
CLIENT IP ADDRESS: 0:0:0:0:0:0:0:1
SERVER IP ADDRESS: 0:0:0:0:0:0:0:1
=============================================================
2020-05-15 16:21:40,211 INFO [org.apereo.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - Audit trail record BEGIN
=============================================================
WHO: https://localhost:8443/geonetwork/cas_security_proxyreceptor
WHAT: Supplied credentials: [AbstractCredential()]
ACTION: AUTHENTICATION_FAILED
APPLICATION: CAS
WHEN: Fri May 15 16:21:40 CEST 2020
CLIENT IP ADDRESS: 127.0.0.1
SERVER IP ADDRESS: 127.0.0.1
=============================================================
2020-05-15 16:21:40,436 INFO [org.apereo.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - Audit trail record BEGIN
=============================================================
WHO: https://localhost:8443/geonetwork/cas_security_proxyreceptor
WHAT: Supplied credentials: [AbstractCredential()]
ACTION: AUTHENTICATION_FAILED
APPLICATION: CAS
WHEN: Fri May 15 16:21:40 CEST 2020
CLIENT IP ADDRESS: 127.0.0.1
SERVER IP ADDRESS: 127.0.0.1
=============================================================
logout.success.url=/?node=@@nodeId@@
loginForm=/signin?node=@@nodeId@@
loginErrorForm=/login.jsp?node=@@nodeId@@&failure=true
passwordSalt=secret-hash-salt=
# LDAP Connection Settings
ldap.base.provider.url=ldaps://localhost:10636
ldap.base.dn=dc=promap,dc=org
ldap.security.principal=uid=admin,ou=system
ldap.security.credentials=secret
# Users are found in the following OU
ldap.users.search.base=ou=users
ldap.users.search.attribute=uid
ldap.base.dn.pattern=uid={0},${ldap.users.search.base}
#ldap.base.dn.pattern=mail={0},${ldap.base.search.base}
# LDAP orgs are synchronised as GN groups:
ldap.groups.search.base=ou=orgs
ldap.group.search.attribute=cn
ldap.group.search.query=(&(objectClass=groupOfMembers)(member=uid={0},${ldap.users.search.base},${ldap.base.dn}))
#ldap.privilege.search.group.query=(&(objectClass=*)(memberUid={0})(cn=EL_*))
ldap.group.search.pattern=(.*)
ldap.group.search.filter=objectClass=groupOfMembers
ldap.group.search.queryprop=member
# roles are found in the following OU:
ldap.roles.search.base=ou=roles
ldap.role.search.attribute=cn
ldap.role.search.query=(&(objectClass=groupOfMembers)(member=uid={0},${ldap.users.search.base},${ldap.base.dn}))
#ldap.privilege.search.privilege.query=(&(objectClass=*)(memberUid={0})(cn=SV_*))
ldap.role.search.pattern=GN_(.*)
# Define if the LDAP user search is case insensitive (true if not present). If true only one user will be created in
# the database, independently of the case introduced in the login box, for example User1 and uSEr1 will be the same user
# in the database, user1.
# If false, GN will create the user in the database using the same string entered in the login input allowing to have
# different users for distinct case combinations, for example user1, User1, usER1...
ldap.usernameCaseInsensitive=true
# Define if groups and profile information are imported from LDAP. If not, local database is used.
# When a new user connect first, the default profile is assigned. A user administrator can update
# privilege information.
ldap.privilege.import=true
# Define if LDAP groups should be create in catalog
# database if they do not exist.
ldap.privilege.create.nonexisting.groups=true
# Define if users should be saved in the LDAP
ldap.privilege.create.nonexisting.users=true
# Run LDAP sync every day at 23:30
#ldap.sync.cron=0 30 23 * * ?
ldap.sync.cron=0 * * * * ?
#ldap.sync.cron=0 0/1 * 1/1 * ? *
ldap.sync.startDelay=60000
ldap.sync.user.search.base=${ldap.users.search.base}
ldap.sync.user.search.filter=uid={0}
#(&(objectClass=*)(mail=*@*)(givenName=*))
ldap.sync.user.search.attribute=${ldap.users.search.attribute}
ldap.sync.group.search.base=${ldap.groups.search.base}
ldap.sync.group.search.filter=${ldap.group.search.filter}
ldap.sync.group.search.attribute=${ldap.group.search.attribute}
ldap.sync.group.search.pattern=${ldap.group.search.pattern}
# CAS properties
cas.baseURL=https://localhost:8443/cas
cas.ticket.validator.url=${cas.baseURL}
cas.login.url=${cas.baseURL}/login
cas.logout.url=${cas.baseURL}/logout?url=${geonetwork.https.url}/
# either the hardcoded url to the server
# or if has the form @blah@ it will be replaced with
# the server details from the server configuration
geonetwork.https.url=https://localhost:8443/geonetwork
# The url to redirect to if a user logs in to one node then logs into another.
wrongNodeRedirectURL=/@@nodeId@@/@@lang@@/node-change-warning?oldUserName=@@oldUserName@@&redirectedFrom=@@redirectedFrom@@&oldNodeId=@@oldNodeId@@
{
"@class" : "org.apereo.cas.services.RegexRegisteredService",
"serviceId" : "^https://localhost:8443/geonetwork/*",
"name" : "Geonetwork",
"id" : 10000005,
"description" : "Geonetwork service",
"evaluationOrder" : 2
}
2020-05-15 16:21:00,000 DEBUG [geonetwork.ldap] - LDAPSynchronizerJob starting ...
2020-05-15 16:21:00,021 DEBUG [geonetwork.ldap] - LDAPSynchronizerJob done.
2020-05-15 16:21:40,445 DEBUG [org.springframework.security.ldap.authentication.LdapAuthenticationProvider] - Processing authentication request for user: _cas_stateless_
2020-05-15 16:21:40,446 DEBUG [org.springframework.security.ldap.authentication.BindAuthenticator] - Attempting to bind as uid=_cas_stateless_,ou=users,dc=promap,dc=org
2020-05-15 16:21:40,446 DEBUG [org.springframework.security.ldap.DefaultSpringSecurityContextSource] - Removing pooling flag for user uid=_cas_stateless_,ou=users,dc=promap,dc=org
2020-05-15 16:21:40,468 DEBUG [org.springframework.security.ldap.authentication.BindAuthenticator] - Failed to bind as uid=_cas_stateless_,ou=users: org.springframework.ldap.AuthenticationException: [LDAP: error code 49 - INVALID_CREDENTIALS: Bind failed: Attempt to lookup non-existant entry: uid=_cas_stateless_,ou=users,dc=promap,dc=org]; nested exception is javax.naming.AuthenticationException: [LDAP: error code 49 - INVALID_CREDENTIALS: Bind failed: Attempt to lookup non-existant entry: uid=_cas_stateless_,ou=users,dc=promap,dc=org]
2020-05-15 16:22:00,001 DEBUG [geonetwork.ldap] - LDAPSynchronizerJob starting ...
2020-05-15 16:22:00,020 DEBUG [geonetwork.ldap] - LDAPSynchronizerJob done.
2020-05-15 16:23:00,000 DEBUG [geonetwork.ldap] - LDAPSynchronizerJob starting ...
2020-05-15 16:23:00,031 DEBUG [geonetwork.ldap] - LDAPSynchronizerJob done.
2020-05-15 16:21:32,516 INFO [org.apereo.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - <Audit trail record BEGIN
=============================================================
WHO: audit:unknown
WHAT: [event=success,timestamp=Fri May 15 16:21:32 CEST 2020,source=RankedAuthenticationProviderWebflowEventResolver]
ACTION: AUTHENTICATION_EVENT_TRIGGERED
APPLICATION: CAS
WHEN: Fri May 15 16:21:32 CEST 2020
CLIENT IP ADDRESS: 0:0:0:0:0:0:0:1
SERVER IP ADDRESS: 0:0:0:0:0:0:0:1
=============================================================
>
2020-05-15 16:21:37,111 DEBUG [org.ldaptive.pool.BlockingConnectionPool] - <begin validate task for [org.ldaptive.pool.BlockingConnectionPool@1960329032::name=null, poolConfig=[org.ldaptive.pool.PoolConfig@1997872493::minPoolSize=3, maxPoolSize=10, validateOnCheckIn=false, validateOnCheckOut=true, validatePeriodically=true, validatePeriod=PT4M30S, validateTimeout=PT5S], activator=null, passivator=[org.ldaptive.pool.BindPassivator@1791863376::bindRequest=[org.ldaptive.BindRequest@1987012004::bindDn=uid=admin,ou=system, saslConfig=null, controls=null, referralHandler=null, intermediateResponseHandlers=null]], validator=[org.ldaptive.pool.SearchValidator@1131951710::searchRequest=[org.ldaptive.SearchRequest@-293822691::baseDn=, searchFilter=[org.ldaptive.SearchFilter@1642584434::filter=(objectClass=*), parameters={}], returnAttributes=[1.1], searchScope=OBJECT, timeLimit=PT0S, sizeLimit=1, derefAliases=null, typesOnly=false, binaryAttributes=null, sortBehavior=UNORDERED, searchEntryHandlers=null, searchReferenceHandlers=[org.ldaptive.referral.SearchReferralHandler$SearchReferenceHandler@168e0741], controls=null, referralHandler=org.ldaptive.referral.SearchReferralHandler@56ab92e3, intermediateResponseHandlers=null]] pruneStrategy=[org.ldaptive.pool.IdlePruneStrategy@821638008::prunePeriod=PT2H, idleTime=PT10M], connectOnCreate=true, connectionFactory=[org.ldaptive.DefaultConnectionFactory@349397558::provider=org.ldaptive.provider.jndi.JndiProvider@697b83de, config=[org.ldaptive.ConnectionConfig@1674393752::ldapUrl=ldaps://localhost:10636, connectTimeout=PT5S, responseTimeout=PT5S, sslConfig=[org.ldaptive.ssl.SslConfig@441890154::credentialConfig=null, trustManagers=null, hostnameVerifier=org.ldaptive.ssl.DefaultHostnameVerifier@151ba6c4, hostnameVerifierConfig=null, enabledCipherSuites=null, enabledProtocols=null, handshakeCompletedListeners=null], useSSL=true, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@550216394::bindDn=uid=admin,ou=system, bindSaslConfig=null, bindControls=null], connectionStrategy=org.ldaptive.DefaultConnectionStrategy@2a4857b3]], initialized=true, availableCount=3, activeCount=0]>
2020-05-15 16:21:37,111 DEBUG [org.ldaptive.pool.BlockingConnectionPool] - <validate available pool of size 3 for [org.ldaptive.pool.BlockingConnectionPool@1960329032::name=null, poolConfig=[org.ldaptive.pool.PoolConfig@1997872493::minPoolSize=3, maxPoolSize=10, validateOnCheckIn=false, validateOnCheckOut=true, validatePeriodically=true, validatePeriod=PT4M30S, validateTimeout=PT5S], activator=null, passivator=[org.ldaptive.pool.BindPassivator@1791863376::bindRequest=[org.ldaptive.BindRequest@1987012004::bindDn=uid=admin,ou=system, saslConfig=null, controls=null, referralHandler=null, intermediateResponseHandlers=null]], validator=[org.ldaptive.pool.SearchValidator@1131951710::searchRequest=[org.ldaptive.SearchRequest@-293822691::baseDn=, searchFilter=[org.ldaptive.SearchFilter@1642584434::filter=(objectClass=*), parameters={}], returnAttributes=[1.1], searchScope=OBJECT, timeLimit=PT0S, sizeLimit=1, derefAliases=null, typesOnly=false, binaryAttributes=null, sortBehavior=UNORDERED, searchEntryHandlers=null, searchReferenceHandlers=[org.ldaptive.referral.SearchReferralHandler$SearchReferenceHandler@168e0741], controls=null, referralHandler=org.ldaptive.referral.SearchReferralHandler@56ab92e3, intermediateResponseHandlers=null]] pruneStrategy=[org.ldaptive.pool.IdlePruneStrategy@821638008::prunePeriod=PT2H, idleTime=PT10M], connectOnCreate=true, connectionFactory=[org.ldaptive.DefaultConnectionFactory@349397558::provider=org.ldaptive.provider.jndi.JndiProvider@697b83de, config=[org.ldaptive.ConnectionConfig@1674393752::ldapUrl=ldaps://localhost:10636, connectTimeout=PT5S, responseTimeout=PT5S, sslConfig=[org.ldaptive.ssl.SslConfig@441890154::credentialConfig=null, trustManagers=null, hostnameVerifier=org.ldaptive.ssl.DefaultHostnameVerifier@151ba6c4, hostnameVerifierConfig=null, enabledCipherSuites=null, enabledProtocols=null, handshakeCompletedListeners=null], useSSL=true, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@550216394::bindDn=uid=admin,ou=system, bindSaslConfig=null, bindControls=null], connectionStrategy=org.ldaptive.DefaultConnectionStrategy@2a4857b3]], initialized=true, availableCount=3, activeCount=0]>
2020-05-15 16:21:37,112 DEBUG [org.ldaptive.SearchOperation] - <execute request=[org.ldaptive.SearchRequest@-293822691::baseDn=, searchFilter=[org.ldaptive.SearchFilter@1642584434::filter=(objectClass=*), parameters={}], returnAttributes=[1.1], searchScope=OBJECT, timeLimit=PT0S, sizeLimit=1, derefAliases=null, typesOnly=false, binaryAttributes=null, sortBehavior=UNORDERED, searchEntryHandlers=null, searchReferenceHandlers=[org.ldaptive.referral.SearchReferralHandler$SearchReferenceHandler@168e0741], controls=null, referralHandler=org.ldaptive.referral.SearchReferralHandler@56ab92e3, intermediateResponseHandlers=null] with connection=[org.ldaptive.DefaultConnectionFactory$DefaultConnection@144770331::config=[org.ldaptive.ConnectionConfig@1674393752::ldapUrl=ldaps://localhost:10636, connectTimeout=PT5S, responseTimeout=PT5S, sslConfig=[org.ldaptive.ssl.SslConfig@441890154::credentialConfig=null, trustManagers=null, hostnameVerifier=org.ldaptive.ssl.DefaultHostnameVerifier@151ba6c4, hostnameVerifierConfig=null, enabledCipherSuites=null, enabledProtocols=null, handshakeCompletedListeners=null], useSSL=true, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@550216394::bindDn=uid=admin,ou=system, bindSaslConfig=null, bindControls=null], connectionStrategy=org.ldaptive.DefaultConnectionStrategy@2a4857b3], providerConnectionFactory=[org.ldaptive.provider.jndi.JndiConnectionFactory@769521523::metadata=[ldapUrl=ldaps://localhost:10636, count=1], environment={java.naming.ldap.factory.socket=org.ldaptive.ssl.ThreadLocalTLSSocketFactory, com.sun.jndi.ldap.connect.timeout=5000, java.naming.ldap.version=3, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory, java.naming.security.protocol=ssl, com.sun.jndi.ldap.read.timeout=5000}, classLoader=null, providerConfig=[org.ldaptive.provider.jndi.JndiProviderConfig@115751302::operationExceptionResultCodes=[PROTOCOL_ERROR, SERVER_DOWN], properties={}, controlProcessor=org.ldaptive.provider.ControlProcessor@6c16356b, environment=null, tracePackets=null, removeDnUrls=true, searchIgnoreResultCodes=[TIME_LIMIT_EXCEEDED, SIZE_LIMIT_EXCEEDED, PARTIAL_RESULTS], classLoader=null, sslSocketFactory=null, hostnameVerifier=null]], providerConnection=org.ldaptive.provider.jndi.JndiConnection@6aeb1c0c]>
2020-05-15 16:21:37,112 DEBUG [org.ldaptive.SearchOperation] - <execute request=[org.ldaptive.SearchRequest@-293822691::baseDn=, searchFilter=[org.ldaptive.SearchFilter@1642584434::filter=(objectClass=*), parameters={}], returnAttributes=[1.1], searchScope=OBJECT, timeLimit=PT0S, sizeLimit=1, derefAliases=null, typesOnly=false, binaryAttributes=null, sortBehavior=UNORDERED, searchEntryHandlers=null, searchReferenceHandlers=[org.ldaptive.referral.SearchReferralHandler$SearchReferenceHandler@168e0741], controls=null, referralHandler=org.ldaptive.referral.SearchReferralHandler@56ab92e3, intermediateResponseHandlers=null] with connection=[org.ldaptive.DefaultConnectionFactory$DefaultConnection@151557927::config=[org.ldaptive.ConnectionConfig@1674393752::ldapUrl=ldaps://localhost:10636, connectTimeout=PT5S, responseTimeout=PT5S, sslConfig=[org.ldaptive.ssl.SslConfig@441890154::credentialConfig=null, trustManagers=null, hostnameVerifier=org.ldaptive.ssl.DefaultHostnameVerifier@151ba6c4, hostnameVerifierConfig=null, enabledCipherSuites=null, enabledProtocols=null, handshakeCompletedListeners=null], useSSL=true, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@550216394::bindDn=uid=admin,ou=system, bindSaslConfig=null, bindControls=null], connectionStrategy=org.ldaptive.DefaultConnectionStrategy@2a4857b3], providerConnectionFactory=[org.ldaptive.provider.jndi.JndiConnectionFactory@757859259::metadata=[ldapUrl=ldaps://localhost:10636, count=1], environment={java.naming.ldap.factory.socket=org.ldaptive.ssl.ThreadLocalTLSSocketFactory, com.sun.jndi.ldap.connect.timeout=5000, java.naming.ldap.version=3, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory, java.naming.security.protocol=ssl, com.sun.jndi.ldap.read.timeout=5000}, classLoader=null, providerConfig=[org.ldaptive.provider.jndi.JndiProviderConfig@115751302::operationExceptionResultCodes=[PROTOCOL_ERROR, SERVER_DOWN], properties={}, controlProcessor=org.ldaptive.provider.ControlProcessor@6c16356b, environment=null, tracePackets=null, removeDnUrls=true, searchIgnoreResultCodes=[TIME_LIMIT_EXCEEDED, SIZE_LIMIT_EXCEEDED, PARTIAL_RESULTS], classLoader=null, sslSocketFactory=null, hostnameVerifier=null]], providerConnection=org.ldaptive.provider.jndi.JndiConnection@1c30e0e4]>
2020-05-15 16:21:37,112 DEBUG [org.ldaptive.SearchOperation] - <execute request=[org.ldaptive.SearchRequest@-293822691::baseDn=, searchFilter=[org.ldaptive.SearchFilter@1642584434::filter=(objectClass=*), parameters={}], returnAttributes=[1.1], searchScope=OBJECT, timeLimit=PT0S, sizeLimit=1, derefAliases=null, typesOnly=false, binaryAttributes=null, sortBehavior=UNORDERED, searchEntryHandlers=null, searchReferenceHandlers=[org.ldaptive.referral.SearchReferralHandler$SearchReferenceHandler@168e0741], controls=null, referralHandler=org.ldaptive.referral.SearchReferralHandler@56ab92e3, intermediateResponseHandlers=null] with connection=[org.ldaptive.DefaultConnectionFactory$DefaultConnection@1873879171::config=[org.ldaptive.ConnectionConfig@1674393752::ldapUrl=ldaps://localhost:10636, connectTimeout=PT5S, responseTimeout=PT5S, sslConfig=[org.ldaptive.ssl.SslConfig@441890154::credentialConfig=null, trustManagers=null, hostnameVerifier=org.ldaptive.ssl.DefaultHostnameVerifier@151ba6c4, hostnameVerifierConfig=null, enabledCipherSuites=null, enabledProtocols=null, handshakeCompletedListeners=null], useSSL=true, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@550216394::bindDn=uid=admin,ou=system, bindSaslConfig=null, bindControls=null], connectionStrategy=org.ldaptive.DefaultConnectionStrategy@2a4857b3], providerConnectionFactory=[org.ldaptive.provider.jndi.JndiConnectionFactory@765815618::metadata=[ldapUrl=ldaps://localhost:10636, count=1], environment={java.naming.ldap.factory.socket=org.ldaptive.ssl.ThreadLocalTLSSocketFactory, com.sun.jndi.ldap.connect.timeout=5000, java.naming.ldap.version=3, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory, java.naming.security.protocol=ssl, com.sun.jndi.ldap.read.timeout=5000}, classLoader=null, providerConfig=[org.ldaptive.provider.jndi.JndiProviderConfig@115751302::operationExceptionResultCodes=[PROTOCOL_ERROR, SERVER_DOWN], properties={}, controlProcessor=org.ldaptive.provider.ControlProcessor@6c16356b, environment=null, tracePackets=null, removeDnUrls=true, searchIgnoreResultCodes=[TIME_LIMIT_EXCEEDED, SIZE_LIMIT_EXCEEDED, PARTIAL_RESULTS], classLoader=null, sslSocketFactory=null, hostnameVerifier=null]], providerConnection=org.ldaptive.provider.jndi.JndiConnection@a45a552]>
2020-05-15 16:21:37,114 DEBUG [org.ldaptive.SearchOperation] - <execute response=[org.ldaptive.Response@1506242051::result=[org.ldaptive.SearchResult@-1951941189::entries=[[dn=[], responseControls=null, messageId=-1]], references=[]], resultCode=SUCCESS, message=null, matchedDn=null, responseControls=null, referralURLs=null, messageId=-1] for request=[org.ldaptive.SearchRequest@-293822691::baseDn=, searchFilter=[org.ldaptive.SearchFilter@1642584434::filter=(objectClass=*), parameters={}], returnAttributes=[1.1], searchScope=OBJECT, timeLimit=PT0S, sizeLimit=1, derefAliases=null, typesOnly=false, binaryAttributes=null, sortBehavior=UNORDERED, searchEntryHandlers=null, searchReferenceHandlers=[org.ldaptive.referral.SearchReferralHandler$SearchReferenceHandler@168e0741], controls=null, referralHandler=org.ldaptive.referral.SearchReferralHandler@56ab92e3, intermediateResponseHandlers=null] with connection=[org.ldaptive.DefaultConnectionFactory$DefaultConnection@151557927::config=[org.ldaptive.ConnectionConfig@1674393752::ldapUrl=ldaps://localhost:10636, connectTimeout=PT5S, responseTimeout=PT5S, sslConfig=[org.ldaptive.ssl.SslConfig@441890154::credentialConfig=null, trustManagers=null, hostnameVerifier=org.ldaptive.ssl.DefaultHostnameVerifier@151ba6c4, hostnameVerifierConfig=null, enabledCipherSuites=null, enabledProtocols=null, handshakeCompletedListeners=null], useSSL=true, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@550216394::bindDn=uid=admin,ou=system, bindSaslConfig=null, bindControls=null], connectionStrategy=org.ldaptive.DefaultConnectionStrategy@2a4857b3], providerConnectionFactory=[org.ldaptive.provider.jndi.JndiConnectionFactory@757859259::metadata=[ldapUrl=ldaps://localhost:10636, count=1], environment={java.naming.ldap.factory.socket=org.ldaptive.ssl.ThreadLocalTLSSocketFactory, com.sun.jndi.ldap.connect.timeout=5000, java.naming.ldap.version=3, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory, java.naming.security.protocol=ssl, com.sun.jndi.ldap.read.timeout=5000}, classLoader=null, providerConfig=[org.ldaptive.provider.jndi.JndiProviderConfig@115751302::operationExceptionResultCodes=[PROTOCOL_ERROR, SERVER_DOWN], properties={}, controlProcessor=org.ldaptive.provider.ControlProcessor@6c16356b, environment=null, tracePackets=null, removeDnUrls=true, searchIgnoreResultCodes=[TIME_LIMIT_EXCEEDED, SIZE_LIMIT_EXCEEDED, PARTIAL_RESULTS], classLoader=null, sslSocketFactory=null, hostnameVerifier=null]], providerConnection=org.ldaptive.provider.jndi.JndiConnection@1c30e0e4]>
2020-05-15 16:21:37,114 DEBUG [org.ldaptive.SearchOperation] - <execute response=[org.ldaptive.Response@814033870::result=[org.ldaptive.SearchResult@-1951941189::entries=[[dn=[], responseControls=null, messageId=-1]], references=[]], resultCode=SUCCESS, message=null, matchedDn=null, responseControls=null, referralURLs=null, messageId=-1] for request=[org.ldaptive.SearchRequest@-293822691::baseDn=, searchFilter=[org.ldaptive.SearchFilter@1642584434::filter=(objectClass=*), parameters={}], returnAttributes=[1.1], searchScope=OBJECT, timeLimit=PT0S, sizeLimit=1, derefAliases=null, typesOnly=false, binaryAttributes=null, sortBehavior=UNORDERED, searchEntryHandlers=null, searchReferenceHandlers=[org.ldaptive.referral.SearchReferralHandler$SearchReferenceHandler@168e0741], controls=null, referralHandler=org.ldaptive.referral.SearchReferralHandler@56ab92e3, intermediateResponseHandlers=null] with connection=[org.ldaptive.DefaultConnectionFactory$DefaultConnection@144770331::config=[org.ldaptive.ConnectionConfig@1674393752::ldapUrl=ldaps://localhost:10636, connectTimeout=PT5S, responseTimeout=PT5S, sslConfig=[org.ldaptive.ssl.SslConfig@441890154::credentialConfig=null, trustManagers=null, hostnameVerifier=org.ldaptive.ssl.DefaultHostnameVerifier@151ba6c4, hostnameVerifierConfig=null, enabledCipherSuites=null, enabledProtocols=null, handshakeCompletedListeners=null], useSSL=true, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@550216394::bindDn=uid=admin,ou=system, bindSaslConfig=null, bindControls=null], connectionStrategy=org.ldaptive.DefaultConnectionStrategy@2a4857b3], providerConnectionFactory=[org.ldaptive.provider.jndi.JndiConnectionFactory@769521523::metadata=[ldapUrl=ldaps://localhost:10636, count=1], environment={java.naming.ldap.factory.socket=org.ldaptive.ssl.ThreadLocalTLSSocketFactory, com.sun.jndi.ldap.connect.timeout=5000, java.naming.ldap.version=3, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory, java.naming.security.protocol=ssl, com.sun.jndi.ldap.read.timeout=5000}, classLoader=null, providerConfig=[org.ldaptive.provider.jndi.JndiProviderConfig@115751302::operationExceptionResultCodes=[PROTOCOL_ERROR, SERVER_DOWN], properties={}, controlProcessor=org.ldaptive.provider.ControlProcessor@6c16356b, environment=null, tracePackets=null, removeDnUrls=true, searchIgnoreResultCodes=[TIME_LIMIT_EXCEEDED, SIZE_LIMIT_EXCEEDED, PARTIAL_RESULTS], classLoader=null, sslSocketFactory=null, hostnameVerifier=null]], providerConnection=org.ldaptive.provider.jndi.JndiConnection@6aeb1c0c]>
2020-05-15 16:21:37,114 DEBUG [org.ldaptive.SearchOperation] - <execute response=[org.ldaptive.Response@343791783::result=[org.ldaptive.SearchResult@-1951941189::entries=[[dn=[], responseControls=null, messageId=-1]], references=[]], resultCode=SUCCESS, message=null, matchedDn=null, responseControls=null, referralURLs=null, messageId=-1] for request=[org.ldaptive.SearchRequest@-293822691::baseDn=, searchFilter=[org.ldaptive.SearchFilter@1642584434::filter=(objectClass=*), parameters={}], returnAttributes=[1.1], searchScope=OBJECT, timeLimit=PT0S, sizeLimit=1, derefAliases=null, typesOnly=false, binaryAttributes=null, sortBehavior=UNORDERED, searchEntryHandlers=null, searchReferenceHandlers=[org.ldaptive.referral.SearchReferralHandler$SearchReferenceHandler@168e0741], controls=null, referralHandler=org.ldaptive.referral.SearchReferralHandler@56ab92e3, intermediateResponseHandlers=null] with connection=[org.ldaptive.DefaultConnectionFactory$DefaultConnection@1873879171::config=[org.ldaptive.ConnectionConfig@1674393752::ldapUrl=ldaps://localhost:10636, connectTimeout=PT5S, responseTimeout=PT5S, sslConfig=[org.ldaptive.ssl.SslConfig@441890154::credentialConfig=null, trustManagers=null, hostnameVerifier=org.ldaptive.ssl.DefaultHostnameVerifier@151ba6c4, hostnameVerifierConfig=null, enabledCipherSuites=null, enabledProtocols=null, handshakeCompletedListeners=null], useSSL=true, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@550216394::bindDn=uid=admin,ou=system, bindSaslConfig=null, bindControls=null], connectionStrategy=org.ldaptive.DefaultConnectionStrategy@2a4857b3], providerConnectionFactory=[org.ldaptive.provider.jndi.JndiConnectionFactory@765815618::metadata=[ldapUrl=ldaps://localhost:10636, count=1], environment={java.naming.ldap.factory.socket=org.ldaptive.ssl.ThreadLocalTLSSocketFactory, com.sun.jndi.ldap.connect.timeout=5000, java.naming.ldap.version=3, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory, java.naming.security.protocol=ssl, com.sun.jndi.ldap.read.timeout=5000}, classLoader=null, providerConfig=[org.ldaptive.provider.jndi.JndiProviderConfig@115751302::operationExceptionResultCodes=[PROTOCOL_ERROR, SERVER_DOWN], properties={}, controlProcessor=org.ldaptive.provider.ControlProcessor@6c16356b, environment=null, tracePackets=null, removeDnUrls=true, searchIgnoreResultCodes=[TIME_LIMIT_EXCEEDED, SIZE_LIMIT_EXCEEDED, PARTIAL_RESULTS], classLoader=null, sslSocketFactory=null, hostnameVerifier=null]], providerConnection=org.ldaptive.provider.jndi.JndiConnection@a45a552]>
2020-05-15 16:21:37,114 DEBUG [org.ldaptive.pool.BlockingConnectionPool] - <checking connection pool size >= 3 for [org.ldaptive.pool.BlockingConnectionPool@1960329032::name=null, poolConfig=[org.ldaptive.pool.PoolConfig@1997872493::minPoolSize=3, maxPoolSize=10, validateOnCheckIn=false, validateOnCheckOut=true, validatePeriodically=true, validatePeriod=PT4M30S, validateTimeout=PT5S], activator=null, passivator=[org.ldaptive.pool.BindPassivator@1791863376::bindRequest=[org.ldaptive.BindRequest@1987012004::bindDn=uid=admin,ou=system, saslConfig=null, controls=null, referralHandler=null, intermediateResponseHandlers=null]], validator=[org.ldaptive.pool.SearchValidator@1131951710::searchRequest=[org.ldaptive.SearchRequest@-293822691::baseDn=, searchFilter=[org.ldaptive.SearchFilter@1642584434::filter=(objectClass=*), parameters={}], returnAttributes=[1.1], searchScope=OBJECT, timeLimit=PT0S, sizeLimit=1, derefAliases=null, typesOnly=false, binaryAttributes=null, sortBehavior=UNORDERED, searchEntryHandlers=null, searchReferenceHandlers=[org.ldaptive.referral.SearchReferralHandler$SearchReferenceHandler@168e0741], controls=null, referralHandler=org.ldaptive.referral.SearchReferralHandler@56ab92e3, intermediateResponseHandlers=null]] pruneStrategy=[org.ldaptive.pool.IdlePruneStrategy@821638008::prunePeriod=PT2H, idleTime=PT10M], connectOnCreate=true, connectionFactory=[org.ldaptive.DefaultConnectionFactory@349397558::provider=org.ldaptive.provider.jndi.JndiProvider@697b83de, config=[org.ldaptive.ConnectionConfig@1674393752::ldapUrl=ldaps://localhost:10636, connectTimeout=PT5S, responseTimeout=PT5S, sslConfig=[org.ldaptive.ssl.SslConfig@441890154::credentialConfig=null, trustManagers=null, hostnameVerifier=org.ldaptive.ssl.DefaultHostnameVerifier@151ba6c4, hostnameVerifierConfig=null, enabledCipherSuites=null, enabledProtocols=null, handshakeCompletedListeners=null], useSSL=true, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@550216394::bindDn=uid=admin,ou=system, bindSaslConfig=null, bindControls=null], connectionStrategy=org.ldaptive.DefaultConnectionStrategy@2a4857b3]], initialized=true, availableCount=3, activeCount=0]>
2020-05-15 16:21:37,114 DEBUG [org.ldaptive.pool.BlockingConnectionPool] - <pool size after validation is 3>
2020-05-15 16:21:37,114 DEBUG [org.ldaptive.pool.BlockingConnectionPool] - <end validate task for [org.ldaptive.pool.BlockingConnectionPool@1960329032::name=null, poolConfig=[org.ldaptive.pool.PoolConfig@1997872493::minPoolSize=3, maxPoolSize=10, validateOnCheckIn=false, validateOnCheckOut=true, validatePeriodically=true, validatePeriod=PT4M30S, validateTimeout=PT5S], activator=null, passivator=[org.ldaptive.pool.BindPassivator@1791863376::bindRequest=[org.ldaptive.BindRequest@1987012004::bindDn=uid=admin,ou=system, saslConfig=null, controls=null, referralHandler=null, intermediateResponseHandlers=null]], validator=[org.ldaptive.pool.SearchValidator@1131951710::searchRequest=[org.ldaptive.SearchRequest@-293822691::baseDn=, searchFilter=[org.ldaptive.SearchFilter@1642584434::filter=(objectClass=*), parameters={}], returnAttributes=[1.1], searchScope=OBJECT, timeLimit=PT0S, sizeLimit=1, derefAliases=null, typesOnly=false, binaryAttributes=null, sortBehavior=UNORDERED, searchEntryHandlers=null, searchReferenceHandlers=[org.ldaptive.referral.SearchReferralHandler$SearchReferenceHandler@168e0741], controls=null, referralHandler=org.ldaptive.referral.SearchReferralHandler@56ab92e3, intermediateResponseHandlers=null]] pruneStrategy=[org.ldaptive.pool.IdlePruneStrategy@821638008::prunePeriod=PT2H, idleTime=PT10M], connectOnCreate=true, connectionFactory=[org.ldaptive.DefaultConnectionFactory@349397558::provider=org.ldaptive.provider.jndi.JndiProvider@697b83de, config=[org.ldaptive.ConnectionConfig@1674393752::ldapUrl=ldaps://localhost:10636, connectTimeout=PT5S, responseTimeout=PT5S, sslConfig=[org.ldaptive.ssl.SslConfig@441890154::credentialConfig=null, trustManagers=null, hostnameVerifier=org.ldaptive.ssl.DefaultHostnameVerifier@151ba6c4, hostnameVerifierConfig=null, enabledCipherSuites=null, enabledProtocols=null, handshakeCompletedListeners=null], useSSL=true, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@550216394::bindDn=uid=admin,ou=system, bindSaslConfig=null, bindControls=null], connectionStrategy=org.ldaptive.DefaultConnectionStrategy@2a4857b3]], initialized=true, availableCount=3, activeCount=0]>
2020-05-15 16:21:37,207 DEBUG [org.ldaptive.pool.BlockingConnectionPool] - <begin validate task for [org.ldaptive.pool.BlockingConnectionPool@889156872::name=null, poolConfig=[org.ldaptive.pool.PoolConfig@892092986::minPoolSize=3, maxPoolSize=10, validateOnCheckIn=false, validateOnCheckOut=true, validatePeriodically=true, validatePeriod=PT4M30S, validateTimeout=PT5S], activator=null, passivator=[org.ldaptive.pool.BindPassivator@1861692425::bindRequest=[org.ldaptive.BindRequest@1561031011::bindDn=uid=admin,ou=system, saslConfig=null, controls=null, referralHandler=null, intermediateResponseHandlers=null]], validator=[org.ldaptive.pool.SearchValidator@311630079::searchRequest=[org.ldaptive.SearchRequest@-150626027::baseDn=, searchFilter=[org.ldaptive.SearchFilter@1642584434::filter=(objectClass=*), parameters={}], returnAttributes=[1.1], searchScope=OBJECT, timeLimit=PT0S, sizeLimit=1, derefAliases=null, typesOnly=false, binaryAttributes=null, sortBehavior=UNORDERED, searchEntryHandlers=null, searchReferenceHandlers=[org.ldaptive.referral.SearchReferralHandler$SearchReferenceHandler@45f9a505], controls=null, referralHandler=org.ldaptive.referral.SearchReferralHandler@12394ed7, intermediateResponseHandlers=null]] pruneStrategy=[org.ldaptive.pool.IdlePruneStrategy@348108186::prunePeriod=PT2H, idleTime=PT10M], connectOnCreate=true, connectionFactory=[org.ldaptive.DefaultConnectionFactory@518066962::provider=org.ldaptive.provider.jndi.JndiProvider@16385c46, config=[org.ldaptive.ConnectionConfig@1311766432::ldapUrl=ldaps://localhost:10636, connectTimeout=PT5S, responseTimeout=PT5S, sslConfig=[org.ldaptive.ssl.SslConfig@659921050::credentialConfig=null, trustManagers=null, hostnameVerifier=org.ldaptive.ssl.DefaultHostnameVerifier@31ba76e1, hostnameVerifierConfig=null, enabledCipherSuites=null, enabledProtocols=null, handshakeCompletedListeners=null], useSSL=true, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@1697957628::bindDn=uid=admin,ou=system, bindSaslConfig=null, bindControls=null], connectionStrategy=org.ldaptive.DefaultConnectionStrategy@5417af0d]], initialized=true, availableCount=3, activeCount=0]>
2020-05-15 16:21:37,207 DEBUG [org.ldaptive.pool.BlockingConnectionPool] - <validate available pool of size 3 for [org.ldaptive.pool.BlockingConnectionPool@889156872::name=null, poolConfig=[org.ldaptive.pool.PoolConfig@892092986::minPoolSize=3, maxPoolSize=10, validateOnCheckIn=false, validateOnCheckOut=true, validatePeriodically=true, validatePeriod=PT4M30S, validateTimeout=PT5S], activator=null, passivator=[org.ldaptive.pool.BindPassivator@1861692425::bindRequest=[org.ldaptive.BindRequest@1561031011::bindDn=uid=admin,ou=system, saslConfig=null, controls=null, referralHandler=null, intermediateResponseHandlers=null]], validator=[org.ldaptive.pool.SearchValidator@311630079::searchRequest=[org.ldaptive.SearchRequest@-150626027::baseDn=, searchFilter=[org.ldaptive.SearchFilter@1642584434::filter=(objectClass=*), parameters={}], returnAttributes=[1.1], searchScope=OBJECT, timeLimit=PT0S, sizeLimit=1, derefAliases=null, typesOnly=false, binaryAttributes=null, sortBehavior=UNORDERED, searchEntryHandlers=null, searchReferenceHandlers=[org.ldaptive.referral.SearchReferralHandler$SearchReferenceHandler@45f9a505], controls=null, referralHandler=org.ldaptive.referral.SearchReferralHandler@12394ed7, intermediateResponseHandlers=null]] pruneStrategy=[org.ldaptive.pool.IdlePruneStrategy@348108186::prunePeriod=PT2H, idleTime=PT10M], connectOnCreate=true, connectionFactory=[org.ldaptive.DefaultConnectionFactory@518066962::provider=org.ldaptive.provider.jndi.JndiProvider@16385c46, config=[org.ldaptive.ConnectionConfig@1311766432::ldapUrl=ldaps://localhost:10636, connectTimeout=PT5S, responseTimeout=PT5S, sslConfig=[org.ldaptive.ssl.SslConfig@659921050::credentialConfig=null, trustManagers=null, hostnameVerifier=org.ldaptive.ssl.DefaultHostnameVerifier@31ba76e1, hostnameVerifierConfig=null, enabledCipherSuites=null, enabledProtocols=null, handshakeCompletedListeners=null], useSSL=true, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@1697957628::bindDn=uid=admin,ou=system, bindSaslConfig=null, bindControls=null], connectionStrategy=org.ldaptive.DefaultConnectionStrategy@5417af0d]], initialized=true, availableCount=3, activeCount=0]>
2020-05-15 16:21:37,208 DEBUG [org.ldaptive.SearchOperation] - <execute request=[org.ldaptive.SearchRequest@-150626027::baseDn=, searchFilter=[org.ldaptive.SearchFilter@1642584434::filter=(objectClass=*), parameters={}], returnAttributes=[1.1], searchScope=OBJECT, timeLimit=PT0S, sizeLimit=1, derefAliases=null, typesOnly=false, binaryAttributes=null, sortBehavior=UNORDERED, searchEntryHandlers=null, searchReferenceHandlers=[org.ldaptive.referral.SearchReferralHandler$SearchReferenceHandler@45f9a505], controls=null, referralHandler=org.ldaptive.referral.SearchReferralHandler@12394ed7, intermediateResponseHandlers=null] with connection=[org.ldaptive.DefaultConnectionFactory$DefaultConnection@778956176::config=[org.ldaptive.ConnectionConfig@1311766432::ldapUrl=ldaps://localhost:10636, connectTimeout=PT5S, responseTimeout=PT5S, sslConfig=[org.ldaptive.ssl.SslConfig@659921050::credentialConfig=null, trustManagers=null, hostnameVerifier=org.ldaptive.ssl.DefaultHostnameVerifier@31ba76e1, hostnameVerifierConfig=null, enabledCipherSuites=null, enabledProtocols=null, handshakeCompletedListeners=null], useSSL=true, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@1697957628::bindDn=uid=admin,ou=system, bindSaslConfig=null, bindControls=null], connectionStrategy=org.ldaptive.DefaultConnectionStrategy@5417af0d], providerConnectionFactory=[org.ldaptive.provider.jndi.JndiConnectionFactory@2015145363::metadata=[ldapUrl=ldaps://localhost:10636, count=1], environment={java.naming.ldap.factory.socket=org.ldaptive.ssl.ThreadLocalTLSSocketFactory, com.sun.jndi.ldap.connect.timeout=5000, java.naming.ldap.version=3, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory, java.naming.security.protocol=ssl, com.sun.jndi.ldap.read.timeout=5000}, classLoader=null, providerConfig=[org.ldaptive.provider.jndi.JndiProviderConfig@1941628011::operationExceptionResultCodes=[PROTOCOL_ERROR, SERVER_DOWN], properties={}, controlProcessor=org.ldaptive.provider.ControlProcessor@6bc9bc66, environment=null, tracePackets=null, removeDnUrls=true, searchIgnoreResultCodes=[TIME_LIMIT_EXCEEDED, SIZE_LIMIT_EXCEEDED, PARTIAL_RESULTS], classLoader=null, sslSocketFactory=null, hostnameVerifier=null]], providerConnection=org.ldaptive.provider.jndi.JndiConnection@33d1c017]>
2020-05-15 16:21:37,208 DEBUG [org.ldaptive.SearchOperation] - <execute request=[org.ldaptive.SearchRequest@-150626027::baseDn=, searchFilter=[org.ldaptive.SearchFilter@1642584434::filter=(objectClass=*), parameters={}], returnAttributes=[1.1], searchScope=OBJECT, timeLimit=PT0S, sizeLimit=1, derefAliases=null, typesOnly=false, binaryAttributes=null, sortBehavior=UNORDERED, searchEntryHandlers=null, searchReferenceHandlers=[org.ldaptive.referral.SearchReferralHandler$SearchReferenceHandler@45f9a505], controls=null, referralHandler=org.ldaptive.referral.SearchReferralHandler@12394ed7, intermediateResponseHandlers=null] with connection=[org.ldaptive.DefaultConnectionFactory$DefaultConnection@465413071::config=[org.ldaptive.ConnectionConfig@1311766432::ldapUrl=ldaps://localhost:10636, connectTimeout=PT5S, responseTimeout=PT5S, sslConfig=[org.ldaptive.ssl.SslConfig@659921050::credentialConfig=null, trustManagers=null, hostnameVerifier=org.ldaptive.ssl.DefaultHostnameVerifier@31ba76e1, hostnameVerifierConfig=null, enabledCipherSuites=null, enabledProtocols=null, handshakeCompletedListeners=null], useSSL=true, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@1697957628::bindDn=uid=admin,ou=system, bindSaslConfig=null, bindControls=null], connectionStrategy=org.ldaptive.DefaultConnectionStrategy@5417af0d], providerConnectionFactory=[org.ldaptive.provider.jndi.JndiConnectionFactory@1552568092::metadata=[ldapUrl=ldaps://localhost:10636, count=1], environment={java.naming.ldap.factory.socket=org.ldaptive.ssl.ThreadLocalTLSSocketFactory, com.sun.jndi.ldap.connect.timeout=5000, java.naming.ldap.version=3, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory, java.naming.security.protocol=ssl, com.sun.jndi.ldap.read.timeout=5000}, classLoader=null, providerConfig=[org.ldaptive.provider.jndi.JndiProviderConfig@1941628011::operationExceptionResultCodes=[PROTOCOL_ERROR, SERVER_DOWN], properties={}, controlProcessor=org.ldaptive.provider.ControlProcessor@6bc9bc66, environment=null, tracePackets=null, removeDnUrls=true, searchIgnoreResultCodes=[TIME_LIMIT_EXCEEDED, SIZE_LIMIT_EXCEEDED, PARTIAL_RESULTS], classLoader=null, sslSocketFactory=null, hostnameVerifier=null]], providerConnection=org.ldaptive.provider.jndi.JndiConnection@70383833]>
2020-05-15 16:21:37,209 DEBUG [org.ldaptive.SearchOperation] - <execute request=[org.ldaptive.SearchRequest@-150626027::baseDn=, searchFilter=[org.ldaptive.SearchFilter@1642584434::filter=(objectClass=*), parameters={}], returnAttributes=[1.1], searchScope=OBJECT, timeLimit=PT0S, sizeLimit=1, derefAliases=null, typesOnly=false, binaryAttributes=null, sortBehavior=UNORDERED, searchEntryHandlers=null, searchReferenceHandlers=[org.ldaptive.referral.SearchReferralHandler$SearchReferenceHandler@45f9a505], controls=null, referralHandler=org.ldaptive.referral.SearchReferralHandler@12394ed7, intermediateResponseHandlers=null] with connection=[org.ldaptive.DefaultConnectionFactory$DefaultConnection@526680651::config=[org.ldaptive.ConnectionConfig@1311766432::ldapUrl=ldaps://localhost:10636, connectTimeout=PT5S, responseTimeout=PT5S, sslConfig=[org.ldaptive.ssl.SslConfig@659921050::credentialConfig=null, trustManagers=null, hostnameVerifier=org.ldaptive.ssl.DefaultHostnameVerifier@31ba76e1, hostnameVerifierConfig=null, enabledCipherSuites=null, enabledProtocols=null, handshakeCompletedListeners=null], useSSL=true, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@1697957628::bindDn=uid=admin,ou=system, bindSaslConfig=null, bindControls=null], connectionStrategy=org.ldaptive.DefaultConnectionStrategy@5417af0d], providerConnectionFactory=[org.ldaptive.provider.jndi.JndiConnectionFactory@55562492::metadata=[ldapUrl=ldaps://localhost:10636, count=1], environment={java.naming.ldap.factory.socket=org.ldaptive.ssl.ThreadLocalTLSSocketFactory, com.sun.jndi.ldap.connect.timeout=5000, java.naming.ldap.version=3, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory, java.naming.security.protocol=ssl, com.sun.jndi.ldap.read.timeout=5000}, classLoader=null, providerConfig=[org.ldaptive.provider.jndi.JndiProviderConfig@1941628011::operationExceptionResultCodes=[PROTOCOL_ERROR, SERVER_DOWN], properties={}, controlProcessor=org.ldaptive.provider.ControlProcessor@6bc9bc66, environment=null, tracePackets=null, removeDnUrls=true, searchIgnoreResultCodes=[TIME_LIMIT_EXCEEDED, SIZE_LIMIT_EXCEEDED, PARTIAL_RESULTS], classLoader=null, sslSocketFactory=null, hostnameVerifier=null]], providerConnection=org.ldaptive.provider.jndi.JndiConnection@50041d8e]>
2020-05-15 16:21:37,210 DEBUG [org.ldaptive.SearchOperation] - <execute response=[org.ldaptive.Response@901639863::result=[org.ldaptive.SearchResult@-1951941189::entries=[[dn=[], responseControls=null, messageId=-1]], references=[]], resultCode=SUCCESS, message=null, matchedDn=null, responseControls=null, referralURLs=null, messageId=-1] for request=[org.ldaptive.SearchRequest@-150626027::baseDn=, searchFilter=[org.ldaptive.SearchFilter@1642584434::filter=(objectClass=*), parameters={}], returnAttributes=[1.1], searchScope=OBJECT, timeLimit=PT0S, sizeLimit=1, derefAliases=null, typesOnly=false, binaryAttributes=null, sortBehavior=UNORDERED, searchEntryHandlers=null, searchReferenceHandlers=[org.ldaptive.referral.SearchReferralHandler$SearchReferenceHandler@45f9a505], controls=null, referralHandler=org.ldaptive.referral.SearchReferralHandler@12394ed7, intermediateResponseHandlers=null] with connection=[org.ldaptive.DefaultConnectionFactory$DefaultConnection@465413071::config=[org.ldaptive.ConnectionConfig@1311766432::ldapUrl=ldaps://localhost:10636, connectTimeout=PT5S, responseTimeout=PT5S, sslConfig=[org.ldaptive.ssl.SslConfig@659921050::credentialConfig=null, trustManagers=null, hostnameVerifier=org.ldaptive.ssl.DefaultHostnameVerifier@31ba76e1, hostnameVerifierConfig=null, enabledCipherSuites=null, enabledProtocols=null, handshakeCompletedListeners=null], useSSL=true, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@1697957628::bindDn=uid=admin,ou=system, bindSaslConfig=null, bindControls=null], connectionStrategy=org.ldaptive.DefaultConnectionStrategy@5417af0d], providerConnectionFactory=[org.ldaptive.provider.jndi.JndiConnectionFactory@1552568092::metadata=[ldapUrl=ldaps://localhost:10636, count=1], environment={java.naming.ldap.factory.socket=org.ldaptive.ssl.ThreadLocalTLSSocketFactory, com.sun.jndi.ldap.connect.timeout=5000, java.naming.ldap.version=3, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory, java.naming.security.protocol=ssl, com.sun.jndi.ldap.read.timeout=5000}, classLoader=null, providerConfig=[org.ldaptive.provider.jndi.JndiProviderConfig@1941628011::operationExceptionResultCodes=[PROTOCOL_ERROR, SERVER_DOWN], properties={}, controlProcessor=org.ldaptive.provider.ControlProcessor@6bc9bc66, environment=null, tracePackets=null, removeDnUrls=true, searchIgnoreResultCodes=[TIME_LIMIT_EXCEEDED, SIZE_LIMIT_EXCEEDED, PARTIAL_RESULTS], classLoader=null, sslSocketFactory=null, hostnameVerifier=null]], providerConnection=org.ldaptive.provider.jndi.JndiConnection@70383833]>
2020-05-15 16:21:37,210 DEBUG [org.ldaptive.SearchOperation] - <execute response=[org.ldaptive.Response@379696537::result=[org.ldaptive.SearchResult@-1951941189::entries=[[dn=[], responseControls=null, messageId=-1]], references=[]], resultCode=SUCCESS, message=null, matchedDn=null, responseControls=null, referralURLs=null, messageId=-1] for request=[org.ldaptive.SearchRequest@-150626027::baseDn=, searchFilter=[org.ldaptive.SearchFilter@1642584434::filter=(objectClass=*), parameters={}], returnAttributes=[1.1], searchScope=OBJECT, timeLimit=PT0S, sizeLimit=1, derefAliases=null, typesOnly=false, binaryAttributes=null, sortBehavior=UNORDERED, searchEntryHandlers=null, searchReferenceHandlers=[org.ldaptive.referral.SearchReferralHandler$SearchReferenceHandler@45f9a505], controls=null, referralHandler=org.ldaptive.referral.SearchReferralHandler@12394ed7, intermediateResponseHandlers=null] with connection=[org.ldaptive.DefaultConnectionFactory$DefaultConnection@778956176::config=[org.ldaptive.ConnectionConfig@1311766432::ldapUrl=ldaps://localhost:10636, connectTimeout=PT5S, responseTimeout=PT5S, sslConfig=[org.ldaptive.ssl.SslConfig@659921050::credentialConfig=null, trustManagers=null, hostnameVerifier=org.ldaptive.ssl.DefaultHostnameVerifier@31ba76e1, hostnameVerifierConfig=null, enabledCipherSuites=null, enabledProtocols=null, handshakeCompletedListeners=null], useSSL=true, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@1697957628::bindDn=uid=admin,ou=system, bindSaslConfig=null, bindControls=null], connectionStrategy=org.ldaptive.DefaultConnectionStrategy@5417af0d], providerConnectionFactory=[org.ldaptive.provider.jndi.JndiConnectionFactory@2015145363::metadata=[ldapUrl=ldaps://localhost:10636, count=1], environment={java.naming.ldap.factory.socket=org.ldaptive.ssl.ThreadLocalTLSSocketFactory, com.sun.jndi.ldap.connect.timeout=5000, java.naming.ldap.version=3, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory, java.naming.security.protocol=ssl, com.sun.jndi.ldap.read.timeout=5000}, classLoader=null, providerConfig=[org.ldaptive.provider.jndi.JndiProviderConfig@1941628011::operationExceptionResultCodes=[PROTOCOL_ERROR, SERVER_DOWN], properties={}, controlProcessor=org.ldaptive.provider.ControlProcessor@6bc9bc66, environment=null, tracePackets=null, removeDnUrls=true, searchIgnoreResultCodes=[TIME_LIMIT_EXCEEDED, SIZE_LIMIT_EXCEEDED, PARTIAL_RESULTS], classLoader=null, sslSocketFactory=null, hostnameVerifier=null]], providerConnection=org.ldaptive.provider.jndi.JndiConnection@33d1c017]>
2020-05-15 16:21:37,210 DEBUG [org.ldaptive.SearchOperation] - <execute response=[org.ldaptive.Response@1086507373::result=[org.ldaptive.SearchResult@-1951941189::entries=[[dn=[], responseControls=null, messageId=-1]], references=[]], resultCode=SUCCESS, message=null, matchedDn=null, responseControls=null, referralURLs=null, messageId=-1] for request=[org.ldaptive.SearchRequest@-150626027::baseDn=, searchFilter=[org.ldaptive.SearchFilter@1642584434::filter=(objectClass=*), parameters={}], returnAttributes=[1.1], searchScope=OBJECT, timeLimit=PT0S, sizeLimit=1, derefAliases=null, typesOnly=false, binaryAttributes=null, sortBehavior=UNORDERED, searchEntryHandlers=null, searchReferenceHandlers=[org.ldaptive.referral.SearchReferralHandler$SearchReferenceHandler@45f9a505], controls=null, referralHandler=org.ldaptive.referral.SearchReferralHandler@12394ed7, intermediateResponseHandlers=null] with connection=[org.ldaptive.DefaultConnectionFactory$DefaultConnection@526680651::config=[org.ldaptive.ConnectionConfig@1311766432::ldapUrl=ldaps://localhost:10636, connectTimeout=PT5S, responseTimeout=PT5S, sslConfig=[org.ldaptive.ssl.SslConfig@659921050::credentialConfig=null, trustManagers=null, hostnameVerifier=org.ldaptive.ssl.DefaultHostnameVerifier@31ba76e1, hostnameVerifierConfig=null, enabledCipherSuites=null, enabledProtocols=null, handshakeCompletedListeners=null], useSSL=true, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@1697957628::bindDn=uid=admin,ou=system, bindSaslConfig=null, bindControls=null], connectionStrategy=org.ldaptive.DefaultConnectionStrategy@5417af0d], providerConnectionFactory=[org.ldaptive.provider.jndi.JndiConnectionFactory@55562492::metadata=[ldapUrl=ldaps://localhost:10636, count=1], environment={java.naming.ldap.factory.socket=org.ldaptive.ssl.ThreadLocalTLSSocketFactory, com.sun.jndi.ldap.connect.timeout=5000, java.naming.ldap.version=3, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory, java.naming.security.protocol=ssl, com.sun.jndi.ldap.read.timeout=5000}, classLoader=null, providerConfig=[org.ldaptive.provider.jndi.JndiProviderConfig@1941628011::operationExceptionResultCodes=[PROTOCOL_ERROR, SERVER_DOWN], properties={}, controlProcessor=org.ldaptive.provider.ControlProcessor@6bc9bc66, environment=null, tracePackets=null, removeDnUrls=true, searchIgnoreResultCodes=[TIME_LIMIT_EXCEEDED, SIZE_LIMIT_EXCEEDED, PARTIAL_RESULTS], classLoader=null, sslSocketFactory=null, hostnameVerifier=null]], providerConnection=org.ldaptive.provider.jndi.JndiConnection@50041d8e]>
2020-05-15 16:21:37,210 DEBUG [org.ldaptive.pool.BlockingConnectionPool] - <checking connection pool size >= 3 for [org.ldaptive.pool.BlockingConnectionPool@889156872::name=null, poolConfig=[org.ldaptive.pool.PoolConfig@892092986::minPoolSize=3, maxPoolSize=10, validateOnCheckIn=false, validateOnCheckOut=true, validatePeriodically=true, validatePeriod=PT4M30S, validateTimeout=PT5S], activator=null, passivator=[org.ldaptive.pool.BindPassivator@1861692425::bindRequest=[org.ldaptive.BindRequest@1561031011::bindDn=uid=admin,ou=system, saslConfig=null, controls=null, referralHandler=null, intermediateResponseHandlers=null]], validator=[org.ldaptive.pool.SearchValidator@311630079::searchRequest=[org.ldaptive.SearchRequest@-150626027::baseDn=, searchFilter=[org.ldaptive.SearchFilter@1642584434::filter=(objectClass=*), parameters={}], returnAttributes=[1.1], searchScope=OBJECT, timeLimit=PT0S, sizeLimit=1, derefAliases=null, typesOnly=false, binaryAttributes=null, sortBehavior=UNORDERED, searchEntryHandlers=null, searchReferenceHandlers=[org.ldaptive.referral.SearchReferralHandler$SearchReferenceHandler@45f9a505], controls=null, referralHandler=org.ldaptive.referral.SearchReferralHandler@12394ed7, intermediateResponseHandlers=null]] pruneStrategy=[org.ldaptive.pool.IdlePruneStrategy@348108186::prunePeriod=PT2H, idleTime=PT10M], connectOnCreate=true, connectionFactory=[org.ldaptive.DefaultConnectionFactory@518066962::provider=org.ldaptive.provider.jndi.JndiProvider@16385c46, config=[org.ldaptive.ConnectionConfig@1311766432::ldapUrl=ldaps://localhost:10636, connectTimeout=PT5S, responseTimeout=PT5S, sslConfig=[org.ldaptive.ssl.SslConfig@659921050::credentialConfig=null, trustManagers=null, hostnameVerifier=org.ldaptive.ssl.DefaultHostnameVerifier@31ba76e1, hostnameVerifierConfig=null, enabledCipherSuites=null, enabledProtocols=null, handshakeCompletedListeners=null], useSSL=true, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@1697957628::bindDn=uid=admin,ou=system, bindSaslConfig=null, bindControls=null], connectionStrategy=org.ldaptive.DefaultConnectionStrategy@5417af0d]], initialized=true, availableCount=3, activeCount=0]>
2020-05-15 16:21:37,210 DEBUG [org.ldaptive.pool.BlockingConnectionPool] - <pool size after validation is 3>
2020-05-15 16:21:37,210 DEBUG [org.ldaptive.pool.BlockingConnectionPool] - <end validate task for [org.ldaptive.pool.BlockingConnectionPool@889156872::name=null, poolConfig=[org.ldaptive.pool.PoolConfig@892092986::minPoolSize=3, maxPoolSize=10, validateOnCheckIn=false, validateOnCheckOut=true, validatePeriodically=true, validatePeriod=PT4M30S, validateTimeout=PT5S], activator=null, passivator=[org.ldaptive.pool.BindPassivator@1861692425::bindRequest=[org.ldaptive.BindRequest@1561031011::bindDn=uid=admin,ou=system, saslConfig=null, controls=null, referralHandler=null, intermediateResponseHandlers=null]], validator=[org.ldaptive.pool.SearchValidator@311630079::searchRequest=[org.ldaptive.SearchRequest@-150626027::baseDn=, searchFilter=[org.ldaptive.SearchFilter@1642584434::filter=(objectClass=*), parameters={}], returnAttributes=[1.1], searchScope=OBJECT, timeLimit=PT0S, sizeLimit=1, derefAliases=null, typesOnly=false, binaryAttributes=null, sortBehavior=UNORDERED, searchEntryHandlers=null, searchReferenceHandlers=[org.ldaptive.referral.SearchReferralHandler$SearchReferenceHandler@45f9a505], controls=null, referralHandler=org.ldaptive.referral.SearchReferralHandler@12394ed7, intermediateResponseHandlers=null]] pruneStrategy=[org.ldaptive.pool.IdlePruneStrategy@348108186::prunePeriod=PT2H, idleTime=PT10M], connectOnCreate=true, connectionFactory=[org.ldaptive.DefaultConnectionFactory@518066962::provider=org.ldaptive.provider.jndi.JndiProvider@16385c46, config=[org.ldaptive.ConnectionConfig@1311766432::ldapUrl=ldaps://localhost:10636, connectTimeout=PT5S, responseTimeout=PT5S, sslConfig=[org.ldaptive.ssl.SslConfig@659921050::credentialConfig=null, trustManagers=null, hostnameVerifier=org.ldaptive.ssl.DefaultHostnameVerifier@31ba76e1, hostnameVerifierConfig=null, enabledCipherSuites=null, enabledProtocols=null, handshakeCompletedListeners=null], useSSL=true, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@1697957628::bindDn=uid=admin,ou=system, bindSaslConfig=null, bindControls=null], connectionStrategy=org.ldaptive.DefaultConnectionStrategy@5417af0d]], initialized=true, availableCount=3, activeCount=0]>
2020-05-15 16:21:37,326 DEBUG [org.ldaptive.pool.BlockingConnectionPool] - <begin validate task for [org.ldaptive.pool.BlockingConnectionPool@1020155882::name=null, poolConfig=[org.ldaptive.pool.PoolConfig@406817698::minPoolSize=3, maxPoolSize=10, validateOnCheckIn=false, validateOnCheckOut=true, validatePeriodically=true, validatePeriod=PT4M30S, validateTimeout=PT5S], activator=null, passivator=[org.ldaptive.pool.BindPassivator@843416218::bindRequest=[org.ldaptive.BindRequest@1674289898::bindDn=uid=admin,ou=system, saslConfig=null, controls=null, referralHandler=null, intermediateResponseHandlers=null]], validator=[org.ldaptive.pool.SearchValidator@762632318::searchRequest=[org.ldaptive.SearchRequest@1010379073::baseDn=, searchFilter=[org.ldaptive.SearchFilter@1642584434::filter=(objectClass=*), parameters={}], returnAttributes=[1.1], searchScope=OBJECT, timeLimit=PT0S, sizeLimit=1, derefAliases=null, typesOnly=false, binaryAttributes=null, sortBehavior=UNORDERED, searchEntryHandlers=null, searchReferenceHandlers=[org.ldaptive.referral.SearchReferralHandler$SearchReferenceHandler@49f234e9], controls=null, referralHandler=org.ldaptive.referral.SearchReferralHandler@573d3e1f, intermediateResponseHandlers=null]] pruneStrategy=[org.ldaptive.pool.IdlePruneStrategy@1776224992::prunePeriod=PT2H, idleTime=PT10M], connectOnCreate=true, connectionFactory=[org.ldaptive.DefaultConnectionFactory@1650690189::provider=org.ldaptive.provider.jndi.JndiProvider@3aeebd54, config=[org.ldaptive.ConnectionConfig@69054928::ldapUrl=ldaps://localhost:10636, connectTimeout=PT5S, responseTimeout=PT5S, sslConfig=[org.ldaptive.ssl.SslConfig@360985529::credentialConfig=null, trustManagers=null, hostnameVerifier=org.ldaptive.ssl.DefaultHostnameVerifier@6b5df664, hostnameVerifierConfig=null, enabledCipherSuites=null, enabledProtocols=null, handshakeCompletedListeners=null], useSSL=true, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@605483590::bindDn=uid=admin,ou=system, bindSaslConfig=null, bindControls=null], connectionStrategy=org.ldaptive.DefaultConnectionStrategy@4d6c4425]], initialized=true, availableCount=3, activeCount=0]>
2020-05-15 16:21:37,326 DEBUG [org.ldaptive.pool.BlockingConnectionPool] - <validate available pool of size 3 for [org.ldaptive.pool.BlockingConnectionPool@1020155882::name=null, poolConfig=[org.ldaptive.pool.PoolConfig@406817698::minPoolSize=3, maxPoolSize=10, validateOnCheckIn=false, validateOnCheckOut=true, validatePeriodically=true, validatePeriod=PT4M30S, validateTimeout=PT5S], activator=null, passivator=[org.ldaptive.pool.BindPassivator@843416218::bindRequest=[org.ldaptive.BindRequest@1674289898::bindDn=uid=admin,ou=system, saslConfig=null, controls=null, referralHandler=null, intermediateResponseHandlers=null]], validator=[org.ldaptive.pool.SearchValidator@762632318::searchRequest=[org.ldaptive.SearchRequest@1010379073::baseDn=, searchFilter=[org.ldaptive.SearchFilter@1642584434::filter=(objectClass=*), parameters={}], returnAttributes=[1.1], searchScope=OBJECT, timeLimit=PT0S, sizeLimit=1, derefAliases=null, typesOnly=false, binaryAttributes=null, sortBehavior=UNORDERED, searchEntryHandlers=null, searchReferenceHandlers=[org.ldaptive.referral.SearchReferralHandler$SearchReferenceHandler@49f234e9], controls=null, referralHandler=org.ldaptive.referral.SearchReferralHandler@573d3e1f, intermediateResponseHandlers=null]] pruneStrategy=[org.ldaptive.pool.IdlePruneStrategy@1776224992::prunePeriod=PT2H, idleTime=PT10M], connectOnCreate=true, connectionFactory=[org.ldaptive.DefaultConnectionFactory@1650690189::provider=org.ldaptive.provider.jndi.JndiProvider@3aeebd54, config=[org.ldaptive.ConnectionConfig@69054928::ldapUrl=ldaps://localhost:10636, connectTimeout=PT5S, responseTimeout=PT5S, sslConfig=[org.ldaptive.ssl.SslConfig@360985529::credentialConfig=null, trustManagers=null, hostnameVerifier=org.ldaptive.ssl.DefaultHostnameVerifier@6b5df664, hostnameVerifierConfig=null, enabledCipherSuites=null, enabledProtocols=null, handshakeCompletedListeners=null], useSSL=true, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@605483590::bindDn=uid=admin,ou=system, bindSaslConfig=null, bindControls=null], connectionStrategy=org.ldaptive.DefaultConnectionStrategy@4d6c4425]], initialized=true, availableCount=3, activeCount=0]>
2020-05-15 16:21:37,326 DEBUG [org.ldaptive.SearchOperation] - <execute request=[org.ldaptive.SearchRequest@1010379073::baseDn=, searchFilter=[org.ldaptive.SearchFilter@1642584434::filter=(objectClass=*), parameters={}], returnAttributes=[1.1], searchScope=OBJECT, timeLimit=PT0S, sizeLimit=1, derefAliases=null, typesOnly=false, binaryAttributes=null, sortBehavior=UNORDERED, searchEntryHandlers=null, searchReferenceHandlers=[org.ldaptive.referral.SearchReferralHandler$SearchReferenceHandler@49f234e9], controls=null, referralHandler=org.ldaptive.referral.SearchReferralHandler@573d3e1f, intermediateResponseHandlers=null] with connection=[org.ldaptive.DefaultConnectionFactory$DefaultConnection@1829212099::config=[org.ldaptive.ConnectionConfig@69054928::ldapUrl=ldaps://localhost:10636, connectTimeout=PT5S, responseTimeout=PT5S, sslConfig=[org.ldaptive.ssl.SslConfig@360985529::credentialConfig=null, trustManagers=null, hostnameVerifier=org.ldaptive.ssl.DefaultHostnameVerifier@6b5df664, hostnameVerifierConfig=null, enabledCipherSuites=null, enabledProtocols=null, handshakeCompletedListeners=null], useSSL=true, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@605483590::bindDn=uid=admin,ou=system, bindSaslConfig=null, bindControls=null], connectionStrategy=org.ldaptive.DefaultConnectionStrategy@4d6c4425], providerConnectionFactory=[org.ldaptive.provider.jndi.JndiConnectionFactory@120885305::metadata=[ldapUrl=ldaps://localhost:10636, count=1], environment={java.naming.ldap.factory.socket=org.ldaptive.ssl.ThreadLocalTLSSocketFactory, com.sun.jndi.ldap.connect.timeout=5000, java.naming.ldap.version=3, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory, java.naming.security.protocol=ssl, com.sun.jndi.ldap.read.timeout=5000}, classLoader=null, providerConfig=[org.ldaptive.provider.jndi.JndiProviderConfig@1257083098::operationExceptionResultCodes=[PROTOCOL_ERROR, SERVER_DOWN], properties={}, controlProcessor=org.ldaptive.provider.ControlProcessor@54fc5824, environment=null, tracePackets=null, removeDnUrls=true, searchIgnoreResultCodes=[TIME_LIMIT_EXCEEDED, SIZE_LIMIT_EXCEEDED, PARTIAL_RESULTS], classLoader=null, sslSocketFactory=null, hostnameVerifier=null]], providerConnection=org.ldaptive.provider.jndi.JndiConnection@4659da82]>
2020-05-15 16:21:37,326 DEBUG [org.ldaptive.SearchOperation] - <execute request=[org.ldaptive.SearchRequest@1010379073::baseDn=, searchFilter=[org.ldaptive.SearchFilter@1642584434::filter=(objectClass=*), parameters={}], returnAttributes=[1.1], searchScope=OBJECT, timeLimit=PT0S, sizeLimit=1, derefAliases=null, typesOnly=false, binaryAttributes=null, sortBehavior=UNORDERED, searchEntryHandlers=null, searchReferenceHandlers=[org.ldaptive.referral.SearchReferralHandler$SearchReferenceHandler@49f234e9], controls=null, referralHandler=org.ldaptive.referral.SearchReferralHandler@573d3e1f, intermediateResponseHandlers=null] with connection=[org.ldaptive.DefaultConnectionFactory$DefaultConnection@846087653::config=[org.ldaptive.ConnectionConfig@69054928::ldapUrl=ldaps://localhost:10636, connectTimeout=PT5S, responseTimeout=PT5S, sslConfig=[org.ldaptive.ssl.SslConfig@360985529::credentialConfig=null, trustManagers=null, hostnameVerifier=org.ldaptive.ssl.DefaultHostnameVerifier@6b5df664, hostnameVerifierConfig=null, enabledCipherSuites=null, enabledProtocols=null, handshakeCompletedListeners=null], useSSL=true, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@605483590::bindDn=uid=admin,ou=system, bindSaslConfig=null, bindControls=null], connectionStrategy=org.ldaptive.DefaultConnectionStrategy@4d6c4425], providerConnectionFactory=[org.ldaptive.provider.jndi.JndiConnectionFactory@1313736059::metadata=[ldapUrl=ldaps://localhost:10636, count=1], environment={java.naming.ldap.factory.socket=org.ldaptive.ssl.ThreadLocalTLSSocketFactory, com.sun.jndi.ldap.connect.timeout=5000, java.naming.ldap.version=3, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory, java.naming.security.protocol=ssl, com.sun.jndi.ldap.read.timeout=5000}, classLoader=null, providerConfig=[org.ldaptive.provider.jndi.JndiProviderConfig@1257083098::operationExceptionResultCodes=[PROTOCOL_ERROR, SERVER_DOWN], properties={}, controlProcessor=org.ldaptive.provider.ControlProcessor@54fc5824, environment=null, tracePackets=null, removeDnUrls=true, searchIgnoreResultCodes=[TIME_LIMIT_EXCEEDED, SIZE_LIMIT_EXCEEDED, PARTIAL_RESULTS], classLoader=null, sslSocketFactory=null, hostnameVerifier=null]], providerConnection=org.ldaptive.provider.jndi.JndiConnection@14fd7e33]>
2020-05-15 16:21:37,327 DEBUG [org.ldaptive.SearchOperation] - <execute request=[org.ldaptive.SearchRequest@1010379073::baseDn=, searchFilter=[org.ldaptive.SearchFilter@1642584434::filter=(objectClass=*), parameters={}], returnAttributes=[1.1], searchScope=OBJECT, timeLimit=PT0S, sizeLimit=1, derefAliases=null, typesOnly=false, binaryAttributes=null, sortBehavior=UNORDERED, searchEntryHandlers=null, searchReferenceHandlers=[org.ldaptive.referral.SearchReferralHandler$SearchReferenceHandler@49f234e9], controls=null, referralHandler=org.ldaptive.referral.SearchReferralHandler@573d3e1f, intermediateResponseHandlers=null] with connection=[org.ldaptive.DefaultConnectionFactory$DefaultConnection@978211464::config=[org.ldaptive.ConnectionConfig@69054928::ldapUrl=ldaps://localhost:10636, connectTimeout=PT5S, responseTimeout=PT5S, sslConfig=[org.ldaptive.ssl.SslConfig@360985529::credentialConfig=null, trustManagers=null, hostnameVerifier=org.ldaptive.ssl.DefaultHostnameVerifier@6b5df664, hostnameVerifierConfig=null, enabledCipherSuites=null, enabledProtocols=null, handshakeCompletedListeners=null], useSSL=true, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@605483590::bindDn=uid=admin,ou=system, bindSaslConfig=null, bindControls=null], connectionStrategy=org.ldaptive.DefaultConnectionStrategy@4d6c4425], providerConnectionFactory=[org.ldaptive.provider.jndi.JndiConnectionFactory@974744765::metadata=[ldapUrl=ldaps://localhost:10636, count=1], environment={java.naming.ldap.factory.socket=org.ldaptive.ssl.ThreadLocalTLSSocketFactory, com.sun.jndi.ldap.connect.timeout=5000, java.naming.ldap.version=3, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory, java.naming.security.protocol=ssl, com.sun.jndi.ldap.read.timeout=5000}, classLoader=null, providerConfig=[org.ldaptive.provider.jndi.JndiProviderConfig@1257083098::operationExceptionResultCodes=[PROTOCOL_ERROR, SERVER_DOWN], properties={}, controlProcessor=org.ldaptive.provider.ControlProcessor@54fc5824, environment=null, tracePackets=null, removeDnUrls=true, searchIgnoreResultCodes=[TIME_LIMIT_EXCEEDED, SIZE_LIMIT_EXCEEDED, PARTIAL_RESULTS], classLoader=null, sslSocketFactory=null, hostnameVerifier=null]], providerConnection=org.ldaptive.provider.jndi.JndiConnection@395fd7f1]>
2020-05-15 16:21:37,328 DEBUG [org.ldaptive.SearchOperation] - <execute response=[org.ldaptive.Response@958338165::result=[org.ldaptive.SearchResult@-1951941189::entries=[[dn=[], responseControls=null, messageId=-1]], references=[]], resultCode=SUCCESS, message=null, matchedDn=null, responseControls=null, referralURLs=null, messageId=-1] for request=[org.ldaptive.SearchRequest@1010379073::baseDn=, searchFilter=[org.ldaptive.SearchFilter@1642584434::filter=(objectClass=*), parameters={}], returnAttributes=[1.1], searchScope=OBJECT, timeLimit=PT0S, sizeLimit=1, derefAliases=null, typesOnly=false, binaryAttributes=null, sortBehavior=UNORDERED, searchEntryHandlers=null, searchReferenceHandlers=[org.ldaptive.referral.SearchReferralHandler$SearchReferenceHandler@49f234e9], controls=null, referralHandler=org.ldaptive.referral.SearchReferralHandler@573d3e1f, intermediateResponseHandlers=null] with connection=[org.ldaptive.DefaultConnectionFactory$DefaultConnection@846087653::config=[org.ldaptive.ConnectionConfig@69054928::ldapUrl=ldaps://localhost:10636, connectTimeout=PT5S, responseTimeout=PT5S, sslConfig=[org.ldaptive.ssl.SslConfig@360985529::credentialConfig=null, trustManagers=null, hostnameVerifier=org.ldaptive.ssl.DefaultHostnameVerifier@6b5df664, hostnameVerifierConfig=null, enabledCipherSuites=null, enabledProtocols=null, handshakeCompletedListeners=null], useSSL=true, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@605483590::bindDn=uid=admin,ou=system, bindSaslConfig=null, bindControls=null], connectionStrategy=org.ldaptive.DefaultConnectionStrategy@4d6c4425], providerConnectionFactory=[org.ldaptive.provider.jndi.JndiConnectionFactory@1313736059::metadata=[ldapUrl=ldaps://localhost:10636, count=1], environment={java.naming.ldap.factory.socket=org.ldaptive.ssl.ThreadLocalTLSSocketFactory, com.sun.jndi.ldap.connect.timeout=5000, java.naming.ldap.version=3, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory, java.naming.security.protocol=ssl, com.sun.jndi.ldap.read.timeout=5000}, classLoader=null, providerConfig=[org.ldaptive.provider.jndi.JndiProviderConfig@1257083098::operationExceptionResultCodes=[PROTOCOL_ERROR, SERVER_DOWN], properties={}, controlProcessor=org.ldaptive.provider.ControlProcessor@54fc5824, environment=null, tracePackets=null, removeDnUrls=true, searchIgnoreResultCodes=[TIME_LIMIT_EXCEEDED, SIZE_LIMIT_EXCEEDED, PARTIAL_RESULTS], classLoader=null, sslSocketFactory=null, hostnameVerifier=null]], providerConnection=org.ldaptive.provider.jndi.JndiConnection@14fd7e33]>
2020-05-15 16:21:37,328 DEBUG [org.ldaptive.SearchOperation] - <execute response=[org.ldaptive.Response@724421680::result=[org.ldaptive.SearchResult@-1951941189::entries=[[dn=[], responseControls=null, messageId=-1]], references=[]], resultCode=SUCCESS, message=null, matchedDn=null, responseControls=null, referralURLs=null, messageId=-1] for request=[org.ldaptive.SearchRequest@1010379073::baseDn=, searchFilter=[org.ldaptive.SearchFilter@1642584434::filter=(objectClass=*), parameters={}], returnAttributes=[1.1], searchScope=OBJECT, timeLimit=PT0S, sizeLimit=1, derefAliases=null, typesOnly=false, binaryAttributes=null, sortBehavior=UNORDERED, searchEntryHandlers=null, searchReferenceHandlers=[org.ldaptive.referral.SearchReferralHandler$SearchReferenceHandler@49f234e9], controls=null, referralHandler=org.ldaptive.referral.SearchReferralHandler@573d3e1f, intermediateResponseHandlers=null] with connection=[org.ldaptive.DefaultConnectionFactory$DefaultConnection@978211464::config=[org.ldaptive.ConnectionConfig@69054928::ldapUrl=ldaps://localhost:10636, connectTimeout=PT5S, responseTimeout=PT5S, sslConfig=[org.ldaptive.ssl.SslConfig@360985529::credentialConfig=null, trustManagers=null, hostnameVerifier=org.ldaptive.ssl.DefaultHostnameVerifier@6b5df664, hostnameVerifierConfig=null, enabledCipherSuites=null, enabledProtocols=null, handshakeCompletedListeners=null], useSSL=true, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@605483590::bindDn=uid=admin,ou=system, bindSaslConfig=null, bindControls=null], connectionStrategy=org.ldaptive.DefaultConnectionStrategy@4d6c4425], providerConnectionFactory=[org.ldaptive.provider.jndi.JndiConnectionFactory@974744765::metadata=[ldapUrl=ldaps://localhost:10636, count=1], environment={java.naming.ldap.factory.socket=org.ldaptive.ssl.ThreadLocalTLSSocketFactory, com.sun.jndi.ldap.connect.timeout=5000, java.naming.ldap.version=3, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory, java.naming.security.protocol=ssl, com.sun.jndi.ldap.read.timeout=5000}, classLoader=null, providerConfig=[org.ldaptive.provider.jndi.JndiProviderConfig@1257083098::operationExceptionResultCodes=[PROTOCOL_ERROR, SERVER_DOWN], properties={}, controlProcessor=org.ldaptive.provider.ControlProcessor@54fc5824, environment=null, tracePackets=null, removeDnUrls=true, searchIgnoreResultCodes=[TIME_LIMIT_EXCEEDED, SIZE_LIMIT_EXCEEDED, PARTIAL_RESULTS], classLoader=null, sslSocketFactory=null, hostnameVerifier=null]], providerConnection=org.ldaptive.provider.jndi.JndiConnection@395fd7f1]>
2020-05-15 16:21:37,328 DEBUG [org.ldaptive.SearchOperation] - <execute response=[org.ldaptive.Response@1431008324::result=[org.ldaptive.SearchResult@-1951941189::entries=[[dn=[], responseControls=null, messageId=-1]], references=[]], resultCode=SUCCESS, message=null, matchedDn=null, responseControls=null, referralURLs=null, messageId=-1] for request=[org.ldaptive.SearchRequest@1010379073::baseDn=, searchFilter=[org.ldaptive.SearchFilter@1642584434::filter=(objectClass=*), parameters={}], returnAttributes=[1.1], searchScope=OBJECT, timeLimit=PT0S, sizeLimit=1, derefAliases=null, typesOnly=false, binaryAttributes=null, sortBehavior=UNORDERED, searchEntryHandlers=null, searchReferenceHandlers=[org.ldaptive.referral.SearchReferralHandler$SearchReferenceHandler@49f234e9], controls=null, referralHandler=org.ldaptive.referral.SearchReferralHandler@573d3e1f, intermediateResponseHandlers=null] with connection=[org.ldaptive.DefaultConnectionFactory$DefaultConnection@1829212099::config=[org.ldaptive.ConnectionConfig@69054928::ldapUrl=ldaps://localhost:10636, connectTimeout=PT5S, responseTimeout=PT5S, sslConfig=[org.ldaptive.ssl.SslConfig@360985529::credentialConfig=null, trustManagers=null, hostnameVerifier=org.ldaptive.ssl.DefaultHostnameVerifier@6b5df664, hostnameVerifierConfig=null, enabledCipherSuites=null, enabledProtocols=null, handshakeCompletedListeners=null], useSSL=true, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@605483590::bindDn=uid=admin,ou=system, bindSaslConfig=null, bindControls=null], connectionStrategy=org.ldaptive.DefaultConnectionStrategy@4d6c4425], providerConnectionFactory=[org.ldaptive.provider.jndi.JndiConnectionFactory@120885305::metadata=[ldapUrl=ldaps://localhost:10636, count=1], environment={java.naming.ldap.factory.socket=org.ldaptive.ssl.ThreadLocalTLSSocketFactory, com.sun.jndi.ldap.connect.timeout=5000, java.naming.ldap.version=3, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory, java.naming.security.protocol=ssl, com.sun.jndi.ldap.read.timeout=5000}, classLoader=null, providerConfig=[org.ldaptive.provider.jndi.JndiProviderConfig@1257083098::operationExceptionResultCodes=[PROTOCOL_ERROR, SERVER_DOWN], properties={}, controlProcessor=org.ldaptive.provider.ControlProcessor@54fc5824, environment=null, tracePackets=null, removeDnUrls=true, searchIgnoreResultCodes=[TIME_LIMIT_EXCEEDED, SIZE_LIMIT_EXCEEDED, PARTIAL_RESULTS], classLoader=null, sslSocketFactory=null, hostnameVerifier=null]], providerConnection=org.ldaptive.provider.jndi.JndiConnection@4659da82]>
2020-05-15 16:21:37,328 DEBUG [org.ldaptive.pool.BlockingConnectionPool] - <checking connection pool size >= 3 for [org.ldaptive.pool.BlockingConnectionPool@1020155882::name=null, poolConfig=[org.ldaptive.pool.PoolConfig@406817698::minPoolSize=3, maxPoolSize=10, validateOnCheckIn=false, validateOnCheckOut=true, validatePeriodically=true, validatePeriod=PT4M30S, validateTimeout=PT5S], activator=null, passivator=[org.ldaptive.pool.BindPassivator@843416218::bindRequest=[org.ldaptive.BindRequest@1674289898::bindDn=uid=admin,ou=system, saslConfig=null, controls=null, referralHandler=null, intermediateResponseHandlers=null]], validator=[org.ldaptive.pool.SearchValidator@762632318::searchRequest=[org.ldaptive.SearchRequest@1010379073::baseDn=, searchFilter=[org.ldaptive.SearchFilter@1642584434::filter=(objectClass=*), parameters={}], returnAttributes=[1.1], searchScope=OBJECT, timeLimit=PT0S, sizeLimit=1, derefAliases=null, typesOnly=false, binaryAttributes=null, sortBehavior=UNORDERED, searchEntryHandlers=null, searchReferenceHandlers=[org.ldaptive.referral.SearchReferralHandler$SearchReferenceHandler@49f234e9], controls=null, referralHandler=org.ldaptive.referral.SearchReferralHandler@573d3e1f, intermediateResponseHandlers=null]] pruneStrategy=[org.ldaptive.pool.IdlePruneStrategy@1776224992::prunePeriod=PT2H, idleTime=PT10M], connectOnCreate=true, connectionFactory=[org.ldaptive.DefaultConnectionFactory@1650690189::provider=org.ldaptive.provider.jndi.JndiProvider@3aeebd54, config=[org.ldaptive.ConnectionConfig@69054928::ldapUrl=ldaps://localhost:10636, connectTimeout=PT5S, responseTimeout=PT5S, sslConfig=[org.ldaptive.ssl.SslConfig@360985529::credentialConfig=null, trustManagers=null, hostnameVerifier=org.ldaptive.ssl.DefaultHostnameVerifier@6b5df664, hostnameVerifierConfig=null, enabledCipherSuites=null, enabledProtocols=null, handshakeCompletedListeners=null], useSSL=true, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@605483590::bindDn=uid=admin,ou=system, bindSaslConfig=null, bindControls=null], connectionStrategy=org.ldaptive.DefaultConnectionStrategy@4d6c4425]], initialized=true, availableCount=3, activeCount=0]>
2020-05-15 16:21:37,329 DEBUG [org.ldaptive.pool.BlockingConnectionPool] - <pool size after validation is 3>
2020-05-15 16:21:37,329 DEBUG [org.ldaptive.pool.BlockingConnectionPool] - <end validate task for [org.ldaptive.pool.BlockingConnectionPool@1020155882::name=null, poolConfig=[org.ldaptive.pool.PoolConfig@406817698::minPoolSize=3, maxPoolSize=10, validateOnCheckIn=false, validateOnCheckOut=true, validatePeriodically=true, validatePeriod=PT4M30S, validateTimeout=PT5S], activator=null, passivator=[org.ldaptive.pool.BindPassivator@843416218::bindRequest=[org.ldaptive.BindRequest@1674289898::bindDn=uid=admin,ou=system, saslConfig=null, controls=null, referralHandler=null, intermediateResponseHandlers=null]], validator=[org.ldaptive.pool.SearchValidator@762632318::searchRequest=[org.ldaptive.SearchRequest@1010379073::baseDn=, searchFilter=[org.ldaptive.SearchFilter@1642584434::filter=(objectClass=*), parameters={}], returnAttributes=[1.1], searchScope=OBJECT, timeLimit=PT0S, sizeLimit=1, derefAliases=null, typesOnly=false, binaryAttributes=null, sortBehavior=UNORDERED, searchEntryHandlers=null, searchReferenceHandlers=[org.ldaptive.referral.SearchReferralHandler$SearchReferenceHandler@49f234e9], controls=null, referralHandler=org.ldaptive.referral.SearchReferralHandler@573d3e1f, intermediateResponseHandlers=null]] pruneStrategy=[org.ldaptive.pool.IdlePruneStrategy@1776224992::prunePeriod=PT2H, idleTime=PT10M], connectOnCreate=true, connectionFactory=[org.ldaptive.DefaultConnectionFactory@1650690189::provider=org.ldaptive.provider.jndi.JndiProvider@3aeebd54, config=[org.ldaptive.ConnectionConfig@69054928::ldapUrl=ldaps://localhost:10636, connectTimeout=PT5S, responseTimeout=PT5S, sslConfig=[org.ldaptive.ssl.SslConfig@360985529::credentialConfig=null, trustManagers=null, hostnameVerifier=org.ldaptive.ssl.DefaultHostnameVerifier@6b5df664, hostnameVerifierConfig=null, enabledCipherSuites=null, enabledProtocols=null, handshakeCompletedListeners=null], useSSL=true, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@605483590::bindDn=uid=admin,ou=system, bindSaslConfig=null, bindControls=null], connectionStrategy=org.ldaptive.DefaultConnectionStrategy@4d6c4425]], initialized=true, availableCount=3, activeCount=0]>
2020-05-15 16:21:40,124 DEBUG [org.apereo.cas.authentication.adaptive.DefaultAdaptiveAuthenticationPolicy] - <Located client IP address as [0:0:0:0:0:0:0:1]>
2020-05-15 16:21:40,124 DEBUG [org.apereo.cas.authentication.adaptive.DefaultAdaptiveAuthenticationPolicy] - <User agent [Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/81.0.4044.138 Safari/537.36] is authorized to proceed>
2020-05-15 16:21:40,124 DEBUG [org.apereo.cas.authentication.adaptive.DefaultAdaptiveAuthenticationPolicy] - <Adaptive authentication policy has authorized client [0:0:0:0:0:0:0:1] to proceed.>
2020-05-15 16:21:40,124 DEBUG [org.apereo.cas.authentication.PolicyBasedAuthenticationManager] - <Invoking authentication pre processors for authentication transaction>
2020-05-15 16:21:40,124 DEBUG [org.apereo.cas.authentication.DefaultAuthenticationEventExecutionPlan] - <Sorted and registered authentication pre processors for this transaction are [[]]>
2020-05-15 16:21:40,124 DEBUG [org.apereo.cas.authentication.PolicyBasedAuthenticationManager] - <Authentication credentials provided for this transaction are [[UsernamePasswordCredential(username=testadmin)]]>
2020-05-15 16:21:40,124 DEBUG [org.apereo.cas.authentication.PolicyBasedAuthenticationManager] - <Candidate/Registered authentication handlers for this transaction are [[org.apereo.cas.authentication.handler.support.HttpBasedServiceCredentialsAuthenticationHandler@25fd5321, org.apereo.cas.authentication.LdapAuthenticationHandler@7771fa6d]]>
2020-05-15 16:21:40,124 DEBUG [org.apereo.cas.authentication.DefaultAuthenticationEventExecutionPlan] - <Sorted and registered authentication handler resolvers for this transaction are [[org.apereo.cas.authentication.RegisteredServiceAuthenticationHandlerResolver@665466f8]]>
2020-05-15 16:21:40,124 DEBUG [org.apereo.cas.authentication.PolicyBasedAuthenticationManager] - <Authentication handler resolvers for this transaction are [[org.apereo.cas.authentication.RegisteredServiceAuthenticationHandlerResolver@665466f8]]>
2020-05-15 16:21:40,125 DEBUG [org.apereo.cas.authentication.RegisteredServiceAuthenticationHandlerResolver] - <Located registered service definition [AbstractRegisteredService(serviceId=^(https|imaps)://.*, name=HTTPS and IMAPS, theme=null, informationUrl=null, privacyUrl=null, responseType=null, id=10000001, description=This service definition authorizes all application urls that support HTTPS and IMAPS protocols., expirationPolicy=DefaultRegisteredServiceExpirationPolicy(deleteWhenExpired=false, notifyWhenDeleted=false, expirationDate=null), proxyPolicy=RegexMatchingRegisteredServiceProxyPolicy(pattern=^https?://.*), evaluationOrder=10000, usernameAttributeProvider=org.apereo.cas.services.DefaultRegisteredServiceUsernameProvider@87297e2, logoutType=BACK_CHANNEL, requiredHandlers=[], attributeReleasePolicy=ReturnAllowedAttributeReleasePolicy(super=AbstractRegisteredServiceAttributeReleasePolicy(attributeFilter=null, principalAttributesRepository=DefaultPrincipalAttributesRepository(), consentPolicy=DefaultRegisteredServiceConsentPolicy(enabled=true, excludedAttributes=null, includeOnlyAttributes=null), authorizedToReleaseCredentialPassword=false, authorizedToReleaseProxyGrantingTicket=false, excludeDefaultAttributes=false, authorizedToReleaseAuthenticationAttributes=true, principalIdAttribute=null), allowedAttributes=[]), multifactorPolicy=DefaultRegisteredServiceMultifactorPolicy(multifactorAuthenticationProviders=[], failureMode=NOT_SET, principalAttributeNameTrigger=null, principalAttributeValueToMatch=null, bypassEnabled=false), logo=null, logoutUrl=null, accessStrategy=DefaultRegisteredServiceAccessStrategy(order=0, enabled=true, ssoEnabled=true, unauthorizedRedirectUrl=null, delegatedAuthenticationPolicy=DefaultRegisteredServiceDelegatedAuthenticationPolicy(allowedProviders=[]), requireAllAttributes=true, requiredAttributes={}, rejectedAttributes={}, caseInsensitive=false), publicKey=null, properties={}, contacts=[])] for this authentication transaction>
2020-05-15 16:21:40,125 DEBUG [org.apereo.cas.authentication.PolicyBasedAuthenticationManager] - <Authentication handler resolvers produced no candidate authentication handler. Using the default handler resolver instead...>
2020-05-15 16:21:40,125 DEBUG [org.apereo.cas.authentication.AuthenticationHandlerResolver] - <Default authentication handlers used for this transaction are [HttpBasedServiceCredentialsAuthenticationHandler,localhost]>
2020-05-15 16:21:40,125 DEBUG [org.apereo.cas.authentication.PolicyBasedAuthenticationManager] - <Resolved and finalized authentication handlers to carry out this authentication transaction are [[org.apereo.cas.authentication.handler.support.HttpBasedServiceCredentialsAuthenticationHandler@25fd5321, org.apereo.cas.authentication.LdapAuthenticationHandler@7771fa6d]]>
2020-05-15 16:21:40,125 DEBUG [org.apereo.cas.authentication.PolicyBasedAuthenticationManager] - <Candidate resolved authentication handlers for this transaction are [[org.apereo.cas.authentication.handler.support.HttpBasedServiceCredentialsAuthenticationHandler@25fd5321, org.apereo.cas.authentication.LdapAuthenticationHandler@7771fa6d]]>
2020-05-15 16:21:40,125 DEBUG [org.apereo.cas.authentication.PolicyBasedAuthenticationManager] - <Attempting to authenticate credential [UsernamePasswordCredential(username=testadmin)]>
2020-05-15 16:21:40,125 DEBUG [org.apereo.cas.authentication.PolicyBasedAuthenticationManager] - <Authentication handler [HttpBasedServiceCredentialsAuthenticationHandler] does not support the credential type [UsernamePasswordCredential(username=testadmin)]. Trying next...>
2020-05-15 16:21:40,125 DEBUG [org.apereo.cas.authentication.handler.support.AbstractUsernamePasswordAuthenticationHandler] - <Examining credential [UsernamePasswordCredential(username=testadmin)] eligibility for authentication handler [localhost]>
2020-05-15 16:21:40,125 DEBUG [org.apereo.cas.authentication.handler.support.AbstractUsernamePasswordAuthenticationHandler] - <Credential [UsernamePasswordCredential(username=testadmin)] eligibility is [localhost] for authentication handler [true]>
2020-05-15 16:21:40,125 DEBUG [org.apereo.cas.authentication.PolicyBasedAuthenticationManager] - <Attempting authentication of [testadmin] using [localhost]>
2020-05-15 16:21:40,126 DEBUG [org.apereo.cas.authentication.handler.support.AbstractUsernamePasswordAuthenticationHandler] - <Transforming credential username via [org.apereo.cas.util.transforms.ChainingPrincipalNameTransformer]>
2020-05-15 16:21:40,126 DEBUG [org.apereo.cas.authentication.handler.support.AbstractUsernamePasswordAuthenticationHandler] - <Attempting to encode credential password via [org.springframework.security.crypto.password.NoOpPasswordEncoder] for [testadmin]>
2020-05-15 16:21:40,126 DEBUG [org.apereo.cas.authentication.handler.support.AbstractUsernamePasswordAuthenticationHandler] - <Attempting authentication internally for transformed credential [UsernamePasswordCredential(username=testadmin)]>
2020-05-15 16:21:40,126 DEBUG [org.apereo.cas.authentication.LdapAuthenticationHandler] - <Attempting LDAP authentication for [UsernamePasswordCredential(username=testadmin)]. Authenticator pre-configured attributes are [null], additional requested attributes for this authentication request are [[]]>
2020-05-15 16:21:40,126 DEBUG [org.ldaptive.auth.PooledSearchDnResolver] - <resolve user=[org.ldaptive.auth.User@1918926652::identifier=testadmin, context=null]>
2020-05-15 16:21:40,126 DEBUG [org.ldaptive.auth.PooledSearchDnResolver] - <searching for DN using userFilter>
2020-05-15 16:21:40,126 DEBUG [org.ldaptive.SearchOperation] - <execute request=[org.ldaptive.SearchRequest@-293822691::baseDn=, searchFilter=[org.ldaptive.SearchFilter@1642584434::filter=(objectClass=*), parameters={}], returnAttributes=[1.1], searchScope=OBJECT, timeLimit=PT0S, sizeLimit=1, derefAliases=null, typesOnly=false, binaryAttributes=null, sortBehavior=UNORDERED, searchEntryHandlers=null, searchReferenceHandlers=[org.ldaptive.referral.SearchReferralHandler$SearchReferenceHandler@168e0741], controls=null, referralHandler=org.ldaptive.referral.SearchReferralHandler@56ab92e3, intermediateResponseHandlers=null] with connection=[org.ldaptive.DefaultConnectionFactory$DefaultConnection@151557927::config=[org.ldaptive.ConnectionConfig@1674393752::ldapUrl=ldaps://localhost:10636, connectTimeout=PT5S, responseTimeout=PT5S, sslConfig=[org.ldaptive.ssl.SslConfig@441890154::credentialConfig=null, trustManagers=null, hostnameVerifier=org.ldaptive.ssl.DefaultHostnameVerifier@151ba6c4, hostnameVerifierConfig=null, enabledCipherSuites=null, enabledProtocols=null, handshakeCompletedListeners=null], useSSL=true, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@550216394::bindDn=uid=admin,ou=system, bindSaslConfig=null, bindControls=null], connectionStrategy=org.ldaptive.DefaultConnectionStrategy@2a4857b3], providerConnectionFactory=[org.ldaptive.provider.jndi.JndiConnectionFactory@757859259::metadata=[ldapUrl=ldaps://localhost:10636, count=1], environment={java.naming.ldap.factory.socket=org.ldaptive.ssl.ThreadLocalTLSSocketFactory, com.sun.jndi.ldap.connect.timeout=5000, java.naming.ldap.version=3, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory, java.naming.security.protocol=ssl, com.sun.jndi.ldap.read.timeout=5000}, classLoader=null, providerConfig=[org.ldaptive.provider.jndi.JndiProviderConfig@115751302::operationExceptionResultCodes=[PROTOCOL_ERROR, SERVER_DOWN], properties={}, controlProcessor=org.ldaptive.provider.ControlProcessor@6c16356b, environment=null, tracePackets=null, removeDnUrls=true, searchIgnoreResultCodes=[TIME_LIMIT_EXCEEDED, SIZE_LIMIT_EXCEEDED, PARTIAL_RESULTS], classLoader=null, sslSocketFactory=null, hostnameVerifier=null]], providerConnection=org.ldaptive.provider.jndi.JndiConnection@1c30e0e4]>
2020-05-15 16:21:40,128 DEBUG [org.ldaptive.SearchOperation] - <execute response=[org.ldaptive.Response@532483090::result=[org.ldaptive.SearchResult@-1951941189::entries=[[dn=[], responseControls=null, messageId=-1]], references=[]], resultCode=SUCCESS, message=null, matchedDn=null, responseControls=null, referralURLs=null, messageId=-1] for request=[org.ldaptive.SearchRequest@-293822691::baseDn=, searchFilter=[org.ldaptive.SearchFilter@1642584434::filter=(objectClass=*), parameters={}], returnAttributes=[1.1], searchScope=OBJECT, timeLimit=PT0S, sizeLimit=1, derefAliases=null, typesOnly=false, binaryAttributes=null, sortBehavior=UNORDERED, searchEntryHandlers=null, searchReferenceHandlers=[org.ldaptive.referral.SearchReferralHandler$SearchReferenceHandler@168e0741], controls=null, referralHandler=org.ldaptive.referral.SearchReferralHandler@56ab92e3, intermediateResponseHandlers=null] with connection=[org.ldaptive.DefaultConnectionFactory$DefaultConnection@151557927::config=[org.ldaptive.ConnectionConfig@1674393752::ldapUrl=ldaps://localhost:10636, connectTimeout=PT5S, responseTimeout=PT5S, sslConfig=[org.ldaptive.ssl.SslConfig@441890154::credentialConfig=null, trustManagers=null, hostnameVerifier=org.ldaptive.ssl.DefaultHostnameVerifier@151ba6c4, hostnameVerifierConfig=null, enabledCipherSuites=null, enabledProtocols=null, handshakeCompletedListeners=null], useSSL=true, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@550216394::bindDn=uid=admin,ou=system, bindSaslConfig=null, bindControls=null], connectionStrategy=org.ldaptive.DefaultConnectionStrategy@2a4857b3], providerConnectionFactory=[org.ldaptive.provider.jndi.JndiConnectionFactory@757859259::metadata=[ldapUrl=ldaps://localhost:10636, count=1], environment={java.naming.ldap.factory.socket=org.ldaptive.ssl.ThreadLocalTLSSocketFactory, com.sun.jndi.ldap.connect.timeout=5000, java.naming.ldap.version=3, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory, java.naming.security.protocol=ssl, com.sun.jndi.ldap.read.timeout=5000}, classLoader=null, providerConfig=[org.ldaptive.provider.jndi.JndiProviderConfig@115751302::operationExceptionResultCodes=[PROTOCOL_ERROR, SERVER_DOWN], properties={}, controlProcessor=org.ldaptive.provider.ControlProcessor@6c16356b, environment=null, tracePackets=null, removeDnUrls=true, searchIgnoreResultCodes=[TIME_LIMIT_EXCEEDED, SIZE_LIMIT_EXCEEDED, PARTIAL_RESULTS], classLoader=null, sslSocketFactory=null, hostnameVerifier=null]], providerConnection=org.ldaptive.provider.jndi.JndiConnection@1c30e0e4]>
2020-05-15 16:21:40,128 DEBUG [org.ldaptive.SearchOperation] - <execute request=[org.ldaptive.SearchRequest@-1786190294::baseDn=dc=promap,dc=org, searchFilter=[org.ldaptive.SearchFilter@517380768::filter=uid={user}, parameters={context=null, user=testadmin}], returnAttributes=[1.1], searchScope=SUBTREE, timeLimit=PT0S, sizeLimit=0, derefAliases=null, typesOnly=false, binaryAttributes=null, sortBehavior=UNORDERED, searchEntryHandlers=null, searchReferenceHandlers=[org.ldaptive.referral.SearchReferralHandler$SearchReferenceHandler@545f62d2], controls=null, referralHandler=org.ldaptive.referral.SearchReferralHandler@20df1951, intermediateResponseHandlers=null] with connection=[org.ldaptive.DefaultConnectionFactory$DefaultConnection@151557927::config=[org.ldaptive.ConnectionConfig@1674393752::ldapUrl=ldaps://localhost:10636, connectTimeout=PT5S, responseTimeout=PT5S, sslConfig=[org.ldaptive.ssl.SslConfig@441890154::credentialConfig=null, trustManagers=null, hostnameVerifier=org.ldaptive.ssl.DefaultHostnameVerifier@151ba6c4, hostnameVerifierConfig=null, enabledCipherSuites=null, enabledProtocols=null, handshakeCompletedListeners=null], useSSL=true, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@550216394::bindDn=uid=admin,ou=system, bindSaslConfig=null, bindControls=null], connectionStrategy=org.ldaptive.DefaultConnectionStrategy@2a4857b3], providerConnectionFactory=[org.ldaptive.provider.jndi.JndiConnectionFactory@757859259::metadata=[ldapUrl=ldaps://localhost:10636, count=1], environment={java.naming.ldap.factory.socket=org.ldaptive.ssl.ThreadLocalTLSSocketFactory, com.sun.jndi.ldap.connect.timeout=5000, java.naming.ldap.version=3, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory, java.naming.security.protocol=ssl, com.sun.jndi.ldap.read.timeout=5000}, classLoader=null, providerConfig=[org.ldaptive.provider.jndi.JndiProviderConfig@115751302::operationExceptionResultCodes=[PROTOCOL_ERROR, SERVER_DOWN], properties={}, controlProcessor=org.ldaptive.provider.ControlProcessor@6c16356b, environment=null, tracePackets=null, removeDnUrls=true, searchIgnoreResultCodes=[TIME_LIMIT_EXCEEDED, SIZE_LIMIT_EXCEEDED, PARTIAL_RESULTS], classLoader=null, sslSocketFactory=null, hostnameVerifier=null]], providerConnection=org.ldaptive.provider.jndi.JndiConnection@1c30e0e4]>
2020-05-15 16:21:40,131 DEBUG [org.ldaptive.SearchOperation] - <execute response=[org.ldaptive.Response@697724893::result=[org.ldaptive.SearchResult@1411040287::entries=[[dn=uid=testadmin,ou=users,dc=promap,dc=org[], responseControls=null, messageId=-1]], references=[]], resultCode=SUCCESS, message=null, matchedDn=null, responseControls=null, referralURLs=null, messageId=-1] for request=[org.ldaptive.SearchRequest@-1786190294::baseDn=dc=promap,dc=org, searchFilter=[org.ldaptive.SearchFilter@517380768::filter=uid={user}, parameters={context=null, user=testadmin}], returnAttributes=[1.1], searchScope=SUBTREE, timeLimit=PT0S, sizeLimit=0, derefAliases=null, typesOnly=false, binaryAttributes=null, sortBehavior=UNORDERED, searchEntryHandlers=null, searchReferenceHandlers=[org.ldaptive.referral.SearchReferralHandler$SearchReferenceHandler@545f62d2], controls=null, referralHandler=org.ldaptive.referral.SearchReferralHandler@20df1951, intermediateResponseHandlers=null] with connection=[org.ldaptive.DefaultConnectionFactory$DefaultConnection@151557927::config=[org.ldaptive.ConnectionConfig@1674393752::ldapUrl=ldaps://localhost:10636, connectTimeout=PT5S, responseTimeout=PT5S, sslConfig=[org.ldaptive.ssl.SslConfig@441890154::credentialConfig=null, trustManagers=null, hostnameVerifier=org.ldaptive.ssl.DefaultHostnameVerifier@151ba6c4, hostnameVerifierConfig=null, enabledCipherSuites=null, enabledProtocols=null, handshakeCompletedListeners=null], useSSL=true, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@550216394::bindDn=uid=admin,ou=system, bindSaslConfig=null, bindControls=null], connectionStrategy=org.ldaptive.DefaultConnectionStrategy@2a4857b3], providerConnectionFactory=[org.ldaptive.provider.jndi.JndiConnectionFactory@757859259::metadata=[ldapUrl=ldaps://localhost:10636, count=1], environment={java.naming.ldap.factory.socket=org.ldaptive.ssl.ThreadLocalTLSSocketFactory, com.sun.jndi.ldap.connect.timeout=5000, java.naming.ldap.version=3, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory, java.naming.security.protocol=ssl, com.sun.jndi.ldap.read.timeout=5000}, classLoader=null, providerConfig=[org.ldaptive.provider.jndi.JndiProviderConfig@115751302::operationExceptionResultCodes=[PROTOCOL_ERROR, SERVER_DOWN], properties={}, controlProcessor=org.ldaptive.provider.ControlProcessor@6c16356b, environment=null, tracePackets=null, removeDnUrls=true, searchIgnoreResultCodes=[TIME_LIMIT_EXCEEDED, SIZE_LIMIT_EXCEEDED, PARTIAL_RESULTS], classLoader=null, sslSocketFactory=null, hostnameVerifier=null]], providerConnection=org.ldaptive.provider.jndi.JndiConnection@1c30e0e4]>
2020-05-15 16:21:40,131 DEBUG [org.ldaptive.BindOperation] - <execute request=[org.ldaptive.BindRequest@1987012004::bindDn=uid=admin,ou=system, saslConfig=null, controls=null, referralHandler=null, intermediateResponseHandlers=null] with connection=[org.ldaptive.DefaultConnectionFactory$DefaultConnection@151557927::config=[org.ldaptive.ConnectionConfig@1674393752::ldapUrl=ldaps://localhost:10636, connectTimeout=PT5S, responseTimeout=PT5S, sslConfig=[org.ldaptive.ssl.SslConfig@441890154::credentialConfig=null, trustManagers=null, hostnameVerifier=org.ldaptive.ssl.DefaultHostnameVerifier@151ba6c4, hostnameVerifierConfig=null, enabledCipherSuites=null, enabledProtocols=null, handshakeCompletedListeners=null], useSSL=true, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@550216394::bindDn=uid=admin,ou=system, bindSaslConfig=null, bindControls=null], connectionStrategy=org.ldaptive.DefaultConnectionStrategy@2a4857b3], providerConnectionFactory=[org.ldaptive.provider.jndi.JndiConnectionFactory@757859259::metadata=[ldapUrl=ldaps://localhost:10636, count=1], environment={java.naming.ldap.factory.socket=org.ldaptive.ssl.ThreadLocalTLSSocketFactory, com.sun.jndi.ldap.connect.timeout=5000, java.naming.ldap.version=3, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory, java.naming.security.protocol=ssl, com.sun.jndi.ldap.read.timeout=5000}, classLoader=null, providerConfig=[org.ldaptive.provider.jndi.JndiProviderConfig@115751302::operationExceptionResultCodes=[PROTOCOL_ERROR, SERVER_DOWN], properties={}, controlProcessor=org.ldaptive.provider.ControlProcessor@6c16356b, environment=null, tracePackets=null, removeDnUrls=true, searchIgnoreResultCodes=[TIME_LIMIT_EXCEEDED, SIZE_LIMIT_EXCEEDED, PARTIAL_RESULTS], classLoader=null, sslSocketFactory=null, hostnameVerifier=null]], providerConnection=org.ldaptive.provider.jndi.JndiConnection@1c30e0e4]>
2020-05-15 16:21:40,132 DEBUG [org.ldaptive.BindOperation] - <execute response=[org.ldaptive.Response@1493072972::result=null, resultCode=SUCCESS, message=null, matchedDn=null, responseControls=null, referralURLs=null, messageId=-1] for request=[org.ldaptive.BindRequest@1987012004::bindDn=uid=admin,ou=system, saslConfig=null, controls=null, referralHandler=null, intermediateResponseHandlers=null] with connection=[org.ldaptive.DefaultConnectionFactory$DefaultConnection@151557927::config=[org.ldaptive.ConnectionConfig@1674393752::ldapUrl=ldaps://localhost:10636, connectTimeout=PT5S, responseTimeout=PT5S, sslConfig=[org.ldaptive.ssl.SslConfig@441890154::credentialConfig=null, trustManagers=null, hostnameVerifier=org.ldaptive.ssl.DefaultHostnameVerifier@151ba6c4, hostnameVerifierConfig=null, enabledCipherSuites=null, enabledProtocols=null, handshakeCompletedListeners=null], useSSL=true, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@550216394::bindDn=uid=admin,ou=system, bindSaslConfig=null, bindControls=null], connectionStrategy=org.ldaptive.DefaultConnectionStrategy@2a4857b3], providerConnectionFactory=[org.ldaptive.provider.jndi.JndiConnectionFactory@757859259::metadata=[ldapUrl=ldaps://localhost:10636, count=1], environment={java.naming.ldap.factory.socket=org.ldaptive.ssl.ThreadLocalTLSSocketFactory, com.sun.jndi.ldap.connect.timeout=5000, java.naming.ldap.version=3, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory, java.naming.security.protocol=ssl, com.sun.jndi.ldap.read.timeout=5000}, classLoader=null, providerConfig=[org.ldaptive.provider.jndi.JndiProviderConfig@115751302::operationExceptionResultCodes=[PROTOCOL_ERROR, SERVER_DOWN], properties={}, controlProcessor=org.ldaptive.provider.ControlProcessor@6c16356b, environment=null, tracePackets=null, removeDnUrls=true, searchIgnoreResultCodes=[TIME_LIMIT_EXCEEDED, SIZE_LIMIT_EXCEEDED, PARTIAL_RESULTS], classLoader=null, sslSocketFactory=null, hostnameVerifier=null]], providerConnection=org.ldaptive.provider.jndi.JndiConnection@1c30e0e4]>
2020-05-15 16:21:40,132 DEBUG [org.ldaptive.auth.PooledSearchDnResolver] - <resolved dn=uid=testadmin,ou=users,dc=promap,dc=org for user=[org.ldaptive.auth.User@1918926652::identifier=testadmin, context=null]>
2020-05-15 16:21:40,132 DEBUG [org.ldaptive.auth.Authenticator] - <authenticate dn=uid=testadmin,ou=users,dc=promap,dc=org with request=[org.ldaptive.auth.AuthenticationRequest@802436829::user=[org.ldaptive.auth.User@1918926652::identifier=testadmin, context=null], returnAttributes=[], controls=null]>
2020-05-15 16:21:40,132 DEBUG [org.ldaptive.auth.PooledBindAuthenticationHandler] - <authenticate criteria=[org.ldaptive.auth.AuthenticationCriteria@11704327::dn=uid=testadmin,ou=users,dc=promap,dc=org, authenticationRequest=[org.ldaptive.auth.AuthenticationRequest@802436829::user=[org.ldaptive.auth.User@1918926652::identifier=testadmin, context=null], returnAttributes=[], controls=null]]>
2020-05-15 16:21:40,133 DEBUG [org.ldaptive.SearchOperation] - <execute request=[org.ldaptive.SearchRequest@-150626027::baseDn=, searchFilter=[org.ldaptive.SearchFilter@1642584434::filter=(objectClass=*), parameters={}], returnAttributes=[1.1], searchScope=OBJECT, timeLimit=PT0S, sizeLimit=1, derefAliases=null, typesOnly=false, binaryAttributes=null, sortBehavior=UNORDERED, searchEntryHandlers=null, searchReferenceHandlers=[org.ldaptive.referral.SearchReferralHandler$SearchReferenceHandler@45f9a505], controls=null, referralHandler=org.ldaptive.referral.SearchReferralHandler@12394ed7, intermediateResponseHandlers=null] with connection=[org.ldaptive.DefaultConnectionFactory$DefaultConnection@778956176::config=[org.ldaptive.ConnectionConfig@1311766432::ldapUrl=ldaps://localhost:10636, connectTimeout=PT5S, responseTimeout=PT5S, sslConfig=[org.ldaptive.ssl.SslConfig@659921050::credentialConfig=null, trustManagers=null, hostnameVerifier=org.ldaptive.ssl.DefaultHostnameVerifier@31ba76e1, hostnameVerifierConfig=null, enabledCipherSuites=null, enabledProtocols=null, handshakeCompletedListeners=null], useSSL=true, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@1697957628::bindDn=uid=admin,ou=system, bindSaslConfig=null, bindControls=null], connectionStrategy=org.ldaptive.DefaultConnectionStrategy@5417af0d], providerConnectionFactory=[org.ldaptive.provider.jndi.JndiConnectionFactory@2015145363::metadata=[ldapUrl=ldaps://localhost:10636, count=1], environment={java.naming.ldap.factory.socket=org.ldaptive.ssl.ThreadLocalTLSSocketFactory, com.sun.jndi.ldap.connect.timeout=5000, java.naming.ldap.version=3, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory, java.naming.security.protocol=ssl, com.sun.jndi.ldap.read.timeout=5000}, classLoader=null, providerConfig=[org.ldaptive.provider.jndi.JndiProviderConfig@1941628011::operationExceptionResultCodes=[PROTOCOL_ERROR, SERVER_DOWN], properties={}, controlProcessor=org.ldaptive.provider.ControlProcessor@6bc9bc66, environment=null, tracePackets=null, removeDnUrls=true, searchIgnoreResultCodes=[TIME_LIMIT_EXCEEDED, SIZE_LIMIT_EXCEEDED, PARTIAL_RESULTS], classLoader=null, sslSocketFactory=null, hostnameVerifier=null]], providerConnection=org.ldaptive.provider.jndi.JndiConnection@33d1c017]>
2020-05-15 16:21:40,134 DEBUG [org.ldaptive.SearchOperation] - <execute response=[org.ldaptive.Response@440461131::result=[org.ldaptive.SearchResult@-1951941189::entries=[[dn=[], responseControls=null, messageId=-1]], references=[]], resultCode=SUCCESS, message=null, matchedDn=null, responseControls=null, referralURLs=null, messageId=-1] for request=[org.ldaptive.SearchRequest@-150626027::baseDn=, searchFilter=[org.ldaptive.SearchFilter@1642584434::filter=(objectClass=*), parameters={}], returnAttributes=[1.1], searchScope=OBJECT, timeLimit=PT0S, sizeLimit=1, derefAliases=null, typesOnly=false, binaryAttributes=null, sortBehavior=UNORDERED, searchEntryHandlers=null, searchReferenceHandlers=[org.ldaptive.referral.SearchReferralHandler$SearchReferenceHandler@45f9a505], controls=null, referralHandler=org.ldaptive.referral.SearchReferralHandler@12394ed7, intermediateResponseHandlers=null] with connection=[org.ldaptive.DefaultConnectionFactory$DefaultConnection@778956176::config=[org.ldaptive.ConnectionConfig@1311766432::ldapUrl=ldaps://localhost:10636, connectTimeout=PT5S, responseTimeout=PT5S, sslConfig=[org.ldaptive.ssl.SslConfig@659921050::credentialConfig=null, trustManagers=null, hostnameVerifier=org.ldaptive.ssl.DefaultHostnameVerifier@31ba76e1, hostnameVerifierConfig=null, enabledCipherSuites=null, enabledProtocols=null, handshakeCompletedListeners=null], useSSL=true, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@1697957628::bindDn=uid=admin,ou=system, bindSaslConfig=null, bindControls=null], connectionStrategy=org.ldaptive.DefaultConnectionStrategy@5417af0d], providerConnectionFactory=[org.ldaptive.provider.jndi.JndiConnectionFactory@2015145363::metadata=[ldapUrl=ldaps://localhost:10636, count=1], environment={java.naming.ldap.factory.socket=org.ldaptive.ssl.ThreadLocalTLSSocketFactory, com.sun.jndi.ldap.connect.timeout=5000, java.naming.ldap.version=3, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory, java.naming.security.protocol=ssl, com.sun.jndi.ldap.read.timeout=5000}, classLoader=null, providerConfig=[org.ldaptive.provider.jndi.JndiProviderConfig@1941628011::operationExceptionResultCodes=[PROTOCOL_ERROR, SERVER_DOWN], properties={}, controlProcessor=org.ldaptive.provider.ControlProcessor@6bc9bc66, environment=null, tracePackets=null, removeDnUrls=true, searchIgnoreResultCodes=[TIME_LIMIT_EXCEEDED, SIZE_LIMIT_EXCEEDED, PARTIAL_RESULTS], classLoader=null, sslSocketFactory=null, hostnameVerifier=null]], providerConnection=org.ldaptive.provider.jndi.JndiConnection@33d1c017]>
2020-05-15 16:21:40,134 DEBUG [org.ldaptive.BindOperation] - <execute request=[org.ldaptive.BindRequest@838333523::bindDn=uid=testadmin,ou=users,dc=promap,dc=org, saslConfig=null, controls=[[org.ldaptive.control.PasswordPolicyControl@-350070253::criticality=false, timeBeforeExpiration=-1, graceAuthNsRemaining=-1, error=null]], referralHandler=null, intermediateResponseHandlers=null] with connection=[org.ldaptive.DefaultConnectionFactory$DefaultConnection@778956176::config=[org.ldaptive.ConnectionConfig@1311766432::ldapUrl=ldaps://localhost:10636, connectTimeout=PT5S, responseTimeout=PT5S, sslConfig=[org.ldaptive.ssl.SslConfig@659921050::credentialConfig=null, trustManagers=null, hostnameVerifier=org.ldaptive.ssl.DefaultHostnameVerifier@31ba76e1, hostnameVerifierConfig=null, enabledCipherSuites=null, enabledProtocols=null, handshakeCompletedListeners=null], useSSL=true, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@1697957628::bindDn=uid=admin,ou=system, bindSaslConfig=null, bindControls=null], connectionStrategy=org.ldaptive.DefaultConnectionStrategy@5417af0d], providerConnectionFactory=[org.ldaptive.provider.jndi.JndiConnectionFactory@2015145363::metadata=[ldapUrl=ldaps://localhost:10636, count=1], environment={java.naming.ldap.factory.socket=org.ldaptive.ssl.ThreadLocalTLSSocketFactory, com.sun.jndi.ldap.connect.timeout=5000, java.naming.ldap.version=3, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory, java.naming.security.protocol=ssl, com.sun.jndi.ldap.read.timeout=5000}, classLoader=null, providerConfig=[org.ldaptive.provider.jndi.JndiProviderConfig@1941628011::operationExceptionResultCodes=[PROTOCOL_ERROR, SERVER_DOWN], properties={}, controlProcessor=org.ldaptive.provider.ControlProcessor@6bc9bc66, environment=null, tracePackets=null, removeDnUrls=true, searchIgnoreResultCodes=[TIME_LIMIT_EXCEEDED, SIZE_LIMIT_EXCEEDED, PARTIAL_RESULTS], classLoader=null, sslSocketFactory=null, hostnameVerifier=null]], providerConnection=org.ldaptive.provider.jndi.JndiConnection@33d1c017]>
2020-05-15 16:21:40,136 DEBUG [org.ldaptive.BindOperation] - <execute response=[org.ldaptive.Response@1067142766::result=null, resultCode=SUCCESS, message=null, matchedDn=null, responseControls=[[org.ldaptive.control.PasswordPolicyControl@-350070253::criticality=false, timeBeforeExpiration=-1, graceAuthNsRemaining=-1, error=null]], referralURLs=null, messageId=-1] for request=[org.ldaptive.BindRequest@838333523::bindDn=uid=testadmin,ou=users,dc=promap,dc=org, saslConfig=null, controls=[[org.ldaptive.control.PasswordPolicyControl@-350070253::criticality=false, timeBeforeExpiration=-1, graceAuthNsRemaining=-1, error=null]], referralHandler=null, intermediateResponseHandlers=null] with connection=[org.ldaptive.DefaultConnectionFactory$DefaultConnection@778956176::config=[org.ldaptive.ConnectionConfig@1311766432::ldapUrl=ldaps://localhost:10636, connectTimeout=PT5S, responseTimeout=PT5S, sslConfig=[org.ldaptive.ssl.SslConfig@659921050::credentialConfig=null, trustManagers=null, hostnameVerifier=org.ldaptive.ssl.DefaultHostnameVerifier@31ba76e1, hostnameVerifierConfig=null, enabledCipherSuites=null, enabledProtocols=null, handshakeCompletedListeners=null], useSSL=true, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@1697957628::bindDn=uid=admin,ou=system, bindSaslConfig=null, bindControls=null], connectionStrategy=org.ldaptive.DefaultConnectionStrategy@5417af0d], providerConnectionFactory=[org.ldaptive.provider.jndi.JndiConnectionFactory@2015145363::metadata=[ldapUrl=ldaps://localhost:10636, count=1], environment={java.naming.ldap.factory.socket=org.ldaptive.ssl.ThreadLocalTLSSocketFactory, com.sun.jndi.ldap.connect.timeout=5000, java.naming.ldap.version=3, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory, java.naming.security.protocol=ssl, com.sun.jndi.ldap.read.timeout=5000}, classLoader=null, providerConfig=[org.ldaptive.provider.jndi.JndiProviderConfig@1941628011::operationExceptionResultCodes=[PROTOCOL_ERROR, SERVER_DOWN], properties={}, controlProcessor=org.ldaptive.provider.ControlProcessor@6bc9bc66, environment=null, tracePackets=null, removeDnUrls=true, searchIgnoreResultCodes=[TIME_LIMIT_EXCEEDED, SIZE_LIMIT_EXCEEDED, PARTIAL_RESULTS], classLoader=null, sslSocketFactory=null, hostnameVerifier=null]], providerConnection=org.ldaptive.provider.jndi.JndiConnection@33d1c017]>
2020-05-15 16:21:40,136 DEBUG [org.ldaptive.auth.PooledBindAuthenticationHandler] - <authenticate response=[org.ldaptive.auth.AuthenticationHandlerResponse@738040634::connection=[org.ldaptive.DefaultConnectionFactory$DefaultConnection@778956176::config=[org.ldaptive.ConnectionConfig@1311766432::ldapUrl=ldaps://localhost:10636, connectTimeout=PT5S, responseTimeout=PT5S, sslConfig=[org.ldaptive.ssl.SslConfig@659921050::credentialConfig=null, trustManagers=null, hostnameVerifier=org.ldaptive.ssl.DefaultHostnameVerifier@31ba76e1, hostnameVerifierConfig=null, enabledCipherSuites=null, enabledProtocols=null, handshakeCompletedListeners=null], useSSL=true, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@1697957628::bindDn=uid=admin,ou=system, bindSaslConfig=null, bindControls=null], connectionStrategy=org.ldaptive.DefaultConnectionStrategy@5417af0d], providerConnectionFactory=[org.ldaptive.provider.jndi.JndiConnectionFactory@2015145363::metadata=[ldapUrl=ldaps://localhost:10636, count=1], environment={java.naming.ldap.factory.socket=org.ldaptive.ssl.ThreadLocalTLSSocketFactory, com.sun.jndi.ldap.connect.timeout=5000, java.naming.ldap.version=3, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory, java.naming.security.protocol=ssl, com.sun.jndi.ldap.read.timeout=5000}, classLoader=null, providerConfig=[org.ldaptive.provider.jndi.JndiProviderConfig@1941628011::operationExceptionResultCodes=[PROTOCOL_ERROR, SERVER_DOWN], properties={}, controlProcessor=org.ldaptive.provider.ControlProcessor@6bc9bc66, environment=null, tracePackets=null, removeDnUrls=true, searchIgnoreResultCodes=[TIME_LIMIT_EXCEEDED, SIZE_LIMIT_EXCEEDED, PARTIAL_RESULTS], classLoader=null, sslSocketFactory=null, hostnameVerifier=null]], providerConnection=org.ldaptive.provider.jndi.JndiConnection@33d1c017], result=true, resultCode=SUCCESS, message=null, controls=[[org.ldaptive.control.PasswordPolicyControl@-350070253::criticality=false, timeBeforeExpiration=-1, graceAuthNsRemaining=-1, error=null]]] for criteria=[org.ldaptive.auth.AuthenticationCriteria@11704327::dn=uid=testadmin,ou=users,dc=promap,dc=org, authenticationRequest=[org.ldaptive.auth.AuthenticationRequest@802436829::user=[org.ldaptive.auth.User@1918926652::identifier=testadmin, context=null], returnAttributes=[], controls=null]]>
2020-05-15 16:21:40,136 DEBUG [org.apereo.cas.util.BinaryAttributeAwarePooledSearchEntryResolver] - <resolve criteria=[org.ldaptive.auth.AuthenticationCriteria@11704327::dn=uid=testadmin,ou=users,dc=promap,dc=org, authenticationRequest=[org.ldaptive.auth.AuthenticationRequest@802436829::user=[org.ldaptive.auth.User@1918926652::identifier=testadmin, context=null], returnAttributes=[], controls=null]]>
2020-05-15 16:21:40,136 DEBUG [org.ldaptive.SearchOperation] - <execute request=[org.ldaptive.SearchRequest@1010379073::baseDn=, searchFilter=[org.ldaptive.SearchFilter@1642584434::filter=(objectClass=*), parameters={}], returnAttributes=[1.1], searchScope=OBJECT, timeLimit=PT0S, sizeLimit=1, derefAliases=null, typesOnly=false, binaryAttributes=null, sortBehavior=UNORDERED, searchEntryHandlers=null, searchReferenceHandlers=[org.ldaptive.referral.SearchReferralHandler$SearchReferenceHandler@49f234e9], controls=null, referralHandler=org.ldaptive.referral.SearchReferralHandler@573d3e1f, intermediateResponseHandlers=null] with connection=[org.ldaptive.DefaultConnectionFactory$DefaultConnection@1829212099::config=[org.ldaptive.ConnectionConfig@69054928::ldapUrl=ldaps://localhost:10636, connectTimeout=PT5S, responseTimeout=PT5S, sslConfig=[org.ldaptive.ssl.SslConfig@360985529::credentialConfig=null, trustManagers=null, hostnameVerifier=org.ldaptive.ssl.DefaultHostnameVerifier@6b5df664, hostnameVerifierConfig=null, enabledCipherSuites=null, enabledProtocols=null, handshakeCompletedListeners=null], useSSL=true, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@605483590::bindDn=uid=admin,ou=system, bindSaslConfig=null, bindControls=null], connectionStrategy=org.ldaptive.DefaultConnectionStrategy@4d6c4425], providerConnectionFactory=[org.ldaptive.provider.jndi.JndiConnectionFactory@120885305::metadata=[ldapUrl=ldaps://localhost:10636, count=1], environment={java.naming.ldap.factory.socket=org.ldaptive.ssl.ThreadLocalTLSSocketFactory, com.sun.jndi.ldap.connect.timeout=5000, java.naming.ldap.version=3, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory, java.naming.security.protocol=ssl, com.sun.jndi.ldap.read.timeout=5000}, classLoader=null, providerConfig=[org.ldaptive.provider.jndi.JndiProviderConfig@1257083098::operationExceptionResultCodes=[PROTOCOL_ERROR, SERVER_DOWN], properties={}, controlProcessor=org.ldaptive.provider.ControlProcessor@54fc5824, environment=null, tracePackets=null, removeDnUrls=true, searchIgnoreResultCodes=[TIME_LIMIT_EXCEEDED, SIZE_LIMIT_EXCEEDED, PARTIAL_RESULTS], classLoader=null, sslSocketFactory=null, hostnameVerifier=null]], providerConnection=org.ldaptive.provider.jndi.JndiConnection@4659da82]>
2020-05-15 16:21:40,137 DEBUG [org.ldaptive.SearchOperation] - <execute response=[org.ldaptive.Response@907697073::result=[org.ldaptive.SearchResult@-1951941189::entries=[[dn=[], responseControls=null, messageId=-1]], references=[]], resultCode=SUCCESS, message=null, matchedDn=null, responseControls=null, referralURLs=null, messageId=-1] for request=[org.ldaptive.SearchRequest@1010379073::baseDn=, searchFilter=[org.ldaptive.SearchFilter@1642584434::filter=(objectClass=*), parameters={}], returnAttributes=[1.1], searchScope=OBJECT, timeLimit=PT0S, sizeLimit=1, derefAliases=null, typesOnly=false, binaryAttributes=null, sortBehavior=UNORDERED, searchEntryHandlers=null, searchReferenceHandlers=[org.ldaptive.referral.SearchReferralHandler$SearchReferenceHandler@49f234e9], controls=null, referralHandler=org.ldaptive.referral.SearchReferralHandler@573d3e1f, intermediateResponseHandlers=null] with connection=[org.ldaptive.DefaultConnectionFactory$DefaultConnection@1829212099::config=[org.ldaptive.ConnectionConfig@69054928::ldapUrl=ldaps://localhost:10636, connectTimeout=PT5S, responseTimeout=PT5S, sslConfig=[org.ldaptive.ssl.SslConfig@360985529::credentialConfig=null, trustManagers=null, hostnameVerifier=org.ldaptive.ssl.DefaultHostnameVerifier@6b5df664, hostnameVerifierConfig=null, enabledCipherSuites=null, enabledProtocols=null, handshakeCompletedListeners=null], useSSL=true, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@605483590::bindDn=uid=admin,ou=system, bindSaslConfig=null, bindControls=null], connectionStrategy=org.ldaptive.DefaultConnectionStrategy@4d6c4425], providerConnectionFactory=[org.ldaptive.provider.jndi.JndiConnectionFactory@120885305::metadata=[ldapUrl=ldaps://localhost:10636, count=1], environment={java.naming.ldap.factory.socket=org.ldaptive.ssl.ThreadLocalTLSSocketFactory, com.sun.jndi.ldap.connect.timeout=5000, java.naming.ldap.version=3, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory, java.naming.security.protocol=ssl, com.sun.jndi.ldap.read.timeout=5000}, classLoader=null, providerConfig=[org.ldaptive.provider.jndi.JndiProviderConfig@1257083098::operationExceptionResultCodes=[PROTOCOL_ERROR, SERVER_DOWN], properties={}, controlProcessor=org.ldaptive.provider.ControlProcessor@54fc5824, environment=null, tracePackets=null, removeDnUrls=true, searchIgnoreResultCodes=[TIME_LIMIT_EXCEEDED, SIZE_LIMIT_EXCEEDED, PARTIAL_RESULTS], classLoader=null, sslSocketFactory=null, hostnameVerifier=null]], providerConnection=org.ldaptive.provider.jndi.JndiConnection@4659da82]>
2020-05-15 16:21:40,137 DEBUG [org.apereo.cas.util.BinaryAttributeAwarePooledSearchEntryResolver] - <searching for entry using userFilter>
2020-05-15 16:21:40,137 DEBUG [org.ldaptive.SearchOperation] - <execute request=[org.ldaptive.SearchRequest@-458869840::baseDn=dc=promap,dc=org, searchFilter=[org.ldaptive.SearchFilter@-1637167474::filter=uid={user}, parameters={context=null, dn=uid=testadmin,ou=users,dc=promap,dc=org, user=testadmin}], returnAttributes=[], searchScope=SUBTREE, timeLimit=PT0S, sizeLimit=0, derefAliases=null, typesOnly=false, binaryAttributes=[objectGUID, objectSid], sortBehavior=UNORDERED, searchEntryHandlers=null, searchReferenceHandlers=[org.ldaptive.referral.SearchReferralHandler$SearchReferenceHandler@38c1744d], controls=null, referralHandler=org.ldaptive.referral.SearchReferralHandler@1a5750e8, intermediateResponseHandlers=null] with connection=[org.ldaptive.DefaultConnectionFactory$DefaultConnection@1829212099::config=[org.ldaptive.ConnectionConfig@69054928::ldapUrl=ldaps://localhost:10636, connectTimeout=PT5S, responseTimeout=PT5S, sslConfig=[org.ldaptive.ssl.SslConfig@360985529::credentialConfig=null, trustManagers=null, hostnameVerifier=org.ldaptive.ssl.DefaultHostnameVerifier@6b5df664, hostnameVerifierConfig=null, enabledCipherSuites=null, enabledProtocols=null, handshakeCompletedListeners=null], useSSL=true, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@605483590::bindDn=uid=admin,ou=system, bindSaslConfig=null, bindControls=null], connectionStrategy=org.ldaptive.DefaultConnectionStrategy@4d6c4425], providerConnectionFactory=[org.ldaptive.provider.jndi.JndiConnectionFactory@120885305::metadata=[ldapUrl=ldaps://localhost:10636, count=1], environment={java.naming.ldap.factory.socket=org.ldaptive.ssl.ThreadLocalTLSSocketFactory, com.sun.jndi.ldap.connect.timeout=5000, java.naming.ldap.version=3, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory, java.naming.security.protocol=ssl, com.sun.jndi.ldap.read.timeout=5000}, classLoader=null, providerConfig=[org.ldaptive.provider.jndi.JndiProviderConfig@1257083098::operationExceptionResultCodes=[PROTOCOL_ERROR, SERVER_DOWN], properties={}, controlProcessor=org.ldaptive.provider.ControlProcessor@54fc5824, environment=null, tracePackets=null, removeDnUrls=true, searchIgnoreResultCodes=[TIME_LIMIT_EXCEEDED, SIZE_LIMIT_EXCEEDED, PARTIAL_RESULTS], classLoader=null, sslSocketFactory=null, hostnameVerifier=null]], providerConnection=org.ldaptive.provider.jndi.JndiConnection@4659da82]>
2020-05-15 16:21:40,139 DEBUG [org.ldaptive.SearchOperation] - <execute response=[org.ldaptive.Response@439341517::result=[org.ldaptive.SearchResult@196203800::entries=[[dn=uid=testadmin,ou=users,dc=promap,dc=org[[uid[testadmin]], [description[Admin user]], [sn[ADMIN]], [cn[testadmin]], [knowledgeInformation[Internal CRM notes on test admin]], [objectClass[geosrpskaUser, top, inetOrgPerson, person, organizationalPerson]], [userPassword[e1NTSEF9YjUwKzBUVHNTeGxYd2FycTFocHVWN3JXTzFJMWxUSGdrVk92Wnc9PQ==]]], responseControls=null, messageId=-1]], references=[]], resultCode=SUCCESS, message=null, matchedDn=null, responseControls=null, referralURLs=null, messageId=-1] for request=[org.ldaptive.SearchRequest@-458869840::baseDn=dc=promap,dc=org, searchFilter=[org.ldaptive.SearchFilter@-1637167474::filter=uid={user}, parameters={context=null, dn=uid=testadmin,ou=users,dc=promap,dc=org, user=testadmin}], returnAttributes=[], searchScope=SUBTREE, timeLimit=PT0S, sizeLimit=0, derefAliases=null, typesOnly=false, binaryAttributes=[objectGUID, objectSid], sortBehavior=UNORDERED, searchEntryHandlers=null, searchReferenceHandlers=[org.ldaptive.referral.SearchReferralHandler$SearchReferenceHandler@38c1744d], controls=null, referralHandler=org.ldaptive.referral.SearchReferralHandler@1a5750e8, intermediateResponseHandlers=null] with connection=[org.ldaptive.DefaultConnectionFactory$DefaultConnection@1829212099::config=[org.ldaptive.ConnectionConfig@69054928::ldapUrl=ldaps://localhost:10636, connectTimeout=PT5S, responseTimeout=PT5S, sslConfig=[org.ldaptive.ssl.SslConfig@360985529::credentialConfig=null, trustManagers=null, hostnameVerifier=org.ldaptive.ssl.DefaultHostnameVerifier@6b5df664, hostnameVerifierConfig=null, enabledCipherSuites=null, enabledProtocols=null, handshakeCompletedListeners=null], useSSL=true, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@605483590::bindDn=uid=admin,ou=system, bindSaslConfig=null, bindControls=null], connectionStrategy=org.ldaptive.DefaultConnectionStrategy@4d6c4425], providerConnectionFactory=[org.ldaptive.provider.jndi.JndiConnectionFactory@120885305::metadata=[ldapUrl=ldaps://localhost:10636, count=1], environment={java.naming.ldap.factory.socket=org.ldaptive.ssl.ThreadLocalTLSSocketFactory, com.sun.jndi.ldap.connect.timeout=5000, java.naming.ldap.version=3, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory, java.naming.security.protocol=ssl, com.sun.jndi.ldap.read.timeout=5000}, classLoader=null, providerConfig=[org.ldaptive.provider.jndi.JndiProviderConfig@1257083098::operationExceptionResultCodes=[PROTOCOL_ERROR, SERVER_DOWN], properties={}, controlProcessor=org.ldaptive.provider.ControlProcessor@54fc5824, environment=null, tracePackets=null, removeDnUrls=true, searchIgnoreResultCodes=[TIME_LIMIT_EXCEEDED, SIZE_LIMIT_EXCEEDED, PARTIAL_RESULTS], classLoader=null, sslSocketFactory=null, hostnameVerifier=null]], providerConnection=org.ldaptive.provider.jndi.JndiConnection@4659da82]>
2020-05-15 16:21:40,139 DEBUG [org.ldaptive.BindOperation] - <execute request=[org.ldaptive.BindRequest@1674289898::bindDn=uid=admin,ou=system, saslConfig=null, controls=null, referralHandler=null, intermediateResponseHandlers=null] with connection=[org.ldaptive.DefaultConnectionFactory$DefaultConnection@1829212099::config=[org.ldaptive.ConnectionConfig@69054928::ldapUrl=ldaps://localhost:10636, connectTimeout=PT5S, responseTimeout=PT5S, sslConfig=[org.ldaptive.ssl.SslConfig@360985529::credentialConfig=null, trustManagers=null, hostnameVerifier=org.ldaptive.ssl.DefaultHostnameVerifier@6b5df664, hostnameVerifierConfig=null, enabledCipherSuites=null, enabledProtocols=null, handshakeCompletedListeners=null], useSSL=true, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@605483590::bindDn=uid=admin,ou=system, bindSaslConfig=null, bindControls=null], connectionStrategy=org.ldaptive.DefaultConnectionStrategy@4d6c4425], providerConnectionFactory=[org.ldaptive.provider.jndi.JndiConnectionFactory@120885305::metadata=[ldapUrl=ldaps://localhost:10636, count=1], environment={java.naming.ldap.factory.socket=org.ldaptive.ssl.ThreadLocalTLSSocketFactory, com.sun.jndi.ldap.connect.timeout=5000, java.naming.ldap.version=3, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory, java.naming.security.protocol=ssl, com.sun.jndi.ldap.read.timeout=5000}, classLoader=null, providerConfig=[org.ldaptive.provider.jndi.JndiProviderConfig@1257083098::operationExceptionResultCodes=[PROTOCOL_ERROR, SERVER_DOWN], properties={}, controlProcessor=org.ldaptive.provider.ControlProcessor@54fc5824, environment=null, tracePackets=null, removeDnUrls=true, searchIgnoreResultCodes=[TIME_LIMIT_EXCEEDED, SIZE_LIMIT_EXCEEDED, PARTIAL_RESULTS], classLoader=null, sslSocketFactory=null, hostnameVerifier=null]], providerConnection=org.ldaptive.provider.jndi.JndiConnection@4659da82]>
2020-05-15 16:21:40,141 DEBUG [org.ldaptive.BindOperation] - <execute response=[org.ldaptive.Response@2123155178::result=null, resultCode=SUCCESS, message=null, matchedDn=null, responseControls=null, referralURLs=null, messageId=-1] for request=[org.ldaptive.BindRequest@1674289898::bindDn=uid=admin,ou=system, saslConfig=null, controls=null, referralHandler=null, intermediateResponseHandlers=null] with connection=[org.ldaptive.DefaultConnectionFactory$DefaultConnection@1829212099::config=[org.ldaptive.ConnectionConfig@69054928::ldapUrl=ldaps://localhost:10636, connectTimeout=PT5S, responseTimeout=PT5S, sslConfig=[org.ldaptive.ssl.SslConfig@360985529::credentialConfig=null, trustManagers=null, hostnameVerifier=org.ldaptive.ssl.DefaultHostnameVerifier@6b5df664, hostnameVerifierConfig=null, enabledCipherSuites=null, enabledProtocols=null, handshakeCompletedListeners=null], useSSL=true, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@605483590::bindDn=uid=admin,ou=system, bindSaslConfig=null, bindControls=null], connectionStrategy=org.ldaptive.DefaultConnectionStrategy@4d6c4425], providerConnectionFactory=[org.ldaptive.provider.jndi.JndiConnectionFactory@120885305::metadata=[ldapUrl=ldaps://localhost:10636, count=1], environment={java.naming.ldap.factory.socket=org.ldaptive.ssl.ThreadLocalTLSSocketFactory, com.sun.jndi.ldap.connect.timeout=5000, java.naming.ldap.version=3, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory, java.naming.security.protocol=ssl, com.sun.jndi.ldap.read.timeout=5000}, classLoader=null, providerConfig=[org.ldaptive.provider.jndi.JndiProviderConfig@1257083098::operationExceptionResultCodes=[PROTOCOL_ERROR, SERVER_DOWN], properties={}, controlProcessor=org.ldaptive.provider.ControlProcessor@54fc5824, environment=null, tracePackets=null, removeDnUrls=true, searchIgnoreResultCodes=[TIME_LIMIT_EXCEEDED, SIZE_LIMIT_EXCEEDED, PARTIAL_RESULTS], classLoader=null, sslSocketFactory=null, hostnameVerifier=null]], providerConnection=org.ldaptive.provider.jndi.JndiConnection@4659da82]>
2020-05-15 16:21:40,141 DEBUG [org.apereo.cas.util.BinaryAttributeAwarePooledSearchEntryResolver] - <resolved result=[org.ldaptive.SearchResult@196203800::entries=[[dn=uid=testadmin,ou=users,dc=promap,dc=org[[uid[testadmin]], [description[Admin user]], [sn[ADMIN]], [cn[testadmin]], [knowledgeInformation[Internal CRM notes on test admin]], [objectClass[geosrpskaUser, top, inetOrgPerson, person, organizationalPerson]], [userPassword[e1NTSEF9YjUwKzBUVHNTeGxYd2FycTFocHVWN3JXTzFJMWxUSGdrVk92Wnc9PQ==]]], responseControls=null, messageId=-1]], references=[]] for criteria=[org.ldaptive.auth.AuthenticationCriteria@11704327::dn=uid=testadmin,ou=users,dc=promap,dc=org, authenticationRequest=[org.ldaptive.auth.AuthenticationRequest@802436829::user=[org.ldaptive.auth.User@1918926652::identifier=testadmin, context=null], returnAttributes=[], controls=null]]>
2020-05-15 16:21:40,142 DEBUG [org.ldaptive.BindOperation] - <execute request=[org.ldaptive.BindRequest@1561031011::bindDn=uid=admin,ou=system, saslConfig=null, controls=null, referralHandler=null, intermediateResponseHandlers=null] with connection=[org.ldaptive.DefaultConnectionFactory$DefaultConnection@778956176::config=[org.ldaptive.ConnectionConfig@1311766432::ldapUrl=ldaps://localhost:10636, connectTimeout=PT5S, responseTimeout=PT5S, sslConfig=[org.ldaptive.ssl.SslConfig@659921050::credentialConfig=null, trustManagers=null, hostnameVerifier=org.ldaptive.ssl.DefaultHostnameVerifier@31ba76e1, hostnameVerifierConfig=null, enabledCipherSuites=null, enabledProtocols=null, handshakeCompletedListeners=null], useSSL=true, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@1697957628::bindDn=uid=admin,ou=system, bindSaslConfig=null, bindControls=null], connectionStrategy=org.ldaptive.DefaultConnectionStrategy@5417af0d], providerConnectionFactory=[org.ldaptive.provider.jndi.JndiConnectionFactory@2015145363::metadata=[ldapUrl=ldaps://localhost:10636, count=1], environment={java.naming.ldap.factory.socket=org.ldaptive.ssl.ThreadLocalTLSSocketFactory, com.sun.jndi.ldap.connect.timeout=5000, java.naming.ldap.version=3, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory, java.naming.security.protocol=ssl, com.sun.jndi.ldap.read.timeout=5000}, classLoader=null, providerConfig=[org.ldaptive.provider.jndi.JndiProviderConfig@1941628011::operationExceptionResultCodes=[PROTOCOL_ERROR, SERVER_DOWN], properties={}, controlProcessor=org.ldaptive.provider.ControlProcessor@6bc9bc66, environment=null, tracePackets=null, removeDnUrls=true, searchIgnoreResultCodes=[TIME_LIMIT_EXCEEDED, SIZE_LIMIT_EXCEEDED, PARTIAL_RESULTS], classLoader=null, sslSocketFactory=null, hostnameVerifier=null]], providerConnection=org.ldaptive.provider.jndi.JndiConnection@33d1c017]>
2020-05-15 16:21:40,144 DEBUG [org.ldaptive.BindOperation] - <execute response=[org.ldaptive.Response@1306310250::result=null, resultCode=SUCCESS, message=null, matchedDn=null, responseControls=null, referralURLs=null, messageId=-1] for request=[org.ldaptive.BindRequest@1561031011::bindDn=uid=admin,ou=system, saslConfig=null, controls=null, referralHandler=null, intermediateResponseHandlers=null] with connection=[org.ldaptive.DefaultConnectionFactory$DefaultConnection@778956176::config=[org.ldaptive.ConnectionConfig@1311766432::ldapUrl=ldaps://localhost:10636, connectTimeout=PT5S, responseTimeout=PT5S, sslConfig=[org.ldaptive.ssl.SslConfig@659921050::credentialConfig=null, trustManagers=null, hostnameVerifier=org.ldaptive.ssl.DefaultHostnameVerifier@31ba76e1, hostnameVerifierConfig=null, enabledCipherSuites=null, enabledProtocols=null, handshakeCompletedListeners=null], useSSL=true, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@1697957628::bindDn=uid=admin,ou=system, bindSaslConfig=null, bindControls=null], connectionStrategy=org.ldaptive.DefaultConnectionStrategy@5417af0d], providerConnectionFactory=[org.ldaptive.provider.jndi.JndiConnectionFactory@2015145363::metadata=[ldapUrl=ldaps://localhost:10636, count=1], environment={java.naming.ldap.factory.socket=org.ldaptive.ssl.ThreadLocalTLSSocketFactory, com.sun.jndi.ldap.connect.timeout=5000, java.naming.ldap.version=3, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory, java.naming.security.protocol=ssl, com.sun.jndi.ldap.read.timeout=5000}, classLoader=null, providerConfig=[org.ldaptive.provider.jndi.JndiProviderConfig@1941628011::operationExceptionResultCodes=[PROTOCOL_ERROR, SERVER_DOWN], properties={}, controlProcessor=org.ldaptive.provider.ControlProcessor@6bc9bc66, environment=null, tracePackets=null, removeDnUrls=true, searchIgnoreResultCodes=[TIME_LIMIT_EXCEEDED, SIZE_LIMIT_EXCEEDED, PARTIAL_RESULTS], classLoader=null, sslSocketFactory=null, hostnameVerifier=null]], providerConnection=org.ldaptive.provider.jndi.JndiConnection@33d1c017]>
2020-05-15 16:21:40,145 INFO [org.ldaptive.auth.Authenticator] - <Authentication succeeded for dn: uid=testadmin,ou=users,dc=promap,dc=org>
2020-05-15 16:21:40,145 DEBUG [org.ldaptive.auth.Authenticator] - <authenticate response=[org.ldaptive.auth.AuthenticationHandlerResponse@738040634::connection=[org.ldaptive.DefaultConnectionFactory$DefaultConnection@778956176::config=[org.ldaptive.ConnectionConfig@1311766432::ldapUrl=ldaps://localhost:10636, connectTimeout=PT5S, responseTimeout=PT5S, sslConfig=[org.ldaptive.ssl.SslConfig@659921050::credentialConfig=null, trustManagers=null, hostnameVerifier=org.ldaptive.ssl.DefaultHostnameVerifier@31ba76e1, hostnameVerifierConfig=null, enabledCipherSuites=null, enabledProtocols=null, handshakeCompletedListeners=null], useSSL=true, useStartTLS=false, connectionInitializer=[org.ldaptive.BindConnectionInitializer@1697957628::bindDn=uid=admin,ou=system, bindSaslConfig=null, bindControls=null], connectionStrategy=org.ldaptive.DefaultConnectionStrategy@5417af0d], providerConnectionFactory=[org.ldaptive.provider.jndi.JndiConnectionFactory@2015145363::metadata=[ldapUrl=ldaps://localhost:10636, count=1], environment={java.naming.ldap.factory.socket=org.ldaptive.ssl.ThreadLocalTLSSocketFactory, com.sun.jndi.ldap.connect.timeout=5000, java.naming.ldap.version=3, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory, java.naming.security.protocol=ssl, com.sun.jndi.ldap.read.timeout=5000}, classLoader=null, providerConfig=[org.ldaptive.provider.jndi.JndiProviderConfig@1941628011::operationExceptionResultCodes=[PROTOCOL_ERROR, SERVER_DOWN], properties={}, controlProcessor=org.ldaptive.provider.ControlProcessor@6bc9bc66, environment=null, tracePackets=null, removeDnUrls=true, searchIgnoreResultCodes=[TIME_LIMIT_EXCEEDED, SIZE_LIMIT_EXCEEDED, PARTIAL_RESULTS], classLoader=null, sslSocketFactory=null, hostnameVerifier=null]], providerConnection=org.ldaptive.provider.jndi.JndiConnection@33d1c017], result=true, resultCode=SUCCESS, message=null, controls=[[org.ldaptive.control.PasswordPolicyControl@-350070253::criticality=false, timeBeforeExpiration=-1, graceAuthNsRemaining=-1, error=null]]] for dn=uid=testadmin,ou=users,dc=promap,dc=org with request=[org.ldaptive.auth.AuthenticationRequest@802436829::user=[org.ldaptive.auth.User@1918926652::identifier=testadmin, context=null], returnAttributes=[], controls=null]>
2020-05-15 16:21:40,145 DEBUG [org.apereo.cas.authentication.LdapAuthenticationHandler] - <LDAP response: [[org.ldaptive.auth.AuthenticationResponse@1971377753::authenticationResultCode=AUTHENTICATION_HANDLER_SUCCESS, resolvedDn=uid=testadmin,ou=users,dc=promap,dc=org, ldapEntry=[dn=uid=testadmin,ou=users,dc=promap,dc=org[[uid[testadmin]], [description[Admin user]], [sn[ADMIN]], [cn[testadmin]], [knowledgeInformation[Internal CRM notes on test admin]], [objectClass[geosrpskaUser, top, inetOrgPerson, person, organizationalPerson]], [userPassword[e1NTSEF9YjUwKzBUVHNTeGxYd2FycTFocHVWN3JXTzFJMWxUSGdrVk92Wnc9PQ==]]], responseControls=null, messageId=-1], accountState=null, result=true, resultCode=SUCCESS, message=null, controls=[[org.ldaptive.control.PasswordPolicyControl@-350070253::criticality=false, timeBeforeExpiration=-1, graceAuthNsRemaining=-1, error=null]]]]>
2020-05-15 16:21:40,145 DEBUG [org.apereo.cas.authentication.LdapAuthenticationHandler] - <Attempting to examine and handle LDAP password policy via [DefaultPasswordPolicyHandlingStrategy]>
2020-05-15 16:21:40,146 DEBUG [org.apereo.cas.authentication.support.password.DefaultPasswordPolicyHandlingStrategy] - <Applying password policy [[org.ldaptive.auth.AuthenticationResponse@1971377753::authenticationResultCode=AUTHENTICATION_HANDLER_SUCCESS, resolvedDn=uid=testadmin,ou=users,dc=promap,dc=org, ldapEntry=[dn=uid=testadmin,ou=users,dc=promap,dc=org[[uid[testadmin]], [description[Admin user]], [sn[ADMIN]], [cn[testadmin]], [knowledgeInformation[Internal CRM notes on test admin]], [objectClass[geosrpskaUser, top, inetOrgPerson, person, organizationalPerson]], [userPassword[e1NTSEF9YjUwKzBUVHNTeGxYd2FycTFocHVWN3JXTzFJMWxUSGdrVk92Wnc9PQ==]]], responseControls=null, messageId=-1], accountState=null, result=true, resultCode=SUCCESS, message=null, controls=[[org.ldaptive.control.PasswordPolicyControl@-350070253::criticality=false, timeBeforeExpiration=-1, graceAuthNsRemaining=-1, error=null]]]] to [org.apereo.cas.authentication.support.DefaultLdapAccountStateHandler@a49873c]>
2020-05-15 16:21:40,146 DEBUG [org.apereo.cas.authentication.support.DefaultLdapAccountStateHandler] - <Attempting to handle LDAP account state for [[org.ldaptive.auth.AuthenticationResponse@1971377753::authenticationResultCode=AUTHENTICATION_HANDLER_SUCCESS, resolvedDn=uid=testadmin,ou=users,dc=promap,dc=org, ldapEntry=[dn=uid=testadmin,ou=users,dc=promap,dc=org[[uid[testadmin]], [description[Admin user]], [sn[ADMIN]], [cn[testadmin]], [knowledgeInformation[Internal CRM notes on test admin]], [objectClass[geosrpskaUser, top, inetOrgPerson, person, organizationalPerson]], [userPassword[e1NTSEF9YjUwKzBUVHNTeGxYd2FycTFocHVWN3JXTzFJMWxUSGdrVk92Wnc9PQ==]]], responseControls=null, messageId=-1], accountState=null, result=true, resultCode=SUCCESS, message=null, controls=[[org.ldaptive.control.PasswordPolicyControl@-350070253::criticality=false, timeBeforeExpiration=-1, graceAuthNsRemaining=-1, error=null]]]]>
2020-05-15 16:21:40,146 DEBUG [org.apereo.cas.authentication.support.DefaultLdapAccountStateHandler] - <Account state not defined. Returning empty list of messages.>
2020-05-15 16:21:40,146 DEBUG [org.apereo.cas.authentication.LdapAuthenticationHandler] - <LDAP response returned a result. Creating the final LDAP principal>
2020-05-15 16:21:40,146 DEBUG [org.apereo.cas.authentication.LdapAuthenticationHandler] - <Creating LDAP principal for [testadmin] based on [uid=testadmin,ou=users,dc=promap,dc=org] and attributes [[uid, description, sn, cn, knowledgeInformation, objectClass, userPassword]]>
2020-05-15 16:21:40,146 DEBUG [org.apereo.cas.authentication.LdapAuthenticationHandler] - <Principal id attribute is not defined. Using the default provided user id [testadmin]>
2020-05-15 16:21:40,146 DEBUG [org.apereo.cas.authentication.LdapAuthenticationHandler] - <LDAP principal identifier created is [testadmin]>
2020-05-15 16:21:40,146 DEBUG [org.apereo.cas.authentication.LdapAuthenticationHandler] - <The following attributes are requested to be retrieved and mapped: [[]]>
2020-05-15 16:21:40,146 DEBUG [org.apereo.cas.authentication.LdapAuthenticationHandler] - <Created LDAP principal for id [testadmin] and [0] attributes>
2020-05-15 16:21:40,146 DEBUG [org.apereo.cas.authentication.DefaultAuthenticationBuilder] - <Recording authentication handler result success under key [localhost]>
2020-05-15 16:21:40,146 DEBUG [org.apereo.cas.authentication.PolicyBasedAuthenticationManager] - <Authentication handler [localhost] successfully authenticated [UsernamePasswordCredential(username=testadmin)]>
2020-05-15 16:21:40,146 DEBUG [org.apereo.cas.authentication.principal.resolvers.ChainingPrincipalResolver] - <Invoking principal resolver [EchoingPrincipalResolver()]>
2020-05-15 16:21:40,146 DEBUG [org.apereo.cas.authentication.principal.resolvers.EchoingPrincipalResolver] - <Echoing back the authenticated principal [Optional[SimplePrincipal(id=testadmin, attributes={})]]>
2020-05-15 16:21:40,146 DEBUG [org.apereo.cas.authentication.principal.resolvers.ChainingPrincipalResolver] - <Resolved principal [SimplePrincipal(id=testadmin, attributes={})]>
2020-05-15 16:21:40,146 DEBUG [org.apereo.cas.authentication.principal.resolvers.ChainingPrincipalResolver] - <Resolved principal [SimplePrincipal(id=testadmin, attributes={})]>
2020-05-15 16:21:40,146 DEBUG [org.apereo.cas.authentication.principal.resolvers.ChainingPrincipalResolver] - <Final principal constructed by the chain of resolvers is [SimplePrincipal(id=testadmin, attributes={})]>
2020-05-15 16:21:40,146 DEBUG [org.apereo.cas.authentication.PolicyBasedAuthenticationManager] - <[ChainingPrincipalResolver(principalFactory=org.apereo.cas.authentication.principal.DefaultPrincipalFactory@1, chain=[EchoingPrincipalResolver()])] resolved [SimplePrincipal(id=testadmin, attributes={})] from [UsernamePasswordCredential(username=testadmin)]>
2020-05-15 16:21:40,147 DEBUG [org.apereo.cas.authentication.PolicyBasedAuthenticationManager] - <Final principal resolved for this authentication event is [SimplePrincipal(id=testadmin, attributes={})]>
2020-05-15 16:21:40,147 DEBUG [org.apereo.cas.authentication.DefaultAuthenticationEventExecutionPlan] - <Sorted and registered authentication policies for this transaction are [[org.apereo.cas.authentication.policy.AnyAuthenticationPolicy@3e4ffa27]]>
2020-05-15 16:21:40,147 DEBUG [org.apereo.cas.authentication.PolicyBasedAuthenticationManager] - <Executing authentication policy [AnyAuthenticationPolicy]>
2020-05-15 16:21:40,147 DEBUG [org.apereo.cas.authentication.policy.AnyAuthenticationPolicy] - <Authentication policy is satisfied having found at least one authentication transactions>
2020-05-15 16:21:40,147 DEBUG [org.apereo.cas.authentication.DefaultAuthenticationEventExecutionPlan] - <Sorted and registered authentication policies for this transaction are [[org.apereo.cas.authentication.policy.AnyAuthenticationPolicy@3e4ffa27]]>
2020-05-15 16:21:40,147 DEBUG [org.apereo.cas.authentication.PolicyBasedAuthenticationManager] - <Executing authentication policy [AnyAuthenticationPolicy]>
2020-05-15 16:21:40,147 DEBUG [org.apereo.cas.authentication.policy.AnyAuthenticationPolicy] - <Authentication policy is satisfied having found at least one authentication transactions>
2020-05-15 16:21:40,147 DEBUG [org.apereo.cas.authentication.PolicyBasedAuthenticationManager] - <Invoking authentication metadata populators for authentication transaction>
2020-05-15 16:21:40,147 DEBUG [org.apereo.cas.authentication.DefaultAuthenticationEventExecutionPlan] - <Sorted and registered metadata populators for this transaction are [[SuccessfulHandlerMetaDataPopulator(super=BaseAuthenticationMetaDataPopulator(order=-2147483648)), RememberMeAuthenticationMetaDataPopulator(super=BaseAuthenticationMetaDataPopulator(order=-2147483648)), BaseAuthenticationMetaDataPopulator(order=-2147483648)]]>
2020-05-15 16:21:40,147 DEBUG [org.apereo.cas.authentication.PolicyBasedAuthenticationManager] - <Invoking authentication post processors for authentication transaction>
2020-05-15 16:21:40,147 DEBUG [org.apereo.cas.authentication.DefaultAuthenticationEventExecutionPlan] - <Sorted and registered authentication post processors for this transaction are [[]]>
2020-05-15 16:21:40,147 INFO [org.apereo.cas.authentication.PolicyBasedAuthenticationManager] - <Authenticated principal [testadmin] with attributes [{}] via credentials [[UsernamePasswordCredential(username=testadmin)]].>
2020-05-15 16:21:40,147 INFO [org.apereo.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - <Audit trail record BEGIN
=============================================================
WHO: testadmin
WHAT: Supplied credentials: [UsernamePasswordCredential(username=testadmin)]
ACTION: AUTHENTICATION_SUCCESS
APPLICATION: CAS
WHEN: Fri May 15 16:21:40 CEST 2020
CLIENT IP ADDRESS: 0:0:0:0:0:0:0:1
SERVER IP ADDRESS: 0:0:0:0:0:0:0:1
=============================================================
>
2020-05-15 16:21:40,147 DEBUG [org.apereo.cas.authentication.DefaultAuthenticationTransactionManager] - <Successful authentication; Collecting authentication result [org.apereo.cas.authentication.DefaultAuthentication@7e26e877]>
2020-05-15 16:21:40,148 DEBUG [org.apereo.cas.services.DefaultRegisteredServiceAccessStrategy] - <Skipping access strategy policy, since no attributes rules are defined>
2020-05-15 16:21:40,148 INFO [org.apereo.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - <Audit trail record BEGIN
=============================================================
WHO: testadmin
WHAT: [result=Service Access Granted,service=https://localhost:8443/geonetwork/sig...,principal=SimplePrincipal(id=testadmin, attributes={}),requiredAttributes={}]
ACTION: SERVICE_ACCESS_ENFORCEMENT_TRIGGERED
APPLICATION: CAS
WHEN: Fri May 15 16:21:40 CEST 2020
CLIENT IP ADDRESS: 0:0:0:0:0:0:0:1
SERVER IP ADDRESS: 0:0:0:0:0:0:0:1
=============================================================
>
2020-05-15 16:21:40,152 DEBUG [org.apereo.cas.authentication.DefaultAuthenticationResultBuilder] - <Collecting authentication history based on [1] authentication events>
2020-05-15 16:21:40,152 DEBUG [org.apereo.cas.authentication.DefaultAuthenticationResultBuilder] - <Evaluating authentication principal [SimplePrincipal(id=testadmin, attributes={})] for inclusion in result>
2020-05-15 16:21:40,152 DEBUG [org.apereo.cas.authentication.DefaultAuthenticationResultBuilder] - <Merging current attributes [{}] with [{}]>
2020-05-15 16:21:40,152 DEBUG [org.apereo.cas.authentication.DefaultAuthenticationResultBuilder] - <Merged attributes with the final result as [{}]>
2020-05-15 16:21:40,152 DEBUG [org.apereo.cas.authentication.DefaultAuthenticationResultBuilder] - <Collected principal attributes [{}] for inclusion in this result for principal [testadmin]>
2020-05-15 16:21:40,152 DEBUG [org.apereo.cas.authentication.DefaultAuthenticationResultBuilder] - <Merging current attributes [{}] with [{authenticationMethod=localhost, successfulAuthenticationHandlers=[localhost], credentialType=UsernamePasswordCredential}]>
2020-05-15 16:21:40,152 DEBUG [org.apereo.cas.authentication.DefaultAuthenticationResultBuilder] - <Merged attributes with the final result as [{credentialType=[UsernamePasswordCredential], authenticationMethod=[localhost], successfulAuthenticationHandlers=[localhost]}]>
2020-05-15 16:21:40,152 DEBUG [org.apereo.cas.authentication.DefaultAuthenticationResultBuilder] - <Finalized authentication attributes [{credentialType=[UsernamePasswordCredential], authenticationMethod=[localhost], successfulAuthenticationHandlers=[localhost]}] for inclusion in this authentication result>
2020-05-15 16:21:40,152 DEBUG [org.apereo.cas.authentication.DefaultAuthenticationBuilder] - <Recording authentication handler result success under key [localhost]>
2020-05-15 16:21:40,152 DEBUG [org.apereo.cas.authentication.DefaultPrincipalElectionStrategy] - <Nominated [SimplePrincipal(id=testadmin, attributes={})] as the primary principal>
2020-05-15 16:21:40,152 DEBUG [org.apereo.cas.authentication.DefaultAuthenticationResultBuilder] - <Determined primary authentication principal to be [SimplePrincipal(id=testadmin, attributes={})]>
2020-05-15 16:21:40,152 DEBUG [org.apereo.cas.authentication.DefaultAuthenticationResultBuilder] - <Collected authentication attributes for this result are [{credentialType=[UsernamePasswordCredential], authenticationMethod=[localhost], successfulAuthenticationHandlers=[localhost]}]>
2020-05-15 16:21:40,152 DEBUG [org.apereo.cas.authentication.DefaultAuthenticationResultBuilder] - <Authentication result commenced at [2020-05-15T16:21:40.152+02:00[Europe/Prague]]>
2020-05-15 16:21:40,152 DEBUG [org.apereo.cas.authentication.DefaultAuthenticationResultBuilder] - <Building an authentication result for authentication [org.apereo.cas.authentication.DefaultAuthentication@7ec14a0d] and service [AbstractWebApplicationService(id=https://localhost:8443/geonetwork/signin-cas, originalUrl=https://localhost:8443/geonetwork/signin-cas, artifactId=null, principal=null, source=service, loggedOutAlready=false, format=XML, attributes={})]>
2020-05-15 16:21:40,153 DEBUG [org.apereo.cas.authentication.PseudoPlatformTransactionManager] - <Creating new transaction with name [org.apereo.cas.DefaultCentralAuthenticationService.createTicketGrantingTicket]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT; 'ticketTransactionManager'>
2020-05-15 16:21:40,153 DEBUG [org.apereo.cas.DefaultCentralAuthenticationService] - <Resolved service [AbstractWebApplicationService(id=https://localhost:8443/geonetwork/signin-cas, originalUrl=https://localhost:8443/geonetwork/signin-cas, artifactId=null, principal=null, source=service, loggedOutAlready=false, format=XML, attributes={})] from the authentication request>
2020-05-15 16:21:40,153 DEBUG [org.apereo.cas.services.DefaultRegisteredServiceAccessStrategy] - <Skipping access strategy policy, since no attributes rules are defined>
2020-05-15 16:21:40,153 INFO [org.apereo.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - <Audit trail record BEGIN
=============================================================
WHO: testadmin
WHAT: [result=Service Access Granted,service=https://localhost:8443/geonetwork/sig...,principal=SimplePrincipal(id=testadmin, attributes={}),requiredAttributes={}]
ACTION: SERVICE_ACCESS_ENFORCEMENT_TRIGGERED
APPLICATION: CAS
WHEN: Fri May 15 16:21:40 CEST 2020
CLIENT IP ADDRESS: 0:0:0:0:0:0:0:1
SERVER IP ADDRESS: 0:0:0:0:0:0:0:1
=============================================================
>
2020-05-15 16:21:40,153 DEBUG [org.apereo.cas.ticket.factory.DefaultTicketGrantingTicketFactory] - <Attempting to encode ticket-granting ticket [TGT-5-********************************************************u4mti7MGrhQGIS-kokeza]>
2020-05-15 16:21:40,153 DEBUG [org.apereo.cas.ticket.factory.DefaultTicketGrantingTicketFactory] - <Encoded ticket-granting ticket id [TGT-5-********************************************************u4mti7MGrhQGIS-kokeza]>
2020-05-15 16:21:40,153 DEBUG [org.apereo.cas.ticket.registry.AbstractMapBasedTicketRegistry] - <Added ticket [TGT-5-********************************************************u4mti7MGrhQGIS-kokeza] to registry.>
2020-05-15 16:21:40,153 DEBUG [org.apereo.cas.AbstractCentralAuthenticationService] - <Publishing [CasTicketGrantingTicketCreatedEvent(ticketGrantingTicket=TGT-5-********************************************************u4mti7MGrhQGIS-kokeza)]>
2020-05-15 16:21:40,153 INFO [org.apereo.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - <Audit trail record BEGIN
=============================================================
WHO: testadmin
WHAT: TGT-5-********************************************************u4mti7MGrhQGIS-kokeza
ACTION: TICKET_GRANTING_TICKET_CREATED
APPLICATION: CAS
WHEN: Fri May 15 16:21:40 CEST 2020
CLIENT IP ADDRESS: 0:0:0:0:0:0:0:1
SERVER IP ADDRESS: 0:0:0:0:0:0:0:1
=============================================================
>
2020-05-15 16:21:40,153 DEBUG [org.apereo.cas.authentication.PseudoPlatformTransactionManager] - <Initiating transaction commit>
2020-05-15 16:21:40,154 DEBUG [org.apereo.cas.web.support.EncryptedCookieValueManager] - <Encoding cookie value [TGT-5-********************************************************u4mti7MGrhQGIS-kokeza@0:0:0:0:0:0:0:1@Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/81.0.4044.138 Safari/537.36]>
2020-05-15 16:21:40,154 DEBUG [org.apereo.cas.util.EncodingUtils] - <Encrypting via [A128CBC-HS256]>
2020-05-15 16:21:40,155 DEBUG [org.apereo.cas.web.support.CookieRetrievingCookieGenerator] - <Locating request parameter [rememberMe] with value [null]>
2020-05-15 16:21:40,155 DEBUG [org.apereo.cas.web.support.CookieRetrievingCookieGenerator] - <Request does not indicate a remember-me authentication event. Locating authentication object from the request context...>
2020-05-15 16:21:40,155 DEBUG [org.apereo.cas.web.support.CookieRetrievingCookieGenerator] - <Located authentication attributes [{credentialType=[UsernamePasswordCredential], authenticationMethod=[localhost], successfulAuthenticationHandlers=[localhost]}]>
2020-05-15 16:21:40,155 DEBUG [org.apereo.cas.web.support.CookieRetrievingCookieGenerator] - <Is this request from a remember-me authentication event? [no]>
2020-05-15 16:21:40,155 DEBUG [org.apereo.cas.web.support.CookieRetrievingCookieGenerator] - <Creating cookie [TGC]>
2020-05-15 16:21:40,155 DEBUG [org.apereo.cas.web.support.TGCCookieRetrievingCookieGenerator] - <Added cookie with name [TGC] and value [eyJhbGciOiJIUzUxMiJ9.ZXlKNmFYQWlPaUpFUlVZaUxDSmhiR2NpT2lKa2FYSWlMQ0psYm1NaU9pSkJNVEk0UTBKRExVaFRNalUySW4wLi54U3U1aVZUdVRHTmczb2ZxZWpQZVJ3LkViUWhoMDVBRGRqN0lWS3JnRDE2bW9oVUVhRzJOSlBqOFVsQzRGS1labDd6by1lZDkwZFFpNklfdGxQQ2Z3SWhBdWk2aXB4R2VsMGVsYk12MVpBclRMVzR0OEktVEtyOVdIaTdpTmNXUm9pcmlVOFFuTWx1RWlKaFp0azEyVXlOMG1XQ2NXN0pFcUdickNvT0Izelk4WnJtRVFiUWhvOUZoSXI4M2pzZm1WZU1UaTRrRkxYcmtZZDA2MDBqQ2hZT1RMbmI4dDNESldjZDhTbm11bFdnY1NNVmpHVnhKNmpKdEVFQTBmVVoyV2lTZ20yZEVwX2JJUGRRT0xXUTBveGwuUFRrdlhfWUZMQUNITWFTR1RhVDgwZw==.gx_5jRzDmLCP2Z6vFyi0WorvvYy9QOYqQpiRqQgfNyH-VA8QjOJH1pPJcg0-rafSnZ36x6hJC_HNHrAM4lyzkg]>
2020-05-15 16:21:40,156 DEBUG [org.apereo.cas.authentication.PseudoPlatformTransactionManager] - <Creating new transaction with name [org.apereo.cas.ticket.registry.DefaultTicketRegistrySupport.getAuthenticationFrom]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT; 'ticketTransactionManager'>
2020-05-15 16:21:40,156 DEBUG [org.apereo.cas.authentication.PseudoPlatformTransactionManager] - <Initiating transaction commit>
2020-05-15 16:21:40,156 DEBUG [org.apereo.cas.authentication.DefaultAuthenticationResultBuilder] - <Collecting authentication history based on [1] authentication events>
2020-05-15 16:21:40,156 DEBUG [org.apereo.cas.authentication.DefaultAuthenticationResultBuilder] - <Evaluating authentication principal [SimplePrincipal(id=testadmin, attributes={})] for inclusion in result>
2020-05-15 16:21:40,156 DEBUG [org.apereo.cas.authentication.DefaultAuthenticationResultBuilder] - <Merging current attributes [{}] with [{}]>
2020-05-15 16:21:40,156 DEBUG [org.apereo.cas.authentication.DefaultAuthenticationResultBuilder] - <Merged attributes with the final result as [{}]>
2020-05-15 16:21:40,156 DEBUG [org.apereo.cas.authentication.DefaultAuthenticationResultBuilder] - <Collected principal attributes [{}] for inclusion in this result for principal [testadmin]>
2020-05-15 16:21:40,156 DEBUG [org.apereo.cas.authentication.DefaultAuthenticationResultBuilder] - <Merging current attributes [{}] with [{credentialType=[UsernamePasswordCredential], authenticationMethod=[localhost], successfulAuthenticationHandlers=[localhost]}]>
2020-05-15 16:21:40,156 DEBUG [org.apereo.cas.authentication.DefaultAuthenticationResultBuilder] - <Merged attributes with the final result as [{credentialType=[UsernamePasswordCredential], authenticationMethod=[localhost], successfulAuthenticationHandlers=[localhost]}]>
2020-05-15 16:21:40,156 DEBUG [org.apereo.cas.authentication.DefaultAuthenticationResultBuilder] - <Finalized authentication attributes [{credentialType=[UsernamePasswordCredential], authenticationMethod=[localhost], successfulAuthenticationHandlers=[localhost]}] for inclusion in this authentication result>
2020-05-15 16:21:40,156 DEBUG [org.apereo.cas.authentication.DefaultAuthenticationBuilder] - <Recording authentication handler result success under key [localhost]>
2020-05-15 16:21:40,156 DEBUG [org.apereo.cas.authentication.DefaultPrincipalElectionStrategy] - <Nominated [SimplePrincipal(id=testadmin, attributes={})] as the primary principal>
2020-05-15 16:21:40,156 DEBUG [org.apereo.cas.authentication.DefaultAuthenticationResultBuilder] - <Determined primary authentication principal to be [SimplePrincipal(id=testadmin, attributes={})]>
2020-05-15 16:21:40,156 DEBUG [org.apereo.cas.authentication.DefaultAuthenticationResultBuilder] - <Collected authentication attributes for this result are [{credentialType=[UsernamePasswordCredential], authenticationMethod=[localhost], successfulAuthenticationHandlers=[localhost]}]>
2020-05-15 16:21:40,157 DEBUG [org.apereo.cas.authentication.DefaultAuthenticationResultBuilder] - <Authentication result commenced at [2020-05-15T16:21:40.157+02:00[Europe/Prague]]>
2020-05-15 16:21:40,157 DEBUG [org.apereo.cas.authentication.DefaultAuthenticationResultBuilder] - <Building an authentication result for authentication [org.apereo.cas.authentication.DefaultAuthentication@9bb0cc4d] and service [AbstractWebApplicationService(id=https://localhost:8443/geonetwork/signin-cas, originalUrl=https://localhost:8443/geonetwork/signin-cas, artifactId=null, principal=null, source=service, loggedOutAlready=false, format=XML, attributes={})]>
2020-05-15 16:21:40,157 DEBUG [org.apereo.cas.authentication.PseudoPlatformTransactionManager] - <Creating new transaction with name [org.apereo.cas.DefaultCentralAuthenticationService.grantServiceTicket]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT; 'ticketTransactionManager'>
2020-05-15 16:21:40,157 DEBUG [org.apereo.cas.services.DefaultRegisteredServiceAccessStrategy] - <Skipping access strategy policy, since no attributes rules are defined>
2020-05-15 16:21:40,157 INFO [org.apereo.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - <Audit trail record BEGIN
=============================================================
WHO: testadmin
WHAT: [result=Service Access Granted,service=https://localhost:8443/geonetwork/sig...,requiredAttributes={}]
ACTION: SERVICE_ACCESS_ENFORCEMENT_TRIGGERED
APPLICATION: CAS
WHEN: Fri May 15 16:21:40 CEST 2020
CLIENT IP ADDRESS: 0:0:0:0:0:0:0:1
SERVER IP ADDRESS: 0:0:0:0:0:0:0:1
=============================================================
>
2020-05-15 16:21:40,157 DEBUG [org.apereo.cas.services.RegisteredServiceAccessStrategyUtils] - <Current authentication via ticket [TGT-5-********************************************************u4mti7MGrhQGIS-kokeza] allows service [https://localhost:8443/geonetwork/signin-cas] to participate in the existing SSO session>
2020-05-15 16:21:40,159 DEBUG [org.apereo.cas.ticket.factory.DefaultServiceTicketFactory] - <Looking up service ticket id generator for [org.apereo.cas.authentication.principal.SimpleWebApplicationServiceImpl]>
2020-05-15 16:21:40,161 DEBUG [org.apereo.cas.ticket.factory.DefaultServiceTicketFactory] - <Attempting to encode service ticket [ST-4-IMGr5Flo9FHSKhba9BVWucPyuW0GIS-kokeza]>
2020-05-15 16:21:40,161 DEBUG [org.apereo.cas.ticket.factory.DefaultServiceTicketFactory] - <Encoded service ticket id [ST-4-IMGr5Flo9FHSKhba9BVWucPyuW0GIS-kokeza]>
2020-05-15 16:21:40,161 DEBUG [org.apereo.cas.ticket.registry.AbstractMapBasedTicketRegistry] - <Added ticket [TGT-5-********************************************************u4mti7MGrhQGIS-kokeza] to registry.>
2020-05-15 16:21:40,161 DEBUG [org.apereo.cas.ticket.registry.AbstractMapBasedTicketRegistry] - <Added ticket [ST-4-IMGr5Flo9FHSKhba9BVWucPyuW0GIS-kokeza] to registry.>
2020-05-15 16:21:40,161 INFO [org.apereo.cas.DefaultCentralAuthenticationService] - <Granted ticket [ST-4-IMGr5Flo9FHSKhba9BVWucPyuW0GIS-kokeza] for service [https://localhost:8443/geonetwork/signin-cas] and principal [testadmin]>
2020-05-15 16:21:40,161 DEBUG [org.apereo.cas.AbstractCentralAuthenticationService] - <Publishing [CasServiceTicketGrantedEvent(ticketGrantingTicket=TGT-5-********************************************************u4mti7MGrhQGIS-kokeza, serviceTicket=ST-4-IMGr5Flo9FHSKhba9BVWucPyuW0GIS-kokeza)]>
2020-05-15 16:21:40,162 INFO [org.apereo.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - <Audit trail record BEGIN
=============================================================
WHO: testadmin
WHAT: ST-4-IMGr5Flo9FHSKhba9BVWucPyuW0GIS-kokeza for https://localhost:8443/geonetwork/signin-cas
ACTION: SERVICE_TICKET_CREATED
APPLICATION: CAS
WHEN: Fri May 15 16:21:40 CEST 2020
CLIENT IP ADDRESS: 0:0:0:0:0:0:0:1
SERVER IP ADDRESS: 0:0:0:0:0:0:0:1
=============================================================
>
2020-05-15 16:21:40,162 DEBUG [org.apereo.cas.authentication.PseudoPlatformTransactionManager] - <Initiating transaction commit>
2020-05-15 16:21:40,162 DEBUG [org.apereo.cas.authentication.principal.DefaultResponse] - <Sanitized URL for redirect response is [https://localhost:8443/geonetwork/signin-cas]>
2020-05-15 16:21:40,162 DEBUG [org.apereo.cas.authentication.principal.DefaultResponse] - <Final redirect response is [https://localhost:8443/geonetwork/signin-cas?ticket=ST-4-IMGr5Flo9FHSKhba9BVWucPyuW0GIS-kokeza]>
2020-05-15 16:21:40,189 DEBUG [org.apereo.cas.authentication.PseudoPlatformTransactionManager] - <Creating new transaction with name [org.apereo.cas.DefaultCentralAuthenticationService.getTicket]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT; 'ticketTransactionManager',+org.apereo.cas.ticket.InvalidTicketException>
2020-05-15 16:21:40,189 DEBUG [org.apereo.cas.authentication.PseudoPlatformTransactionManager] - <Initiating transaction commit>
2020-05-15 16:21:40,189 DEBUG [org.apereo.cas.authentication.PolicyBasedAuthenticationManager] - <Invoking authentication pre processors for authentication transaction>
2020-05-15 16:21:40,189 DEBUG [org.apereo.cas.authentication.DefaultAuthenticationEventExecutionPlan] - <Sorted and registered authentication pre processors for this transaction are [[]]>
2020-05-15 16:21:40,189 DEBUG [org.apereo.cas.authentication.PolicyBasedAuthenticationManager] - <Authentication credentials provided for this transaction are [[AbstractCredential()]]>
2020-05-15 16:21:40,189 DEBUG [org.apereo.cas.authentication.PolicyBasedAuthenticationManager] - <Candidate/Registered authentication handlers for this transaction are [[org.apereo.cas.authentication.handler.support.HttpBasedServiceCredentialsAuthenticationHandler@25fd5321, org.apereo.cas.authentication.LdapAuthenticationHandler@7771fa6d]]>
2020-05-15 16:21:40,189 DEBUG [org.apereo.cas.authentication.DefaultAuthenticationEventExecutionPlan] - <Sorted and registered authentication handler resolvers for this transaction are [[org.apereo.cas.authentication.RegisteredServiceAuthenticationHandlerResolver@665466f8]]>
2020-05-15 16:21:40,189 DEBUG [org.apereo.cas.authentication.PolicyBasedAuthenticationManager] - <Authentication handler resolvers for this transaction are [[org.apereo.cas.authentication.RegisteredServiceAuthenticationHandlerResolver@665466f8]]>
2020-05-15 16:21:40,189 DEBUG [org.apereo.cas.authentication.RegisteredServiceAuthenticationHandlerResolver] - <Located registered service definition [AbstractRegisteredService(serviceId=^(https|imaps)://.*, name=HTTPS and IMAPS, theme=null, informationUrl=null, privacyUrl=null, responseType=null, id=10000001, description=This service definition authorizes all application urls that support HTTPS and IMAPS protocols., expirationPolicy=DefaultRegisteredServiceExpirationPolicy(deleteWhenExpired=false, notifyWhenDeleted=false, expirationDate=null), proxyPolicy=RegexMatchingRegisteredServiceProxyPolicy(pattern=^https?://.*), evaluationOrder=10000, usernameAttributeProvider=org.apereo.cas.services.DefaultRegisteredServiceUsernameProvider@87297e2, logoutType=BACK_CHANNEL, requiredHandlers=[], attributeReleasePolicy=ReturnAllowedAttributeReleasePolicy(super=AbstractRegisteredServiceAttributeReleasePolicy(attributeFilter=null, principalAttributesRepository=DefaultPrincipalAttributesRepository(), consentPolicy=DefaultRegisteredServiceConsentPolicy(enabled=true, excludedAttributes=null, includeOnlyAttributes=null), authorizedToReleaseCredentialPassword=false, authorizedToReleaseProxyGrantingTicket=false, excludeDefaultAttributes=false, authorizedToReleaseAuthenticationAttributes=true, principalIdAttribute=null), allowedAttributes=[]), multifactorPolicy=DefaultRegisteredServiceMultifactorPolicy(multifactorAuthenticationProviders=[], failureMode=NOT_SET, principalAttributeNameTrigger=null, principalAttributeValueToMatch=null, bypassEnabled=false), logo=null, logoutUrl=null, accessStrategy=DefaultRegisteredServiceAccessStrategy(order=0, enabled=true, ssoEnabled=true, unauthorizedRedirectUrl=null, delegatedAuthenticationPolicy=DefaultRegisteredServiceDelegatedAuthenticationPolicy(allowedProviders=[]), requireAllAttributes=true, requiredAttributes={}, rejectedAttributes={}, caseInsensitive=false), publicKey=null, properties={}, contacts=[])] for this authentication transaction>
2020-05-15 16:21:40,189 DEBUG [org.apereo.cas.authentication.PolicyBasedAuthenticationManager] - <Authentication handler resolvers produced no candidate authentication handler. Using the default handler resolver instead...>
2020-05-15 16:21:40,189 DEBUG [org.apereo.cas.authentication.AuthenticationHandlerResolver] - <Default authentication handlers used for this transaction are [HttpBasedServiceCredentialsAuthenticationHandler,localhost]>
2020-05-15 16:21:40,189 DEBUG [org.apereo.cas.authentication.PolicyBasedAuthenticationManager] - <Resolved and finalized authentication handlers to carry out this authentication transaction are [[org.apereo.cas.authentication.handler.support.HttpBasedServiceCredentialsAuthenticationHandler@25fd5321, org.apereo.cas.authentication.LdapAuthenticationHandler@7771fa6d]]>
2020-05-15 16:21:40,189 DEBUG [org.apereo.cas.authentication.PolicyBasedAuthenticationManager] - <Candidate resolved authentication handlers for this transaction are [[org.apereo.cas.authentication.handler.support.HttpBasedServiceCredentialsAuthenticationHandler@25fd5321, org.apereo.cas.authentication.LdapAuthenticationHandler@7771fa6d]]>
2020-05-15 16:21:40,189 DEBUG [org.apereo.cas.authentication.PolicyBasedAuthenticationManager] - <Attempting to authenticate credential [AbstractCredential()]>
2020-05-15 16:21:40,189 DEBUG [org.apereo.cas.authentication.PolicyBasedAuthenticationManager] - <Attempting authentication of [https://localhost:8443/geonetwork/cas_security_proxyreceptor] using [HttpBasedServiceCredentialsAuthenticationHandler]>
2020-05-15 16:21:40,190 DEBUG [org.apereo.cas.authentication.handler.support.HttpBasedServiceCredentialsAuthenticationHandler] - <Attempting to authenticate [AbstractCredential()]>
2020-05-15 16:21:40,209 DEBUG [org.apereo.cas.util.http.SimpleHttpClient] - <Response code did not match any of the acceptable response codes. Code returned was [400]>
2020-05-15 16:21:40,210 ERROR [org.apereo.cas.authentication.PolicyBasedAuthenticationManager] - <Authentication has failed. Credentials may be incorrect or CAS cannot find authentication handler that supports [AbstractCredential()] of type [HttpBasedServiceCredential]. Examine the configuration to ensure a method of authentication is defined and analyze CAS logs at DEBUG level to trace the authentication event.>
2020-05-15 16:21:40,210 DEBUG [org.apereo.cas.authentication.PolicyBasedAuthenticationManager] - <[HttpBasedServiceCredentialsAuthenticationHandler] exception details: [https://localhost:8443/geonetwork/cas_security_proxyreceptor sent an unacceptable response status code].>
2020-05-15 16:21:40,210 DEBUG [org.apereo.cas.authentication.DefaultAuthenticationBuilder] - <Recording authentication handler failure under key [HttpBasedServiceCredentialsAuthenticationHandler]>
2020-05-15 16:21:40,211 DEBUG [org.apereo.cas.authentication.handler.support.AbstractUsernamePasswordAuthenticationHandler] - <Credential is not one of username/password and is not accepted by handler [localhost]>
2020-05-15 16:21:40,211 DEBUG [org.apereo.cas.authentication.PolicyBasedAuthenticationManager] - <Authentication handler [localhost] does not support the credential type [AbstractCredential()]. Trying next...>
2020-05-15 16:21:40,211 INFO [org.apereo.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - <Audit trail record BEGIN
=============================================================
WHO: https://localhost:8443/geonetwork/cas_security_proxyreceptor
WHAT: Supplied credentials: [AbstractCredential()]
ACTION: AUTHENTICATION_FAILED
APPLICATION: CAS
WHEN: Fri May 15 16:21:40 CEST 2020
CLIENT IP ADDRESS: 127.0.0.1
SERVER IP ADDRESS: 127.0.0.1
=============================================================
>
2020-05-15 16:21:40,211 WARN [org.apereo.cas.web.AbstractServiceValidateController] - <Failed to authenticate service credential [AbstractCredential()]>
2020-05-15 16:21:40,273 DEBUG [org.apereo.cas.web.view.CasReloadableMessageBundle] - <No properties file found for [classpath:custom_messages_en_US] - neither plain properties nor XML>
2020-05-15 16:21:40,276 DEBUG [org.apereo.cas.web.view.CasReloadableMessageBundle] - <No properties file found for [classpath:messages_en_US] - neither plain properties nor XML>
2020-05-15 16:21:40,418 DEBUG [org.apereo.cas.authentication.PseudoPlatformTransactionManager] - <Creating new transaction with name [org.apereo.cas.DefaultCentralAuthenticationService.getTicket]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT; 'ticketTransactionManager',+org.apereo.cas.ticket.InvalidTicketException>
2020-05-15 16:21:40,418 DEBUG [org.apereo.cas.authentication.PseudoPlatformTransactionManager] - <Initiating transaction commit>
2020-05-15 16:21:40,418 DEBUG [org.apereo.cas.authentication.PolicyBasedAuthenticationManager] - <Invoking authentication pre processors for authentication transaction>
2020-05-15 16:21:40,418 DEBUG [org.apereo.cas.authentication.DefaultAuthenticationEventExecutionPlan] - <Sorted and registered authentication pre processors for this transaction are [[]]>
2020-05-15 16:21:40,418 DEBUG [org.apereo.cas.authentication.PolicyBasedAuthenticationManager] - <Authentication credentials provided for this transaction are [[AbstractCredential()]]>
2020-05-15 16:21:40,418 DEBUG [org.apereo.cas.authentication.PolicyBasedAuthenticationManager] - <Candidate/Registered authentication handlers for this transaction are [[org.apereo.cas.authentication.handler.support.HttpBasedServiceCredentialsAuthenticationHandler@25fd5321, org.apereo.cas.authentication.LdapAuthenticationHandler@7771fa6d]]>
2020-05-15 16:21:40,418 DEBUG [org.apereo.cas.authentication.DefaultAuthenticationEventExecutionPlan] - <Sorted and registered authentication handler resolvers for this transaction are [[org.apereo.cas.authentication.RegisteredServiceAuthenticationHandlerResolver@665466f8]]>
2020-05-15 16:21:40,418 DEBUG [org.apereo.cas.authentication.PolicyBasedAuthenticationManager] - <Authentication handler resolvers for this transaction are [[org.apereo.cas.authentication.RegisteredServiceAuthenticationHandlerResolver@665466f8]]>
2020-05-15 16:21:40,418 DEBUG [org.apereo.cas.authentication.RegisteredServiceAuthenticationHandlerResolver] - <Located registered service definition [AbstractRegisteredService(serviceId=^(https|imaps)://.*, name=HTTPS and IMAPS, theme=null, informationUrl=null, privacyUrl=null, responseType=null, id=10000001, description=This service definition authorizes all application urls that support HTTPS and IMAPS protocols., expirationPolicy=DefaultRegisteredServiceExpirationPolicy(deleteWhenExpired=false, notifyWhenDeleted=false, expirationDate=null), proxyPolicy=RegexMatchingRegisteredServiceProxyPolicy(pattern=^https?://.*), evaluationOrder=10000, usernameAttributeProvider=org.apereo.cas.services.DefaultRegisteredServiceUsernameProvider@87297e2, logoutType=BACK_CHANNEL, requiredHandlers=[], attributeReleasePolicy=ReturnAllowedAttributeReleasePolicy(super=AbstractRegisteredServiceAttributeReleasePolicy(attributeFilter=null, principalAttributesRepository=DefaultPrincipalAttributesRepository(), consentPolicy=DefaultRegisteredServiceConsentPolicy(enabled=true, excludedAttributes=null, includeOnlyAttributes=null), authorizedToReleaseCredentialPassword=false, authorizedToReleaseProxyGrantingTicket=false, excludeDefaultAttributes=false, authorizedToReleaseAuthenticationAttributes=true, principalIdAttribute=null), allowedAttributes=[]), multifactorPolicy=DefaultRegisteredServiceMultifactorPolicy(multifactorAuthenticationProviders=[], failureMode=NOT_SET, principalAttributeNameTrigger=null, principalAttributeValueToMatch=null, bypassEnabled=false), logo=null, logoutUrl=null, accessStrategy=DefaultRegisteredServiceAccessStrategy(order=0, enabled=true, ssoEnabled=true, unauthorizedRedirectUrl=null, delegatedAuthenticationPolicy=DefaultRegisteredServiceDelegatedAuthenticationPolicy(allowedProviders=[]), requireAllAttributes=true, requiredAttributes={}, rejectedAttributes={}, caseInsensitive=false), publicKey=null, properties={}, contacts=[])] for this authentication transaction>
2020-05-15 16:21:40,418 DEBUG [org.apereo.cas.authentication.PolicyBasedAuthenticationManager] - <Authentication handler resolvers produced no candidate authentication handler. Using the default handler resolver instead...>
2020-05-15 16:21:40,418 DEBUG [org.apereo.cas.authentication.AuthenticationHandlerResolver] - <Default authentication handlers used for this transaction are [HttpBasedServiceCredentialsAuthenticationHandler,localhost]>
2020-05-15 16:21:40,418 DEBUG [org.apereo.cas.authentication.PolicyBasedAuthenticationManager] - <Resolved and finalized authentication handlers to carry out this authentication transaction are [[org.apereo.cas.authentication.handler.support.HttpBasedServiceCredentialsAuthenticationHandler@25fd5321, org.apereo.cas.authentication.LdapAuthenticationHandler@7771fa6d]]>
2020-05-15 16:21:40,418 DEBUG [org.apereo.cas.authentication.PolicyBasedAuthenticationManager] - <Candidate resolved authentication handlers for this transaction are [[org.apereo.cas.authentication.handler.support.HttpBasedServiceCredentialsAuthenticationHandler@25fd5321, org.apereo.cas.authentication.LdapAuthenticationHandler@7771fa6d]]>
2020-05-15 16:21:40,418 DEBUG [org.apereo.cas.authentication.PolicyBasedAuthenticationManager] - <Attempting to authenticate credential [AbstractCredential()]>
2020-05-15 16:21:40,419 DEBUG [org.apereo.cas.authentication.PolicyBasedAuthenticationManager] - <Attempting authentication of [https://localhost:8443/geonetwork/cas_security_proxyreceptor] using [HttpBasedServiceCredentialsAuthenticationHandler]>
2020-05-15 16:21:40,419 DEBUG [org.apereo.cas.authentication.handler.support.HttpBasedServiceCredentialsAuthenticationHandler] - <Attempting to authenticate [AbstractCredential()]>
2020-05-15 16:21:40,435 DEBUG [org.apereo.cas.util.http.SimpleHttpClient] - <Response code did not match any of the acceptable response codes. Code returned was [400]>
2020-05-15 16:21:40,435 ERROR [org.apereo.cas.authentication.PolicyBasedAuthenticationManager] - <Authentication has failed. Credentials may be incorrect or CAS cannot find authentication handler that supports [AbstractCredential()] of type [HttpBasedServiceCredential]. Examine the configuration to ensure a method of authentication is defined and analyze CAS logs at DEBUG level to trace the authentication event.>
2020-05-15 16:21:40,435 DEBUG [org.apereo.cas.authentication.PolicyBasedAuthenticationManager] - <[HttpBasedServiceCredentialsAuthenticationHandler] exception details: [https://localhost:8443/geonetwork/cas_security_proxyreceptor sent an unacceptable response status code].>
2020-05-15 16:21:40,435 DEBUG [org.apereo.cas.authentication.DefaultAuthenticationBuilder] - <Recording authentication handler failure under key [HttpBasedServiceCredentialsAuthenticationHandler]>
2020-05-15 16:21:40,435 DEBUG [org.apereo.cas.authentication.handler.support.AbstractUsernamePasswordAuthenticationHandler] - <Credential is not one of username/password and is not accepted by handler [localhost]>
2020-05-15 16:21:40,435 DEBUG [org.apereo.cas.authentication.PolicyBasedAuthenticationManager] - <Authentication handler [localhost] does not support the credential type [AbstractCredential()]. Trying next...>
2020-05-15 16:21:40,436 INFO [org.apereo.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - <Audit trail record BEGIN
=============================================================
WHO: https://localhost:8443/geonetwork/cas_security_proxyreceptor
WHAT: Supplied credentials: [AbstractCredential()]
ACTION: AUTHENTICATION_FAILED
APPLICATION: CAS
WHEN: Fri May 15 16:21:40 CEST 2020
CLIENT IP ADDRESS: 127.0.0.1
SERVER IP ADDRESS: 127.0.0.1
=============================================================
>
2020-05-15 16:21:40,436 WARN [org.apereo.cas.web.AbstractServiceValidateController] - <Failed to authenticate service credential [AbstractCredential()]>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment