Repository: cekit/cekit
Pull request #772 (2022-03-29 08:17:32)

Refactor and improve logging for CalledProcessError


Patch:
diff --git a/cekit/builders/buildah.py b/cekit/builders/buildah.py
index ee1c198..22a1819 100644
--- a/cekit/builders/buildah.py
+++ b/cekit/builders/buildah.py
@@ -3,7 +3,6 @@ import os
 import subprocess
 
 from cekit.builder import Builder
-from cekit.errors import CekitError
 
 LOGGER = logging.getLogger("cekit")
 
@@ -52,13 +51,8 @@ class BuildahBuilder(Builder):
 
         LOGGER.debug("Running Buildah build: '{}'".format(" ".join(cmd)))
 
-        try:
-            subprocess.check_call(cmd)
+        subprocess.check_call(cmd)
 
-            LOGGER.info(
-                "Image built and available under following tags: {}".format(
-                    ", ".join(tags)
-                )
-            )
-        except Exception:
-            raise CekitError("Image build failed, see logs above.")
+        LOGGER.info(
+            "Image built and available under following tags: {}".format(", ".join(tags))
+        )
diff --git a/cekit/builders/osbs.py b/cekit/builders/osbs.py
index e4bd2ef..4537752 100644
--- a/cekit/builders/osbs.py
+++ b/cekit/builders/osbs.py
@@ -282,11 +282,7 @@ class OSBSBuilder(Builder):
 
         LOGGER.debug("Executing '{}'".format(cmd))
         with Chdir(self.dist_git_dir):
-            try:
-                subprocess.check_output(cmd, stderr=subprocess.STDOUT)
-            except subprocess.CalledProcessError as ex:
-                LOGGER.error("Cannot run '{}', output: '{}'".format(cmd, ex.output))
-                raise CekitError("Cannot update sources.")
+            subprocess.check_output(cmd)
 
         LOGGER.info("Update finished.")
 
@@ -350,11 +346,7 @@ class OSBSBuilder(Builder):
                     "Executing {} container build in OSBS...".format(build_type)
                 )
 
-                try:
-                    task_id = subprocess.check_output(cmd).strip().decode("utf8")
-
-                except subprocess.CalledProcessError as ex:
-                    raise CekitError("Building container image in OSBS failed", ex)
+                task_id = subprocess.check_output(cmd).strip().decode("utf8")
 
                 LOGGER.info(
                     "Task {0} was submitted, you can watch the progress here: {1}/taskinfo?taskID={0}".format(
@@ -436,9 +428,7 @@ class DistGit(object):
                 LOGGER.info("Fetching latest changes in repo {}...".format(self.repo))
                 subprocess.check_call(["git", "fetch"])
                 LOGGER.debug("Checking out {} branch...".format(self.branch))
-                subprocess.check_call(
-                    ["git", "checkout", "-f", self.branch], stderr=subprocess.STDOUT
-                )
+                subprocess.check_call(["git", "checkout", "-f", self.branch])
                 LOGGER.debug("Resetting branch...")
                 subprocess.check_call(
                     ["git", "reset", "--hard", "origin/%s" % self.branch]
diff --git a/cekit/cli.py b/cekit/cli.py
index 6e71089..cb25589 100644
--- a/cekit/cli.py
+++ b/cekit/cli.py
@@ -4,6 +4,7 @@ import logging
 import os
 import shutil
 import sys
+from subprocess import CalledProcessError
 
 import click
 
@@ -462,6 +463,13 @@ class Cekit(object):
             sys.exit(0)
         except KeyboardInterrupt:
             pass
+        except CalledProcessError as ex:
+            LOGGER.error(ex)
+            if ex.stdout:
+                LOGGER.error("Command stdout is:\n{}".format(ex.stdout))
+            if ex.stderr:
+                LOGGER.error("Command stderr is:\n{}".format(ex.stderr))
+            sys.exit(1)
         except CekitError as ex:
             if self.params.verbose:
                 LOGGER.exception(ex)
diff --git a/cekit/descriptor/resource.py b/cekit/descriptor/resource.py
index 11f7056..37c4319 100644
--- a/cekit/descriptor/resource.py
+++ b/cekit/descriptor/resource.py
@@ -473,14 +473,14 @@ class _GitResource(Resource):
     def _copy_impl(self, target):
         cmd = ["git", "clone", self.git.url, target]
         logger.debug("Cloning Git repository: '{}'".format(" ".join(cmd)))
-        subprocess.check_output(cmd, stderr=subprocess.STDOUT)
+        subprocess.check_output(cmd)
 
         with Chdir(target):
             cmd = ["git", "checkout", self.git.ref]
             logger.debug(
                 "Checking out '{}' ref: '{}'".format(self.git.ref, " ".join(cmd))
             )
-            subprocess.check_output(cmd, stderr=subprocess.STDOUT)
+            subprocess.check_output(cmd)
 
         return target
 
diff --git a/cekit/tools.py b/cekit/tools.py
index 1f48ac5..4c94c36 100644
--- a/cekit/tools.py
+++ b/cekit/tools.py
@@ -137,102 +137,100 @@ def decision(question):
 
 
 def get_brew_url(md5):
+    logger.debug("Getting brew details for an artifact with '{}' md5 sum".format(md5))
+    list_archives_cmd = [
+        "/usr/bin/brew",
+        "call",
+        "--json-output",
+        "listArchives",
+        "checksum={}".format(md5),
+        "type=maven",
+    ]
+    logger.debug("Executing '{}'.".format(" ".join(list_archives_cmd)))
+
     try:
-        logger.debug(
-            "Getting brew details for an artifact with '{}' md5 sum".format(md5)
+        json_archives = (
+            subprocess.check_output(list_archives_cmd).strip().decode("utf8")
         )
-        list_archives_cmd = [
-            "/usr/bin/brew",
-            "call",
-            "--json-output",
-            "listArchives",
-            "checksum={}".format(md5),
-            "type=maven",
-        ]
-        logger.debug("Executing '{}'.".format(" ".join(list_archives_cmd)))
-
-        try:
-            json_archives = (
-                subprocess.check_output(list_archives_cmd).strip().decode("utf8")
+    except subprocess.CalledProcessError as ex:
+        if ex.output is not None and "AuthError" in ex.output:
+            logger.warning(
+                "Brew authentication failed, please make sure you have a valid Kerberos ticket"
             )
-        except subprocess.CalledProcessError as ex:
-            if ex.output is not None and "AuthError" in ex.output:
-                logger.warning(
-                    "Brew authentication failed, please make sure you have a valid Kerberos ticket"
-                )
-            raise CekitError("Could not fetch archives for checksum {}".format(md5), ex)
+        raise CekitError("Could not fetch archives for checksum {}".format(md5), ex)
 
-        archives = yaml.safe_load(json_archives)
+    archives = yaml.safe_load(json_archives)
 
-        if not archives:
-            raise CekitError(
-                "Artifact with md5 checksum {} could not be found in Brew".format(md5)
-            )
+    if not archives:
+        raise CekitError(
+            "Artifact with md5 checksum {} could not be found in Brew".format(md5)
+        )
 
-        archive = archives[0]
-        build_id = archive["build_id"]
-        filename = archive["filename"]
-        group_id = archive["group_id"]
-        artifact_id = archive["artifact_id"]
-        version = archive["version"]
+    archive = archives[0]
+    build_id = archive["build_id"]
+    filename = archive["filename"]
+    group_id = archive["group_id"]
+    artifact_id = archive["artifact_id"]
+    version = archive["version"]
 
-        get_build_cmd = [
-            "brew",
-            "call",
-            "--json-output",
-            "getBuild",
-            "buildInfo={}".format(build_id),
-        ]
+    get_build_cmd = [
+        "brew",
+        "call",
+        "--json-output",
+        "getBuild",
+        "buildInfo={}".format(build_id),
+    ]
 
-        logger.debug("Executing '{}'".format(" ".join(get_build_cmd)))
+    logger.debug("Executing '{}'".format(" ".join(get_build_cmd)))
 
-        try:
-            json_build = subprocess.check_output(get_build_cmd).strip().decode("utf8")
-        except subprocess.CalledProcessError as ex:
-            raise CekitError("Could not fetch build {} from Brew".format(build_id), ex)
-
-        build = yaml.safe_load(json_build)
-
-        build_states = ["BUILDING", "COMPLETE", "DELETED", "FAILED", "CANCELED"]
-
-        # State 1 means: COMPLETE which is the only success state. Other states are:
-        #
-        # 'BUILDING': 0
-        # 'COMPLETE': 1
-        # 'DELETED': 2
-        # 'FAILED': 3
-        # 'CANCELED': 4
-        if build["state"] != 1:
-            raise CekitError(
-                "Artifact with checksum {} was found in Koji metadata but the build is in incorrect state ({}) making "
-                "the artifact not available for downloading anymore".format(
-                    md5, build_states[build["state"]]
-                )
+    try:
+        json_build = subprocess.check_output(get_build_cmd).strip().decode("utf8")
+    except subprocess.CalledProcessError as ex:
+        logger.error(
+            "{} Command stdout is '{}' with stderr '{}'".format(
+                ex, ex.stdout, ex.stderr
             )
+        )
+        raise CekitError("Could not fetch build {} from Brew".format(build_id), ex)
+
+    build = yaml.safe_load(json_build)
 
-        package = build["package_name"]
-        release = build["release"]
-
-        url = (
-            "http://download.devel.redhat.com/brewroot/packages/"
-            + package
-            + "/"
-            + version.replace("-", "_")
-            + "/"
-            + release
-            + "/maven/"
-            + group_id.replace(".", "/")
-            + "/"
-            + artifact_id
-            + "/"
-            + version
-            + "/"
-            + filename
+    build_states = ["BUILDING", "COMPLETE", "DELETED", "FAILED", "CANCELED"]
+
+    # State 1 means: COMPLETE which is the only success state. Other states are:
+    #
+    # 'BUILDING': 0
+    # 'COMPLETE': 1
+    # 'DELETED': 2
+    # 'FAILED': 3
+    # 'CANCELED': 4
+    if build["state"] != 1:
+        raise CekitError(
+            "Artifact with checksum {} was found in Koji metadata but the build is in incorrect state ({}) making "
+            "the artifact not available for downloading anymore".format(
+                md5, build_states[build["state"]]
+            )
         )
-    except subprocess.CalledProcessError as ex:
-        logger.error("Can't fetch artifacts details from brew: '{}'.".format(ex.output))
-        raise ex
-    return url
+
+    package = build["package_name"]
+    release = build["release"]
+
+    return (
+        "http://download.devel.redhat.com/brewroot/packages/"
+        + package
+        + "/"
+        + version.replace("-", "_")
+        + "/"
+        + release
+        + "/maven/"
+        + group_id.replace(".", "/")
+        + "/"
+        + artifact_id
+        + "/"
+        + version
+        + "/"
+        + filename
+    )
 
 
 def copy_recursively(source_directory, destination_directory):
diff --git a/docs/_ext/schema.py b/docs/_ext/schema.py
index 43ca076..5fd1ad1 100644
--- a/docs/_ext/schema.py
+++ b/docs/_ext/schema.py
@@ -12,7 +12,12 @@ class SchemaDirective(SphinxDirective):
     required_arguments = 1
     optional_arguments = 1
 
-    option_spec = {"name": directives.unchanged}
+    option_spec = {
+        "name": directives.unchanged,
+        "language": directives.unchanged,
+        "encoding": directives.unchanged,
+        "linenos": directives.flag,
+    }
 
     def run(self):
         module, clazz = self.arguments[0].rsplit(".", 1)
@@ -36,15 +41,7 @@ class SchemaDirective(SphinxDirective):
 
 
 def setup(app):
-    app.add_directive(
-        "schema",
-        SchemaDirective,
-        content=0,
-        arguments=(1, 0, 0),
-        linenos=directives.flag,
-        language=directives.unchanged,
-        encoding=directives.encoding,
-    )
+    app.add_directive("schema", SchemaDirective)
 
     # TODO: Replace nodes after the source was changed
     # app.connect('source-read', process_schema_nodes)
diff --git a/docs/descriptor/includes/module/packages.rst b/docs/descriptor/includes/module/packages.rst
index 31164de..141ed88 100644
--- a/docs/descriptor/includes/module/packages.rst
+++ b/docs/descriptor/includes/module/packages.rst
@@ -5,4 +5,3 @@
 .. include:: includes/packages/repositories/plain.rst
 .. include:: includes/packages/repositories/rpm.rst
 .. include:: includes/packages/repositories/url.rst
-
diff --git a/docs/requirements.txt b/docs/requirements.txt
index 1bc7b64..640168c 100644
--- a/docs/requirements.txt
+++ b/docs/requirements.txt
@@ -1,4 +1,4 @@
-sphinx>=1.7.6,<3.0
+sphinx>=1.7.6
 sphinx-autobuild==0.7.1
 https://github.com/guzzle/guzzle_sphinx_theme/archive/eefd45b79383b1b4aab1607444e41366fd1348a6.zip
 pykwalify>=1.6.0


Test patch:
diff --git a/cekit/test/collector.py b/cekit/test/collector.py
index ec37a09..e0a3a96 100644
--- a/cekit/test/collector.py
+++ b/cekit/test/collector.py
@@ -52,7 +52,7 @@ class BehaveTestCollector(object):
             "v%s" % version,
         ]
         logger.debug("Running '{}'".format(" ".join(cmd)))
-        subprocess.check_output(cmd, stderr=subprocess.STDOUT)
+        subprocess.check_output(cmd)
 
     def collect(self, version, url):
         # first clone common steps
diff --git a/tests/test_integ_builder_osbs.py b/tests/test_integ_builder_osbs.py
index f06d0ba..85becda 100644
--- a/tests/test_integ_builder_osbs.py
+++ b/tests/test_integ_builder_osbs.py
@@ -90,7 +90,7 @@ def run_osbs(
     )
 
 
-def test_osbs_builder_with_asume_yes(tmpdir, mocker, caplog):
+def test_osbs_builder_with_assume_yes(tmpdir, mocker, caplog):
     caplog.set_level(logging.DEBUG, logger="cekit")
 
     # Specifically set the decision result to False, to fail any build
@@ -136,6 +136,37 @@ def test_osbs_builder_with_asume_yes(tmpdir, mocker, caplog):
     assert "Image was built successfully in OSBS!" in caplog.text
 
 
+def test_osbs_builder_with_process_error(tmpdir, mocker, caplog):
+    caplog.set_level(logging.DEBUG, logger="cekit")
+
+    # Specifically set the decision result to False, to fail any build
+    # that depends on the decision. But in case the --assume-yes switch is used
+    # we should not get to this point at all. If we get, the test should fail.
+    mock_decision = mocker.patch("cekit.tools.decision", return_value=False)
+    mock_check_call = mocker.patch.object(subprocess, "check_call")
+    mock_check_call.side_effect = [
+        0,
+        subprocess.CalledProcessError(1, "git", output="A GIT ERROR"),
+    ]
+    mocker.patch.object(subprocess, "call", return_value=1)
+
+    source_dir = tmpdir.mkdir("source")
+    source_dir.mkdir("osbs").mkdir("repo")
+
+    run_osbs(
+        image_descriptor.copy(),
+        str(source_dir),
+        mocker,
+        1,
+        ["build", "osbs", "--assume-yes"],
+    )
+
+    mock_decision.assert_not_called()
+
+    assert "A GIT ERROR" in caplog.text
+    assert "Image was built successfully in OSBS!" not in caplog.text
+
+
 def test_osbs_builder_with_push_with_sync_only(tmpdir, mocker, caplog):
     """
     Should sync with dist-git repository without kicking the build
diff --git a/tests/test_unit_resource.py b/tests/test_unit_resource.py
index 6237ef0..4b35a58 100644
--- a/tests/test_unit_resource.py
+++ b/tests/test_unit_resource.py
@@ -75,10 +75,8 @@ def test_git_clone(mocker):
     res.copy("dir")
     mock.assert_has_calls(
         [
-            call(
-                ["git", "clone", "http://host.com/url/path.git", "dir/path"], stderr=-2
-            ),
-            call(["git", "checkout", "ref"], stderr=-2),
+            call(["git", "clone", "http://host.com/url/path.git", "dir/path"]),
+            call(["git", "checkout", "ref"]),
         ]
     )