A problem with metadata:FilesystemMetadataProvider
Marco Malavolti
marco.malavolti at garr.it
Wed Aug 13 15:53:12 EDT 2014
Update 2:
The new steps that I have executed are:
1) Configured the Metadata Provider like this:
<metadata:MetadataProvider id="URLMD-IDEM-Federation"
xsi:type="metadata:FileBackedHTTPMetadataProvider"
metadataURL="http://example.it/metadata-sha256.xml"
backingFile="/opt/shibboleth-idp/metadata/metadata-sha256.xml"
maxRefreshDelay="PT1H">
<metadata:MetadataFilter xsi:type="metadata:ChainingFilter">
<metadata:MetadataFilter
xsi:type="metadata:SignatureValidation"
trustEngineRef="shibboleth.MetadataTrustEngine"
requireSignedMetadata="true" />
</metadata:MetadataFilter>
</metadata:MetadataProvider>
2) Removed the old "metadata-sha256.xml"
3) Restarted Tomcat7 and retrieved the new "metadata-sha256.xml"
4) Modified the source metadata file on the example.it server
5) Waited the refresh time
6) Obtained this log:
21:21:48.977 - DEBUG
[org.opensaml.saml2.metadata.provider.AbstractReloadingMetadataProvider:253]
- Beginning refresh of metadata from 'http://example.it/metadata-sha256.xml'
21:21:48.979 - DEBUG
[org.opensaml.saml2.metadata.provider.HTTPMetadataProvider:249] -
Attempting to fetch metadata document from
'http://example.it/metadata-sha256.xml'
21:21:48.986 - DEBUG
[org.opensaml.saml2.metadata.provider.HTTPMetadataProvider:334] -
Attempting to extract metadata from response to request for metadata
from 'http://example.it/metadata-sha256.xml'
21:21:50.100 - DEBUG
[org.opensaml.saml2.metadata.provider.HTTPMetadataProvider:268] -
Successfully fetched 5384875bytes of metadata from
http://example.it/metadata-sha256.xml
21:21:50.100 - DEBUG
[org.opensaml.saml2.metadata.provider.AbstractReloadingMetadataProvider:260]
- Processing new metadata from 'http://example.it/metadata-sha256.xml'
21:21:50.101 - DEBUG
[org.opensaml.saml2.metadata.provider.AbstractReloadingMetadataProvider:349]
- Unmarshalling metadata from 'http://example.it/metadata-sha256.xml'
21:22:06.147 - DEBUG
[org.opensaml.saml2.metadata.provider.AbstractReloadingMetadataProvider:264]
- Error occurred while attempting to refresh metadata from
'http://example.it/metadata-sha256.xml'
java.lang.OutOfMemoryError: Java heap space
at java.util.Arrays.copyOfRange(Arrays.java:2694) ~[na:1.7.0_60]
at java.lang.String.<init>(String.java:203) ~[na:1.7.0_60]
at java.lang.StringBuffer.toString(StringBuffer.java:561)
~[na:1.7.0_60]
at org.apache.xerces.dom.TextImpl.getWholeText(Unknown Source) ~[na:na]
at
org.opensaml.xml.io.AbstractXMLObjectUnmarshaller.unmarshallTextContent(AbstractXMLObjectUnmarshaller.java:369)
~[xmltooling-1.4.1.jar:na]
at
org.opensaml.xml.io.AbstractXMLObjectUnmarshaller.unmarshall(AbstractXMLObjectUnmarshaller.java:130)
~[xmltooling-1.4.1.jar:na]
at
org.opensaml.xml.io.AbstractXMLObjectUnmarshaller.unmarshallChildElement(AbstractXMLObjectUnmarshaller.java:355)
~[xmltooling-1.4.1.jar:na]
at
org.opensaml.xml.io.AbstractXMLObjectUnmarshaller.unmarshall(AbstractXMLObjectUnmarshaller.java:127)
~[xmltooling-1.4.1.jar:na]
at
org.opensaml.xml.io.AbstractXMLObjectUnmarshaller.unmarshallChildElement(AbstractXMLObjectUnmarshaller.java:355)
~[xmltooling-1.4.1.jar:na]
at
org.opensaml.xml.io.AbstractXMLObjectUnmarshaller.unmarshall(AbstractXMLObjectUnmarshaller.java:127)
~[xmltooling-1.4.1.jar:na]
at
org.opensaml.xml.io.AbstractXMLObjectUnmarshaller.unmarshallChildElement(AbstractXMLObjectUnmarshaller.java:355)
~[xmltooling-1.4.1.jar:na]
at
org.opensaml.xml.io.AbstractXMLObjectUnmarshaller.unmarshall(AbstractXMLObjectUnmarshaller.java:127)
~[xmltooling-1.4.1.jar:na]
at
org.opensaml.xml.io.AbstractXMLObjectUnmarshaller.unmarshallChildElement(AbstractXMLObjectUnmarshaller.java:355)
~[xmltooling-1.4.1.jar:na]
at
org.opensaml.xml.io.AbstractXMLObjectUnmarshaller.unmarshall(AbstractXMLObjectUnmarshaller.java:127)
~[xmltooling-1.4.1.jar:na]
at
org.opensaml.xml.io.AbstractXMLObjectUnmarshaller.unmarshallChildElement(AbstractXMLObjectUnmarshaller.java:355)
~[xmltooling-1.4.1.jar:na]
at
org.opensaml.xml.io.AbstractXMLObjectUnmarshaller.unmarshall(AbstractXMLObjectUnmarshaller.java:127)
~[xmltooling-1.4.1.jar:na]
at
org.opensaml.saml2.metadata.provider.AbstractMetadataProvider.unmarshallMetadata(AbstractMetadataProvider.java:470)
~[opensaml-2.6.1.jar:na]
at
org.opensaml.saml2.metadata.provider.AbstractReloadingMetadataProvider.unmarshallMetadata(AbstractReloadingMetadataProvider.java:309)
~[opensaml-2.6.1.jar:na]
at
org.opensaml.saml2.metadata.provider.AbstractReloadingMetadataProvider.processNewMetadata(AbstractReloadingMetadataProvider.java:350)
~[opensaml-2.6.1.jar:na]
at
org.opensaml.saml2.metadata.provider.AbstractReloadingMetadataProvider.refresh(AbstractReloadingMetadataProvider.java:261)
~[opensaml-2.6.1.jar:na]
at
org.opensaml.saml2.metadata.provider.AbstractReloadingMetadataProvider$RefreshMetadataTask.run(AbstractReloadingMetadataProvider.java:513)
[opensaml-2.6.1.jar:na]
at java.util.TimerThread.mainLoop(Timer.java:555) [na:1.7.0_60]
at java.util.TimerThread.run(Timer.java:505) [na:1.7.0_60]
21:22:06.150 - INFO
[org.opensaml.saml2.metadata.provider.AbstractReloadingMetadataProvider:276]
- Next refresh cycle for metadata provider
'http://example.it/metadata-sha256.xml' will occur on
'2014-08-13T19:27:06.149Z' ('2014-08-13T21:27:06.149+02:00' local time)
21:24:08.044 - INFO [Shibboleth-Access:73] -
20140813T192408Z|155.185.30.207|idem-pupagent.dmz-int.unimo.it:443|/profile/Metadata/SAML|
21:27:06.150 - DEBUG
[org.opensaml.saml2.metadata.provider.AbstractReloadingMetadataProvider:253]
- Beginning refresh of metadata from 'http://example.it/metadata-sha256.xml'
21:27:06.151 - DEBUG
[org.opensaml.saml2.metadata.provider.HTTPMetadataProvider:249] -
Attempting to fetch metadata document from
'http://example.it/metadata-sha256.xml'
21:27:06.156 - DEBUG
[org.opensaml.saml2.metadata.provider.HTTPMetadataProvider:254] -
Metadata document from 'http://example.it/metadata-sha256.xml' has not
changed since last retrieval
21:27:06.156 - DEBUG
[org.opensaml.saml2.metadata.provider.AbstractReloadingMetadataProvider:257]
- Metadata from 'http://example.it/metadata-sha256.xml' has not changed
since last refresh
21:27:06.157 - DEBUG
[org.opensaml.saml2.metadata.provider.AbstractReloadingMetadataProvider:327]
- Computing new expiration time for cached metadata from
'http://example.it/metadata-sha256.xml
21:27:06.556 - INFO
[org.opensaml.saml2.metadata.provider.AbstractReloadingMetadataProvider:276]
- Next refresh cycle for metadata provider
'http://example.it/metadata-sha256.xml' will occur on
'2014-08-13T20:12:06.251Z' ('2014-08-13T22:12:06.251+02:00' local time)
This is my /etc/environments:
PATH="/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/games"
IDP_LOG=/opt/shibboleth-idp/logs/idp-process.log
TOMCAT_LOG_DIR=/var/log/tomcat7/
CATALINA_HOME=/var/lib/tomcat7
CATALINA_OUT=/var/log/tomcat7/catalina.out
JAVA_OPTS="-Djava.awt.headless=true -Xms256m -Xmx2g -XX:MaxPermSize=128m
-XX:+DisableExplicitGC -XX:+UseParallelOldGC"
JAVA_HOME=/usr/lib/jvm/java-7-oracle
TOMCAT_HOME=/usr/share/tomcat7
IDP_HOME=/opt/shibboleth-idp
JAVA_ENDORSED_DIRS=/usr/share/tomcat7/endorsed
before I had this /etc/environment:
PATH="/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/games"
IDP_LOG=/opt/shibboleth-idp/logs/idp-process.log
TOMCAT_LOG_DIR=/var/log/tomcat7/
CATALINA_HOME=/var/lib/tomcat7
CATALINA_OUT=/var/log/tomcat7/catalina.out
JAVA_OPTS="-Djava.awt.headless=true -Xmx512M -XX:MaxPermSize=128m"
JAVA_HOME=/usr/lib/jvm/java-7-oracle
TOMCAT_HOME=/usr/share/tomcat7
IDP_HOME=/opt/shibboleth-idp
JAVA_ENDORSED_DIRS=/usr/share/tomcat7/endorsed
and, I'm not sure it is important, I haven't restarted the VM after
apply the new /etc/environments.
I hope this can be useful to solve my problem...
Thank you very much for all, really!
Regards,
Marco
Il 12/08/14 15:59, Marco Malavolti ha scritto:
> Update:
>
> The "http://www.example.it/metadata/metadata-sha256.xml" has a new
> validUntil value, but the backingFile is not updated.
>
> I have tried this steps:
> 1) Removed the metadata-sha256.xml from its location.
> 2) Restarted Tomcat7
> 3) Removed again the new metadata-sha256.xml from its location.
> 4) I have waited the new refresh cycle to see what happen and I see
> the "Log" that I have attached here.
>
> I have used the same MetadataProvider configuration with a different
> HTTP URL where I have uploaded the metadata-sha256.xml file and it works.
>
> I begin to think that the problem can be on the retrieving URL, but I
> don't understand why, with a Tomcat restart, the metadata is updated
> correctly.
>
> Thank you for all the help that you have gave to me.
>
> I appreciate it very much.
>
> Best Regards,
> Marco
> ------------------------------------------------------------
>
> Config:
> <!-- Metadata Refresh Period
> minRefreshDelay == every 5 minutes (default value)
> maxRefreshDelay == every 4 hours (default value) -->
>
> <metadata:MetadataProvider id="URLMD-Federation"
> xsi:type="metadata:FileBackedHTTPMetadataProvider"
> metadataURL="http://www.example.it/metadata/metadata-sha256.xml"
> backingFile="/opt/shibboleth-idp/metadata/metadata-sha256.xml">
>
> <metadata:MetadataFilter xsi:type="metadata:ChainingFilter">
> <metadata:MetadataFilter xsi:type="metadata:SignatureValidation"
> trustEngineRef="shibboleth.MetadataTrustEngine"
> requireSignedMetadata="true" />
> <metadata:MetadataFilter xsi:type="EntityRoleWhiteList">
> <metadata:RetainedRole>samlmd:SPSSODescriptor</metadata:RetainedRole>
> </metadata:MetadataFilter>
> </metadata:MetadataFilter>
> </metadata:MetadataProvider>
>
> </metadata:MetadataProvider>
>
> Log:
> 10:58:58.125 - DEBUG
> [org.opensaml.saml2.metadata.provider.AbstractReloadingMetadataProvider:253]
> - Beginning refresh of metadata from
> 'http://www.example.it/metadata/metadata-sha256.xml'
> 10:58:58.126 - DEBUG
> [org.opensaml.saml2.metadata.provider.HTTPMetadataProvider:249] -
> Attempting to fetch metadata document from
> 'http://www.example.it/metadata/metadata-sha256.xml'
> 10:58:58.145 - DEBUG
> [org.opensaml.saml2.metadata.provider.HTTPMetadataProvider:254] -
> Metadata document from
> 'http://www.example.it/metadata/metadata-sha256.xml' has not changed
> since last retrieval
> 10:58:58.145 - DEBUG
> [org.opensaml.saml2.metadata.provider.AbstractReloadingMetadataProvider:257]
> - Metadata from 'http://www.example.it/metadata/metadata-sha256.xml'
> has not changed since last refresh
> 10:58:58.146 - DEBUG
> [org.opensaml.saml2.metadata.provider.AbstractReloadingMetadataProvider:327]
> - Computing new expiration time for cached metadata from
> 'http://www.example.it/metadata/metadata-sha256.xml
> 10:58:58.193 - INFO
> [org.opensaml.saml2.metadata.provider.AbstractReloadingMetadataProvider:276]
> - Next refresh cycle for metadata provider
> 'http://www.example.it/metadata/metadata-sha256.xml' will occur on
> '2014-08-12T11:58:58.142Z' ('2014-08-12T13:58:58.142+02:00' local time)
>
> --------------------------------------------------------------------------------------------------------------
>
>
> Il 11/08/14 17:00, Cantor, Scott ha scritto:
>> On 8/11/14, 10:52 AM, "Marco Malavolti" <marco.malavolti at garr.it> wrote:
>>
>>> Yes, I have set these so low in order to reproduce the issue more
>>> quickly, but I have the same problem with the default configuration
>>> values:
>>> - minRefreshDelay="PT5M"
>>> - maxRefreshDelay="PT4H"
>> Then your file has a last-modified value that's older than every time it
>> runs a check. Trust me, it works, so the only way it's not working is if
>> you're essentially forcibly causing the race condition every time. Your
>> tests won't mean anything unless you keep the timestamp on the file new
>> enough to trigger a load.
>>
>> What you want is for the file time to be essentially the exact time you
>> update the file, not the actual time the file was last changed at the
>> source.
>>
>> Basically, either change your file update process, or switch to the HTTP
>> versions.
>>
>>
>> -- Scott
>>
>
>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: smime.p7s
Type: application/pkcs7-signature
Size: 3239 bytes
Desc: Firma crittografica S/MIME
Url : http://shibboleth.net/pipermail/users/attachments/20140813/5406eb6b/attachment-0001.bin
More information about the users
mailing list