diff --git a/supervisor/docker/const.py b/supervisor/docker/const.py index f8658d021..623305801 100644 --- a/supervisor/docker/const.py +++ b/supervisor/docker/const.py @@ -1,15 +1,20 @@ """Docker constants.""" +from __future__ import annotations + from contextlib import suppress from enum import Enum, StrEnum from functools import total_ordering from pathlib import PurePath -from typing import Self, cast +import re +from typing import cast from docker.types import Mount from ..const import MACHINE_ID +RE_RETRYING_DOWNLOAD_STATUS = re.compile(r"Retrying in \d+ seconds?") + class Capabilities(StrEnum): """Linux Capabilities.""" @@ -79,6 +84,7 @@ class PullImageLayerStage(Enum): """ PULLING_FS_LAYER = 1, "Pulling fs layer" + RETRYING_DOWNLOAD = 2, "Retrying download" DOWNLOADING = 2, "Downloading" VERIFYING_CHECKSUM = 3, "Verifying Checksum" DOWNLOAD_COMPLETE = 4, "Download complete" @@ -107,11 +113,16 @@ class PullImageLayerStage(Enum): return hash(self.status) @classmethod - def from_status(cls, status: str) -> Self | None: + def from_status(cls, status: str) -> PullImageLayerStage | None: """Return stage instance from pull log status.""" for i in cls: if i.status == status: return i + + # This one includes number of seconds until download so its not constant + if RE_RETRYING_DOWNLOAD_STATUS.match(status): + return cls.RETRYING_DOWNLOAD + return None diff --git a/supervisor/docker/interface.py b/supervisor/docker/interface.py index 5faf90492..d91c70d27 100644 --- a/supervisor/docker/interface.py +++ b/supervisor/docker/interface.py @@ -291,8 +291,10 @@ class DockerInterface(JobGroup, ABC): progress = 50 case PullImageLayerStage.PULL_COMPLETE: progress = 100 + case PullImageLayerStage.RETRYING_DOWNLOAD: + progress = 0 - if progress < job.progress: + if stage != PullImageLayerStage.RETRYING_DOWNLOAD and progress < job.progress: raise DockerLogOutOfOrder( f"Received pull image log with status {reference.status} for job {job.uuid} that implied progress was {progress} but current progress is {job.progress}, skipping", _LOGGER.debug, @@ -300,7 +302,7 @@ class DockerInterface(JobGroup, ABC): # Our filters have all passed. Time to update the job # Only downloading and extracting have progress details. Use that to set extra - # We'll leave it around on other stages as the total bytes may be useful after that stage + # We'll leave it around on later stages as the total bytes may be useful after that stage if ( stage in {PullImageLayerStage.DOWNLOADING, PullImageLayerStage.EXTRACTING} and reference.progress_detail @@ -318,6 +320,9 @@ class DockerInterface(JobGroup, ABC): progress=progress, stage=stage.status, done=stage == PullImageLayerStage.PULL_COMPLETE, + extra=None + if stage == PullImageLayerStage.RETRYING_DOWNLOAD + else job.extra, ) @Job( diff --git a/tests/docker/test_interface.py b/tests/docker/test_interface.py index 5a8d4efca..01480c263 100644 --- a/tests/docker/test_interface.py +++ b/tests/docker/test_interface.py @@ -774,3 +774,140 @@ async def test_install_raises_on_pull_error( with pytest.raises(exc_type, match=exc_msg): await test_docker_interface.install(AwesomeVersion("1.2.3"), "test") + + +async def test_install_progress_handles_download_restart( + coresys: CoreSys, test_docker_interface: DockerInterface, ha_ws_client: AsyncMock +): + """Test install handles docker progress events that include a download restart.""" + coresys.core.set_state(CoreState.RUNNING) + coresys.docker.docker.api.pull.return_value = load_json_fixture( + "docker_pull_image_log_restart.json" + ) + + with ( + patch.object( + type(coresys.supervisor), "arch", PropertyMock(return_value="i386") + ), + ): + # Schedule job so we can listen for the end. Then we can assert against the WS mock + event = asyncio.Event() + job, install_task = coresys.jobs.schedule_job( + test_docker_interface.install, + JobSchedulerOptions(), + AwesomeVersion("1.2.3"), + "test", + ) + + async def listen_for_job_end(reference: SupervisorJob): + if reference.uuid != job.uuid: + return + event.set() + + coresys.bus.register_event(BusEvent.SUPERVISOR_JOB_END, listen_for_job_end) + await install_task + await event.wait() + + events = [ + evt.args[0]["data"]["data"] + for evt in ha_ws_client.async_send_command.call_args_list + if "data" in evt.args[0] and evt.args[0]["data"]["event"] == WSEvent.JOB + ] + + def make_sub_log(layer_id: str): + return [ + { + "stage": evt["stage"], + "progress": evt["progress"], + "done": evt["done"], + "extra": evt["extra"], + } + for evt in events + if evt["name"] == "Pulling container image layer" + and evt["reference"] == layer_id + and evt["parent_id"] == job.uuid + ] + + layer_1_log = make_sub_log("1e214cd6d7d0") + assert len(layer_1_log) == 14 + assert layer_1_log == [ + {"stage": "Pulling fs layer", "progress": 0, "done": False, "extra": None}, + { + "stage": "Downloading", + "progress": 11.9, + "done": False, + "extra": {"current": 103619904, "total": 436480882}, + }, + { + "stage": "Downloading", + "progress": 26.1, + "done": False, + "extra": {"current": 227726144, "total": 436480882}, + }, + { + "stage": "Downloading", + "progress": 49.6, + "done": False, + "extra": {"current": 433170048, "total": 436480882}, + }, + { + "stage": "Retrying download", + "progress": 0, + "done": False, + "extra": None, + }, + { + "stage": "Retrying download", + "progress": 0, + "done": False, + "extra": None, + }, + { + "stage": "Downloading", + "progress": 11.9, + "done": False, + "extra": {"current": 103619904, "total": 436480882}, + }, + { + "stage": "Downloading", + "progress": 26.1, + "done": False, + "extra": {"current": 227726144, "total": 436480882}, + }, + { + "stage": "Downloading", + "progress": 49.6, + "done": False, + "extra": {"current": 433170048, "total": 436480882}, + }, + { + "stage": "Verifying Checksum", + "progress": 50, + "done": False, + "extra": {"current": 433170048, "total": 436480882}, + }, + { + "stage": "Download complete", + "progress": 50, + "done": False, + "extra": {"current": 433170048, "total": 436480882}, + }, + { + "stage": "Extracting", + "progress": 80.0, + "done": False, + "extra": {"current": 261816320, "total": 436480882}, + }, + { + "stage": "Extracting", + "progress": 100.0, + "done": False, + "extra": {"current": 436480882, "total": 436480882}, + }, + { + "stage": "Pull complete", + "progress": 100.0, + "done": True, + "extra": {"current": 436480882, "total": 436480882}, + }, + ] diff --git a/tests/fixtures/docker_pull_image_log_restart.json b/tests/fixtures/docker_pull_image_log_restart.json new file mode 100644 index 000000000..d20a32482 --- /dev/null +++ b/tests/fixtures/docker_pull_image_log_restart.json @@ -0,0 +1,134 @@ +[ + { + "status": "Pulling from home-assistant/odroid-n2-homeassistant", + "id": "2025.7.1" + }, + { + "status": "Already exists", + "progressDetail": {}, + "id": "6e771e15690e" + }, + { + "status": "Already exists", + "progressDetail": {}, + "id": "58da640818f4" + }, + { + "status": "Pulling fs layer", + "progressDetail": {}, + "id": "1e214cd6d7d0" + }, + { + "status": "Already exists", + "progressDetail": {}, + "id": "1a38e1d5e18d" + }, + { + "status": "Waiting", + "progressDetail": {}, + "id": "1e214cd6d7d0" + }, + { + "status": "Downloading", + "progressDetail": { + "current": 103619904, + "total": 436480882 + }, + "progress": "[===========> ] 103.6MB/436.5MB", + "id": "1e214cd6d7d0" + }, + { + "status": "Downloading", + "progressDetail": { + "current": 227726144, + "total": 436480882 + }, + "progress": "[==========================> ] 227.7MB/436.5MB", + "id": "1e214cd6d7d0" + }, + { + "status": "Downloading", + "progressDetail": { + "current": 433170048, + "total": 436480882 + }, + "progress": "[=================================================> ] 433.2MB/436.5MB", + "id": "1e214cd6d7d0" + }, + { + "status": "Retrying in 2 seconds", + "progressDetail": {}, + "id": "1e214cd6d7d0" + }, + { + "status": "Retrying in 1 seconds", + "progressDetail": {}, + "id": "1e214cd6d7d0" + }, + { + "status": "Downloading", + "progressDetail": { + "current": 103619904, + "total": 436480882 + }, + "progress": "[===========> ] 103.6MB/436.5MB", + "id": "1e214cd6d7d0" + }, + { + "status": "Downloading", + "progressDetail": { + "current": 227726144, + "total": 436480882 + }, + "progress": "[==========================> ] 227.7MB/436.5MB", + "id": "1e214cd6d7d0" + }, + { + "status": "Downloading", + "progressDetail": { + "current": 433170048, + "total": 436480882 + }, + "progress": "[=================================================> ] 433.2MB/436.5MB", + "id": "1e214cd6d7d0" + }, + { + "status": "Verifying Checksum", + "progressDetail": {}, + "id": "1e214cd6d7d0" + }, + { + "status": "Download complete", + "progressDetail": {}, + "id": "1e214cd6d7d0" + }, + { + "status": "Extracting", + "progressDetail": { + "current": 261816320, + "total": 436480882 + }, + "progress": "[=============================> ] 261.8MB/436.5MB", + "id": "1e214cd6d7d0" + }, + { + "status": "Extracting", + "progressDetail": { + "current": 436480882, + "total": 436480882 + }, + "progress": "[==================================================>] 436.5MB/436.5MB", + "id": "1e214cd6d7d0" + }, + { + "status": "Pull complete", + "progressDetail": {}, + "id": "1e214cd6d7d0" + }, + { + "status": "Digest: sha256:7d97da645f232f82a768d0a537e452536719d56d484d419836e53dbe3e4ec736" + }, + { + "status": "Status: Downloaded newer image for ghcr.io/home-assistant/odroid-n2-homeassistant:2025.7.1" + } +] \ No newline at end of file