diff --git a/module_build_service/builder/KojiModuleBuilder.py b/module_build_service/builder/KojiModuleBuilder.py index b8044519..5b56f29a 100644 --- a/module_build_service/builder/KojiModuleBuilder.py +++ b/module_build_service/builder/KojiModuleBuilder.py @@ -356,7 +356,7 @@ class KojiModuleBuilder(GenericBuilder): fd.close() log.debug("Building %s.spec" % name) - # We are not interested in the rpmbuild stdout... + # We are not interested in the rpmbuild output... null_fd = open(os.devnull, "w") execute_cmd( [ @@ -369,7 +369,7 @@ class KojiModuleBuilder(GenericBuilder): "_sourcedir %s" % sources_dir, ], cwd=td, - stdout=null_fd, + output=null_fd, ) null_fd.close() sdir = os.path.join(td, "SRPMS") diff --git a/module_build_service/builder/MockModuleBuilder.py b/module_build_service/builder/MockModuleBuilder.py index ccfc5f29..5d7d8879 100644 --- a/module_build_service/builder/MockModuleBuilder.py +++ b/module_build_service/builder/MockModuleBuilder.py @@ -23,7 +23,7 @@ from module_build_service.builder.utils import ( get_koji_config, validate_koji_tag, ) -from module_build_service.common import conf, log, models +from module_build_service.common import build_logs, conf, log, models from module_build_service.common.koji import get_session from module_build_service.common.modulemd import Modulemd from module_build_service.common.utils import import_mmd, load_mmd_file, mmd_to_str @@ -409,14 +409,16 @@ class MockModuleBuilder(GenericBuilder): m1_mmd.add_rpm_artifact(artifact_to_add) # Generate repo. - execute_cmd(["/usr/bin/createrepo_c", "--pkglist", pkglist, path]) + execute_cmd(["/usr/bin/createrepo_c", "--pkglist", pkglist, path], + output=build_logs.current_log_stream) # ...and inject modules.yaml there if asked. if include_module_yaml: mmd_path = os.path.join(path, "modules.yaml") with open(mmd_path, "wb") as f: f.write(mmd_to_str(m1_mmd).encode("utf-8")) - execute_cmd(["/usr/bin/modifyrepo_c", "--mdtype=modules", mmd_path, repodata_path]) + execute_cmd(["/usr/bin/modifyrepo_c", "--mdtype=modules", mmd_path, repodata_path], + output=build_logs.current_log_stream) def _add_repo(self, name, baseurl, extra=""): """ @@ -646,24 +648,21 @@ class MockModuleBuilder(GenericBuilder): mock_config = os.path.join( self.configdir, "mock-%s.cfg" % str(threading.current_thread().name)) - # Open the logs to which we will forward mock stdout/stderr. - mock_stdout_log = open( - os.path.join(self.resultsdir, artifact_name + "-mock-stdout.log"), "w") - mock_stderr_log = open( - os.path.join(self.resultsdir, artifact_name + "-mock-stderr.log"), "w") + # Open the log to which we will forward mock stdout/stderr. + mock_output_log = open( + os.path.join(self.resultsdir, artifact_name + "-mock-output.log"), "w") srpm = artifact_name resultsdir = builder.resultsdir try: # Initialize mock. execute_cmd( - ["mock", "-v", "-r", mock_config, "--init"], - stdout=mock_stdout_log, - stderr=mock_stderr_log, + ["mock", "-r", mock_config, "--init"], + output=mock_output_log, ) # Start the build and store results to resultsdir - builder.build(mock_stdout_log, mock_stderr_log) + builder.build(mock_output_log) srpm = find_srpm(resultsdir) # Emit messages simulating complete build. These messages @@ -687,8 +686,7 @@ class MockModuleBuilder(GenericBuilder): with open(os.path.join(resultsdir, "status.log"), "w") as f: f.write("failed\n") - mock_stdout_log.close() - mock_stderr_log.close() + mock_output_log.close() self._save_log(resultsdir, "state.log", artifact_name) self._save_log(resultsdir, "root.log", artifact_name) @@ -808,10 +806,10 @@ class BaseBuilder(object): def __init__(self, config, resultsdir): self.config = config self.resultsdir = resultsdir - self.cmd = ["mock", "-v", "-r", config, "--no-clean", "--resultdir=%s" % resultsdir] + self.cmd = ["mock", "-r", config, "--no-clean", "--resultdir=%s" % resultsdir] - def build(self, stdout, stderr): - execute_cmd(self.cmd, stdout=stdout, stderr=stderr) + def build(self, output): + execute_cmd(self.cmd, output=output) class SRPMBuilder(BaseBuilder): diff --git a/module_build_service/builder/utils.py b/module_build_service/builder/utils.py index 5c779e09..bb78b87b 100644 --- a/module_build_service/builder/utils.py +++ b/module_build_service/builder/utils.py @@ -13,7 +13,7 @@ import subprocess import munch import requests -from module_build_service.common import conf, log, models +from module_build_service.common import build_logs, conf, log, models from module_build_service.common.errors import ValidationError, ProgrammingError @@ -26,33 +26,29 @@ def find_srpm(cod): return os.path.join(cod, f) -def execute_cmd(args, stdout=None, stderr=None, cwd=None): +def execute_cmd(args, output=None, cwd=None): """ - Executes command defined by `args`. If `stdout` or `stderr` is set to - Python file object, the stderr/stdout output is redirecter to that file. + Executes command defined by `args`. If `output` is set to + Python file object, the stderr and stdout output is redirected to that file. If `cwd` is set, current working directory is set accordingly for the executed command. :param args: list defining the command to execute. - :param stdout: Python file object to redirect the stdout to. - :param stderr: Python file object to redirect the stderr to. + :param output: Python file object to redirect the stderr and stdout to. :param cwd: string defining the current working directory for command. :raises RuntimeError: Raised when command exits with non-zero exit code. """ out_log_msg = "" - if stdout and hasattr(stdout, "name"): - out_log_msg += ", stdout log: %s" % stdout.name - if stderr and hasattr(stderr, "name"): - out_log_msg += ", stderr log: %s" % stderr.name + if output and hasattr(output, "name"): + out_log_msg += ", output log: %s" % output.name log.info("Executing the command \"%s\"%s" % (" ".join(args), out_log_msg)) - proc = subprocess.Popen(args, stdout=stdout, stderr=stderr, cwd=cwd) - out, err = proc.communicate() + proc = subprocess.Popen(args, stdout=output, stderr=output, cwd=cwd) + proc.wait() if proc.returncode != 0: err_msg = "Command '%s' returned non-zero value %d%s" % (args, proc.returncode, out_log_msg) raise RuntimeError(err_msg) - return out, err def get_koji_config(mbs_config): @@ -181,7 +177,8 @@ def create_local_repo_from_koji_tag(config, tag, repo_dir, archs=None): shutil.rmtree(repodata_path) log.info("Creating local repository in %s" % repo_dir) - execute_cmd(["/usr/bin/createrepo_c", repo_dir]) + execute_cmd(["/usr/bin/createrepo_c", repo_dir], + output=build_logs.current_log_stream) log.local_repo_done(tag, 'Finished downloading packages') diff --git a/module_build_service/common/logger.py b/module_build_service/common/logger.py index a29fc3b5..78d300b9 100644 --- a/module_build_service/common/logger.py +++ b/module_build_service/common/logger.py @@ -205,6 +205,21 @@ class ModuleBuildLogs(object): log.removeHandler(handler) del self.handlers[build.id] + @property + def current_log_stream(self): + # Imported here because of importing cycle between __init__.py, + # scheduler and models. + from module_build_service.scheduler.consumer import MBSConsumer + + if MBSConsumer.current_module_build_id: + handler = self.handlers.get(MBSConsumer.current_module_build_id) + if handler: + return handler.stream + else: + return sys.stderr + else: + return sys.stderr + class LocalRepo(object): def __init__(self, koji_tag): diff --git a/tests/test_builder/test_builder_utils.py b/tests/test_builder/test_builder_utils.py index 2af324d3..5ea337ea 100644 --- a/tests/test_builder/test_builder_utils.py +++ b/tests/test_builder/test_builder_utils.py @@ -17,6 +17,22 @@ from module_build_service.scheduler.db_session import db_session from tests import read_staged_data, scheduler_init_data +def test_execute_cmd(tmpdir, caplog): + logfile = str(tmpdir / "out.log") + with open(logfile, "w") as f: + utils.execute_cmd(["echo", "hello"], output=f) + + with open(logfile) as f: + assert f.read() == "hello\n" + + assert 'Executing the command "echo hello", output log: %s' % logfile in caplog.text + + +def test_execute_cmd_fail(): + with pytest.raises(RuntimeError): + utils.execute_cmd(["false"]) + + @pytest.mark.parametrize("variation", ("none", "empty", "already_downloaded")) @patch("requests.get") @patch("koji.ClientSession") diff --git a/tests/test_common/test_logger.py b/tests/test_common/test_logger.py index 0ce0b2ab..0a049aad 100644 --- a/tests/test_common/test_logger.py +++ b/tests/test_common/test_logger.py @@ -8,6 +8,7 @@ from os import path import re import pytest import shutil +import sys import tempfile import textwrap from unittest.mock import patch @@ -69,10 +70,11 @@ class TestLogger: log.info("ignore this test msg") log.warning("ignore this test msg") log.error("ignore this test msg") + assert self.build_log.current_log_stream is sys.stderr self.build_log.stop(build) assert not os.path.exists(path) - # Try logging with current_module_build_id set to 2 and then to 2. + # Try logging with current_module_build_id set to 1 and then to 2. # Only messages with current_module_build_id set to 2 should appear in # the log. self.build_log.start(db_session, build) @@ -81,12 +83,14 @@ class TestLogger: log.info("ignore this test msg1") log.warning("ignore this test msg1") log.error("ignore this test msg1") + assert self.build_log.current_log_stream is sys.stderr MBSConsumer.current_module_build_id = 2 log.debug("ignore this test msg2") log.info("ignore this test msg2") log.warning("ignore this test msg2") log.error("ignore this test msg2") + self.build_log.current_log_stream.write("ignore this test output2") self.build_log.stop(build) assert os.path.exists(path) @@ -95,6 +99,7 @@ class TestLogger: # Note that DEBUG is not present unless configured server-wide. for level in ["INFO", "WARNING", "ERROR"]: assert data.find("MBS - {0} - ignore this test msg2".format(level)) != -1 + assert data.find("ignore this test output2") # Try to log more messages when build_log for module 1 is stopped. # New messages should not appear in a log. @@ -103,6 +108,7 @@ class TestLogger: log.info("ignore this test msg3") log.warning("ignore this test msg3") log.error("ignore this test msg3") + assert self.build_log.current_log_stream is sys.stderr self.build_log.stop(build) with open(path, "r") as f: data = f.read()