Shibboleth support in my application

mmichaelchn mmichaelchn at gmail.com
Tue Sep 17 15:14:42 EDT 2013 

Below is log from my idp logs. Not sure where the problem is. Can you please
suggest what I need to fix so I can see the attributes?

00:33:49.404 - DEBUG
[edu.internet2.middleware.shibboleth.idp.authn.provider.UsernamePasswordLoginServlet:170]
- Attempting to authenticate user user.0
00:33:49.413 - TRACE [edu.vt.middleware.ldap.jaas.LdapLoginModule:144] -
Begin initialize
00:33:49.413 - DEBUG [edu.vt.middleware.ldap.jaas.LdapLoginModule:180] -
useFirstPass = false
00:33:49.413 - DEBUG [edu.vt.middleware.ldap.jaas.LdapLoginModule:181] -
tryFirstPass = false
00:33:49.413 - DEBUG [edu.vt.middleware.ldap.jaas.LdapLoginModule:182] -
storePass = false
00:33:49.413 - DEBUG [edu.vt.middleware.ldap.jaas.LdapLoginModule:183] -
clearPass = false
00:33:49.413 - DEBUG [edu.vt.middleware.ldap.jaas.LdapLoginModule:184] -
setLdapPrincipal = true
00:33:49.414 - DEBUG [edu.vt.middleware.ldap.jaas.LdapLoginModule:185] -
setLdapDnPrincipal = false
00:33:49.414 - DEBUG [edu.vt.middleware.ldap.jaas.LdapLoginModule:186] -
setLdapCredential = true
00:33:49.414 - DEBUG [edu.vt.middleware.ldap.jaas.LdapLoginModule:187] -
defaultRole = []
00:33:49.414 - DEBUG [edu.vt.middleware.ldap.jaas.LdapLoginModule:188] -
principalGroupName = null
00:33:49.414 - DEBUG [edu.vt.middleware.ldap.jaas.LdapLoginModule:189] -
roleGroupName = null
00:33:49.414 - DEBUG [edu.vt.middleware.ldap.jaas.LdapLoginModule:77] -
userRoleAttribute = []
00:33:49.419 - TRACE [edu.vt.middleware.ldap.auth.AuthenticatorConfig:1385]
- setting searchScope: ONELEVEL
00:33:49.997 - TRACE [edu.vt.middleware.ldap.auth.AuthenticatorConfig:427] -
setting subtreeSearch: true
00:33:49.997 - TRACE [edu.vt.middleware.ldap.auth.AuthenticatorConfig:1385]
- setting searchScope: SUBTREE
00:33:49.997 - TRACE [edu.vt.middleware.ldap.auth.AuthenticatorConfig:1370]
- setting baseDn: ou=people,dc=example,dc=com
00:33:49.997 - TRACE [edu.vt.middleware.ldap.auth.AuthenticatorConfig:1834]
- setting ssl: false
00:33:49.997 - TRACE [edu.vt.middleware.ldap.auth.AuthenticatorConfig:1168]
- setting ldapUrl: ldap://localhost:389
00:33:49.998 - TRACE [edu.vt.middleware.ldap.auth.AuthenticatorConfig:1276]
- setting bindDn: cn=Directory Manager
00:33:49.998 - TRACE [edu.vt.middleware.ldap.auth.AuthenticatorConfig:290] -
setting userFilter: uid={0}
00:33:49.998 - TRACE [edu.vt.middleware.ldap.auth.AuthenticatorConfig:1309]
- setting bindCredential: <suppressed>
00:33:49.998 - TRACE [edu.vt.middleware.ldap.auth.AuthenticatorConfig:1119]
- setting connectionHandler:
edu.vt.middleware.ldap.handler.DefaultConnectionHandler at 157a1a5
00:33:50.001 - DEBUG [edu.vt.middleware.ldap.jaas.LdapLoginModule:83] -
Created authenticator:
edu.vt.middleware.ldap.auth.AuthenticatorConfig at 16964234::env={java.naming.provider.url=ldap://localhost:389,
java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory}
00:33:50.001 - TRACE [edu.vt.middleware.ldap.jaas.LdapLoginModule:412] -
Begin getCredentials
00:33:50.002 - TRACE [edu.vt.middleware.ldap.jaas.LdapLoginModule:413] -  
useFistPass = false
00:33:50.002 - TRACE [edu.vt.middleware.ldap.jaas.LdapLoginModule:414] -  
tryFistPass = false
00:33:50.002 - TRACE [edu.vt.middleware.ldap.jaas.LdapLoginModule:415] -  
useCallback = false
00:33:50.002 - TRACE [edu.vt.middleware.ldap.jaas.LdapLoginModule:416] -  
callbackhandler class =
javax.security.auth.login.LoginContext$SecureCallbackHandler
00:33:50.002 - TRACE [edu.vt.middleware.ldap.jaas.LdapLoginModule:419] -  
name callback class = javax.security.auth.callback.NameCallback
00:33:50.002 - TRACE [edu.vt.middleware.ldap.jaas.LdapLoginModule:421] -  
password callback class = javax.security.auth.callback.PasswordCallback
00:33:50.003 - DEBUG [edu.vt.middleware.ldap.auth.SearchDnResolver:102] -
Looking up DN using userFilter
00:33:50.004 - DEBUG [edu.vt.middleware.ldap.auth.SearchDnResolver:193] -
Search with the following parameters:
00:33:50.004 - DEBUG [edu.vt.middleware.ldap.auth.SearchDnResolver:194] -  
dn = ou=people,dc=example,dc=com
00:33:50.004 - DEBUG [edu.vt.middleware.ldap.auth.SearchDnResolver:195] -  
filter = uid={0}
00:33:50.004 - DEBUG [edu.vt.middleware.ldap.auth.SearchDnResolver:196] -  
filterArgs = [user.0]
00:33:50.004 - DEBUG [edu.vt.middleware.ldap.auth.SearchDnResolver:197] -  
searchControls = javax.naming.directory.SearchControls at 1593ad3
00:33:50.004 - DEBUG [edu.vt.middleware.ldap.auth.SearchDnResolver:198] -  
handler = [edu.vt.middleware.ldap.handler.FqdnSearchResultHandler at 12533f6]
00:33:50.004 - TRACE [edu.vt.middleware.ldap.auth.SearchDnResolver:200] -  
config = {java.naming.provider.url=ldap://localhost:389,
java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory}
00:33:50.004 - TRACE
[edu.vt.middleware.ldap.handler.DefaultConnectionHandler:93] - setting
connectionStrategy: DEFAULT
00:33:50.004 - TRACE
[edu.vt.middleware.ldap.handler.DefaultConnectionHandler:110] - setting
connectionRetryExceptions: [class javax.naming.NamingException]
00:33:50.006 - TRACE
[edu.vt.middleware.ldap.handler.DefaultConnectionHandler:152] - {0}
Attempting connection to ldap://localhost:389 for strategy DEFAULT
00:33:50.006 - DEBUG
[edu.vt.middleware.ldap.handler.DefaultConnectionHandler:74] - Bind with the
following parameters:
00:33:50.006 - DEBUG
[edu.vt.middleware.ldap.handler.DefaultConnectionHandler:75] -   authtype =
simple
00:33:50.006 - DEBUG
[edu.vt.middleware.ldap.handler.DefaultConnectionHandler:76] -   dn =
cn=Directory Manager
00:33:50.006 - DEBUG
[edu.vt.middleware.ldap.handler.DefaultConnectionHandler:83] -   credential
= <suppressed>
00:33:50.006 - TRACE
[edu.vt.middleware.ldap.handler.DefaultConnectionHandler:87] -   env =
{java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory,
java.naming.provider.url=ldap://localhost:389}
00:33:50.014 - TRACE
[edu.vt.middleware.ldap.handler.FqdnSearchResultHandler:69] - processing
relative dn: uid=user.0,ou=People
00:33:50.016 - TRACE
[edu.vt.middleware.ldap.handler.FqdnSearchResultHandler:95] - processed dn:
uid=user.0,ou=People,ou=people,dc=example,dc=com
00:33:50.017 - TRACE
[edu.vt.middleware.ldap.handler.DefaultConnectionHandler:93] - setting
connectionStrategy: DEFAULT
00:33:50.017 - TRACE
[edu.vt.middleware.ldap.handler.DefaultConnectionHandler:110] - setting
connectionRetryExceptions: [class javax.naming.NamingException]
00:33:50.018 - TRACE
[edu.vt.middleware.ldap.handler.DefaultConnectionHandler:152] - {1}
Attempting connection to ldap://localhost:389 for strategy DEFAULT
00:33:50.018 - DEBUG
[edu.vt.middleware.ldap.handler.DefaultConnectionHandler:74] - Bind with the
following parameters:
00:33:50.018 - DEBUG
[edu.vt.middleware.ldap.handler.DefaultConnectionHandler:75] -   authtype =
simple
00:33:50.018 - DEBUG
[edu.vt.middleware.ldap.handler.DefaultConnectionHandler:76] -   dn =
uid=user.0,ou=People,ou=people,dc=example,dc=com
00:33:50.018 - DEBUG
[edu.vt.middleware.ldap.handler.DefaultConnectionHandler:83] -   credential
= <suppressed>
00:33:50.018 - TRACE
[edu.vt.middleware.ldap.handler.DefaultConnectionHandler:87] -   env =
{java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory,
java.naming.provider.url=ldap://localhost:389}
00:33:50.022 - INFO [edu.vt.middleware.ldap.jaas.JaasAuthenticator:176] -
Authentication succeeded for dn:
uid=user.0,ou=People,ou=people,dc=example,dc=com
00:33:50.029 - DEBUG [edu.vt.middleware.ldap.auth.SearchDnResolver:102] -
Looking up DN using userFilter
00:33:50.029 - DEBUG [edu.vt.middleware.ldap.auth.SearchDnResolver:193] -
Search with the following parameters:
00:33:50.029 - DEBUG [edu.vt.middleware.ldap.auth.SearchDnResolver:194] -  
dn = ou=people,dc=example,dc=com
00:33:50.029 - DEBUG [edu.vt.middleware.ldap.auth.SearchDnResolver:195] -  
filter = uid={0}
00:33:50.029 - DEBUG [edu.vt.middleware.ldap.auth.SearchDnResolver:196] -  
filterArgs = [user.0]
00:33:50.029 - DEBUG [edu.vt.middleware.ldap.auth.SearchDnResolver:197] -  
searchControls = javax.naming.directory.SearchControls at cfd097
00:33:50.029 - DEBUG [edu.vt.middleware.ldap.auth.SearchDnResolver:198] -  
handler = [edu.vt.middleware.ldap.handler.FqdnSearchResultHandler at 12533f6]
00:33:50.029 - TRACE [edu.vt.middleware.ldap.auth.SearchDnResolver:200] -  
config = {java.naming.provider.url=ldap://localhost:389,
java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory}
00:33:50.031 - TRACE
[edu.vt.middleware.ldap.handler.FqdnSearchResultHandler:69] - processing
relative dn: uid=user.0,ou=People
00:33:50.031 - TRACE
[edu.vt.middleware.ldap.handler.FqdnSearchResultHandler:95] - processed dn:
uid=user.0,ou=People,ou=people,dc=example,dc=com
00:33:50.032 - TRACE [edu.vt.middleware.ldap.jaas.LdapLoginModule:208] -
Begin commit
00:33:50.033 - DEBUG [edu.vt.middleware.ldap.jaas.LdapLoginModule:223] -
Committed the following principals: [user.0[]]
00:33:50.033 - DEBUG [edu.vt.middleware.ldap.jaas.LdapLoginModule:229] -
Committed the following roles: []
00:33:50.033 - DEBUG
[edu.internet2.middleware.shibboleth.idp.authn.provider.UsernamePasswordLoginServlet:178]
- Successfully authenticated user user.0
00:33:50.034 - DEBUG
[edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine:144] -
Returning control to authentication engine
00:33:50.034 - TRACE
[edu.internet2.middleware.shibboleth.idp.util.HttpServletHelper:349] -
Looking up LoginContext with key
3a29f4c93a5fb16ec128d96be033891fab5ce01d57c7ae481ea50433c3f1e931 from
StorageService parition: loginContexts
00:33:50.034 - TRACE
[edu.internet2.middleware.shibboleth.idp.util.HttpServletHelper:355] -
Retrieved LoginContext with key
3a29f4c93a5fb16ec128d96be033891fab5ce01d57c7ae481ea50433c3f1e931 from
StorageService parition: loginContexts
00:33:50.034 - DEBUG
[edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine:209] -
Processing incoming request
00:33:50.035 - TRACE
[edu.internet2.middleware.shibboleth.idp.util.HttpServletHelper:349] -
Looking up LoginContext with key
3a29f4c93a5fb16ec128d96be033891fab5ce01d57c7ae481ea50433c3f1e931 from
StorageService parition: loginContexts
00:33:50.036 - TRACE
[edu.internet2.middleware.shibboleth.idp.util.HttpServletHelper:355] -
Retrieved LoginContext with key
3a29f4c93a5fb16ec128d96be033891fab5ce01d57c7ae481ea50433c3f1e931 from
StorageService parition: loginContexts
00:33:50.036 - DEBUG
[edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine:514] -
Completing user authentication process
00:33:50.036 - DEBUG
[edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine:585] -
Validating authentication was performed successfully
00:33:50.036 - DEBUG
[edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine:696] -
Updating session information for principal user.0
00:33:50.036 - DEBUG
[edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine:700] -
Creating shibboleth session for principal user.0
00:33:50.038 - TRACE
[edu.internet2.middleware.shibboleth.idp.session.impl.SessionManagerImpl:98]
- Created session
ec3ca827843a7628408860f30d5a6fb49c5282f048aa7f38885dd55b18306bf9
00:33:50.038 - DEBUG
[edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine:815] -
Adding IdP session cookie to HTTP response
00:33:50.039 - DEBUG
[edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine:715] -
Recording authentication and service information in Shibboleth session for
principal: user.0
00:33:50.040 - TRACE
[edu.internet2.middleware.shibboleth.idp.session.impl.SessionManagerImpl:173]
- Added index user.0 to session
ec3ca827843a7628408860f30d5a6fb49c5282f048aa7f38885dd55b18306bf9
00:33:50.041 - DEBUG
[edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine:560] -
User user.0 authenticated with method
urn:oasis:names:tc:SAML:2.0:ac:classes:PasswordProtectedTransport
00:33:50.042 - DEBUG
[edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine:161] -
Returning control to profile handler
00:33:50.042 - TRACE
[edu.internet2.middleware.shibboleth.idp.util.HttpServletHelper:349] -
Looking up LoginContext with key
3a29f4c93a5fb16ec128d96be033891fab5ce01d57c7ae481ea50433c3f1e931 from
StorageService parition: loginContexts
00:33:50.042 - TRACE
[edu.internet2.middleware.shibboleth.idp.util.HttpServletHelper:355] -
Retrieved LoginContext with key
3a29f4c93a5fb16ec128d96be033891fab5ce01d57c7ae481ea50433c3f1e931 from
StorageService parition: loginContexts
00:33:50.042 - DEBUG
[edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine:177] -
Redirecting user to profile handler at
https://localhost:553/idp/profile/SAML2/Redirect/SSO
00:33:50.047 - TRACE
[edu.internet2.middleware.shibboleth.idp.session.IdPSessionFilter:117] -
Attempting to retrieve IdP session cookie.
00:33:50.048 - TRACE
[edu.internet2.middleware.shibboleth.idp.session.IdPSessionFilter:123] -
Found IdP session cookie.
00:33:50.048 - TRACE
[edu.internet2.middleware.shibboleth.idp.session.IdPSessionFilter:81] -
Updating IdP session activity time and adding session object to the request
00:33:50.048 - INFO [Shibboleth-Access:73] -
20130917T190350Z|127.0.0.1|localhost:553|/profile/SAML2/Redirect/SSO|
00:33:50.048 - DEBUG
[edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:86]
- shibboleth.HandlerManager: Looking up profile handler for request path:
/SAML2/Redirect/SSO
00:33:50.048 - DEBUG
[edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:97]
- shibboleth.HandlerManager: Located profile handler of the following type
for the request path:
edu.internet2.middleware.shibboleth.idp.profile.saml2.SSOProfileHandler
00:33:50.049 - TRACE
[edu.internet2.middleware.shibboleth.idp.util.HttpServletHelper:349] -
Looking up LoginContext with key
3a29f4c93a5fb16ec128d96be033891fab5ce01d57c7ae481ea50433c3f1e931 from
StorageService parition: loginContexts
00:33:50.049 - TRACE
[edu.internet2.middleware.shibboleth.idp.util.HttpServletHelper:355] -
Retrieved LoginContext with key
3a29f4c93a5fb16ec128d96be033891fab5ce01d57c7ae481ea50433c3f1e931 from
StorageService parition: loginContexts
00:33:50.049 - DEBUG
[edu.internet2.middleware.shibboleth.idp.util.HttpServletHelper:588] -
Unbinding LoginContext
00:33:50.049 - DEBUG
[edu.internet2.middleware.shibboleth.idp.util.HttpServletHelper:614] -
Expiring LoginContext cookie
00:33:50.049 - DEBUG
[edu.internet2.middleware.shibboleth.idp.util.HttpServletHelper:625] -
Removed LoginContext, with key
3a29f4c93a5fb16ec128d96be033891fab5ce01d57c7ae481ea50433c3f1e931, from
StorageService partition loginContexts
00:33:50.049 - DEBUG
[edu.internet2.middleware.shibboleth.idp.profile.saml2.SSOProfileHandler:172]
- Incoming request contains a login context and indicates principal was
authenticated, processing second leg of request
00:33:50.049 - DEBUG
[org.opensaml.saml2.metadata.provider.ChainingMetadataProvider:253] -
Checking child metadata provider for entity descriptor with entity ID:
https://192.168.2.4:444/shibboleth
00:33:50.049 - DEBUG
[org.opensaml.saml2.metadata.provider.AbstractMetadataProvider:520] -
Searching for entity descriptor with an entity ID of
https://192.168.2.4:444/shibboleth
00:33:50.050 - TRACE
[org.opensaml.saml2.metadata.provider.AbstractMetadataProvider:524] - Entity
descriptor for the ID https://192.168.2.4:444/shibboleth was found in index
cache, returning
00:33:50.050 - DEBUG
[org.opensaml.saml2.metadata.provider.ChainingMetadataProvider:253] -
Checking child metadata provider for entity descriptor with entity ID:
https://192.168.2.4:444/shibboleth
00:33:50.050 - DEBUG
[org.opensaml.saml2.metadata.provider.AbstractMetadataProvider:520] -
Searching for entity descriptor with an entity ID of
https://192.168.2.4:444/shibboleth
00:33:50.050 - TRACE
[org.opensaml.saml2.metadata.provider.AbstractMetadataProvider:524] - Entity
descriptor for the ID https://192.168.2.4:444/shibboleth was found in index
cache, returning
00:33:50.050 - DEBUG
[edu.internet2.middleware.shibboleth.common.relyingparty.provider.SAMLMDRelyingPartyConfigurationManager:128]
- Looking up relying party configuration for
https://192.168.2.4:444/shibboleth
00:33:50.050 - DEBUG
[edu.internet2.middleware.shibboleth.common.relyingparty.provider.SAMLMDRelyingPartyConfigurationManager:134]
- No custom relying party configuration found for
https://192.168.2.4:444/shibboleth, looking up configuration based on
metadata groups.
00:33:50.050 - DEBUG
[org.opensaml.saml2.metadata.provider.ChainingMetadataProvider:253] -
Checking child metadata provider for entity descriptor with entity ID:
https://192.168.2.4:444/shibboleth
00:33:50.050 - DEBUG
[org.opensaml.saml2.metadata.provider.AbstractMetadataProvider:520] -
Searching for entity descriptor with an entity ID of
https://192.168.2.4:444/shibboleth
00:33:50.050 - TRACE
[org.opensaml.saml2.metadata.provider.AbstractMetadataProvider:524] - Entity
descriptor for the ID https://192.168.2.4:444/shibboleth was found in index
cache, returning
00:33:50.050 - DEBUG
[edu.internet2.middleware.shibboleth.common.relyingparty.provider.SAMLMDRelyingPartyConfigurationManager:157]
- No custom or group-based relying party configuration found for
https://192.168.2.4:444/shibboleth. Using default relying party
configuration.
00:33:50.051 - DEBUG
[org.opensaml.saml2.metadata.provider.ChainingMetadataProvider:253] -
Checking child metadata provider for entity descriptor with entity ID:
https://localhost:553/idp/shibboleth
00:33:50.051 - DEBUG
[org.opensaml.saml2.metadata.provider.AbstractMetadataProvider:520] -
Searching for entity descriptor with an entity ID of
https://localhost:553/idp/shibboleth
00:33:50.051 - TRACE
[org.opensaml.saml2.metadata.provider.AbstractMetadataProvider:533] -
Metadata root is an entity descriptor, checking if it's the one we're
looking for.
00:33:50.051 - TRACE
[org.opensaml.saml2.metadata.provider.AbstractMetadataProvider:540] - Found
entity descriptor for entity with ID https://localhost:553/idp/shibboleth
but it is no longer valid, skipping it.
00:33:50.051 - DEBUG
[org.opensaml.saml2.metadata.provider.AbstractMetadataProvider:167] -
Metadata document does not contain an EntityDescriptor with the ID
https://localhost:553/idp/shibboleth
00:33:50.051 - TRACE [org.opensaml.xml.io.AbstractXMLObjectUnmarshaller:95]
- Starting to unmarshall DOM element
{urn:oasis:names:tc:SAML:2.0:protocol}AuthnRequest
00:33:50.051 - TRACE [org.opensaml.xml.io.AbstractXMLObjectUnmarshaller:152]
- Targeted QName checking is not available for this unmarshaller, DOM
Element {urn:oasis:names:tc:SAML:2.0:protocol}AuthnRequest was not verified
00:33:50.052 - TRACE [org.opensaml.xml.io.AbstractXMLObjectUnmarshaller:194]
- Building XMLObject for {urn:oasis:names:tc:SAML:2.0:protocol}AuthnRequest
00:33:50.052 - TRACE [org.opensaml.xml.io.AbstractXMLObjectUnmarshaller:103]
- Unmarshalling attributes of DOM Element
{urn:oasis:names:tc:SAML:2.0:protocol}AuthnRequest
00:33:50.052 - TRACE [org.opensaml.xml.io.AbstractXMLObjectUnmarshaller:230]
- Pre-processing attribute AssertionConsumerServiceURL
00:33:50.052 - TRACE [org.opensaml.xml.io.AbstractXMLObjectUnmarshaller:239]
- Attribute AssertionConsumerServiceURL is neither a schema type nor
namespace, calling processAttribute()
00:33:50.052 - TRACE [org.opensaml.xml.io.AbstractXMLObjectUnmarshaller:230]
- Pre-processing attribute Destination
00:33:50.052 - TRACE [org.opensaml.xml.io.AbstractXMLObjectUnmarshaller:239]
- Attribute Destination is neither a schema type nor namespace, calling
processAttribute()
00:33:50.052 - TRACE [org.opensaml.xml.io.AbstractXMLObjectUnmarshaller:230]
- Pre-processing attribute ID
00:33:50.052 - TRACE [org.opensaml.xml.io.AbstractXMLObjectUnmarshaller:239]
- Attribute ID is neither a schema type nor namespace, calling
processAttribute()
00:33:50.052 - TRACE [org.opensaml.xml.io.AbstractXMLObjectUnmarshaller:230]
- Pre-processing attribute IssueInstant
00:33:50.052 - TRACE [org.opensaml.xml.io.AbstractXMLObjectUnmarshaller:239]
- Attribute IssueInstant is neither a schema type nor namespace, calling
processAttribute()
00:33:50.053 - TRACE [org.opensaml.xml.io.AbstractXMLObjectUnmarshaller:230]
- Pre-processing attribute ProtocolBinding
00:33:50.053 - TRACE [org.opensaml.xml.io.AbstractXMLObjectUnmarshaller:239]
- Attribute ProtocolBinding is neither a schema type nor namespace, calling
processAttribute()
00:33:50.053 - TRACE [org.opensaml.xml.io.AbstractXMLObjectUnmarshaller:230]
- Pre-processing attribute Version
00:33:50.053 - TRACE [org.opensaml.xml.io.AbstractXMLObjectUnmarshaller:239]
- Attribute Version is neither a schema type nor namespace, calling
processAttribute()
00:33:50.053 - TRACE [org.opensaml.xml.io.AbstractXMLObjectUnmarshaller:230]
- Pre-processing attribute {http://www.w3.org/2000/xmlns/}samlp
00:33:50.053 - TRACE [org.opensaml.xml.io.AbstractXMLObjectUnmarshaller:266]
- {http://www.w3.org/2000/xmlns/}samlp is a namespace declaration, adding it
to the list of namespaces on the XMLObject
00:33:50.053 - TRACE [org.opensaml.xml.io.AbstractXMLObjectUnmarshaller:118]
- Unmarshalling other child nodes of DOM Element
{urn:oasis:names:tc:SAML:2.0:protocol}AuthnRequest
00:33:50.053 - TRACE [org.opensaml.xml.io.AbstractXMLObjectUnmarshaller:332]
- Unmarshalling child elements of XMLObject
{urn:oasis:names:tc:SAML:2.0:protocol}AuthnRequest
00:33:50.053 - TRACE [org.opensaml.xml.io.AbstractXMLObjectUnmarshaller:352]
- Unmarshalling child element
{urn:oasis:names:tc:SAML:2.0:assertion}Issuerwith unmarshaller
org.opensaml.saml2.core.impl.IssuerUnmarshaller
00:33:50.054 - TRACE [org.opensaml.xml.io.AbstractXMLObjectUnmarshaller:95]
- Starting to unmarshall DOM element
{urn:oasis:names:tc:SAML:2.0:assertion}Issuer
00:33:50.054 - TRACE [org.opensaml.xml.io.AbstractXMLObjectUnmarshaller:152]
- Targeted QName checking is not available for this unmarshaller, DOM
Element {urn:oasis:names:tc:SAML:2.0:assertion}Issuer was not verified
00:33:50.054 - TRACE [org.opensaml.xml.io.AbstractXMLObjectUnmarshaller:194]
- Building XMLObject for {urn:oasis:names:tc:SAML:2.0:assertion}Issuer
00:33:50.054 - TRACE [org.opensaml.xml.io.AbstractXMLObjectUnmarshaller:103]
- Unmarshalling attributes of DOM Element
{urn:oasis:names:tc:SAML:2.0:assertion}Issuer
00:33:50.054 - TRACE [org.opensaml.xml.io.AbstractXMLObjectUnmarshaller:230]
- Pre-processing attribute {http://www.w3.org/2000/xmlns/}saml
00:33:50.054 - TRACE [org.opensaml.xml.io.AbstractXMLObjectUnmarshaller:266]
- {http://www.w3.org/2000/xmlns/}saml is a namespace declaration, adding it
to the list of namespaces on the XMLObject
00:33:50.054 - TRACE [org.opensaml.xml.io.AbstractXMLObjectUnmarshaller:118]
- Unmarshalling other child nodes of DOM Element
{urn:oasis:names:tc:SAML:2.0:assertion}Issuer
00:33:50.054 - TRACE [org.opensaml.xml.io.AbstractXMLObjectUnmarshaller:332]
- Unmarshalling child elements of XMLObject
{urn:oasis:names:tc:SAML:2.0:protocol}AuthnRequest
00:33:50.054 - TRACE [org.opensaml.xml.io.AbstractXMLObjectUnmarshaller:352]
- Unmarshalling child element
{urn:oasis:names:tc:SAML:2.0:protocol}NameIDPolicywith unmarshaller
org.opensaml.saml2.core.impl.NameIDPolicyUnmarshaller
00:33:50.054 - TRACE [org.opensaml.xml.io.AbstractXMLObjectUnmarshaller:95]
- Starting to unmarshall DOM element
{urn:oasis:names:tc:SAML:2.0:protocol}NameIDPolicy
00:33:50.054 - TRACE [org.opensaml.xml.io.AbstractXMLObjectUnmarshaller:152]
- Targeted QName checking is not available for this unmarshaller, DOM
Element {urn:oasis:names:tc:SAML:2.0:protocol}NameIDPolicy was not verified
00:33:50.055 - TRACE [org.opensaml.xml.io.AbstractXMLObjectUnmarshaller:194]
- Building XMLObject for {urn:oasis:names:tc:SAML:2.0:protocol}NameIDPolicy
00:33:50.055 - TRACE [org.opensaml.xml.io.AbstractXMLObjectUnmarshaller:103]
- Unmarshalling attributes of DOM Element
{urn:oasis:names:tc:SAML:2.0:protocol}NameIDPolicy
00:33:50.055 - TRACE [org.opensaml.xml.io.AbstractXMLObjectUnmarshaller:230]
- Pre-processing attribute AllowCreate
00:33:50.055 - TRACE [org.opensaml.xml.io.AbstractXMLObjectUnmarshaller:239]
- Attribute AllowCreate is neither a schema type nor namespace, calling
processAttribute()
00:33:50.055 - TRACE [org.opensaml.xml.io.AbstractXMLObjectUnmarshaller:118]
- Unmarshalling other child nodes of DOM Element
{urn:oasis:names:tc:SAML:2.0:protocol}NameIDPolicy
00:33:50.057 - DEBUG
[org.opensaml.saml2.binding.AuthnResponseEndpointSelector:99] - Filtering
peer endpoints.  Supported peer endpoint bindings:
[urn:oasis:names:tc:SAML:2.0:bindings:HTTP-POST-SimpleSign,
urn:oasis:names:tc:SAML:2.0:bindings:HTTP-POST,
urn:oasis:names:tc:SAML:2.0:bindings:HTTP-Artifact]
00:33:50.058 - DEBUG
[org.opensaml.saml2.binding.AuthnResponseEndpointSelector:114] - Removing
endpoint https://localhost:444/Shibboleth.sso/SAML2/ECP because its binding
urn:oasis:names:tc:SAML:2.0:bindings:PAOS is not supported
00:33:50.058 - DEBUG
[org.opensaml.saml2.binding.AuthnResponseEndpointSelector:114] - Removing
endpoint https://localhost:444/Shibboleth.sso/SAML/POST because its binding
urn:oasis:names:tc:SAML:1.0:profiles:browser-post is not supported
00:33:50.058 - DEBUG
[org.opensaml.saml2.binding.AuthnResponseEndpointSelector:114] - Removing
endpoint https://localhost:444/Shibboleth.sso/SAML/Artifact because its
binding urn:oasis:names:tc:SAML:1.0:profiles:artifact-01 is not supported
00:33:50.058 - DEBUG
[org.opensaml.saml2.binding.AuthnResponseEndpointSelector:69] - Selecting
endpoint by ACS URL 'https://localhost:444/Shibboleth.sso/SAML2/POST' and
protocol binding 'urn:oasis:names:tc:SAML:2.0:bindings:HTTP-POST' for
request '_d1ba311129d889f88fb5f773ef0175a1' from entity
'https://192.168.2.4:444/shibboleth'
00:33:50.058 - DEBUG
[edu.internet2.middleware.shibboleth.idp.profile.saml2.AbstractSAML2ProfileHandler:478]
- Resolving attributes for principal 'user.0' for SAML request from relying
party 'https://192.168.2.4:444/shibboleth'
00:33:50.060 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:119]
- shibboleth.AttributeResolver resolving attributes for principal user.0
00:33:50.060 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:275]
- Specific attributes for principal user.0 were not requested, resolving all
attributes.
00:33:50.060 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:314]
- Resolving attribute uid for principal user.0
00:33:50.061 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:354]
- Resolving data connector myldapdc for principal user.0
00:33:50.062 - TRACE
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.dataConnector.TemplateEngine:119]
- Populating velocity context
00:33:50.066 - TRACE
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.dataConnector.TemplateEngine:93]
- Populating the following shibboleth.resolver.dc.myldapdc template
00:33:50.077 - DEBUG [org.apache.velocity:99] - ResourceManager : found
shibboleth.resolver.dc.myldapdc with loader
org.apache.velocity.runtime.resource.loader.StringResourceLoader
00:33:50.084 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.dataConnector.LdapDataConnector:308]
- Search filter: (uid=user.0)
00:33:50.084 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.dataConnector.LdapDataConnector:363]
- LDAP data connector myldapdc - Retrieving attributes from LDAP
00:33:50.084 - TRACE
[edu.vt.middleware.ldap.handler.DefaultConnectionHandler:93] - setting
connectionStrategy: ACTIVE_PASSIVE
00:33:50.085 - TRACE
[edu.vt.middleware.ldap.handler.DefaultConnectionHandler:110] - setting
connectionRetryExceptions: [class javax.naming.NamingException]
00:33:50.085 - TRACE
[edu.vt.middleware.ldap.handler.DefaultConnectionHandler:152] - {2}
Attempting connection to ldap://localhost:389 for strategy ACTIVE_PASSIVE
00:33:50.085 - DEBUG
[edu.vt.middleware.ldap.handler.DefaultConnectionHandler:74] - Bind with the
following parameters:
00:33:50.085 - DEBUG
[edu.vt.middleware.ldap.handler.DefaultConnectionHandler:75] -   authtype =
simple
00:33:50.085 - DEBUG
[edu.vt.middleware.ldap.handler.DefaultConnectionHandler:76] -   dn =
cn=Directory Manager
00:33:50.085 - DEBUG
[edu.vt.middleware.ldap.handler.DefaultConnectionHandler:83] -   credential
= <suppressed>
00:33:50.085 - TRACE
[edu.vt.middleware.ldap.handler.DefaultConnectionHandler:87] -   env =
{java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory,
java.naming.provider.url=ldap://localhost:389}
00:33:50.088 - DEBUG [edu.vt.middleware.ldap.Ldap:193] - Search with the
following parameters:
00:33:50.088 - DEBUG [edu.vt.middleware.ldap.Ldap:194] -   dn =
ou=people,dc=example,dc=com
00:33:50.088 - DEBUG [edu.vt.middleware.ldap.Ldap:195] -   filter =
(uid=user.0)
00:33:50.089 - DEBUG [edu.vt.middleware.ldap.Ldap:196] -   filterArgs = []
00:33:50.089 - DEBUG [edu.vt.middleware.ldap.Ldap:197] -   searchControls =
javax.naming.directory.SearchControls at 17bb14a
00:33:50.089 - DEBUG [edu.vt.middleware.ldap.Ldap:198] -   handler =
[edu.vt.middleware.ldap.handler.FqdnSearchResultHandler at 1931514,
edu.vt.middleware.ldap.handler.EntryDnSearchResultHandler at 14d0d46,
edu.vt.middleware.ldap.handler.BinarySearchResultHandler at 1a27fbe]
00:33:50.089 - TRACE [edu.vt.middleware.ldap.Ldap:200] -   config =
{java.naming.provider.url=ldap://localhost:389,
java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory}
00:33:50.092 - TRACE
[edu.vt.middleware.ldap.handler.FqdnSearchResultHandler:69] - processing
relative dn: uid=user.0,ou=People
00:33:50.092 - TRACE
[edu.vt.middleware.ldap.handler.FqdnSearchResultHandler:95] - processed dn:
uid=user.0,ou=People,ou=people,dc=example,dc=com
00:33:50.098 - TRACE [edu.vt.middleware.ldap.pool.DefaultLdapFactory:123] -
destroyed ldap object:
edu.vt.middleware.ldap.Ldap at 15156255::config=edu.vt.middleware.ldap.LdapConfig at 10282000::env={java.naming.provider.url=ldap://localhost:389,
java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory}
00:33:50.100 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.dataConnector.LdapDataConnector:414]
- LDAP data connector myldapdc - Found the following attribute: pager[+1 779
041 6341]
00:33:50.100 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.dataConnector.LdapDataConnector:414]
- LDAP data connector myldapdc - Found the following attribute: uid[user.0]
00:33:50.100 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.dataConnector.LdapDataConnector:414]
- LDAP data connector myldapdc - Found the following attribute:
mail[user.0 at maildomain.net]
00:33:50.100 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.dataConnector.LdapDataConnector:414]
- LDAP data connector myldapdc - Found the following attribute: sn[Amar]
00:33:50.101 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.dataConnector.LdapDataConnector:414]
- LDAP data connector myldapdc - Found the following attribute: street[01251
Chestnut Street]
00:33:50.101 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.dataConnector.LdapDataConnector:414]
- LDAP data connector myldapdc - Found the following attribute:
userPassword[e1NTSEF9WlFIOFUyZDI5b1o1WGVuUW1DV1o5bHJ1RXczMU5MNTRlUjBJT1E9PQ==]
00:33:50.101 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.dataConnector.LdapDataConnector:414]
- LDAP data connector myldapdc - Found the following attribute:
entryDN[uid=user.0,ou=People,ou=people,dc=example,dc=com]
00:33:50.101 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.dataConnector.LdapDataConnector:414]
- LDAP data connector myldapdc - Found the following attribute: l[Panama
City]
00:33:50.101 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.dataConnector.LdapDataConnector:414]
- LDAP data connector myldapdc - Found the following attribute:
objectClass[person, inetorgperson, organizationalperson, top]
00:33:50.101 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.dataConnector.LdapDataConnector:414]
- LDAP data connector myldapdc - Found the following attribute:
givenName[Aaccf]
00:33:50.101 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.dataConnector.LdapDataConnector:414]
- LDAP data connector myldapdc - Found the following attribute: homePhone[+1
225 216 5900]
00:33:50.101 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.dataConnector.LdapDataConnector:414]
- LDAP data connector myldapdc - Found the following attribute:
postalCode[50369]
00:33:50.102 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.dataConnector.LdapDataConnector:414]
- LDAP data connector myldapdc - Found the following attribute: cn[Aaccf
Amar]
00:33:50.102 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.dataConnector.LdapDataConnector:414]
- LDAP data connector myldapdc - Found the following attribute:
initials[ASA]
00:33:50.102 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.dataConnector.LdapDataConnector:414]
- LDAP data connector myldapdc - Found the following attribute:
description[This is the description for Aaccf Amar.]
00:33:50.102 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.dataConnector.LdapDataConnector:414]
- LDAP data connector myldapdc - Found the following attribute:
telephoneNumber[+1 685 622 6202]
00:33:50.102 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.dataConnector.LdapDataConnector:414]
- LDAP data connector myldapdc - Found the following attribute:
postalAddress[Aaccf Amar$01251 Chestnut Street$Panama City, DE  50369]
00:33:50.102 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.dataConnector.LdapDataConnector:414]
- LDAP data connector myldapdc - Found the following attribute: st[DE]
00:33:50.102 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.dataConnector.LdapDataConnector:414]
- LDAP data connector myldapdc - Found the following attribute:
employeeNumber[0]
00:33:50.103 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.dataConnector.LdapDataConnector:414]
- LDAP data connector myldapdc - Found the following attribute: mobile[+1
010 154 3228]
00:33:50.103 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:336]
- Resolved attribute uid containing 1 values
00:33:50.103 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:314]
- Resolving attribute commonName for principal user.0
00:33:50.103 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:336]
- Resolved attribute commonName containing 1 values
00:33:50.103 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:314]
- Resolving attribute homePostalAddress for principal user.0
00:33:50.103 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:336]
- Resolved attribute homePostalAddress containing 0 values
00:33:50.103 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:314]
- Resolving attribute organizationName for principal user.0
00:33:50.103 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:336]
- Resolved attribute organizationName containing 0 values
00:33:50.103 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:314]
- Resolving attribute transientId for principal user.0
00:33:50.104 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.attributeDefinition.TransientIdAttributeDefinition:97]
- Building transient ID for request _d1ba311129d889f88fb5f773ef0175a1;
outbound message issuer: https://localhost:553/idp/shibboleth, inbound
message issuer: https://192.168.2.4:444/shibboleth, principal identifer:
user.0
00:33:50.104 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.attributeDefinition.TransientIdAttributeDefinition:115]
- Created transient ID _feb7060aeb1593924aae3035cba274bc for request
_d1ba311129d889f88fb5f773ef0175a1
00:33:50.104 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:336]
- Resolved attribute transientId containing 1 values
00:33:50.104 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:314]
- Resolving attribute street for principal user.0
00:33:50.104 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:336]
- Resolved attribute street containing 1 values
00:33:50.104 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:314]
- Resolving attribute surname for principal user.0
00:33:50.104 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:336]
- Resolved attribute surname containing 1 values
00:33:50.104 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:314]
- Resolving attribute givenName for principal user.0
00:33:50.105 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:336]
- Resolved attribute givenName containing 1 values
00:33:50.105 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:314]
- Resolving attribute homePhone for principal user.0
00:33:50.105 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:336]
- Resolved attribute homePhone containing 1 values
00:33:50.105 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:314]
- Resolving attribute title for principal user.0
00:33:50.105 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:336]
- Resolved attribute title containing 0 values
00:33:50.105 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:314]
- Resolving attribute postalCode for principal user.0
00:33:50.105 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:336]
- Resolved attribute postalCode containing 1 values
00:33:50.105 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:314]
- Resolving attribute initials for principal user.0
00:33:50.105 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:336]
- Resolved attribute initials containing 1 values
00:33:50.105 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:314]
- Resolving attribute email for principal user.0
00:33:50.106 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:336]
- Resolved attribute email containing 1 values
00:33:50.106 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:314]
- Resolving attribute telephoneNumber for principal user.0
00:33:50.106 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:336]
- Resolved attribute telephoneNumber containing 1 values
00:33:50.106 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:314]
- Resolving attribute pagerNumber for principal user.0
00:33:50.106 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:336]
- Resolved attribute pagerNumber containing 1 values
00:33:50.106 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:314]
- Resolving attribute postalAddress for principal user.0
00:33:50.106 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:336]
- Resolved attribute postalAddress containing 1 values
00:33:50.106 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:314]
- Resolving attribute locality for principal user.0
00:33:50.106 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:336]
- Resolved attribute locality containing 1 values
00:33:50.106 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:314]
- Resolving attribute stateProvince for principal user.0
00:33:50.107 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:336]
- Resolved attribute stateProvince containing 1 values
00:33:50.107 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:314]
- Resolving attribute postOfficeBox for principal user.0
00:33:50.107 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:336]
- Resolved attribute postOfficeBox containing 0 values
00:33:50.107 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:314]
- Resolving attribute mobileNumber for principal user.0
00:33:50.107 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:336]
- Resolved attribute mobileNumber containing 1 values
00:33:50.107 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:314]
- Resolving attribute organizationalUnit for principal user.0
00:33:50.107 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:336]
- Resolved attribute organizationalUnit containing 0 values
00:33:50.107 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:468]
- Attribute uid has 1 values after post-processing
00:33:50.107 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:468]
- Attribute commonName has 1 values after post-processing
00:33:50.108 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:450]
- Removing attribute homePostalAddress from resolution result for principal
user.0.  It contains no values.
00:33:50.108 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:450]
- Removing attribute organizationName from resolution result for principal
user.0.  It contains no values.
00:33:50.108 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:468]
- Attribute transientId has 1 values after post-processing
00:33:50.108 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:468]
- Attribute street has 1 values after post-processing
00:33:50.108 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:468]
- Attribute surname has 1 values after post-processing
00:33:50.108 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:468]
- Attribute givenName has 1 values after post-processing
00:33:50.108 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:468]
- Attribute homePhone has 1 values after post-processing
00:33:50.108 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:450]
- Removing attribute title from resolution result for principal user.0.  It
contains no values.
00:33:50.108 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:468]
- Attribute postalCode has 1 values after post-processing
00:33:50.108 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:468]
- Attribute initials has 1 values after post-processing
00:33:50.108 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:468]
- Attribute email has 1 values after post-processing
00:33:50.109 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:468]
- Attribute telephoneNumber has 1 values after post-processing
00:33:50.109 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:468]
- Attribute pagerNumber has 1 values after post-processing
00:33:50.109 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:468]
- Attribute stateProvince has 1 values after post-processing
00:33:50.109 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:468]
- Attribute locality has 1 values after post-processing
00:33:50.109 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:468]
- Attribute postalAddress has 1 values after post-processing
00:33:50.109 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:468]
- Attribute mobileNumber has 1 values after post-processing
00:33:50.109 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:450]
- Removing attribute postOfficeBox from resolution result for principal
user.0.  It contains no values.
00:33:50.109 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:450]
- Removing attribute organizationalUnit from resolution result for principal
user.0.  It contains no values.
00:33:50.109 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:137]
- shibboleth.AttributeResolver resolved, for principal user.0, the
attributes: [uid, commonName, transientId, street, surname, givenName,
homePhone, postalCode, initials, email, telephoneNumber, pagerNumber,
stateProvince, locality, postalAddress, mobileNumber]
00:33:50.109 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.filtering.provider.ShibbolethAttributeFilteringEngine:71]
- shibboleth.AttributeFilterEngine filtering 16 attributes for principal
user.0
00:33:50.110 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.filtering.provider.ShibbolethAttributeFilteringEngine:130]
- Evaluating if filter policy releaseTransientIdToAnyone is active for
principal user.0
00:33:50.110 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.filtering.provider.ShibbolethAttributeFilteringEngine:139]
- Filter policy releaseTransientIdToAnyone is active for principal user.0
00:33:50.110 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.filtering.provider.ShibbolethAttributeFilteringEngine:163]
- Processing permit value rule for attribute transientId for principal
user.0
00:33:50.110 - TRACE
[edu.internet2.middleware.shibboleth.common.attribute.filtering.provider.ShibbolethAttributeFilteringEngine:174]
- The following value for attribute transientId meets the permit value rule:
_feb7060aeb1593924aae3035cba274bc
00:33:50.110 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.filtering.provider.ShibbolethAttributeFilteringEngine:130]
- Evaluating if filter policy mikefilter is active for principal user.0
00:33:50.110 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.filtering.provider.ShibbolethAttributeFilteringEngine:134]
- Filter policy mikefilter is not active for principal user.0
00:33:50.110 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.filtering.provider.ShibbolethAttributeFilteringEngine:106]
- Removing attribute from return set, no more values: uid
00:33:50.111 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.filtering.provider.ShibbolethAttributeFilteringEngine:106]
- Removing attribute from return set, no more values: commonName
00:33:50.111 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.filtering.provider.ShibbolethAttributeFilteringEngine:109]
- Attribute transientId has 1 values after filtering
00:33:50.111 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.filtering.provider.ShibbolethAttributeFilteringEngine:106]
- Removing attribute from return set, no more values: street
00:33:50.111 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.filtering.provider.ShibbolethAttributeFilteringEngine:106]
- Removing attribute from return set, no more values: surname
00:33:50.111 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.filtering.provider.ShibbolethAttributeFilteringEngine:106]
- Removing attribute from return set, no more values: givenName
00:33:50.111 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.filtering.provider.ShibbolethAttributeFilteringEngine:106]
- Removing attribute from return set, no more values: homePhone
00:33:50.111 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.filtering.provider.ShibbolethAttributeFilteringEngine:106]
- Removing attribute from return set, no more values: postalCode
00:33:50.111 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.filtering.provider.ShibbolethAttributeFilteringEngine:106]
- Removing attribute from return set, no more values: initials
00:33:50.111 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.filtering.provider.ShibbolethAttributeFilteringEngine:106]
- Removing attribute from return set, no more values: email
00:33:50.111 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.filtering.provider.ShibbolethAttributeFilteringEngine:106]
- Removing attribute from return set, no more values: telephoneNumber
00:33:50.112 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.filtering.provider.ShibbolethAttributeFilteringEngine:106]
- Removing attribute from return set, no more values: pagerNumber
00:33:50.112 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.filtering.provider.ShibbolethAttributeFilteringEngine:106]
- Removing attribute from return set, no more values: stateProvince
00:33:50.112 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.filtering.provider.ShibbolethAttributeFilteringEngine:106]
- Removing attribute from return set, no more values: locality
00:33:50.112 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.filtering.provider.ShibbolethAttributeFilteringEngine:106]
- Removing attribute from return set, no more values: postalAddress
00:33:50.112 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.filtering.provider.ShibbolethAttributeFilteringEngine:106]
- Removing attribute from return set, no more values: mobileNumber
00:33:50.112 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.filtering.provider.ShibbolethAttributeFilteringEngine:114]
- Filtered attributes for principal user.0.  The following attributes
remain: [transientId]
00:33:50.115 - DEBUG
[edu.internet2.middleware.shibboleth.idp.profile.saml2.AbstractSAML2ProfileHandler:505]
- Creating attribute statement in response to SAML request
'_d1ba311129d889f88fb5f773ef0175a1' from relying party
'https://192.168.2.4:444/shibboleth'
00:33:50.115 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.provider.ShibbolethSAML2AttributeAuthority:263]
- Attribute transientId was not encoded (filtered by query, or no
SAML2AttributeEncoder attached).
00:33:50.115 - DEBUG
[edu.internet2.middleware.shibboleth.common.attribute.provider.ShibbolethSAML2AttributeAuthority:129]
- No attributes remained after encoding and filtering by value, no attribute
statement built




--
View this message in context: http://shibboleth.1660669.n2.nabble.com/Shibboleth-support-in-my-application-tp7589693p7590036.html
Sent from the Shibboleth - Users mailing list archive at Nabble.com.

More information about the users mailing list