review logging noisiness

Author: knifecake

TODOs.md

@@ -29,7 +29,7 @@
 - [x] Test using PostgreSQL
 - [x] Remove demo app in favor of test dummy
 - [x] Configure package builds
-- [ ] Review logging noisiness
+- [x] Review logging noisiness
 - [ ] Concurrency controls
 - [ ] Lifecycle hooks on processes
 - [ ] Tests

steady_queue/__init__.py

@@ -1,7 +1,7 @@
 from datetime import timedelta
 from typing import Optional
 
-VERSION = (0, 1, "0b4")
+VERSION = (0, 1, "0b5")
 
 __version__ = ".".join(map(str, VERSION))
 

steady_queue/app_executor.py

@@ -32,7 +32,7 @@ def wrap_in_app_executor():
         except Exception as e:
             # Handle any database-related errors
             # Close connection on error to prevent connection leaks
-            logger.exception("Error in AppExecutor: %s", e)
+            logger.exception("error in AppExecutor: %(e)s", {"e": e})
             if connection.connection:
                 connection.close()
             raise

steady_queue/management/commands/robust_queue.py

@@ -7,8 +7,6 @@
 from steady_queue.processes.supervisor import Supervisor
 
 logger = logging.getLogger("steady_queue")
-logger.setLevel(logging.INFO)
-logger.addHandler(logging.StreamHandler())
 
 
 class Command(BaseCommand):

steady_queue/management/commands/steady_queue.py

@@ -68,9 +68,8 @@ def disable_connection_pooling(self):
                     options = db_config.setdefault("OPTIONS", {})
                     if "pool" in options:
                         logger.info(
-                            "PID %d disabling connection pooling for database '%s'",
-                            os.getpid(),
-                            alias,
+                            "%(name)s disabling connection pooling for database '%(alias)s'",
+                            {"name": self.name, "alias": alias},
                         )
                         del options["pool"]
 
@@ -82,14 +81,13 @@ def disable_connection_pooling(self):
                     connection.pool.close()
                     connection.pool = None
                     logger.debug(
-                        "PID %d removed existing pool for '%s'", os.getpid(), alias
+                        "%(name)s removed existing pool for '%(alias)s'",
+                        {"name": self.name, "alias": alias},
                     )
                 except Exception as e:
                     logger.debug(
-                        "PID %d failed to close existing pool for '%s': %s",
-                        os.getpid(),
-                        alias,
-                        e,
+                        "%(name)s failed to close existing pool for '%(alias)s': %(e)s",
+                        {"name": self.name, "alias": alias, "e": e},
                     )
 
     def reset_database_connections(self):
@@ -99,8 +97,6 @@ def reset_database_connections(self):
         This disables connection pooling and resets connection state to prevent
         issues with shared connections between parent and child processes.
         """
-        # First disable connection pooling for steady_queue processes
         self.disable_connection_pooling()
 
-        # Close all existing connections
         connections.close_all()

steady_queue/processes/base.py

@@ -27,9 +27,11 @@ def metadata(self) -> dict[str, Any]:
 
     def run(self):
         logger.info(
-            "%s polling every %g seconds",
-            self.kind,
-            self.polling_interval.total_seconds(),
+            "%(name)s polling every %(polling_interval)g seconds",
+            {
+                "name": self.name,
+                "polling_interval": self.polling_interval.total_seconds(),
+            },
         )
         self.start_loop()
 

steady_queue/processes/poller.py

@@ -1,5 +1,4 @@
 import logging
-import os
 
 from steady_queue.processes.supervised import Supervised
 
@@ -10,16 +9,12 @@ class Runnable(Supervised):
     mode: str = "async"
 
     def start(self):
-        logger.info("starting runnable %s (PID %d)", self.name, os.getpid())
         self.boot()
-        logger.debug("booted runnable %s", self.name)
 
         if self.is_running_async:
             raise NotImplementedError
         else:
-            logger.debug("running runnable %s", self.name)
             self.run()
-            logger.info("runnable %s finished, exiting", self.name)
 
     def stop(self):
         super().stop()

steady_queue/processes/runnable.py

@@ -56,7 +56,8 @@ def shutdown(self):
 
     def schedule_recurring_tasks(self):
         logger.info(
-            "Scheduling recurring tasks from %s", self.recurring_schedule.task_keys
+            "scheduling recurring tasks: %(task_keys)s",
+            {"task_keys": self.recurring_schedule.task_keys},
         )
         self.recurring_schedule.schedule_tasks()
 

steady_queue/processes/scheduler.py

@@ -26,7 +26,8 @@ def set_procline(self):
     def register_signal_handlers(self):
         def h(signum, frame):
             logger.info(
-                "%s supervised received signal %s", self.name, signal.strsignal(signum)
+                "%(name)s received signal %(signal)s",
+                {"name": self.name, "signal": signal.strsignal(signum)},
             )
             self.stop()