'RE: IDP v 4 on Windows No Apache'

[prev in list] [next in list] [prev in thread] [next in thread] 

List:       shibboleth-users
Subject:    RE: IDP v 4 on Windows No Apache
From:       Rick Hoodenpyle <rhoodenpyle () rms-inc ! com>
Date:       2022-07-19 7:05:22
Message-ID: 89caaa091738bb92c8c88043838584d3 () mail ! gmail ! com
[Download RAW message or body]

Thank you Rod. Here are the logs after the initial startup finishes.

2022-07-19 01:45:16,725 -  - INFO
[net.shibboleth.ext.spring.service.ReloadableSpringService:428] - Service
'shibboleth.ManagedBeanService': Reload complete

2022-07-19 01:45:18,650 -  - INFO
[net.shibboleth.idp.authn.impl.RemoteUserAuthServlet:214] -
RemoteUserAuthServlet will process REMOTE_USER, along with attributes []
and headers []

2022-07-19 01:49:57,045 - IP - INFO
[org.ldaptive.pool.BlockingConnectionPool:497] - added available
connection:
org.ldaptive.pool.AbstractConnectionPool$DefaultPooledConnectionProxy@1a30
4bf1

2022-07-19 01:49:57,049 - IP - INFO
[org.ldaptive.pool.BlockingConnectionPool:497] - added available
connection:
org.ldaptive.pool.AbstractConnectionPool$DefaultPooledConnectionProxy@7c62
680

2022-07-19 01:49:57,051 - IP - INFO
[org.ldaptive.pool.BlockingConnectionPool:497] - added available
connection:
org.ldaptive.pool.AbstractConnectionPool$DefaultPooledConnectionProxy@78ec
f88c

2022-07-19 01:49:57,053 - IP - INFO
[org.ldaptive.pool.BlockingConnectionPool:306] - pool initialized
[org.ldaptive.pool.BlockingConnectionPool@614332969::name=bind-pool,
poolConfig=[org.ldaptive.pool.PoolConfig@2049891072::minPoolSize=3,
maxPoolSize=10, validateOnCheckIn=false, validateOnCheckOut=false,
validatePeriodically=true, validatePeriod=PT5M, validateTimeout=PT5S],
activator=null, passivator=null,
validator=[org.ldaptive.pool.SearchValidator@1725755135::searchRequest=[or
g.ldaptive.SearchRequest@1190780177::baseDn=,
searchFilter=[org.ldaptive.SearchFilter@1642584434::filter=(objectClass=*)
, parameters={}], returnAttributes=[1.1], searchScope=OBJECT,
timeLimit=PT0S, sizeLimit=1, derefAliases=null, typesOnly=false,
binaryAttributes=null, sortBehavior=UNORDERED, searchEntryHandlers=null,
searchReferenceHandlers=null, controls=null, referralHandler=null,
intermediateResponseHandlers=null]]
pruneStrategy=[org.ldaptive.pool.IdlePruneStrategy@1610234869::prunePeriod
=PT5M, idleTime=PT10M], connectOnCreate=true,
connectionFactory=[org.ldaptive.DefaultConnectionFactory@1590730211::provi
der=org.ldaptive.provider.unboundid.UnboundIDProvider@79fec625,
config=[org.ldaptive.ConnectionConfig@718231464::ldapUrl=ldap://ldap.domai
n.com:389, connectTimeout=PT3S, responseTimeout=PT3S,
sslConfig=[org.ldaptive.ssl.SslConfig@618984599::credentialConfig=net.shib
boleth.idp.authn.impl.X509ResourceCredentialConfig@3ae6179e,
trustManagers=null, hostnameVerifier=null, hostnameVerifierConfig=null,
enabledCipherSuites=null, enabledProtocols=null,
handshakeCompletedListeners=null], useSSL=false, useStartTLS=false,
connectionInitializer=null,
connectionStrategy=org.ldaptive.ActivePassiveConnectionStrategy@7e015a6d]]
, initialized=true, availableCount=3, activeCount=0]

2022-07-19 01:49:57,102 - IP - INFO
[org.ldaptive.pool.BlockingConnectionPool:497] - added available
connection:
org.ldaptive.pool.AbstractConnectionPool$DefaultPooledConnectionProxy@177b
57c3

2022-07-19 01:49:57,104 - IP - INFO
[org.ldaptive.pool.BlockingConnectionPool:497] - added available
connection:
org.ldaptive.pool.AbstractConnectionPool$DefaultPooledConnectionProxy@3f36
fa7d

2022-07-19 01:49:57,107 - IP - INFO
[org.ldaptive.pool.BlockingConnectionPool:497] - added available
connection:
org.ldaptive.pool.AbstractConnectionPool$DefaultPooledConnectionProxy@64c8
bae3

2022-07-19 01:49:57,108 - IP - INFO
[org.ldaptive.pool.BlockingConnectionPool:306] - pool initialized
[org.ldaptive.pool.BlockingConnectionPool@144077722::name=dn-search-pool,
poolConfig=[org.ldaptive.pool.PoolConfig@122424146::minPoolSize=3,
maxPoolSize=10, validateOnCheckIn=false, validateOnCheckOut=false,
validatePeriodically=true, validatePeriod=PT5M, validateTimeout=PT5S],
activator=null, passivator=null,
validator=[org.ldaptive.pool.SearchValidator@1563891291::searchRequest=[or
g.ldaptive.SearchRequest@1190780177::baseDn=,
searchFilter=[org.ldaptive.SearchFilter@1642584434::filter=(objectClass=*)
, parameters={}], returnAttributes=[1.1], searchScope=OBJECT,
timeLimit=PT0S, sizeLimit=1, derefAliases=null, typesOnly=false,
binaryAttributes=null, sortBehavior=UNORDERED, searchEntryHandlers=null,
searchReferenceHandlers=null, controls=null, referralHandler=null,
intermediateResponseHandlers=null]]
pruneStrategy=[org.ldaptive.pool.IdlePruneStrategy@999625986::prunePeriod=
PT5M, idleTime=PT10M], connectOnCreate=true,
connectionFactory=[org.ldaptive.DefaultConnectionFactory@2407241::provider
=org.ldaptive.provider.unboundid.UnboundIDProvider@67552684,
config=[org.ldaptive.ConnectionConfig@37057019::ldapUrl=ldap://ldap.domain
.com:389, connectTimeout=PT3S, responseTimeout=PT3S,
sslConfig=[org.ldaptive.ssl.SslConfig@295389626::credentialConfig=net.shib
boleth.idp.authn.impl.X509ResourceCredentialConfig@3ae6179e,
trustManagers=null, hostnameVerifier=null, hostnameVerifierConfig=null,
enabledCipherSuites=null, enabledProtocols=null,
handshakeCompletedListeners=null], useSSL=false, useStartTLS=false,
connectionInitializer=[org.ldaptive.BindConnectionInitializer@885020211::b
indDn=cn=root,dc=domain,dc=com, bindSaslConfig=null, bindControls=null],
connectionStrategy=org.ldaptive.ActivePassiveConnectionStrategy@7aef3729]]
, initialized=true, availableCount=3, activeCount=0]

2022-07-19 01:50:11,978 - IP  - INFO [org.ldaptive.auth.Authenticator:291]
- Authentication succeeded for dn: cn=user,ou=users,dc=domain,dc=com

2022-07-19 01:50:11,979 - IP - INFO
[net.shibboleth.idp.authn.impl.LDAPCredentialValidator:163] - Credential
Validator ldap: Login by 'user' succeeded

2022-07-19 01:50:12,082 - IP - INFO
[net.shibboleth.idp.authn.impl.FinalizeAuthentication:196] - Profile
Action FinalizeAuthentication: Principal user  authenticated

2022-07-19 01:50:12,824 - IP - INFO [Shibboleth-Audit.SSO:283] -
IP|2022-07-19T05:49:55.952513100Z|2022-07-19T05:50:12.824587100Z|user|http
s://server.domain.com/shibboleth|_20a8c0dfeded5d513a5b745918d7d84b|passwor
d|2022-07-19T05:50:11.984575300Z||AAdzZWNyZXQxSsAEcIp4H7CMeAnwlsZMPKe0D/m4
l5/kJ7oym+ZQ9HRN6B70d24bJO6Kj3MOvOGFvicM7lJkYqsNs66Z0GcelKW3qFaG9+d4Ft0TUa
koMhSQPiy3/TZ+n+BUbVxSRW/EOqGaken9lWRLPvwak3U=|transient|false|false|AES12
8-GCM|urn:oasis:names:tc:SAML:2.0:bindings:HTTP-Redirect|urn:oasis:names:t
c:SAML:2.0:bindings:HTTP-POST||Success||0f15b2d6cac986a462530f8987bfe9d26b
6db1d421989b2820153d9a82a8ad3e|Mozilla/5.0 (Windows NT 10.0; Win64; x64)
AppleWebKit/537.36 (KHTML, like Gecko) Chrome/103.0.0.0 Safari/537.36

2022-07-19 01:54:57,060 -  - WARN
[org.ldaptive.pool.BlockingConnectionPool:784] -
org.ldaptive.pool.AbstractConnectionPool$DefaultPooledConnectionProxy@1a30
4bf1 failed validation

2022-07-19 01:54:57,061 -  - WARN
[org.ldaptive.pool.BlockingConnectionPool:784] -
org.ldaptive.pool.AbstractConnectionPool$DefaultPooledConnectionProxy@7c62
680 failed validation

2022-07-19 01:54:57,072 -  - INFO
[org.ldaptive.pool.BlockingConnectionPool:497] - added available
connection:
org.ldaptive.pool.AbstractConnectionPool$DefaultPooledConnectionProxy@cb6c
dd4
2022-07-19 01:54:57,073 -  - INFO
[org.ldaptive.pool.BlockingConnectionPool:497] - added available
connection:
org.ldaptive.pool.AbstractConnectionPool$DefaultPooledConnectionProxy@24ba
3997

2022-07-19 01:57:16,539 - 192.168.0.241 - INFO
[net.shibboleth.idp.authn.impl.FinalizeAuthentication:196] - Profile
Action FinalizeAuthentication: Principal user authenticated

2022-07-19 01:57:16,621 - 192.168.0.241 - INFO [Shibboleth-Audit.SSO:283]
-
IP|2022-07-19T05:57:16.483054100Z|2022-07-19T05:57:16.621051200Z|user|http
s://server.domain.com/shibboleth|_c42b02ef868fd1042f809e99e2943e75|passwor
d|2022-07-19T05:50:11.984Z||AAdzZWNyZXQxR3rg6Ap2AVPSQCcAuYpQr+rWsBVf81feDL
YQWwcGY4DiIU+0Dbm6ECRfIaHm0Srq1iAcTmy5AZBxMWDrrCBk+/1AlUFDVUY76W9fnnqR12Ft
9t8uzy6XVEWdeEh0gNsJnwaw/C5lag0Ew0PyRQA=|transient|true|false|AES128-GCM|u
rn:oasis:names:tc:SAML:2.0:bindings:HTTP-Redirect|urn:oasis:names:tc:SAML:
2.0:bindings:HTTP-POST||Success||0f15b2d6cac986a462530f8987bfe9d26b6db1d42
1989b2820153d9a82a8ad3e|Mozilla/5.0 (Windows NT 10.0; Win64; x64)
AppleWebKit/537.36 (KHTML, like Gecko) Chrome/103.0.0.0 Safari/537.36

2022-07-19 01:59:57,063 -  - WARN
[org.ldaptive.pool.BlockingConnectionPool:784] -
org.ldaptive.pool.AbstractConnectionPool$DefaultPooledConnectionProxy@24ba
3997 failed validation

2022-07-19 01:59:57,064 -  - WARN
[org.ldaptive.pool.BlockingConnectionPool:784] -
org.ldaptive.pool.AbstractConnectionPool$DefaultPooledConnectionProxy@cb6c
dd4 failed validation

2022-07-19 01:59:57,068 -  - INFO
[org.ldaptive.pool.BlockingConnectionPool:497] - added available
connection:
org.ldaptive.pool.AbstractConnectionPool$DefaultPooledConnectionProxy@1530
0357

2022-07-19 01:59:57,072 -  - INFO
[org.ldaptive.pool.BlockingConnectionPool:497] - added available
connection:
org.ldaptive.pool.AbstractConnectionPool$DefaultPooledConnectionProxy@43cc
bf94

2022-07-19 02:04:57,065 -  - WARN
[org.ldaptive.pool.BlockingConnectionPool:784] -
org.ldaptive.pool.AbstractConnectionPool$DefaultPooledConnectionProxy@43cc
bf94 failed validation

2022-07-19 02:04:57,066 -  - WARN
[org.ldaptive.pool.BlockingConnectionPool:784] -
org.ldaptive.pool.AbstractConnectionPool$DefaultPooledConnectionProxy@1530
0357 failed validation

2022-07-19 02:04:57,073 -  - INFO
[org.ldaptive.pool.BlockingConnectionPool:497] - added available
connection:
org.ldaptive.pool.AbstractConnectionPool$DefaultPooledConnectionProxy@524b
66a7

2022-07-19 02:04:57,074 -  - INFO
[org.ldaptive.pool.BlockingConnectionPool:497] - added available
connection:
org.ldaptive.pool.AbstractConnectionPool$DefaultPooledConnectionProxy@2fe9
785c

2022-07-19 02:09:57,071 -  - WARN
[org.ldaptive.pool.BlockingConnectionPool:784] -
org.ldaptive.pool.AbstractConnectionPool$DefaultPooledConnectionProxy@524b
66a7 failed validation

2022-07-19 02:09:57,072 -  - WARN
[org.ldaptive.pool.BlockingConnectionPool:784] -
org.ldaptive.pool.AbstractConnectionPool$DefaultPooledConnectionProxy@2fe9
785c failed validation

2022-07-19 02:09:57,077 -  - INFO
[org.ldaptive.pool.BlockingConnectionPool:497] - added available
connection:
org.ldaptive.pool.AbstractConnectionPool$DefaultPooledConnectionProxy@635d
ff44

2022-07-19 02:09:57,078 -  - INFO
[org.ldaptive.pool.BlockingConnectionPool:497] - added available
connection:
org.ldaptive.pool.AbstractConnectionPool$DefaultPooledConnectionProxy@5453
2d6a

Cheers,

Rick

-----Original Message-----
From: users <users-bounces@shibboleth.net> On Behalf Of Rod Widdowson
Sent: 19 July 2022 07:47
To: 'Shib Users' <users@shibboleth.net>
Subject: RE: IDP v 4 on Windows No Apache

> 2022-07-19 01:54:57,060 -  - WARN
[org.ldaptive.pool.BlockingConnectionPool:784] -
org.ldaptive.pool.AbstractConnectionPool$DefaultPooledConnectionProxy@1a30
4bf1 failed validation

Looks like that is what you have to chase up.  If you are logging in and
you are using LDAP to do the AuthN I would assume that it is your
dataconnector.

But that error will be preceded by other errors.  So look for them; and if
there aren't any turn up logging for org.ldaptive (and potentially
net.shibboleth.idp.attribute) and see what pops up

Rod

-- 
For Consortium Member technical support, see
https://shibboleth.atlassian.net/wiki/x/ZYEpPw
To unsubscribe from this list send an email to
users-unsubscribe@shibboleth.net
-- 
For Consortium Member technical support, see https://shibboleth.atlassian.net/wiki/x/ZYEpPw
To unsubscribe from this list send an email to users-unsubscribe@shibboleth.net
[prev in list] [next in list] [prev in thread] [next in thread]
Configure | About | News | Add a list | Sponsored by KoreLogic