21:54:40.171 - INFO [edu.internet2.middleware.shibboleth.common.config.BaseService:158] - Loading new configuration for service shibboleth.AttributeResolver
21:54:40.215 - INFO [edu.internet2.middleware.shibboleth.common.config.attribute.resolver.AbstractResolutionPlugInBeanDefinitionParser:55] - Parsing configuration for PrincipalConnector plugin with ID: shibTransient
21:54:40.215 - INFO [edu.internet2.middleware.shibboleth.common.config.attribute.resolver.AbstractResolutionPlugInBeanDefinitionParser:55] - Parsing configuration for PrincipalConnector plugin with ID: saml1Unspec
21:54:40.215 - INFO [edu.internet2.middleware.shibboleth.common.config.attribute.resolver.AbstractResolutionPlugInBeanDefinitionParser:55] - Parsing configuration for PrincipalConnector plugin with ID: saml2Transient
21:54:40.223 - INFO [edu.internet2.middleware.shibboleth.common.config.attribute.resolver.AbstractResolutionPlugInBeanDefinitionParser:55] - Parsing configuration for DataConnector plugin with ID: myLDAP
21:54:40.236 - INFO [edu.internet2.middleware.shibboleth.common.config.attribute.resolver.AbstractResolutionPlugInBeanDefinitionParser:55] - Parsing configuration for AttributeDefinition plugin with ID: uid
21:54:40.245 - INFO [edu.internet2.middleware.shibboleth.common.config.attribute.resolver.AbstractResolutionPlugInBeanDefinitionParser:55] - Parsing configuration for AttributeDefinition plugin with ID: email
21:54:40.249 - INFO [edu.internet2.middleware.shibboleth.common.config.attribute.resolver.AbstractResolutionPlugInBeanDefinitionParser:55] - Parsing configuration for AttributeDefinition plugin with ID: pagerNumber
21:54:40.249 - INFO [edu.internet2.middleware.shibboleth.common.config.attribute.resolver.AbstractResolutionPlugInBeanDefinitionParser:55] - Parsing configuration for AttributeDefinition plugin with ID: commonName
21:54:40.250 - INFO [edu.internet2.middleware.shibboleth.common.config.attribute.resolver.AbstractResolutionPlugInBeanDefinitionParser:55] - Parsing configuration for AttributeDefinition plugin with ID: surname
21:54:40.251 - INFO [edu.internet2.middleware.shibboleth.common.config.attribute.resolver.AbstractResolutionPlugInBeanDefinitionParser:55] - Parsing configuration for AttributeDefinition plugin with ID: locality
21:54:40.257 - INFO [edu.internet2.middleware.shibboleth.common.config.attribute.resolver.AbstractResolutionPlugInBeanDefinitionParser:55] - Parsing configuration for AttributeDefinition plugin with ID: givenName
21:54:40.258 - INFO [edu.internet2.middleware.shibboleth.common.config.attribute.resolver.AbstractResolutionPlugInBeanDefinitionParser:55] - Parsing configuration for AttributeDefinition plugin with ID: initials
21:54:40.259 - INFO [edu.internet2.middleware.shibboleth.common.config.attribute.resolver.AbstractResolutionPlugInBeanDefinitionParser:55] - Parsing configuration for AttributeDefinition plugin with ID: transientId
21:54:40.328 - DEBUG [edu.vt.middleware.ldap.handler.DefaultConnectionHandler:74] - Bind with the following parameters:
21:54:40.328 - DEBUG [edu.vt.middleware.ldap.handler.DefaultConnectionHandler:75] -   authtype = simple
21:54:40.328 - DEBUG [edu.vt.middleware.ldap.handler.DefaultConnectionHandler:76] -   dn = null
21:54:40.328 - DEBUG [edu.vt.middleware.ldap.handler.DefaultConnectionHandler:83] -   credential = <suppressed>
21:54:40.440 - DEBUG [edu.vt.middleware.ldap.handler.DefaultConnectionHandler:74] - Bind with the following parameters:
21:54:40.440 - DEBUG [edu.vt.middleware.ldap.handler.DefaultConnectionHandler:75] -   authtype = simple
21:54:40.440 - DEBUG [edu.vt.middleware.ldap.handler.DefaultConnectionHandler:76] -   dn = null
21:54:40.441 - DEBUG [edu.vt.middleware.ldap.handler.DefaultConnectionHandler:83] -   credential = <suppressed>
21:54:40.442 - INFO [edu.internet2.middleware.shibboleth.common.config.BaseService:180] - shibboleth.AttributeResolver service loaded new configuration
21:54:40.450 - INFO [edu.internet2.middleware.shibboleth.common.config.BaseService:158] - Loading new configuration for service shibboleth.AttributeFilterEngine
21:54:40.465 - INFO [edu.internet2.middleware.shibboleth.common.config.attribute.filtering.AttributeFilterPolicyBeanDefinitionParser:72] - Parsing configuration for attribute filter policy citrixShareFile_nameID
21:54:40.489 - INFO [edu.internet2.middleware.shibboleth.common.config.BaseService:180] - shibboleth.AttributeFilterEngine service loaded new configuration
21:54:40.501 - INFO [edu.internet2.middleware.shibboleth.common.config.BaseService:158] - Loading new configuration for service shibboleth.SAML1AttributeAuthority
21:54:40.507 - INFO [edu.internet2.middleware.shibboleth.common.config.BaseService:158] - Loading new configuration for service shibboleth.SAML2AttributeAuthority
21:54:40.515 - INFO [edu.internet2.middleware.shibboleth.common.config.BaseService:158] - Loading new configuration for service shibboleth.RelyingPartyConfigurationManager
21:54:40.618 - INFO [edu.internet2.middleware.shibboleth.common.config.relyingparty.RelyingPartyConfigurationBeanDefinitionParser:73] - Parsing configuration for relying party with id: anonymous
21:54:40.619 - INFO [edu.internet2.middleware.shibboleth.common.config.relyingparty.RelyingPartyConfigurationBeanDefinitionParser:73] - Parsing configuration for relying party with id: default
21:54:40.631 - INFO [edu.internet2.middleware.shibboleth.common.config.relyingparty.RelyingPartyConfigurationBeanDefinitionParser:73] - Parsing configuration for relying party with id: inw00003973
21:54:40.644 - INFO [edu.internet2.middleware.shibboleth.common.config.security.AbstractX509CredentialBeanDefinitionParser:63] - Parsing configuration for X509Filesystem credential with id: IdPCredential
21:54:40.706 - INFO [edu.internet2.middleware.shibboleth.common.config.security.ChainingSignatureTrustEngineBeanDefinitionParser:59] - Parsing configuration for SignatureChaining trust engine with id: shibboleth.SignatureTrustEngine
21:54:40.707 - INFO [edu.internet2.middleware.shibboleth.common.config.security.MetadataExplicitKeySignatureTrustEngineBeanDefinitionParser:50] - Parsing configuration for MetadataExplicitKeySignature trust engine with id: shibboleth.SignatureMetadataExplicitKeyTrustEngine
21:54:40.708 - INFO [edu.internet2.middleware.shibboleth.common.config.security.MetadataPKIXSignatureTrustEngineBeanDefinitionParser:52] - Parsing configuration for MetadataPKIXSignature trust engine with id: shibboleth.SignatureMetadataPKIXTrustEngine
21:54:40.709 - INFO [edu.internet2.middleware.shibboleth.common.config.security.ChainingTrustEngineBeanDefinitionParser:59] - Parsing configuration for Chaining trust engine with id: shibboleth.CredentialTrustEngine
21:54:40.710 - INFO [edu.internet2.middleware.shibboleth.common.config.security.MetadataExplicitKeyTrustEngineBeanDefinitionParser:48] - Parsing configuration for MetadataExplicitKey trust engine with id: shibboleth.CredentialMetadataExplictKeyTrustEngine
21:54:40.711 - INFO [edu.internet2.middleware.shibboleth.common.config.security.MetadataPKIXX509CredentialTrustEngineBeanDefinitionParser:52] - Parsing configuration for MetadataPKIXX509Credential trust engine with id: shibboleth.CredentialMetadataPKIXTrustEngine
21:54:42.245 - INFO [edu.internet2.middleware.shibboleth.common.config.BaseService:180] - shibboleth.RelyingPartyConfigurationManager service loaded new configuration
21:54:42.254 - INFO [edu.internet2.middleware.shibboleth.common.config.BaseService:158] - Loading new configuration for service shibboleth.HandlerManager
21:54:42.267 - INFO [edu.internet2.middleware.shibboleth.common.config.profile.JSPErrorHandlerBeanDefinitionParser:46] - Parsing configuration for JSP error handler.
21:54:42.475 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:125] - shibboleth.HandlerManager: Loading new configuration into service
21:54:42.476 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:149] - shibboleth.HandlerManager: Loading 1 new error handler.
21:54:42.476 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:152] - shibboleth.HandlerManager: Loaded new error handler of type: edu.internet2.middleware.shibboleth.common.profile.provider.JSPErrorHandler
21:54:42.476 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:162] - shibboleth.HandlerManager: Loading 17 new profile handlers.
21:54:42.479 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:183] - shibboleth.HandlerManager: Loading 2 new authentication handlers.
21:54:42.479 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:189] - shibboleth.HandlerManager: Loading authentication handler of type supporting authentication methods: [urn:oasis:names:tc:SAML:2.0:ac:classes:PasswordProtectedTransport]
21:54:42.479 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:189] - shibboleth.HandlerManager: Loading authentication handler of type supporting authentication methods: [urn:oasis:names:tc:SAML:2.0:ac:classes:PreviousSession]
21:54:42.479 - INFO [edu.internet2.middleware.shibboleth.common.config.BaseService:180] - shibboleth.HandlerManager service loaded new configuration
21:55:08.383 - INFO [Shibboleth-Access:73] - 20131121T162508Z|192.168.1.8|inw00003973:443|/profile/SAML2/Redirect/SSO|
21:55:08.385 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:86] - shibboleth.HandlerManager: Looking up profile handler for request path: /SAML2/Redirect/SSO
21:55:08.385 - 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
21:55:08.386 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.saml2.SSOProfileHandler:188] - Incoming request does not contain a login context, processing as first leg of request
21:55:08.386 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.saml2.SSOProfileHandler:366] - Decoding message with decoder binding 'urn:oasis:names:tc:SAML:2.0:bindings:HTTP-Redirect'
21:55:08.407 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.saml2.SSOProfileHandler:387] - Decoded request from relying party 'https://inw00003973:8443'
21:55:08.407 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.saml2.SSOProfileHandler:226] - Creating login context and transferring control to authentication engine
21:55:08.411 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.saml2.SSOProfileHandler:240] - Redirecting user to authentication engine at https://inw00003973:443/idp/AuthnEngine
21:55:08.416 - DEBUG [edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine:209] - Processing incoming request
21:55:08.417 - DEBUG [edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine:240] - Beginning user authentication process.
21:55:08.417 - 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@1b827f02, urn:oasis:names:tc:SAML:2.0:ac:classes:PasswordProtectedTransport=edu.internet2.middleware.shibboleth.idp.authn.provider.UsernamePasswordLoginHandler@14606a6a}
21:55:08.417 - DEBUG [edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine:332] - Filtering out previous session login handler because there is no existing IdP session
21:55:08.417 - 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:PasswordProtectedTransport=edu.internet2.middleware.shibboleth.idp.authn.provider.UsernamePasswordLoginHandler@14606a6a}
21:55:08.417 - DEBUG [edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine:497] - Authenticating user with login handler of type edu.internet2.middleware.shibboleth.idp.authn.provider.UsernamePasswordLoginHandler
21:55:08.417 - DEBUG [edu.internet2.middleware.shibboleth.idp.authn.provider.UsernamePasswordLoginHandler:66] - Redirecting to https://inw00003973:443/idp/Authn/UserPassword
21:55:08.485 - DEBUG [edu.internet2.middleware.shibboleth.idp.authn.provider.UsernamePasswordLoginServlet:150] - Redirecting to login page /login.jsp
21:55:10.929 - DEBUG [edu.internet2.middleware.shibboleth.idp.authn.provider.UsernamePasswordLoginServlet:170] - Attempting to authenticate user user1
21:55:10.948 - DEBUG [edu.vt.middleware.ldap.jaas.LdapLoginModule:180] - useFirstPass = false
21:55:10.949 - DEBUG [edu.vt.middleware.ldap.jaas.LdapLoginModule:181] - tryFirstPass = false
21:55:10.949 - DEBUG [edu.vt.middleware.ldap.jaas.LdapLoginModule:182] - storePass = false
21:55:10.950 - DEBUG [edu.vt.middleware.ldap.jaas.LdapLoginModule:183] - clearPass = false
21:55:10.950 - DEBUG [edu.vt.middleware.ldap.jaas.LdapLoginModule:184] - setLdapPrincipal = true
21:55:10.950 - DEBUG [edu.vt.middleware.ldap.jaas.LdapLoginModule:185] - setLdapDnPrincipal = false
21:55:10.951 - DEBUG [edu.vt.middleware.ldap.jaas.LdapLoginModule:186] - setLdapCredential = true
21:55:10.951 - DEBUG [edu.vt.middleware.ldap.jaas.LdapLoginModule:187] - defaultRole = []
21:55:10.951 - DEBUG [edu.vt.middleware.ldap.jaas.LdapLoginModule:188] - principalGroupName = null
21:55:10.952 - DEBUG [edu.vt.middleware.ldap.jaas.LdapLoginModule:189] - roleGroupName = null
21:55:10.952 - DEBUG [edu.vt.middleware.ldap.jaas.LdapLoginModule:77] - userRoleAttribute = []
21:55:10.966 - DEBUG [edu.vt.middleware.ldap.jaas.LdapLoginModule:83] - Created authenticator: edu.vt.middleware.ldap.auth.AuthenticatorConfig@324353357::env={java.naming.provider.url=ldap://127.0.0.1:389, java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory}
21:55:10.968 - DEBUG [edu.vt.middleware.ldap.auth.SearchDnResolver:102] - Looking up DN using userFilter
21:55:10.968 - DEBUG [edu.vt.middleware.ldap.auth.SearchDnResolver:193] - Search with the following parameters:
21:55:10.969 - DEBUG [edu.vt.middleware.ldap.auth.SearchDnResolver:194] -   dn = ou=People,dc=maxcrc,dc=com
21:55:10.969 - DEBUG [edu.vt.middleware.ldap.auth.SearchDnResolver:195] -   filter = cn={0}
21:55:10.969 - DEBUG [edu.vt.middleware.ldap.auth.SearchDnResolver:196] -   filterArgs = [user1]
21:55:10.969 - DEBUG [edu.vt.middleware.ldap.auth.SearchDnResolver:197] -   searchControls = javax.naming.directory.SearchControls@747a3e3e
21:55:10.969 - DEBUG [edu.vt.middleware.ldap.auth.SearchDnResolver:198] -   handler = [edu.vt.middleware.ldap.handler.FqdnSearchResultHandler@58c9430]
21:55:10.970 - DEBUG [edu.vt.middleware.ldap.handler.DefaultConnectionHandler:74] - Bind with the following parameters:
21:55:10.970 - DEBUG [edu.vt.middleware.ldap.handler.DefaultConnectionHandler:75] -   authtype = simple
21:55:10.970 - DEBUG [edu.vt.middleware.ldap.handler.DefaultConnectionHandler:76] -   dn = null
21:55:10.970 - DEBUG [edu.vt.middleware.ldap.handler.DefaultConnectionHandler:83] -   credential = <suppressed>
21:55:10.981 - DEBUG [edu.vt.middleware.ldap.handler.DefaultConnectionHandler:74] - Bind with the following parameters:
21:55:10.981 - DEBUG [edu.vt.middleware.ldap.handler.DefaultConnectionHandler:75] -   authtype = simple
21:55:10.981 - DEBUG [edu.vt.middleware.ldap.handler.DefaultConnectionHandler:76] -   dn = cn=user1,ou=People,dc=maxcrc,dc=com
21:55:10.981 - DEBUG [edu.vt.middleware.ldap.handler.DefaultConnectionHandler:83] -   credential = <suppressed>
21:55:10.984 - INFO [edu.vt.middleware.ldap.jaas.JaasAuthenticator:176] - Authentication succeeded for dn: cn=user1,ou=People,dc=maxcrc,dc=com
21:55:10.993 - DEBUG [edu.vt.middleware.ldap.auth.SearchDnResolver:102] - Looking up DN using userFilter
21:55:10.993 - DEBUG [edu.vt.middleware.ldap.auth.SearchDnResolver:193] - Search with the following parameters:
21:55:10.994 - DEBUG [edu.vt.middleware.ldap.auth.SearchDnResolver:194] -   dn = ou=People,dc=maxcrc,dc=com
21:55:10.994 - DEBUG [edu.vt.middleware.ldap.auth.SearchDnResolver:195] -   filter = cn={0}
21:55:10.994 - DEBUG [edu.vt.middleware.ldap.auth.SearchDnResolver:196] -   filterArgs = [user1]
21:55:10.994 - DEBUG [edu.vt.middleware.ldap.auth.SearchDnResolver:197] -   searchControls = javax.naming.directory.SearchControls@4adaead8
21:55:10.994 - DEBUG [edu.vt.middleware.ldap.auth.SearchDnResolver:198] -   handler = [edu.vt.middleware.ldap.handler.FqdnSearchResultHandler@58c9430]
21:55:10.997 - DEBUG [edu.vt.middleware.ldap.jaas.LdapLoginModule:223] - Committed the following principals: [user1[]]
21:55:10.998 - DEBUG [edu.vt.middleware.ldap.jaas.LdapLoginModule:229] - Committed the following roles: []
21:55:10.998 - DEBUG [edu.internet2.middleware.shibboleth.idp.authn.provider.UsernamePasswordLoginServlet:178] - Successfully authenticated user user1
21:55:10.999 - DEBUG [edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine:144] - Returning control to authentication engine
21:55:11.000 - DEBUG [edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine:209] - Processing incoming request
21:55:11.000 - DEBUG [edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine:514] - Completing user authentication process
21:55:11.000 - DEBUG [edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine:585] - Validating authentication was performed successfully
21:55:11.000 - DEBUG [edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine:696] - Updating session information for principal user1
21:55:11.000 - DEBUG [edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine:700] - Creating shibboleth session for principal user1
21:55:11.002 - DEBUG [edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine:815] - Adding IdP session cookie to HTTP response
21:55:11.003 - DEBUG [edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine:715] - Recording authentication and service information in Shibboleth session for principal: user1
21:55:11.005 - DEBUG [edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine:560] - User user1 authenticated with method urn:oasis:names:tc:SAML:2.0:ac:classes:PasswordProtectedTransport
21:55:11.005 - DEBUG [edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine:161] - Returning control to profile handler
21:55:11.005 - DEBUG [edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine:177] - Redirecting user to profile handler at https://inw00003973:443/idp/profile/SAML2/Redirect/SSO
21:55:11.009 - INFO [Shibboleth-Access:73] - 20131121T162511Z|192.168.1.8|inw00003973:443|/profile/SAML2/Redirect/SSO|
21:55:11.009 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:86] - shibboleth.HandlerManager: Looking up profile handler for request path: /SAML2/Redirect/SSO
21:55:11.009 - 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
21:55:11.009 - 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
21:55:11.013 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.saml2.AbstractSAML2ProfileHandler:478] - Resolving attributes for principal 'user1' for SAML request from relying party 'https://inw00003973:8443'
21:55:11.041 - DEBUG [edu.vt.middleware.ldap.handler.DefaultConnectionHandler:74] - Bind with the following parameters:
21:55:11.041 - DEBUG [edu.vt.middleware.ldap.handler.DefaultConnectionHandler:75] -   authtype = simple
21:55:11.042 - DEBUG [edu.vt.middleware.ldap.handler.DefaultConnectionHandler:76] -   dn = null
21:55:11.042 - DEBUG [edu.vt.middleware.ldap.handler.DefaultConnectionHandler:83] -   credential = <suppressed>
21:55:11.044 - DEBUG [edu.vt.middleware.ldap.Ldap:193] - Search with the following parameters:
21:55:11.045 - DEBUG [edu.vt.middleware.ldap.Ldap:194] -   dn = dc=maxcrc,dc=com
21:55:11.045 - DEBUG [edu.vt.middleware.ldap.Ldap:195] -   filter = (uid=user1)
21:55:11.045 - DEBUG [edu.vt.middleware.ldap.Ldap:196] -   filterArgs = []
21:55:11.045 - DEBUG [edu.vt.middleware.ldap.Ldap:197] -   searchControls = javax.naming.directory.SearchControls@5b4ca52d
21:55:11.045 - DEBUG [edu.vt.middleware.ldap.Ldap:198] -   handler = [edu.vt.middleware.ldap.handler.FqdnSearchResultHandler@4f05c2f, edu.vt.middleware.ldap.handler.EntryDnSearchResultHandler@40341431, edu.vt.middleware.ldap.handler.BinarySearchResultHandler@1b19bde5]
21:55:11.053 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.saml2.AbstractSAML2ProfileHandler:505] - Creating attribute statement in response to SAML request '6bf05b7b-46e9-4c5b-8ecd-b66130ff4bb6' from relying party 'https://inw00003973:8443'
21:55:11.059 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.AbstractSAMLProfileHandler:483] - Attempting to select name identifier attribute for relying party 'https://inw00003973:8443' that requires format 'urn:oasis:names:tc:SAML:1.1:nameid-format:emailAddress'
21:55:11.059 - WARN [edu.internet2.middleware.shibboleth.idp.profile.AbstractSAMLProfileHandler:491] - No attribute of principal 'user1' can be encoded in to a NameIdentifier of required format 'urn:oasis:names:tc:SAML:1.1:nameid-format:emailAddress' for relying party 'https://inw00003973:8443'
21:55:11.061 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.AbstractSAMLProfileHandler:796] - Encoding response to SAML request 6bf05b7b-46e9-4c5b-8ecd-b66130ff4bb6 from relying party https://inw00003973:8443
21:55:11.076 - INFO [Shibboleth-Audit:1028] - 20131121T162511Z|urn:oasis:names:tc:SAML:2.0:bindings:HTTP-Redirect|6bf05b7b-46e9-4c5b-8ecd-b66130ff4bb6|https://inw00003973:8443|urn:mace:shibboleth:2.0:profiles:saml2:sso|https://inw00003973/idp/shibboleth|urn:oasis:names:tc:SAML:2.0:bindings:HTTP-POST|_ad29b8ed0b1e3281b552a70c0411f3a8|user1|urn:oasis:names:tc:SAML:2.0:ac:classes:PasswordProtectedTransport||||