First Response Dispatched by mod_shib Before Metadata Reloading Completes?

Nate Klingenstein ndk at internet2.edu
Mon Sep 3 19:02:12 EDT 2012


I've got a 2.5.0 SP loading a folder of metadata with the new Folder  
MetadataProvider.  If I place a new metadata file in that folder and  
touch /etc/shibboleth/shibboleth2.xml, and then try accessing a  
SessionInitiator, the session initiator will dispatch a response(e.g.  
Unable to locate metadata for identity provider) before the metadata  
reloading is complete.

The response is not logged in shibd.log; I would have expected to see  
a 2012-09-03 18:59:49 WARN Shibboleth.SessionInitiator.SAML2 [8]:  
unable to locate metadata for provider.  It does appear in native.log.

shibd.log:
2012-09-03 18:53:13 DEBUG Shibboleth.Listener [7]: dispatching message  
(default/TestShib::run::SAML2SI)
2012-09-03 18:53:13 DEBUG Shibboleth.Config [7]: timestamp of local  
resource changed, elevating to a write lock
2012-09-03 18:53:13 INFO Shibboleth.Config [7]: change detected,  
signaling reload thread...
2012-09-03 18:53:13 INFO Shibboleth.Config : reloading local resource...
2012-09-03 18:53:13 DEBUG Shibboleth.Config : loading configuration  
from external resource...
(much configuration reloading)
2012-09-03 18:53:15 INFO OpenSAML.MetadataProvider.XML : reload thread  
finished
2012-09-03 18:53:15 INFO Shibboleth.SecurityPolicyProvider.XML :  
reload thread finished

native.log:
2012-09-03 18:53:13 ERROR Shibboleth.Listener [13506] shib_handler:  
remoted message returned an error: Unable to locate metadata for  
identity provider (https://idp.training.incommon.org/idp/shibboleth)
2012-09-03 18:53:13 ERROR Shibboleth.Apache [13506] shib_handler:  
Unable to locate metadata for identity provider (https://idp.training.incommon.org/idp/shibboleth 
)

As seen in shibd.log above, the new configuration (and new metadata  
file) are loaded after a few moments.  An identical request to the  
same SessionInitiator will now succeed and it is logged:

shibd.log:
2012-09-03 18:53:45 DEBUG Shibboleth.Listener [4]: dispatching message  
(default/TestShib::run::SAML2SI)
2012-09-03 18:53:45 DEBUG OpenSAML.MessageEncoder.SAML2Redirect [4]:  
validating input
2012-09-03 18:53:45 DEBUG OpenSAML.MessageEncoder.SAML2Redirect [4]:  
marshalling, deflating, base64-encoding the message
2012-09-03 18:53:45 DEBUG OpenSAML.MessageEncoder.SAML2Redirect [4]:  
marshalled message:
<samlp:AuthnRequest xmlns:samlp="urn:oasis:names:tc:SAML:2.0:protocol"  
AssertionConsumerServiceURL="https://sp.testshib.org/Shibboleth.sso/SAML2/POST 
" Destination="https://idp.testshib.org/idp/profile/SAML2/Redirect/ 
SSO" ID="_69a545d35ae9fdf7dd93f28664ae846e"  
IssueInstant="2012-09-03T22:53:45Z" ProtocolBinding="urn:oasis:names:tc:SAML:2.0:bindings:HTTP-POST 
" Version="2.0"><saml:Issuer xmlns:saml="urn:oasis:names:tc:SAML:2.0:assertion 
">https://sp.testshib.org/shibboleth-sp</ 
saml:Issuer><samlp:NameIDPolicy AllowCreate="1"/></samlp:AuthnRequest>
2012-09-03 18:53:45 DEBUG OpenSAML.MessageEncoder.SAML2Redirect [4]:  
message encoded, sending redirect to client

native.log:
2012-09-03 18:53:45 DEBUG Shibboleth.Config [13508] shib_handler:  
timestamp of local resource changed, elevating to a write lock
2012-09-03 18:53:45 INFO Shibboleth.Config [13508] shib_handler:  
change detected, signaling reload thread...
2012-09-03 18:53:45 DEBUG Shibboleth.Apache [13508] shib_handler:  
mapped https://sp.testshib.org/Shibboleth.sso/TestShib?entityID=https%3A%2F%2Fidp.training.incommon.org%2Fidp%2Fshibboleth 
  to default
2012-09-03 18:53:45 DEBUG Shibboleth.SessionInitiator.SAML2 [13508]  
shib_handler: attempting to initiate session using SAML 2.0 with  
provider (https://idp.training.incommon.org/idp/shibboleth)
2012-09-03 18:53:45 DEBUG Shibboleth.Listener [13508] shib_handler:  
sending message (default/TestShib::run::SAML2SI)

Is there anything I can do to get the metadata loaded by mod_shib  
before the first response is dispatched?

Thanks,
Nate.


More information about the users mailing list