From d5de6448287c2e80ab819b1ad5916afd6efbab5c Mon Sep 17 00:00:00 2001 From: Kasper Date: Fri, 31 Oct 2025 21:22:32 +0100 Subject: [PATCH] feat: add colored and formatted logging Add a custom logging setup function to add custom levels and custom formatters (partly for future use with extended logging functionality). Also implemented a basic colored formatter to make our logs nicer. Also improved the handling of logging in external libraries, so now we should only get WARNings or above. ref: N25B-233 --- logging_config.yaml | 41 ++++++++++++++++ pyproject.toml | 3 ++ src/control_backend/logging/__init__.py | 1 + src/control_backend/logging/setup_logging.py | 50 ++++++++++++++++++++ src/control_backend/main.py | 17 +++---- uv.lock | 27 +++++++++++ 6 files changed, 131 insertions(+), 8 deletions(-) create mode 100644 logging_config.yaml create mode 100644 src/control_backend/logging/__init__.py create mode 100644 src/control_backend/logging/setup_logging.py diff --git a/logging_config.yaml b/logging_config.yaml new file mode 100644 index 0000000..12fccdb --- /dev/null +++ b/logging_config.yaml @@ -0,0 +1,41 @@ +version: 1 + +custom_levels: + OBSERVATION: 25 + ACTION: 26 + +formatters: + # Console output + colored: + (): 'colorlog.ColoredFormatter' + format: '{log_color}{asctime} | {levelname:11} | {name:70} | {message}' + style: '{' + datefmt: '%H:%M:%S' + + # User-facing UI (structured JSON) + json_experiment: + (): 'pythonjsonlogger.jsonlogger.JsonFormatter' + format: '{asctime} {name} {levelname} {message}' + style: '{' + + +handlers: + console: + class: logging.StreamHandler + level: DEBUG + formatter: colored + stream: ext://sys.stdout + +# Level of external libraries +root: + level: WARN + handlers: [console] + +loggers: + experiment: + level: OBSERVATION + handlers: [console] # TODO: custom handler for user-facing logs (ticket about UI logs) + propagate: no + control_backend: + level: INFO + diff --git a/pyproject.toml b/pyproject.toml index ee3ca08..87b5bdd 100644 --- a/pyproject.toml +++ b/pyproject.toml @@ -5,6 +5,7 @@ description = "Add your description here" readme = "README.md" requires-python = ">=3.13" dependencies = [ + "colorlog>=6.10.1", "fastapi[all]>=0.115.6", "mlx-whisper>=0.4.3 ; sys_platform == 'darwin'", "numpy>=2.3.3", @@ -16,6 +17,8 @@ dependencies = [ "pytest-asyncio>=1.2.0", "pytest-cov>=7.0.0", "pytest-mock>=3.15.1", + "python-json-logger>=4.0.0", + "pyyaml>=6.0.3", "pyzmq>=27.1.0", "silero-vad>=6.0.0", "spade>=4.1.0", diff --git a/src/control_backend/logging/__init__.py b/src/control_backend/logging/__init__.py new file mode 100644 index 0000000..f433558 --- /dev/null +++ b/src/control_backend/logging/__init__.py @@ -0,0 +1 @@ +from .setup_logging import setup_logging diff --git a/src/control_backend/logging/setup_logging.py b/src/control_backend/logging/setup_logging.py new file mode 100644 index 0000000..488d7c9 --- /dev/null +++ b/src/control_backend/logging/setup_logging.py @@ -0,0 +1,50 @@ +import logging +import logging.config +import os + +import yaml + + +def add_logging_level(level_name: str, level_num: int, method_name: str | None = None) -> None: + """ + Adds a logging level to the `logging` module and the + currently configured logging class. + """ + if not method_name: + method_name = level_name.lower() + + if hasattr(logging, level_name): + raise AttributeError(f"{level_name} already defined in logging module") + if hasattr(logging, method_name): + raise AttributeError(f"{method_name} already defined in logging module") + if hasattr(logging.getLoggerClass(), method_name): + raise AttributeError(f"{method_name} already defined in logger class") + + def log_for_level(self, message, *args, **kwargs): + if self.isEnabledFor(level_num): + self._log(level_num, message, args, **kwargs) + + def log_to_root(message, *args, **kwargs): + logging.log(level_num, message, *args, **kwargs) + + logging.addLevelName(level_num, level_name) + setattr(logging, level_name, level_num) + setattr(logging.getLoggerClass(), method_name, log_for_level) + setattr(logging, method_name, log_to_root) + + +def setup_logging(path: str = "logging_config.yaml") -> None: + if os.path.exists(path): + with open(path) as f: + try: + config = yaml.safe_load(f.read()) + + if "custom_levels" in config: + for level_name, level_num in config["custom_levels"].items(): + add_logging_level(level_name, level_num) + + logging.config.dictConfig(config) + except (AttributeError, yaml.YAMLError) as e: + logging.warning(f"Could not load logging configuration: {e}") + else: + logging.warning("Logging config file not found. Using default logging configuration.") diff --git a/src/control_backend/main.py b/src/control_backend/main.py index d3588ea..5f6a2f2 100644 --- a/src/control_backend/main.py +++ b/src/control_backend/main.py @@ -8,23 +8,25 @@ import zmq from fastapi import FastAPI from fastapi.middleware.cors import CORSMiddleware -# Internal imports -from control_backend.agents.ri_communication_agent import RICommunicationAgent from control_backend.agents.bdi.bdi_core import BDICoreAgent -from control_backend.agents.vad_agent import VADAgent -from control_backend.agents.llm.llm import LLMAgent from control_backend.agents.bdi.text_extractor import TBeliefExtractor from control_backend.agents.belief_collector.belief_collector import BeliefCollectorAgent +from control_backend.agents.llm.llm import LLMAgent + +# Internal imports +from control_backend.agents.ri_communication_agent import RICommunicationAgent +from control_backend.agents.vad_agent import VADAgent from control_backend.api.v1.router import api_router from control_backend.core.config import settings from control_backend.core.zmq_context import context - -logger = logging.getLogger(__name__) -logging.basicConfig(level=logging.DEBUG) +from control_backend.logging import setup_logging @contextlib.asynccontextmanager async def lifespan(app: FastAPI): + setup_logging() + logger = logging.getLogger(__name__) + logger.info("%s starting up.", app.title) # Initiate sockets @@ -34,7 +36,6 @@ async def lifespan(app: FastAPI): app.state.internal_comm_socket = internal_comm_socket logger.info("Internal publishing socket bound to %s", internal_comm_socket) - # Initiate agents ri_communication_agent = RICommunicationAgent( settings.agent_settings.ri_communication_agent_name + "@" + settings.agent_settings.host, diff --git a/uv.lock b/uv.lock index c2bb61a..bcb6ebe 100644 --- a/uv.lock +++ b/uv.lock @@ -313,6 +313,18 @@ wheels = [ { url = "https://files.pythonhosted.org/packages/a7/06/3d6badcf13db419e25b07041d9c7b4a2c331d3f4e7134445ec5df57714cd/coloredlogs-15.0.1-py2.py3-none-any.whl", hash = "sha256:612ee75c546f53e92e70049c9dbfcc18c935a2b9a53b66085ce9ef6a6e5c0934", size = 46018, upload-time = "2021-06-11T10:22:42.561Z" }, ] +[[package]] +name = "colorlog" +version = "6.10.1" +source = { registry = "https://pypi.org/simple" } +dependencies = [ + { name = "colorama", marker = "sys_platform == 'win32'" }, +] +sdist = { url = "https://files.pythonhosted.org/packages/a2/61/f083b5ac52e505dfc1c624eafbf8c7589a0d7f32daa398d2e7590efa5fda/colorlog-6.10.1.tar.gz", hash = "sha256:eb4ae5cb65fe7fec7773c2306061a8e63e02efc2c72eba9d27b0fa23c94f1321", size = 17162, upload-time = "2025-10-16T16:14:11.978Z" } +wheels = [ + { url = "https://files.pythonhosted.org/packages/6d/c1/e419ef3723a074172b68aaa89c9f3de486ed4c2399e2dbd8113a4fdcaf9e/colorlog-6.10.1-py3-none-any.whl", hash = "sha256:2d7e8348291948af66122cff006c9f8da6255d224e7cf8e37d8de2df3bad8c9c", size = 11743, upload-time = "2025-10-16T16:14:10.512Z" }, +] + [[package]] name = "coverage" version = "7.11.0" @@ -1330,6 +1342,7 @@ name = "pepperplus-cb" version = "0.1.0" source = { virtual = "." } dependencies = [ + { name = "colorlog" }, { name = "fastapi", extra = ["all"] }, { name = "mlx-whisper", marker = "sys_platform == 'darwin'" }, { name = "numpy" }, @@ -1341,6 +1354,8 @@ dependencies = [ { name = "pytest-asyncio" }, { name = "pytest-cov" }, { name = "pytest-mock" }, + { name = "python-json-logger" }, + { name = "pyyaml" }, { name = "pyzmq" }, { name = "silero-vad" }, { name = "spade" }, @@ -1368,6 +1383,7 @@ test = [ [package.metadata] requires-dist = [ + { name = "colorlog", specifier = ">=6.10.1" }, { name = "fastapi", extras = ["all"], specifier = ">=0.115.6" }, { name = "mlx-whisper", marker = "sys_platform == 'darwin'", specifier = ">=0.4.3" }, { name = "numpy", specifier = ">=2.3.3" }, @@ -1379,6 +1395,8 @@ requires-dist = [ { name = "pytest-asyncio", specifier = ">=1.2.0" }, { name = "pytest-cov", specifier = ">=7.0.0" }, { name = "pytest-mock", specifier = ">=3.15.1" }, + { name = "python-json-logger", specifier = ">=4.0.0" }, + { name = "pyyaml", specifier = ">=6.0.3" }, { name = "pyzmq", specifier = ">=27.1.0" }, { name = "silero-vad", specifier = ">=6.0.0" }, { name = "spade", specifier = ">=4.1.0" }, @@ -1815,6 +1833,15 @@ wheels = [ { url = "https://files.pythonhosted.org/packages/5f/ed/539768cf28c661b5b068d66d96a2f155c4971a5d55684a514c1a0e0dec2f/python_dotenv-1.1.1-py3-none-any.whl", hash = "sha256:31f23644fe2602f88ff55e1f5c79ba497e01224ee7737937930c448e4d0e24dc", size = 20556, upload-time = "2025-06-24T04:21:06.073Z" }, ] +[[package]] +name = "python-json-logger" +version = "4.0.0" +source = { registry = "https://pypi.org/simple" } +sdist = { url = "https://files.pythonhosted.org/packages/29/bf/eca6a3d43db1dae7070f70e160ab20b807627ba953663ba07928cdd3dc58/python_json_logger-4.0.0.tar.gz", hash = "sha256:f58e68eb46e1faed27e0f574a55a0455eecd7b8a5b88b85a784519ba3cff047f", size = 17683, upload-time = "2025-10-06T04:15:18.984Z" } +wheels = [ + { url = "https://files.pythonhosted.org/packages/51/e5/fecf13f06e5e5f67e8837d777d1bc43fac0ed2b77a676804df5c34744727/python_json_logger-4.0.0-py3-none-any.whl", hash = "sha256:af09c9daf6a813aa4cc7180395f50f2a9e5fa056034c9953aec92e381c5ba1e2", size = 15548, upload-time = "2025-10-06T04:15:17.553Z" }, +] + [[package]] name = "python-multipart" version = "0.0.20"