From 58050af7e8de0a24e1ca48c11a642cd93a87406d Mon Sep 17 00:00:00 2001 From: Hook25 Date: Thu, 14 Dec 2023 13:30:00 +0100 Subject: [PATCH 1/4] Fix pending binary builds --- tools/release/lp_build_monitor_recipe.py | 33 +++++++++++++++---- tools/release/test_lp_build_monitor_recipe.py | 11 +++++-- 2 files changed, 35 insertions(+), 9 deletions(-) diff --git a/tools/release/lp_build_monitor_recipe.py b/tools/release/lp_build_monitor_recipe.py index 3f7822195f..6dc723b41d 100755 --- a/tools/release/lp_build_monitor_recipe.py +++ b/tools/release/lp_build_monitor_recipe.py @@ -91,9 +91,14 @@ def get_all_binary_builds( builds = build_recipe.daily_build_archive.getBuildRecords( source_name=recipe_target ) + + # date_first_dispatched is filled in once a build is dispatched + # and is the actual start time, it can be None if the build is + # still waiting to get picked up by a builder return list( itertools.takewhile( - lambda build: build.date_first_dispatched > started_datetime, + lambda build: build.date_first_dispatched is None + or build.date_first_dispatched >= started_datetime, builds, ) ) @@ -111,7 +116,7 @@ def get_all_source_builds( # need return list( itertools.takewhile( - lambda build: build.date_first_dispatched > started_datetime, + lambda build: build.date_first_dispatched >= started_datetime, build_recipe.builds, ) ) @@ -140,9 +145,10 @@ def monitor_retry_binary_builds( iteration_start_time = get_date_utc_now() # this filters the binary builds from start_checking_binary (the - # beginning of the previous iteration). This is done because if a build - # was included in the previous get_all_binary_builds it has been - # taken to completion by monitor_retry_builds either failing it + # beginning of the previous iteration or the latest pending build). + # This is done because if a build was included in the previous + # get_all_binary_builds it has been taken to completion + # by monitor_retry_builds either failing it # completely or making it pass. What matters is that we don't # under-monitor, as re-getting the same build will deterministically # yield the same result resulting in the wcs. in a duplicated @@ -197,14 +203,27 @@ def monitor_retry_builds(builds_to_check: list[LPBuild]) -> list[LPBuild]: "Gathering build output", ]: # avoid flooding LP with requests + print(f"Build ongoing with status '{buildstate}'") + print(f" weblink: {build.web_link}") time.sleep(LP_POLLING_DELAY) builds_to_check.insert(0, build) - print(f"Build ongoing with status '{buildstate}'") + elif buildstate not in [ + "Failed to build", + "Dependency wait", + "Chroot problem", + "Failed to upload", + "Build for superseded Source", + "Cancelling build", + "Cancelled build", + ]: + print(f"Unknown build status '{buildstate}'") print(f" weblink: {build.web_link}") - elif build.can_be_retried: time.sleep(LP_POLLING_DELAY) + builds_to_check.insert(0, build) + elif build.can_be_retried: print(f"Build failed with status '{buildstate}'") print(f" retrying: {build.web_link}") + time.sleep(LP_POLLING_DELAY) build.retry() builds_to_check.insert(0, build) else: diff --git a/tools/release/test_lp_build_monitor_recipe.py b/tools/release/test_lp_build_monitor_recipe.py index 6e52e79ddd..8d6815ee17 100644 --- a/tools/release/test_lp_build_monitor_recipe.py +++ b/tools/release/test_lp_build_monitor_recipe.py @@ -1,6 +1,6 @@ import unittest -from unittest.mock import MagicMock, patch, call +from unittest.mock import MagicMock, patch import lp_build_monitor_recipe @@ -14,18 +14,25 @@ def test_get_all_binary_builds(self): build_selected = MagicMock() build_selected.date_first_dispatched = 10 + build_selected_pending = MagicMock() + # pending builds have a None date_first_dispatched + # we select them because they are "newer" of the start date + # for sure given that they didn't even start yet + build_selected_pending.date_first_dispatched = None + build_not_selected = MagicMock() build_not_selected.date_first_dispatched = 0 build_recipe.daily_build_archive.getBuildRecords.return_value = [ build_selected, + build_selected_pending, build_not_selected, ] selected = lp_build_monitor_recipe.get_all_binary_builds( build_recipe, 6 ) - self.assertEqual(selected, [build_selected]) + self.assertEqual(selected, [build_selected, build_selected_pending]) build_recipe.daily_build_archive.getBuildRecords.assert_called_with( source_name="checkbox-ng" ) From 118ff2e178e2d54afefb0299da0a4279fb7d5b5f Mon Sep 17 00:00:00 2001 From: Hook25 Date: Thu, 14 Dec 2023 13:39:40 +0100 Subject: [PATCH 2/4] Rolled back comment update --- tools/release/lp_build_monitor_recipe.py | 7 +++---- 1 file changed, 3 insertions(+), 4 deletions(-) diff --git a/tools/release/lp_build_monitor_recipe.py b/tools/release/lp_build_monitor_recipe.py index 6dc723b41d..3a538f0f7d 100755 --- a/tools/release/lp_build_monitor_recipe.py +++ b/tools/release/lp_build_monitor_recipe.py @@ -145,10 +145,9 @@ def monitor_retry_binary_builds( iteration_start_time = get_date_utc_now() # this filters the binary builds from start_checking_binary (the - # beginning of the previous iteration or the latest pending build). - # This is done because if a build was included in the previous - # get_all_binary_builds it has been taken to completion - # by monitor_retry_builds either failing it + # beginning of the previous iteration). This is done because if a build + # was included in the previous get_all_binary_builds it has been + # taken to completion by monitor_retry_builds either failing it # completely or making it pass. What matters is that we don't # under-monitor, as re-getting the same build will deterministically # yield the same result resulting in the wcs. in a duplicated From d048a42ec711ed53aee308247d5deb7f3721d84b Mon Sep 17 00:00:00 2001 From: Hook25 Date: Thu, 14 Dec 2023 14:15:34 +0100 Subject: [PATCH 3/4] New test for unknown buildstatus --- tools/release/test_lp_build_monitor_recipe.py | 23 +++++++++++++++++++ 1 file changed, 23 insertions(+) diff --git a/tools/release/test_lp_build_monitor_recipe.py b/tools/release/test_lp_build_monitor_recipe.py index 8d6815ee17..7ab0c6a036 100644 --- a/tools/release/test_lp_build_monitor_recipe.py +++ b/tools/release/test_lp_build_monitor_recipe.py @@ -144,6 +144,29 @@ def lp_refresh_side_effect(): # each time a failure was detected, the build was retried self.assertEqual(build_mock.retry.call_count, 3) + @patch("time.sleep") + def test_monitor_retry_builds_robust(self, time_sleep_mock): + build_mock = MagicMock() + # A build is updated via the lp_refresh function, lets do the same + # here but inject our test values + build_status_evolution = [ + "Successfully built", + None # this may be possible for pending builds + ] + + def lp_refresh_side_effect(): + if build_status_evolution: + build_mock.buildstate = build_status_evolution.pop() + + build_mock.lp_refresh.side_effect = lp_refresh_side_effect + + lp_build_monitor_recipe.monitor_retry_builds([build_mock]) + + # we updated till the build reported a success + self.assertEqual(build_mock.lp_refresh.call_count, 2) + # we didnt fload LP with requests, waiting once per progress + self.assertEqual(time_sleep_mock.call_count, 1) + @patch("time.sleep") def test_monitor_retry_builds_more_wait(self, time_sleep_mock): build_mock = MagicMock() From 9b1ae5c667f11057c91c1afff32534eafcae0baf Mon Sep 17 00:00:00 2001 From: Hook25 Date: Thu, 14 Dec 2023 14:55:53 +0100 Subject: [PATCH 4/4] Motivate time sleep everywhere --- tools/release/lp_build_monitor_recipe.py | 5 ++++- 1 file changed, 4 insertions(+), 1 deletion(-) diff --git a/tools/release/lp_build_monitor_recipe.py b/tools/release/lp_build_monitor_recipe.py index 3a538f0f7d..f9625f2215 100755 --- a/tools/release/lp_build_monitor_recipe.py +++ b/tools/release/lp_build_monitor_recipe.py @@ -68,6 +68,7 @@ def wait_every_source_build_started(build_recipe: LPSourcePackageRecipe): " ", ) ) + # avoid flooding LP with requests time.sleep(LP_POLLING_DELAY) pending_builds = build_recipe.getPendingBuildInfo() @@ -201,9 +202,9 @@ def monitor_retry_builds(builds_to_check: list[LPBuild]) -> list[LPBuild]: "Uploading build", "Gathering build output", ]: - # avoid flooding LP with requests print(f"Build ongoing with status '{buildstate}'") print(f" weblink: {build.web_link}") + # avoid flooding LP with requests time.sleep(LP_POLLING_DELAY) builds_to_check.insert(0, build) elif buildstate not in [ @@ -217,11 +218,13 @@ def monitor_retry_builds(builds_to_check: list[LPBuild]) -> list[LPBuild]: ]: print(f"Unknown build status '{buildstate}'") print(f" weblink: {build.web_link}") + # avoid flooding LP with requests time.sleep(LP_POLLING_DELAY) builds_to_check.insert(0, build) elif build.can_be_retried: print(f"Build failed with status '{buildstate}'") print(f" retrying: {build.web_link}") + # avoid flooding LP with requests time.sleep(LP_POLLING_DELAY) build.retry() builds_to_check.insert(0, build)