feat: log package update events

docs/ahriman.core.repository.rst

@@ -12,6 +12,14 @@ ahriman.core.repository.cleaner module
    :no-undoc-members:
    :show-inheritance:
 
+ahriman.core.repository.event\_logger module
+--------------------------------------------
+
+.. automodule:: ahriman.core.repository.event_logger
+   :members:
+   :no-undoc-members:
+   :show-inheritance:
+
 ahriman.core.repository.executor module
 ---------------------------------------
 

src/ahriman/core/configuration/configuration.py

@@ -46,7 +46,8 @@ class Configuration(configparser.RawConfigParser):
     Examples:
         Configuration class provides additional method in order to handle application configuration. Since this class is
         derived from built-in :class:`configparser.RawConfigParser` class, the same flow is applicable here.
-        Nevertheless, it is recommended to use :func:`from_path` class method which also calls initialization methods::
+        Nevertheless, it is recommended to use :func:`from_path()` class method which also calls initialization
+        methods::
 
             >>> from pathlib import Path
             >>>
@@ -57,7 +58,7 @@ class Configuration(configparser.RawConfigParser):
         The configuration instance loaded in this way will contain only sections which are defined for the specified
         architecture according to the merge rules. Moreover, the architecture names will be removed from section names.
 
-        In order to get current settings, the :func:`check_loaded` method can be used. This method will raise an
+        In order to get current settings, the :func:`check_loaded()` method can be used. This method will raise an
         :exc:`ahriman.core.exceptions.InitializeError` in case if configuration was not yet loaded::
 
             >>> path, repository_id = configuration.check_loaded()
@@ -344,7 +345,8 @@ class Configuration(configparser.RawConfigParser):
 
     def set_option(self, section: str, option: str, value: str) -> None:
         """
-        set option. Unlike default :func:`configparser.RawConfigParser.set` it also creates section if it does not exist
+        set option. Unlike default :func:`configparser.RawConfigParser.set()` it also creates section if
+        it does not exist
 
         Args:
             section(str): section name

src/ahriman/core/log/http_log_handler.py

@@ -29,7 +29,8 @@ from ahriman.models.repository_id import RepositoryId
 class HttpLogHandler(logging.Handler):
     """
     handler for the http logging. Because default :class:`logging.handlers.HTTPHandler` does not support cookies
-    authorization, we have to implement own handler which overrides the :func:`logging.handlers.HTTPHandler.emit` method
+    authorization, we have to implement own handler which overrides the :func:`logging.handlers.HTTPHandler.emit()`
+    method
 
     Attributes:
         reporter(Client): build status reporter instance

src/ahriman/core/repository/event_logger.py

@@ -0,0 +1,84 @@
+#
+# Copyright (c) 2021-2024 ahriman team.
+#
+# This file is part of ahriman
+# (see https://github.com/arcan1s/ahriman).
+#
+# This program is free software: you can redistribute it and/or modify
+# it under the terms of the GNU General Public License as published by
+# the Free Software Foundation, either version 3 of the License, or
+# (at your option) any later version.
+#
+# This program is distributed in the hope that it will be useful,
+# but WITHOUT ANY WARRANTY; without even the implied warranty of
+# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+# GNU General Public License for more details.
+#
+# You should have received a copy of the GNU General Public License
+# along with this program. If not, see <http://www.gnu.org/licenses/>.
+#
+import contextlib
+
+from typing import Generator
+
+from ahriman.core.status import Client
+from ahriman.models.event import Event, EventType
+from ahriman.models.metrics_timer import MetricsTimer
+
+
+class EventLogger:
+    """
+    wrapper for logging events
+
+    Attributes:
+        reporter(Client): build status reporter instance
+    """
+
+    reporter: Client
+
+    def event(self, package_base: str, event: EventType, message: str | None = None) -> None:
+        """
+        log single event. For timed events use context manager :func:`in_event()` instead
+
+        Args:
+            package_base(str): package base name
+            event(EventType): event type to be logged on success action
+            message(str | None, optional): optional message describing the action (Default value = None)
+
+        Examples:
+            This method must be used as simple wrapper for :class:`ahriman.core.status.Client` methods, e.g.::
+
+                >>> do_something()
+                >>> self.event(package_base, EventType.PackageUpdated)
+        """
+        self.reporter.event_add(Event(event, package_base, message))
+
+    @contextlib.contextmanager
+    def in_event(self, package_base: str, event: EventType, message: str | None = None,
+                 failure: EventType | None = None) -> Generator[None, None, None]:
+        """
+        perform action in package context and log event with time elapsed
+
+        Args:
+            package_base(str): package base name
+            event(EventType): event type to be logged on success action
+            message(str | None, optional): optional message describing the action (Default value = None)
+            failure(EventType | None, optional): event type to be logged on exception (Default value = None)
+
+        Examples:
+            This method must be used to perform action in context with time measurement::
+
+                >>> with self.in_event(package_base, EventType.PackageUpdated):
+                >>>     do_something()
+
+            Additional parameter ``failure`` can be set in order to emit an event on exception occured. If none set
+            (default), then no event will be recorded on exception
+        """
+        with MetricsTimer() as timer:
+            try:
+                yield
+                self.reporter.event_add(Event(event, package_base, message, took=timer.elapsed))
+            except Exception:
+                if failure is not None:
+                    self.reporter.event_add(Event(failure, package_base, took=timer.elapsed))
+                raise

src/ahriman/core/repository/executor.py

@@ -29,6 +29,7 @@ from ahriman.core.repository.cleaner import Cleaner
 from ahriman.core.repository.package_info import PackageInfo
 from ahriman.core.utils import safe_filename
 from ahriman.models.changes import Changes
+from ahriman.models.event import EventType
 from ahriman.models.package import Package
 from ahriman.models.package_description import PackageDescription
 from ahriman.models.packagers import Packagers
@@ -75,16 +76,17 @@ class Executor(PackageInfo, Cleaner):
             with self.in_package_context(single.base, local_versions.get(single.base)), \
                     TemporaryDirectory(ignore_cleanup_errors=True) as dir_name:
                 try:
-                    packager = self.packager(packagers, single.base)
+                    with self.in_event(single.base, EventType.PackageUpdated, failure=EventType.PackageUpdateFailed):
-                    last_commit_sha = build_single(single, Path(dir_name), packager.packager_id)
+                        packager = self.packager(packagers, single.base)
-                    # clear changes and update commit hash
+                        last_commit_sha = build_single(single, Path(dir_name), packager.packager_id)
-                    self.reporter.package_changes_update(single.base, Changes(last_commit_sha))
+                        # clear changes and update commit hash
-                    # update dependencies list
+                        self.reporter.package_changes_update(single.base, Changes(last_commit_sha))
-                    package_archive = PackageArchive(self.paths.build_directory, single, self.pacman, self.scan_paths)
+                        # update dependencies list
-                    dependencies = package_archive.depends_on()
+                        package_archive = PackageArchive(self.paths.build_root, single, self.pacman, self.scan_paths)
-                    self.reporter.package_dependencies_update(single.base, dependencies)
+                        dependencies = package_archive.depends_on()
-                    # update result set
+                        self.reporter.package_dependencies_update(single.base, dependencies)
-                    result.add_updated(single)
+                        # update result set
+                        result.add_updated(single)
                 except Exception:
                     self.reporter.set_failed(single.base)
                     result.add_failed(single)
@@ -104,7 +106,8 @@ class Executor(PackageInfo, Cleaner):
         """
         def remove_base(package_base: str) -> None:
             try:
-                self.reporter.package_remove(package_base)
+                with self.in_event(package_base, EventType.PackageRemoved):
+                    self.reporter.package_remove(package_base)
             except Exception:
                 self.logger.exception("could not remove base %s", package_base)
 

src/ahriman/core/repository/repository_properties.py

@@ -22,6 +22,7 @@ from ahriman.core.alpm.repo import Repo
 from ahriman.core.configuration import Configuration
 from ahriman.core.database import SQLite
 from ahriman.core.log import LazyLogging
+from ahriman.core.repository.event_logger import EventLogger
 from ahriman.core.sign.gpg import GPG
 from ahriman.core.status import Client
 from ahriman.core.triggers import TriggerLoader
@@ -34,7 +35,7 @@ from ahriman.models.user import User
 from ahriman.models.user_access import UserAccess
 
 
-class RepositoryProperties(LazyLogging):
+class RepositoryProperties(EventLogger, LazyLogging):
     """
     repository internal objects holder
 

src/ahriman/core/repository/update_handler.py

@@ -23,6 +23,7 @@ from ahriman.core.build_tools.sources import Sources
 from ahriman.core.exceptions import UnknownPackageError
 from ahriman.core.repository.cleaner import Cleaner
 from ahriman.core.repository.package_info import PackageInfo
+from ahriman.models.event import EventType
 from ahriman.models.package import Package
 from ahriman.models.package_source import PackageSource
 from ahriman.models.remote_source import RemoteSource
@@ -71,6 +72,7 @@ class UpdateHandler(PackageInfo, Cleaner):
                             vcs_allowed_age=self.vcs_allowed_age,
                             calculate_version=vcs):
                         self.reporter.set_pending(local.base)
+                        self.event(local.base, EventType.PackageOutdated, "Remote version is newer than local")
                         result.append(remote)
                 except Exception:
                     self.reporter.set_failed(local.base)
@@ -98,8 +100,8 @@ class UpdateHandler(PackageInfo, Cleaner):
             return files
 
         result: list[Package] = []
-        for package in self.packages(filter_packages):
+        for local in self.packages(filter_packages):
-            dependencies = self.reporter.package_dependencies_get(package.base)
+            dependencies = self.reporter.package_dependencies_get(local.base)
             if not dependencies.paths:
                 continue  # skip check if no package dependencies found
 
@@ -112,7 +114,10 @@ class UpdateHandler(PackageInfo, Cleaner):
                     continue
 
                 # there are no packages found in filesystem with the same paths
-                result.append(package)
+                self.reporter.set_pending(local.base)
+                self.event(local.base, EventType.PackageOutdated, "Implicit dependencies are broken")
+                result.append(local)
+
                 break
 
         return result
@@ -153,6 +158,7 @@ class UpdateHandler(PackageInfo, Cleaner):
                                          vcs_allowed_age=self.vcs_allowed_age,
                                          calculate_version=vcs):
                         self.reporter.set_pending(local.base)
+                        self.event(local.base, EventType.PackageOutdated, "Locally pulled sources are outdated")
                         result.append(remote)
                 except Exception:
                     self.logger.exception("could not process package at %s", cache_dir)
@@ -176,6 +182,7 @@ class UpdateHandler(PackageInfo, Cleaner):
                     self.reporter.set_unknown(local)
                 else:
                     self.reporter.set_pending(local.base)
+                self.event(local.base, EventType.PackageOutdated, "Manual update is requested")
         except Exception:
             self.logger.exception("could not load packages from database")
         self.clear_queue()

src/ahriman/core/upload/upload.py

@@ -39,14 +39,15 @@ class Upload(LazyLogging):
 
     Examples:
         These classes provide the way to upload packages to remote sources as it is described in their implementations.
-        Basic flow includes class instantiating by using the :func:`load` method and then calling the :func:`run` method
+        Basic flow includes class instantiating by using the :func:`load()` method and then calling the :func:`run()`
-        which wraps any internal exceptions into the :exc:`ahriman.core.exceptions.SynchronizationError` exception::
+        method which wraps any internal exceptions into the :exc:`ahriman.core.exceptions.SynchronizationError`
+        exception::
 
             >>> configuration = Configuration()
             >>> upload = Upload.load(RepositoryId("x86_64", "aur-clone"), configuration, "s3")
             >>> upload.run(configuration.repository_paths.repository, [])
 
-        Or in case if direct access to exception is required, the :func:`sync` method can be used::
+        Or in case if direct access to exception is required, the :func:`sync()` method can be used::
 
             >>> try:
             >>>     upload.sync(configuration.repository_paths.repository, [])

src/ahriman/models/repository_paths.py

@@ -85,7 +85,7 @@ class RepositoryPaths(LazyLogging):
         return Path(self.repository_id.name) / self.repository_id.architecture
 
     @property
-    def build_directory(self) -> Path:
+    def build_root(self) -> Path:
         """
         same as :attr:`chroot`, but exactly build chroot
 

tests/ahriman/core/build_tools/conftest.py

@@ -29,7 +29,7 @@ def package_archive_ahriman(package_ahriman: Package, repository_paths: Reposito
         PackageArchive: package archive test instance
     """
     mocker.patch("ahriman.models.repository_paths.getpwuid", return_value=passwd)
-    return PackageArchive(repository_paths.build_directory, package_ahriman, pacman, scan_paths)
+    return PackageArchive(repository_paths.build_root, package_ahriman, pacman, scan_paths)
 
 
 @pytest.fixture

tests/ahriman/core/repository/test_event_logger.py

@@ -0,0 +1,58 @@
+import pytest
+
+from pytest_mock import MockerFixture
+
+from ahriman.core.repository.event_logger import EventLogger
+from ahriman.models.event import Event, EventType
+
+
+def test_event(repository: EventLogger, mocker: MockerFixture) -> None:
+    """
+    must log event
+    """
+    event = Event(EventType.PackageUpdated, "base", "message", created=pytest.helpers.anyvar(int, True))
+    event_mock = mocker.patch("ahriman.core.status.local_client.LocalClient.event_add")
+
+    repository.event(event.object_id, event.event, event.message)
+    event_mock.assert_called_once_with(event)
+
+
+def test_in_event(repository: EventLogger, mocker: MockerFixture) -> None:
+    """
+    must log success action
+    """
+    event = Event(EventType.PackageUpdated, "base", "message",
+                  created=pytest.helpers.anyvar(int, True), took=pytest.helpers.anyvar(float, True))
+    event_mock = mocker.patch("ahriman.core.status.local_client.LocalClient.event_add")
+
+    with repository.in_event(event.object_id, event.event, event.message):
+        pass
+    event_mock.assert_called_once_with(event)
+
+
+def test_in_event_exception(repository: EventLogger, mocker: MockerFixture) -> None:
+    """
+    must reraise exception in context
+    """
+    event = Event(EventType.PackageUpdated, "base", "message",
+                  created=pytest.helpers.anyvar(int, True), took=pytest.helpers.anyvar(float, True))
+    event_mock = mocker.patch("ahriman.core.status.local_client.LocalClient.event_add")
+
+    with pytest.raises(Exception):
+        with repository.in_event(event.object_id, event.event, event.message):
+            raise Exception
+    event_mock.assert_not_called()
+
+
+def test_in_event_exception_event(repository: EventLogger, mocker: MockerFixture) -> None:
+    """
+    must reraise exception in context and emit new event
+    """
+    event = Event(EventType.PackageUpdateFailed, "base", created=pytest.helpers.anyvar(int, True),
+                  took=pytest.helpers.anyvar(float, True))
+    event_mock = mocker.patch("ahriman.core.status.local_client.LocalClient.event_add")
+
+    with pytest.raises(Exception):
+        with repository.in_event(event.object_id, EventType.PackageUpdated, failure=event.event):
+            raise Exception
+    event_mock.assert_called_once_with(event)

tests/ahriman/core/repository/test_update_handler.py

@@ -7,6 +7,7 @@ from typing import Any
 from ahriman.core.exceptions import UnknownPackageError
 from ahriman.core.repository.update_handler import UpdateHandler
 from ahriman.models.dependencies import Dependencies
+from ahriman.models.event import EventType
 from ahriman.models.package import Package
 from ahriman.models.package_source import PackageSource
 from ahriman.models.remote_source import RemoteSource
@@ -21,11 +22,14 @@ def test_updates_aur(update_handler: UpdateHandler, package_ahriman: Package,
                                  return_value=[package_ahriman])
     mocker.patch("ahriman.models.package.Package.from_aur", return_value=package_ahriman)
     status_client_mock = mocker.patch("ahriman.core.status.Client.set_pending")
+    event_mock = mocker.patch("ahriman.core.repository.update_handler.UpdateHandler.event")
     package_is_outdated_mock = mocker.patch("ahriman.models.package.Package.is_outdated", return_value=True)
 
     assert update_handler.updates_aur([], vcs=True) == [package_ahriman]
     packages_mock.assert_called_once_with([])
     status_client_mock.assert_called_once_with(package_ahriman.base)
+    event_mock.assert_called_once_with(package_ahriman.base, EventType.PackageOutdated,
+                                       pytest.helpers.anyvar(str, True))
     package_is_outdated_mock.assert_called_once_with(
         package_ahriman, update_handler.paths,
         vcs_allowed_age=update_handler.vcs_allowed_age,
@@ -42,9 +46,12 @@ def test_updates_aur_official(update_handler: UpdateHandler, package_ahriman: Pa
     mocker.patch("ahriman.models.package.Package.is_outdated", return_value=True)
     mocker.patch("ahriman.models.package.Package.from_official", return_value=package_ahriman)
     status_client_mock = mocker.patch("ahriman.core.status.Client.set_pending")
+    event_mock = mocker.patch("ahriman.core.repository.update_handler.UpdateHandler.event")
 
     assert update_handler.updates_aur([], vcs=True) == [package_ahriman]
     status_client_mock.assert_called_once_with(package_ahriman.base)
+    event_mock.assert_called_once_with(package_ahriman.base, EventType.PackageOutdated,
+                                       pytest.helpers.anyvar(str, True))
 
 
 def test_updates_aur_failed(update_handler: UpdateHandler, package_ahriman: Package,
@@ -153,6 +160,8 @@ def test_updates_dependencies(update_handler: UpdateHandler, package_ahriman: Pa
     """
     packages_mock = mocker.patch("ahriman.core.repository.update_handler.UpdateHandler.packages",
                                  return_value=[package_ahriman, package_python_schedule])
+    status_client_mock = mocker.patch("ahriman.core.status.Client.set_pending")
+    event_mock = mocker.patch("ahriman.core.repository.update_handler.UpdateHandler.event")
     dependencies = {
         package_ahriman.base: Dependencies({"usr/lib/python3.11/site-packages": ["python"]}),
         package_python_schedule.base: Dependencies({"usr/lib/python3.12/site-packages": ["python"]}),
@@ -164,6 +173,9 @@ def test_updates_dependencies(update_handler: UpdateHandler, package_ahriman: Pa
 
     assert update_handler.updates_dependencies(["filter"]) == [package_ahriman]
     packages_mock.assert_called_once_with(["filter"])
+    status_client_mock.assert_called_once_with(package_ahriman.base)
+    event_mock.assert_called_once_with(package_ahriman.base, EventType.PackageOutdated,
+                                       pytest.helpers.anyvar(str, True))
 
 
 def test_updates_dependencies_skip_unknown(update_handler: UpdateHandler, package_ahriman: Package,
@@ -205,12 +217,15 @@ def test_updates_local(update_handler: UpdateHandler, package_ahriman: Package,
     fetch_mock = mocker.patch("ahriman.core.build_tools.sources.Sources.fetch")
     package_load_mock = mocker.patch("ahriman.models.package.Package.from_build", return_value=package_ahriman)
     status_client_mock = mocker.patch("ahriman.core.status.Client.set_pending")
+    event_mock = mocker.patch("ahriman.core.repository.update_handler.UpdateHandler.event")
     package_is_outdated_mock = mocker.patch("ahriman.models.package.Package.is_outdated", return_value=True)
 
     assert update_handler.updates_local(vcs=True) == [package_ahriman]
     fetch_mock.assert_called_once_with(Path(package_ahriman.base), pytest.helpers.anyvar(int))
     package_load_mock.assert_called_once_with(Path(package_ahriman.base), "x86_64", None)
     status_client_mock.assert_called_once_with(package_ahriman.base)
+    event_mock.assert_called_once_with(package_ahriman.base, EventType.PackageOutdated,
+                                       pytest.helpers.anyvar(str, True))
     package_is_outdated_mock.assert_called_once_with(
         package_ahriman, update_handler.paths,
         vcs_allowed_age=update_handler.vcs_allowed_age,
@@ -281,9 +296,12 @@ def test_updates_manual_status_known(update_handler: UpdateHandler, package_ahri
     mocker.patch("ahriman.core.database.SQLite.build_queue_get", return_value=[package_ahriman])
     mocker.patch("ahriman.core.repository.update_handler.UpdateHandler.packages", return_value=[package_ahriman])
     status_client_mock = mocker.patch("ahriman.core.status.Client.set_pending")
+    event_mock = mocker.patch("ahriman.core.repository.update_handler.UpdateHandler.event")
 
     update_handler.updates_manual()
     status_client_mock.assert_called_once_with(package_ahriman.base)
+    event_mock.assert_called_once_with(package_ahriman.base, EventType.PackageOutdated,
+                                       pytest.helpers.anyvar(str, True))
 
 
 def test_updates_manual_status_unknown(update_handler: UpdateHandler, package_ahriman: Package,
@@ -294,9 +312,12 @@ def test_updates_manual_status_unknown(update_handler: UpdateHandler, package_ah
     mocker.patch("ahriman.core.database.SQLite.build_queue_get", return_value=[package_ahriman])
     mocker.patch("ahriman.core.repository.update_handler.UpdateHandler.packages", return_value=[])
     status_client_mock = mocker.patch("ahriman.core.status.Client.set_unknown")
+    event_mock = mocker.patch("ahriman.core.repository.update_handler.UpdateHandler.event")
 
     update_handler.updates_manual()
     status_client_mock.assert_called_once_with(package_ahriman)
+    event_mock.assert_called_once_with(package_ahriman.base, EventType.PackageOutdated,
+                                       pytest.helpers.anyvar(str, True))
 
 
 def test_updates_manual_with_failures(update_handler: UpdateHandler, package_ahriman: Package,

tests/ahriman/models/test_repository_paths.py

@@ -283,7 +283,7 @@ def test_tree_create(repository_paths: RepositoryPaths, mocker: MockerFixture) -
         for prop in dir(repository_paths)
         if not prop.startswith("_")
         and prop not in (
-            "build_directory",
+            "build_root",
             "logger_name",
             "logger",
             "repository_id",