🎨Progress bar: Add structured message in progress report (#5702)

Author: sanderegg

ci/github/helpers/install_rclone_docker_volume_plugin.bash

@@ -4,14 +4,13 @@
 #
 
 # http://redsymbol.net/articles/unofficial-bash-strict-mode/
-set -o errexit   # abort on nonzero exitstatus
-set -o nounset   # abort on unbound variable
-set -o pipefail  # don't hide errors within pipes
+set -o errexit  # abort on nonzero exitstatus
+set -o nounset  # abort on unbound variable
+set -o pipefail # don't hide errors within pipes
 IFS=$'\n\t'
 
-
 # Installation instructions from https://rclone.org/docker/
-R_CLONE_VERSION="1.63.1"
+R_CLONE_VERSION="1.66.0"
 mkdir --parents /var/lib/docker-plugins/rclone/config
 mkdir --parents /var/lib/docker-plugins/rclone/cache
 docker plugin install rclone/docker-volume-rclone:amd64-${R_CLONE_VERSION} args="-v" --alias rclone --grant-all-permissions

packages/models-library/src/models_library/progress_bar.py

@@ -2,21 +2,81 @@
 
 from pydantic import BaseModel
 
+from .basic_types import IDStr
+
 # NOTE: keep a list of possible unit, and please use correct official unit names
 ProgressUnit: TypeAlias = Literal["Byte"]
 
 
+class ProgressStructuredMessage(BaseModel):
+    description: IDStr
+    current: float
+    total: int
+    unit: str | None
+    sub: "ProgressStructuredMessage | None"
+
+    class Config:
+        schema_extra: ClassVar[dict[str, Any]] = {
+            "examples": [
+                {
+                    "description": "some description",
+                    "current": 12.2,
+                    "total": 123,
+                },
+                {
+                    "description": "some description",
+                    "current": 12.2,
+                    "total": 123,
+                    "unit": "Byte",
+                },
+                {
+                    "description": "downloading",
+                    "current": 2.0,
+                    "total": 5,
+                    "sub": {
+                        "description": "port 2",
+                        "current": 12.2,
+                        "total": 123,
+                        "unit": "Byte",
+                    },
+                },
+            ]
+        }
+
+
+UNITLESS = None
+
+
 class ProgressReport(BaseModel):
     actual_value: float
-    total: float
-    unit: ProgressUnit | None = None
+    total: float = 1.0
+    unit: ProgressUnit | None = UNITLESS
+    message: ProgressStructuredMessage | None = None
 
     @property
     def percent_value(self) -> float:
         if self.total != 0:
             return max(min(self.actual_value / self.total, 1.0), 0.0)
         return 0
 
+    def _recursive_compose_message(self, struct_msg: ProgressStructuredMessage) -> str:
+        msg = f"{struct_msg.description}"
+        if struct_msg.sub:
+            return f"{msg}/{self._recursive_compose_message(struct_msg.sub)}"
+        msg = f"{msg} {struct_msg.current} / {struct_msg.total}"
+        return f"{msg} {struct_msg.unit}" if struct_msg.unit is not UNITLESS else msg
+
+    @property
+    def composed_message(self) -> str:
+        msg = f"{self.actual_value} / {self.total}"
+        msg = f"{msg} {self.unit}" if self.unit is not UNITLESS else msg
+        if self.message:
+            msg = f"{self.message.description} ({msg})"
+            if self.message.sub:
+                msg = f"{msg}/{self._recursive_compose_message(self.message.sub)}"
+
+        return msg
+
     class Config:
         frozen = True
         schema_extra: ClassVar[dict[str, Any]] = {
@@ -32,5 +92,13 @@ class Config:
                     "total": 1024.0,
                     "unit": "Byte",
                 },
+                # typical progress with sub progresses
+                {
+                    "actual_value": 0.3,
+                    "total": 1.0,
+                    "message": ProgressStructuredMessage.Config.schema_extra[
+                        "examples"
+                    ][2],
+                },
             ]
         }

packages/service-library/src/servicelib/archiving_utils.py

@@ -171,7 +171,9 @@ async def unarchive_dir(
     ::raise ArchiveError
     """
     if not progress_bar:
-        progress_bar = ProgressBarData(num_steps=1)
+        progress_bar = ProgressBarData(
+            num_steps=1, description=f"extracting {archive_to_extract.name}"
+        )
     async with AsyncExitStack() as zip_stack:
         zip_file_handler = zip_stack.enter_context(
             zipfile.ZipFile(  # pylint: disable=consider-using-with
@@ -213,7 +215,7 @@ async def unarchive_dir(
             )
             async with AsyncExitStack() as progress_stack:
                 sub_prog = await progress_stack.enter_async_context(
-                    progress_bar.sub_progress(steps=total_file_size)
+                    progress_bar.sub_progress(steps=total_file_size, description="...")
                 )
                 tqdm_progress = progress_stack.enter_context(
                     tqdm.tqdm(
@@ -355,15 +357,17 @@ async def archive_dir(
     ::raise ArchiveError
     """
     if not progress_bar:
-        progress_bar = ProgressBarData(num_steps=1)
+        progress_bar = ProgressBarData(
+            num_steps=1, description=f"compressing {dir_to_compress.name}"
+        )
 
     async with AsyncExitStack() as stack:
         folder_size_bytes = sum(
             file.stat().st_size
             for file in _iter_files_to_compress(dir_to_compress, exclude_patterns)
         )
         sub_progress = await stack.enter_async_context(
-            progress_bar.sub_progress(folder_size_bytes)
+            progress_bar.sub_progress(folder_size_bytes, description="...")
         )
         thread_pool = stack.enter_context(
             non_blocking_thread_pool_executor(max_workers=1)

packages/service-library/src/servicelib/docker_utils.py

@@ -212,7 +212,8 @@ async def pull_image(
                     assert parsed_progress.progress_detail  # nosec
                     assert parsed_progress.progress_detail.current  # nosec
                     layer_id_to_size.setdefault(
-                        parsed_progress.id, _PulledStatus(0)
+                        parsed_progress.id,
+                        _PulledStatus(parsed_progress.progress_detail.total or 0),
                     ).extracted = parsed_progress.progress_detail.current
                 case "pull complete":
                     assert parsed_progress.id  # nosec

packages/service-library/src/servicelib/fastapi/docker_utils.py

@@ -123,6 +123,7 @@ async def pull_images(
         num_steps=images_total_size,
         progress_report_cb=progress_cb,
         progress_unit="Byte",
+        description=f"pulling {len(images)} images",
     ) as pbar:
 
         await asyncio.gather(

packages/service-library/src/servicelib/progress_bar.py

@@ -4,7 +4,11 @@
 from inspect import isawaitable
 from typing import Final, Optional, Protocol, runtime_checkable
 
-from models_library.progress_bar import ProgressReport, ProgressUnit
+from models_library.progress_bar import (
+    ProgressReport,
+    ProgressStructuredMessage,
+    ProgressUnit,
+)
 from pydantic import parse_obj_as
 
 from .logging_utils import log_catch
@@ -35,9 +39,12 @@ def _normalize_weights(steps: int, weights: list[float]) -> list[float]:
 
 
 @dataclass(slots=True, kw_only=True)
-class ProgressBarData:
+class ProgressBarData:  # pylint: disable=too-many-instance-attributes
     """A progress bar data allows to keep track of multiple progress(es) even in deeply nested processes.
 
+    BEWARE: Using weights AND concurrency is a recipe for disaster as the progress bar does not know which
+    sub progress finished. Concurrency may only be used with a single progress bar or with equal step weights!!
+
     - Simple example:
     async def main_fct():
         async with ProgressBarData(num_steps=3) as root_progress_bar:
@@ -76,10 +83,11 @@ async def main_fct():
             "description": "Optionally defines the step relative weight (defaults to steps of equal weights)"
         },
     )
+    description: str = field(metadata={"description": "define the progress name"})
     progress_unit: ProgressUnit | None = None
     progress_report_cb: AsyncReportCB | ReportCB | None = None
     _current_steps: float = _INITIAL_VALUE
-    _children: list = field(default_factory=list)
+    _children: list["ProgressBarData"] = field(default_factory=list)
     _parent: Optional["ProgressBarData"] = None
     _continuous_value_lock: asyncio.Lock = field(init=False)
     _last_report_value: float = _INITIAL_VALUE
@@ -107,23 +115,39 @@ async def _update_parent(self, value: float) -> None:
         if self._parent:
             await self._parent.update(value)
 
-    async def _report_external(self, value: float, *, force: bool = False) -> None:
+    def is_running(self) -> bool:
+        return self._current_steps < self.num_steps
+
+    def compute_report_message_stuct(self) -> ProgressStructuredMessage:
+        self_report = ProgressStructuredMessage(
+            description=self.description,
+            current=self._current_steps,
+            total=self.num_steps,
+            unit=self.progress_unit,
+            sub=None,
+        )
+        for child in self._children:
+            if child.is_running():
+                self_report.sub = child.compute_report_message_stuct()
+        return self_report
+
+    async def _report_external(self, value: float) -> None:
         if not self.progress_report_cb:
             return
 
         with log_catch(_logger, reraise=False):
             # NOTE: only report if at least a percent was increased
             if (
-                (force and value != self._last_report_value)
-                or ((value - self._last_report_value) > _MIN_PROGRESS_UPDATE_PERCENT)
-                or value == _FINAL_VALUE
-            ):
+                (value - self._last_report_value) > _MIN_PROGRESS_UPDATE_PERCENT
+            ) or value == _FINAL_VALUE:
+                # compute progress string
                 call = self.progress_report_cb(
                     ProgressReport(
                         # NOTE: here we convert back to actual value since this is possibly weighted
                         actual_value=value * self.num_steps,
                         total=self.num_steps,
                         unit=self.progress_unit,
+                        message=self.compute_report_message_stuct(),
                     ),
                 )
                 if isawaitable(call):
@@ -180,13 +204,21 @@ async def finish(self) -> None:
         await self.set_(self.num_steps)
 
     def sub_progress(
-        self, steps: int, step_weights: list[float] | None = None
+        self,
+        steps: int,
+        description: str,
+        step_weights: list[float] | None = None,
+        progress_unit: ProgressUnit | None = None,
     ) -> "ProgressBarData":
         if len(self._children) == self.num_steps:
             msg = "Too many sub progresses created already. Wrong usage of the progress bar"
             raise RuntimeError(msg)
         child = ProgressBarData(
-            num_steps=steps, step_weights=step_weights, _parent=self
+            num_steps=steps,
+            description=description,
+            step_weights=step_weights,
+            progress_unit=progress_unit,
+            _parent=self,
         )
         self._children.append(child)
         return child

packages/service-library/tests/aiohttp/test_docker_utils.py

@@ -6,9 +6,9 @@
 from collections.abc import Awaitable, Callable
 from typing import Any
 from unittest import mock
-from unittest.mock import call
 
 import pytest
+from faker import Faker
 from models_library.docker import DockerGenericTag
 from models_library.progress_bar import ProgressReport
 from pydantic import parse_obj_as
@@ -93,11 +93,18 @@ async def _progress_cb(*args, **kwargs) -> None:
 def _assert_progress_report_values(
     mocked_progress_cb: mock.AsyncMock, *, total: float
 ) -> None:
-    assert mocked_progress_cb.call_args_list[0] == call(
-        ProgressReport(actual_value=0, total=total)
+    # NOTE: we exclude the message part here as this is already tested in servicelib
+    # check first progress
+    assert mocked_progress_cb.call_args_list[0].args[0].dict(
+        exclude={"message"}
+    ) == ProgressReport(actual_value=0, total=total, unit="Byte").dict(
+        exclude={"message"}
     )
-    assert mocked_progress_cb.call_args_list[-1] == call(
-        ProgressReport(actual_value=total, total=total)
+    # check last progress
+    assert mocked_progress_cb.call_args_list[-1].args[0].dict(
+        exclude={"message"}
+    ) == ProgressReport(actual_value=total, total=total, unit="Byte").dict(
+        exclude={"message"}
     )
 
 
@@ -112,6 +119,7 @@ async def test_pull_image(
     mocked_log_cb: mock.AsyncMock,
     mocked_progress_cb: mock.AsyncMock,
     caplog: pytest.LogCaptureFixture,
+    faker: Faker,
 ):
     # clean first
     await remove_images_from_host([image])
@@ -121,6 +129,8 @@ async def test_pull_image(
     async with progress_bar.ProgressBarData(
         num_steps=layer_information.layers_total_size,
         progress_report_cb=mocked_progress_cb,
+        progress_unit="Byte",
+        description=faker.pystr(),
     ) as main_progress_bar:
         await pull_image(
             image,
@@ -130,10 +140,7 @@ async def test_pull_image(
             layer_information,
         )
         mocked_log_cb.assert_called()
-        assert (
-            main_progress_bar._current_steps  # noqa: SLF001
-            == layer_information.layers_total_size
-        )
+
     _assert_progress_report_values(
         mocked_progress_cb, total=layer_information.layers_total_size
     )
@@ -149,6 +156,8 @@ async def test_pull_image(
     async with progress_bar.ProgressBarData(
         num_steps=layer_information.layers_total_size,
         progress_report_cb=mocked_progress_cb,
+        description=faker.pystr(),
+        progress_unit="Byte",
     ) as main_progress_bar:
         await pull_image(
             image,
@@ -158,10 +167,7 @@ async def test_pull_image(
             layer_information,
         )
         mocked_log_cb.assert_called()
-        assert (
-            main_progress_bar._current_steps  # noqa: SLF001
-            == layer_information.layers_total_size
-        )
+
     _assert_progress_report_values(
         mocked_progress_cb, total=layer_information.layers_total_size
     )