From 5822e493bebfed031d389431425f1f66f6d7c77e Mon Sep 17 00:00:00 2001 From: Dhwani Patel Date: Fri, 13 Sep 2024 12:55:44 -0600 Subject: [PATCH 1/5] Add logger in fixity script --- fixity/fixity.py | 62 +++++++++++++-------- fixity/utils.py | 11 ---- tests/test_fixity.py | 125 ++++++++++++++++++------------------------- 3 files changed, 93 insertions(+), 105 deletions(-) diff --git a/fixity/fixity.py b/fixity/fixity.py index 64a5fac..2da4c2e 100644 --- a/fixity/fixity.py +++ b/fixity/fixity.py @@ -1,8 +1,11 @@ import json +import logging import os import sys import traceback from argparse import ArgumentParser +from datetime import datetime +from datetime import timezone from time import sleep from uuid import uuid4 @@ -22,7 +25,7 @@ def validate_arguments(args): raise ArgumentError("An AIP UUID must be specified when scanning a single AIP") -def parse_arguments(): +def parse_arguments(argument): parser = ArgumentParser() parser.add_argument("command", choices=["scan", "scanall"], help="Command to run.") parser.add_argument("aip", nargs="?", help="If 'scan', UUID of the AIP to scan") @@ -45,7 +48,7 @@ def parse_arguments(): action="store_true", help="Add a timestamp to the beginning of each line of output.", ) - args = parser.parse_args() + args = parser.parse_args(argument) validate_arguments(args) return args @@ -100,6 +103,7 @@ def scan( ss_user, ss_key, session, + logger, report_url=None, report_auth=(), session_id=None, @@ -123,7 +127,6 @@ def scan( :param bool force_local: If True, will request the Storage Service to perform a local fixity check, instead of using the Space's fixity (if available). :param bool timestamps: If True, will add a timestamp to the beginning of each line of output. """ - # Ensure the storage service knows about this AIP first; # get_single_aip() will raise an exception if the storage service # does not have an AIP with that UUID, or otherwise errors out @@ -142,10 +145,7 @@ def scan( session_id=session_id, ) except reporting.ReportServiceException: - utils.pyprint( - f"Unable to POST pre-scan report to {report_url}", timestamps=timestamps - ) - + logger.log(logging.WARNING, f"Unable to POST pre-scan report to {report_url}") try: status, report = storage_service.scan_aip( aip, @@ -157,11 +157,10 @@ def scan( force_local=force_local, ) report_data = json.loads(report.report) - utils.pyprint( - scan_message(aip, status, report_data["message"]), timestamps=timestamps - ) + logger.log(logging.WARNING, scan_message(aip, status, report_data["message"])) except Exception as e: - utils.pyprint(str(e), timestamps=timestamps) + logger.log(logging.WARNING, str(e)) + status = None if hasattr(e, "report") and e.report: report = e.report @@ -190,11 +189,10 @@ def scan( aip, report, report_url, report_auth=report_auth, session_id=session_id ) except reporting.ReportServiceException: - utils.pyprint( + logger.log( + logging.WARNING, f"Unable to POST report for AIP {aip} to remote service", - timestamps=timestamps, ) - if report: session.add(report) @@ -206,6 +204,7 @@ def scanall( ss_user, ss_key, session, + logger, report_url=None, report_auth=(), throttle_time=0, @@ -243,6 +242,7 @@ def scanall( ss_user, ss_key, session, + logger, report_url=report_url, report_auth=report_auth, session_id=session_id, @@ -252,24 +252,23 @@ def scanall( if not scan_success: success = False except Exception as e: - utils.pyprint( + logger.log( + logging.WARNING, f"Internal error encountered while scanning AIP {aip['uuid']} ({type(e).__name__})", - timestamps=timestamps, ) if throttle_time: sleep(throttle_time) if count > 0: - utils.pyprint(f"Successfully scanned {count} AIPs", timestamps=timestamps) - + logger.log(logging.WARNING, f"Successfully scanned {count} AIPs") return success -def main(): +def main(arguements=None): success = 0 try: - args = parse_arguments() + args = parse_arguments(arguements) except ArgumentError as e: return e @@ -280,6 +279,25 @@ def main(): session = Session() + logger = logging.getLogger(__name__) + + # create console handler which logs stderr messages + stderr_handler = logging.StreamHandler(stream=sys.stderr) + + # create formatter and add it to the handlers + if args.timestamps: + format_time = datetime.now(timezone.utc).strftime("%Y-%m-%d %H:%M:%S %Z") + message_format = logging.Formatter( + "[%(asctime)s] %(message)s", + datefmt=format_time, + ) + else: + message_format = logging.Formatter("%(message)s") + stderr_handler.setFormatter(message_format) + + # add the handlers to the logger + logger.addHandler(stderr_handler) + status = False if args.report_user and args.report_pass: @@ -296,6 +314,7 @@ def main(): args.ss_user, args.ss_key, session, + logger, report_url=report_url, report_auth=auth, throttle_time=args.throttle, @@ -310,6 +329,7 @@ def main(): args.ss_user, args.ss_key, session, + logger, report_url=report_url, report_auth=auth, session_id=session_id, @@ -339,4 +359,4 @@ def main(): if __name__ == "__main__": - sys.exit(main()) + sys.exit(main(sys.argv[1:])) diff --git a/fixity/utils.py b/fixity/utils.py index 7ffa2a2..9d8b8d1 100644 --- a/fixity/utils.py +++ b/fixity/utils.py @@ -1,4 +1,3 @@ -import sys from datetime import datetime from datetime import timezone from uuid import UUID @@ -34,13 +33,3 @@ def check_valid_uuid(uuid): def utcnow(): return datetime.now(timezone.utc) - - -def format_timestamp(t): - return t.strftime("%Y-%m-%d %H:%M:%S %Z") - - -def pyprint(message, **kwargs): - if kwargs.get("timestamps"): - message = f"[{format_timestamp(utcnow())}] {message}" - print(message, file=sys.stderr) diff --git a/tests/test_fixity.py b/tests/test_fixity.py index 02be432..a7a0ad9 100644 --- a/tests/test_fixity.py +++ b/tests/test_fixity.py @@ -1,5 +1,5 @@ import json -import sys +import logging import uuid from datetime import datetime from datetime import timezone @@ -18,6 +18,7 @@ STORAGE_SERVICE_USER = "test" STORAGE_SERVICE_KEY = "test" REPORT_URL = "http://localhost:8003/" +logger = logging.getLogger(__name__) mock_scan_aip = mock.Mock( **{ @@ -58,6 +59,7 @@ def test_scan(_get, mock_check_fixity): ss_user=STORAGE_SERVICE_USER, ss_key=STORAGE_SERVICE_KEY, session=SESSION, + logger=logger, ) assert response is True @@ -74,31 +76,23 @@ def test_scan(_get, mock_check_fixity): ] -@mock.patch("fixity.utils.utcnow") @mock.patch("requests.get") -def test_scan_if_timestamps_argument_is_passed(_get, utcnow, mock_check_fixity, capsys): +@mock.patch.object(fixity, "Session", lambda: SESSION) +def test_scan_if_timestamps_argument_is_passed( + _get, monkeypatch, mock_check_fixity, caplog +): _get.side_effect = mock_check_fixity - aip_id = uuid.uuid4() - timestamp = 1514775600 - utcnow.return_value = datetime.fromtimestamp(timestamp, timezone.utc) + monkeypatch.setenv("STORAGE_SERVICE_URL", STORAGE_SERVICE_URL) + monkeypatch.setenv("STORAGE_SERVICE_USER", STORAGE_SERVICE_USER) + monkeypatch.setenv("STORAGE_SERVICE_KEY", STORAGE_SERVICE_KEY) - response = fixity.scan( - aip=str(aip_id), - ss_url=STORAGE_SERVICE_URL, - ss_user=STORAGE_SERVICE_USER, - ss_key=STORAGE_SERVICE_KEY, - session=SESSION, - timestamps=True, - ) + aip_id = str(uuid.uuid4()) + response = fixity.main(["scan", aip_id, "--timestamps"]) - assert response is True + assert response == 0 + + assert f"Fixity scan succeeded for AIP: {aip_id}" in caplog.text - captured = capsys.readouterr() - assert captured.out == "" - assert ( - captured.err.strip() - == f"[2018-01-01 03:00:00 UTC] Fixity scan succeeded for AIP: {aip_id}" - ) assert _get.mock_calls == [ mock.call( f"{STORAGE_SERVICE_URL}api/v2/file/{aip_id}/", @@ -132,6 +126,7 @@ def test_scan_if_report_url_exists(_post, _get, utcnow, mock_check_fixity): ss_user=STORAGE_SERVICE_USER, ss_key=STORAGE_SERVICE_KEY, session=SESSION, + logger=logger, report_url=REPORT_URL, ) @@ -191,7 +186,7 @@ def test_scan_if_report_url_exists(_post, _get, utcnow, mock_check_fixity): ], ) def test_scan_handles_exceptions_if_report_url_exists( - _post, _get, capsys, mock_check_fixity + _post, _get, mock_check_fixity, caplog ): _get.side_effect = mock_check_fixity aip_id = uuid.uuid4() @@ -202,20 +197,17 @@ def test_scan_handles_exceptions_if_report_url_exists( ss_user=STORAGE_SERVICE_USER, ss_key=STORAGE_SERVICE_KEY, session=SESSION, + logger=logger, report_url=REPORT_URL, ) assert response is True - captured = capsys.readouterr() - assert captured.out.strip() == "" - assert captured.err.strip() == "\n".join( - [ - f"Unable to POST pre-scan report to {REPORT_URL}", - f"Fixity scan succeeded for AIP: {aip_id}", - f"Unable to POST report for AIP {aip_id} to remote service", - ] - ) + assert [rec.message for rec in caplog.records] == [ + f"Unable to POST pre-scan report to {REPORT_URL}", + f"Fixity scan succeeded for AIP: {aip_id}", + f"Unable to POST report for AIP {aip_id} to remote service", + ] @mock.patch( @@ -237,7 +229,7 @@ def test_scan_handles_exceptions_if_report_url_exists( ), ], ) -def test_scan_handles_exceptions(_get, capsys): +def test_scan_handles_exceptions(_get, caplog): aip_id = uuid.uuid4() response = fixity.scan( @@ -246,16 +238,14 @@ def test_scan_handles_exceptions(_get, capsys): ss_user=STORAGE_SERVICE_USER, ss_key=STORAGE_SERVICE_KEY, session=SESSION, + logger=logger, ) assert response is None - captured = capsys.readouterr() - assert captured.out.strip() == "" - assert ( - f'Storage service at "{STORAGE_SERVICE_URL}" encountered an internal error while scanning AIP {aip_id}\n' - == captured.err - ) + assert [rec.message for rec in caplog.records] == [ + f'Storage service at "{STORAGE_SERVICE_URL}" encountered an internal error while scanning AIP {aip_id}' + ] @mock.patch( @@ -286,6 +276,7 @@ def test_scan_handles_exceptions_if_no_scan_attempted(_get): ss_user=STORAGE_SERVICE_USER, ss_key=STORAGE_SERVICE_KEY, session=SESSION, + logger=logger, ) assert response is None @@ -316,7 +307,7 @@ def test_scan_message(status, error_message): @mock.patch( "requests.get", ) -def test_scanall(_get, capsys, mock_check_fixity): +def test_scanall(_get, caplog, mock_check_fixity): aip1_uuid = "41e12f76-354e-402d-85ee-f812cb72f6e6" aip2_uuid = "807ecfb7-08b1-4435-87ec-5c6bfbe62225" _get.side_effect = [ @@ -350,20 +341,17 @@ def test_scanall(_get, capsys, mock_check_fixity): ss_user=STORAGE_SERVICE_USER, ss_key=STORAGE_SERVICE_KEY, session=SESSION, + logger=logger, ) assert response is True - captured = capsys.readouterr() - assert captured.out.strip() == "" - expected_output = "\n".join( - [ - f"Fixity scan succeeded for AIP: {aip1_uuid}", - f"Fixity scan succeeded for AIP: {aip2_uuid}", - "Successfully scanned 2 AIPs", - ] - ) - assert captured.err.strip() == expected_output + expected_output = [ + f"Fixity scan succeeded for AIP: {aip1_uuid}", + f"Fixity scan succeeded for AIP: {aip2_uuid}", + "Successfully scanned 2 AIPs", + ] + assert [rec.message for rec in caplog.records] == expected_output @mock.patch( @@ -410,25 +398,22 @@ def test_scanall(_get, capsys, mock_check_fixity): mock_scan_aip, ], ) -def test_scanall_handles_exceptions(_get, capsys): +def test_scanall_handles_exceptions(_get, caplog): response = fixity.scanall( ss_url=STORAGE_SERVICE_URL, ss_user=STORAGE_SERVICE_USER, ss_key=STORAGE_SERVICE_KEY, session=SESSION, + logger=logger, ) assert response is False - captured = capsys.readouterr() - - assert captured.err.strip() == "\n".join( - [ - "Internal error encountered while scanning AIP 77adb748-8d9c-47ec-b593-53465749ce0e (StorageServiceError)", - f'Storage service at "{STORAGE_SERVICE_URL}" failed authentication while scanning AIP 32f62f8b-ecfd-419e-a3e9-911ec23d0573', - "Successfully scanned 2 AIPs", - ] - ) + assert [rec.message for rec in caplog.records] == [ + "Internal error encountered while scanning AIP 77adb748-8d9c-47ec-b593-53465749ce0e (StorageServiceError)", + f'Storage service at "{STORAGE_SERVICE_URL}" failed authentication while scanning AIP 32f62f8b-ecfd-419e-a3e9-911ec23d0573', + "Successfully scanned 2 AIPs", + ] @mock.patch("requests.get") @@ -439,9 +424,8 @@ def test_main_scan(_get, monkeypatch, mock_check_fixity, capsys): monkeypatch.setenv("STORAGE_SERVICE_USER", STORAGE_SERVICE_USER) monkeypatch.setenv("STORAGE_SERVICE_KEY", STORAGE_SERVICE_KEY) aip_id = str(uuid.uuid4()) - sys.argv = ["fixity.py", "scan", aip_id] - result = fixity.main() + result = fixity.main(["scan", aip_id]) assert result == 0 @@ -452,7 +436,7 @@ def test_main_scan(_get, monkeypatch, mock_check_fixity, capsys): @mock.patch("requests.get") @mock.patch.object(fixity, "Session", lambda: SESSION) -def test_main_handles_exceptions_if_scanall_fails(_get, monkeypatch, capsys): +def test_main_handles_exceptions_if_scanall_fails(_get, monkeypatch, caplog): aip_id = str(uuid.uuid4()) _get.side_effect = [ mock.Mock( @@ -499,18 +483,13 @@ def test_main_handles_exceptions_if_scanall_fails(_get, monkeypatch, capsys): monkeypatch.setenv("STORAGE_SERVICE_URL", STORAGE_SERVICE_URL) monkeypatch.setenv("STORAGE_SERVICE_USER", STORAGE_SERVICE_USER) monkeypatch.setenv("STORAGE_SERVICE_KEY", STORAGE_SERVICE_KEY) - sys.argv = ["fixity.py", "scanall"] - result = fixity.main() + result = fixity.main(["scanall"]) assert result == 1 - captured = capsys.readouterr() - assert captured.out.strip() == "" - assert captured.err.strip() == "\n".join( - [ - f"Internal error encountered while scanning AIP {aip_id} (StorageServiceError)", - f'Storage service at "{STORAGE_SERVICE_URL}" failed authentication while scanning AIP 32f62f8b-ecfd-419e-a3e9-911ec23d0573', - "Successfully scanned 2 AIPs", - ] - ) + assert [rec.message for rec in caplog.records] == [ + f"Internal error encountered while scanning AIP {aip_id} (StorageServiceError)", + f'Storage service at "{STORAGE_SERVICE_URL}" failed authentication while scanning AIP 32f62f8b-ecfd-419e-a3e9-911ec23d0573', + "Successfully scanned 2 AIPs", + ] From 06d582d557330287d48e0d3c897982c7b863e2e9 Mon Sep 17 00:00:00 2001 From: Dhwani Patel Date: Wed, 18 Sep 2024 14:19:06 -0600 Subject: [PATCH 2/5] WIP --- fixity/fixity.py | 65 +++++++++++----------- tests/test_fixity.py | 128 ++++++++++++++++++++++++++++++------------- 2 files changed, 123 insertions(+), 70 deletions(-) diff --git a/fixity/fixity.py b/fixity/fixity.py index 2da4c2e..ab53ce7 100644 --- a/fixity/fixity.py +++ b/fixity/fixity.py @@ -25,7 +25,7 @@ def validate_arguments(args): raise ArgumentError("An AIP UUID must be specified when scanning a single AIP") -def parse_arguments(argument): +def parse_arguments(arguments): parser = ArgumentParser() parser.add_argument("command", choices=["scan", "scanall"], help="Command to run.") parser.add_argument("aip", nargs="?", help="If 'scan', UUID of the AIP to scan") @@ -48,7 +48,7 @@ def parse_arguments(argument): action="store_true", help="Add a timestamp to the beginning of each line of output.", ) - args = parser.parse_args(argument) + args = parser.parse_args(arguments) validate_arguments(args) return args @@ -108,7 +108,6 @@ def scan( report_auth=(), session_id=None, force_local=False, - timestamps=False, ): """ Instruct the storage service to scan a single AIP. @@ -125,7 +124,6 @@ def scan( :param report_auth: Authentication for the report_url. Tupel of (user, password) for HTTP auth. :param session_id: Identifier for this session, allowing every scan from one run to be identified. :param bool force_local: If True, will request the Storage Service to perform a local fixity check, instead of using the Space's fixity (if available). - :param bool timestamps: If True, will add a timestamp to the beginning of each line of output. """ # Ensure the storage service knows about this AIP first; # get_single_aip() will raise an exception if the storage service @@ -209,7 +207,6 @@ def scanall( report_auth=(), throttle_time=0, force_local=False, - timestamps=False, ): """ Run a fixity scan on every AIP in a storage service instance. @@ -221,7 +218,6 @@ def scanall( :param report_auth: Authentication for the report_url. Tupel of (user, password) for HTTP auth. :param int throttle_time: Time to wait between scans. :param bool force_local: If True, will request the Storage Service to perform a local fixity check, instead of using the Space's fixity (if available). - :param bool timestamps: If True, will add a timestamp to the beginning of each line of output. """ success = True @@ -247,7 +243,6 @@ def scanall( report_auth=report_auth, session_id=session_id, force_local=force_local, - timestamps=timestamps, ) if not scan_success: success = False @@ -264,11 +259,38 @@ def scanall( return success -def main(arguements=None): +class UTCFormatter(logging.Formatter): + def formatTime(self, record, datefmt=None): + return datetime.fromtimestamp(record.created, tz=timezone.utc).strftime( + "%Y-%m-%d %H:%M:%S %Z" + ) + + +def get_logger() -> logging.Logger: + logger = logging.getLogger("fixity") + logger.setLevel(logging.WARNING) + return logger + + +def get_handler(stream, timestamps): + stderr_handler = logging.StreamHandler(stream=stream) + if timestamps: + message_format = UTCFormatter("[%(asctime)s] %(message)s") + else: + message_format = logging.Formatter("%(message)s") + stderr_handler.setFormatter(message_format) + return stderr_handler + + +def main(arguments=None, logger=None, stream=None): + if logger is None: + logger = get_logger() + if stream is None: + stream = sys.stderr success = 0 try: - args = parse_arguments(arguements) + args = parse_arguments(arguments) except ArgumentError as e: return e @@ -277,26 +299,10 @@ def main(arguements=None): except ArgumentError as e: return e - session = Session() - - logger = logging.getLogger(__name__) - - # create console handler which logs stderr messages - stderr_handler = logging.StreamHandler(stream=sys.stderr) - - # create formatter and add it to the handlers - if args.timestamps: - format_time = datetime.now(timezone.utc).strftime("%Y-%m-%d %H:%M:%S %Z") - message_format = logging.Formatter( - "[%(asctime)s] %(message)s", - datefmt=format_time, - ) - else: - message_format = logging.Formatter("%(message)s") - stderr_handler.setFormatter(message_format) + stderr_handler = get_handler(stream=stream, timestamps=args.timestamps) - # add the handlers to the logger logger.addHandler(stderr_handler) + session = Session() status = False @@ -319,7 +325,6 @@ def main(arguements=None): report_auth=auth, throttle_time=args.throttle, force_local=args.force_local, - timestamps=args.timestamps, ) elif args.command == "scan": session_id = str(uuid4()) @@ -334,7 +339,6 @@ def main(arguements=None): report_auth=auth, session_id=session_id, force_local=args.force_local, - timestamps=args.timestamps, ) else: return Exception(f'Error: "{args.command}" is not a valid command.') @@ -354,9 +358,8 @@ def main(arguements=None): success = 1 else: success = status - return success if __name__ == "__main__": - sys.exit(main(sys.argv[1:])) + sys.exit(main(sys.argv[1:], get_logger(), sys.stderr)) diff --git a/tests/test_fixity.py b/tests/test_fixity.py index a7a0ad9..93271f8 100644 --- a/tests/test_fixity.py +++ b/tests/test_fixity.py @@ -1,5 +1,6 @@ +import io import json -import logging +import time import uuid from datetime import datetime from datetime import timezone @@ -10,6 +11,7 @@ from fixity import fixity from fixity import reporting +from fixity.fixity import get_handler from fixity.models import Report from fixity.models import Session @@ -18,7 +20,7 @@ STORAGE_SERVICE_USER = "test" STORAGE_SERVICE_KEY = "test" REPORT_URL = "http://localhost:8003/" -logger = logging.getLogger(__name__) + mock_scan_aip = mock.Mock( **{ @@ -52,6 +54,9 @@ def mock_check_fixity(): def test_scan(_get, mock_check_fixity): _get.side_effect = mock_check_fixity aip_id = uuid.uuid4() + stream = io.StringIO() + logger = fixity.get_logger() + logger.addHandler(get_handler(stream=stream, timestamps=False)) response = fixity.scan( aip=str(aip_id), @@ -64,6 +69,11 @@ def test_scan(_get, mock_check_fixity): assert response is True + stream.seek(0) + assert [line.strip() for line in stream.readlines()] == [ + f"Fixity scan succeeded for AIP: {aip_id}" + ] + assert _get.mock_calls == [ mock.call( f"{STORAGE_SERVICE_URL}api/v2/file/{aip_id}/", @@ -78,20 +88,28 @@ def test_scan(_get, mock_check_fixity): @mock.patch("requests.get") @mock.patch.object(fixity, "Session", lambda: SESSION) -def test_scan_if_timestamps_argument_is_passed( - _get, monkeypatch, mock_check_fixity, caplog -): +def test_scan_if_timestamps_argument_is_passed(_get, monkeypatch, mock_check_fixity): _get.side_effect = mock_check_fixity monkeypatch.setenv("STORAGE_SERVICE_URL", STORAGE_SERVICE_URL) monkeypatch.setenv("STORAGE_SERVICE_USER", STORAGE_SERVICE_USER) monkeypatch.setenv("STORAGE_SERVICE_KEY", STORAGE_SERVICE_KEY) - aip_id = str(uuid.uuid4()) - response = fixity.main(["scan", aip_id, "--timestamps"]) + stream = io.StringIO() + logger = fixity.get_logger() + + timestamp = 1514775600 + expected_time = time.localtime(timestamp) - assert response == 0 + with mock.patch.object(time, "localtime", return_value=expected_time): + response = fixity.main( + ["scan", aip_id, "--timestamps"], logger=logger, stream=stream + ) - assert f"Fixity scan succeeded for AIP: {aip_id}" in caplog.text + assert response == 0 + stream.seek(0) + assert [line.strip() for line in stream.readlines()] == [ + f"[2018-01-01 03:00:00 UTC] Fixity scan succeeded for AIP: {aip_id}" + ] assert _get.mock_calls == [ mock.call( @@ -119,6 +137,9 @@ def test_scan_if_report_url_exists(_post, _get, utcnow, mock_check_fixity): start_time = 1514775600 utcnow.return_value = datetime.fromtimestamp(start_time, timezone.utc) aip_id = uuid.uuid4() + stream = io.StringIO() + logger = fixity.get_logger() + logger.addHandler(get_handler(stream=stream, timestamps=False)) response = fixity.scan( aip=str(aip_id), @@ -185,11 +206,12 @@ def test_scan_if_report_url_exists(_post, _get, utcnow, mock_check_fixity): ), ], ) -def test_scan_handles_exceptions_if_report_url_exists( - _post, _get, mock_check_fixity, caplog -): +def test_scan_handles_exceptions_if_report_url_exists(_post, _get, mock_check_fixity): _get.side_effect = mock_check_fixity aip_id = uuid.uuid4() + stream = io.StringIO() + logger = fixity.get_logger() + logger.addHandler(get_handler(stream=stream, timestamps=False)) response = fixity.scan( aip=str(aip_id), @@ -203,7 +225,8 @@ def test_scan_handles_exceptions_if_report_url_exists( assert response is True - assert [rec.message for rec in caplog.records] == [ + stream.seek(0) + assert [line.strip() for line in stream.readlines()] == [ f"Unable to POST pre-scan report to {REPORT_URL}", f"Fixity scan succeeded for AIP: {aip_id}", f"Unable to POST report for AIP {aip_id} to remote service", @@ -229,8 +252,11 @@ def test_scan_handles_exceptions_if_report_url_exists( ), ], ) -def test_scan_handles_exceptions(_get, caplog): +def test_scan_handles_exceptions(_get): aip_id = uuid.uuid4() + stream = io.StringIO() + logger = fixity.get_logger() + logger.addHandler(get_handler(stream=stream, timestamps=False)) response = fixity.scan( aip=str(aip_id), @@ -243,7 +269,8 @@ def test_scan_handles_exceptions(_get, caplog): assert response is None - assert [rec.message for rec in caplog.records] == [ + stream.seek(0) + assert [line.strip() for line in stream.readlines()] == [ f'Storage service at "{STORAGE_SERVICE_URL}" encountered an internal error while scanning AIP {aip_id}' ] @@ -269,6 +296,9 @@ def test_scan_handles_exceptions(_get, caplog): ) def test_scan_handles_exceptions_if_no_scan_attempted(_get): aip_id = uuid.uuid4() + stream = io.StringIO() + logger = fixity.get_logger() + logger.addHandler(get_handler(stream=stream, timestamps=False)) response = fixity.scan( aip=str(aip_id), @@ -280,6 +310,7 @@ def test_scan_handles_exceptions_if_no_scan_attempted(_get): ) assert response is None + assert Report(aip_id=aip_id).success is None @@ -307,7 +338,7 @@ def test_scan_message(status, error_message): @mock.patch( "requests.get", ) -def test_scanall(_get, caplog, mock_check_fixity): +def test_scanall(_get, mock_check_fixity): aip1_uuid = "41e12f76-354e-402d-85ee-f812cb72f6e6" aip2_uuid = "807ecfb7-08b1-4435-87ec-5c6bfbe62225" _get.side_effect = [ @@ -335,6 +366,9 @@ def test_scanall(_get, caplog, mock_check_fixity): *mock_check_fixity, *mock_check_fixity, ] + stream = io.StringIO() + logger = fixity.get_logger() + logger.addHandler(get_handler(stream=stream, timestamps=False)) response = fixity.scanall( ss_url=STORAGE_SERVICE_URL, @@ -346,17 +380,20 @@ def test_scanall(_get, caplog, mock_check_fixity): assert response is True + stream.seek(0) expected_output = [ f"Fixity scan succeeded for AIP: {aip1_uuid}", f"Fixity scan succeeded for AIP: {aip2_uuid}", "Successfully scanned 2 AIPs", ] - assert [rec.message for rec in caplog.records] == expected_output + assert [line.strip() for line in stream.readlines()] == expected_output -@mock.patch( - "requests.get", - side_effect=[ +@mock.patch("requests.get") +def test_scanall_handles_exceptions(_get): + aip_id1 = str(uuid.uuid4()) + aip_id2 = str(uuid.uuid4()) + _get.side_effect = [ mock.Mock( **{ "status_code": 200, @@ -366,12 +403,12 @@ def test_scanall(_get, caplog, mock_check_fixity): { "package_type": "AIP", "status": "UPLOADED", - "uuid": "77adb748-8d9c-47ec-b593-53465749ce0e", + "uuid": f"{aip_id1}", }, { "package_type": "AIP", "status": "UPLOADED", - "uuid": "32f62f8b-ecfd-419e-a3e9-911ec23d0573", + "uuid": f"{aip_id2}", }, ], }, @@ -396,9 +433,12 @@ def test_scanall(_get, caplog, mock_check_fixity): side_effect=Exception, ), mock_scan_aip, - ], -) -def test_scanall_handles_exceptions(_get, caplog): + ] + + stream = io.StringIO() + logger = fixity.get_logger() + logger.addHandler(get_handler(stream=stream, timestamps=False)) + response = fixity.scanall( ss_url=STORAGE_SERVICE_URL, ss_user=STORAGE_SERVICE_USER, @@ -409,35 +449,41 @@ def test_scanall_handles_exceptions(_get, caplog): assert response is False - assert [rec.message for rec in caplog.records] == [ - "Internal error encountered while scanning AIP 77adb748-8d9c-47ec-b593-53465749ce0e (StorageServiceError)", - f'Storage service at "{STORAGE_SERVICE_URL}" failed authentication while scanning AIP 32f62f8b-ecfd-419e-a3e9-911ec23d0573', + stream.seek(0) + assert [line.strip() for line in stream.readlines()] == [ + f"Internal error encountered while scanning AIP {aip_id1} (StorageServiceError)", + f'Storage service at "{STORAGE_SERVICE_URL}" failed authentication while scanning AIP {aip_id2}', "Successfully scanned 2 AIPs", ] @mock.patch("requests.get") @mock.patch.object(fixity, "Session", lambda: SESSION) -def test_main_scan(_get, monkeypatch, mock_check_fixity, capsys): +def test_main_scan(_get, monkeypatch, mock_check_fixity): _get.side_effect = mock_check_fixity monkeypatch.setenv("STORAGE_SERVICE_URL", STORAGE_SERVICE_URL) monkeypatch.setenv("STORAGE_SERVICE_USER", STORAGE_SERVICE_USER) monkeypatch.setenv("STORAGE_SERVICE_KEY", STORAGE_SERVICE_KEY) aip_id = str(uuid.uuid4()) + stream = io.StringIO() + logger = fixity.get_logger() + logger.addHandler(get_handler(stream=stream, timestamps=False)) result = fixity.main(["scan", aip_id]) assert result == 0 - captured = capsys.readouterr() - assert captured.out.strip() == "" - assert captured.err.strip() == f"Fixity scan succeeded for AIP: {aip_id}" + stream.seek(0) + assert [line.strip() for line in stream.readlines()] == [ + f"Fixity scan succeeded for AIP: {aip_id}" + ] @mock.patch("requests.get") @mock.patch.object(fixity, "Session", lambda: SESSION) -def test_main_handles_exceptions_if_scanall_fails(_get, monkeypatch, caplog): - aip_id = str(uuid.uuid4()) +def test_main_handles_exceptions_if_scanall_fails(_get, monkeypatch): + aip_id1 = str(uuid.uuid4()) + aip_id2 = str(uuid.uuid4()) _get.side_effect = [ mock.Mock( **{ @@ -448,12 +494,12 @@ def test_main_handles_exceptions_if_scanall_fails(_get, monkeypatch, caplog): { "package_type": "AIP", "status": "UPLOADED", - "uuid": f"{aip_id}", + "uuid": f"{aip_id1}", }, { "package_type": "AIP", "status": "UPLOADED", - "uuid": "32f62f8b-ecfd-419e-a3e9-911ec23d0573", + "uuid": f"{aip_id2}", }, ], }, @@ -483,13 +529,17 @@ def test_main_handles_exceptions_if_scanall_fails(_get, monkeypatch, caplog): monkeypatch.setenv("STORAGE_SERVICE_URL", STORAGE_SERVICE_URL) monkeypatch.setenv("STORAGE_SERVICE_USER", STORAGE_SERVICE_USER) monkeypatch.setenv("STORAGE_SERVICE_KEY", STORAGE_SERVICE_KEY) + stream = io.StringIO() + logger = fixity.get_logger() + logger.addHandler(get_handler(stream=stream, timestamps=False)) result = fixity.main(["scanall"]) assert result == 1 - assert [rec.message for rec in caplog.records] == [ - f"Internal error encountered while scanning AIP {aip_id} (StorageServiceError)", - f'Storage service at "{STORAGE_SERVICE_URL}" failed authentication while scanning AIP 32f62f8b-ecfd-419e-a3e9-911ec23d0573', + stream.seek(0) + assert [line.strip() for line in stream.readlines()] == [ + f"Internal error encountered while scanning AIP {aip_id1} (StorageServiceError)", + f'Storage service at "{STORAGE_SERVICE_URL}" failed authentication while scanning AIP {aip_id2}', "Successfully scanned 2 AIPs", ] From 97440338fd33697cceafb58c43671dccd9a41d9a Mon Sep 17 00:00:00 2001 From: "Douglas Cerna (Soy Douglas)" Date: Fri, 20 Sep 2024 21:54:42 +0000 Subject: [PATCH 3/5] Mock time.time in timestamps test --- tests/test_fixity.py | 4 +--- 1 file changed, 1 insertion(+), 3 deletions(-) diff --git a/tests/test_fixity.py b/tests/test_fixity.py index 93271f8..6c347ec 100644 --- a/tests/test_fixity.py +++ b/tests/test_fixity.py @@ -1,6 +1,5 @@ import io import json -import time import uuid from datetime import datetime from datetime import timezone @@ -98,9 +97,8 @@ def test_scan_if_timestamps_argument_is_passed(_get, monkeypatch, mock_check_fix logger = fixity.get_logger() timestamp = 1514775600 - expected_time = time.localtime(timestamp) - with mock.patch.object(time, "localtime", return_value=expected_time): + with mock.patch("time.time", return_value=timestamp): response = fixity.main( ["scan", aip_id, "--timestamps"], logger=logger, stream=stream ) From 5e0752ee5433ddf3a99cb153e1f8a0f3aba43755 Mon Sep 17 00:00:00 2001 From: "Douglas Cerna (Soy Douglas)" Date: Fri, 20 Sep 2024 22:13:44 +0000 Subject: [PATCH 4/5] Add helper to assert stream content in tests --- tests/test_fixity.py | 92 ++++++++++++++++++++++++-------------------- 1 file changed, 50 insertions(+), 42 deletions(-) diff --git a/tests/test_fixity.py b/tests/test_fixity.py index 6c347ec..2b2e95d 100644 --- a/tests/test_fixity.py +++ b/tests/test_fixity.py @@ -49,6 +49,11 @@ def mock_check_fixity(): ] +def _assert_stream_content_matches(stream, expected): + stream.seek(0) + assert [line.strip() for line in stream.readlines()] == expected + + @mock.patch("requests.get") def test_scan(_get, mock_check_fixity): _get.side_effect = mock_check_fixity @@ -68,10 +73,7 @@ def test_scan(_get, mock_check_fixity): assert response is True - stream.seek(0) - assert [line.strip() for line in stream.readlines()] == [ - f"Fixity scan succeeded for AIP: {aip_id}" - ] + _assert_stream_content_matches(stream, [f"Fixity scan succeeded for AIP: {aip_id}"]) assert _get.mock_calls == [ mock.call( @@ -103,11 +105,11 @@ def test_scan_if_timestamps_argument_is_passed(_get, monkeypatch, mock_check_fix ["scan", aip_id, "--timestamps"], logger=logger, stream=stream ) - assert response == 0 - stream.seek(0) - assert [line.strip() for line in stream.readlines()] == [ - f"[2018-01-01 03:00:00 UTC] Fixity scan succeeded for AIP: {aip_id}" - ] + assert response == 0 + _assert_stream_content_matches( + stream, + [f"[2018-01-01 03:00:00 UTC] Fixity scan succeeded for AIP: {aip_id}"], + ) assert _get.mock_calls == [ mock.call( @@ -223,12 +225,14 @@ def test_scan_handles_exceptions_if_report_url_exists(_post, _get, mock_check_fi assert response is True - stream.seek(0) - assert [line.strip() for line in stream.readlines()] == [ - f"Unable to POST pre-scan report to {REPORT_URL}", - f"Fixity scan succeeded for AIP: {aip_id}", - f"Unable to POST report for AIP {aip_id} to remote service", - ] + _assert_stream_content_matches( + stream, + [ + f"Unable to POST pre-scan report to {REPORT_URL}", + f"Fixity scan succeeded for AIP: {aip_id}", + f"Unable to POST report for AIP {aip_id} to remote service", + ], + ) @mock.patch( @@ -267,10 +271,12 @@ def test_scan_handles_exceptions(_get): assert response is None - stream.seek(0) - assert [line.strip() for line in stream.readlines()] == [ - f'Storage service at "{STORAGE_SERVICE_URL}" encountered an internal error while scanning AIP {aip_id}' - ] + _assert_stream_content_matches( + stream, + [ + f'Storage service at "{STORAGE_SERVICE_URL}" encountered an internal error while scanning AIP {aip_id}' + ], + ) @mock.patch( @@ -378,13 +384,14 @@ def test_scanall(_get, mock_check_fixity): assert response is True - stream.seek(0) - expected_output = [ - f"Fixity scan succeeded for AIP: {aip1_uuid}", - f"Fixity scan succeeded for AIP: {aip2_uuid}", - "Successfully scanned 2 AIPs", - ] - assert [line.strip() for line in stream.readlines()] == expected_output + _assert_stream_content_matches( + stream, + [ + f"Fixity scan succeeded for AIP: {aip1_uuid}", + f"Fixity scan succeeded for AIP: {aip2_uuid}", + "Successfully scanned 2 AIPs", + ], + ) @mock.patch("requests.get") @@ -447,12 +454,14 @@ def test_scanall_handles_exceptions(_get): assert response is False - stream.seek(0) - assert [line.strip() for line in stream.readlines()] == [ - f"Internal error encountered while scanning AIP {aip_id1} (StorageServiceError)", - f'Storage service at "{STORAGE_SERVICE_URL}" failed authentication while scanning AIP {aip_id2}', - "Successfully scanned 2 AIPs", - ] + _assert_stream_content_matches( + stream, + [ + f"Internal error encountered while scanning AIP {aip_id1} (StorageServiceError)", + f'Storage service at "{STORAGE_SERVICE_URL}" failed authentication while scanning AIP {aip_id2}', + "Successfully scanned 2 AIPs", + ], + ) @mock.patch("requests.get") @@ -471,10 +480,7 @@ def test_main_scan(_get, monkeypatch, mock_check_fixity): assert result == 0 - stream.seek(0) - assert [line.strip() for line in stream.readlines()] == [ - f"Fixity scan succeeded for AIP: {aip_id}" - ] + _assert_stream_content_matches(stream, [f"Fixity scan succeeded for AIP: {aip_id}"]) @mock.patch("requests.get") @@ -535,9 +541,11 @@ def test_main_handles_exceptions_if_scanall_fails(_get, monkeypatch): assert result == 1 - stream.seek(0) - assert [line.strip() for line in stream.readlines()] == [ - f"Internal error encountered while scanning AIP {aip_id1} (StorageServiceError)", - f'Storage service at "{STORAGE_SERVICE_URL}" failed authentication while scanning AIP {aip_id2}', - "Successfully scanned 2 AIPs", - ] + _assert_stream_content_matches( + stream, + [ + f"Internal error encountered while scanning AIP {aip_id1} (StorageServiceError)", + f'Storage service at "{STORAGE_SERVICE_URL}" failed authentication while scanning AIP {aip_id2}', + "Successfully scanned 2 AIPs", + ], + ) From 2e48f5be6137eba3ad367dd9feef824596c535da Mon Sep 17 00:00:00 2001 From: "Douglas Cerna (Soy Douglas)" Date: Fri, 20 Sep 2024 22:19:08 +0000 Subject: [PATCH 5/5] Clean up --- fixity/fixity.py | 17 ++++++++++------- tests/test_fixity.py | 20 +++++++++++--------- 2 files changed, 21 insertions(+), 16 deletions(-) diff --git a/fixity/fixity.py b/fixity/fixity.py index ab53ce7..11d57fd 100644 --- a/fixity/fixity.py +++ b/fixity/fixity.py @@ -25,7 +25,7 @@ def validate_arguments(args): raise ArgumentError("An AIP UUID must be specified when scanning a single AIP") -def parse_arguments(arguments): +def parse_arguments(argv): parser = ArgumentParser() parser.add_argument("command", choices=["scan", "scanall"], help="Command to run.") parser.add_argument("aip", nargs="?", help="If 'scan', UUID of the AIP to scan") @@ -48,7 +48,7 @@ def parse_arguments(arguments): action="store_true", help="Add a timestamp to the beginning of each line of output.", ) - args = parser.parse_args(arguments) + args = parser.parse_args(argv) validate_arguments(args) return args @@ -120,11 +120,13 @@ def scan( :param str ss_url: The base URL to a storage service installation. :param str ss_user: Storage service user to authenticate as :param str ss_key: API key of the storage service user + :param Logger logger: Logger to print output. :param str report_url: The base URL to a server to which the report will be POSTed after the scan completes. If absent, the report will not be transmitted. :param report_auth: Authentication for the report_url. Tupel of (user, password) for HTTP auth. :param session_id: Identifier for this session, allowing every scan from one run to be identified. :param bool force_local: If True, will request the Storage Service to perform a local fixity check, instead of using the Space's fixity (if available). """ + # Ensure the storage service knows about this AIP first; # get_single_aip() will raise an exception if the storage service # does not have an AIP with that UUID, or otherwise errors out @@ -214,6 +216,7 @@ def scanall( :param str ss_url: The base URL to a storage service installation. :param str ss_user: Storage service user to authenticate as :param str ss_key: API key of the storage service user + :param Logger logger: Logger to print output. :param str report_url: The base URL to a server to which the report will be POSTed after the scan completes. If absent, the report will not be transmitted. :param report_auth: Authentication for the report_url. Tupel of (user, password) for HTTP auth. :param int throttle_time: Time to wait between scans. @@ -282,15 +285,16 @@ def get_handler(stream, timestamps): return stderr_handler -def main(arguments=None, logger=None, stream=None): +def main(argv=None, logger=None, stream=None): if logger is None: logger = get_logger() if stream is None: stream = sys.stderr + success = 0 try: - args = parse_arguments(arguments) + args = parse_arguments(argv) except ArgumentError as e: return e @@ -299,9 +303,7 @@ def main(arguments=None, logger=None, stream=None): except ArgumentError as e: return e - stderr_handler = get_handler(stream=stream, timestamps=args.timestamps) - - logger.addHandler(stderr_handler) + logger.addHandler(get_handler(stream=stream, timestamps=args.timestamps)) session = Session() status = False @@ -358,6 +360,7 @@ def main(arguments=None, logger=None, stream=None): success = 1 else: success = status + return success diff --git a/tests/test_fixity.py b/tests/test_fixity.py index 2b2e95d..bb9c4cc 100644 --- a/tests/test_fixity.py +++ b/tests/test_fixity.py @@ -20,7 +20,6 @@ STORAGE_SERVICE_KEY = "test" REPORT_URL = "http://localhost:8003/" - mock_scan_aip = mock.Mock( **{ "status_code": 200, @@ -87,25 +86,28 @@ def test_scan(_get, mock_check_fixity): ] +@mock.patch("time.time") @mock.patch("requests.get") @mock.patch.object(fixity, "Session", lambda: SESSION) -def test_scan_if_timestamps_argument_is_passed(_get, monkeypatch, mock_check_fixity): +def test_scan_if_timestamps_argument_is_passed( + _get, time, monkeypatch, mock_check_fixity +): _get.side_effect = mock_check_fixity monkeypatch.setenv("STORAGE_SERVICE_URL", STORAGE_SERVICE_URL) monkeypatch.setenv("STORAGE_SERVICE_USER", STORAGE_SERVICE_USER) monkeypatch.setenv("STORAGE_SERVICE_KEY", STORAGE_SERVICE_KEY) - aip_id = str(uuid.uuid4()) + aip_id = uuid.uuid4() + timestamp = 1514775600 + time.return_value = timestamp stream = io.StringIO() logger = fixity.get_logger() - timestamp = 1514775600 - - with mock.patch("time.time", return_value=timestamp): - response = fixity.main( - ["scan", aip_id, "--timestamps"], logger=logger, stream=stream - ) + response = fixity.main( + ["scan", str(aip_id), "--timestamps"], logger=logger, stream=stream + ) assert response == 0 + _assert_stream_content_matches( stream, [f"[2018-01-01 03:00:00 UTC] Fixity scan succeeded for AIP: {aip_id}"],