From afbf8f9b9a04068e5f872423c34df47d8680f54b Mon Sep 17 00:00:00 2001 From: mikecarper Date: Fri, 16 Oct 2026 00:20:23 -0700 Subject: [PATCH] Keep seeder log inspection working after flush errors --- tools/lora_ota/lora_ota.py | 18 ++++++---- tools/lora_ota/test_lora_ota.py | 33 +++++++++++++++++-- .../lora_ota/test_lora_ota_seeder_startup.py | 33 +++++++++++++++++++ 3 files changed, 76 insertions(+), 8 deletions(-) diff --git a/tools/lora_ota/lora_ota.py b/tools/lora_ota/lora_ota.py index f42ca0d12..83b42edbe 100755 --- a/tools/lora_ota/lora_ota.py +++ b/tools/lora_ota/lora_ota.py @@ -3868,11 +3868,19 @@ class SeederProcess: self._wait_until_attached() print("[seeder] running (device COUNT confirmed)") - def _log_tail(self) -> str: + def _read_log(self) -> str: if self.log_file is not None and not self.log_file.closed: - self.log_file.flush() + try: + self.log_file.flush() + except OSError: + # The subprocess writes directly to this descriptor. A parent + # flush failure must not hide bytes already readable on disk. + pass + return self.log_path.read_text(encoding="utf-8", errors="replace") + + def _log_tail(self) -> str: try: - detail = self.log_path.read_text(encoding="utf-8", errors="replace") + detail = self._read_log() except OSError as exc: return f"could not read seeder log: {exc}" return detail[-4096:].strip() or "no seeder log output" @@ -3973,10 +3981,8 @@ class SeederProcess: ``ota status``, reading it consumes no LoRa airtime and cannot collide with the transfer it is observing. """ - if self.log_file is not None and not self.log_file.closed: - self.log_file.flush() try: - detail = self.log_path.read_text(encoding="utf-8", errors="replace") + detail = self._read_log() except OSError: return 0, math.ceil(package.payload_size / package.block_size), 0 offsets = [ diff --git a/tools/lora_ota/test_lora_ota.py b/tools/lora_ota/test_lora_ota.py index 845eed931..1f4efb467 100644 --- a/tools/lora_ota/test_lora_ota.py +++ b/tools/lora_ota/test_lora_ota.py @@ -2553,8 +2553,13 @@ class DownloadSessionTests(unittest.TestCase): seeder.log_file = None seeder.process = mock.Mock() seeder.process.poll.return_value = None - for unreadable in (False, True): - with self.subTest(unreadable=unreadable), contextlib.ExitStack() as stack: + for unreadable, flush_failed in ((False, False), (True, False), + (False, True), (True, True)): + with self.subTest(unreadable=unreadable, flush_failed=flush_failed), \ + contextlib.ExitStack() as stack: + seeder.log_file = mock.Mock(closed=False) if flush_failed else None + if flush_failed: + seeder.log_file.flush.side_effect = OSError("log flush failed") if unreadable: stack.enter_context(mock.patch.object( Path, "read_text", side_effect=PermissionError("unreadable log"))) @@ -5365,6 +5370,30 @@ class ReliabilityTests(unittest.TestCase): with mock.patch.object(Path, "read_text", side_effect=PermissionError("unreadable log")): self.assertEqual(seeder.payload_read_progress(package), (0, 3, 0)) + def test_seeder_progress_flush_failure_preserves_readable_progress(self) -> None: + package = ota.parse_mota(mota_blob(firmware(b"B" * 2500, VERSION_NEW))) + seeder = object.__new__(ota.SeederProcess) + seeder.log_path = Path("serve.log") + seeder.log_file = mock.Mock(closed=False) + seeder.log_file.flush.side_effect = OSError("log flush failed") + detail = (f"[dev] READ 0 @{package.payload_offset} OK\n" + f"[dev] READ 0 @{package.payload_offset + 2 * package.block_size} OK\n" + f"[dev] READ 0 @{package.payload_offset} OK\n") + with mock.patch.object(Path, "read_text", return_value=detail): + self.assertEqual(seeder.payload_read_progress(package), (2, 3, 3)) + + def test_seeder_progress_flush_and_read_failures_keep_zero_activity(self) -> None: + package = ota.parse_mota(mota_blob(firmware(b"B" * 2500, VERSION_NEW))) + seeder = object.__new__(ota.SeederProcess) + seeder.log_path = Path("serve.log") + seeder.log_file = mock.Mock(closed=False) + seeder.log_file.flush.side_effect = OSError("log flush failed") + for error in (FileNotFoundError("missing log"), PermissionError("unreadable log")): + with self.subTest(error=error), mock.patch.object( + Path, "read_text", side_effect=error) as read: + self.assertEqual(seeder.payload_read_progress(package), (0, 3, 0)) + read.assert_called_once() + def test_marked_output_excludes_queued_messages(self) -> None: controller = object.__new__(ota.Controller) controller._execute = lambda _commands, _label: subprocess.CompletedProcess( diff --git a/tools/lora_ota/test_lora_ota_seeder_startup.py b/tools/lora_ota/test_lora_ota_seeder_startup.py index 4033b5043..1fce6b1a5 100644 --- a/tools/lora_ota/test_lora_ota_seeder_startup.py +++ b/tools/lora_ota/test_lora_ota_seeder_startup.py @@ -209,6 +209,39 @@ class SeederStartupTests(unittest.TestCase): seeder._wait_until_attached() self.assertEqual(self.clock.now, 10) + def test_flush_failure_does_not_hide_a_real_count(self): + seeder = ota.SeederProcess(self.args, Path("/served"), Path("/work")) + seeder.process = mock.Mock() + seeder.process.poll.return_value = None + seeder.log_file = mock.Mock(closed=False) + seeder.log_file.flush.side_effect = OSError("log flush failed") + with mock.patch.object(Path, "read_text", return_value="[dev] COUNT -> 1\n"): + seeder._wait_until_attached() + self.assertEqual(self.clock.now, 0) + + def test_flush_and_read_failures_cannot_prove_readiness_or_skip_deadline(self): + seeder = ota.SeederProcess(self.args, Path("/served"), Path("/work")) + seeder.process = mock.Mock() + seeder.process.poll.return_value = None + seeder.log_file = mock.Mock(closed=False) + seeder.log_file.flush.side_effect = OSError("log flush failed") + with mock.patch.object(Path, "read_text", side_effect=PermissionError("unreadable log")): + with self.assertRaisesRegex(ota.OtaError, "COUNT acknowledgement within 5s") as failure: + seeder._wait_until_attached() + self.assertIn("could not read seeder log", str(failure.exception)) + self.assertEqual(self.clock.now, 5) + + def test_flush_failure_preserves_process_exit_diagnostics(self): + seeder = ota.SeederProcess(self.args, Path("/served"), Path("/work")) + seeder.process = mock.Mock() + seeder.process.poll.return_value = 17 + seeder.log_file = mock.Mock(closed=False) + seeder.log_file.flush.side_effect = OSError("log flush failed") + with mock.patch.object(Path, "read_text", return_value="child diagnostic\n"): + with self.assertRaisesRegex(ota.OtaError, "exited with status 17") as failure: + seeder.ensure_running("during startup") + self.assertIn("child diagnostic", str(failure.exception)) + class SeederOptionTests(unittest.TestCase): def arguments(self, chain=False, *options):