After upgrade to V2.2, the IdP attempts to refresh its copy of the federation metadata about every 5 minutes.
Description
Environment
Activity
Scott Cantor January 10, 2011 at 3:56 PM
Fixed in rev. 1496.
There seems to be a separate bug causing Resource-Backed file metadata to be reloaded twice on each interval, I'll open a separate bug to keep that straight.
Scott Cantor January 7, 2011 at 1:09 PM
Looking closer at AbstractReloadingMetadataProvider, I think the bug is in the processCachedMetadata helper. It's calculating the metadata expiration time, but it passes the object member expirationTime in to the computeNext method instead of the calculated expiration. Or it should be overwriting the object member first.
Result is that it gets "stuck" with the old expirationTime value and never changes it, which causes computeNext to keep returning the min interval.
Scott Cantor December 22, 2010 at 5:08 PM
I think it might be related to this code in computeNextRefreshDelay:
long expireInstant = 0;
if (expectedExpiration != null) {
expireInstant = expectedExpiration.toDateTime(ISOChronology.getInstanceUTC()).getMillis();
}
long refreshDelay = (long) ((expireInstant - now) * getRefreshDelayFactor());
I'm not sure under what conditions expectedExpiration might be null, but if it were, refreshDelay will go negative, and end up as minRefreshDelay.
Rod Widdowson October 7, 2010 at 11:41 AM(edited)
Sample DEBUG log at start for a metadata file with one toplevel validUntil="2010-02-24T17:03:52Z" and no cacheDuration.
16:54:45.644 - DEBUG [org.opensaml.saml2.metadata.provider.AbstractReloadingMetadataProvider:230] - Beginning refresh of metadata from 'C:\Program Files\Internet2\Shib2Idp\metadata\idp-metadata.xml'
16:54:45.644 - DEBUG [org.opensaml.saml2.metadata.provider.AbstractReloadingMetadataProvider:240] - Processing new metadata from 'C:\Program Files\Internet2\Shib2Idp\metadata\idp-metadata.xml'
16:54:45.644 - DEBUG [org.opensaml.saml2.metadata.provider.AbstractReloadingMetadataProvider:320] - Unmarshalling metadata from 'C:\Program Files\Internet2\Shib2Idp\metadata\idp-metadata.xml'
16:54:45.644 - DEBUG [org.opensaml.saml2.metadata.provider.AbstractReloadingMetadataProvider:366] - Filtering metadata from 'C:\Program Files\Internet2\Shib2Idp\metadata\idp-metadata.xml'
16:54:45.644 - DEBUG [org.opensaml.saml2.metadata.provider.AbstractReloadingMetadataProvider:375] - Releasing cached DOM for metadata from 'C:\Program Files\Internet2\Shib2Idp\metadata\idp-metadata.xml'
16:54:45.644 - DEBUG [org.opensaml.saml2.metadata.provider.AbstractReloadingMetadataProvider:378] - Post-processing metadata from 'C:\Program Files\Internet2\Shib2Idp\metadata\idp-metadata.xml'
16:54:45.644 - DEBUG [org.opensaml.saml2.metadata.provider.AbstractReloadingMetadataProvider:381] - Computing expiration time for metadata from 'C:\Program Files\Internet2\Shib2Idp\metadata\idp-metadata.xml'
16:54:45.644 - DEBUG [org.opensaml.saml2.metadata.provider.AbstractReloadingMetadataProvider:384] - Expiration of metadata from 'C:\Program Files\Internet2\Shib2Idp\metadata\idp-metadata.xml' will occur at 2010-10-07T19:54:45.644Z
16:54:45.644 - INFO [org.opensaml.saml2.metadata.provider.AbstractReloadingMetadataProvider:402] - New metadata loaded from 'C:\Program Files\Internet2\Shib2Idp\metadata\idp-metadata.xml', next refresh will occur at approximately 2010-10-07T18:54:45.644Z
After upgrade to V2.2, the IdP attempts to refresh its copy of the federation metadata about every 5 minutes. Prior to the upgrade, it was refreshing the metadata at 8 hour intervals.
I initially thought that this was happening because I hadn't converted the time-related properties in relying-party.xml to duration notation, but after doing this (using the values recommended in the WARN log lines in idp-process.log) it is still refreshing approximately every 5 minutes (using conditional gets, fortunately).