From 95d9a433e39a2960e062b0358becf8011730e2ab Mon Sep 17 00:00:00 2001 From: pasinskim Date: Fri, 26 Jun 2026 09:26:47 +0200 Subject: [PATCH 1/3] test(deployments): derive reboot-crossing deployment timeout from client watchdog A deployment that crosses a reboot only reaches its terminal status after the client's automatic system-reboot watchdog: mender-update waits a hardcoded chrono::minutes(10) (update_module_call.cpp, AsyncSystemReboot) for the `reboot` to take effect before giving up and reporting a terminal status. When that watchdog is hit, the deployment reaches 'failure' at ~601s. check_expected_statistics defaulted to a 600s poll window -- an exact dead heat with that 600s watchdog -- so reboot-crossing failure cases flaked with "Never found ". Bumping to an independent literal (e.g. 900s) only relocates the race (901 vs 900). Introduce a single source of truth, CLIENT_AUTOMATIC_REBOOT_WATCHDOG, and a DERIVED deadline REBOOT_CROSSING_DEPLOYMENT_TIMEOUT (= watchdog * 2). Deriving it (multiplicatively) means a change to either value can never create a dead heat. Polling returns the instant the status is observed, so the larger deadline never slows a passing test; it only bounds a genuinely-stuck deployment. Also make the timeout self-diagnosing: dump the per-device deployment log and the observed status progression, and warn explicitly when max_wait <= the watchdog. The failure now shows the reboot / "Version file error" / watchdog gap directly, without pulling artifacts. Changelog: None Signed-off-by: pasinskim Co-Authored-By: Claude Opus 4.8 (1M context) --- tests/MenderAPI/deployments.py | 60 ++++++++++++++++++++++++++++++++-- 1 file changed, 58 insertions(+), 2 deletions(-) diff --git a/tests/MenderAPI/deployments.py b/tests/MenderAPI/deployments.py index f099bc8b1..e1c339bf4 100644 --- a/tests/MenderAPI/deployments.py +++ b/tests/MenderAPI/deployments.py @@ -24,6 +24,26 @@ from .requests_helpers import requests_retry +# The mender-update client's automatic system-reboot watchdog: if the `reboot` +# command does not kill the client, mender-update waits this long before giving +# up and reporting a terminal deployment status. Hardcoded in the client as +# chrono::minutes(10): +# mender/src/mender-update/update_module/v3/platform/c++17/update_module_call.cpp +# -> UpdateModule::AsyncSystemReboot +# A deployment that crosses a reboot can therefore take up to this long to reach +# a terminal status on the server. SINGLE SOURCE OF TRUTH -- if the client value +# changes, change it here and everything derived below follows. +CLIENT_AUTOMATIC_REBOOT_WATCHDOG = 10 * 60 + +# Give-up deadline for a deployment that crosses a reboot. DERIVED from the +# client watchdog with a *multiplicative* margin, deliberately NOT an independent +# literal: a +/-1s drift on either side can never create a dead heat (the +# 600-vs-601 / 900-vs-901 trap). Polling returns the instant the terminal status +# is observed, so a larger value never slows a passing test -- it only bounds a +# genuinely-stuck deployment. +REBOOT_CROSSING_DEPLOYMENT_TIMEOUT = CLIENT_AUTOMATIC_REBOOT_WATCHDOG * 2 + + class Deployments: # track the last statistic for a deployment id last_statistic = {} @@ -258,9 +278,45 @@ def check_expected_statistics( return time.sleep(polling_frequency) + # Self-diagnosing timeout. Dump the per-device deployment log so the real + # cause (a hung reboot, "Version file error", the state the client got + # stuck in) is visible directly in the test output -- no need to pull + # artifacts. Also flag the dead-heat case explicitly. + racing = max_wait <= CLIENT_AUTOMATIC_REBOOT_WATCHDOG + device_logs = "" + try: + for device in self.devauth.get_devices(): + try: + device_logs += "----- device %s -----\n%s\n\n" % ( + device["id"], + self.get_logs(device["id"], deployment_id), + ) + except Exception: + pass + except Exception: + pass pytest.fail( - "Never found: %s:%s, only seen: %s after %d seconds" - % (expected_status, expected_count, str(seen), max_wait) + "Never found %s:%s within %ds for deployment %s.\n" + "Statuses seen (in order of appearance): %s\n" + "%s" + "Device deployment log(s):\n%s" + % ( + expected_status, + expected_count, + max_wait, + deployment_id, + str(seen), + ( + "WARNING: max_wait (%ds) <= client automatic-reboot watchdog " + "(%ds). This poll is racing the watchdog, not testing the " + "client. Pass max_wait=REBOOT_CROSSING_DEPLOYMENT_TIMEOUT for " + "any deployment that crosses a reboot.\n" + % (max_wait, CLIENT_AUTOMATIC_REBOOT_WATCHDOG) + if racing + else "" + ), + device_logs or "(could not fetch device logs)", + ) ) def get_deployment_overview(self, deployment_id): From e6b5bd530494aa966e28f2c7493bc354de21a686 Mon Sep 17 00:00:00 2001 From: pasinskim Date: Fri, 26 Jun 2026 09:29:00 +0200 Subject: [PATCH 2/3] test(state_scripts): wait past the client reboot watchdog for reboot-crossing failures The reboot-crossing failure cases (Failure_in_ArtifactCommit_* and the Corrupted_script_version_* sets) drive the client through an automatic system reboot; the deployment only reaches 'failure' after the client's 10-minute reboot watchdog. The default 600s check_expected_statistics window was an exact dead heat with that watchdog, so these cases flaked intermittently with "Never found failure ... after 600 seconds". Use REBOOT_CROSSING_DEPLOYMENT_TIMEOUT (derived from the client watchdog) instead of the default. This supersedes the bare max_wait=15*60 approach: the value is a function of the watchdog, so it cannot drift back into a dead heat, and on timeout the failure now dumps the device deployment log (the reboot / "Version file error" / watchdog gap) directly. Changelog: None Signed-off-by: pasinskim Co-Authored-By: Claude Opus 4.8 (1M context) --- tests/tests/test_state_scripts.py | 11 ++++++++++- 1 file changed, 10 insertions(+), 1 deletion(-) diff --git a/tests/tests/test_state_scripts.py b/tests/tests/test_state_scripts.py index ebcfd0121..784d57888 100644 --- a/tests/tests/test_state_scripts.py +++ b/tests/tests/test_state_scripts.py @@ -28,6 +28,7 @@ from .common_update import common_update_procedure from ..helpers import Helpers from ..MenderAPI import DeviceAuthV2, Deployments, logger, image +from ..MenderAPI.deployments import REBOOT_CROSSING_DEPLOYMENT_TIMEOUT from .mendertesting import MenderTesting from testutils.infra.device import MenderDeviceGroup @@ -838,8 +839,16 @@ def fetch_info(cmd_list): 'Waited too long for "Error" to appear in log:\n%s' % info ) else: + # Reboot-crossing failure cases (ArtifactReboot / ArtifactCommit + # failures and the Corrupted_script_version sets) only reach + # 'failure' after the client's automatic-reboot watchdog. Use the + # derived deadline so we never race it -- it is a function of the + # client watchdog, not an independent magic number. deploy.check_expected_statistics( - deployment_id, test_set["ExpectedStatus"], 1 + deployment_id, + test_set["ExpectedStatus"], + 1, + max_wait=REBOOT_CROSSING_DEPLOYMENT_TIMEOUT, ) # Always give the client a little bit of time to settle in the base From 30a455bfb30fe8db7f9776df4d81a04cee306e16 Mon Sep 17 00:00:00 2001 From: pasinskim Date: Fri, 26 Jun 2026 09:31:06 +0200 Subject: [PATCH 3/3] test(fault_tolerance): wait past the client reboot watchdog for reboot waits verify_reboot_performed() and the post-reboot check_expected_statistics() calls defaulted to a 600s window -- an exact dead heat with the client's 600s automatic-reboot watchdog. When a reboot is slow to take effect the device recovers at ~601s, one second after the wait gives up, producing flaky "Device never rebooted" / "Never found " failures. Use REBOOT_CROSSING_DEPLOYMENT_TIMEOUT (derived from the client watchdog) for the reboot-crossing waits. verify_reboot_not_performed() (the intentional short "confirm no reboot" checks) are left untouched. Changelog: None Signed-off-by: pasinskim Co-Authored-By: Claude Opus 4.8 (1M context) --- tests/tests/test_fault_tolerance.py | 19 ++++++++++++------- 1 file changed, 12 insertions(+), 7 deletions(-) diff --git a/tests/tests/test_fault_tolerance.py b/tests/tests/test_fault_tolerance.py index 0b5c1034e..62e79ae91 100644 --- a/tests/tests/test_fault_tolerance.py +++ b/tests/tests/test_fault_tolerance.py @@ -25,6 +25,7 @@ ) from .common_update import common_update_procedure, update_image_failed from ..MenderAPI import DeviceAuthV2, Deployments, logger +from ..MenderAPI.deployments import REBOOT_CROSSING_DEPLOYMENT_TIMEOUT from .mendertesting import MenderTesting @@ -156,8 +157,10 @@ def do_test_update_image_breaks_networking( deployment_id, _ = common_update_procedure( broken_network_image, devauth=devauth, deploy=deploy ) - reboot.verify_reboot_performed() # since the network is broken, two reboots will be performed, and the last one will be detected - deploy.check_expected_statistics(deployment_id, "failure", 1) + reboot.verify_reboot_performed(max_wait=REBOOT_CROSSING_DEPLOYMENT_TIMEOUT) # since the network is broken, two reboots will be performed, and the last one will be detected + deploy.check_expected_statistics( + deployment_id, "failure", 1, max_wait=REBOOT_CROSSING_DEPLOYMENT_TIMEOUT + ) def do_test_deployed_during_network_outage( self, @@ -194,8 +197,10 @@ def do_test_deployed_during_network_outage( self.manipulate_network_connectivity(mender_device, True) logger.info("Network stabilized") - reboot.verify_reboot_performed() - deploy.check_expected_statistics(deployment_id, "success", 1) + reboot.verify_reboot_performed(max_wait=REBOOT_CROSSING_DEPLOYMENT_TIMEOUT) + deploy.check_expected_statistics( + deployment_id, "success", 1, max_wait=REBOOT_CROSSING_DEPLOYMENT_TIMEOUT + ) assert mender_device.yocto_id_installed_on_machine() == expected_yocto_id @@ -270,7 +275,7 @@ def do_test_image_download_retry_timeout( mender_device, True, hosts=[blocked_service] ) - reboot.verify_reboot_performed() + reboot.verify_reboot_performed(max_wait=REBOOT_CROSSING_DEPLOYMENT_TIMEOUT) deploy.check_expected_status("finished", deployment_id) assert mender_device.get_active_partition() == inactive_part @@ -388,7 +393,7 @@ def do_test_image_download_retry_download_count( ) if success: - reboot.verify_reboot_performed() + reboot.verify_reboot_performed(max_wait=REBOOT_CROSSING_DEPLOYMENT_TIMEOUT) deploy.check_expected_status("finished", deployment_id) assert mender_device.get_active_partition() == inactive_part @@ -435,7 +440,7 @@ def do_test_image_download_retry_hosts_broken( ) mender_device.run("sed -i.bak '/1.1.1.1/d' /etc/hosts") - reboot.verify_reboot_performed() + reboot.verify_reboot_performed(max_wait=REBOOT_CROSSING_DEPLOYMENT_TIMEOUT) deploy.check_expected_status("finished", deployment_id) assert mender_device.get_active_partition() == inactive_part