Logger adjustments (#37)

* Add TRACE to logger.py

* Modify logs

src/async_utils.py

@@ -32,7 +32,7 @@ async def launch_workers(worker_tasks: list[partial], done_queue: asyncio.Queue[
             await sem.acquire()
 
         # worker.args has (nodes, sender, receiver)
-        logger.info(f"Launching task {worker.func.__name__}: {worker.args[1:]}")
+        logger.debug(f"Launching task {worker.func.__name__}: {worker.args[1:]}")
         fut = asyncio.create_task(worker())
 
         def _on_done(t: asyncio.Task, j=worker) -> None:
@@ -58,7 +58,7 @@ async def collect_results_from_tasks(done_queue: asyncio.Queue[TaskResult | None
         status, payload = await done_queue.get()
         if status == "ok":
             partial_object, results = payload
-            logger.info(f"Task completed: {partial_object.func.__name__} {partial_object.args[1:]}")
+            logger.debug(f"Task completed: {partial_object.func.__name__} {partial_object.args[1:]}")
             results_queue.put_nowait((partial_object.func.__name__, results))
         else:
             e, tb = payload  # from the launcher callback

src/logger.py

@@ -1,10 +1,18 @@
-# Python Imports
+import logging
 import logging.config
 import pathlib
 import yaml
 
-# Project Imports
+class TraceLogger(logging.Logger):
+    TRACE = 5
+    def trace(self, msg, *args, **kwargs) -> None:
+        self.log(self.TRACE, msg, *args, **kwargs)
 
+# Register level name and custom class BEFORE dictConfig/getLogger
+logging.addLevelName(TraceLogger.TRACE, "TRACE")
+logging.setLoggerClass(TraceLogger)
+
+# Load YAML config
 with open(pathlib.Path(__file__).parent.resolve() / 'logger_config.yaml', 'r') as f:
-    config = yaml.safe_load(f.read())
+    config = yaml.safe_load(f)
     logging.config.dictConfig(config)

src/rpc_client.py

@@ -2,13 +2,14 @@
 import asyncio
 import json
 import logging
-from typing import List, Optional, Any
+from typing import List, Optional, Any, cast
 from aiohttp import ClientSession, ClientTimeout, ClientError
 from tenacity import retry, stop_after_delay, wait_fixed, retry_if_exception_type
 
 # Project Imports
+from src.logger import TraceLogger
 
-logger = logging.getLogger(__name__)
+logger = cast(TraceLogger, logging.getLogger(__name__))
 
 
 class AsyncRpcClient:
@@ -54,7 +55,7 @@ class AsyncRpcClient:
         payload = {"jsonrpc": "2.0", "method": method, "id": request_id, "params": params or []}
 
         if enable_logging:
-            logger.debug(f"Sending async POST to {url} with data: {json.dumps(payload, sort_keys=True)}")
+            logger.trace(f"Sending async POST to {url} with data: {json.dumps(payload, sort_keys=True)}")
 
         async with self.session.post(url, json=payload) as response:
             resp_text = await response.text()
@@ -68,7 +69,7 @@ class AsyncRpcClient:
                 raise AssertionError(f"Invalid JSON in response: {resp_text}")
 
             if enable_logging:
-                logger.debug(f"Received response: {json.dumps(resp_json, sort_keys=True)}")
+                logger.trace(f"Received response: {json.dumps(resp_json, sort_keys=True)}")
 
             if "error" in resp_json:
                 raise AssertionError(f"JSON-RPC Error: {resp_json['error']}")

src/signal_client.py

@@ -4,7 +4,7 @@ import contextlib
 import json
 import logging
 import os
-from typing import Optional, AsyncGenerator
+from typing import Optional, AsyncGenerator, cast
 from aiohttp import ClientSession, ClientWebSocketResponse, WSMsgType
 from pathlib import Path
 from datetime import datetime
@@ -12,8 +12,9 @@ from collections import deque
 
 # Project Imports
 from src.enums import SignalType
+from src.logger import TraceLogger
 
-logger = logging.getLogger(__name__)
+logger = cast(TraceLogger, logging.getLogger(__name__))
 
 LOG_SIGNALS_TO_FILE = False
 SIGNALS_DIR = os.path.dirname(os.path.abspath(__file__))
@@ -77,7 +78,7 @@ class AsyncSignalClient:
                 await self.listener_task
 
     async def _listen(self):
-        logger.debug("WebSocket listener started")
+        logger.trace("WebSocket listener started")
         async for msg in self.ws:
             if msg.type == WSMsgType.TEXT:
                 await self.on_message(msg.data)
@@ -102,7 +103,7 @@ class AsyncSignalClient:
 
     async def on_message(self, signal: str):
         signal_data = json.loads(signal)
-        logger.debug(f"Received WebSocket message: {signal_data}")
+        logger.trace(f"Received WebSocket message: {signal_data}")
 
         if LOG_SIGNALS_TO_FILE:
             pass  # TODO: write to file if needed
@@ -110,16 +111,16 @@ class AsyncSignalClient:
         signal_type = signal_data.get("type")
         if signal_type in self.signal_queues:
             await self.signal_queues[signal_type].put(signal_data)
-            logger.debug(f"Queued signal: {signal_type}")
+            logger.trace(f"Queued signal: {signal_type}")
         else:
-            logger.debug(f"Ignored signal not in await list: {signal_type}")
+            logger.trace(f"Ignored signal not in await list: {signal_type}")
 
     async def wait_for_signal(self, signal_type: str, timeout: int = 20) -> dict:
         if signal_type not in self.signal_queues:
             raise ValueError(f"Signal type {signal_type} is not in the list of awaited signals")
         try:
             signal = await asyncio.wait_for(self.signal_queues[signal_type].get(), timeout)
-            logger.debug(f"Received {signal_type} signal: {signal}")
+            logger.trace(f"Received {signal_type} signal: {signal} in {self.url}")
             return signal
         except asyncio.TimeoutError:
             raise TimeoutError(f"Signal {signal_type} not received in {timeout} seconds")
@@ -136,7 +137,7 @@ class AsyncSignalClient:
         return self.signal_queues[signal_type].recent()
 
     async def wait_for_login(self) -> dict:
-        logger.debug("Waiting for login signal...")
+        logger.debug(f"Waiting for login signal in {self.url}...")
         signal = await self.wait_for_signal(SignalType.NODE_LOGIN.value)
         logger.debug(f"Login signal received: {signal}")
         if "error" in signal.get("event", {}):
@@ -163,7 +164,7 @@ class AsyncSignalClient:
                 if event_string in message[1]:
                     # Remove the found signal from the buffer
                     # queue.buffer.remove(signal)
-                    logger.info(f"Found {signal_type} containing '{event_string}' in messages")
+                    logger.debug(f"Found {signal_type} containing '{event_string}' in messages")
                     return message
 
             if asyncio.get_event_loop().time() > end_time:

src/status_backend.py

@@ -2,18 +2,19 @@
 import logging
 import json
 import time
-from typing import List, Dict
+from typing import List, Dict, cast
 from aiohttp import ClientSession, ClientTimeout
 
 # Project Imports
 from src.account_service import AccountAsyncService
 from src.enums import SignalType
+from src.logger import TraceLogger
 from src.rpc_client import AsyncRpcClient
 from src.signal_client import AsyncSignalClient
 from src.wakuext_service import WakuextAsyncService
 from src.wallet_service import WalletAsyncService
 
-logger = logging.getLogger(__name__)
+logger = cast(TraceLogger, logging.getLogger(__name__))
 
 
 class StatusBackend:
@@ -52,9 +53,9 @@ class StatusBackend:
 
     async def api_request(self, method: str, data: Dict) -> dict:
         url = f"{self.api_url}/{method}"
-        logger.debug(f"Sending POST to {url} with data: {data}")
+        logger.trace(f"Sending POST to {url} with data: {data}")
         async with self.session.post(url, json=data) as response:
-            logger.debug(f"Received response from {method}: {response.status}")
+            logger.trace(f"Received response from {method}: {response.status}")
 
             if response.status != 200:
                 body = await response.text()
@@ -73,7 +74,7 @@ class StatusBackend:
 
     async def api_valid_request(self, method: str, data: Dict) -> dict:
         json_data = await self.api_request(method, data)
-        logger.debug(f"Valid response from {method}: {json_data}")
+        logger.trace(f"Valid response from {method}: {json_data}")
         return json_data
 
     async def start_status_backend(self) -> dict:
@@ -81,7 +82,7 @@ class StatusBackend:
         try:
             await self.logout()
         except AssertionError:
-            logger.debug("Failed to log out")
+            logger.debug(f"Failed to log out in {self.base_url}")
 
         method = "InitializeApplication"
         data = {
@@ -160,7 +161,7 @@ class StatusBackend:
     async def logout(self, clean_signals = False) -> dict:
         json_response = await self.api_valid_request("Logout", {})
         _ = await self.signal.wait_for_logout()
-        logger.debug("Successfully logged out")
+        logger.debug(f"Successfully logged out in {self.base_url}")
         if clean_signals:
             self.signal.cleanup_signal_queues()