set package context in main functions

src/ahriman/core/log/lazy_logging.py

@@ -17,9 +17,10 @@
 # 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
 import logging
 
-from typing import Any
+from typing import Any, Generator
 
 
 class LazyLogging:
@@ -63,14 +64,15 @@ class LazyLogging:
         prefix = "" if clazz.__module__ is None else f"{clazz.__module__}."
         return f"{prefix}{clazz.__qualname__}"
 
-    def package_logger_reset(self) -> None:
+    @staticmethod
+    def _package_logger_reset() -> None:
         """
         reset package logger to empty one
         """
-        self.logger.debug("reset package logging")
         logging.setLogRecordFactory(logging.LogRecord)
 
-    def package_logger_set(self, package_base: str) -> None:
+    @staticmethod
+    def _package_logger_set(package_base: str) -> None:
         """
         set package base as extra info to the logger
 
@@ -85,4 +87,23 @@ class LazyLogging:
             return record
 
         logging.setLogRecordFactory(package_record_factory)
-        self.logger.debug("start package %s logging", package_base)
+
+    @contextlib.contextmanager
+    def in_package_context(self, package_base: str) -> Generator[None, None, None]:
+        """
+        execute function while setting package context
+
+        Args:
+            package_base(str): package base to set context in
+
+        Examples:
+            This function is designed to be called as context manager with ``package_base`` argument, e.g.:
+
+                >>> with self.in_package_context(package.base):
+                >>>     build_package(package)
+        """
+        try:
+            self._package_logger_set(package_base)
+            yield
+        finally:
+            self._package_logger_reset()

src/ahriman/core/repository/executor.py

@@ -84,7 +84,8 @@ class Executor(Cleaner):
 
         result = Result()
         for single in updates:
-            with TemporaryDirectory(ignore_cleanup_errors=True) as dir_name, (build_dir := Path(dir_name)):
+            with self.in_package_context(single.base), \
+                    TemporaryDirectory(ignore_cleanup_errors=True) as dir_name, (build_dir := Path(dir_name)):
                 try:
                     build_single(single, build_dir)
                     result.add_success(single)
@@ -110,6 +111,7 @@ class Executor(Cleaner):
                 self.paths.tree_clear(package_base)  # remove all internal files
                 self.database.build_queue_clear(package_base)
                 self.database.patches_remove(package_base, [])
+                self.database.logs_remove(package_base, None)
                 self.reporter.remove(package_base)  # we only update status page in case of base removal
             except Exception:
                 self.logger.exception("could not remove base %s", package_base)
@@ -180,24 +182,25 @@ class Executor(Cleaner):
 
         result = Result()
         for local in updates:
-            try:
-                for description in local.packages.values():
-                    rename(description, local.base)
-                    update_single(description.filename, local.base)
-                self.reporter.set_success(local)
-                result.add_success(local)
+            with self.in_package_context(local.base):
+                try:
+                    for description in local.packages.values():
+                        rename(description, local.base)
+                        update_single(description.filename, local.base)
+                    self.reporter.set_success(local)
+                    result.add_success(local)
 
-                current_package_archives = {
-                    package
-                    for current in current_packages
-                    if current.base == local.base
-                    for package in current.packages
-                }
-                removed_packages.extend(current_package_archives.difference(local.packages))
-            except Exception:
-                self.reporter.set_failed(local.base)
-                result.add_failed(local)
-                self.logger.exception("could not process %s", local.base)
+                    current_package_archives = {
+                        package
+                        for current in current_packages
+                        if current.base == local.base
+                        for package in current.packages
+                    }
+                    removed_packages.extend(current_package_archives.difference(local.packages))
+                except Exception:
+                    self.reporter.set_failed(local.base)
+                    result.add_failed(local)
+                    self.logger.exception("could not process %s", local.base)
         self.clear_packages()
 
         self.process_remove(removed_packages)

src/ahriman/core/repository/update_handler.py

@@ -56,26 +56,26 @@ class UpdateHandler(Cleaner):
         result: List[Package] = []
 
         for local in self.packages():
-            if local.base in self.ignore_list:
-                continue
-            if local.is_vcs and not vcs:
-                continue
-            if filter_packages and local.base not in filter_packages:
-                continue
-            source = local.remote.source if local.remote is not None else None
+            with self.in_package_context(local.base):
+                if local.base in self.ignore_list:
+                    continue
+                if local.is_vcs and not vcs:
+                    continue
+                if filter_packages and local.base not in filter_packages:
+                    continue
+                source = local.remote.source if local.remote is not None else None
 
-            try:
-                if source == PackageSource.Repository:
-                    remote = Package.from_official(local.base, self.pacman)
-                else:
-                    remote = Package.from_aur(local.base, self.pacman)
-                if local.is_outdated(remote, self.paths):
-                    self.reporter.set_pending(local.base)
-                    result.append(remote)
-            except Exception:
-                self.reporter.set_failed(local.base)
-                self.logger.exception("could not load remote package %s", local.base)
-                continue
+                try:
+                    if source == PackageSource.Repository:
+                        remote = Package.from_official(local.base, self.pacman)
+                    else:
+                        remote = Package.from_aur(local.base, self.pacman)
+                    if local.is_outdated(remote, self.paths):
+                        self.reporter.set_pending(local.base)
+                        result.append(remote)
+                except Exception:
+                    self.reporter.set_failed(local.base)
+                    self.logger.exception("could not load remote package %s", local.base)
 
         return result
 
@@ -90,19 +90,20 @@ class UpdateHandler(Cleaner):
         packages = {local.base: local for local in self.packages()}
 
         for cache_dir in self.paths.cache.iterdir():
-            try:
-                Sources.fetch(cache_dir, remote=None)
-                remote = Package.from_build(cache_dir)
+            with self.in_package_context(cache_dir.name):
+                try:
+                    Sources.fetch(cache_dir, remote=None)
+                    remote = Package.from_build(cache_dir)
 
-                local = packages.get(remote.base)
-                if local is None:
-                    self.reporter.set_unknown(remote)
-                    result.append(remote)
-                elif local.is_outdated(remote, self.paths):
-                    self.reporter.set_pending(local.base)
-                    result.append(remote)
-            except Exception:
-                self.logger.exception("could not process package at %s", cache_dir)
+                    local = packages.get(remote.base)
+                    if local is None:
+                        self.reporter.set_unknown(remote)
+                        result.append(remote)
+                    elif local.is_outdated(remote, self.paths):
+                        self.reporter.set_pending(local.base)
+                        result.append(remote)
+                except Exception:
+                    self.logger.exception("could not process package at %s", cache_dir)
 
         return result
 

tests/ahriman/core/log/test_lazy_logging.py

@@ -1,8 +1,11 @@
 import logging
 import pytest
 
+from pytest_mock import MockerFixture
+
 from ahriman.core.alpm.repo import Repo
 from ahriman.core.database import SQLite
+from ahriman.models.package import Package
 
 
 def test_logger(database: SQLite) -> None:
@@ -35,11 +38,39 @@ def test_package_logger_set_reset(database: SQLite) -> None:
     """
     package_base = "package base"
 
-    database.package_logger_set(package_base)
+    database._package_logger_set(package_base)
     record = logging.makeLogRecord({})
     assert record.package_base == package_base
 
-    database.package_logger_reset()
+    database._package_logger_reset()
     record = logging.makeLogRecord({})
     with pytest.raises(AttributeError):
         record.package_base
+
+
+def test_in_package_context(database: SQLite, package_ahriman: Package, mocker: MockerFixture) -> None:
+    """
+    must set package log context
+    """
+    set_mock = mocker.patch("ahriman.core.log.LazyLogging._package_logger_set")
+    reset_mock = mocker.patch("ahriman.core.log.LazyLogging._package_logger_reset")
+
+    with database.in_package_context(package_ahriman.base):
+        pass
+
+    set_mock.assert_called_once_with(package_ahriman.base)
+    reset_mock.assert_called_once_with()
+
+
+def test_in_package_context_failed(database: SQLite, package_ahriman: Package, mocker: MockerFixture) -> None:
+    """
+    must reset package context even if exception occurs
+    """
+    mocker.patch("ahriman.core.log.LazyLogging._package_logger_set")
+    reset_mock = mocker.patch("ahriman.core.log.LazyLogging._package_logger_reset")
+
+    with pytest.raises(Exception):
+        with database.in_package_context(package_ahriman.base):
+            raise Exception()
+
+    reset_mock.assert_called_once_with()

tests/ahriman/core/repository/test_executor.py

@@ -63,6 +63,7 @@ def test_process_remove_base(executor: Executor, package_ahriman: Package, mocke
     repo_remove_mock = mocker.patch("ahriman.core.alpm.repo.Repo.remove")
     build_queue_mock = mocker.patch("ahriman.core.database.SQLite.build_queue_clear")
     patches_mock = mocker.patch("ahriman.core.database.SQLite.patches_remove")
+    logs_mock = mocker.patch("ahriman.core.database.SQLite.logs_remove")
     status_client_mock = mocker.patch("ahriman.core.status.client.Client.remove")
 
     executor.process_remove([package_ahriman.base])
@@ -73,6 +74,7 @@ def test_process_remove_base(executor: Executor, package_ahriman: Package, mocke
     tree_clear_mock.assert_called_once_with(package_ahriman.base)
     build_queue_mock.assert_called_once_with(package_ahriman.base)
     patches_mock.assert_called_once_with(package_ahriman.base, [])
+    logs_mock.assert_called_once_with(package_ahriman.base, None)
     status_client_mock.assert_called_once_with(package_ahriman.base)
 
 

tests/ahriman/core/repository/test_update_handler.py

@@ -1,5 +1,6 @@
 import pytest
 
+from pathlib import Path
 from pytest_mock import MockerFixture
 
 from ahriman.core.repository.update_handler import UpdateHandler
@@ -103,15 +104,15 @@ def test_updates_local(update_handler: UpdateHandler, package_ahriman: Package,
     must check for updates for locally stored packages
     """
     mocker.patch("ahriman.core.repository.update_handler.UpdateHandler.packages", return_value=[package_ahriman])
-    mocker.patch("pathlib.Path.iterdir", return_value=[package_ahriman.base])
+    mocker.patch("pathlib.Path.iterdir", return_value=[Path(package_ahriman.base)])
     mocker.patch("ahriman.models.package.Package.is_outdated", return_value=True)
     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.Client.set_pending")
 
     assert update_handler.updates_local() == [package_ahriman]
-    fetch_mock.assert_called_once_with(package_ahriman.base, remote=None)
-    package_load_mock.assert_called_once_with(package_ahriman.base)
+    fetch_mock.assert_called_once_with(Path(package_ahriman.base), remote=None)
+    package_load_mock.assert_called_once_with(Path(package_ahriman.base))
     status_client_mock.assert_called_once_with(package_ahriman.base)
 
 
@@ -120,7 +121,7 @@ def test_updates_local_unknown(update_handler: UpdateHandler, package_ahriman: P
     must return unknown package as out-dated
     """
     mocker.patch("ahriman.core.repository.update_handler.UpdateHandler.packages", return_value=[])
-    mocker.patch("pathlib.Path.iterdir", return_value=[package_ahriman.base])
+    mocker.patch("pathlib.Path.iterdir", return_value=[Path(package_ahriman.base)])
     mocker.patch("ahriman.models.package.Package.is_outdated", return_value=True)
     mocker.patch("ahriman.core.build_tools.sources.Sources.fetch")
     mocker.patch("ahriman.models.package.Package.from_build", return_value=package_ahriman)
@@ -136,7 +137,7 @@ def test_updates_local_with_failures(update_handler: UpdateHandler, package_ahri
     must process local through the packages with failure
     """
     mocker.patch("ahriman.core.repository.update_handler.UpdateHandler.packages")
-    mocker.patch("pathlib.Path.iterdir", return_value=[package_ahriman.base])
+    mocker.patch("pathlib.Path.iterdir", return_value=[Path(package_ahriman.base)])
     mocker.patch("ahriman.core.build_tools.sources.Sources.fetch", side_effect=Exception())
 
     assert not update_handler.updates_local()