diff --git a/packit_service/worker/helpers/logdetective.py b/packit_service/worker/helpers/logdetective.py index 00a0ffbfb..282643c5b 100644 --- a/packit_service/worker/helpers/logdetective.py +++ b/packit_service/worker/helpers/logdetective.py @@ -13,24 +13,19 @@ from packit_service.events import koji from packit_service.events.event_data import EventData from packit_service.models import ( + GitBranchModel, LogDetectiveBuildSystem, LogDetectiveResult, LogDetectiveRunGroupModel, LogDetectiveRunModel, + ProjectReleaseModel, + PullRequestModel, ) from packit_service.utils import verify_artifact from packit_service.worker.monitoring import Pushgateway logger = logging.getLogger(__name__) -LD_COMMENTARY = ( - "Build was executed in downstream Koji using containerized environment provided by Mock." - "The build.log contains output of the package build, it is the most likely to contain messages," - " indicating the root cause." - "The mock_output.log is a general log from Mock." - "The root.log is a log from creation of the chroot environment." -) - class LogDetectiveKojiTriggerHelper: """ @@ -65,6 +60,55 @@ def __init__( # run_group created after 1st succcessful trigger, right before creating RunModel self.run_group: Optional[LogDetectiveRunGroupModel] = None + def _format_duration(self) -> str: + """Return a human-readable build duration, or empty string if unavailable.""" + try: + start = float(self.koji_event.start_time) + end = float(self.koji_event.completion_time) + except (TypeError, ValueError): + return "" + seconds = end - start + if seconds < 0: + return "" + return f"Build ran for {seconds:.0f} seconds before failing." + + def _build_commentary(self, arch: str) -> str: + """Build a dynamic commentary string with per-build context for Log Detective.""" + build = self.koji_event.build_model + parts = [ + "Build was executed in downstream Koji" + " using containerized environment provided by Mock.", + f"Package NVR: {build.nvr or 'unknown'}," + f" target: {self.koji_event.target or 'unknown'}, arch: {arch}.", + "Scratch build." if build.scratch else "Official (non-scratch) build.", + ] + db_project_object = self.koji_event.db_project_object + if isinstance(db_project_object, PullRequestModel): + parts.append(f"PR build (PR #{db_project_object.pr_id}).") + elif isinstance(db_project_object, GitBranchModel): + parts.append(f"Branch build ({db_project_object.name}).") + elif isinstance(db_project_object, ProjectReleaseModel): + parts.append(f"Release build (tag: {db_project_object.tag_name}).") + duration = self._format_duration() + if duration: + parts.append(duration) + if build.sidetag: + parts.append( + f"Built in sidetag: {build.sidetag}." + " Sidetag builds use an isolated buildroot inheriting from the base tag;" + " dependency resolution failures may reflect non-default package versions" + " present in the sidetag." + ) + parts += [ + "The build.log contains output of the package build" + " and is the most likely source of the root cause.", + "The mock_output.log is a general log from Mock.", + "The root.log is a log from creation of the chroot environment.", + ] + if build.build_submission_stdout: + parts.append(f"Build submission output: {build.build_submission_stdout}") + return " ".join(parts) + def trigger_log_detective_analysis(self) -> list[bool]: """ Run a trigger over all arches for which we have a failed buildArch task. @@ -121,7 +165,7 @@ def trigger_log_detective_analysis_for_arch(self, arch: str) -> bool: endpoint_url = f"{self.url}/analyze" request_json = { "artifacts": artifacts, - "build_metadata": {"commentary": LD_COMMENTARY}, + "build_metadata": {"commentary": self._build_commentary(arch)}, "target_build": str(build_arch_task_id), "build_system": LogDetectiveBuildSystem.koji.value, "commit_sha": self.data.commit_sha, diff --git a/tests/integration/test_logdetective_koji.py b/tests/integration/test_logdetective_koji.py index c6cc6b8d2..721ed64dc 100644 --- a/tests/integration/test_logdetective_koji.py +++ b/tests/integration/test_logdetective_koji.py @@ -73,6 +73,10 @@ def test_logdetective_koji_build_scratch_downstream( flexmock(ServiceConfig).should_receive("get_service_config").and_return(service_config) koji_build_pr_downstream.target = "rawhide" + koji_build_pr_downstream.nvr = "packit-0.123.0-1.fc00" + koji_build_pr_downstream.scratch = True + koji_build_pr_downstream.sidetag = None + koji_build_pr_downstream.build_submission_stdout = "MOCK STDOUT" flexmock(koji.result.Task).should_receive("get_packages_config").and_return(None) flexmock(KojiBuildTargetModel).should_receive("get_by_task_id").and_return( koji_build_pr_downstream diff --git a/tests/unit/test_logdetective_koji_helper.py b/tests/unit/test_logdetective_koji_helper.py index ae5dec37c..69dcca197 100644 --- a/tests/unit/test_logdetective_koji_helper.py +++ b/tests/unit/test_logdetective_koji_helper.py @@ -5,6 +5,8 @@ Unit tests for LogDetectiveKojiTriggerHelper class. """ +from unittest.mock import MagicMock + import pytest import requests from flexmock import flexmock @@ -12,13 +14,15 @@ import packit_service.worker.helpers.logdetective as logdetective_module from packit_service.constants import LOGDETECTIVE_PACKIT_SERVER_URL, KojiTaskState from packit_service.models import ( + GitBranchModel, LogDetectiveBuildSystem, LogDetectiveResult, LogDetectiveRunGroupModel, LogDetectiveRunModel, + ProjectReleaseModel, + PullRequestModel, ) from packit_service.worker.helpers.logdetective import ( - LD_COMMENTARY, LogDetectiveKojiTriggerHelper, logger, ) @@ -54,7 +58,13 @@ def mock_event_data(): @pytest.fixture def mock_koji_task_failed_event(): mock_group = flexmock(runs=[flexmock()]) - mock_build_model = flexmock(group_of_targets=mock_group) + mock_build_model = flexmock( + group_of_targets=mock_group, + nvr="test-package-1.0-1.fc44", + scratch=False, + sidetag=None, + build_submission_stdout=None, + ) return flexmock( task_id=12340, @@ -64,6 +74,9 @@ def mock_koji_task_failed_event(): build_model=mock_build_model, rpm_build_task_ids={"x86_64": 12345}, rpm_build_failed_arch_list=["x86_64"], + db_project_object=None, + start_time=1000, + completion_time=1045, ) @@ -84,11 +97,23 @@ def test_logdetective_koji_set_payload(mock_koji_task_failed_event, mock_event_d request_json = { "artifacts": { "root.log": "https://kojipkgs.fedoraproject.org//work/tasks/2345/12345/root.log", - "mock_output.log": "https://kojipkgs.fedoraproject.org//work/tasks/2345/12345/mock_output.log", + "mock_output.log": ( + "https://kojipkgs.fedoraproject.org//work/tasks/2345/12345/mock_output.log" + ), "build.log": "https://kojipkgs.fedoraproject.org//work/tasks/2345/12345/build.log", }, "build_metadata": { - "commentary": LD_COMMENTARY, + "commentary": ( + "Build was executed in downstream Koji" + " using containerized environment provided by Mock." + " Package NVR: test-package-1.0-1.fc44, target: rawhide, arch: x86_64." + " Official (non-scratch) build." + " Build ran for 45 seconds before failing." + " The build.log contains output of the package build" + " and is the most likely source of the root cause." + " The mock_output.log is a general log from Mock." + " The root.log is a log from creation of the chroot environment." + ), }, "target_build": "12345", "build_system": "koji", @@ -130,12 +155,26 @@ def test_logdetective_koji_success( f"{LOGDETECTIVE_PACKIT_SERVER_URL}/analyze", json={ "artifacts": { - "root.log": "https://kojipkgs.fedoraproject.org//work/tasks/2345/12345/root.log", - "mock_output.log": "https://kojipkgs.fedoraproject.org//work/tasks/2345/12345/mock_output.log", - "build.log": "https://kojipkgs.fedoraproject.org//work/tasks/2345/12345/build.log", + "root.log": ("https://kojipkgs.fedoraproject.org//work/tasks/2345/12345/root.log"), + "mock_output.log": ( + "https://kojipkgs.fedoraproject.org//work/tasks/2345/12345/mock_output.log" + ), + "build.log": ( + "https://kojipkgs.fedoraproject.org//work/tasks/2345/12345/build.log" + ), }, "build_metadata": { - "commentary": LD_COMMENTARY, + "commentary": ( + "Build was executed in downstream Koji" + " using containerized environment provided by Mock." + " Package NVR: test-package-1.0-1.fc44, target: rawhide, arch: x86_64." + " Official (non-scratch) build." + " Build ran for 45 seconds before failing." + " The build.log contains output of the package build" + " and is the most likely source of the root cause." + " The mock_output.log is a general log from Mock." + " The root.log is a log from creation of the chroot environment." + ), }, "target_build": "12345", "build_system": LogDetectiveBuildSystem.koji.value, @@ -343,3 +382,224 @@ def test_logdetective_koji_missing_time( trigger_success = helper.trigger_log_detective_analysis() assert not all(trigger_success) + + +def _make_helper(koji_event, event_data=None): + """Return a LogDetectiveKojiTriggerHelper with stub credentials.""" + if event_data is None: + event_data = flexmock(commit_sha="abc", project_url="https://example.com", pr_id=None) + return LogDetectiveKojiTriggerHelper( + koji_event, + event_data, + flexmock(), + "https://kojipkgs.fedoraproject.org", + LOGDETECTIVE_PACKIT_SERVER_URL, + "token", + ) + + +def _make_build_model(*, nvr="pkg-1.0-1.fc44", scratch=False, sidetag=None, stdout=None): + return flexmock( + nvr=nvr, + scratch=scratch, + sidetag=sidetag, + build_submission_stdout=stdout, + ) + + +def _make_event( + build_model, *, target="rawhide", db_project_object=None, start_time=1000, completion_time=1045 +): + return flexmock( + build_model=build_model, + target=target, + db_project_object=db_project_object, + start_time=start_time, + completion_time=completion_time, + ) + + +def test_format_duration_valid(): + event = _make_event(_make_build_model(), start_time=1000, completion_time=1060) + helper = _make_helper(event) + assert helper._format_duration() == "Build ran for 60 seconds before failing." + + +def test_format_duration_zero_seconds(): + event = _make_event(_make_build_model(), start_time=1000, completion_time=1000) + helper = _make_helper(event) + assert helper._format_duration() == "Build ran for 0 seconds before failing." + + +def test_format_duration_start_time_none(): + event = _make_event(_make_build_model(), start_time=None, completion_time=1045) + helper = _make_helper(event) + assert helper._format_duration() == "" + + +def test_format_duration_completion_time_none(): + event = _make_event(_make_build_model(), start_time=1000, completion_time=None) + helper = _make_helper(event) + assert helper._format_duration() == "" + + +def test_format_duration_non_numeric_start(): + event = _make_event(_make_build_model(), start_time="not-a-number", completion_time=1045) + helper = _make_helper(event) + assert helper._format_duration() == "" + + +def test_format_duration_non_numeric_completion(): + event = _make_event(_make_build_model(), start_time=1000, completion_time="bad") + helper = _make_helper(event) + assert helper._format_duration() == "" + + +def test_format_duration_negative(): + # end before start — physically impossible but must be handled gracefully + event = _make_event(_make_build_model(), start_time=2000, completion_time=1000) + helper = _make_helper(event) + assert helper._format_duration() == "" + + +def test_build_commentary_baseline(mock_koji_task_failed_event): + """Non-scratch, no project object, known NVR, valid duration, no sidetag, no stdout.""" + helper = _make_helper(mock_koji_task_failed_event) + result = helper._build_commentary("x86_64") + assert "Build was executed in downstream Koji" in result + assert "Package NVR: test-package-1.0-1.fc44, target: rawhide, arch: x86_64." in result + assert "Official (non-scratch) build." in result + assert "Build ran for 45 seconds before failing." in result + assert result.endswith("The root.log is a log from creation of the chroot environment.") + + +def test_build_commentary_scratch_build(): + build = _make_build_model(scratch=True) + event = _make_event(build) + helper = _make_helper(event) + result = helper._build_commentary("x86_64") + assert "Scratch build." in result + assert "Official (non-scratch) build." not in result + + +def test_build_commentary_unknown_nvr(): + build = _make_build_model(nvr=None) + event = _make_event(build) + helper = _make_helper(event) + result = helper._build_commentary("x86_64") + assert "Package NVR: unknown" in result + + +def test_build_commentary_unknown_target(): + build = _make_build_model() + event = _make_event(build, target=None) + helper = _make_helper(event) + result = helper._build_commentary("x86_64") + assert "target: unknown" in result + + +def test_build_commentary_pr_build(): + build = _make_build_model() + pr_model = MagicMock(spec=PullRequestModel) + pr_model.pr_id = 99 + event = _make_event(build, db_project_object=pr_model) + helper = _make_helper(event) + result = helper._build_commentary("x86_64") + assert "PR build (PR #99)." in result + assert "Branch build" not in result + assert "Release build" not in result + + +def test_build_commentary_branch_build(): + build = _make_build_model() + branch_model = MagicMock(spec=GitBranchModel) + branch_model.name = "main" + event = _make_event(build, db_project_object=branch_model) + helper = _make_helper(event) + result = helper._build_commentary("aarch64") + assert "Branch build (main)." in result + assert "PR build" not in result + assert "Release build" not in result + + +def test_build_commentary_release_build(): + build = _make_build_model() + release_model = MagicMock(spec=ProjectReleaseModel) + release_model.tag_name = "v1.2.3" + event = _make_event(build, db_project_object=release_model) + helper = _make_helper(event) + result = helper._build_commentary("s390x") + assert "Release build (tag: v1.2.3)." in result + assert "PR build" not in result + assert "Branch build" not in result + + +def test_build_commentary_no_project_object(): + build = _make_build_model() + event = _make_event(build, db_project_object=None) + helper = _make_helper(event) + result = helper._build_commentary("x86_64") + assert "PR build" not in result + assert "Branch build" not in result + assert "Release build" not in result + + +def test_build_commentary_no_duration(): + build = _make_build_model() + event = _make_event(build, start_time=None, completion_time=None) + helper = _make_helper(event) + result = helper._build_commentary("x86_64") + assert "seconds before failing" not in result + + +def test_build_commentary_with_sidetag(): + build = _make_build_model(sidetag="f44-build-side-12345") + event = _make_event(build) + helper = _make_helper(event) + result = helper._build_commentary("x86_64") + assert "Built in sidetag: f44-build-side-12345." in result + assert "Sidetag builds use an isolated buildroot" in result + + +def test_build_commentary_without_sidetag(): + build = _make_build_model(sidetag=None) + event = _make_event(build) + helper = _make_helper(event) + result = helper._build_commentary("x86_64") + assert "Built in sidetag" not in result + + +def test_build_commentary_with_build_submission_stdout(): + build = _make_build_model(stdout="Task submitted: 12345") + event = _make_event(build) + helper = _make_helper(event) + result = helper._build_commentary("x86_64") + assert "Build submission output: Task submitted: 12345" in result + + +def test_build_commentary_without_build_submission_stdout(): + build = _make_build_model(stdout=None) + event = _make_event(build) + helper = _make_helper(event) + result = helper._build_commentary("x86_64") + assert "Build submission output" not in result + + +def test_build_commentary_all_optional_fields(): + """All optional fields present simultaneously.""" + build = _make_build_model( + scratch=True, + sidetag="f44-side-99", + stdout="Submitted OK", + ) + pr_model = MagicMock(spec=PullRequestModel) + pr_model.pr_id = 7 + event = _make_event(build, db_project_object=pr_model, start_time=500, completion_time=800) + helper = _make_helper(event) + result = helper._build_commentary("ppc64le") + + assert "Scratch build." in result + assert "PR build (PR #7)." in result + assert "Build ran for 300 seconds before failing." in result + assert "Built in sidetag: f44-side-99." in result + assert "Build submission output: Submitted OK" in result