[Shib-Users] Shiboleth SP 2.4 Problem - xmltooling::IOException
Shaji Nair
i installed the new SP and configured it to protect an URL in an apache web
server. When I access the URL I'm getting this error
xmltooling::IOException
The system encountered an error at Tue Dec 14 19:45:06 2010
To report this problem, please contact the site administrator at
root@localhost.
Please include the following message in any email:
xmltooling::IOException at (https://hapc1.praveendomain.com/secure)
Attempted to insert duplicate storage key.
Further the native log cantains these line :
2010-12-14 19:45:06 ERROR Shibboleth.Listener [1040] shib_check_user: remoted
message returned an error: Attempted to insert duplicate storage key.
2010-12-14 19:45:06 ERROR Shibboleth.Apache [1040] shib_check_user: Attempted
to insert duplicate storage key.
------------------------------------------------------------------------------
------------
Changed the below lines in shibboleth2.xml :
<RequestMapper type="Native">
<RequestMap>
<Host name="hapc1.praveendomain.com">
<Path name="secure" authType="shibboleth"
requireSession="true"/>
</Host>
</RequestMap>
</RequestMapper>
....
<ApplicationDefaults entityID="https://hapc1.praveendomain.com/shibboleth"
REMOTE_USER="eppn persistent-id targeted-id">
...
<SSO entityID="https://shaji.fischer.com/idp/shibboleth"
discoveryProtocol="SAMLDS"
discoveryURL="https://ds.example.org/DS/WAYF">
SAML2 SAML1
</SSO>
...
<!-- added metadata for idp -->
<MetadataProvider type="XML" file="idp-metadata.xml"/>
...
Can anyone please tell me how to fix the issue,
Thanks
Shaji Nair
Cantor, Scott E.
>web
>server. When I access the URL I'm getting this error
Did you have an older version installed and working, or is this new? I
don't care, but I'm more concerned about regressions than anything else.
>Further the native log cantains these line :
>2010-12-14 19:45:06 ERROR Shibboleth.Listener [1040] shib_check_user:
>remoted
>message returned an error: Attempted to insert duplicate storage key.
>2010-12-14 19:45:06 ERROR Shibboleth.Apache [1040] shib_check_user:
>Attempted
>to insert duplicate storage key.
Wrong log. I'd need to know what's using the storage service, which is
always a shibd issue.
><SSO entityID="https://shaji.fischer.com/idp/shibboleth"
> discoveryProtocol="SAMLDS"
>discoveryURL="https://ds.example.org/DS/WAYF">
> SAML2 SAML1
> </SSO>
It won't break, but it's very confusing to anybody else looking at the
config to have both an entityID and discovery bits in the element.
-- Scott
Shaji Nair
Thanks for the reply. I had an older version that was working fine.
17:26:05.669 - DEBUG [org.opensaml.common.binding.decoding.BaseSAMLMessageDecoder:190] - Checking SAML message intended destination endpoint against receiver endpoint
17:26:05.669 - DEBUG [org.opensaml.common.binding.decoding.BaseSAMLMessageDecoder:209] - Intended message destination endpoint: https://shaji.fischer.com:8443/idp/profile/SAML2/Redirect/SSO
17:26:05.669 - DEBUG [org.opensaml.common.binding.decoding.BaseSAMLMessageDecoder:210] - Actual message receiver endpoint: https://shaji.fischer.com:8443/idp/profile/SAML2/Redirect/SSO
17:26:05.669 - DEBUG [org.opensaml.common.binding.decoding.BaseSAMLMessageDecoder:218] - SAML message intended destination endpoint matched recipient endpoint
17:26:05.669 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.saml2.SSOProfileHandler:325] - Decoded request from relying party 'secure'
17:26:05.670 - DEBUG [org.opensaml.saml2.metadata.provider.ChainingMetadataProvider:199] - Checking child metadata provider for entity descriptor with entity ID: secure
17:26:05.670 - DEBUG [org.opensaml.saml2.metadata.provider.AbstractMetadataProvider:509] - Searching for entity descriptor with an entity ID of secure
17:26:05.670 - DEBUG [org.opensaml.saml2.metadata.provider.AbstractMetadataProvider:166] - Metadata document does not contain an EntityDescriptor with the ID secure
17:26:05.670 - DEBUG [org.opensaml.saml2.metadata.provider.AbstractMetadataProvider:170] - Metadata document contained an EntityDescriptor with the ID secure, but it was no longer valid
17:26:05.670 - DEBUG [org.opensaml.saml2.metadata.provider.ChainingMetadataProvider:199] - Checking child metadata provider for entity descriptor with entity ID: secure
17:26:05.670 - DEBUG [org.opensaml.saml2.metadata.provider.AbstractMetadataProvider:509] - Searching for entity descriptor with an entity ID of secure
17:26:05.670 - DEBUG [edu.internet2.middleware.shibboleth.common.relyingparty.provider.SAMLMDRelyingPartyConfigurationManager:126] - Looking up relying party configuration for secure
17:26:05.670 - DEBUG [edu.internet2.middleware.shibboleth.common.relyingparty.provider.SAMLMDRelyingPartyConfigurationManager:132] - No custom relying party configuration found for secure, looking up configuration based on metadata groups.
17:26:05.670 - DEBUG [org.opensaml.saml2.metadata.provider.ChainingMetadataProvider:199] - Checking child metadata provider for entity descriptor with entity ID: secure
17:26:05.670 - DEBUG [org.opensaml.saml2.metadata.provider.AbstractMetadataProvider:509] - Searching for entity descriptor with an entity ID of secure
17:26:05.670 - DEBUG [org.opensaml.saml2.metadata.provider.AbstractMetadataProvider:166] - Metadata document does not contain an EntityDescriptor with the ID secure
17:26:05.670 - DEBUG [org.opensaml.saml2.metadata.provider.AbstractMetadataProvider:170] - Metadata document contained an EntityDescriptor with the ID secure, but it was no longer valid
17:26:05.671 - DEBUG [org.opensaml.saml2.metadata.provider.ChainingMetadataProvider:199] - Checking child metadata provider for entity descriptor with entity ID: secure
17:26:05.671 - DEBUG [org.opensaml.saml2.metadata.provider.AbstractMetadataProvider:509] - Searching for entity descriptor with an entity ID of secure
17:26:05.671 - DEBUG [edu.internet2.middleware.shibboleth.common.relyingparty.provider.SAMLMDRelyingPartyConfigurationManager:155] - No custom or group-based relying party configuration found for secure. Using default relying party configuration.
17:26:05.671 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.saml2.SSOProfileHandler:198] - Creating login context and transferring control to authentication engine
17:26:05.673 - DEBUG [edu.internet2.middleware.shibboleth.idp.util.HttpServletHelper:166] - Storing LoginContext to StorageService partition loginContexts, key 93a5a262-f84e-48a0-9224-d01b1b7d3dc3
17:26:05.673 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.saml2.SSOProfileHandler:211] - Redirecting user to authentication engine at https://shaji.fischer.com:8443/idp/AuthnEngine
17:26:05.675 - DEBUG [edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine:203] - Processing incoming request
17:26:05.675 - DEBUG [edu.internet2.middleware.shibboleth.idp.util.HttpServletHelper:326] - Looking up LoginContext with key 93a5a262-f84e-48a0-9224-d01b1b7d3dc3 from StorageService parition: loginContexts
17:26:05.675 - DEBUG [edu.internet2.middleware.shibboleth.idp.util.HttpServletHelper:332] - Retrieved LoginContext with key 93a5a262-f84e-48a0-9224-d01b1b7d3dc3 from StorageService parition: loginContexts
17:26:05.675 - DEBUG [edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine:233] - Beginning user authentication process.
17:26:05.675 - DEBUG [edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine:237] - Existing IdP session available for principal null
17:26:05.675 - DEBUG [edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine:279] - Filtering configured LoginHandlers: {urn:oasis:names:tc:SAML:2.0:ac:classes:PreviousSession=edu.internet2.middleware.shibboleth.idp.authn.provider.PreviousSessionLoginHandler@13e00b, urn:oasis:names:tc:SAML:2.0:ac:classes:unspecified=edu.internet2.middleware.shibboleth.idp.authn.provider.RemoteUserLoginHandler@da2ebd}
17:26:05.676 - DEBUG [edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine:344] - Filtering out previous session login handler because there are no active authentication methods
17:26:05.676 - DEBUG [edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine:463] - Selecting appropriate login handler from filtered set {urn:oasis:names:tc:SAML:2.0:ac:classes:unspecified=edu.internet2.middleware.shibboleth.idp.authn.provider.RemoteUserLoginHandler@da2ebd}
17:26:05.676 - DEBUG [edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine:496] - Authenticating user with login handler of type edu.internet2.middleware.shibboleth.idp.authn.provider.RemoteUserLoginHandler
17:26:05.676 - DEBUG [edu.internet2.middleware.shibboleth.idp.util.HttpServletHelper:166] - Storing LoginContext to StorageService partition loginContexts, key db69381a-bba3-41b6-a3aa-b26d54c46e13
17:26:05.676 - DEBUG [edu.internet2.middleware.shibboleth.idp.authn.provider.RemoteUserLoginHandler:75] - Redirecting to https://shaji.fischer.com:8443/idp/Authn/RemoteUser
17:26:05.678 - DEBUG [edu.internet2.middleware.shibboleth.idp.authn.provider.RemoteUserAuthServlet:47] - Remote user identified as null returning control back to authentication engine
17:26:05.678 - DEBUG [edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine:144] - Returning control to authentication engine
17:26:05.678 - DEBUG [edu.internet2.middleware.shibboleth.idp.util.HttpServletHelper:326] - Looking up LoginContext with key db69381a-bba3-41b6-a3aa-b26d54c46e13 from StorageService parition: loginContexts
17:26:05.678 - DEBUG [edu.internet2.middleware.shibboleth.idp.util.HttpServletHelper:332] - Retrieved LoginContext with key db69381a-bba3-41b6-a3aa-b26d54c46e13 from StorageService parition: loginContexts
17:26:05.678 - DEBUG [edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine:203] - Processing incoming request
17:26:05.678 - DEBUG [edu.internet2.middleware.shibboleth.idp.util.HttpServletHelper:326] - Looking up LoginContext with key db69381a-bba3-41b6-a3aa-b26d54c46e13 from StorageService parition: loginContexts
17:26:05.678 - DEBUG [edu.internet2.middleware.shibboleth.idp.util.HttpServletHelper:332] - Retrieved LoginContext with key db69381a-bba3-41b6-a3aa-b26d54c46e13 from StorageService parition: loginContexts
17:26:05.679 - DEBUG [edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine:513] - Completing user authentication process
17:26:05.679 - DEBUG [edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine:572] - Validating authentication was performed successfully
17:26:05.679 - DEBUG [edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine:675] - Updating session information for principal null
...
xmlns="urn:mace:shibboleth:2.0:metadata"
id="sp-secure" requireValidMetadata="false"
metadataFile="D:/Softwares/Shib/shibboleth-idp/metadata/sp-metadata.xml" />
Cantor, Scott E.
> service requires cookies. Please ensure that they are enabled and try your
> going back to your desired resource and trying to login again"
Possibly the IdP is crashing, that seems to be a common source of that message. I'd check other logs.
> I dont understand why this line came : " Metadata document contained an
> EntityDescriptor with the ID secure, but it was no longer valid"
Well, for starters you have a completely bogus entityID in the SP apparently, it's not naming itself with a URL.
> I generated the metadata with the SP URL
> https://hapc1.praveendomain.com/secure/Shibboleth.sso/Metadata.
> and it doent not contain "validUntil" attribute.
Then start by making sure you understand the metadata, make sure it's correct, do not give it to the IdP via that URL without some kind of oversight of what's actually in it, and make sure the entityID the SP is using is a URL and that it matches the entityID in the metadata.
-- Scott
Cantor, Scott E.
> > https://hapc1.praveendomain.com/secure/Shibboleth.sso/Metadata.
> > and it doent not contain "validUntil" attribute.
That's also a questionable URL, BTW. The handlerURL should not live inside the /secure directory, so that suggests you have some strange mojo going on in your config that you'd better understand, or undo it and revert to a more traditional config.
-- Scott