diff --git a/applepay/utils.py b/applepay/utils.py index 467bd6d..0f669ae 100644 --- a/applepay/utils.py +++ b/applepay/utils.py @@ -1,9 +1,13 @@ import base64 from datetime import timedelta +import logging from asn1crypto import cms +logger = logging.getLogger(__name__) + + def retrieve_signature_signing_time(signature): """ Return the 'signingTime' CMS attribute from the detached PKCS signature. @@ -50,4 +54,15 @@ def signing_time_is_valid(signature, current_time, threshold): unexpected format, inconsistent with the CMS 'ContentInfo' object. """ signing_time = retrieve_signature_signing_time(signature) - return timedelta(0) <= (current_time - signing_time) <= threshold + is_valid = timedelta(0) <= (current_time - signing_time) <= threshold + logger.debug(( + "Signing time is {is_valid}. " + "Signing time: {signing_time:%Y-%m-%d %H:%M:%S %Z}, " + "Current time: {current_time:%Y-%m-%d %H:%M:%S %Z}, " + "Threshold: {threshold}.").format( + is_valid='valid' if is_valid else 'invalid', + signing_time=signing_time, + current_time=current_time, + threshold=threshold) + ) + return is_valid diff --git a/setup.py b/setup.py index 0ab208d..f42b2de 100644 --- a/setup.py +++ b/setup.py @@ -12,7 +12,7 @@ packages=['applepay', 'tests'], install_requires=['asn1crypto>=0.21.0', 'cryptography>=1.7.2'], setup_requires=['pytest-runner>=2.0,<3dev'], - tests_require=['pytest>=3.0.6', 'pytz==2016.10'], + tests_require=['pytest>=3.0.6', 'pytz==2016.10', 'pytest-capturelog>=0.7'], classifiers=[ "Development Status :: 4 - Beta", "Topic :: Utilities", diff --git a/tests/applepay_test.py b/tests/applepay_test.py index a2af36b..0db15cc 100644 --- a/tests/applepay_test.py +++ b/tests/applepay_test.py @@ -1,4 +1,5 @@ from datetime import datetime, timedelta +import logging import pytest from pytz import utc @@ -91,3 +92,37 @@ def test_signing_time_equals_current_time(token_fixture): # then the token should be considered valid. assert valid is True + + +def test_valid_signing_time_data_is_logged(token_fixture, caplog): + # Given: a valid signature for a current time and threshold + signature = token_fixture['signature'] + current_time = datetime(2014, 10, 27, 20, 51, 43, tzinfo=utc) + threshold = timedelta(hours=1) + + # When we attempt to validate the signing time against the threshold, + with caplog.atLevel(logging.DEBUG): + applepay_utils.signing_time_is_valid(signature, current_time, threshold) + + # Then a new debug log is captured + records = caplog.records() + assert len(records) == 1 + assert records[0].name == 'applepay.utils' + assert records[0].message == 'Signing time is valid. Signing time: 2014-10-27 19:51:43 UTC+00:00, Current time: 2014-10-27 20:51:43 UTC, Threshold: 1:00:00.' + + +def test_invalid_signing_time_data_is_logged(token_fixture, caplog): + # Given: a invalid signature for a current time and threshold + signature = token_fixture['signature'] + current_time = datetime(2010, 1, 2, 5, 22, 13, tzinfo=utc) + threshold = timedelta(hours=1) + + # When we attempt to validate the signing time against the threshold, + with caplog.atLevel(logging.DEBUG): + applepay_utils.signing_time_is_valid(signature, current_time, threshold) + + # Then a new debug log is captured + records = caplog.records() + assert len(records) == 1 + assert records[0].name == 'applepay.utils' + assert records[0].message == 'Signing time is invalid. Signing time: 2014-10-27 19:51:43 UTC+00:00, Current time: 2010-01-02 05:22:13 UTC, Threshold: 1:00:00.'