add Pydantic models for borg 1.4's CLI output, incomplete tests (#8338)

Author: a-gn

requirements.d/development.txt

@@ -12,3 +12,4 @@ pytest-cov
 pytest-benchmark
 Cython
 pre-commit
+pydantic>=2.0

src/borg/helpers/progress.py

@@ -1,10 +1,12 @@
-import logging
 import json
+import logging
 import sys
 import time
+import typing
 from shutil import get_terminal_size
 
 from ..logger import create_logger
+
 logger = create_logger()
 
 from .parseformat import ellipsis_truncate
@@ -75,7 +77,7 @@ def __del__(self):
             self.logger.removeHandler(self.handler)
             self.handler.close()
 
-    def output_json(self, *, finished=False, **kwargs):
+    def output_json(self, *, finished=False, override_time: typing.Optional[float] = None, **kwargs):
         assert self.json
         if not self.emit:
             return
@@ -84,7 +86,7 @@ def output_json(self, *, finished=False, **kwargs):
             msgid=self.msgid,
             type=self.JSON_TYPE,
             finished=finished,
-            time=time.time(),
+            time=override_time if override_time is not None else time.time(),
         ))
         print(json.dumps(kwargs), file=sys.stderr, flush=True)
 

src/borg/public/cli_api/v1.py

@@ -0,0 +1,161 @@
+"""Pydantic models that can parse borg 1.x's JSON output.
+
+The two top-level models are:
+
+- `BorgLogLine`, which parses any line of borg's logging output,
+- all `Borg*Result` classes, which parse the final JSON output of some borg commands.
+
+The different types of log lines are defined in the other models.
+"""
+
+import json
+import logging
+import typing
+from datetime import datetime
+from pathlib import Path
+
+import pydantic
+import typing_extensions
+
+_log = logging.getLogger(__name__)
+
+
+class BaseBorgLogLine(pydantic.BaseModel):
+    def get_level(self) -> int:
+        """Get the log level for this line as a `logging` level value.
+
+        If this is a log message with a levelname, use it.
+        Otherwise, progress messages get `DEBUG` level, and other messages get `INFO`.
+        """
+        return logging.DEBUG
+
+
+class ArchiveProgressLogLine(BaseBorgLogLine):
+    original_size: int
+    compressed_size: int
+    deduplicated_size: int
+    nfiles: int
+    path: Path
+    time: float
+
+
+class FinishedArchiveProgress(BaseBorgLogLine):
+    """JSON object printed on stdout when an archive is finished."""
+
+    time: float
+    type: typing.Literal["archive_progress"]
+    finished: bool
+
+
+class ProgressMessage(BaseBorgLogLine):
+    operation: int
+    msgid: typing.Optional[str]
+    finished: bool
+    message: typing.Optional[str]
+    time: float
+
+
+class ProgressPercent(BaseBorgLogLine):
+    operation: int
+    msgid: str | None = pydantic.Field(None)
+    finished: bool
+    message: str | None = pydantic.Field(None)
+    current: float | None = pydantic.Field(None)
+    info: list[str] | None = pydantic.Field(None)
+    total: float | None = pydantic.Field(None)
+    time: float
+
+    @pydantic.model_validator(mode="after")
+    def fields_depending_on_finished(self) -> typing_extensions.Self:
+        if self.finished:
+            if self.message is not None:
+                raise ValueError("message must be None if finished is True")
+            if self.current is not None and self.total is not None and self.current != self.total:
+                raise ValueError("current must be equal to total if finished is True")
+            if self.info is not None:
+                raise ValueError("info must be None if finished is True")
+            if self.total is not None:
+                raise ValueError("total must be None if finished is True")
+        return self
+
+
+class FileStatus(BaseBorgLogLine):
+    status: str
+    path: Path
+
+
+class LogMessage(BaseBorgLogLine):
+    time: float
+    levelname: typing.Literal["DEBUG", "INFO", "WARNING", "ERROR", "CRITICAL"]
+    name: str
+    message: str
+    msgid: typing.Optional[str]
+
+    def get_level(self) -> int:
+        try:
+            return getattr(logging, self.levelname)
+        except AttributeError:
+            _log.warning(
+                "could not find log level %s, giving the following message WARNING level: %s",
+                self.levelname,
+                json.dumps(self),
+            )
+            return logging.WARNING
+
+
+_BorgLogLinePossibleTypes = (
+    ArchiveProgressLogLine | FinishedArchiveProgress | ProgressMessage | ProgressPercent | FileStatus | LogMessage
+)
+
+
+class BorgLogLine(pydantic.RootModel[_BorgLogLinePossibleTypes]):
+    """A log line from Borg with the `--log-json` argument."""
+
+    def get_level(self) -> int:
+        return self.root.get_level()
+
+
+class _BorgArchive(pydantic.BaseModel):
+    """Basic archive attributes."""
+
+    name: str
+    id: str
+    start: datetime
+
+
+class _BorgArchiveStatistics(pydantic.BaseModel):
+    """Statistics of an archive."""
+
+    original_size: int
+    compressed_size: int
+    deduplicated_size: int
+    nfiles: int
+
+
+class _BorgLimitUsage(pydantic.BaseModel):
+    """Usage of borg limits by an archive."""
+
+    max_archive_size: float
+
+
+class _BorgDetailedArchive(_BorgArchive):
+    """Archive attributes, as printed by `json info` or `json create`."""
+
+    end: datetime
+    duration: float
+    stats: _BorgArchiveStatistics
+    limits: _BorgLimitUsage
+    command_line: typing.List[str]
+    chunker_params: typing.Any | None = None
+
+
+class BorgCreateResult(pydantic.BaseModel):
+    """JSON object printed at the end of `borg create`."""
+
+    archive: _BorgDetailedArchive
+
+
+class BorgListResult(pydantic.BaseModel):
+    """JSON object printed at the end of `borg list`."""
+
+    archives: typing.List[_BorgArchive]

src/borg/testsuite/public/cli_api.py

@@ -0,0 +1,48 @@
+from unittest.mock import patch
+
+import pytest
+
+import borg.public.cli_api.v1 as v1
+from borg.helpers.progress import ProgressIndicatorBase
+
+
+@pytest.fixture(autouse=True)
+def reset_progress_operation_id():
+    """Reset ProgressIndicatorBase operation ID counter after each test.
+
+    This ensures each test gets predictable operation IDs starting from 1.
+    """
+    yield
+    ProgressIndicatorBase.operation_id_counter = 0
+
+
+def test_parse_progress_percent_unfinished():
+    percent = ProgressIndicatorBase()
+    percent.json = True
+    percent.emit = True
+    override_time = 4567.23
+
+    with patch("builtins.print") as mock_print:
+        percent.output_json(finished=False, current=10, override_time=override_time)
+        mock_print.assert_called_once()
+        json_output = mock_print.call_args[0][0]
+
+    assert v1.ProgressPercent.model_validate_json(json_output) == v1.ProgressPercent(
+        operation=1, msgid=None, finished=False, message=None, current=10, info=None, total=None, time=4567.23
+    )
+
+
+def test_parse_progress_percent_finished():
+    percent = ProgressIndicatorBase()
+    percent.json = True
+    percent.emit = True
+    override_time = 4567.23
+
+    with patch("builtins.print") as mock_print:
+        percent.output_json(finished=True, override_time=override_time)
+        mock_print.assert_called_once()
+        json_output = mock_print.call_args[0][0]
+
+    assert v1.ProgressPercent.model_validate_json(json_output) == v1.ProgressPercent(
+        operation=1, msgid=None, finished=True, message=None, current=None, info=None, total=None, time=override_time
+    )