metadata refresh frequency on IDP 3.3.x

[Liam Hoekenga]

I've got a filesystem metadata provider on my IDP for my campus
federation.  Nothing fancy:

    <MetadataProvider id="umichFederation"
xsi:type="FilesystemMetadataProvider"
metadataFile="/opt/shibboleth-idp/metadata/umfed.xml">
        <MetadataFilter xsi:type="SignatureValidation"
certificateFile=/etc/pki/tls/certs/um-md-sign.pem"/>
        <MetadataFilter xsi:type="EntityRoleWhiteList">
            <RetainedRole>md:SPSSODescriptor</RetainedRole>
        </MetadataFilter>
    </MetadataProvider>

I'm somewhat confused by the frequency at which the IDP is reloading the
metadata.  Based on
https://wiki.shibboleth.net/confluence/display/IDP30/MetadataConfiguration#MetadataConfiguration-ReloadingAttributes,
it looks like it could be anywhere from every 30 seconds to every 4 hours.

What I'm seeing seems seems like anywhere between 30s - a few minutes, with
the "Next refresh cycle ... will occur on..." seemingly being false, but it
you look through the slew of messages, you can find it's corresponding mate:

2017-09-08 00:00:16,574 - INFO
[org.opensaml.saml.metadata.resolver.impl.AbstractReloadingMetadataResolver:306]
-  - Metadata Resolver FilesystemMetadataResolver umichFederation: Next
refresh cycle for metadata provider
'/opt/shibboleth-idp/metadata/umfed.xml' will occur on
'2017-09-08T08:00:16.572Z' ('2017-09-08T04:00:16.572-04:00' local time)
2017-09-08 00:02:29,765 - INFO
[org.opensaml.saml.metadata.resolver.impl.AbstractReloadingMetadataResolver:306]
-  - Metadata Resolver FilesystemMetadataResolver umichFederation: Next
refresh cycle for metadata provider
'/opt/shibboleth-idp/metadata/umfed.xml' will occur on
'2017-09-08T04:07:29.765Z' ('2017-09-08T00:07:29.765-04:00' local time)
2017-09-08 00:03:03,347 - INFO
[org.opensaml.saml.metadata.resolver.impl.AbstractReloadingMetadataResolver:306]
-  - Metadata Resolver FilesystemMetadataResolver umichFederation: Next
refresh cycle for metadata provider
'/opt/shibboleth-idp/metadata/umfed.xml' will occur on
'2017-09-08T04:08:03.347Z' ('2017-09-08T00:08:03.347-04:00' local time)
2017-09-08 00:04:18,800 - INFO
[org.opensaml.saml.metadata.resolver.impl.AbstractReloadingMetadataResolver:306]
-  - Metadata Resolver FilesystemMetadataResolver umichFederation: Next
refresh cycle for metadata provider
'/opt/shibboleth-idp/metadata/umfed.xml' will occur on
'2017-09-08T04:09:18.800Z' ('2017-09-08T00:09:18.800-04:00' local time)
2017-09-08 00:07:29,775 - INFO
[org.opensaml.saml.metadata.resolver.impl.AbstractReloadingMetadataResolver:306]
-  - Metadata Resolver FilesystemMetadataResolver umichFederation: Next
refresh cycle for metadata provider
'/opt/shibboleth-idp/metadata/umfed.xml' will occur on
'2017-09-08T04:12:29.775Z' ('2017-09-08T00:12:29.775-04:00' local time)


Can anyone shed any light on how the IDP is deciding to reload the
metadata?  I guess the periodicity is getting influenced by refreshDelayFactor,
but it seems like i've got several different refresh cycles (5?) in play.

thanks!
Liam
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://shibboleth.net/pipermail/users/attachments/20170908/32a752d9/attachment.html>