From 97674280f5ae43f6c4ad367e115d401104e9d733 Mon Sep 17 00:00:00 2001 From: Major Hayden Date: Tue, 24 Feb 2026 09:30:52 -0600 Subject: [PATCH 1/3] refactor(logging): extract resolve_log_level and create_log_handler into log.py Add DEFAULT_LOG_FORMAT constant to constants.py and extract two public functions into log.py: resolve_log_level() for env-var-based level resolution and create_log_handler() for TTY-aware handler selection. Simplify get_logger() to delegate to these new functions while keeping its signature unchanged. Signed-off-by: Major Hayden --- src/constants.py | 2 + src/log.py | 102 ++++++++++++++++++++++++++++++++--------------- 2 files changed, 72 insertions(+), 32 deletions(-) diff --git a/src/constants.py b/src/constants.py index fadaa064f..4056c74c8 100644 --- a/src/constants.py +++ b/src/constants.py @@ -183,3 +183,5 @@ LIGHTSPEED_STACK_LOG_LEVEL_ENV_VAR = "LIGHTSPEED_STACK_LOG_LEVEL" # Default log level when environment variable is not set DEFAULT_LOG_LEVEL = "INFO" +# Default log format for plain-text logging in non-TTY environments +DEFAULT_LOG_FORMAT = "%(asctime)s %(levelname)-8s %(name)s:%(lineno)d %(message)s" diff --git a/src/log.py b/src/log.py index a1f74a98c..f11493457 100644 --- a/src/log.py +++ b/src/log.py @@ -6,7 +6,72 @@ from rich.logging import RichHandler -from constants import LIGHTSPEED_STACK_LOG_LEVEL_ENV_VAR, DEFAULT_LOG_LEVEL +from constants import ( + LIGHTSPEED_STACK_LOG_LEVEL_ENV_VAR, + DEFAULT_LOG_LEVEL, + DEFAULT_LOG_FORMAT, +) + + +def resolve_log_level() -> int: + """ + Resolve and validate the log level from environment variable. + + Reads the LIGHTSPEED_STACK_LOG_LEVEL environment variable and validates + it against Python's logging module. If the environment variable is not set, + defaults to DEFAULT_LOG_LEVEL. If the value is invalid, logs a warning and + falls back to DEFAULT_LOG_LEVEL. + + Parameters: + None + + Returns: + int: A valid logging level constant (e.g., logging.INFO, logging.DEBUG). + """ + level_str = os.environ.get(LIGHTSPEED_STACK_LOG_LEVEL_ENV_VAR, DEFAULT_LOG_LEVEL) + + # Validate the level string and convert to logging level constant + validated_level = getattr(logging, level_str.upper(), None) + if not isinstance(validated_level, int): + # Write directly to stderr instead of using a logger. This function is + # called at module-import time (before logging is configured), so routing + # through a logger produces inconsistent output depending on root-logger + # state. + print( + f"WARNING: Invalid log level '{level_str}', " + f"falling back to {DEFAULT_LOG_LEVEL}", + file=sys.stderr, + ) + validated_level = getattr(logging, DEFAULT_LOG_LEVEL) + + return validated_level + + +def create_log_handler() -> logging.Handler: + """ + Create and return a configured log handler based on TTY availability. + + If stderr is connected to a terminal (TTY), returns a RichHandler for + rich-formatted console output. Otherwise, returns a StreamHandler with + plain-text formatting suitable for non-TTY environments (e.g., containers). + + Parameters: + None + + Returns: + logging.Handler: A configured handler instance (RichHandler or StreamHandler). + """ + if sys.stderr.isatty(): + # RichHandler's columnar layout assumes a real terminal. + # RichHandler handles its own formatting, so no formatter is set. + return RichHandler() + + # In containers without a TTY, Rich falls back to 80 columns and + # the columns consume most of that width, leaving ~40 chars for the actual message. + # Tracebacks become nearly unreadable. Use a plain StreamHandler instead. + handler = logging.StreamHandler() + handler.setFormatter(logging.Formatter(DEFAULT_LOG_FORMAT)) + return handler def get_logger(name: str) -> logging.Logger: @@ -15,8 +80,8 @@ def get_logger(name: str) -> logging.Logger: The returned logger has its level set based on the LIGHTSPEED_STACK_LOG_LEVEL environment variable (defaults to INFO), its handlers replaced with a single - RichHandler for rich-formatted console output, and propagation to ancestor - loggers disabled. + handler (RichHandler for TTY or StreamHandler for non-TTY), and propagation + to ancestor loggers disabled. Parameters: name (str): Name of the logger to retrieve or create. @@ -30,34 +95,7 @@ def get_logger(name: str) -> logging.Logger: if logger.handlers: return logger - # RichHandler's columnar layout (timestamp, level, right-aligned filename) assumes - # a real terminal. In containers without a TTY, Rich falls back to 80 columns and - # the columns consume most of that width, leaving ~40 chars for the actual message. - # Tracebacks become nearly unreadable. Use a plain StreamHandler when there's no TTY. - if sys.stderr.isatty(): - logger.handlers = [RichHandler()] - else: - handler = logging.StreamHandler() - handler.setFormatter( - logging.Formatter( - "%(asctime)s %(levelname)-8s %(name)s:%(lineno)d %(message)s" - ) - ) - logger.handlers = [handler] + logger.handlers = [create_log_handler()] logger.propagate = False - - # Read log level from environment variable with default fallback - level_str = os.environ.get(LIGHTSPEED_STACK_LOG_LEVEL_ENV_VAR, DEFAULT_LOG_LEVEL) - - # Validate the level string and convert to logging level constant - validated_level = getattr(logging, level_str.upper(), None) - if not isinstance(validated_level, int): - logger.warning( - "Invalid log level '%s', falling back to %s", - level_str, - DEFAULT_LOG_LEVEL, - ) - validated_level = getattr(logging, DEFAULT_LOG_LEVEL) - - logger.setLevel(validated_level) + logger.setLevel(resolve_log_level()) return logger From c1eb55b8c8ee564d97d895a89602a1e47f7fec01 Mon Sep 17 00:00:00 2001 From: Major Hayden Date: Tue, 24 Feb 2026 09:30:59 -0600 Subject: [PATCH 2/3] refactor(logging): use centralized logging helpers in consumers Replace inline log-level resolution and handler creation in lightspeed_stack.py and runners/uvicorn.py with calls to the shared resolve_log_level() and create_log_handler() from log.py. Remove the private _resolve_log_level() from uvicorn.py and the direct RichHandler import from lightspeed_stack.py. Signed-off-by: Major Hayden --- src/lightspeed_stack.py | 30 ++++++++++-------------------- src/runners/uvicorn.py | 28 ++-------------------------- 2 files changed, 12 insertions(+), 46 deletions(-) diff --git a/src/lightspeed_stack.py b/src/lightspeed_stack.py index b11d46d06..a8731df12 100644 --- a/src/lightspeed_stack.py +++ b/src/lightspeed_stack.py @@ -9,41 +9,31 @@ import sys from argparse import ArgumentParser - -from rich.logging import RichHandler - -from log import get_logger +from log import get_logger, resolve_log_level, create_log_handler from configuration import configuration from runners.uvicorn import start_uvicorn from runners.quota_scheduler import start_quota_scheduler from utils import schema_dumper -from constants import LIGHTSPEED_STACK_LOG_LEVEL_ENV_VAR, DEFAULT_LOG_LEVEL - -# Read log level from environment variable with validation -log_level_str = os.environ.get(LIGHTSPEED_STACK_LOG_LEVEL_ENV_VAR, DEFAULT_LOG_LEVEL) -log_level = getattr(logging, log_level_str.upper(), None) -if not isinstance(log_level, int): - print( - f"WARNING: Invalid log level '{log_level_str}', falling back to {DEFAULT_LOG_LEVEL}", - file=sys.stderr, - ) - log_level = getattr(logging, DEFAULT_LOG_LEVEL) +from constants import LIGHTSPEED_STACK_LOG_LEVEL_ENV_VAR + +# Resolve log level and handler from centralized logging utilities +log_level = resolve_log_level() -# RichHandler's columnar layout produces very narrow log output in containers -# without a TTY (Rich falls back to 80 columns, columns consume ~40 of those). -# Use a plain format when there's no terminal attached. +# Configure root logger. basicConfig(force=True) is intentionally root-logger-specific. +# RichHandler needs format="%(message)s" to prevent double-formatting by the root Formatter. +handler = create_log_handler() if sys.stderr.isatty(): logging.basicConfig( level=log_level, format="%(message)s", datefmt="[%X]", - handlers=[RichHandler()], + handlers=[handler], force=True, ) else: logging.basicConfig( level=log_level, - format="%(asctime)s %(levelname)-8s %(name)s:%(lineno)d %(message)s", + handlers=[handler], force=True, ) diff --git a/src/runners/uvicorn.py b/src/runners/uvicorn.py index 3cd55851a..b2aefafd7 100644 --- a/src/runners/uvicorn.py +++ b/src/runners/uvicorn.py @@ -1,39 +1,15 @@ """Uvicorn runner.""" import logging -import os import uvicorn -from constants import DEFAULT_LOG_LEVEL, LIGHTSPEED_STACK_LOG_LEVEL_ENV_VAR -from log import get_logger +from log import get_logger, resolve_log_level from models.config import ServiceConfiguration logger = get_logger(__name__) -def _resolve_log_level() -> int: - """Resolve the uvicorn log level from the environment. - - Reads the LIGHTSPEED_STACK_LOG_LEVEL environment variable and converts it - to a Python logging level constant. Falls back to the default log level - when the variable is unset or contains an invalid value. - - Returns: - The resolved logging level as an integer constant. - """ - level_str = os.environ.get(LIGHTSPEED_STACK_LOG_LEVEL_ENV_VAR, DEFAULT_LOG_LEVEL) - level = getattr(logging, level_str.upper(), None) - if not isinstance(level, int): - logger.warning( - "Invalid log level '%s', falling back to %s", - level_str, - DEFAULT_LOG_LEVEL, - ) - level = getattr(logging, DEFAULT_LOG_LEVEL) - return level - - def start_uvicorn(configuration: ServiceConfiguration) -> None: """Start the Uvicorn server using the provided service configuration. @@ -43,7 +19,7 @@ def start_uvicorn(configuration: ServiceConfiguration) -> None: `tls_certificate_path`, and `tls_key_password`). TLS fields may be None and will be forwarded to uvicorn.run as provided. """ - log_level = _resolve_log_level() + log_level = resolve_log_level() logger.info("Starting Uvicorn with log level %s", logging.getLevelName(log_level)) # please note: From bf2ccceb7944174525de0a3aaedbe199448b4105 Mon Sep 17 00:00:00 2001 From: Major Hayden Date: Tue, 24 Feb 2026 09:31:07 -0600 Subject: [PATCH 3/3] test(logging): add tests for centralized logging helpers Add parametrized tests for resolve_log_level() covering valid levels, invalid fallback, and unset default. Add tests for create_log_handler() verifying TTY returns RichHandler, non-TTY returns StreamHandler with the correct format. Update test_uvicorn_runner.py to import resolve_log_level from log instead of the deleted private _resolve_log_level from runners.uvicorn. Signed-off-by: Major Hayden --- tests/unit/runners/test_uvicorn_runner.py | 11 ++-- tests/unit/test_log.py | 63 ++++++++++++++++++++++- 2 files changed, 67 insertions(+), 7 deletions(-) diff --git a/tests/unit/runners/test_uvicorn_runner.py b/tests/unit/runners/test_uvicorn_runner.py index 34d7e796f..5c0ceb01e 100644 --- a/tests/unit/runners/test_uvicorn_runner.py +++ b/tests/unit/runners/test_uvicorn_runner.py @@ -7,8 +7,9 @@ from pytest_mock import MockerFixture from constants import LIGHTSPEED_STACK_LOG_LEVEL_ENV_VAR +from log import resolve_log_level from models.config import ServiceConfiguration, TLSConfiguration -from runners.uvicorn import _resolve_log_level, start_uvicorn +from runners.uvicorn import start_uvicorn def test_start_uvicorn(mocker: MockerFixture) -> None: @@ -146,17 +147,17 @@ def test_start_uvicorn_with_root_path(mocker: MockerFixture) -> None: def test_resolve_log_level_from_env( monkeypatch: pytest.MonkeyPatch, env_value: str, expected_level: int ) -> None: - """Test that _resolve_log_level resolves env var values to logging constants.""" + """Test that resolve_log_level resolves env var values to logging constants.""" monkeypatch.setenv(LIGHTSPEED_STACK_LOG_LEVEL_ENV_VAR, env_value) - assert _resolve_log_level() == expected_level + assert resolve_log_level() == expected_level def test_resolve_log_level_defaults_to_info( monkeypatch: pytest.MonkeyPatch, ) -> None: - """Test that _resolve_log_level falls back to INFO when the env var is unset.""" + """Test that resolve_log_level falls back to INFO when the env var is unset.""" monkeypatch.delenv(LIGHTSPEED_STACK_LOG_LEVEL_ENV_VAR, raising=False) - assert _resolve_log_level() == logging.INFO + assert resolve_log_level() == logging.INFO def test_start_uvicorn_respects_debug_log_level( diff --git a/tests/unit/test_log.py b/tests/unit/test_log.py index cb31d384f..47fcd6b8b 100644 --- a/tests/unit/test_log.py +++ b/tests/unit/test_log.py @@ -1,10 +1,13 @@ """Unit tests for functions defined in src/log.py.""" import logging + import pytest +from pytest_mock import MockerFixture +from rich.logging import RichHandler -from log import get_logger -from constants import LIGHTSPEED_STACK_LOG_LEVEL_ENV_VAR +from log import get_logger, resolve_log_level, create_log_handler +from constants import LIGHTSPEED_STACK_LOG_LEVEL_ENV_VAR, DEFAULT_LOG_FORMAT def test_get_logger() -> None: @@ -57,3 +60,59 @@ def test_get_logger_default_log_level(monkeypatch: pytest.MonkeyPatch) -> None: logger = get_logger("test_default") assert logger.level == logging.INFO + + +@pytest.mark.parametrize( + ("level_name", "expected_level"), + [ + ("DEBUG", logging.DEBUG), + ("debug", logging.DEBUG), + ("INFO", logging.INFO), + ("WARNING", logging.WARNING), + ("ERROR", logging.ERROR), + ("CRITICAL", logging.CRITICAL), + ("critical", logging.CRITICAL), + ], +) +def test_resolve_log_level( + monkeypatch: pytest.MonkeyPatch, level_name: str, expected_level: int +) -> None: + """Test that resolve_log_level correctly resolves valid level names.""" + monkeypatch.setenv(LIGHTSPEED_STACK_LOG_LEVEL_ENV_VAR, level_name) + assert resolve_log_level() == expected_level + + +def test_resolve_log_level_invalid_fallback(monkeypatch: pytest.MonkeyPatch) -> None: + """Test that resolve_log_level falls back to INFO for invalid values.""" + monkeypatch.setenv(LIGHTSPEED_STACK_LOG_LEVEL_ENV_VAR, "BOGUS") + assert resolve_log_level() == logging.INFO + + +def test_resolve_log_level_default(monkeypatch: pytest.MonkeyPatch) -> None: + """Test that resolve_log_level defaults to INFO when env var is unset.""" + monkeypatch.delenv(LIGHTSPEED_STACK_LOG_LEVEL_ENV_VAR, raising=False) + assert resolve_log_level() == logging.INFO + + +def test_create_log_handler_tty(mocker: MockerFixture) -> None: + """Test that create_log_handler returns RichHandler when TTY is available.""" + mocker.patch("sys.stderr.isatty", return_value=True) + handler = create_log_handler() + assert isinstance(handler, RichHandler) + + +def test_create_log_handler_non_tty(mocker: MockerFixture) -> None: + """Test that create_log_handler returns StreamHandler when no TTY.""" + mocker.patch("sys.stderr.isatty", return_value=False) + handler = create_log_handler() + assert isinstance(handler, logging.StreamHandler) + assert not isinstance(handler, RichHandler) + + +def test_create_log_handler_non_tty_format(mocker: MockerFixture) -> None: + """Test that non-TTY handler uses DEFAULT_LOG_FORMAT.""" + mocker.patch("sys.stderr.isatty", return_value=False) + handler = create_log_handler() + assert handler.formatter is not None + # pylint: disable=protected-access + assert handler.formatter._fmt == DEFAULT_LOG_FORMAT