diff --git a/requirements-swh.txt b/requirements-swh.txt index e7a7564..95a7c77 100644 --- a/requirements-swh.txt +++ b/requirements-swh.txt @@ -1,3 +1,3 @@ swh.core[http] >= 0.3 -swh.deposit +swh.deposit >= 0.3 swh.storage >= 0.0.162 diff --git a/swh/icinga_plugins/deposit.py b/swh/icinga_plugins/deposit.py index 26271c4..e7221ef 100644 --- a/swh/icinga_plugins/deposit.py +++ b/swh/icinga_plugins/deposit.py @@ -1,128 +1,181 @@ -# Copyright (C) 2019 The Software Heritage developers +# Copyright (C) 2019-2020 The Software Heritage developers # See the AUTHORS file at the top-level directory of this distribution # License: GNU General Public License version 3, or any later version # See top-level LICENSE file for more information import datetime import sys import time +from typing import Any, Dict, Optional from swh.deposit.client import PublicApiDepositClient from .base_check import BaseCheck class DepositCheck(BaseCheck): TYPE = "DEPOSIT" DEFAULT_WARNING_THRESHOLD = 120 DEFAULT_CRITICAL_THRESHOLD = 3600 def __init__(self, obj): super().__init__(obj) self._poll_interval = obj["poll_interval"] self._archive_path = obj["archive"] self._metadata_path = obj["metadata"] self._collection = obj["collection"] + self._slug: Optional[str] = None self._client = PublicApiDepositClient( { "url": obj["server"], "auth": {"username": obj["username"], "password": obj["password"]}, } ) def upload_deposit(self): + slug = "check-deposit-%s" % datetime.datetime.now().isoformat() result = self._client.deposit_create( archive=self._archive_path, metadata=self._metadata_path, collection=self._collection, in_progress=False, - slug="check-deposit-%s" % datetime.datetime.now().isoformat(), + slug=slug, ) + self._slug = slug self._deposit_id = result["deposit_id"] return result + def update_deposit_with_metadata(self) -> Dict[str, Any]: + """Trigger a metadata update on the deposit once it's completed. + + """ + deposit = self.get_deposit_status() + swhid = deposit["deposit_swh_id"] + assert deposit["deposit_id"] == self._deposit_id + + # We can reuse the initial metadata file we already sent + return self._client.deposit_update( + self._collection, + self._deposit_id, + self._slug, + metadata=self._metadata_path, + swhid=swhid, + ) + def get_deposit_status(self): return self._client.deposit_status( collection=self._collection, deposit_id=self._deposit_id ) def wait_while_status(self, statuses, start_time, metrics, result): while result["deposit_status"] in statuses: metrics["total_time"] = time.time() - start_time if metrics["total_time"] > self.critical_threshold: self.print_result( "CRITICAL", f"Timed out while in status " f'{result["deposit_status"]} ' f'({metrics["total_time"]}s seconds since deposit ' f"started)", **metrics, ) sys.exit(2) time.sleep(self._poll_interval) result = self.get_deposit_status() return result def main(self): start_time = time.time() metrics = {} # Upload the archive and metadata result = self.upload_deposit() metrics["upload_time"] = time.time() - start_time # Wait for validation result = self.wait_while_status(["deposited"], start_time, metrics, result) metrics["total_time"] = time.time() - start_time metrics["validation_time"] = metrics["total_time"] - metrics["upload_time"] # Check validation succeeded if result["deposit_status"] == "rejected": self.print_result( "CRITICAL", f'Deposit was rejected: {result["deposit_status_detail"]}', **metrics, ) return 2 # Wait for loading result = self.wait_while_status( ["verified", "loading"], start_time, metrics, result ) metrics["total_time"] = time.time() - start_time metrics["load_time"] = ( metrics["total_time"] - metrics["upload_time"] - metrics["validation_time"] ) # Check loading succeeded if result["deposit_status"] == "failed": self.print_result( "CRITICAL", f'Deposit loading failed: {result["deposit_status_detail"]}', **metrics, ) return 2 # Check for unexpected status if result["deposit_status"] != "done": self.print_result( "CRITICAL", f'Deposit got unexpected status: {result["deposit_status"]} ' f'({result["deposit_status_detail"]})', **metrics, ) return 2 # Everything went fine, check total time wasn't too large and # print result (status_code, status) = self.get_status(metrics["total_time"]) self.print_result( status, f'Deposit took {metrics["total_time"]:.2f}s and succeeded.', **metrics, ) + + if status_code != 0: # Stop if any problem in the initial scenario + return status_code + + # Initial deposit is now completed, now we can update the deposit with metadata + result = self.update_deposit_with_metadata() + total_time = time.time() - start_time + metrics_update = { + "total_time": total_time, + "update_time": ( + total_time + - metrics["upload_time"] + - metrics["validation_time"] + - metrics["load_time"] + ), + } + + if "error" in result: + self.print_result( + "CRITICAL", + f'Deposit Metadata update failed: {result["error"]} ', + **metrics_update, + ) + return 2 + + (status_code, status) = self.get_status(metrics_update["total_time"]) + self.print_result( + status, + f'Deposit Metadata update took {metrics_update["update_time"]:.2f}s ' + "and succeeded.", + **metrics_update, + ) return status_code diff --git a/swh/icinga_plugins/tests/test_deposit.py b/swh/icinga_plugins/tests/test_deposit.py index 60d27aa..d7d8b5b 100644 --- a/swh/icinga_plugins/tests/test_deposit.py +++ b/swh/icinga_plugins/tests/test_deposit.py @@ -1,506 +1,621 @@ # Copyright (C) 2019-2020 The Software Heritage developers # See the AUTHORS file at the top-level directory of this distribution # License: GNU General Public License version 3, or any later version # See top-level LICENSE file for more information import io import os import tarfile import time from typing import Optional from click.testing import CliRunner import pytest from swh.icinga_plugins.cli import icinga_cli_group from .web_scenario import WebScenario BASE_URL = "http://swh-deposit.example.org/1" COMMON_OPTIONS = [ "--server", BASE_URL, "--username", "test", "--password", "test", "--collection", "testcol", ] SAMPLE_METADATA = """ Test Software swh test-software No One """ ENTRY_TEMPLATE = """ 42 2019-12-19 18:11:00 foo.tar.gz {status} http://purl.org/net/sword/package/SimpleZip """ STATUS_TEMPLATE = """ 42 {status} {status_detail}%s """ def status_template( status: str, status_detail: str = "", swhid: Optional[str] = None ) -> str: """Generate a proper status template out of status, status_detail and optional swhid """ if swhid is not None: template = STATUS_TEMPLATE % f"\n {swhid}" return template.format(status=status, status_detail=status_detail, swhid=swhid) template = STATUS_TEMPLATE % "" return template.format(status=status, status_detail=status_detail) def test_status_template(): actual_status = status_template(status="deposited") assert ( actual_status == """ 42 deposited """ ) actual_status = status_template(status="verified", status_detail="detail") assert ( actual_status == """ 42 verified detail """ ) actual_status = status_template(status="done", swhid="10") assert ( actual_status == """ 42 done 10 """ ) @pytest.fixture(scope="session") def tmp_path(tmp_path_factory): return tmp_path_factory.mktemp(__name__) @pytest.fixture(scope="session") def sample_metadata(tmp_path): """Returns a sample metadata file's path """ path = os.path.join(tmp_path, "metadata.xml") with open(path, "w") as fd: fd.write(SAMPLE_METADATA) return path @pytest.fixture(scope="session") def sample_archive(tmp_path): """Returns a sample archive's path """ path = os.path.join(tmp_path, "archive.tar.gz") with tarfile.open(path, "w:gz") as tf: tf.addfile(tarfile.TarInfo("hello.py"), io.BytesIO(b'print("Hello world")')) return path def invoke(args, catch_exceptions=False): runner = CliRunner() result = runner.invoke(icinga_cli_group, args) if not catch_exceptions and result.exception: print(result.output) raise result.exception return result def test_deposit_immediate_success( requests_mock, mocker, sample_archive, sample_metadata, mocked_time ): + """Both deposit creation and deposit metadata update passed without delays + + """ scenario = WebScenario() + status_xml = status_template( + status="done", + status_detail="", + swhid="swh:1:dir:02ed6084fb0e8384ac58980e07548a547431cf74", + ) + + # Initial deposit scenario.add_step( "post", f"{BASE_URL}/testcol/", ENTRY_TEMPLATE.format(status="done") ) + # Then metadata update + status_xml = status_template( + status="done", + status_detail="", + swhid="swh:1:dir:02ed6084fb0e8384ac58980e07548a547431cf74", + ) + scenario.add_step("get", f"{BASE_URL}/testcol/42/status/", status_xml) + # internal deposit client does call status, then update metadata then status api + scenario.add_step( + "get", f"{BASE_URL}/testcol/42/status/", status_xml, + ) + scenario.add_step( + "put", f"{BASE_URL}/testcol/42/metadata/", status_xml, + ) + scenario.add_step( + "get", f"{BASE_URL}/testcol/42/status/", status_xml, + ) scenario.install_mock(requests_mock) result = invoke( [ "check-deposit", *COMMON_OPTIONS, "single", "--archive", sample_archive, "--metadata", sample_metadata, ] ) assert result.output == ( "DEPOSIT OK - Deposit took 0.00s and succeeded.\n" "| 'load_time' = 0.00s\n" "| 'total_time' = 0.00s\n" "| 'upload_time' = 0.00s\n" "| 'validation_time' = 0.00s\n" + "DEPOSIT OK - Deposit Metadata update took 0.00s and succeeded.\n" + "| 'total_time' = 0.00s\n" + "| 'update_time' = 0.00s\n" ) assert result.exit_code == 0, f"Unexpected output: {result.output}" def test_deposit_delays( requests_mock, mocker, sample_archive, sample_metadata, mocked_time ): + """Deposit creation passed with some delays, deposit metadata update passed without + delay + + """ scenario = WebScenario() scenario.add_step( "post", f"{BASE_URL}/testcol/", ENTRY_TEMPLATE.format(status="deposited") ) scenario.add_step( "get", f"{BASE_URL}/testcol/42/status/", status_template(status="verified"), ) scenario.add_step( "get", f"{BASE_URL}/testcol/42/status/", status_template(status="loading"), ) scenario.add_step( "get", f"{BASE_URL}/testcol/42/status/", status_template(status="done"), ) + # Then metadata update + status_xml = status_template( + status="done", + status_detail="", + swhid="swh:1:dir:02ed6084fb0e8384ac58980e07548a547431cf74", + ) + scenario.add_step("get", f"{BASE_URL}/testcol/42/status/", status_xml) + # internal deposit client does call status, then update metadata then status api + scenario.add_step( + "get", f"{BASE_URL}/testcol/42/status/", status_xml, + ) + scenario.add_step( + "put", f"{BASE_URL}/testcol/42/metadata/", status_xml, + ) + scenario.add_step( + "get", f"{BASE_URL}/testcol/42/status/", status_xml, + ) scenario.install_mock(requests_mock) result = invoke( [ "check-deposit", *COMMON_OPTIONS, "single", "--archive", sample_archive, "--metadata", sample_metadata, ] ) assert result.output == ( "DEPOSIT OK - Deposit took 30.00s and succeeded.\n" "| 'load_time' = 20.00s\n" "| 'total_time' = 30.00s\n" "| 'upload_time' = 0.00s\n" "| 'validation_time' = 10.00s\n" + "DEPOSIT OK - Deposit Metadata update took 0.00s and succeeded.\n" + "| 'total_time' = 30.00s\n" + "| 'update_time' = 0.00s\n" ) assert result.exit_code == 0, f"Unexpected output: {result.output}" +def test_deposit_then_metadata_update_failed( + requests_mock, mocker, sample_archive, sample_metadata, mocked_time +): + """Deposit creation passed, deposit metadata update failed + + """ + scenario = WebScenario() + + scenario.add_step( + "post", f"{BASE_URL}/testcol/", ENTRY_TEMPLATE.format(status="deposited") + ) + scenario.add_step( + "get", f"{BASE_URL}/testcol/42/status/", status_template(status="verified"), + ) + scenario.add_step( + "get", f"{BASE_URL}/testcol/42/status/", status_template(status="loading"), + ) + scenario.add_step( + "get", f"{BASE_URL}/testcol/42/status/", status_template(status="done"), + ) + # Then metadata update calls + failed_status_xml = status_template( + status="failed", # lying here + status_detail="Failure to ingest", + swhid="swh:1:dir:02ed6084fb0e8384ac58980e07548a547431cf74", + ) + scenario.add_step("get", f"{BASE_URL}/testcol/42/status/", failed_status_xml) + scenario.add_step("get", f"{BASE_URL}/testcol/42/status/", failed_status_xml) + + scenario.install_mock(requests_mock) + + result = invoke( + [ + "check-deposit", + *COMMON_OPTIONS, + "single", + "--archive", + sample_archive, + "--metadata", + sample_metadata, + ], + catch_exceptions=True, + ) + + assert result.output == ( + "DEPOSIT OK - Deposit took 30.00s and succeeded.\n" + "| 'load_time' = 20.00s\n" + "| 'total_time' = 30.00s\n" + "| 'upload_time' = 0.00s\n" + "| 'validation_time' = 10.00s\n" + "DEPOSIT CRITICAL - Deposit Metadata update failed: You can only update " + "metadata on deposit with status 'done' \n" + "| 'total_time' = 30.00s\n" + "| 'update_time' = 0.00s\n" + ) + assert result.exit_code == 2, f"Unexpected output: {result.output}" + + def test_deposit_delay_warning( requests_mock, mocker, sample_archive, sample_metadata, mocked_time ): + """Deposit creation exceeded delays, no deposit update occurred. + + """ scenario = WebScenario() scenario.add_step( "post", f"{BASE_URL}/testcol/", ENTRY_TEMPLATE.format(status="deposited") ) scenario.add_step( "get", f"{BASE_URL}/testcol/42/status/", status_template(status="verified"), ) scenario.add_step( "get", f"{BASE_URL}/testcol/42/status/", status_template(status="done"), ) scenario.install_mock(requests_mock) result = invoke( [ "--warning", "15", "check-deposit", *COMMON_OPTIONS, "single", "--archive", sample_archive, "--metadata", sample_metadata, ], catch_exceptions=True, ) assert result.output == ( "DEPOSIT WARNING - Deposit took 20.00s and succeeded.\n" "| 'load_time' = 10.00s\n" "| 'total_time' = 20.00s\n" "| 'upload_time' = 0.00s\n" "| 'validation_time' = 10.00s\n" ) assert result.exit_code == 1, f"Unexpected output: {result.output}" def test_deposit_delay_critical( requests_mock, mocker, sample_archive, sample_metadata, mocked_time ): scenario = WebScenario() scenario.add_step( "post", f"{BASE_URL}/testcol/", ENTRY_TEMPLATE.format(status="deposited") ) scenario.add_step( "get", f"{BASE_URL}/testcol/42/status/", status_template(status="verified"), ) scenario.add_step( "get", f"{BASE_URL}/testcol/42/status/", status_template(status="done"), callback=lambda: time.sleep(60), ) scenario.install_mock(requests_mock) result = invoke( [ "--critical", "50", "check-deposit", *COMMON_OPTIONS, "single", "--archive", sample_archive, "--metadata", sample_metadata, ], catch_exceptions=True, ) assert result.output == ( "DEPOSIT CRITICAL - Deposit took 80.00s and succeeded.\n" "| 'load_time' = 70.00s\n" "| 'total_time' = 80.00s\n" "| 'upload_time' = 0.00s\n" "| 'validation_time' = 10.00s\n" ) assert result.exit_code == 2, f"Unexpected output: {result.output}" def test_deposit_timeout( requests_mock, mocker, sample_archive, sample_metadata, mocked_time ): scenario = WebScenario() scenario.add_step( "post", f"{BASE_URL}/testcol/", ENTRY_TEMPLATE.format(status="deposited"), callback=lambda: time.sleep(1500), ) scenario.add_step( "get", f"{BASE_URL}/testcol/42/status/", status_template(status="verified"), callback=lambda: time.sleep(1500), ) scenario.add_step( "get", f"{BASE_URL}/testcol/42/status/", status_template(status="loading"), callback=lambda: time.sleep(1500), ) scenario.install_mock(requests_mock) result = invoke( [ "check-deposit", *COMMON_OPTIONS, "single", "--archive", sample_archive, "--metadata", sample_metadata, ], catch_exceptions=True, ) assert result.output == ( "DEPOSIT CRITICAL - Timed out while in status loading " "(4520.0s seconds since deposit started)\n" "| 'total_time' = 4520.00s\n" "| 'upload_time' = 1500.00s\n" "| 'validation_time' = 1510.00s\n" ) assert result.exit_code == 2, f"Unexpected output: {result.output}" def test_deposit_rejected( requests_mock, mocker, sample_archive, sample_metadata, mocked_time ): scenario = WebScenario() scenario.add_step( "post", f"{BASE_URL}/testcol/", ENTRY_TEMPLATE.format(status="deposited") ) scenario.add_step( "get", f"{BASE_URL}/testcol/42/status/", status_template(status="rejected", status_detail="booo"), ) scenario.install_mock(requests_mock) result = invoke( [ "check-deposit", *COMMON_OPTIONS, "single", "--archive", sample_archive, "--metadata", sample_metadata, ], catch_exceptions=True, ) assert result.output == ( "DEPOSIT CRITICAL - Deposit was rejected: booo\n" "| 'total_time' = 10.00s\n" "| 'upload_time' = 0.00s\n" "| 'validation_time' = 10.00s\n" ) assert result.exit_code == 2, f"Unexpected output: {result.output}" def test_deposit_failed( requests_mock, mocker, sample_archive, sample_metadata, mocked_time ): scenario = WebScenario() scenario.add_step( "post", f"{BASE_URL}/testcol/", ENTRY_TEMPLATE.format(status="deposited") ) scenario.add_step( "get", f"{BASE_URL}/testcol/42/status/", status_template(status="verified"), ) scenario.add_step( "get", f"{BASE_URL}/testcol/42/status/", status_template(status="loading"), ) scenario.add_step( "get", f"{BASE_URL}/testcol/42/status/", status_template(status="failed", status_detail="booo"), ) scenario.install_mock(requests_mock) result = invoke( [ "check-deposit", *COMMON_OPTIONS, "single", "--archive", sample_archive, "--metadata", sample_metadata, ], catch_exceptions=True, ) assert result.output == ( "DEPOSIT CRITICAL - Deposit loading failed: booo\n" "| 'load_time' = 20.00s\n" "| 'total_time' = 30.00s\n" "| 'upload_time' = 0.00s\n" "| 'validation_time' = 10.00s\n" ) assert result.exit_code == 2, f"Unexpected output: {result.output}" def test_deposit_unexpected_status( requests_mock, mocker, sample_archive, sample_metadata, mocked_time ): scenario = WebScenario() scenario.add_step( "post", f"{BASE_URL}/testcol/", ENTRY_TEMPLATE.format(status="deposited") ) scenario.add_step( "get", f"{BASE_URL}/testcol/42/status/", status_template(status="verified"), ) scenario.add_step( "get", f"{BASE_URL}/testcol/42/status/", status_template(status="loading"), ) scenario.add_step( "get", f"{BASE_URL}/testcol/42/status/", status_template(status="what", status_detail="booo"), ) scenario.install_mock(requests_mock) result = invoke( [ "check-deposit", *COMMON_OPTIONS, "single", "--archive", sample_archive, "--metadata", sample_metadata, ], catch_exceptions=True, ) assert result.output == ( "DEPOSIT CRITICAL - Deposit got unexpected status: what (booo)\n" "| 'load_time' = 20.00s\n" "| 'total_time' = 30.00s\n" "| 'upload_time' = 0.00s\n" "| 'validation_time' = 10.00s\n" ) assert result.exit_code == 2, f"Unexpected output: {result.output}"