okta ResponseLifetimeExceed erros in Nagios

[Paul Everitt]

ResponseLifetimeExceed: Can't use it, it's too old 1503943386 > 1503942986
Exception when processing https://karl.soros.org/saml/okta
Referer: https://osf.okta.com/app/opensocietyfoundations_karl_1/exk1cj6u1jjv4UDmR0h8/sso/saml?SAMLRequest=nVJNc9owEL3nV2h04WTL9uSD0WBnaGimZJJAwXSmvWRUswSBrXW0MoV%2FX9mQZnrhkJu0%2B%2Fbt27c7uN1XJduBJY0m7cVh1GNgClxq85r2Fvl90O%2FdZhcDQ5EcNm5tZvDWADnmywxJH055Y41ERdp%2FVQUkXSHnw6dHmYSRrC06LLDk%2Fwri8wWKCKzzYjgbvj%2Fv0FBTgZ2D3ekCFrPHlK%2Bdq0kKsVW2DAktUoj2VZCqSoFbpzgbeZnaqJbgA460Ctt0WGAlVF0LrMEQFhrcYYWNWXZ4emlpX2IB%2B21cbK6beLPZXS5G1Sxa9wURdn04G49SrpdB%2FrV%2BuKqrZHKJdr%2F4id99hqiBsSGnjEt5EsU3QdQPkn4e38irSCbRL86mJ2%2B%2BaNPZfdaX30cQyW95Pg2mk3neEez0EuyzR6f8OPWP0yq5L%2BKZ31ssOy2W3aOtlDvfpY34gVYdVIJx2h14NvEesfnRJE%2Fz7tJAfLBn3YW0QsajKZa6OLBhWeKfOwvKeXErVRLwT2hwVhnSXglnIms7%2Fn%2BH2V8%3D&fromLoginToken=EuumR4HsjtOO0zQObiM1TtAAwuBFYUORwyQZeahCWDpWUcbMax5hVfYZwi_y6-ItPXXgdE-aSEyQBC7vuChkYaJ-aIeQ62XXXklZgCvIb_R5RcX5FAmuDRpWBcsiShGvoR5nlLItsZ88noPoFlLl8lseO7iDXOu_qh4IdPVzsdEjUDhGbkQ3xt_kaGhsyAP8FwTSHvye1Zb-fkMnfEK-BchGMZvfvIoSAHp-IdEtE2UomUnUzFMvmvhSmYHichMY6DWRIOaq5km8HjZi2YifHKpDN8zw8Jt1M5F6kq2A140tzI7-E-OFMoMC3163wN9_VUhbSBq5tGWdqBH0nE1nJQ

Traceback (most recent call last):
  File "/srv/osfkarl/.buildout/eggs/cp27mu/pyramid-1.2.1-py2.7.egg/pyramid/tweens.py", line 17, in excview_tween
    response = handler(request)
  File "/srv/osfkarl/.buildout/eggs/cp27mu/pyramid_tm-0.5-py2.7.egg/pyramid_tm/__init__.py", line 107, in tm_tween
    return response
  File "/srv/osfkarl/.buildout/eggs/cp27mu/pyramid_tm-0.5-py2.7.egg/pyramid_tm/__init__.py", line 75, in __exit__
    return self._retry_or_raise(t, v, tb)
  File "/srv/osfkarl/.buildout/eggs/cp27mu/pyramid_tm-0.5-py2.7.egg/pyramid_tm/__init__.py", line 60, in _retry_or_raise
    reraise(t, v, tb) # otherwise reraise the exception
  File "/srv/osfkarl/.buildout/eggs/cp27mu/pyramid_tm-0.5-py2.7.egg/pyramid_tm/__init__.py", line 100, in tm_tween
    response = handler(request)
  File "/srv/osfkarl/.buildout/eggs/cp27mu/pyramid-1.2.1-py2.7.egg/pyramid/router.py", line 153, in handle_request
    response = view_callable(context, request)
  File "/srv/osfkarl/.buildout/eggs/cp27mu/pyramid-1.2.1-py2.7.egg/pyramid/config/views.py", line 319, in viewresult_to_response
    result = view(context, request)
  File "/srv/osfkarl/production/109/karl/saml.py", line 88, in callback
    username = provider.username_from_callback(request)
  File "/srv/osfkarl/production/109/karl/saml.py", line 79, in username_from_callback
    entity.BINDING_HTTP_POST)
  File "/srv/osfkarl/.buildout/eggs/cp27mu/pysaml2-4.4.0-py2.7.egg/saml2/client_base.py", line 597, in parse_authn_request_response
    binding, **kwargs)
  File "/srv/osfkarl/.buildout/eggs/cp27mu/pysaml2-4.4.0-py2.7.egg/saml2/entity.py", line 1172, in _parse_response
    response = response.verify(keys)
  File "/srv/osfkarl/.buildout/eggs/cp27mu/pysaml2-4.4.0-py2.7.egg/saml2/response.py", line 1017, in verify
    if self.parse_assertion(keys):
  File "/srv/osfkarl/.buildout/eggs/cp27mu/pysaml2-4.4.0-py2.7.egg/saml2/response.py", line 929, in parse_assertion
    if not self._assertion(assertion, False):
  File "/srv/osfkarl/.buildout/eggs/cp27mu/pysaml2-4.4.0-py2.7.egg/saml2/response.py", line 803, in _assertion
    if not self.condition_ok():
  File "/srv/osfkarl/.buildout/eggs/cp27mu/pysaml2-4.4.0-py2.7.egg/saml2/response.py", line 591, in condition_ok
    conditions.not_on_or_after, self.timeslack)
  File "/srv/osfkarl/.buildout/eggs/cp27mu/pysaml2-4.4.0-py2.7.egg/saml2/validate.py", line 94, in validate_on_or_after
    "Can't use it, it's too old %d > %d" % (now - slack, nooa))
ResponseLifetimeExceed: Can't use it, it's too old 1503943386 > 1503942986

[Chris Rossi (chris-archimedeanco)]

It can't hurt to check and make sure that NTP is working properly on all of the Flying Circus servers.

If this isn't an clock synchronization issue, then it's just a something on the internet is too slow issue. In this particular ticket we're getting a response back from the IP about 7 seconds too late:

>>> datetime.datetime.fromtimestamp(1503943386)
datetime.datetime(2017, 8, 28, 14, 3, 6)
>>> datetime.datetime.fromtimestamp(1503942986)
datetime.datetime(2017, 8, 28, 13, 56, 26)
>>>

I don't know what the actual time window is, so I don't know when the transaction was actually initiated.

I guess the question is what is the user experience when this occurs and can it be improved? Better error message? Automatically retry?

Whatever the ultimate solution, obviously, capture and log the exception and whatever was done about it, so it doesn't set off alarms.

[Paul Everitt (paul-agendaless)]

I'm going to close this and throw Sentry at it if it re-occurs.