perf(unpack): poll for the build artifact under a deadline

src/constants.py

@@ -46,10 +46,10 @@
 DEFAULT_ENDPOINT_TIMEOUT = 300
 """Default timeout in seconds for cross-endpoint HTTP requests."""
 
-DEFAULT_TARBALL_UNPACK_ATTEMPTS = 3
-"""Number of times the Flash-deployed endpoint will attempt to unpack the worker-flash tarball from mounted volume."""
-DEFAULT_TARBALL_UNPACK_INTERVAL = 30
-"""Time in seconds the Flash-deployed endpoint will wait between tarball unpack attempts."""
+DEFAULT_TARBALL_UNPACK_TIMEOUT = 60
+"""Time in seconds the Flash-deployed endpoint will keep retrying the tarball unpack before giving up."""
+DEFAULT_TARBALL_UNPACK_POLL_INTERVAL = 0.5
+"""Time in seconds between tarball unpack attempts. Kept short because the artifact can land just after container start."""
 
 # Dependency Recovery Configuration
 MAX_IMPORT_RECOVERY_ATTEMPTS = 3

src/unpack_volume.py

@@ -6,13 +6,13 @@
 import tarfile
 import threading
 from pathlib import Path
-from time import sleep
+from time import monotonic, sleep
 
 from constants import (
     DEFAULT_APP_DIR,
     DEFAULT_ARTIFACT_PATH,
-    DEFAULT_TARBALL_UNPACK_ATTEMPTS,
-    DEFAULT_TARBALL_UNPACK_INTERVAL,
+    DEFAULT_TARBALL_UNPACK_POLL_INTERVAL,
+    DEFAULT_TARBALL_UNPACK_TIMEOUT,
 )
 from manifest_reconciliation import is_flash_deployment
 
@@ -127,24 +127,52 @@ def maybe_unpack():
             return
 
         logger.info("unpacking app from volume")
+        _unpack_before_deadline()
+        _UNPACKED = True
 
-        last_error: Exception | None = None
-        for attempt in range(DEFAULT_TARBALL_UNPACK_ATTEMPTS):
-            try:
-                unpack_app_from_volume()
-                _UNPACKED = True
-                return
-            except (FileNotFoundError, RuntimeError) as e:
-                last_error = e
-                logger.error(
-                    "failed to unpack app from volume (attempt %s/%s): %s",
-                    attempt + 1,
-                    DEFAULT_TARBALL_UNPACK_ATTEMPTS,
+
+def _unpack_before_deadline() -> None:
+    """Retry the unpack at a short interval until it succeeds or the deadline passes.
+
+    The artifact can land on the volume just after the container starts, so a
+    short poll picks it up within a fraction of a second instead of after a
+    long fixed sleep. Extraction errors are retried too, since a partially
+    written tarball fails to extract.
+
+    Raises:
+        RuntimeError: the unpack did not succeed before the deadline; the last
+            error is chained.
+    """
+    started = monotonic()
+    deadline = started + DEFAULT_TARBALL_UNPACK_TIMEOUT
+    last_error: Exception | None = None
+    while True:
+        try:
+            unpack_app_from_volume()
+        except (FileNotFoundError, RuntimeError) as e:
+            if last_error is None:
+                logger.warning(
+                    "artifact not ready, retrying every %ss for up to %ss: %s",
+                    DEFAULT_TARBALL_UNPACK_POLL_INTERVAL,
+                    DEFAULT_TARBALL_UNPACK_TIMEOUT,
                     e,
-                    exc_info=True,
                 )
-                if attempt < DEFAULT_TARBALL_UNPACK_ATTEMPTS - 1:
-                    sleep(DEFAULT_TARBALL_UNPACK_INTERVAL)
-        raise RuntimeError(
-            f"failed to unpack app from volume after retries: {last_error}"
-        ) from last_error
+            last_error = e
+        else:
+            if last_error is not None:
+                logger.info("artifact unpacked after %.1fs of retries", monotonic() - started)
+            return
+
+        if monotonic() >= deadline:
+            break
+        sleep(DEFAULT_TARBALL_UNPACK_POLL_INTERVAL)
+
+    logger.error(
+        "failed to unpack app from volume after %ss: %s",
+        DEFAULT_TARBALL_UNPACK_TIMEOUT,
+        last_error,
+        exc_info=last_error,
+    )
+    raise RuntimeError(
+        f"failed to unpack app from volume after retries: {last_error}"
+    ) from last_error

tests/unit/test_unpack_volume.py

@@ -349,6 +349,30 @@ def test_should_not_unpack_when_disabled_with_mixed_case(self):
             assert _should_unpack_from_volume() is False
 
 
+class FakeClock:
+    """Monotonic clock that only advances when sleep() is called."""
+
+    def __init__(self) -> None:
+        self.now = 0.0
+
+    def monotonic(self) -> float:
+        return self.now
+
+    def sleep(self, seconds: float) -> None:
+        self.now += seconds
+
+
+@pytest.fixture
+def fake_clock():
+    """Run maybe_unpack's retry loop against a fake clock instead of real time."""
+    clock = FakeClock()
+    with (
+        patch("unpack_volume.monotonic", clock.monotonic),
+        patch("unpack_volume.sleep", clock.sleep),
+    ):
+        yield clock
+
+
 class TestMaybeUnpack:
     """Test idempotency and error handling of maybe_unpack."""
 
@@ -396,17 +420,43 @@ def test_maybe_unpack_skips_when_should_not_unpack(self, mock_unpack, mock_shoul
         mock_should_unpack.assert_called_once()
         mock_unpack.assert_not_called()
 
-    @patch("unpack_volume.sleep")
     @patch("unpack_volume._should_unpack_from_volume")
     @patch("unpack_volume.unpack_app_from_volume")
-    def test_maybe_unpack_propagates_exceptions(self, mock_unpack, mock_should_unpack, mock_sleep):
+    def test_maybe_unpack_propagates_exceptions(self, mock_unpack, mock_should_unpack, fake_clock):
         """Test that exceptions during unpacking are propagated."""
         mock_should_unpack.return_value = True
         mock_unpack.side_effect = FileNotFoundError("Artifact not found")
 
         with pytest.raises(RuntimeError, match="failed to unpack app from volume"):
             maybe_unpack()
 
+    @patch("unpack_volume._should_unpack_from_volume")
+    @patch("unpack_volume.unpack_app_from_volume")
+    def test_maybe_unpack_gives_up_at_deadline(self, mock_unpack, mock_should_unpack, fake_clock):
+        """A missing artifact is retried until the deadline, then the last error is chained."""
+        mock_should_unpack.return_value = True
+        mock_unpack.side_effect = FileNotFoundError("artifact not found")
+
+        with pytest.raises(RuntimeError) as exc_info:
+            maybe_unpack()
+
+        assert isinstance(exc_info.value.__cause__, FileNotFoundError)
+        assert 60 <= fake_clock.now <= 61
+
+    @patch("unpack_volume._should_unpack_from_volume")
+    @patch("unpack_volume.unpack_app_from_volume")
+    def test_maybe_unpack_picks_up_late_artifact_promptly(self, mock_unpack, mock_should_unpack):
+        """An artifact that lands just after container start is unpacked without a long wait."""
+        mock_should_unpack.return_value = True
+        mock_unpack.side_effect = [FileNotFoundError("artifact not found"), True]
+        waited: list[float] = []
+
+        with patch("unpack_volume.sleep", side_effect=waited.append):
+            maybe_unpack()
+
+        assert mock_unpack.call_count == 2
+        assert sum(waited) <= 1.0
+
     @patch("unpack_volume._should_unpack_from_volume")
     @patch("unpack_volume.unpack_app_from_volume")
     @patch("unpack_volume.logger")
@@ -419,23 +469,21 @@ def test_maybe_unpack_logs_info_on_start(self, mock_logger, mock_unpack, mock_sh
 
         mock_logger.info.assert_called_once_with("unpacking app from volume")
 
-    @patch("unpack_volume.sleep")
     @patch("unpack_volume._should_unpack_from_volume")
     @patch("unpack_volume.unpack_app_from_volume")
     @patch("unpack_volume.logger")
     def test_maybe_unpack_logs_error_on_failure(
-        self, mock_logger, mock_unpack, mock_should_unpack, mock_sleep
+        self, mock_logger, mock_unpack, mock_should_unpack, fake_clock
     ):
-        """Test that errors are logged when unpacking fails."""
+        """The wait is logged once when it starts, and the failure once at the deadline."""
         mock_should_unpack.return_value = True
         error_msg = "Extraction failed"
         mock_unpack.side_effect = RuntimeError(error_msg)
 
         with pytest.raises(RuntimeError, match="failed to unpack app from volume"):
             maybe_unpack()
 
-        # Error should be logged once per retry attempt (3 total)
-        assert mock_logger.error.call_count == 3
-        # Verify all error calls include the expected message
-        for call in mock_logger.error.call_args_list:
-            assert "failed to unpack app from volume" in call[0][0]
+        assert mock_unpack.call_count > 3
+        assert mock_logger.warning.call_count == 1
+        assert mock_logger.error.call_count == 1
+        assert "failed to unpack app from volume" in mock_logger.error.call_args[0][0]