From 179250fb3f1bdd2eebcaebc965b4505f5bc12c90 Mon Sep 17 00:00:00 2001 From: Nick Dokos Date: Mon, 10 Apr 2023 14:17:57 -0400 Subject: [PATCH] pbench-results-push: Backport of #3348 to b0.72 * Do not use the file logger at all in python commands. The logger only uses the default Streamhandler now which outputs to stderr. * - copy_result_tb: return the response to the PUT request copy_result_tb returns the response from the server. The callers are responsible for interpreting it. However, it can still raise an exception (e.g. on connection error). - push.py: construct a reasonable message out of the response and check if the HTTP status is 201: we exit with 0 if so. Otherwise, if the status is OK (i.e. < 400), then we exit with 0 but print a message with a reasonably self-explanatory status on stderr. We expect that we will only ever get two OK responses: a 201 which indicates a successful PUT with a newly created dataset and 200 which indicates a duplicate dataset. In all non-OK cases, we output the message on stderr and exit with 1. - move.py: check the response - if not OK (>= 400) raise exception. * Fix the monkeypatching in test_copy_result_tb.py Monkeypatching pathlib components (.exists() and .open()) causes pytest to blow up. Limit the scope by using `monkeypatch.context()' so that it is only applied to the objects under test (and not e.g. to what is used in checking assertions). * Use symbolic constant instead of explicit 201 * Parametrize the "normal" test This is just the first step - see issue #3374 for some more work along these lines. --- agent/config/pbench-agent-default.cfg | 6 - lib/pbench/agent/__init__.py | 7 - lib/pbench/agent/base.py | 7 +- lib/pbench/agent/results.py | 14 +- lib/pbench/cli/agent/commands/results/move.py | 9 +- lib/pbench/cli/agent/commands/results/push.py | 25 ++- .../unit/agent/task/test_copy_result_tb.py | 149 ++++++++++-------- .../test/unit/agent/task/test_results_push.py | 117 ++++++++++++-- 8 files changed, 221 insertions(+), 113 deletions(-) diff --git a/agent/config/pbench-agent-default.cfg b/agent/config/pbench-agent-default.cfg index dca41baa3a..aff4ac3c14 100644 --- a/agent/config/pbench-agent-default.cfg +++ b/agent/config/pbench-agent-default.cfg @@ -9,12 +9,6 @@ pbench_log = %(pbench_run)s/pbench.log # RPM requirement mode: strict vs relaxed rpm_requirement_mode = strict -[logging] -logger_type = file -# # "log_dir" is only considered when "logger_type" is set to "file"; And by -# # default the log file directory is the "pbench_run" directory. -# log_dir = - [results] user = pbench host_info_uri = pbench-results-host-info.versioned/pbench-results-host-info.URL002 diff --git a/lib/pbench/agent/__init__.py b/lib/pbench/agent/__init__.py index 905f2f066a..48040b5214 100644 --- a/lib/pbench/agent/__init__.py +++ b/lib/pbench/agent/__init__.py @@ -61,13 +61,6 @@ def __init__(self, cfg_name): ) self.pbench_lib_dir = self.pbench_install_dir / "lib" - if self.logger_type == "file" and self.log_dir is None: - # The configuration file has a logging section configured to use - # "file" logging, but no log directory is set. We'll set the log - # directory to be the directory of the legacy ${pbench_log} value - # determined above. - self.log_dir = str(self.pbench_log.parent) - try: self.ssh_opts = self.get("results", "ssh_opts", fallback=DEFAULT_SSH_OPTS) except (NoOptionError, NoSectionError): diff --git a/lib/pbench/agent/base.py b/lib/pbench/agent/base.py index f782edf00f..58cac9a675 100644 --- a/lib/pbench/agent/base.py +++ b/lib/pbench/agent/base.py @@ -54,11 +54,6 @@ def __init__(self, context): ) click.get_current_context().exit(1) - # log file - N.B. not a directory - self.pbench_log = self.config.pbench_log - if self.pbench_log is None: - self.pbench_log = self.pbench_run / "pbench.log" - self.pbench_install_dir = self.config.pbench_install_dir if self.pbench_install_dir is None: self.pbench_install_dir = "/opt/pbench-agent" @@ -71,7 +66,7 @@ def __init__(self, context): self.pbench_bspp_dir = self.pbench_install_dir / "bench-scripts" / "postprocess" self.pbench_lib_dir = self.pbench_install_dir / "lib" - self.logger = setup_logging(debug=False, logfile=self.pbench_log) + self.logger = setup_logging(debug=False, logfile=None) self.ssh_opts = os.environ.get("ssh_opts", self.config.ssh_opts) self.scp_opts = os.environ.get("scp_opts", self.config.scp_opts) diff --git a/lib/pbench/agent/results.py b/lib/pbench/agent/results.py index 884cee9f58..39bb822e38 100644 --- a/lib/pbench/agent/results.py +++ b/lib/pbench/agent/results.py @@ -313,7 +313,7 @@ def __init__( def copy_result_tb( self, token: str, access: Optional[str] = None, metadata: Optional[List] = None - ) -> None: + ) -> requests.Response: """Copies the tar ball from the agent to the configured server using upload API. @@ -327,6 +327,9 @@ def copy_result_tb( metadata: list of metadata keys to be sent on PUT. (Optional) Format: key:value + Returns: + response from the PUT request + Raises: RuntimeError if a connection to the server fails FileUploadError if the tar ball failed to upload properly @@ -367,17 +370,12 @@ def copy_result_tb( ) ) - response = requests.Session().send(request) - response.raise_for_status() - self.logger.info("File uploaded successfully") + return requests.Session().send(request) except requests.exceptions.ConnectionError as exc: raise RuntimeError(f"Cannot connect to '{self.upload_url}': {exc}") except Exception as exc: raise self.FileUploadError( - "There was something wrong with file upload request: " + "There was something wrong with the file upload request: " f"file: '{self.tarball}', URL: '{self.upload_url}';" f" error: '{exc}'" ) - assert ( - response.ok - ), f"Logic error! Unexpected error response, '{response.reason}' ({response.status_code})" diff --git a/lib/pbench/cli/agent/commands/results/move.py b/lib/pbench/cli/agent/commands/results/move.py index 96fa1c9586..b9b8ef8355 100644 --- a/lib/pbench/cli/agent/commands/results/move.py +++ b/lib/pbench/cli/agent/commands/results/move.py @@ -5,6 +5,7 @@ from typing import List import click +import requests from pbench.agent.base import BaseCommand from pbench.agent.results import CopyResultTb, MakeResultTb @@ -104,9 +105,15 @@ def execute(self, single_threaded: bool, delete: bool = True) -> int: self.config, self.logger, ) - crt.copy_result_tb( + res = crt.copy_result_tb( self.context.token, self.context.access, self.context.metadata ) + if not res.ok: + try: + msg = res.json()["message"] + except requests.exceptions.JSONDecodeError: + msg = res.text if res.text else res.reason + raise CopyResultTb.FileUploadError(msg) except Exception as exc: if isinstance(exc, (CopyResultTb.FileUploadError, RuntimeError)): msg = "Error uploading file" diff --git a/lib/pbench/cli/agent/commands/results/push.py b/lib/pbench/cli/agent/commands/results/push.py index 0d1fd0f268..186405ad07 100644 --- a/lib/pbench/cli/agent/commands/results/push.py +++ b/lib/pbench/cli/agent/commands/results/push.py @@ -1,7 +1,9 @@ +from http import HTTPStatus from pathlib import Path from typing import List import click +import requests from pbench.agent.base import BaseCommand from pbench.agent.results import CopyResultTb @@ -24,10 +26,29 @@ def execute(self) -> int: self.config, self.logger, ) - crt.copy_result_tb( + res = crt.copy_result_tb( self.context.token, self.context.access, self.context.metadata ) - return 0 + + # success + if res.status_code == HTTPStatus.CREATED: + return 0 + + try: + msg = res.json()["message"] + except requests.exceptions.JSONDecodeError: + msg = res.text if res.text else res.reason + + # dup or other unexpected but non-error status + if res.ok: + click.echo(msg, err=True) + return 0 + + click.echo( + f"HTTP Error status: {res.status_code}, message: {msg}", + err=True, + ) + return 1 @sort_click_command_parameters diff --git a/lib/pbench/test/unit/agent/task/test_copy_result_tb.py b/lib/pbench/test/unit/agent/task/test_copy_result_tb.py index 124954dfca..64f03c3a14 100644 --- a/lib/pbench/test/unit/agent/task/test_copy_result_tb.py +++ b/lib/pbench/test/unit/agent/task/test_copy_result_tb.py @@ -42,18 +42,20 @@ def test_tarball_nonexistent(self, monkeypatch, agent_logger): bad_tarball_name = "nonexistent-tarball.tar.xz" expected_error_message = f"Tar ball '{bad_tarball_name}' does not exist" - monkeypatch.setattr( - Path, "exists", self.get_path_exists_mock(bad_tarball_name, False) - ) - - with pytest.raises(FileNotFoundError) as excinfo: - CopyResultTb( - bad_tarball_name, - 0, - "ignoremd5", - self.config, - agent_logger, + with monkeypatch.context() as m: + m.setattr( + Path, "exists", self.get_path_exists_mock(bad_tarball_name, False) ) + + with pytest.raises(FileNotFoundError) as excinfo: + CopyResultTb( + bad_tarball_name, + 0, + "ignoremd5", + self.config, + agent_logger, + ) + assert str(excinfo.value).endswith( expected_error_message ), f"expected='...{expected_error_message}', found='{str(excinfo.value)}'" @@ -70,7 +72,7 @@ def request_callback(request: requests.Request): else: assert "access" in request.params assert request.params["access"] == access - return HTTPStatus.OK, {}, "" + return HTTPStatus.CREATED, {}, "" responses.add_callback( responses.PUT, @@ -78,22 +80,25 @@ def request_callback(request: requests.Request): callback=request_callback, ) - monkeypatch.setattr(Path, "exists", self.get_path_exists_mock(tb_name, True)) - monkeypatch.setattr( - Path, "open", self.get_path_open_mock(tb_name, io.StringIO(tb_contents)) - ) + with monkeypatch.context() as m: + m.setattr(Path, "exists", self.get_path_exists_mock(tb_name, True)) + m.setattr( + Path, "open", self.get_path_open_mock(tb_name, io.StringIO(tb_contents)) + ) - crt = CopyResultTb( - tb_name, - len(tb_contents), - "someMD5", - self.config, - agent_logger, - ) - if access is None: - crt.copy_result_tb("token") - else: - crt.copy_result_tb("token", access) + crt = CopyResultTb( + tb_name, + len(tb_contents), + "someMD5", + self.config, + agent_logger, + ) + if access is None: + res = crt.copy_result_tb("token") + else: + res = crt.copy_result_tb("token", access) + + assert res.status_code == HTTPStatus.CREATED # If we got this far without an exception, then the test passes. @responses.activate @@ -111,7 +116,7 @@ def request_callback(request: requests.Request): assert request.params["metadata"] == metadata else: assert "metadata" not in request.params - return HTTPStatus.OK, {}, "" + return HTTPStatus.CREATED, {}, "" responses.add_callback( responses.PUT, @@ -119,22 +124,25 @@ def request_callback(request: requests.Request): callback=request_callback, ) - monkeypatch.setattr(Path, "exists", self.get_path_exists_mock(tb_name, True)) - monkeypatch.setattr( - Path, "open", self.get_path_open_mock(tb_name, io.StringIO(tb_contents)) - ) + with monkeypatch.context() as m: + m.setattr(Path, "exists", self.get_path_exists_mock(tb_name, True)) + m.setattr( + Path, "open", self.get_path_open_mock(tb_name, io.StringIO(tb_contents)) + ) - crt = CopyResultTb( - tb_name, - len(tb_contents), - "someMD5", - self.config, - agent_logger, - ) - if metadata is None: - crt.copy_result_tb("token") - else: - crt.copy_result_tb("token", access, metadata) + crt = CopyResultTb( + tb_name, + len(tb_contents), + "someMD5", + self.config, + agent_logger, + ) + if metadata is None: + res = crt.copy_result_tb("token") + else: + res = crt.copy_result_tb("token", access, metadata) + + assert res.status_code == HTTPStatus.CREATED # If we got this far without an exception, then the test passes. @responses.activate @@ -147,20 +155,21 @@ def test_connection_error(self, monkeypatch, agent_logger): responses.PUT, upload_url, body=requests.exceptions.ConnectionError("uh-oh") ) - monkeypatch.setattr(Path, "exists", self.get_path_exists_mock(tb_name, True)) - monkeypatch.setattr( - Path, "open", self.get_path_open_mock(tb_name, io.StringIO(tb_contents)) - ) - - with pytest.raises(RuntimeError) as excinfo: - crt = CopyResultTb( - tb_name, - len(tb_contents), - "someMD5", - self.config, - agent_logger, + with monkeypatch.context() as m: + m.setattr(Path, "exists", self.get_path_exists_mock(tb_name, True)) + m.setattr( + Path, "open", self.get_path_open_mock(tb_name, io.StringIO(tb_contents)) ) - crt.copy_result_tb("token") + + with pytest.raises(RuntimeError) as excinfo: + crt = CopyResultTb( + tb_name, + len(tb_contents), + "someMD5", + self.config, + agent_logger, + ) + crt.copy_result_tb("token") assert str(excinfo.value).startswith( expected_error_message @@ -174,18 +183,20 @@ def test_unexpected_error(self, monkeypatch, agent_logger): responses.add(responses.PUT, upload_url, body=RuntimeError("uh-oh")) - monkeypatch.setattr(Path, "exists", self.get_path_exists_mock(tb_name, True)) - monkeypatch.setattr( - Path, "open", self.get_path_open_mock(tb_name, io.StringIO(tb_contents)) - ) - - with pytest.raises(CopyResultTb.FileUploadError) as excinfo: - crt = CopyResultTb( - tb_name, - len(tb_contents), - "someMD5", - self.config, - agent_logger, + with monkeypatch.context() as m: + m.setattr(Path, "exists", self.get_path_exists_mock(tb_name, True)) + m.setattr( + Path, "open", self.get_path_open_mock(tb_name, io.StringIO(tb_contents)) ) - crt.copy_result_tb("token") + + with pytest.raises(CopyResultTb.FileUploadError) as excinfo: + crt = CopyResultTb( + tb_name, + len(tb_contents), + "someMD5", + self.config, + agent_logger, + ) + crt.copy_result_tb("token") + assert "something wrong" in str(excinfo.value) diff --git a/lib/pbench/test/unit/agent/task/test_results_push.py b/lib/pbench/test/unit/agent/task/test_results_push.py index 763971e333..a303b1967b 100644 --- a/lib/pbench/test/unit/agent/task/test_results_push.py +++ b/lib/pbench/test/unit/agent/task/test_results_push.py @@ -1,8 +1,10 @@ from http import HTTPStatus import logging import os +from typing import Dict, Optional, Union from click.testing import CliRunner +import pytest import requests import responses @@ -23,11 +25,22 @@ class TestResultsPush: URL = "http://pbench.example.com/api/v1" @staticmethod - def add_http_mock_response(code: HTTPStatus = HTTPStatus.OK): + def add_http_mock_response( + status_code: HTTPStatus = None, message: Optional[Union[str, Dict]] = None + ): + parms = {} + if status_code: + parms["status"] = status_code + + if isinstance(message, dict): + parms["json"] = message + elif isinstance(message, str): + parms["body"] = message + responses.add( responses.PUT, f"{TestResultsPush.URL}/upload/{os.path.basename(tarball)}", - status=code, + **parms, ) @staticmethod @@ -63,7 +76,7 @@ def test_missing_arg(): ], ) assert result.exit_code == 2 - assert result.stderr.find("Missing argument") > -1 + assert "Missing argument" in result.stderr @staticmethod @responses.activate @@ -79,11 +92,8 @@ def test_bad_arg(): ) assert result.exit_code == 2 assert ( - result.stderr.find( - "Invalid value for 'RESULT_TB_NAME': " - "File 'nothing.tar.xz' does not exist." - ) - > -1 + "Invalid value for 'RESULT_TB_NAME': " + "File 'nothing.tar.xz' does not exist." in result.stderr ) @staticmethod @@ -126,7 +136,7 @@ def test_extra_arg(): ], ) assert result.exit_code == 2 - assert result.stderr.find("unexpected extra argument") > -1 + assert "unexpected extra argument" in result.stderr @staticmethod @responses.activate @@ -148,7 +158,7 @@ def test_multiple_meta_args_single_option(): ], ) assert result.exit_code == 0, result.stderr - assert result.stderr == "File uploaded successfully\n" + assert result.stdout == "" @staticmethod @responses.activate @@ -172,7 +182,84 @@ def test_multiple_meta_args(): ], ) assert result.exit_code == 0, result.stderr - assert result.stderr == "File uploaded successfully\n" + assert result.stdout == "" + + @staticmethod + @responses.activate + @pytest.mark.parametrize( + "status_code,message,exit_code", + ( + (HTTPStatus.CREATED, None, 0), + (HTTPStatus.OK, {"message": "Dup"}, 0), + (HTTPStatus.OK, "Dup", 0), + (HTTPStatus.NO_CONTENT, {"message": "No content"}, 0), + (HTTPStatus.NO_CONTENT, "No content", 0), + ( + HTTPStatus.REQUEST_ENTITY_TOO_LARGE, + {"message": "Request Entity Too Large"}, + 1, + ), + (HTTPStatus.REQUEST_ENTITY_TOO_LARGE, "Request Entity Too Large", 1), + (HTTPStatus.NOT_FOUND, {"message": "Not Found"}, 1), + (HTTPStatus.NOT_FOUND, "Not Found", 1), + ), + ) + def test_push_status(status_code, message, exit_code): + """Test normal operation when all arguments and options are specified""" + + TestResultsPush.add_http_mock_response(status_code, message) + runner = CliRunner(mix_stderr=False) + result = runner.invoke( + main, + args=[ + TestResultsPush.TOKN_SWITCH, + TestResultsPush.TOKN_TEXT, + TestResultsPush.ACCESS_SWITCH, + TestResultsPush.ACCESS_TEXT, + TestResultsPush.META_SWITCH, + TestResultsPush.META_TEXT_TEST + "," + TestResultsPush.META_TEXT_FOO, + tarball, + ], + ) + assert result.exit_code == exit_code, result.stderr + assert result.stdout == "" + + try: + err_msg = "" if not message else message["message"] + except TypeError: + err_msg = message + + if status_code >= HTTPStatus.BAD_REQUEST: + err_msg = f"HTTP Error status: {status_code.value}, message: {err_msg}" + assert result.stderr.strip() == err_msg + + @staticmethod + @responses.activate + def test_error_too_large_tarball(): + """Test normal operation when all arguments and options are specified""" + + TestResultsPush.add_http_mock_response( + status_code=HTTPStatus.REQUEST_ENTITY_TOO_LARGE, + message={"message": "Request Entity Too Large"}, + ) + runner = CliRunner(mix_stderr=False) + result = runner.invoke( + main, + args=[ + TestResultsPush.TOKN_SWITCH, + TestResultsPush.TOKN_TEXT, + TestResultsPush.ACCESS_SWITCH, + TestResultsPush.ACCESS_TEXT, + TestResultsPush.META_SWITCH, + TestResultsPush.META_TEXT_TEST + "," + TestResultsPush.META_TEXT_FOO, + tarball, + ], + ) + assert result.exit_code == 1, result.stderr + assert ( + result.stderr + == "HTTP Error status: 413, message: Request Entity Too Large\n" + ) @staticmethod @responses.activate @@ -196,7 +283,7 @@ def test_token_envar(monkeypatch, caplog): runner = CliRunner(mix_stderr=False) result = runner.invoke(main, args=[tarball]) assert result.exit_code == 0, result.stderr - assert result.stderr == "File uploaded successfully\n" + assert result.stdout == "" @staticmethod @responses.activate @@ -239,11 +326,13 @@ def test_http_error(monkeypatch, caplog): """Test handling of 404 errors""" monkeypatch.setenv("PBENCH_ACCESS_TOKEN", TestResultsPush.TOKN_TEXT) - TestResultsPush.add_http_mock_response(HTTPStatus.NOT_FOUND) + TestResultsPush.add_http_mock_response( + HTTPStatus.NOT_FOUND, message={"message": "Not Found"} + ) caplog.set_level(logging.DEBUG) runner = CliRunner(mix_stderr=False) result = runner.invoke(main, args=[tarball]) assert result.exit_code == 1 assert ( - str(result.stderr).find("Not Found") > -1 + "Not Found" in result.stderr ), f"stderr: {result.stderr!r}; stdout: {result.stdout!r}"