From baf9e4f0be352b906fecf204e35986652aa000cb Mon Sep 17 00:00:00 2001 From: Alberto Soutullo Date: Tue, 4 Nov 2025 14:41:57 +0100 Subject: [PATCH] Logger adjustments (#37) * Add TRACE to logger.py * Modify logs --- src/async_utils.py | 4 ++-- src/logger.py | 14 +++++++++++--- src/rpc_client.py | 9 +++++---- src/signal_client.py | 19 ++++++++++--------- src/status_backend.py | 15 ++++++++------- 5 files changed, 36 insertions(+), 25 deletions(-) diff --git a/src/async_utils.py b/src/async_utils.py index 53ed7d6..13bfdd7 100644 --- a/src/async_utils.py +++ b/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 diff --git a/src/logger.py b/src/logger.py index f6a1cd2..a91e967 100644 --- a/src/logger.py +++ b/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) diff --git a/src/rpc_client.py b/src/rpc_client.py index fc5b414..9f12a63 100644 --- a/src/rpc_client.py +++ b/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']}") diff --git a/src/signal_client.py b/src/signal_client.py index 20461ac..937b5b4 100644 --- a/src/signal_client.py +++ b/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: diff --git a/src/status_backend.py b/src/status_backend.py index a13f062..3871354 100644 --- a/src/status_backend.py +++ b/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()