IDP reports: Message was expired but times look valid

[Douglas E. Engert]

With a Shibboleth-2.3.8 IDP, we are getting intermittent "Message was expired:"
and "Message was rejected due to issue instant expiration"
messages, but the times look valid, with the IDP getting the assertion 2 seconds
after it was created.

The IDP log has (vendor IP replaced with XX.XX.XXX.XXX):

16:59:28.233 - INFO [Shibboleth-Access:74] - 20131113T225928Z|XX.XX.XXX.XXX|login.anl.gov:443|/profile/SAML2/Redirect/SSO|
16:59:28.235 - WARN [org.opensaml.common.binding.security.IssueInstantRule:108] - Message was expired: message issue time was '2013-11-13T10:59:26.348Z', message expired at: 
'2013-11-13T11:05:26.348Z', current time: '2013-11-13T16:59:28.235-06:00'
16:59:28.236 - WARN [edu.internet2.middleware.shibboleth.idp.profile.saml2.SSOProfileHandler:377] - Message did not meet security requirements
org.opensaml.ws.security.SecurityPolicyException: Message was rejected due to issue instant expiration
         at org.opensaml.common.binding.security.IssueInstantRule.evaluate(IssueInstantRule.java:110) ~[opensaml-2.5.3.jar:na]
         at org.opensaml.ws.security.provider.BasicSecurityPolicy.evaluate(BasicSecurityPolicy.java:51) ~[openws-1.4.4.jar:na]
         at org.opensaml.ws.message.decoder.BaseMessageDecoder.processSecurityPolicy(BaseMessageDecoder.java:132) ~[openws-1.4.4.jar:na]
         at org.opensaml.ws.message.decoder.BaseMessageDecoder.decode(BaseMessageDecoder.java:83) ~[openws-1.4.4.jar:na]
         at org.opensaml.saml2.binding.decoding.BaseSAML2MessageDecoder.decode(BaseSAML2MessageDecoder.java:70) ~[opensaml-2.5.3.jar:na]
         at edu.internet2.middleware.shibboleth.idp.profile.saml2.SSOProfileHandler.decodeRequest(SSOProfileHandler.java:357) [shibboleth-identityprovider-2.3.8.jar:na]

This appears to be with the time frame of issue time and default expiration time of 5 minutes.


This is the assertion the vendor reported as sending (vendor name and IP replaced with xxxxxxxx)

<?xml version="1.0" encoding="UTF-8"?>
<samlp:AuthnRequest
    AssertionConsumerServiceURL="https://argonne.xxxxxxxx.com/rs/rest/samlsso/authenticateSSO"
    Destination="https://login.anl.gov/idp/profile/SAML2/Redirect/SSO"
    ForceAuthn="false"
    ID="83631DDF595E12BF1270436F0526C9117DCC85872C60862490A0CADDFF5043842E38BE8018E9F9C54E4F"
    IsPassive="false"
    IssueInstant="2013-11-13T10:59:26.348Z"
    ProtocolBinding="urn:oasis:names:tc:SAML:2.0:bindings:HTTP-POST"
    Version="2.0"
    xmlns:samlp="urn:oasis:names:tc:SAML:2.0:protocol">
<samlp:Issuer
    xmlns:samlp="urn:oasis:names:tc:SAML:2.0:assertion">https://argonne.xxxxxxxx.com/rs/rest/samlsso</samlp:Issuer>
<saml2p:NameIDPolicy
    AllowCreate="true"
    Format="urn:oasis:names:tc:SAML:2.0:nameid-format:transient"
    SPNameQualifier="https://argonne.xxxxxxxx.com/rs/rest/samlsso"
    xmlns:saml2p="urn:oasis:names:tc:SAML:2.0:protocol"/>
</samlp:AuthnRequest>


Any ideas?
-- 

  Douglas E. Engert  <DEEngert at anl.gov>
  Argonne National Laboratory
  9700 South Cass Avenue
  Argonne, Illinois  60439
  (630) 252-5444