Using debug logs

Author: harishkannarao

app/config.py

@@ -19,6 +19,7 @@ class Settings(BaseSettings):
     app_db_min_con: int = 5
     app_db_max_con: int = 20
     app_db_log_sql: bool = False
+    app_retry_consumer_log_debug: bool = False
     # db settings end
 
     # rabbit mq broker settings start

app/consumer/retry_consumer.py

@@ -12,11 +12,11 @@
 
 
 async def process_retry_message_task(message: AbstractIncomingMessage):
-    logger = structlog.get_logger()
+    logger = structlog.get_logger("retry_consumer")
     async with message.process():  # Automatically ACKs if no exception occurs
         payload_string: str = message.body.decode()
         headers = dict(message.headers) if message.headers else {}
-        logger.info(
+        logger.debug(
             f"Received retry message {payload_string}",
             payload=payload_string,
             headers=headers,
@@ -41,17 +41,17 @@ async def process_retry_message_task(message: AbstractIncomingMessage):
             await publish_to_inbound_retry(
                 payload_string=payload_string, headers=headers
             )
+            logger.debug(
+                f"Sent to retry queue {payload_string}",
+                headers=headers,
+                payload_string=payload_string,
+            )
         else:
             logger.info(
                 f"Max retries exhausted, discarding message {payload_string}",
                 payload=payload_string,
                 headers=headers,
             )
-        logger.info(
-            f"Processed retry message {payload_string}",
-            headers=headers,
-            payload_string=payload_string,
-        )
 
 
 async def start_retry_consumer() -> Task[str]:

app/logging/logging_config.py

@@ -6,8 +6,10 @@
 from structlog.contextvars import merge_contextvars
 from structlog.stdlib import LoggerFactory
 
+from app.config import Settings
 
-def setup_logging(json_logs: bool = False, db_logs: bool = False):
+
+def setup_logging(settings: Settings):
     shared_processors = [
         CallsiteParameterAdder(
             {
@@ -22,7 +24,7 @@ def setup_logging(json_logs: bool = False, db_logs: bool = False):
         merge_contextvars,
     ]
 
-    if json_logs:
+    if settings.app_json_logs:
         log_renderer = structlog.processors.JSONRenderer()
     else:
         log_renderer = structlog.dev.ConsoleRenderer()
@@ -37,9 +39,12 @@ def setup_logging(json_logs: bool = False, db_logs: bool = False):
         handlers=[logging.StreamHandler(sys.stdout)],
     )
 
-    if db_logs:
+    if settings.app_db_log_sql:
         logging.getLogger("databases").setLevel(logging.DEBUG)
 
+    if settings.app_retry_consumer_log_debug:
+        logging.getLogger("retry_consumer").setLevel(logging.DEBUG)
+
     structlog.configure(
         processors=processors,
         logger_factory=LoggerFactory(),

app/main.py

@@ -41,7 +41,7 @@
 from app.consumer.retry_consumer import start_retry_consumer
 
 # Initialize logging at application startup
-setup_logging(json_logs=settings.app_json_logs, db_logs=settings.app_db_log_sql)
+setup_logging(settings)
 logger = structlog.get_logger()
 
 context = FastAPI(openapi_url=settings.app_open_api_url)

tests_integration/producer/test_inbound_producer.py

@@ -147,16 +147,16 @@ async def publish_outbound_side_effect_logic(*args, **kwargs):
     ):
         with attempt:
             assert_that(len(captured_logs)).is_greater_than(0)
-            retry_consumer_logs = list(
+            retry_sent_to_inbound_logs = list(
                 filter(
                     lambda entry: str(entry["event"]).startswith(
                         "Sent to inbound queue"
                     ),
                     captured_logs,
                 )
             )
-            assert_that(retry_consumer_logs).is_length(2)
-            retry_headers: HeadersType = retry_consumer_logs[0]["headers"]
+            assert_that(retry_sent_to_inbound_logs).is_length(2)
+            retry_headers: HeadersType = retry_sent_to_inbound_logs[0]["headers"]
             assert_that(retry_headers.get("test")).is_equal_to(headers.get("test"))
             assert_that(retry_headers.get("message_id")).is_equal_to(
                 headers.get("message_id")
@@ -170,7 +170,7 @@ async def publish_outbound_side_effect_logic(*args, **kwargs):
                 datetime.now(UTC) - timedelta(seconds=10),
                 datetime.now(UTC) + timedelta(seconds=10),
             )
-            retry_payload_string = retry_consumer_logs[0]["payload_string"]
+            retry_payload_string = retry_sent_to_inbound_logs[0]["payload_string"]
             outbound_samples: list[dict[str, Any]] = json.loads(retry_payload_string)
             assert_that(
                 DeepDiff(
@@ -180,6 +180,14 @@ async def publish_outbound_side_effect_logic(*args, **kwargs):
                 )
             ).is_empty()
 
+    retry_sent_to_retry_logs = list(
+        filter(
+            lambda entry: str(entry["event"]).startswith("Sent to retry queue"),
+            captured_logs,
+        )
+    )
+    assert_that(len(retry_sent_to_retry_logs)).is_greater_than(1)
+
     for attempt in Retrying(
         stop=stop_after_delay(5), wait=wait_fixed(0.5), reraise=True
     ):