From 2339cdcbab3f01d2114291ab1d002de0dc702247 Mon Sep 17 00:00:00 2001 From: Daniel Fernandes Date: Tue, 21 Oct 2025 12:25:20 +0000 Subject: [PATCH 1/8] Enable uvicorn logger propagation --- src/blueapi/service/main.py | 1 + 1 file changed, 1 insertion(+) diff --git a/src/blueapi/service/main.py b/src/blueapi/service/main.py index 73cfed637..d45be6431 100644 --- a/src/blueapi/service/main.py +++ b/src/blueapi/service/main.py @@ -562,6 +562,7 @@ def start(config: ApplicationConfig): "%(asctime)s %(levelprefix)s %(client_addr)s" + " - '%(request_line)s' %(status_code)s" ) + LOGGING_CONFIG["loggers"]["uvicorn"]["propagate"] = True app = get_app(config) FastAPIInstrumentor().instrument_app( From 58c403c87e2c8745c77e7970f3975fbac6784143 Mon Sep 17 00:00:00 2001 From: Daniel Fernandes Date: Tue, 21 Oct 2025 12:52:10 +0000 Subject: [PATCH 2/8] Add formatter to blueapi stream handler --- src/blueapi/log.py | 6 ++++++ 1 file changed, 6 insertions(+) diff --git a/src/blueapi/log.py b/src/blueapi/log.py index f964f85ca..fc4708049 100644 --- a/src/blueapi/log.py +++ b/src/blueapi/log.py @@ -2,6 +2,7 @@ import os from contextlib import contextmanager +import uvicorn from graypy import GELFTCPHandler from blueapi.config import LoggingConfig @@ -91,6 +92,11 @@ def set_up_stream_handler( stream_handler = logging.StreamHandler() stream_handler.setLevel(logging_config.level) + formatter = uvicorn.logging.DefaultFormatter( + "%(asctime)s %(levelprefix)s %(message)s" + ) + stream_handler.setFormatter(formatter) + for filter in filters: stream_handler.addFilter(filter) From 791e2327222ed19abb5564e3c25e9f84765fa1ef Mon Sep 17 00:00:00 2001 From: Daniel Fernandes Date: Tue, 21 Oct 2025 12:54:37 +0000 Subject: [PATCH 3/8] Disable uvicorn logger handler --- src/blueapi/service/main.py | 4 +--- 1 file changed, 1 insertion(+), 3 deletions(-) diff --git a/src/blueapi/service/main.py b/src/blueapi/service/main.py index d45be6431..a5716c15e 100644 --- a/src/blueapi/service/main.py +++ b/src/blueapi/service/main.py @@ -555,9 +555,7 @@ def start(config: ApplicationConfig): import uvicorn from uvicorn.config import LOGGING_CONFIG - LOGGING_CONFIG["formatters"]["default"]["fmt"] = ( - "%(asctime)s %(levelprefix)s %(message)s" - ) + LOGGING_CONFIG["loggers"]["uvicorn"]["handlers"] = [] LOGGING_CONFIG["formatters"]["access"]["fmt"] = ( "%(asctime)s %(levelprefix)s %(client_addr)s" + " - '%(request_line)s' %(status_code)s" From 5e263e58d32c914efe0a328b347c6923ae40af41 Mon Sep 17 00:00:00 2001 From: Daniel Fernandes Date: Wed, 22 Oct 2025 06:34:38 +0000 Subject: [PATCH 4/8] Implement own formatter to replace use of private Uvicorn formatter --- src/blueapi/log.py | 52 ++++++++++++++++++++++++++++++++++++++++++---- 1 file changed, 48 insertions(+), 4 deletions(-) diff --git a/src/blueapi/log.py b/src/blueapi/log.py index fc4708049..0e53b78b5 100644 --- a/src/blueapi/log.py +++ b/src/blueapi/log.py @@ -1,8 +1,10 @@ +import enum import logging import os from contextlib import contextmanager +from copy import copy -import uvicorn +import click from graypy import GELFTCPHandler from blueapi.config import LoggingConfig @@ -92,9 +94,7 @@ def set_up_stream_handler( stream_handler = logging.StreamHandler() stream_handler.setLevel(logging_config.level) - formatter = uvicorn.logging.DefaultFormatter( - "%(asctime)s %(levelprefix)s %(message)s" - ) + formatter = ColorFormatter("%(asctime)s %(levelname)s %(message)s") stream_handler.setFormatter(formatter) for filter in filters: @@ -126,3 +126,47 @@ def set_up_graylog_handler( logger.addHandler(graylog_handler) return graylog_handler + + +class IBMColorBlindSafeColors(enum.Enum): + ultramarine = (100, 143, 255) + indigo = (120, 94, 240) + magenta = (220, 38, 127) + orange = (254, 97, 0) + gold = (255, 176, 0) + + +class ColorFormatter(logging.Formatter): + """Colors level_name of log using IBM Color blind safe palette.""" + + def color_level_name(self, level_name: str, level_no: int) -> str: + match level_no: + case logging.DEBUG: + return click.style( + str(level_name), fg=IBMColorBlindSafeColors.ultramarine.value + ) + case logging.INFO: + return click.style( + str(level_name), fg=IBMColorBlindSafeColors.indigo.value + ) + case logging.WARNING: + return click.style( + str(level_name), fg=IBMColorBlindSafeColors.gold.value + ) + case logging.ERROR: + return click.style( + str(level_name), fg=IBMColorBlindSafeColors.magenta.value + ) + case logging.CRITICAL: + return click.style( + str(level_name), fg=IBMColorBlindSafeColors.orange.value + ) + return level_name + + def formatMessage(self, record: logging.LogRecord) -> str: + # Copy record to avoid modifying for other handlers etc. + recordcopy = copy(record) + recordcopy.levelname = self.color_level_name( + recordcopy.levelname, recordcopy.levelno + ) + return super().formatMessage(recordcopy) From bd5a40b7f1a1b2b072bd33869deae48a68f11c03 Mon Sep 17 00:00:00 2001 From: Daniel Fernandes Date: Wed, 22 Oct 2025 07:03:56 +0000 Subject: [PATCH 5/8] Add tests for log.ColorFormatter --- tests/unit_tests/test_log.py | 60 +++++++++++++++++++++++++++++++++++- 1 file changed, 59 insertions(+), 1 deletion(-) diff --git a/tests/unit_tests/test_log.py b/tests/unit_tests/test_log.py index 277468f38..2c9ad0697 100644 --- a/tests/unit_tests/test_log.py +++ b/tests/unit_tests/test_log.py @@ -7,7 +7,12 @@ from dodal.log import LOGGER as dodal_logger from blueapi.config import GraylogConfig, LoggingConfig -from blueapi.log import PlanTagFilter, plan_tag_filter_context, set_up_logging +from blueapi.log import ( + ColorFormatter, + PlanTagFilter, + plan_tag_filter_context, + set_up_logging, +) def clear_all_loggers_and_handlers(logger): @@ -124,3 +129,56 @@ def test_filter_tags_plan_name(logger, mock_handler_emit): logger.addFilter(PlanTagFilter("foo")) logger.info("FOO") assert mock_handler_emit.call_args[0][0].plan_name == "foo" + + +@pytest.fixture +def color_formatter(): + return ColorFormatter("%(levelname)s %(message)s") + + +@pytest.fixture +def foo_record(): + return logging.LogRecord("foo", logging.INFO, "foo", 0, "foo", None, None) + + +class TestColorFormatter: + def test_debug(self, color_formatter, foo_record): + foo_record.levelno = logging.DEBUG + + assert ( + color_formatter.format(foo_record) + == "\x1b[38;2;100;143;255mINFO\x1b[0m foo" + ) + + def test_info(self, color_formatter, foo_record): + foo_record.levelno = logging.INFO + + assert ( + color_formatter.format(foo_record) == "\x1b[38;2;120;94;240mINFO\x1b[0m foo" + ) + + def test_warning(self, color_formatter, foo_record): + foo_record.levelno = logging.WARNING + + assert ( + color_formatter.format(foo_record) == "\x1b[38;2;255;176;0mINFO\x1b[0m foo" + ) + + def test_error(self, color_formatter, foo_record): + foo_record.levelno = logging.ERROR + + assert ( + color_formatter.format(foo_record) == "\x1b[38;2;220;38;127mINFO\x1b[0m foo" + ) + + def test_critical(self, color_formatter, foo_record): + foo_record.levelno = logging.CRITICAL + + assert ( + color_formatter.format(foo_record) == "\x1b[38;2;254;97;0mINFO\x1b[0m foo" + ) + + def test_other(self, color_formatter, foo_record): + foo_record.levelno = -1 + + assert color_formatter.format(foo_record) == "INFO foo" From 7ca42388e85e453e43f938dd31cfb11e3b8c5046 Mon Sep 17 00:00:00 2001 From: Daniel Fernandes Date: Wed, 22 Oct 2025 07:10:08 +0000 Subject: [PATCH 6/8] Add comment --- src/blueapi/service/main.py | 1 + 1 file changed, 1 insertion(+) diff --git a/src/blueapi/service/main.py b/src/blueapi/service/main.py index a5716c15e..6585dda47 100644 --- a/src/blueapi/service/main.py +++ b/src/blueapi/service/main.py @@ -555,6 +555,7 @@ def start(config: ApplicationConfig): import uvicorn from uvicorn.config import LOGGING_CONFIG + # Enable propagation and disable default handlers, so that blueapi handles all logs LOGGING_CONFIG["loggers"]["uvicorn"]["handlers"] = [] LOGGING_CONFIG["formatters"]["access"]["fmt"] = ( "%(asctime)s %(levelprefix)s %(client_addr)s" From bee52418f6152a849f143de7e9db20f1a1fcd0b2 Mon Sep 17 00:00:00 2001 From: Daniel Fernandes Date: Wed, 22 Oct 2025 07:12:07 +0000 Subject: [PATCH 7/8] Remove uneccessary capitalisation --- src/blueapi/log.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/blueapi/log.py b/src/blueapi/log.py index 0e53b78b5..8d951d545 100644 --- a/src/blueapi/log.py +++ b/src/blueapi/log.py @@ -137,7 +137,7 @@ class IBMColorBlindSafeColors(enum.Enum): class ColorFormatter(logging.Formatter): - """Colors level_name of log using IBM Color blind safe palette.""" + """Colors level_name of log using IBM color blind safe palette.""" def color_level_name(self, level_name: str, level_no: int) -> str: match level_no: From b04480049c3f1a5296ea09e2ab5004d7c5aa683a Mon Sep 17 00:00:00 2001 From: Joseph Ware <53935796+DiamondJoseph@users.noreply.github.com> Date: Thu, 30 Oct 2025 16:33:35 +0000 Subject: [PATCH 8/8] Ignore linting rule for library extension --- src/blueapi/log.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/blueapi/log.py b/src/blueapi/log.py index 8d951d545..df1a17d40 100644 --- a/src/blueapi/log.py +++ b/src/blueapi/log.py @@ -163,7 +163,7 @@ def color_level_name(self, level_name: str, level_no: int) -> str: ) return level_name - def formatMessage(self, record: logging.LogRecord) -> str: + def formatMessage(self, record: logging.LogRecord) -> str: # noqa: N802 # Copy record to avoid modifying for other handlers etc. recordcopy = copy(record) recordcopy.levelname = self.color_level_name(