Record the current step of a template build

alembic/versions/0009_template_build_step.py

@@ -0,0 +1,22 @@
+"""Record the step a template build is in."""
+
+from collections.abc import Sequence
+
+import sqlalchemy as sa
+from alembic import op
+
+revision: str = "0009_template_build_step"
+down_revision: str | None = "0008_template_base_image_ref"
+branch_labels: str | Sequence[str] | None = None
+depends_on: str | Sequence[str] | None = None
+
+
+def upgrade() -> None:
+    op.add_column(
+        "templates", sa.Column("build_step", sa.Text(), nullable=False, server_default="")
+    )
+
+
+def downgrade() -> None:
+    with op.batch_alter_table("templates") as templates:
+        templates.drop_column("build_step")

docs/architecture.md

@@ -183,7 +183,9 @@ For example, `{"base_image":"sandbox:latest","setup_script":"echo ready"}`
 reuses a template only while the tag resolves to the same digest. A new digest
 creates a `building` record and returns `202 Accepted`. The build uses the
 saved digest reference even if the tag moves again. Callers poll until the
-template becomes `available` or `failed`. A `POST` for a `failed` template
+template becomes `available` or `failed`. While it builds, `build_step` names
+the current step, such as `running setup script: <last output line>`; a failed
+build keeps the step it failed in. A `POST` for a `failed` template
 builds the same record again, and its `last_error` stays until that build
 ends. A pull or store failure returns `502`; a provider without template
 support returns `400`.

src/providers/capabilities.py

@@ -1,6 +1,7 @@
 import abc
 import base64
 import pathlib
+from collections.abc import Awaitable, Callable
 from typing import ClassVar, TypeVar
 
 from cryptography import x509
@@ -13,6 +14,8 @@
 from providers.exceptions import CapabilityUnsupportedError, ProviderCommandError
 
 CapabilityT = TypeVar("CapabilityT")
+# Records the step a template build is in, such as "pushing image".
+RecordStep = Callable[[str], Awaitable[None]]
 
 # The box itself and the cloud metadata address.
 NO_PROXY = "localhost,127.0.0.1,::1,169.254.169.254"
@@ -21,6 +24,7 @@
 
 
 def resolve_capability(provider, capability: type[CapabilityT]) -> CapabilityT:
+    # ast-grep-ignore: rule-3
     if not isinstance(provider, capability):
         raise CapabilityUnsupportedError(
             f"VM provider '{provider.name}' does not support {capability.__name__}",
@@ -119,6 +123,7 @@ async def build_template_image(
         base_image: str,
         setup_script: str,
         label: str,
+        record_step: RecordStep,
     ) -> str: ...
 
     @abc.abstractmethod

src/providers/docker/api.py

@@ -1,4 +1,5 @@
 import io
+from collections.abc import AsyncIterator
 from pathlib import Path
 
 import aiodocker
@@ -93,13 +94,17 @@ async def remove_container(self, name: str) -> None:
         except aiohttp.ClientError as exc:
             raise DockerTransportError(str(exc)) from exc
 
-    async def build_image(self, image: str, context_tar: bytes) -> None:
+    async def build_image(self, image: str, context_tar: bytes) -> AsyncIterator[str]:
+        """Build the image and yield the last line of each output chunk."""
         try:
-            await self._get_client().images.build(
+            async for event in self._get_client().images.build(
                 fileobj=io.BytesIO(context_tar),
                 encoding="gzip",
                 tag=image,
-            )
+                stream=True,
+            ):
+                if output := event.get("stream", "").strip():
+                    yield output.splitlines()[-1]
         except (aiodocker.DockerError, aiohttp.ClientError) as exc:
             raise DockerTransportError(_detail(exc)) from exc
 

src/providers/docker/images.py

@@ -2,13 +2,18 @@
 import io
 import re
 import tarfile
+import time
 
 from core.settings import get_settings
+from providers.capabilities import RecordStep
 from providers.exceptions import ProviderNotFoundError, ProviderTransportError
 
 from .api import DockerAPI
 from .exceptions import DockerImageNotFoundError, DockerProviderError
 
+# A setup script can print thousands of lines. The step shows one per interval.
+SETUP_OUTPUT_INTERVAL_SECONDS = 3.0
+
 
 def derive_image_name(
     *,
@@ -49,6 +54,7 @@ async def build_derived_image(
     base_image: str,
     setup_script: str,
     label: str,
+    record_step: RecordStep,
 ) -> str:
     settings = get_settings()
     repository = "drukbox-template"
@@ -62,8 +68,14 @@ async def build_derived_image(
     )
     context_tar = create_build_context(base_image=base_image, setup_script=setup_script)
     try:
-        await docker.build_image(image, context_tar)
+        await record_step("running setup script")
+        shown_at = time.monotonic()
+        async for line in docker.build_image(image, context_tar):
+            if time.monotonic() - shown_at >= SETUP_OUTPUT_INTERVAL_SECONDS:
+                await record_step(f"running setup script: {line}")
+                shown_at = time.monotonic()
         if settings.template_repository:
+            await record_step("pushing image")
             await docker.push_image(
                 image,
                 username=settings.registry_username,

src/providers/docker/provider.py

@@ -3,7 +3,7 @@
 
 from core.settings import get_settings
 from providers.base import VMCreateResult, VMProvider
-from providers.capabilities import TemplateCapability
+from providers.capabilities import RecordStep, TemplateCapability
 from providers.exceptions import (
     ProviderCommandError,
     ProviderNotFoundError,
@@ -143,12 +143,14 @@ async def build_template_image(
         base_image: str,
         setup_script: str,
         label: str,
+        record_step: RecordStep,
     ) -> str:
         return await build_derived_image(
             self.api,
             base_image=base_image,
             setup_script=setup_script,
             label=label,
+            record_step=record_step,
         )
 
     async def delete_template_image(self, image: str) -> None:

src/providers/docker/tests/test_api.py

@@ -28,7 +28,7 @@ def _fake_docker(**overrides: object) -> SimpleNamespace:
         ),
         images=SimpleNamespace(
             pull=AsyncMock(return_value=[{"status": "Digest: sha256:" + "a" * 64}]),
-            build=AsyncMock(),
+            build=MagicMock(),
             delete=AsyncMock(),
             push=AsyncMock(),
         ),
@@ -111,18 +111,27 @@ async def test_remove_container_forces_and_drops_volumes() -> None:
     fake.containers.container.return_value.delete.assert_awaited_once_with(force=True, v=True)
 
 
-async def test_build_image_sends_the_context_tar_under_the_tag() -> None:
+async def test_build_image_sends_the_context_tar_and_yields_its_output() -> None:
     fake = _fake_docker()
+    fake.images.build.return_value.__aiter__.return_value = [
+        {"stream": "Step 3/3 : RUN sh /drukbox-setup.sh\n"},
+        {"aux": {"ID": "sha256:abc"}},
+        {"stream": "Reading package lists...\nInstalling nodejs\n"},
+    ]
     buffer = io.BytesIO()
     with tarfile.open(fileobj=buffer, mode="w:gz"):
         pass
     context_tar = buffer.getvalue()
 
-    await _api(fake).build_image("drukbox-template:123456789abc", context_tar)
+    output = [
+        line async for line in _api(fake).build_image("drukbox-template:123456789abc", context_tar)
+    ]
 
-    kwargs = fake.images.build.await_args.kwargs
+    assert output == ["Step 3/3 : RUN sh /drukbox-setup.sh", "Installing nodejs"]
+    kwargs = fake.images.build.call_args.kwargs
     assert kwargs["tag"] == "drukbox-template:123456789abc"
     assert kwargs["encoding"] == "gzip"
+    assert kwargs["stream"] is True
     assert kwargs["fileobj"].getvalue() == context_tar
 
 
@@ -131,7 +140,8 @@ async def test_build_failure_keeps_the_engine_detail() -> None:
     fake.images.build.side_effect = DockerError(0, "RUN sh /drukbox-setup.sh: exit code 127")
 
     with pytest.raises(DockerTransportError, match="exit code 127"):
-        await _api(fake).build_image("drukbox-template:123456789abc", b"")
+        async for _ in _api(fake).build_image("drukbox-template:123456789abc", b""):
+            pass
 
 
 @pytest.mark.parametrize(

src/providers/docker/tests/test_images.py

@@ -6,6 +6,7 @@
 from pydantic import SecretStr
 
 from core.settings import get_settings
+from providers.docker import images
 from providers.docker.images import (
     build_derived_image,
     create_build_context,
@@ -68,12 +69,24 @@ async def test_build_derived_image_publishes_to_the_template_repository(
     monkeypatch.setattr(get_settings(), "registry_username", "bot")
     monkeypatch.setattr(get_settings(), "registry_password", SecretStr("secret"))
     monkeypatch.setattr(get_settings(), "template_repository", "acme/templates")
-    docker = MagicMock(build_image=AsyncMock(), push_image=AsyncMock())
+    monkeypatch.setattr(images, "SETUP_OUTPUT_INTERVAL_SECONDS", 0)
+    docker = MagicMock(push_image=AsyncMock())
+    docker.build_image.return_value.__aiter__.return_value = ["Installing nodejs"]
+    record_step = AsyncMock()
 
     image = await build_derived_image(
-        docker, base_image="sandbox:base", setup_script="apt-get update", label="node-tools"
+        docker,
+        base_image="sandbox:base",
+        setup_script="apt-get update",
+        label="node-tools",
+        record_step=record_step,
     )
 
     assert image.startswith("ghcr.io/acme/templates:node-tools-")
-    assert docker.build_image.await_args.args[0] == image
+    assert docker.build_image.call_args.args[0] == image
     docker.push_image.assert_awaited_once_with(image, username="bot", password="secret")
+    assert [call.args[0] for call in record_step.await_args_list] == [
+        "running setup script",
+        "running setup script: Installing nodejs",
+        "pushing image",
+    ]

src/providers/docker/tests/test_provider.py

@@ -28,7 +28,7 @@ def _api_mock() -> MagicMock:
     api.run_container = AsyncMock(return_value="container-id")
     api.published_ssh_port = AsyncMock(return_value=49160)
     api.remove_container = AsyncMock()
-    api.build_image = AsyncMock()
+    api.build_image = MagicMock()
     api.remove_image = AsyncMock()
     api.server_version = AsyncMock(return_value="27.0.3")
     return api
@@ -174,10 +174,11 @@ async def test_build_template_image_builds_and_returns_the_derived_tag():
         base_image="sandbox:base",
         setup_script="apt-get update",
         label="Node tools",
+        record_step=AsyncMock(),
     )
 
     assert image.startswith("drukbox-template:node-tools-")
-    assert api.build_image.await_args.args[0] == image
+    assert api.build_image.call_args.args[0] == image
 
 
 @pytest.mark.asyncio
@@ -191,6 +192,7 @@ async def test_build_template_image_translates_build_failure():
             base_image="sandbox:base",
             setup_script="apt-get update",
             label="Node tools",
+            record_step=AsyncMock(),
         )
 
 

src/providers/docker_sbx/provider.py

@@ -10,7 +10,7 @@
 from core.settings import get_settings
 from providers import environment
 from providers.base import VMCreateResult, VMProvider
-from providers.capabilities import TemplateCapability
+from providers.capabilities import RecordStep, TemplateCapability
 from providers.docker.api import DockerAPI
 from providers.docker.exceptions import DockerProviderError
 from providers.docker.images import build_derived_image
@@ -188,18 +188,22 @@ async def build_template_image(
         base_image: str,
         setup_script: str,
         label: str,
+        record_step: RecordStep,
     ) -> str:
         image = await build_derived_image(
             self.docker,
             base_image=base_image,
             setup_script=setup_script,
             label=label,
+            record_step=record_step,
         )
         # sbx keeps its own image store. The Docker image only carries the build.
         try:
             with tempfile.TemporaryDirectory() as directory:
                 archive = Path(directory) / "template.tar"
+                await record_step("saving image")
                 await self.docker.save_image(image, archive)
+                await record_step("loading into sbx")
                 await self.api.load_template(archive)
             await self.docker.remove_image(image)
         except (OSError, DockerProviderError, DockerSbxProviderError) as exc:

src/providers/docker_sbx/tests/test_provider.py

@@ -36,7 +36,7 @@ def _api_mock() -> MagicMock:
 
 def _docker_mock() -> MagicMock:
     docker = MagicMock()
-    docker.build_image = AsyncMock()
+    docker.build_image = MagicMock()
     docker.remove_image = AsyncMock()
     docker.save_image = AsyncMock()
     return docker
@@ -172,6 +172,7 @@ def test_the_value_files_live_beside_the_workspaces(tmp_path):
     provider = _provider(_api_mock(), _settings(tmp_path))
 
     injection = provider.secrets
+    # ast-grep-ignore: rule-3
     assert isinstance(injection, SbxInjection)
     assert injection.secrets_root == provider.secrets_root == tmp_path / "secrets"
 
@@ -222,19 +223,26 @@ async def test_build_template_image_moves_the_built_image_into_sbx(tmp_path):
     docker = _docker_mock()
     provider = _provider(api, _settings(tmp_path), docker=docker)
 
+    record_step = AsyncMock()
     image = await provider.build_template_image(
         base_image="sandbox:base",
         setup_script="apt-get update",
         label="Node tools",
+        record_step=record_step,
     )
 
     assert image.startswith("drukbox-template:")
-    assert docker.build_image.await_args.args[0] == image
+    assert docker.build_image.call_args.args[0] == image
     saved, archive = docker.save_image.await_args.args
     assert saved == image
     api.load_template.assert_awaited_once_with(archive)
     assert not archive.exists()
     docker.remove_image.assert_awaited_once_with(image)
+    assert [call.args[0] for call in record_step.await_args_list] == [
+        "running setup script",
+        "saving image",
+        "loading into sbx",
+    ]
 
 
 @pytest.mark.asyncio
@@ -248,6 +256,7 @@ async def test_build_template_image_translates_a_failed_load(tmp_path):
             base_image="sandbox:base",
             setup_script="apt-get update",
             label="Node tools",
+            record_step=AsyncMock(),
         )