Shib IdP 2.4 metadata refresh bug?

[Michael A Grady]

I've been trying to help someone running IdP 2.4 / Tomcat 6 on Windows 2008 R2 with a problem where the InCommon metadata is not refreshing. After ruling out all other reasons for it not to be refreshing, and turning on debug for metadata, I see where the check for InCommon metadata was happening just fine, until it seemed to reach a point where, during an update of that metadata, the timer went off for a refresh of its own (idp-metadata.xml) file. Which seemed to not only "stomp on" the current refresh of the InCommon metadata, but also prevent a new timer being set for the next update, so subsequent to the below, there was never again a check to see if the InCommon metadata needed updating. See log lines at end of this note.

Now its quite hard for me to believe that such a problem could never have occurred somewhere else, if indeed there was an underlying bug. But I can't see anything odd about the relying-party config, nothing out of the range of ordinary.

Now one strategy to get around this would seem to be to just stop it from reloading its own metadata (idp-metadata), but there also seems to be a limit to how large of duration a minRefreshDelay can be -- we tried P365D, and then P5M, but both produced the error on restart of:

10:39:42.896 - ERROR [edu.internet2.middleware.shibboleth.common.config.BaseService:188] - Configuration was not loaded for shibboleth.RelyingPartyConfigurationManager service, error creating components.  The root cause of this error was: java.lang.IllegalArgumentException: Cannot convert value of type [java.lang.Long] to required type [int] for property 'minRefreshDelay': PropertyEditor [org.springframework.beans.propertyeditors.CustomNumberEditor] returned inappropriate value

What is the max allowed time for minRefreshDelay? I'd try just leaving the IdP's metadata out (not sure that would start up), but there is another file metadata source also, so I was trying to find some combination of refresh factors to minimize the chance of this occurring.


18:00:45.178 - DEBUG [org.opensaml.saml2.metadata.provider.AbstractReloadingMetadataProvider:253] - Beginning refresh of metadata from 'http://md.incommon.org/InCommon/InCommon-metadata.xml';
18:00:45.178 - DEBUG [org.opensaml.saml2.metadata.provider.HTTPMetadataProvider:249] - Attempting to fetch metadata document from 'http://md.incommon.org/InCommon/InCommon-metadata.xml';
18:00:53.069 - DEBUG [org.opensaml.saml2.metadata.provider.HTTPMetadataProvider:334] - Attempting to extract metadata from response to request for metadata from 'http://md.incommon.org/InCommon/InCommon-metadata.xml';
18:00:58.319 - DEBUG [org.opensaml.saml2.metadata.provider.HTTPMetadataProvider:268] - Successfully fetched 12968056bytes of metadata from http://md.incommon.org/InCommon/InCommon-metadata.xml
18:00:58.319 - DEBUG [org.opensaml.saml2.metadata.provider.AbstractReloadingMetadataProvider:260] - Processing new metadata from 'http://md.incommon.org/InCommon/InCommon-metadata.xml';
18:00:58.319 - DEBUG [org.opensaml.saml2.metadata.provider.AbstractReloadingMetadataProvider:344] - Unmarshalling metadata from 'http://md.incommon.org/InCommon/InCommon-metadata.xml';
18:45:56.850 - DEBUG [org.opensaml.saml2.metadata.provider.AbstractReloadingMetadataProvider:253] - Beginning refresh of metadata from 'C:\opt\shibboleth-idp\metadata\idp-metadata.xml'
18:45:56.850 - DEBUG [org.opensaml.saml2.metadata.provider.AbstractReloadingMetadataProvider:257] - Metadata from 'C:\opt\shibboleth-idp\metadata\idp-metadata.xml' has not changed since last refresh
18:45:56.850 - DEBUG [org.opensaml.saml2.metadata.provider.AbstractReloadingMetadataProvider:322] - Computing new expiration time for cached metadata from 'C:\opt\shibboleth-idp\metadata\idp-metadata.xml
18:45:56.850 - INFO [org.opensaml.saml2.metadata.provider.AbstractReloadingMetadataProvider:271] - Next refresh cycle for metadata provider 'C:\opt\shibboleth-idp\metadata\idp-metadata.xml' will occur on '2015-04-16T01:45:56.850Z' ('2015-04-15T21:45:56.850-04:00' local time)
21:45:56.850 - DEBUG [org.opensaml.saml2.metadata.provider.AbstractReloadingMetadataProvider:253] - Beginning refresh of metadata from 'C:\opt\shibboleth-idp\metadata\idp-metadata.xml'



--
Michael A. Grady
Senior IAM Consultant, Unicon, Inc.