Merge pull request #287 from thegridelectric/dev

Logging refinements

pyproject.toml

@@ -1,6 +1,6 @@
 [tool.poetry]
 name = "gridworks-proactor"
-version = "1.1.4"
+version = "1.1.5"
 description = "Gridworks Proactor"
 authors = ["Jessica Millar <[email protected]>"]
 license = "MIT"

src/gwproactor/links/reuploads.py

@@ -154,7 +154,7 @@ def process_ack_for_reupload(self, ack_id: str) -> list[str]:
             path_dbg |= 0x00000008
             self.stats.complete_reupload()
             self._logger.comm_event(
-                f"Reupload completed. Total started: {self.stats.reupload_counts.started}  "
+                f"Reupload completed. Reuploads started: {self.stats.reupload_counts.started}  "
                 f"completed: {self.stats.reupload_counts.completed}."
             )
         if self._logger.path_enabled:

src/gwproactor/logger.py

@@ -214,18 +214,31 @@ def add_category_logger(
                     "ERROR. add_category_logger() requires category value "
                     "unless logger is provided."
                 )
-            logger = logging.getLogger(self.category_logger_name(category))
-            logger.setLevel(level)
+            logger = self.category_logger(category)
+            if logger is None:
+                logger = logging.getLogger(self.category_logger_name(category))
+                logger.setLevel(level)
+                self.category_loggers[category] = CategoryLoggerInfo(
+                    logger=logger,
+                    default_level=level,
+                )
         else:
-            category = logger.name
-            self_prefix = f"{self.name}."
-            if category.startswith(self_prefix):
-                category = category[len(self_prefix) :]
+            if not category:
+                category = logger.name
+                self_prefix = f"{self.name}."
+                if category.startswith(self_prefix):
+                    category = category[len(self_prefix) :]
+            if category in self.category_loggers:
+                raise ValueError(
+                    "ERROR. add_category_logger() got explicit logger "
+                    f"named {logger.name}, categorized as {category}, but "
+                    f"logger for that category is already present."
+                )
             level = logger.getEffectiveLevel()
-        self.category_loggers[category] = CategoryLoggerInfo(
-            logger=logger,
-            default_level=level,
-        )
+            self.category_loggers[category] = CategoryLoggerInfo(
+                logger=logger,
+                default_level=level,
+            )
         return logger
 
     def reset_default_category_levels(self) -> None:

src/gwproactor/persister.py

@@ -100,6 +100,11 @@ def pending_ids(self) -> list[str]:
     def num_pending(self) -> int:
         """Get number of pending uids"""
 
+    @property
+    @abstractmethod
+    def curr_bytes(self) -> int:
+        """Return number of bytes used to store events, if known."""
+
     @abstractmethod
     def __contains__(self, uid: str) -> bool:
         """Check whether a uid is pending"""
@@ -132,6 +137,10 @@ def pending_ids(self) -> list[str]:
     def num_pending(self) -> int:
         return 0
 
+    @property
+    def curr_bytes(self) -> int:
+        return 0
+
     def __contains__(self, uid: str) -> bool:
         return False
 

src/gwproactor/proactor_implementation.py

@@ -119,12 +119,18 @@ def __init__(
             )
         self._layout = hardware_layout
         self._node = self._layout.node(name)
-        self._logger = ProactorLogger(**settings.logging.qualified_logger_names())
+        self._logger = self.make_logger(settings)
         self._stats = self.make_stats()
         self._event_persister = self.make_event_persister(settings)
-        self._logger.lifecycle(f"Proactor {self._name} reindexing events")
+        self._logger.lifecycle(f"Proactor <{self._name}> reindexing events")
         reindex_result = self._event_persister.reindex()
-        self._logger.lifecycle(f"Proactor {self._name} reindexing complete")
+        self._logger.lifecycle(
+            f"Proactor <{self._name}> reindexing complete.\n"
+            f"  {self._event_persister.num_pending} events present for upload, "
+            f"using approximately {int(self._event_persister.curr_bytes / 1024)} KB / "
+            f"{round(self._event_persister.curr_bytes / 1024 / 1024, 1)} MB "
+            f"storage space."
+        )
         if reindex_result.is_err():
             self._reindex_problems = reindex_result.err()
             self._logger.error("ERROR in event persister reindex():")
@@ -161,6 +167,10 @@ def __init__(
     def make_stats(cls) -> ProactorStats:
         return ProactorStats()
 
+    @classmethod
+    def make_logger(cls, settings: ProactorSettings) -> ProactorLogger:
+        return ProactorLogger(**settings.logging.qualified_logger_names())
+
     @classmethod
     def make_event_persister(cls, settings: ProactorSettings) -> PersisterInterface:  # noqa: ARG003
         return StubPersister()

src/gwproactor/problems.py

@@ -51,10 +51,7 @@ def __str__(self) -> str:
                 if lst:
                     s += f"\n{attr_name.capitalize()}:\n"
                     for i, entry in enumerate(lst):
-                        entry_str = str(entry)
-                        if not entry_str:
-                            entry_str = entry.__class__.__name__
-                        s += f"  {i:2d}: {entry_str}\n"
+                        s += f"  {i:2d}: <{entry.__class__.__name__}>  " f"<{entry}>\n"
             return s
         return ""
 

src/gwproactor/sync_thread.py

@@ -1,13 +1,15 @@
 """Classes providing interaction between synchronous and asynchronous code"""
 
 import asyncio
+import logging
 import queue
 import threading
 import time
 import traceback
 from abc import ABC
 from typing import Any, Optional
 
+from gwproactor.logger import LoggerOrAdapter
 from gwproactor.message import InternalShutdownMessage, PatInternalWatchdogMessage
 
 DEFAULT_STEP_DURATION = 0.1
@@ -141,6 +143,7 @@ class SyncAsyncInteractionThread(threading.Thread, ABC):
     _responsive_sleep_step_seconds: float
     pat_timeout: Optional[float]
     _last_pat_time: float
+    _logger: LoggerOrAdapter
 
     def __init__(  # noqa: PLR0913
         self,
@@ -151,6 +154,7 @@ def __init__(  # noqa: PLR0913
         responsive_sleep_step_seconds: float = SLEEP_STEP_SECONDS,
         pat_timeout: Optional[float] = PAT_TIMEOUT,
         daemon: bool = True,
+        logger: Optional[LoggerOrAdapter] = None,
     ) -> None:
         super().__init__(name=name, daemon=daemon)
         if channel is None:
@@ -162,6 +166,10 @@ def __init__(  # noqa: PLR0913
         self.running = None
         self.pat_timeout = pat_timeout
         self._last_pat_time = 0.0
+        if logger is None:
+            self._logger = logging.getLogger(__package__)
+        else:
+            self._logger = logger
 
     def _preiterate(self) -> None:
         pass