Issue with a ServiceProvider authenticating against testshib.org IdP

Alessandro Molina alessandro.molina at axant.it
Mon Oct 5 12:19:58 EDT 2015


I'm currently trying to check a ServiceProvider configuration against 
testshib.org (using testshib.org as an IdP),
but testshib.org si currently failing with the following traceback:

12:07:04.650 - ERROR 
[edu.internet2.middleware.shibboleth.idp.profile.saml2.AbstractSAML2ProfileHandler:927] 
- Could not resolve a key encryption credential for peer entity: 
https://localhost/sprovide.xml
12:07:04.651 - ERROR 
[edu.internet2.middleware.shibboleth.idp.profile.saml2.AbstractSAML2ProfileHandler:289] 
- Unable to construct encrypter
org.opensaml.xml.security.SecurityException: Could not resolve key 
encryption credential
     at 
edu.internet2.middleware.shibboleth.idp.profile.saml2.AbstractSAML2ProfileHandler.getEncrypter(AbstractSAML2ProfileHandler.java:928) 
~[shibboleth-identityprovider-2.4.0.jar:na]
     at 
edu.internet2.middleware.shibboleth.idp.profile.saml2.AbstractSAML2ProfileHandler.buildResponse(AbstractSAML2ProfileHandler.java:286) 
~[shibboleth-identityprovider-2.4.0.jar:na]

I'm able to get to the login page and login with the myself-myself user, 
but then that traceback is produced when trying to send back the answer 
to my application.
Here is the service provider .xml file uploaded to 
http://www.testshib.org/register.html

<?xml version='1.0' encoding='UTF-8'?>
<ns0:EntityDescriptor xmlns:ns0="urn:oasis:names:tc:SAML:2.0:metadata" 
xmlns:xs="http://www.w3.org/2001/XMLSchema"
xmlns:ns1="urn:oasis:names:tc:SAML:metadata:attribute"
xmlns:ns2="urn:oasis:names:tc:SAML:2.0:assertion" 
xmlns:ns4="http://www.w3.org/2000/09/xmldsig#"
xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" 
entityID="https://localhost/sprovide.xml">
     <ns0:Extensions>
         <ns1:EntityAttributes>
             <ns2:Attribute Name="http://macedir.org/entity-category"
NameFormat="urn:oasis:names:tc:SAML:2.0:attrname-format:uri">
                 <ns2:AttributeValue 
xsi:type="xs:string">http://www.geant.net/uri/dataprotection-code-of-conduct/v1
                 </ns2:AttributeValue>
             </ns2:Attribute>
         </ns1:EntityAttributes>
     </ns0:Extensions>
     <ns0:SPSSODescriptor AuthnRequestsSigned="false" 
WantAssertionsSigned="true"
protocolSupportEnumeration="urn:oasis:names:tc:SAML:2.0:protocol">
         <ns0:KeyDescriptor use="signing">
             <ns4:KeyInfo>
                 <ns4:X509Data>
<ns4:X509Certificate>MIIC7zCCAdegAwIBAgIJAKNUFVpcL0KLMA0GCSqGSIb3DQEBBQUAMBIxEDAOBgNV
BAMTB0xQdWxzYXIwHhcNMTUxMDA1MTYwNTAyWhcNMjUxMDAyMTYwNTAyWjASMRAw
DgYDVQQDEwdMUHVsc2FyMIIBIjANBgkqhkiG9w0BAQEFAAOCAQ8AMIIBCgKCAQEA
04Dvyk0OAmkcjFIzptAJyluGcfP8WsmdE01XOvIV0bi40Cc1c3SCfdXM+AU7kiz6
Ew37m9kXz1FbIw9n9Zsv3ImJ7lqQ1/ZKUkzB/Aj49p85XsoqMwtRq8Zwun9sLAME
+sjWh4+OyQH2Dr/Na7WnafuuYeIl72rFAoUg2IDEodZ5b204suKp1qi0GQwYm2Jp
Ahh0f46RhXawcYVmTMPUS6XQjJ+WH95sDxxxV6Yjfw7d3uZNQ+cNAec7hFxSSAka
nShkimm6KfC5x04jgjz1YA4iNXPoj2Pi2E0l3EBl16qBmhjXoppagriHfN+xIxcD
hEggCSaYLui2Qm/8maeqQwIDAQABo0gwRjAlBgNVHREEHjAcggdMUHVsc2FyhhFo
dHRwczovL2xvY2FsaG9zdDAdBgNVHQ4EFgQUQbbmEqIJlFT8GRdSPE56N+dGZi8w
DQYJKoZIhvcNAQEFBQADggEBAC8jKuZWkHx/AhM1GL2vHq/h9SxHoHFcyYDipVyC
Ql5VB5PjTaLdQ9RZCtJhlJa75DeVfW6hncDY5Q2phb7MwH2GfWm/bZwmPyfwsEeI
uzOcfyWU24582ITtWBNGkaxkE3uI5cDRvmKfO6fTrAdvw+emtVzYOUcAxzqz0PAQ
B5f2jLbg2sTLB6d4KawGPoq3JtVXPgagIANZ5IsR/dem3FIsZFj8nsztibFFTH/O
ljUAfZledVW5KIfApmHMc4qLvAuSSOSmax6ksBjPE4LVZx/9iftHQOMsucW1O4Ob
ykh4ttyYdRoNP1es5xuzTF3Qw2XRMK1N4ZgFsOQudlEexik=
                     </ns4:X509Certificate>
                 </ns4:X509Data>
             </ns4:KeyInfo>
         </ns0:KeyDescriptor>
         <ns0:SingleLogoutService 
Binding="urn:oasis:names:tc:SAML:2.0:bindings:HTTP-Redirect"
Location="https://localhost/slo/redirect"/>
         <ns0:SingleLogoutService 
Binding="urn:oasis:names:tc:SAML:2.0:bindings:HTTP-POST"
Location="https://localhost/slo/post"/>
         <ns0:AssertionConsumerService 
Binding="urn:oasis:names:tc:SAML:2.0:bindings:HTTP-POST"
Location="https://localhost/acs/post" index="1"/>
     </ns0:SPSSODescriptor>
</ns0:EntityDescriptor>

We are currently using PySAML2 which has also generated the previous XML.
It something wrong that I'm missing? The whole testshib.org traceback is 
attached to the email


-- 
Alessandro Molina
Chief Technical Officer & Director of Operations

Axant s.n.c. - http://www.axant.it
Phone: +39 346 739 9923
Fax: +39 011 412 1756

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://shibboleth.net/pipermail/users/attachments/20151005/3d60e0da/attachment-0001.html>
-------------- next part --------------
12:07:03.793 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.saml2.SSOProfileHandler:387] - Decoded request from relying party 'https://localhost/sprovide.xml'
12:07:03.793 - DEBUG [edu.internet2.middleware.shibboleth.common.relyingparty.provider.SAMLMDRelyingPartyConfigurationManager:128] - Looking up relying party configuration for https://localhost/sprovide.xml
12:07:03.793 - DEBUG [edu.internet2.middleware.shibboleth.common.relyingparty.provider.SAMLMDRelyingPartyConfigurationManager:134] - No custom relying party configuration found for https://localhost/sprovide.xml, looking up configuration based on metadata groups.
12:07:03.794 - DEBUG [edu.internet2.middleware.shibboleth.common.relyingparty.provider.SAMLMDRelyingPartyConfigurationManager:157] - No custom or group-based relying party configuration found for https://localhost/sprovide.xml. Using default relying party configuration.
12:07:03.794 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.saml2.SSOProfileHandler:226] - Creating login context and transferring control to authentication engine
12:07:03.794 - DEBUG [edu.internet2.middleware.shibboleth.idp.util.HttpServletHelper:181] - Storing LoginContext to StorageService partition loginContexts, key 730f62421de5ef55c172b91e726c89cbf7d31756badff986e1fe3d9a071f7146
12:07:03.794 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.saml2.SSOProfileHandler:240] - Redirecting user to authentication engine at https://idp.testshib.org:443/idp/AuthnEngine
12:07:04.199 - DEBUG [edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine:209] - Processing incoming request
12:07:04.199 - DEBUG [edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine:240] - Beginning user authentication process.
12:07:04.199 - DEBUG [edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine:244] - Existing IdP session available for principal myself
12:07:04.199 - DEBUG [edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine:283] - Filtering configured LoginHandlers: {urn:oasis:names:tc:SAML:2.0:ac:classes:PreviousSession=edu.internet2.middleware.shibboleth.idp.authn.provider.PreviousSessionLoginHandler at 5d0ba9f3, urn:oasis:names:tc:SAML:2.0:ac:classes:PasswordProtectedTransport=edu.internet2.middleware.shibboleth.idp.authn.provider.UsernamePasswordLoginHandler at 28c2c03e}
12:07:04.200 - DEBUG [edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine:464] - Selecting appropriate login handler from filtered set {urn:oasis:names:tc:SAML:2.0:ac:classes:PreviousSession=edu.internet2.middleware.shibboleth.idp.authn.provider.PreviousSessionLoginHandler at 5d0ba9f3, urn:oasis:names:tc:SAML:2.0:ac:classes:PasswordProtectedTransport=edu.internet2.middleware.shibboleth.idp.authn.provider.UsernamePasswordLoginHandler at 28c2c03e}
12:07:04.200 - DEBUG [edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine:467] - Authenticating user with previous session LoginHandler
12:07:04.200 - DEBUG [edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine:478] - Basing previous session authentication on active authentication method urn:oasis:names:tc:SAML:2.0:ac:classes:PasswordProtectedTransport
12:07:04.200 - DEBUG [edu.internet2.middleware.shibboleth.idp.authn.provider.PreviousSessionLoginHandler:112] - Using existing IdP session for myself
12:07:04.200 - DEBUG [edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine:144] - Returning control to authentication engine
12:07:04.200 - DEBUG [edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine:209] - Processing incoming request
12:07:04.200 - DEBUG [edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine:514] - Completing user authentication process
12:07:04.200 - DEBUG [edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine:585] - Validating authentication was performed successfully
12:07:04.200 - DEBUG [edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine:696] - Updating session information for principal myself
12:07:04.201 - DEBUG [edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine:560] - User myself authenticated with method urn:oasis:names:tc:SAML:2.0:ac:classes:PasswordProtectedTransport
12:07:04.201 - DEBUG [edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine:161] - Returning control to profile handler
12:07:04.201 - DEBUG [edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine:177] - Redirecting user to profile handler at https://idp.testshib.org:443/idp/profile/SAML2/Redirect/SSO
12:07:04.615 - INFO [Shibboleth-Access:73] - 20151005T160704Z|93.38.220.210|idp.testshib.org:443|/profile/SAML2/Redirect/SSO|
12:07:04.615 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:86] - shibboleth.HandlerManager: Looking up profile handler for request path: /SAML2/Redirect/SSO
12:07:04.615 - 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
12:07:04.615 - DEBUG [edu.internet2.middleware.shibboleth.idp.util.HttpServletHelper:588] - Unbinding LoginContext
12:07:04.615 - DEBUG [edu.internet2.middleware.shibboleth.idp.util.HttpServletHelper:614] - Expiring LoginContext cookie
12:07:04.615 - DEBUG [edu.internet2.middleware.shibboleth.idp.util.HttpServletHelper:625] - Removed LoginContext, with key 730f62421de5ef55c172b91e726c89cbf7d31756badff986e1fe3d9a071f7146, from StorageService partition loginContexts
12:07:04.616 - 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
12:07:04.617 - DEBUG [edu.internet2.middleware.shibboleth.common.relyingparty.provider.SAMLMDRelyingPartyConfigurationManager:128] - Looking up relying party configuration for https://localhost/sprovide.xml
12:07:04.617 - DEBUG [edu.internet2.middleware.shibboleth.common.relyingparty.provider.SAMLMDRelyingPartyConfigurationManager:134] - No custom relying party configuration found for https://localhost/sprovide.xml, looking up configuration based on metadata groups.
12:07:04.617 - DEBUG [edu.internet2.middleware.shibboleth.common.relyingparty.provider.SAMLMDRelyingPartyConfigurationManager:157] - No custom or group-based relying party configuration found for https://localhost/sprovide.xml. Using default relying party configuration.
12:07:04.617 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.saml2.AbstractSAML2ProfileHandler:478] - Resolving attributes for principal 'myself' for SAML request from relying party 'https://localhost/sprovide.xml'
12:07:04.617 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:119] - shibboleth.AttributeResolver resolving attributes for principal myself
12:07:04.618 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:275] - Specific attributes for principal myself were not requested, resolving all attributes.
12:07:04.618 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:314] - Resolving attribute uid for principal myself
12:07:04.618 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:354] - Resolving data connector myLDAP for principal myself
12:07:04.618 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.dataConnector.LdapDataConnector:308] - Search filter: (uid=myself)
12:07:04.618 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.dataConnector.LdapDataConnector:363] - LDAP data connector myLDAP - Retrieving attributes from LDAP
12:07:04.619 - DEBUG [edu.vt.middleware.ldap.handler.DefaultConnectionHandler:74] - Bind with the following parameters:
12:07:04.619 - DEBUG [edu.vt.middleware.ldap.handler.DefaultConnectionHandler:75] -   authtype = simple
12:07:04.619 - DEBUG [edu.vt.middleware.ldap.handler.DefaultConnectionHandler:76] -   dn = cn=testshibldap,dc=testshib,dc=org
12:07:04.619 - DEBUG [edu.vt.middleware.ldap.handler.DefaultConnectionHandler:83] -   credential = <suppressed>
12:07:04.620 - DEBUG [edu.vt.middleware.ldap.Ldap:193] - Search with the following parameters:
12:07:04.620 - DEBUG [edu.vt.middleware.ldap.Ldap:194] -   dn = ou=people,dc=testshib,dc=org
12:07:04.620 - DEBUG [edu.vt.middleware.ldap.Ldap:195] -   filter = (uid=myself)
12:07:04.620 - DEBUG [edu.vt.middleware.ldap.Ldap:196] -   filterArgs = []
12:07:04.620 - DEBUG [edu.vt.middleware.ldap.Ldap:197] -   searchControls = javax.naming.directory.SearchControls at 33537b2f
12:07:04.620 - DEBUG [edu.vt.middleware.ldap.Ldap:198] -   handler = [edu.vt.middleware.ldap.handler.FqdnSearchResultHandler at 5f2421d0, edu.vt.middleware.ldap.handler.EntryDnSearchResultHandler at 3d280f7c, edu.vt.middleware.ldap.handler.BinarySearchResultHandler at 1110b542]
12:07:04.621 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.dataConnector.LdapDataConnector:414] - LDAP data connector myLDAP - Found the following attribute: uid[myself]
12:07:04.621 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.dataConnector.LdapDataConnector:414] - LDAP data connector myLDAP - Found the following attribute: eduPersonAffiliation[Member, Staff]
12:07:04.622 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.dataConnector.LdapDataConnector:414] - LDAP data connector myLDAP - Found the following attribute: eduPersonPrincipalName[myself at testshib.org]
12:07:04.622 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.dataConnector.LdapDataConnector:414] - LDAP data connector myLDAP - Found the following attribute: sn[And I]
12:07:04.622 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.dataConnector.LdapDataConnector:414] - LDAP data connector myLDAP - Found the following attribute: ou[people]
12:07:04.622 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.dataConnector.LdapDataConnector:414] - LDAP data connector myLDAP - Found the following attribute: cn[Me Myself And I]
12:07:04.622 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.dataConnector.LdapDataConnector:414] - LDAP data connector myLDAP - Found the following attribute: description[Self-reflection.]
12:07:04.622 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.dataConnector.LdapDataConnector:414] - LDAP data connector myLDAP - Found the following attribute: telephoneNumber[555-5555]
12:07:04.622 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.dataConnector.LdapDataConnector:414] - LDAP data connector myLDAP - Found the following attribute: userPassword[bXlzZWxm]
12:07:04.622 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.dataConnector.LdapDataConnector:414] - LDAP data connector myLDAP - Found the following attribute: entryDN[uid=myself,ou=people,dc=testshib,dc=org]
12:07:04.623 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.dataConnector.LdapDataConnector:414] - LDAP data connector myLDAP - Found the following attribute: objectClass[organizationalPerson, person, eduPerson, inetOrgPerson, top]
12:07:04.623 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.dataConnector.LdapDataConnector:414] - LDAP data connector myLDAP - Found the following attribute: eduPersonEntitlement[urn:mace:dir:entitlement:common-lib-terms]
12:07:04.623 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.dataConnector.LdapDataConnector:414] - LDAP data connector myLDAP - Found the following attribute: givenName[Me Myself]
12:07:04.623 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:336] - Resolved attribute uid containing 1 values
12:07:04.623 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:314] - Resolving attribute eduPersonPrincipalName for principal myself
12:07:04.623 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:336] - Resolved attribute eduPersonPrincipalName containing 1 values
12:07:04.623 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:314] - Resolving attribute eduPersonAffiliation for principal myself
12:07:04.623 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:336] - Resolved attribute eduPersonAffiliation containing 2 values
12:07:04.623 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:314] - Resolving attribute eduPersonPrimaryAffiliation for principal myself
12:07:04.623 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:336] - Resolved attribute eduPersonPrimaryAffiliation containing 0 values
12:07:04.624 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:314] - Resolving attribute organizationName for principal myself
12:07:04.624 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:336] - Resolved attribute organizationName containing 0 values
12:07:04.624 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:314] - Resolving attribute street for principal myself
12:07:04.624 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:336] - Resolved attribute street containing 0 values
12:07:04.624 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:314] - Resolving attribute eduPersonScopedAffiliation for principal myself
12:07:04.624 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:336] - Resolved attribute eduPersonScopedAffiliation containing 2 values
12:07:04.624 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:314] - Resolving attribute surname for principal myself
12:07:04.624 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:336] - Resolved attribute surname containing 1 values
12:07:04.624 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:314] - Resolving attribute givenName for principal myself
12:07:04.624 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:336] - Resolved attribute givenName containing 1 values
12:07:04.624 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:314] - Resolving attribute eduPersonNickname for principal myself
12:07:04.625 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:336] - Resolved attribute eduPersonNickname containing 0 values
12:07:04.625 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:314] - Resolving attribute homePhone for principal myself
12:07:04.625 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:336] - Resolved attribute homePhone containing 0 values
12:07:04.625 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:314] - Resolving attribute preferredLanguage for principal myself
12:07:04.625 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:336] - Resolved attribute preferredLanguage containing 0 values
12:07:04.625 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:314] - Resolving attribute title for principal myself
12:07:04.625 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:336] - Resolved attribute title containing 0 values
12:07:04.625 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:314] - Resolving attribute eduPersonOrgDN for principal myself
12:07:04.625 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:336] - Resolved attribute eduPersonOrgDN containing 0 values
12:07:04.625 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:314] - Resolving attribute postalCode for principal myself
12:07:04.625 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:336] - Resolved attribute postalCode containing 0 values
12:07:04.626 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:314] - Resolving attribute initials for principal myself
12:07:04.626 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:336] - Resolved attribute initials containing 0 values
12:07:04.626 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:314] - Resolving attribute pagerNumber for principal myself
12:07:04.626 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:336] - Resolved attribute pagerNumber containing 0 values
12:07:04.626 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:314] - Resolving attribute stateProvince for principal myself
12:07:04.626 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:336] - Resolved attribute stateProvince containing 0 values
12:07:04.626 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:314] - Resolving attribute eduPersonEntitlement for principal myself
12:07:04.626 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:336] - Resolved attribute eduPersonEntitlement containing 1 values
12:07:04.626 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:314] - Resolving attribute postOfficeBox for principal myself
12:07:04.626 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:336] - Resolved attribute postOfficeBox containing 0 values
12:07:04.626 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:314] - Resolving attribute organizationalUnit for principal myself
12:07:04.626 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:336] - Resolved attribute organizationalUnit containing 1 values
12:07:04.627 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:314] - Resolving attribute employeeType for principal myself
12:07:04.627 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:336] - Resolved attribute employeeType containing 0 values
12:07:04.627 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:314] - Resolving attribute commonName for principal myself
12:07:04.627 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:336] - Resolved attribute commonName containing 1 values
12:07:04.627 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:314] - Resolving attribute homePostalAddress for principal myself
12:07:04.627 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:336] - Resolved attribute homePostalAddress containing 0 values
12:07:04.627 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:314] - Resolving attribute transientId for principal myself
12:07:04.627 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.attributeDefinition.TransientIdAttributeDefinition:97] - Building transient ID for request id-aiZ6edDhIYmMuTHcQ; outbound message issuer: https://idp.testshib.org/idp/shibboleth, inbound message issuer: https://localhost/sprovide.xml, principal identifer: myself
12:07:04.627 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.attributeDefinition.TransientIdAttributeDefinition:115] - Created transient ID _3be84f1ad354480f53ab3c5ef393711d for request id-aiZ6edDhIYmMuTHcQ
12:07:04.627 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:336] - Resolved attribute transientId containing 1 values
12:07:04.628 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:314] - Resolving attribute eduPersonPrimaryOrgUnitDN for principal myself
12:07:04.628 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:336] - Resolved attribute eduPersonPrimaryOrgUnitDN containing 0 values
12:07:04.628 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:314] - Resolving attribute eduPersonTargetedID for principal myself
12:07:04.628 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:354] - Resolving data connector computedID for principal myself
12:07:04.628 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:336] - Resolved attribute eduPersonTargetedID containing 1 values
12:07:04.628 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:314] - Resolving attribute eduPersonOrgUnitDN for principal myself
12:07:04.628 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:336] - Resolved attribute eduPersonOrgUnitDN containing 0 values
12:07:04.628 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:314] - Resolving attribute email for principal myself
12:07:04.628 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:336] - Resolved attribute email containing 0 values
12:07:04.628 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:314] - Resolving attribute departmentNumber for principal myself
12:07:04.628 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:336] - Resolved attribute departmentNumber containing 0 values
12:07:04.629 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:314] - Resolving attribute jpegPhoto for principal myself
12:07:04.629 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:336] - Resolved attribute jpegPhoto containing 0 values
12:07:04.629 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:314] - Resolving attribute telephoneNumber for principal myself
12:07:04.629 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:336] - Resolved attribute telephoneNumber containing 1 values
12:07:04.629 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:314] - Resolving attribute eduPersonAssurance for principal myself
12:07:04.629 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:336] - Resolved attribute eduPersonAssurance containing 0 values
12:07:04.629 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:314] - Resolving attribute locality for principal myself
12:07:04.629 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:336] - Resolved attribute locality containing 0 values
12:07:04.629 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:314] - Resolving attribute postalAddress for principal myself
12:07:04.629 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:336] - Resolved attribute postalAddress containing 0 values
12:07:04.629 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:314] - Resolving attribute mobileNumber for principal myself
12:07:04.630 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:336] - Resolved attribute mobileNumber containing 0 values
12:07:04.630 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:314] - Resolving attribute displayName for principal myself
12:07:04.630 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:336] - Resolved attribute displayName containing 0 values
12:07:04.630 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:314] - Resolving attribute employeeNumber for principal myself
12:07:04.630 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:336] - Resolved attribute employeeNumber containing 0 values
12:07:04.630 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:468] - Attribute uid has 1 values after post-processing
12:07:04.630 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:468] - Attribute eduPersonAffiliation has 2 values after post-processing
12:07:04.630 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:468] - Attribute eduPersonPrincipalName has 1 values after post-processing
12:07:04.630 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:450] - Removing attribute eduPersonPrimaryAffiliation from resolution result for principal myself.  It contains no values.
12:07:04.630 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:450] - Removing attribute organizationName from resolution result for principal myself.  It contains no values.
12:07:04.630 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:450] - Removing attribute street from resolution result for principal myself.  It contains no values.
12:07:04.631 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:468] - Attribute surname has 1 values after post-processing
12:07:04.631 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:468] - Attribute eduPersonScopedAffiliation has 2 values after post-processing
12:07:04.631 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:468] - Attribute givenName has 1 values after post-processing
12:07:04.631 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:450] - Removing attribute homePhone from resolution result for principal myself.  It contains no values.
12:07:04.631 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:450] - Removing attribute eduPersonNickname from resolution result for principal myself.  It contains no values.
12:07:04.631 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:450] - Removing attribute preferredLanguage from resolution result for principal myself.  It contains no values.
12:07:04.631 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:450] - Removing attribute title from resolution result for principal myself.  It contains no values.
12:07:04.631 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:450] - Removing attribute eduPersonOrgDN from resolution result for principal myself.  It contains no values.
12:07:04.631 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:450] - Removing attribute postalCode from resolution result for principal myself.  It contains no values.
12:07:04.631 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:450] - Removing attribute initials from resolution result for principal myself.  It contains no values.
12:07:04.631 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:450] - Removing attribute pagerNumber from resolution result for principal myself.  It contains no values.
12:07:04.631 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:450] - Removing attribute stateProvince from resolution result for principal myself.  It contains no values.
12:07:04.632 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:468] - Attribute eduPersonEntitlement has 1 values after post-processing
12:07:04.632 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:450] - Removing attribute postOfficeBox from resolution result for principal myself.  It contains no values.
12:07:04.632 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:468] - Attribute organizationalUnit has 1 values after post-processing
12:07:04.632 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:450] - Removing attribute employeeType from resolution result for principal myself.  It contains no values.
12:07:04.632 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:468] - Attribute commonName has 1 values after post-processing
12:07:04.632 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:450] - Removing attribute homePostalAddress from resolution result for principal myself.  It contains no values.
12:07:04.632 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:468] - Attribute transientId has 1 values after post-processing
12:07:04.632 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:450] - Removing attribute eduPersonPrimaryOrgUnitDN from resolution result for principal myself.  It contains no values.
12:07:04.632 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:468] - Attribute eduPersonTargetedID has 1 values after post-processing
12:07:04.632 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:450] - Removing attribute eduPersonOrgUnitDN from resolution result for principal myself.  It contains no values.
12:07:04.632 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:450] - Removing attribute departmentNumber from resolution result for principal myself.  It contains no values.
12:07:04.632 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:450] - Removing attribute email from resolution result for principal myself.  It contains no values.
12:07:04.633 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:468] - Attribute telephoneNumber has 1 values after post-processing
12:07:04.633 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:450] - Removing attribute jpegPhoto from resolution result for principal myself.  It contains no values.
12:07:04.633 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:450] - Removing attribute postalAddress from resolution result for principal myself.  It contains no values.
12:07:04.633 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:450] - Removing attribute locality from resolution result for principal myself.  It contains no values.
12:07:04.633 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:450] - Removing attribute eduPersonAssurance from resolution result for principal myself.  It contains no values.
12:07:04.633 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:450] - Removing attribute employeeNumber from resolution result for principal myself.  It contains no values.
12:07:04.633 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:450] - Removing attribute displayName from resolution result for principal myself.  It contains no values.
12:07:04.633 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:450] - Removing attribute mobileNumber from resolution result for principal myself.  It contains no values.
12:07:04.633 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver:137] - shibboleth.AttributeResolver resolved, for principal myself, the attributes: [uid, eduPersonAffiliation, eduPersonPrincipalName, surname, eduPersonScopedAffiliation, givenName, eduPersonEntitlement, organizationalUnit, commonName, transientId, eduPersonTargetedID, telephoneNumber]
12:07:04.633 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.filtering.provider.ShibbolethAttributeFilteringEngine:71] - shibboleth.AttributeFilterEngine filtering 12 attributes for principal myself
12:07:04.633 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.filtering.provider.ShibbolethAttributeFilteringEngine:130] - Evaluating if filter policy releaseEverythingToAnyone is active for principal myself
12:07:04.633 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.filtering.provider.ShibbolethAttributeFilteringEngine:139] - Filter policy releaseEverythingToAnyone is active for principal myself
12:07:04.634 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.filtering.provider.ShibbolethAttributeFilteringEngine:163] - Processing permit value rule for attribute transientId for principal myself
12:07:04.634 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.filtering.provider.ShibbolethAttributeFilteringEngine:163] - Processing permit value rule for attribute eduPersonTargetedID for principal myself
12:07:04.634 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.filtering.provider.ShibbolethAttributeFilteringEngine:163] - Processing permit value rule for attribute eduPersonPrincipalName for principal myself
12:07:04.634 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.filtering.provider.ShibbolethAttributeFilteringEngine:163] - Processing permit value rule for attribute title for principal myself
12:07:04.634 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.filtering.provider.ShibbolethAttributeFilteringEngine:163] - Processing permit value rule for attribute eduPersonScopedAffiliation for principal myself
12:07:04.634 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.filtering.provider.ShibbolethAttributeFilteringEngine:163] - Processing permit value rule for attribute eduPersonAffiliation for principal myself
12:07:04.634 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.filtering.provider.ShibbolethAttributeFilteringEngine:163] - Processing permit value rule for attribute givenName for principal myself
12:07:04.634 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.filtering.provider.ShibbolethAttributeFilteringEngine:163] - Processing permit value rule for attribute surname for principal myself
12:07:04.634 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.filtering.provider.ShibbolethAttributeFilteringEngine:163] - Processing permit value rule for attribute commonName for principal myself
12:07:04.634 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.filtering.provider.ShibbolethAttributeFilteringEngine:163] - Processing permit value rule for attribute uid for principal myself
12:07:04.634 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.filtering.provider.ShibbolethAttributeFilteringEngine:163] - Processing permit value rule for attribute telephoneNumber for principal myself
12:07:04.635 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.filtering.provider.ShibbolethAttributeFilteringEngine:163] - Processing permit value rule for attribute eduPersonEntitlement for principal myself
12:07:04.635 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.filtering.provider.ShibbolethAttributeFilteringEngine:109] - Attribute uid has 1 values after filtering
12:07:04.635 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.filtering.provider.ShibbolethAttributeFilteringEngine:109] - Attribute eduPersonAffiliation has 2 values after filtering
12:07:04.635 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.filtering.provider.ShibbolethAttributeFilteringEngine:109] - Attribute eduPersonPrincipalName has 1 values after filtering
12:07:04.635 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.filtering.provider.ShibbolethAttributeFilteringEngine:109] - Attribute surname has 1 values after filtering
12:07:04.635 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.filtering.provider.ShibbolethAttributeFilteringEngine:109] - Attribute eduPersonScopedAffiliation has 2 values after filtering
12:07:04.635 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.filtering.provider.ShibbolethAttributeFilteringEngine:109] - Attribute givenName has 1 values after filtering
12:07:04.635 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.filtering.provider.ShibbolethAttributeFilteringEngine:109] - Attribute eduPersonEntitlement has 1 values after filtering
12:07:04.635 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.filtering.provider.ShibbolethAttributeFilteringEngine:106] - Removing attribute from return set, no more values: organizationalUnit
12:07:04.635 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.filtering.provider.ShibbolethAttributeFilteringEngine:109] - Attribute commonName has 1 values after filtering
12:07:04.635 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.filtering.provider.ShibbolethAttributeFilteringEngine:109] - Attribute transientId has 1 values after filtering
12:07:04.635 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.filtering.provider.ShibbolethAttributeFilteringEngine:109] - Attribute eduPersonTargetedID has 1 values after filtering
12:07:04.636 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.filtering.provider.ShibbolethAttributeFilteringEngine:109] - Attribute telephoneNumber has 1 values after filtering
12:07:04.636 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.filtering.provider.ShibbolethAttributeFilteringEngine:114] - Filtered attributes for principal myself.  The following attributes remain: [uid, eduPersonAffiliation, eduPersonPrincipalName, surname, eduPersonScopedAffiliation, givenName, eduPersonEntitlement, commonName, transientId, eduPersonTargetedID, telephoneNumber]
12:07:04.636 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.saml2.AbstractSAML2ProfileHandler:505] - Creating attribute statement in response to SAML request 'id-aiZ6edDhIYmMuTHcQ' from relying party 'https://localhost/sprovide.xml'
12:07:04.636 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.provider.ShibbolethSAML2AttributeAuthority:247] - Encoded attribute uid with encoder of type edu.internet2.middleware.shibboleth.common.attribute.encoding.provider.SAML2StringAttributeEncoder
12:07:04.636 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.provider.ShibbolethSAML2AttributeAuthority:247] - Encoded attribute eduPersonAffiliation with encoder of type edu.internet2.middleware.shibboleth.common.attribute.encoding.provider.SAML2StringAttributeEncoder
12:07:04.636 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.provider.ShibbolethSAML2AttributeAuthority:247] - Encoded attribute eduPersonPrincipalName with encoder of type edu.internet2.middleware.shibboleth.common.attribute.encoding.provider.SAML2ScopedStringAttributeEncoder
12:07:04.636 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.provider.ShibbolethSAML2AttributeAuthority:247] - Encoded attribute surname with encoder of type edu.internet2.middleware.shibboleth.common.attribute.encoding.provider.SAML2StringAttributeEncoder
12:07:04.636 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.provider.ShibbolethSAML2AttributeAuthority:247] - Encoded attribute eduPersonScopedAffiliation with encoder of type edu.internet2.middleware.shibboleth.common.attribute.encoding.provider.SAML2ScopedStringAttributeEncoder
12:07:04.636 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.provider.ShibbolethSAML2AttributeAuthority:247] - Encoded attribute givenName with encoder of type edu.internet2.middleware.shibboleth.common.attribute.encoding.provider.SAML2StringAttributeEncoder
12:07:04.636 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.provider.ShibbolethSAML2AttributeAuthority:247] - Encoded attribute eduPersonEntitlement with encoder of type edu.internet2.middleware.shibboleth.common.attribute.encoding.provider.SAML2StringAttributeEncoder
12:07:04.637 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.provider.ShibbolethSAML2AttributeAuthority:247] - Encoded attribute commonName with encoder of type edu.internet2.middleware.shibboleth.common.attribute.encoding.provider.SAML2StringAttributeEncoder
12:07:04.637 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.provider.ShibbolethSAML2AttributeAuthority:263] - Attribute transientId was not encoded (filtered by query, or no SAML2AttributeEncoder attached).
12:07:04.637 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.provider.ShibbolethSAML2AttributeAuthority:247] - Encoded attribute eduPersonTargetedID with encoder of type edu.internet2.middleware.shibboleth.common.attribute.encoding.provider.SAML2XMLObjectAttributeEncoder
12:07:04.637 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.provider.ShibbolethSAML2AttributeAuthority:247] - Encoded attribute telephoneNumber with encoder of type edu.internet2.middleware.shibboleth.common.attribute.encoding.provider.SAML2StringAttributeEncoder
12:07:04.637 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.AbstractSAMLProfileHandler:527] - Filtering out potential name identifier attributes which can not be encoded by edu.internet2.middleware.shibboleth.common.attribute.encoding.SAML2NameIDEncoder
12:07:04.637 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.AbstractSAMLProfileHandler:546] - Removing attribute uid, it can not be encoded via edu.internet2.middleware.shibboleth.common.attribute.encoding.SAML2NameIDEncoder
12:07:04.637 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.AbstractSAMLProfileHandler:546] - Removing attribute eduPersonAffiliation, it can not be encoded via edu.internet2.middleware.shibboleth.common.attribute.encoding.SAML2NameIDEncoder
12:07:04.637 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.AbstractSAMLProfileHandler:546] - Removing attribute eduPersonPrincipalName, it can not be encoded via edu.internet2.middleware.shibboleth.common.attribute.encoding.SAML2NameIDEncoder
12:07:04.637 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.AbstractSAMLProfileHandler:546] - Removing attribute surname, it can not be encoded via edu.internet2.middleware.shibboleth.common.attribute.encoding.SAML2NameIDEncoder
12:07:04.637 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.AbstractSAMLProfileHandler:546] - Removing attribute eduPersonScopedAffiliation, it can not be encoded via edu.internet2.middleware.shibboleth.common.attribute.encoding.SAML2NameIDEncoder
12:07:04.638 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.AbstractSAMLProfileHandler:546] - Removing attribute givenName, it can not be encoded via edu.internet2.middleware.shibboleth.common.attribute.encoding.SAML2NameIDEncoder
12:07:04.638 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.AbstractSAMLProfileHandler:546] - Removing attribute eduPersonEntitlement, it can not be encoded via edu.internet2.middleware.shibboleth.common.attribute.encoding.SAML2NameIDEncoder
12:07:04.638 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.AbstractSAMLProfileHandler:546] - Removing attribute commonName, it can not be encoded via edu.internet2.middleware.shibboleth.common.attribute.encoding.SAML2NameIDEncoder
12:07:04.638 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.AbstractSAMLProfileHandler:541] - Retaining attribute transientId which may be encoded to via edu.internet2.middleware.shibboleth.common.attribute.encoding.SAML2NameIDEncoder
12:07:04.638 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.AbstractSAMLProfileHandler:546] - Removing attribute eduPersonTargetedID, it can not be encoded via edu.internet2.middleware.shibboleth.common.attribute.encoding.SAML2NameIDEncoder
12:07:04.638 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.AbstractSAMLProfileHandler:546] - Removing attribute telephoneNumber, it can not be encoded via edu.internet2.middleware.shibboleth.common.attribute.encoding.SAML2NameIDEncoder
12:07:04.638 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.AbstractSAMLProfileHandler:483] - Attempting to select name identifier attribute for relying party 'https://localhost/sprovide.xml' that requires format 'urn:oasis:names:tc:SAML:2.0:nameid-format:transient'
12:07:04.638 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.AbstractSAMLProfileHandler:566] - Filtering out potential name identifier attributes which do not support one of the following formats: [urn:oasis:names:tc:SAML:2.0:nameid-format:transient]
12:07:04.638 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.AbstractSAMLProfileHandler:585] - Retaining attribute transientId which may be encoded as a name identifier of format urn:oasis:names:tc:SAML:2.0:nameid-format:transient
12:07:04.638 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.AbstractSAMLProfileHandler:690] - Selecting attribute to be encoded as a name identifier by encoder of type edu.internet2.middleware.shibboleth.common.attribute.encoding.SAML2NameIDEncoder
12:07:04.638 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.AbstractSAMLProfileHandler:717] - Selecting the first attribute that can be encoded in to a name identifier
12:07:04.638 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.AbstractSAMLProfileHandler:501] - Name identifier for relying party 'https://localhost/sprovide.xml' will be built from attribute 'transientId'
12:07:04.639 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.saml2.AbstractSAML2ProfileHandler:868] - Using attribute 'transientId' supporting NameID format 'urn:oasis:names:tc:SAML:2.0:nameid-format:transient' to create the NameID for relying party 'https://localhost/sprovide.xml'
12:07:04.639 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.saml2.AbstractSAML2ProfileHandler:572] - Determining if SAML assertion to relying party 'https://localhost/sprovide.xml' should be signed
12:07:04.639 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.saml2.AbstractSAML2ProfileHandler:653] - IdP relying party configuration 'default' indicates to sign assertions: true
12:07:04.639 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.saml2.AbstractSAML2ProfileHandler:583] - Determining signing credntial for assertion to relying party 'https://localhost/sprovide.xml'
12:07:04.639 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.saml2.AbstractSAML2ProfileHandler:599] - Signing assertion to relying party https://localhost/sprovide.xml
12:07:04.649 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.saml2.AbstractSAML2ProfileHandler:274] - Attempting to encrypt assertion to relying party 'https://localhost/sprovide.xml'
12:07:04.650 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.saml2.AbstractSAML2ProfileHandler:279] - Assertion to be encrypted is:
<?xml version="1.0" encoding="UTF-8"?><saml2:Assertion xmlns:saml2="urn:oasis:names:tc:SAML:2.0:assertion" ID="_eb78e9ffa430b1f0a82288a1fd36e467" IssueInstant="2015-10-05T16:07:04.637Z" Version="2.0" xmlns:xs="http://www.w3.org/2001/XMLSchema">
   <saml2:Issuer Format="urn:oasis:names:tc:SAML:2.0:nameid-format:entity">https://idp.testshib.org/idp/shibboleth</saml2:Issuer>
   <ds:Signature xmlns:ds="http://www.w3.org/2000/09/xmldsig#">
      <ds:SignedInfo>
         <ds:CanonicalizationMethod Algorithm="http://www.w3.org/2001/10/xml-exc-c14n#"/>
         <ds:SignatureMethod Algorithm="http://www.w3.org/2001/04/xmldsig-more#rsa-sha256"/>
         <ds:Reference URI="#_eb78e9ffa430b1f0a82288a1fd36e467">
            <ds:Transforms>
               <ds:Transform Algorithm="http://www.w3.org/2000/09/xmldsig#enveloped-signature"/>
               <ds:Transform Algorithm="http://www.w3.org/2001/10/xml-exc-c14n#">
                  <ec:InclusiveNamespaces xmlns:ec="http://www.w3.org/2001/10/xml-exc-c14n#" PrefixList="xs"/>
               </ds:Transform>
            </ds:Transforms>
            <ds:DigestMethod Algorithm="http://www.w3.org/2001/04/xmlenc#sha256"/>
            <ds:DigestValue>/8vTEOswAGUz5+q+AfUS0Gw+fpg32K7mZdd1MwawMA0=</ds:DigestValue>
         </ds:Reference>
      </ds:SignedInfo>
      <ds:SignatureValue>P3KDDAEI2m3cTliFkI7cK58FSq1S4TM7V1NueqscfdXYNsNpwCz2QK4TneXvjCCaaNWog7ZD7Q3kgvNIufJvFHSSPBT9eAyikrvj/s+RC75a4jsHe5GkDuzzNFO8I6/7H9DzGAImHPtsM60C1PrCrommZCMCsoSY1IBzF0fgKi9auFgLxcZ7eYAOnCVpFW1b5/FwzGeAdk2aiwByBI3TiZllsa0EJN4HU6Eg76NIYk6QJyC7SKoN1VlUW0fqWnNe3wGT674vXkb75B+fDG9+a4raNQGMmWv+/Rh+FBz8Y1FzfwTJwc+u21onyt3vr5laagT3fFXTrxhrN8tbIL4prw==</ds:SignatureValue>
      <ds:KeyInfo>
         <ds:X509Data>
            <ds:X509Certificate>MIIEDjCCAvagAwIBAgIBADANBgkqhkiG9w0BAQUFADBnMQswCQYDVQQGEwJVUzEVMBMGA1UECBMM
UGVubnN5bHZhbmlhMRMwEQYDVQQHEwpQaXR0c2J1cmdoMREwDwYDVQQKEwhUZXN0U2hpYjEZMBcG
A1UEAxMQaWRwLnRlc3RzaGliLm9yZzAeFw0wNjA4MzAyMTEyMjVaFw0xNjA4MjcyMTEyMjVaMGcx
CzAJBgNVBAYTAlVTMRUwEwYDVQQIEwxQZW5uc3lsdmFuaWExEzARBgNVBAcTClBpdHRzYnVyZ2gx
ETAPBgNVBAoTCFRlc3RTaGliMRkwFwYDVQQDExBpZHAudGVzdHNoaWIub3JnMIIBIjANBgkqhkiG
9w0BAQEFAAOCAQ8AMIIBCgKCAQEArYkCGuTmJp9eAOSGHwRJo1SNatB5ZOKqDM9ysg7CyVTDClcp
u93gSP10nH4gkCZOlnESNgttg0r+MqL8tfJC6ybddEFB3YBo8PZajKSe3OQ01Ow3yT4I+Wdg1tsT
pSge9gEz7SrC07EkYmHuPtd71CHiUaCWDv+xVfUQX0aTNPFmDixzUjoYzbGDrtAyCqA8f9CN2txI
fJnpHE6q6CmKcoLADS4UrNPlhHSzd614kR/JYiks0K4kbRqCQF0Dv0P5Di+rEfefC6glV8ysC8dB
5/9nb0yh/ojRuJGmgMWHgWk6h0ihjihqiu4jACovUZ7vVOCgSE5Ipn7OIwqd93zp2wIDAQABo4HE
MIHBMB0GA1UdDgQWBBSsBQ869nh83KqZr5jArr4/7b+QazCBkQYDVR0jBIGJMIGGgBSsBQ869nh8
3KqZr5jArr4/7b+Qa6FrpGkwZzELMAkGA1UEBhMCVVMxFTATBgNVBAgTDFBlbm5zeWx2YW5pYTET
MBEGA1UEBxMKUGl0dHNidXJnaDERMA8GA1UEChMIVGVzdFNoaWIxGTAXBgNVBAMTEGlkcC50ZXN0
c2hpYi5vcmeCAQAwDAYDVR0TBAUwAwEB/zANBgkqhkiG9w0BAQUFAAOCAQEAjR29PhrCbk8qLN5M
FfSVk98t3CT9jHZoYxd8QMRLI4j7iYQxXiGJTT1FXs1nd4Rha9un+LqTfeMMYqISdDDI6tv8iNpk
OAvZZUosVkUo93pv1T0RPz35hcHHYq2yee59HJOco2bFlcsH8JBXRSRrJ3Q7Eut+z9uo80JdGNJ4
/SJy5UorZ8KazGj16lfJhOBXldgrhppQBb0Nq6HKHguqmwRfJ+WkxemZXzhediAjGeka8nz8Jjwx
pUjAiSWYKLtJhGEaTqCYxCCX2Dw+dOTqUzHOZ7WKv4JXPK5G/Uhr8K/qhmFT2nIQi538n6rVYLeW
j8Bbnl+ev0peYzxFyF5sQA==</ds:X509Certificate>
         </ds:X509Data>
      </ds:KeyInfo>
   </ds:Signature>
   <saml2:Subject>
      <saml2:NameID Format="urn:oasis:names:tc:SAML:2.0:nameid-format:transient" NameQualifier="https://idp.testshib.org/idp/shibboleth" SPNameQualifier="https://localhost/sprovide.xml">_3be84f1ad354480f53ab3c5ef393711d</saml2:NameID>
      <saml2:SubjectConfirmation Method="urn:oasis:names:tc:SAML:2.0:cm:bearer">
         <saml2:SubjectConfirmationData Address="93.38.220.210" InResponseTo="id-aiZ6edDhIYmMuTHcQ" NotOnOrAfter="2015-10-05T16:12:04.637Z" Recipient="https://localhost/acs/post"/>
      </saml2:SubjectConfirmation>
   </saml2:Subject>
   <saml2:Conditions NotBefore="2015-10-05T16:07:04.637Z" NotOnOrAfter="2015-10-05T16:12:04.637Z">
      <saml2:AudienceRestriction>
         <saml2:Audience>https://localhost/sprovide.xml</saml2:Audience>
      </saml2:AudienceRestriction>
   </saml2:Conditions>
   <saml2:AuthnStatement AuthnInstant="2015-10-05T16:02:19.896Z" SessionIndex="_d38230473cae130bc1cc15ea3c80787e">
      <saml2:SubjectLocality Address="93.38.220.210"/>
      <saml2:AuthnContext>
         <saml2:AuthnContextClassRef>urn:oasis:names:tc:SAML:2.0:ac:classes:PasswordProtectedTransport</saml2:AuthnContextClassRef>
      </saml2:AuthnContext>
   </saml2:AuthnStatement>
   <saml2:AttributeStatement>
      <saml2:Attribute FriendlyName="uid" Name="urn:oid:0.9.2342.19200300.100.1.1" NameFormat="urn:oasis:names:tc:SAML:2.0:attrname-format:uri">
         <saml2:AttributeValue xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:type="xs:string">myself</saml2:AttributeValue>
      </saml2:Attribute>
      <saml2:Attribute FriendlyName="eduPersonAffiliation" Name="urn:oid:1.3.6.1.4.1.5923.1.1.1.1" NameFormat="urn:oasis:names:tc:SAML:2.0:attrname-format:uri">
         <saml2:AttributeValue xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:type="xs:string">Member</saml2:AttributeValue>
         <saml2:AttributeValue xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:type="xs:string">Staff</saml2:AttributeValue>
      </saml2:Attribute>
      <saml2:Attribute FriendlyName="eduPersonPrincipalName" Name="urn:oid:1.3.6.1.4.1.5923.1.1.1.6" NameFormat="urn:oasis:names:tc:SAML:2.0:attrname-format:uri">
         <saml2:AttributeValue xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:type="xs:string">myself at testshib.org</saml2:AttributeValue>
      </saml2:Attribute>
      <saml2:Attribute FriendlyName="sn" Name="urn:oid:2.5.4.4" NameFormat="urn:oasis:names:tc:SAML:2.0:attrname-format:uri">
         <saml2:AttributeValue xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:type="xs:string">And I</saml2:AttributeValue>
      </saml2:Attribute>
      <saml2:Attribute FriendlyName="eduPersonScopedAffiliation" Name="urn:oid:1.3.6.1.4.1.5923.1.1.1.9" NameFormat="urn:oasis:names:tc:SAML:2.0:attrname-format:uri">
         <saml2:AttributeValue xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:type="xs:string">Member at testshib.org</saml2:AttributeValue>
         <saml2:AttributeValue xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:type="xs:string">Staff at testshib.org</saml2:AttributeValue>
      </saml2:Attribute>
      <saml2:Attribute FriendlyName="givenName" Name="urn:oid:2.5.4.42" NameFormat="urn:oasis:names:tc:SAML:2.0:attrname-format:uri">
         <saml2:AttributeValue xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:type="xs:string">Me Myself</saml2:AttributeValue>
      </saml2:Attribute>
      <saml2:Attribute FriendlyName="eduPersonEntitlement" Name="urn:oid:1.3.6.1.4.1.5923.1.1.1.7" NameFormat="urn:oasis:names:tc:SAML:2.0:attrname-format:uri">
         <saml2:AttributeValue xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:type="xs:string">urn:mace:dir:entitlement:common-lib-terms</saml2:AttributeValue>
      </saml2:Attribute>
      <saml2:Attribute FriendlyName="cn" Name="urn:oid:2.5.4.3" NameFormat="urn:oasis:names:tc:SAML:2.0:attrname-format:uri">
         <saml2:AttributeValue xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:type="xs:string">Me Myself And I</saml2:AttributeValue>
      </saml2:Attribute>
      <saml2:Attribute FriendlyName="eduPersonTargetedID" Name="urn:oid:1.3.6.1.4.1.5923.1.1.1.10" NameFormat="urn:oasis:names:tc:SAML:2.0:attrname-format:uri">
         <saml2:AttributeValue>
            <saml2:NameID Format="urn:oasis:names:tc:SAML:2.0:nameid-format:persistent" NameQualifier="https://idp.testshib.org/idp/shibboleth" SPNameQualifier="https://localhost/sprovide.xml">2TlhI3tY5yUFccod2wQ525EbDtI=</saml2:NameID>
         </saml2:AttributeValue>
      </saml2:Attribute>
      <saml2:Attribute FriendlyName="telephoneNumber" Name="urn:oid:2.5.4.20" NameFormat="urn:oasis:names:tc:SAML:2.0:attrname-format:uri">
         <saml2:AttributeValue xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:type="xs:string">555-5555</saml2:AttributeValue>
      </saml2:Attribute>
   </saml2:AttributeStatement>
</saml2:Assertion>

12:07:04.650 - ERROR [edu.internet2.middleware.shibboleth.idp.profile.saml2.AbstractSAML2ProfileHandler:927] - Could not resolve a key encryption credential for peer entity: https://localhost/sprovide.xml
12:07:04.651 - ERROR [edu.internet2.middleware.shibboleth.idp.profile.saml2.AbstractSAML2ProfileHandler:289] - Unable to construct encrypter
org.opensaml.xml.security.SecurityException: Could not resolve key encryption credential
    at edu.internet2.middleware.shibboleth.idp.profile.saml2.AbstractSAML2ProfileHandler.getEncrypter(AbstractSAML2ProfileHandler.java:928) ~[shibboleth-identityprovider-2.4.0.jar:na]
    at edu.internet2.middleware.shibboleth.idp.profile.saml2.AbstractSAML2ProfileHandler.buildResponse(AbstractSAML2ProfileHandler.java:286) ~[shibboleth-identityprovider-2.4.0.jar:na]
    at edu.internet2.middleware.shibboleth.idp.profile.saml2.SSOProfileHandler.completeAuthenticationRequest(SSOProfileHandler.java:319) [shibboleth-identityprovider-2.4.0.jar:na]
    at edu.internet2.middleware.shibboleth.idp.profile.saml2.SSOProfileHandler.processRequest(SSOProfileHandler.java:173) [shibboleth-identityprovider-2.4.0.jar:na]
    at edu.internet2.middleware.shibboleth.idp.profile.saml2.SSOProfileHandler.processRequest(SSOProfileHandler.java:90) [shibboleth-identityprovider-2.4.0.jar:na]
    at edu.internet2.middleware.shibboleth.common.profile.ProfileRequestDispatcherServlet.service(ProfileRequestDispatcherServlet.java:83) [shibboleth-common-1.4.0.jar:na]
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:717) [servlet-api.jar:na]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290) [catalina.jar:6.0.36]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [catalina.jar:6.0.36]
    at edu.internet2.middleware.shibboleth.idp.util.NoCacheFilter.doFilter(NoCacheFilter.java:50) [shibboleth-identityprovider-2.4.0.jar:na]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235) [catalina.jar:6.0.36]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [catalina.jar:6.0.36]
    at edu.internet2.middleware.shibboleth.idp.session.IdPSessionFilter.doFilter(IdPSessionFilter.java:87) [shibboleth-identityprovider-2.4.0.jar:na]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235) [catalina.jar:6.0.36]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [catalina.jar:6.0.36]
    at edu.internet2.middleware.shibboleth.common.log.SLF4JMDCCleanupFilter.doFilter(SLF4JMDCCleanupFilter.java:52) [shibboleth-common-1.4.0.jar:na]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235) [catalina.jar:6.0.36]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [catalina.jar:6.0.36]
    at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:219) [catalina.jar:6.0.36]
    at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191) [catalina.jar:6.0.36]
    at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:470) [catalina.jar:6.0.36]
    at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127) [catalina.jar:6.0.36]
    at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:103) [catalina.jar:6.0.36]
    at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109) [catalina.jar:6.0.36]
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:293) [catalina.jar:6.0.36]
    at org.apache.jk.server.JkCoyoteHandler.invoke(JkCoyoteHandler.java:190) [tomcat-coyote.jar:6.0.36]
    at org.apache.jk.common.HandlerRequest.invoke(HandlerRequest.java:311) [tomcat-coyote.jar:6.0.36]
    at org.apache.jk.common.ChannelSocket.invoke(ChannelSocket.java:776) [tomcat-coyote.jar:6.0.36]
    at org.apache.jk.common.ChannelSocket.processConnection(ChannelSocket.java:705) [tomcat-coyote.jar:6.0.36]
    at org.apache.jk.common.ChannelSocket$SocketConnection.runIt(ChannelSocket.java:898) [tomcat-coyote.jar:6.0.36]
    at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:690) [tomcat-coyote.jar:6.0.36]
    at java.lang.Thread.run(Thread.java:745) [na:1.7.0_55]
12:07:04.651 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.AbstractSAMLProfileHandler:796] - Encoding response to SAML request id-aiZ6edDhIYmMuTHcQ from relying party https://localhost/sprovide.xml


More information about the users mailing list