From 9b3d78e4828f9292aa89b220a9b3010474906f86 Mon Sep 17 00:00:00 2001 From: Sam Doran Date: Mon, 4 May 2026 17:36:11 -0400 Subject: [PATCH 01/28] Create one place where logging is setup Meroge the existing config from uvicorn with the logging for lightspeed-stack with some modifications and pass that to uvicorn. This ensures the logging configs work together and do not clobber each other. Call setup_logging() early in the main entrypoint. --- src/lightspeed_stack.py | 27 +-------- src/log.py | 119 ++++++++++++++++++++-------------------- 2 files changed, 63 insertions(+), 83 deletions(-) diff --git a/src/lightspeed_stack.py b/src/lightspeed_stack.py index 4cbf40326..eccd19452 100644 --- a/src/lightspeed_stack.py +++ b/src/lightspeed_stack.py @@ -6,39 +6,18 @@ import logging import os -import sys from argparse import ArgumentParser import constants from configuration import configuration from constants import LIGHTSPEED_STACK_LOG_LEVEL_ENV_VAR -from log import create_log_handler, get_logger, resolve_log_level +from log import get_logger, setup_logging from runners.quota_scheduler import start_quota_scheduler from runners.uvicorn import start_uvicorn from utils import schema_dumper -# Resolve log level and handler from centralized logging utilities -log_level = resolve_log_level() - -# 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=[handler], - force=True, - ) -else: - logging.basicConfig( - level=log_level, - handlers=[handler], - force=True, - ) - -logger = get_logger(__name__) +setup_logging() +logger = get_logger(__file__) def create_argument_parser() -> ArgumentParser: diff --git a/src/log.py b/src/log.py index 389b32fca..bbd3c0c02 100644 --- a/src/log.py +++ b/src/log.py @@ -1,14 +1,20 @@ """Log utilities.""" import logging +import logging.config import os import sys +import typing as t +from functools import lru_cache +from pathlib import Path -from rich.logging import RichHandler +import uvicorn.config +from pydantic.v1.utils import deep_update from constants import ( DEFAULT_LOG_FORMAT, DEFAULT_LOG_LEVEL, + DEFAULT_LOGGER_NAME, LIGHTSPEED_STACK_DISABLE_RICH_HANDLER_ENV_VAR, LIGHTSPEED_STACK_LOG_LEVEL_ENV_VAR, ) @@ -50,62 +56,57 @@ def resolve_log_level() -> int: return validated_level -def create_log_handler() -> logging.Handler: - """ - Create and return a configured log handler based on TTY availability and environment settings. - - If LIGHTSPEED_STACK_DISABLE_RICH_HANDLER is set to any non-empty value, - returns a StreamHandler with plain-text formatting. Otherwise, if stderr - is connected to a terminal (TTY), returns a RichHandler for rich-formatted - console output. If neither condition is met, returns a StreamHandler with - plain-text formatting suitable for non-TTY environments (e.g., containers). - - Returns: - logging.Handler: A configured handler instance (RichHandler or StreamHandler). - """ - # Check if RichHandler is explicitly disabled via environment variable - if os.environ.get(LIGHTSPEED_STACK_DISABLE_RICH_HANDLER_ENV_VAR): - handler = logging.StreamHandler() - handler.setFormatter(logging.Formatter(DEFAULT_LOG_FORMAT)) - return handler - - 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: - """ - Get a logger configured for Rich console output. - - 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 - 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. - - Returns: - ------- - logging.Logger: The configured logger instance. - """ - logger = logging.getLogger(name) - - # Skip reconfiguration if logger already has handlers from a prior call - if logger.handlers: - return logger - logger.handlers = [create_log_handler()] - logger.propagate = False - logger.setLevel(resolve_log_level()) - return logger +@lru_cache +def setup_logging() -> dict[t.Any, t.Any]: + handler = "console" + log_level = resolve_log_level() + if sys.stderr.isatty() and not os.environ.get( + LIGHTSPEED_STACK_DISABLE_RICH_HANDLER_ENV_VAR + ): + handler = "rich" + + logging_conf = { + "version": 1, + "disable_existing_loggers": False, + "formatters": { + # RichHandler needs format="%(message)s" to prevent double-formatting by the root Formatter. + "rich": { + "format": "RICH %(message)s", + "datefmt": "[%X]", + }, + "console": { + "format": DEFAULT_LOG_FORMAT, + "datefmt": "%Y-%m-%d %H:%M:%S", + }, + }, + "handlers": { + "console": { + "formatter": "console", + "class": "logging.StreamHandler", + "stream": "ext://sys.stderr", + }, + "rich": { + "formatter": "rich", + "class": "rich.logging.RichHandler", + }, + }, + "loggers": { + DEFAULT_LOGGER_NAME: { + "handlers": [handler], + "level": log_level, + "propagate": False, + }, + }, + } + + merged_config = deep_update(uvicorn.config.LOGGING_CONFIG, logging_conf) + merged_config["formatters"]["access"]["fmt"] = ( + '%(asctime)s.%(msecs)03d %(levelprefix)s %(client_addr)s - "%(request_line)s" %(status_code)s' + ) + merged_config["formatters"]["default"]["fmt"] = ( + "%(asctime)s.%(msecs)03d %(levelprefix)s%(message)s" + ) + logging.config.dictConfig(merged_config) + + return merged_config From 73ca5a1737debfe5d68edf52114153c3c5f6a4c1 Mon Sep 17 00:00:00 2001 From: Sam Doran Date: Mon, 4 May 2026 17:39:13 -0400 Subject: [PATCH 02/28] Add a helper function to correctly construct the value that is usually in __name__. MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The logging library assumes __name__ will be “package.module.module”. Since this project does not have a package, the value for __name__ varies widely in each module. Thise breaks design assumpmtions of logging. To work around this, define a default logger name that is used as the primary configuration and add a helper function to always get the logger with a name that aligns with how logging works. --- src/constants.py | 1 + src/log.py | 3 +++ 2 files changed, 4 insertions(+) diff --git a/src/constants.py b/src/constants.py index 9756c4003..5e161ee26 100644 --- a/src/constants.py +++ b/src/constants.py @@ -248,6 +248,7 @@ # Environment variable name for configurable log level LIGHTSPEED_STACK_LOG_LEVEL_ENV_VAR: Final[str] = "LIGHTSPEED_STACK_LOG_LEVEL" # Default log level when environment variable is not set +DEFAULT_LOGGER_NAME = "lcs" DEFAULT_LOG_LEVEL: Final[str] = "INFO" # Default log format for plain-text logging in non-TTY environments DEFAULT_LOG_FORMAT: Final[str] = ( diff --git a/src/log.py b/src/log.py index bbd3c0c02..a5a2b7c20 100644 --- a/src/log.py +++ b/src/log.py @@ -56,6 +56,9 @@ def resolve_log_level() -> int: return validated_level +def get_logger(file: str) -> logging.Logger: + return logging.getLogger(f"{DEFAULT_LOGGER_NAME}.{Path(file).stem}") + @lru_cache def setup_logging() -> dict[t.Any, t.Any]: From 5e064f56fa2f5e88f94e5b8991e926d1e283b5cb Mon Sep 17 00:00:00 2001 From: Sam Doran Date: Mon, 4 May 2026 18:05:58 -0400 Subject: [PATCH 03/28] Get logger using __file__ instead of __name__ Since there is no root package for this project, manually set the logger and get the filename in order to show where the log message was emitted. --- src/a2a_storage/in_memory_context_store.py | 2 +- src/a2a_storage/postgres_context_store.py | 2 +- src/a2a_storage/sqlite_context_store.py | 2 +- src/a2a_storage/storage_factory.py | 2 +- src/app/database.py | 2 +- src/app/endpoints/a2a.py | 2 +- src/app/endpoints/authorized.py | 2 +- src/app/endpoints/config.py | 2 +- src/app/endpoints/conversations_v1.py | 2 +- src/app/endpoints/conversations_v2.py | 2 +- src/app/endpoints/feedback.py | 2 +- src/app/endpoints/health.py | 2 +- src/app/endpoints/info.py | 2 +- src/app/endpoints/mcp_auth.py | 2 +- src/app/endpoints/mcp_servers.py | 2 +- src/app/endpoints/models.py | 2 +- src/app/endpoints/prompts.py | 2 +- src/app/endpoints/providers.py | 2 +- src/app/endpoints/query.py | 2 +- src/app/endpoints/rags.py | 2 +- src/app/endpoints/responses.py | 2 +- src/app/endpoints/rlsapi_v1.py | 2 +- src/app/endpoints/root.py | 2 +- src/app/endpoints/shields.py | 2 +- src/app/endpoints/streaming_query.py | 2 +- src/app/endpoints/tools.py | 2 +- src/app/endpoints/vector_stores.py | 2 +- src/app/main.py | 2 +- src/authentication/__init__.py | 2 +- src/authentication/api_key_token.py | 2 +- src/authentication/jwk_token.py | 2 +- src/authentication/k8s.py | 2 +- src/authentication/noop.py | 2 +- src/authentication/noop_with_token.py | 2 +- src/authentication/rh_identity.py | 2 +- src/authorization/azure_token_manager.py | 2 +- src/authorization/middleware.py | 2 +- src/authorization/resolvers.py | 2 +- src/cache/cache_factory.py | 2 +- src/cache/in_memory_cache.py | 2 +- src/cache/noop_cache.py | 2 +- src/cache/postgres_cache.py | 2 +- src/cache/sqlite_cache.py | 2 +- src/client.py | 2 +- src/configuration.py | 2 +- src/llama_stack_configuration.py | 2 +- src/metrics/recording.py | 2 +- src/metrics/utils.py | 2 +- src/models/config.py | 2 +- src/observability/splunk.py | 2 +- src/quota/cluster_quota_limiter.py | 2 +- src/quota/connect_pg.py | 2 +- src/quota/connect_sqlite.py | 2 +- src/quota/quota_limiter.py | 2 +- src/quota/quota_limiter_factory.py | 2 +- src/quota/revokable_quota_limiter.py | 2 +- src/quota/token_usage_history.py | 2 +- src/quota/user_quota_limiter.py | 2 +- src/runners/quota_scheduler.py | 2 +- src/sentry.py | 2 +- src/telemetry/configuration_snapshot.py | 2 +- src/utils/endpoints.py | 2 +- src/utils/llama_stack_version.py | 2 +- src/utils/mcp_auth_headers.py | 2 +- src/utils/mcp_headers.py | 2 +- src/utils/mcp_oauth_probe.py | 2 +- src/utils/query.py | 2 +- src/utils/quota.py | 2 +- src/utils/responses.py | 2 +- src/utils/shields.py | 2 +- src/utils/stream_interrupts.py | 2 +- src/utils/token_counter.py | 2 +- src/utils/tool_formatter.py | 2 +- src/utils/transcripts.py | 2 +- src/utils/vector_search.py | 2 +- 75 files changed, 75 insertions(+), 75 deletions(-) diff --git a/src/a2a_storage/in_memory_context_store.py b/src/a2a_storage/in_memory_context_store.py index 0699ccd03..e053661d0 100644 --- a/src/a2a_storage/in_memory_context_store.py +++ b/src/a2a_storage/in_memory_context_store.py @@ -6,7 +6,7 @@ from a2a_storage.context_store import A2AContextStore from log import get_logger -logger = get_logger(__name__) +logger = get_logger(__file__) class InMemoryA2AContextStore(A2AContextStore): diff --git a/src/a2a_storage/postgres_context_store.py b/src/a2a_storage/postgres_context_store.py index 2d630af9f..900924409 100644 --- a/src/a2a_storage/postgres_context_store.py +++ b/src/a2a_storage/postgres_context_store.py @@ -9,7 +9,7 @@ from a2a_storage.context_store import A2AContextStore from log import get_logger -logger = get_logger(__name__) +logger = get_logger(__file__) # Define the table metadata metadata = MetaData() diff --git a/src/a2a_storage/sqlite_context_store.py b/src/a2a_storage/sqlite_context_store.py index 6cdbabb23..2f94b0f77 100644 --- a/src/a2a_storage/sqlite_context_store.py +++ b/src/a2a_storage/sqlite_context_store.py @@ -8,7 +8,7 @@ from a2a_storage.context_store import A2AContextStore from log import get_logger -logger = get_logger(__name__) +logger = get_logger(__file__) # Define the table metadata metadata = MetaData() diff --git a/src/a2a_storage/storage_factory.py b/src/a2a_storage/storage_factory.py index 16870eb10..4a6f223cc 100644 --- a/src/a2a_storage/storage_factory.py +++ b/src/a2a_storage/storage_factory.py @@ -13,7 +13,7 @@ from log import get_logger from models.config import A2AStateConfiguration -logger = get_logger(__name__) +logger = get_logger(__file__) class A2AStorageFactory: diff --git a/src/app/database.py b/src/app/database.py index 0b6881896..53f0dec40 100644 --- a/src/app/database.py +++ b/src/app/database.py @@ -13,7 +13,7 @@ from models.config import PostgreSQLDatabaseConfiguration, SQLiteDatabaseConfiguration from models.database.base import Base -logger = get_logger(__name__) +logger = get_logger(__file__) # pylint: disable=invalid-name engine: Optional[Engine] = None diff --git a/src/app/endpoints/a2a.py b/src/app/endpoints/a2a.py index 99c53b8d6..589ebd8ad 100644 --- a/src/app/endpoints/a2a.py +++ b/src/app/endpoints/a2a.py @@ -61,7 +61,7 @@ from utils.suid import normalize_conversation_id, to_llama_stack_conversation_id from version import __version__ -logger = get_logger(__name__) +logger = get_logger(__file__) router = APIRouter(tags=["a2a"]) auth_dependency = get_auth_dependency() diff --git a/src/app/endpoints/authorized.py b/src/app/endpoints/authorized.py index 175c42a1f..83d79e266 100644 --- a/src/app/endpoints/authorized.py +++ b/src/app/endpoints/authorized.py @@ -15,7 +15,7 @@ ) from models.api.responses.successful import AuthorizedResponse -logger = get_logger(__name__) +logger = get_logger(__file__) router = APIRouter(tags=["authorized"]) authorized_responses: dict[int | str, dict[str, Any]] = { diff --git a/src/app/endpoints/config.py b/src/app/endpoints/config.py index 120180817..fda13c41f 100644 --- a/src/app/endpoints/config.py +++ b/src/app/endpoints/config.py @@ -20,7 +20,7 @@ from models.config import Action from utils.endpoints import check_configuration_loaded -logger = get_logger(__name__) +logger = get_logger(__file__) router = APIRouter(tags=["config"]) diff --git a/src/app/endpoints/conversations_v1.py b/src/app/endpoints/conversations_v1.py index 4bc9237cb..4d7db1bed 100644 --- a/src/app/endpoints/conversations_v1.py +++ b/src/app/endpoints/conversations_v1.py @@ -55,7 +55,7 @@ to_llama_stack_conversation_id, ) -logger = get_logger(__name__) +logger = get_logger(__file__) router = APIRouter(tags=["conversations_v1"]) conversation_get_responses: dict[int | str, dict[str, Any]] = { diff --git a/src/app/endpoints/conversations_v2.py b/src/app/endpoints/conversations_v2.py index 1f61220da..3c9a94c35 100644 --- a/src/app/endpoints/conversations_v2.py +++ b/src/app/endpoints/conversations_v2.py @@ -33,7 +33,7 @@ from utils.endpoints import check_configuration_loaded from utils.suid import check_suid -logger = get_logger(__name__) +logger = get_logger(__file__) router = APIRouter(tags=["conversations_v2"]) diff --git a/src/app/endpoints/feedback.py b/src/app/endpoints/feedback.py index f01e0fb16..b6396cd23 100644 --- a/src/app/endpoints/feedback.py +++ b/src/app/endpoints/feedback.py @@ -31,7 +31,7 @@ from utils.endpoints import check_configuration_loaded, retrieve_conversation from utils.suid import get_suid -logger = get_logger(__name__) +logger = get_logger(__file__) router = APIRouter(prefix="/feedback", tags=["feedback"]) feedback_status_lock = threading.Lock() diff --git a/src/app/endpoints/health.py b/src/app/endpoints/health.py index b718dc178..2174ad074 100644 --- a/src/app/endpoints/health.py +++ b/src/app/endpoints/health.py @@ -33,7 +33,7 @@ from models.config import Action from utils.degraded_mode import DegradedModeTracker -logger = get_logger(__name__) +logger = get_logger(__file__) router = APIRouter(tags=["health"]) diff --git a/src/app/endpoints/info.py b/src/app/endpoints/info.py index 52490e611..2550b033a 100644 --- a/src/app/endpoints/info.py +++ b/src/app/endpoints/info.py @@ -21,7 +21,7 @@ from models.config import Action from version import __version__ -logger = get_logger(__name__) +logger = get_logger(__file__) router = APIRouter(tags=["info"]) diff --git a/src/app/endpoints/mcp_auth.py b/src/app/endpoints/mcp_auth.py index 62aea7615..1a9e885cf 100644 --- a/src/app/endpoints/mcp_auth.py +++ b/src/app/endpoints/mcp_auth.py @@ -22,7 +22,7 @@ from models.config import Action from utils.endpoints import check_configuration_loaded -logger = get_logger(__name__) +logger = get_logger(__file__) router = APIRouter(prefix="/mcp-auth", tags=["mcp-auth"]) diff --git a/src/app/endpoints/mcp_servers.py b/src/app/endpoints/mcp_servers.py index 045334a49..73d55c00b 100644 --- a/src/app/endpoints/mcp_servers.py +++ b/src/app/endpoints/mcp_servers.py @@ -30,7 +30,7 @@ from models.config import Action, ModelContextProtocolServer from utils.endpoints import check_configuration_loaded -logger = get_logger(__name__) +logger = get_logger(__file__) router = APIRouter(tags=["mcp-servers"]) diff --git a/src/app/endpoints/models.py b/src/app/endpoints/models.py index fa435a6f9..5dd76ef60 100644 --- a/src/app/endpoints/models.py +++ b/src/app/endpoints/models.py @@ -24,7 +24,7 @@ from models.config import Action from utils.endpoints import check_configuration_loaded -logger = get_logger(__name__) +logger = get_logger(__file__) router = APIRouter(tags=["models"]) diff --git a/src/app/endpoints/prompts.py b/src/app/endpoints/prompts.py index 6c85603c8..625928e97 100644 --- a/src/app/endpoints/prompts.py +++ b/src/app/endpoints/prompts.py @@ -33,7 +33,7 @@ from utils.query import handle_known_apistatus_errors from utils.suid import check_suid_prompt -logger = get_logger(__name__) +logger = get_logger(__file__) router = APIRouter(tags=["prompts"]) diff --git a/src/app/endpoints/providers.py b/src/app/endpoints/providers.py index e6cb8ed07..d521b5483 100644 --- a/src/app/endpoints/providers.py +++ b/src/app/endpoints/providers.py @@ -28,7 +28,7 @@ from models.config import Action from utils.endpoints import check_configuration_loaded -logger = get_logger(__name__) +logger = get_logger(__file__) router = APIRouter(tags=["providers"]) diff --git a/src/app/endpoints/query.py b/src/app/endpoints/query.py index 800b15374..6a2cb2800 100644 --- a/src/app/endpoints/query.py +++ b/src/app/endpoints/query.py @@ -77,7 +77,7 @@ from utils.suid import normalize_conversation_id from utils.vector_search import build_rag_context -logger = get_logger(__name__) +logger = get_logger(__file__) router = APIRouter(tags=["query"]) query_response: dict[int | str, dict[str, Any]] = { diff --git a/src/app/endpoints/rags.py b/src/app/endpoints/rags.py index 8cf5c7679..bca41295d 100644 --- a/src/app/endpoints/rags.py +++ b/src/app/endpoints/rags.py @@ -27,7 +27,7 @@ from models.config import Action, ByokRag from utils.endpoints import check_configuration_loaded -logger = get_logger(__name__) +logger = get_logger(__file__) router = APIRouter(tags=["rags"]) diff --git a/src/app/endpoints/responses.py b/src/app/endpoints/responses.py index 6d0cd9b05..1340f9b8d 100644 --- a/src/app/endpoints/responses.py +++ b/src/app/endpoints/responses.py @@ -115,7 +115,7 @@ build_rag_context, ) -logger = get_logger(__name__) +logger = get_logger(__file__) router = APIRouter(tags=["responses"]) _USER_AGENT_MAX_LENGTH: Final[int] = 128 diff --git a/src/app/endpoints/rlsapi_v1.py b/src/app/endpoints/rlsapi_v1.py index 7a354cbc7..30e2ebcdd 100644 --- a/src/app/endpoints/rlsapi_v1.py +++ b/src/app/endpoints/rlsapi_v1.py @@ -64,7 +64,7 @@ from utils.shields import run_shield_moderation from utils.suid import get_suid -logger = get_logger(__name__) +logger = get_logger(__file__) router = APIRouter(tags=["rlsapi-v1"]) diff --git a/src/app/endpoints/root.py b/src/app/endpoints/root.py index 956a6805b..7d77396fe 100644 --- a/src/app/endpoints/root.py +++ b/src/app/endpoints/root.py @@ -17,7 +17,7 @@ ) from models.config import Action -logger = get_logger(__name__) +logger = get_logger(__file__) router = APIRouter(tags=["root"]) diff --git a/src/app/endpoints/shields.py b/src/app/endpoints/shields.py index 641064234..52ed8720b 100644 --- a/src/app/endpoints/shields.py +++ b/src/app/endpoints/shields.py @@ -23,7 +23,7 @@ from models.config import Action from utils.endpoints import check_configuration_loaded -logger = get_logger(__name__) +logger = get_logger(__file__) router = APIRouter(tags=["shields"]) diff --git a/src/app/endpoints/streaming_query.py b/src/app/endpoints/streaming_query.py index fc7d740c5..14fec097b 100644 --- a/src/app/endpoints/streaming_query.py +++ b/src/app/endpoints/streaming_query.py @@ -139,7 +139,7 @@ from utils.suid import get_suid, normalize_conversation_id from utils.vector_search import build_rag_context -logger = get_logger(__name__) +logger = get_logger(__file__) router = APIRouter(tags=["streaming_query"]) # Tracks background topic summary tasks for graceful shutdown. diff --git a/src/app/endpoints/tools.py b/src/app/endpoints/tools.py index f0941a6a6..46375f7e3 100644 --- a/src/app/endpoints/tools.py +++ b/src/app/endpoints/tools.py @@ -30,7 +30,7 @@ from utils.mcp_oauth_probe import check_mcp_auth from utils.tool_formatter import format_tools_list -logger = get_logger(__name__) +logger = get_logger(__file__) router = APIRouter(tags=["tools"]) diff --git a/src/app/endpoints/vector_stores.py b/src/app/endpoints/vector_stores.py index ee55bc00e..6225d8046 100644 --- a/src/app/endpoints/vector_stores.py +++ b/src/app/endpoints/vector_stores.py @@ -49,7 +49,7 @@ from utils.endpoints import check_configuration_loaded from utils.query import handle_known_apistatus_errors -logger = get_logger(__name__) +logger = get_logger(__file__) router = APIRouter(tags=["vector-stores"]) diff --git a/src/app/main.py b/src/app/main.py index e54c730bc..28171a015 100644 --- a/src/app/main.py +++ b/src/app/main.py @@ -30,7 +30,7 @@ from utils.degraded_mode import DegradedModeTracker from utils.llama_stack_version import check_llama_stack_version -logger = get_logger(__name__) +logger = get_logger(__file__) logger.info("Initializing app") diff --git a/src/authentication/__init__.py b/src/authentication/__init__.py index 44e8ddc42..434c69876 100644 --- a/src/authentication/__init__.py +++ b/src/authentication/__init__.py @@ -16,7 +16,7 @@ from configuration import LogicError, configuration from log import get_logger -logger = get_logger(__name__) +logger = get_logger(__file__) def get_auth_dependency( # pylint: disable=too-many-return-statements diff --git a/src/authentication/api_key_token.py b/src/authentication/api_key_token.py index 9a53363ff..3dc5305ae 100644 --- a/src/authentication/api_key_token.py +++ b/src/authentication/api_key_token.py @@ -21,7 +21,7 @@ from log import get_logger from models.config import APIKeyTokenConfiguration -logger = get_logger(__name__) +logger = get_logger(__file__) def _should_skip_auth(request: Request) -> bool: diff --git a/src/authentication/jwk_token.py b/src/authentication/jwk_token.py index 3ac275cc7..744e88903 100644 --- a/src/authentication/jwk_token.py +++ b/src/authentication/jwk_token.py @@ -26,7 +26,7 @@ from models.api.responses.error import UnauthorizedResponse from models.config import JwkConfiguration -logger = get_logger(__name__) +logger = get_logger(__file__) # Global JWK registry to avoid re-fetching JWKs for each request. Cached for 1 # hour, keys are unlikely to change frequently. diff --git a/src/authentication/k8s.py b/src/authentication/k8s.py index b86953169..42ff4fe16 100644 --- a/src/authentication/k8s.py +++ b/src/authentication/k8s.py @@ -21,7 +21,7 @@ UnauthorizedResponse, ) -logger = get_logger(__name__) +logger = get_logger(__file__) CLUSTER_ID_LOCAL = "local" diff --git a/src/authentication/noop.py b/src/authentication/noop.py index 6d32f45c3..c193c5ac8 100644 --- a/src/authentication/noop.py +++ b/src/authentication/noop.py @@ -11,7 +11,7 @@ ) from log import get_logger -logger = get_logger(__name__) +logger = get_logger(__file__) class NoopAuthDependency(AuthInterface): # pylint: disable=too-few-public-methods diff --git a/src/authentication/noop_with_token.py b/src/authentication/noop_with_token.py index 0656d952a..588ad195a 100644 --- a/src/authentication/noop_with_token.py +++ b/src/authentication/noop_with_token.py @@ -20,7 +20,7 @@ ) from log import get_logger -logger = get_logger(__name__) +logger = get_logger(__file__) class NoopWithTokenAuthDependency( diff --git a/src/authentication/rh_identity.py b/src/authentication/rh_identity.py index ff0a560b7..9197758cd 100644 --- a/src/authentication/rh_identity.py +++ b/src/authentication/rh_identity.py @@ -20,7 +20,7 @@ ) from log import get_logger -logger = get_logger(__name__) +logger = get_logger(__file__) RH_INSIGHTS_REQUEST_ID_HEADER = "x-rh-insights-request-id" REQUEST_ID_HEADER = "x-request-id" diff --git a/src/authorization/azure_token_manager.py b/src/authorization/azure_token_manager.py index 702efe465..28824bc18 100644 --- a/src/authorization/azure_token_manager.py +++ b/src/authorization/azure_token_manager.py @@ -12,7 +12,7 @@ from log import get_logger from utils.types import Singleton -logger = get_logger(__name__) +logger = get_logger(__file__) # Refresh token before actual expiration to avoid edge cases TOKEN_EXPIRATION_LEEWAY = 30 # seconds diff --git a/src/authorization/middleware.py b/src/authorization/middleware.py index 93cb5e7e0..9d267d823 100644 --- a/src/authorization/middleware.py +++ b/src/authorization/middleware.py @@ -24,7 +24,7 @@ ) from models.config import Action -logger = get_logger(__name__) +logger = get_logger(__file__) @lru_cache(maxsize=1) diff --git a/src/authorization/resolvers.py b/src/authorization/resolvers.py index b848f8f34..b4ee76dda 100644 --- a/src/authorization/resolvers.py +++ b/src/authorization/resolvers.py @@ -12,7 +12,7 @@ from log import get_logger from models.config import AccessRule, Action, JsonPathOperator, JwtRoleRule -logger = get_logger(__name__) +logger = get_logger(__file__) UserRoles = set[str] diff --git a/src/cache/cache_factory.py b/src/cache/cache_factory.py index cbc066a29..93826fa36 100644 --- a/src/cache/cache_factory.py +++ b/src/cache/cache_factory.py @@ -9,7 +9,7 @@ from log import get_logger from models.config import ConversationHistoryConfiguration -logger = get_logger(__name__) +logger = get_logger(__file__) # pylint: disable=R0903 diff --git a/src/cache/in_memory_cache.py b/src/cache/in_memory_cache.py index 302893a42..e87b6e6e6 100644 --- a/src/cache/in_memory_cache.py +++ b/src/cache/in_memory_cache.py @@ -10,7 +10,7 @@ from models.config import InMemoryCacheConfig from utils.connection_decorator import connection -logger = get_logger(__name__) +logger = get_logger(__file__) class InMemoryCache(Cache): diff --git a/src/cache/noop_cache.py b/src/cache/noop_cache.py index a0bbb017d..ef4f7910c 100644 --- a/src/cache/noop_cache.py +++ b/src/cache/noop_cache.py @@ -9,7 +9,7 @@ from models.compaction import ConversationSummary from utils.connection_decorator import connection -logger = get_logger(__name__) +logger = get_logger(__file__) class NoopCache(Cache): diff --git a/src/cache/postgres_cache.py b/src/cache/postgres_cache.py index ea0661a3d..dd993e6ae 100644 --- a/src/cache/postgres_cache.py +++ b/src/cache/postgres_cache.py @@ -20,7 +20,7 @@ from models.config import PostgreSQLDatabaseConfiguration from utils.connection_decorator import connection -logger = get_logger(__name__) +logger = get_logger(__file__) class PostgresCache(Cache): diff --git a/src/cache/sqlite_cache.py b/src/cache/sqlite_cache.py index 6e6eae9d7..cc30cae26 100644 --- a/src/cache/sqlite_cache.py +++ b/src/cache/sqlite_cache.py @@ -19,7 +19,7 @@ from models.config import SQLiteDatabaseConfiguration from utils.connection_decorator import connection -logger = get_logger(__name__) +logger = get_logger(__file__) class SQLiteCache(Cache): diff --git a/src/client.py b/src/client.py index d66d5dfb3..eea7acbee 100644 --- a/src/client.py +++ b/src/client.py @@ -25,7 +25,7 @@ from models.config import LlamaStackConfiguration from utils.types import Singleton -logger = get_logger(__name__) +logger = get_logger(__file__) class AsyncLlamaStackClientHolder(metaclass=Singleton): diff --git a/src/configuration.py b/src/configuration.py index e95e89083..2fe677d65 100644 --- a/src/configuration.py +++ b/src/configuration.py @@ -40,7 +40,7 @@ from quota.quota_limiter_factory import QuotaLimiterFactory from quota.token_usage_history import TokenUsageHistory -logger = get_logger(__name__) +logger = get_logger(__file__) def replace_env_vars_preserving_native_override( diff --git a/src/llama_stack_configuration.py b/src/llama_stack_configuration.py index e9caebe74..ff5ed9ceb 100644 --- a/src/llama_stack_configuration.py +++ b/src/llama_stack_configuration.py @@ -30,7 +30,7 @@ import constants from log import get_logger -logger = get_logger(__name__) +logger = get_logger(__file__) # Maps a UnifiedInferenceProvider.type (canonical, backend-agnostic vocabulary) # to the Llama Stack provider_type emitted by apply_high_level_inference. The diff --git a/src/metrics/recording.py b/src/metrics/recording.py index c41c105b5..2013660f9 100644 --- a/src/metrics/recording.py +++ b/src/metrics/recording.py @@ -12,7 +12,7 @@ import metrics from log import get_logger -logger = get_logger(__name__) +logger = get_logger(__file__) @contextmanager diff --git a/src/metrics/utils.py b/src/metrics/utils.py index afb832d29..fa6d44534 100644 --- a/src/metrics/utils.py +++ b/src/metrics/utils.py @@ -6,7 +6,7 @@ from log import get_logger from utils.endpoints import check_configuration_loaded -logger = get_logger(__name__) +logger = get_logger(__file__) async def setup_model_metrics() -> None: diff --git a/src/models/config.py b/src/models/config.py index 0563047b5..67b7d2fe0 100644 --- a/src/models/config.py +++ b/src/models/config.py @@ -32,7 +32,7 @@ from utils import checks from utils.mcp_auth_headers import resolve_authorization_headers -logger = get_logger(__name__) +logger = get_logger(__file__) class ConfigurationBase(BaseModel): diff --git a/src/observability/splunk.py b/src/observability/splunk.py index 2763b0ef1..95aa6dcc6 100644 --- a/src/observability/splunk.py +++ b/src/observability/splunk.py @@ -12,7 +12,7 @@ from log import get_logger from version import __version__ -logger = get_logger(__name__) +logger = get_logger(__file__) def _get_hostname() -> str: diff --git a/src/quota/cluster_quota_limiter.py b/src/quota/cluster_quota_limiter.py index f378f2aef..ed08613b5 100644 --- a/src/quota/cluster_quota_limiter.py +++ b/src/quota/cluster_quota_limiter.py @@ -4,7 +4,7 @@ from models.config import QuotaHandlersConfiguration from quota.revokable_quota_limiter import RevokableQuotaLimiter -logger = get_logger(__name__) +logger = get_logger(__file__) class ClusterQuotaLimiter(RevokableQuotaLimiter): diff --git a/src/quota/connect_pg.py b/src/quota/connect_pg.py index e74700a5d..fef185b5e 100644 --- a/src/quota/connect_pg.py +++ b/src/quota/connect_pg.py @@ -7,7 +7,7 @@ from log import get_logger from models.config import PostgreSQLDatabaseConfiguration -logger = get_logger(__name__) +logger = get_logger(__file__) def connect_pg(config: PostgreSQLDatabaseConfiguration) -> Any: diff --git a/src/quota/connect_sqlite.py b/src/quota/connect_sqlite.py index a745f57cb..f6073d307 100644 --- a/src/quota/connect_sqlite.py +++ b/src/quota/connect_sqlite.py @@ -6,7 +6,7 @@ from log import get_logger from models.config import SQLiteDatabaseConfiguration -logger = get_logger(__name__) +logger = get_logger(__file__) def connect_sqlite(config: SQLiteDatabaseConfiguration) -> Any: diff --git a/src/quota/quota_limiter.py b/src/quota/quota_limiter.py index 9fdc8adbe..d0f48adb7 100644 --- a/src/quota/quota_limiter.py +++ b/src/quota/quota_limiter.py @@ -42,7 +42,7 @@ from quota.connect_pg import connect_pg from quota.connect_sqlite import connect_sqlite -logger = get_logger(__name__) +logger = get_logger(__file__) class QuotaLimiter(ABC): diff --git a/src/quota/quota_limiter_factory.py b/src/quota/quota_limiter_factory.py index 6e86e8d31..418ea0340 100644 --- a/src/quota/quota_limiter_factory.py +++ b/src/quota/quota_limiter_factory.py @@ -7,7 +7,7 @@ from quota.quota_limiter import QuotaLimiter from quota.user_quota_limiter import UserQuotaLimiter -logger = get_logger(__name__) +logger = get_logger(__file__) # pylint: disable=too-few-public-methods diff --git a/src/quota/revokable_quota_limiter.py b/src/quota/revokable_quota_limiter.py index 8e51e18b1..d7dfa2a3a 100644 --- a/src/quota/revokable_quota_limiter.py +++ b/src/quota/revokable_quota_limiter.py @@ -20,7 +20,7 @@ ) from utils.connection_decorator import connection -logger = get_logger(__name__) +logger = get_logger(__file__) class RevokableQuotaLimiter(QuotaLimiter): diff --git a/src/quota/token_usage_history.py b/src/quota/token_usage_history.py index 0ac56f860..d3960ac94 100644 --- a/src/quota/token_usage_history.py +++ b/src/quota/token_usage_history.py @@ -26,7 +26,7 @@ ) from utils.connection_decorator import connection -logger = get_logger(__name__) +logger = get_logger(__file__) class TokenUsageHistory: diff --git a/src/quota/user_quota_limiter.py b/src/quota/user_quota_limiter.py index 67cea6bfc..6bdbc7020 100644 --- a/src/quota/user_quota_limiter.py +++ b/src/quota/user_quota_limiter.py @@ -4,7 +4,7 @@ from models.config import QuotaHandlersConfiguration from quota.revokable_quota_limiter import RevokableQuotaLimiter -logger = get_logger(__name__) +logger = get_logger(__file__) class UserQuotaLimiter(RevokableQuotaLimiter): diff --git a/src/runners/quota_scheduler.py b/src/runners/quota_scheduler.py index de9ce7451..3d9d4bfda 100644 --- a/src/runners/quota_scheduler.py +++ b/src/runners/quota_scheduler.py @@ -22,7 +22,7 @@ RESET_QUOTA_STATEMENT_SQLITE, ) -logger = get_logger(__name__) +logger = get_logger(__file__) # pylint: disable=R0912 diff --git a/src/sentry.py b/src/sentry.py index e8040b54c..28c5d24a6 100644 --- a/src/sentry.py +++ b/src/sentry.py @@ -18,7 +18,7 @@ ) from log import get_logger -logger = get_logger(__name__) +logger = get_logger(__file__) def sentry_traces_sampler(tracing_context: dict) -> float: diff --git a/src/telemetry/configuration_snapshot.py b/src/telemetry/configuration_snapshot.py index e0e9a9fe2..ccd37df36 100644 --- a/src/telemetry/configuration_snapshot.py +++ b/src/telemetry/configuration_snapshot.py @@ -21,7 +21,7 @@ from log import get_logger from models.config import Configuration -logger = get_logger(__name__) +logger = get_logger(__file__) # Masking output constants CONFIGURED: Literal["configured"] = "configured" diff --git a/src/utils/endpoints.py b/src/utils/endpoints.py index 5ea928b51..a4f837a51 100644 --- a/src/utils/endpoints.py +++ b/src/utils/endpoints.py @@ -24,7 +24,7 @@ from utils.responses import create_new_conversation from utils.suid import normalize_conversation_id, to_llama_stack_conversation_id -logger = get_logger(__name__) +logger = get_logger(__file__) def delete_conversation(conversation_id: str) -> bool: diff --git a/src/utils/llama_stack_version.py b/src/utils/llama_stack_version.py index 7075a94ec..d38fa11eb 100644 --- a/src/utils/llama_stack_version.py +++ b/src/utils/llama_stack_version.py @@ -15,7 +15,7 @@ ) from log import get_logger -logger = get_logger(__name__) +logger = get_logger(__file__) class InvalidLlamaStackVersionException(Exception): diff --git a/src/utils/mcp_auth_headers.py b/src/utils/mcp_auth_headers.py index d89890477..c8d3ee58b 100644 --- a/src/utils/mcp_auth_headers.py +++ b/src/utils/mcp_auth_headers.py @@ -5,7 +5,7 @@ import constants from log import get_logger -logger = get_logger(__name__) +logger = get_logger(__file__) def resolve_authorization_headers( diff --git a/src/utils/mcp_headers.py b/src/utils/mcp_headers.py index 980d7a421..809436a6a 100644 --- a/src/utils/mcp_headers.py +++ b/src/utils/mcp_headers.py @@ -12,7 +12,7 @@ from log import get_logger from models.config import ModelContextProtocolServer -logger = get_logger(__name__) +logger = get_logger(__file__) type McpHeaders = dict[str, dict[str, str]] diff --git a/src/utils/mcp_oauth_probe.py b/src/utils/mcp_oauth_probe.py index 570e968eb..73134556d 100644 --- a/src/utils/mcp_oauth_probe.py +++ b/src/utils/mcp_oauth_probe.py @@ -17,7 +17,7 @@ from models.api.responses.error import UnauthorizedResponse from utils.mcp_headers import McpHeaders, build_mcp_headers -logger = get_logger(__name__) +logger = get_logger(__file__) async def check_mcp_auth( diff --git a/src/utils/query.py b/src/utils/query.py index 4ccb3abeb..a49ea2a7a 100644 --- a/src/utils/query.py +++ b/src/utils/query.py @@ -42,7 +42,7 @@ store_transcript, ) -logger = get_logger(__name__) +logger = get_logger(__file__) def is_context_length_error(error_message: str) -> bool: diff --git a/src/utils/quota.py b/src/utils/quota.py index b66d9b022..e5e898088 100644 --- a/src/utils/quota.py +++ b/src/utils/quota.py @@ -15,7 +15,7 @@ from quota.quota_limiter import QuotaLimiter from quota.token_usage_history import TokenUsageHistory -logger = get_logger(__name__) +logger = get_logger(__file__) # pylint: disable=R0913,R0917 diff --git a/src/utils/responses.py b/src/utils/responses.py index 3141742d8..f578d9f65 100644 --- a/src/utils/responses.py +++ b/src/utils/responses.py @@ -124,7 +124,7 @@ from utils.suid import to_llama_stack_conversation_id from utils.token_counter import TokenCounter -logger = get_logger(__name__) +logger = get_logger(__file__) async def get_vector_store_ids( diff --git a/src/utils/shields.py b/src/utils/shields.py index 5dca71ad3..abf58a7f6 100644 --- a/src/utils/shields.py +++ b/src/utils/shields.py @@ -32,7 +32,7 @@ ) from utils.query import handle_known_apistatus_errors -logger = get_logger(__name__) +logger = get_logger(__file__) async def get_available_shields(client: AsyncLlamaStackClient) -> list[str]: diff --git a/src/utils/stream_interrupts.py b/src/utils/stream_interrupts.py index 5afaf92f8..55fa0937b 100644 --- a/src/utils/stream_interrupts.py +++ b/src/utils/stream_interrupts.py @@ -26,7 +26,7 @@ from utils.shields import append_turn_to_conversation from utils.types import Singleton -logger = get_logger(__name__) +logger = get_logger(__file__) @dataclass diff --git a/src/utils/token_counter.py b/src/utils/token_counter.py index 94f0667d0..c439be8a5 100644 --- a/src/utils/token_counter.py +++ b/src/utils/token_counter.py @@ -4,7 +4,7 @@ from log import get_logger -logger = get_logger(__name__) +logger = get_logger(__file__) @dataclass diff --git a/src/utils/tool_formatter.py b/src/utils/tool_formatter.py index 4b55141ea..5619f9c45 100644 --- a/src/utils/tool_formatter.py +++ b/src/utils/tool_formatter.py @@ -5,7 +5,7 @@ from log import get_logger -logger = get_logger(__name__) +logger = get_logger(__file__) def format_tool_response(tool_dict: dict[str, Any]) -> dict[str, Any]: diff --git a/src/utils/transcripts.py b/src/utils/transcripts.py index 8f001c3ce..b4c9f473b 100644 --- a/src/utils/transcripts.py +++ b/src/utils/transcripts.py @@ -21,7 +21,7 @@ from models.common.turn_summary import TurnSummary from utils.suid import get_suid -logger = get_logger(__name__) +logger = get_logger(__file__) def _hash_user_id(user_id: str) -> str: diff --git a/src/utils/vector_search.py b/src/utils/vector_search.py index 7267ddb92..e4e6cf577 100644 --- a/src/utils/vector_search.py +++ b/src/utils/vector_search.py @@ -24,7 +24,7 @@ from utils.reranker import apply_byok_rerank_boost, rerank_chunks_with_cross_encoder from utils.responses import resolve_vector_store_ids -logger = get_logger(__name__) +logger = get_logger(__file__) def _filter_documents_for_chunks( From a388a80f8935eba6adcbdda8edd74240cb641b81 Mon Sep 17 00:00:00 2001 From: Sam Doran Date: Mon, 4 May 2026 18:09:11 -0400 Subject: [PATCH 04/28] Pass logging config to uvicorn --- src/runners/uvicorn.py | 12 +++++++++--- 1 file changed, 9 insertions(+), 3 deletions(-) diff --git a/src/runners/uvicorn.py b/src/runners/uvicorn.py index 6e217095e..e857827ea 100644 --- a/src/runners/uvicorn.py +++ b/src/runners/uvicorn.py @@ -4,13 +4,16 @@ import uvicorn -from log import get_logger, resolve_log_level +from log import get_logger, resolve_log_level, setup_logging from models.config import ServiceConfiguration -logger = get_logger(__name__) +logger = get_logger(__file__) -def start_uvicorn(configuration: ServiceConfiguration) -> None: +def start_uvicorn( + configuration: ServiceConfiguration, + log_config: dict | None = None, +) -> None: """Start the Uvicorn server using the provided service configuration. Parameters: @@ -22,6 +25,8 @@ def start_uvicorn(configuration: ServiceConfiguration) -> None: """ log_level = resolve_log_level() logger.info("Starting Uvicorn with log level %s", logging.getLevelName(log_level)) + if log_config is None: + log_config = setup_logging() # please note: # TLS fields can be None, which means we will pass those values as None to uvicorn.run @@ -30,6 +35,7 @@ def start_uvicorn(configuration: ServiceConfiguration) -> None: host=configuration.host, port=configuration.port, workers=configuration.workers, + log_config=log_config, log_level=log_level, ssl_keyfile=configuration.tls_config.tls_key_path, ssl_certfile=configuration.tls_config.tls_certificate_path, From 92cdb8f942184a0cf807edd6376811bb5cdfe34b Mon Sep 17 00:00:00 2001 From: Sam Doran Date: Mon, 4 May 2026 18:09:31 -0400 Subject: [PATCH 05/28] Fine tune default log format Use levelprefix for uvicorn.logging.DefaultFormatte. Move filename and position to end of line so that information is arranged in most important order from left to right within the line, where the message came from being least relevant in my thinking compared to the time, log level, and actual message. --- src/constants.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/constants.py b/src/constants.py index 5e161ee26..ed77219ed 100644 --- a/src/constants.py +++ b/src/constants.py @@ -252,7 +252,7 @@ DEFAULT_LOG_LEVEL: Final[str] = "INFO" # Default log format for plain-text logging in non-TTY environments DEFAULT_LOG_FORMAT: Final[str] = ( - "%(asctime)s %(levelname)-8s %(name)s:%(lineno)d %(message)s" + "%(asctime)s.%(msecs)03d %(levelprefix)s %(message)s [%(name)s:%(lineno)d]" ) # Environment variable to force StreamHandler instead of RichHandler # Set to any non-empty value to disable RichHandler From 218bb3d49aa6e78a033b5cb7903cb8d5164a4711 Mon Sep 17 00:00:00 2001 From: Sam Doran Date: Tue, 5 May 2026 00:40:06 -0400 Subject: [PATCH 06/28] Make logging config work with rich and uvicorn When rich is not selected, use the uvicorn.logging.DefaultFormatter for log messages. Modify the default format slightly to include miliseconds in the timestamp. --- src/log.py | 48 +++++++++++++++++++++++------------------------- 1 file changed, 23 insertions(+), 25 deletions(-) diff --git a/src/log.py b/src/log.py index a5a2b7c20..68ff30bda 100644 --- a/src/log.py +++ b/src/log.py @@ -62,7 +62,8 @@ def get_logger(file: str) -> logging.Logger: @lru_cache def setup_logging() -> dict[t.Any, t.Any]: - handler = "console" + """Create logging configuration.""" + handler = "default" log_level = resolve_log_level() if sys.stderr.isatty() and not os.environ.get( LIGHTSPEED_STACK_DISABLE_RICH_HANDLER_ENV_VAR @@ -72,26 +73,12 @@ def setup_logging() -> dict[t.Any, t.Any]: logging_conf = { "version": 1, "disable_existing_loggers": False, - "formatters": { - # RichHandler needs format="%(message)s" to prevent double-formatting by the root Formatter. - "rich": { - "format": "RICH %(message)s", - "datefmt": "[%X]", - }, - "console": { - "format": DEFAULT_LOG_FORMAT, - "datefmt": "%Y-%m-%d %H:%M:%S", - }, - }, "handlers": { - "console": { - "formatter": "console", - "class": "logging.StreamHandler", - "stream": "ext://sys.stderr", - }, "rich": { - "formatter": "rich", - "class": "rich.logging.RichHandler", + "()": "rich.logging.RichHandler", + "show_time": True, + "log_time_format": "%Y-%m-%d %H:%M:%S.%f", + "level": log_level, }, }, "loggers": { @@ -100,16 +87,27 @@ def setup_logging() -> dict[t.Any, t.Any]: "level": log_level, "propagate": False, }, + "llama_stack_client": { + "handlers": [handler], + "level": log_level, + "propagate": False, + }, }, } merged_config = deep_update(uvicorn.config.LOGGING_CONFIG, logging_conf) - merged_config["formatters"]["access"]["fmt"] = ( - '%(asctime)s.%(msecs)03d %(levelprefix)s %(client_addr)s - "%(request_line)s" %(status_code)s' - ) - merged_config["formatters"]["default"]["fmt"] = ( - "%(asctime)s.%(msecs)03d %(levelprefix)s%(message)s" - ) + + if handler == "rich": + merged_config["loggers"]["uvicorn"]["handlers"] = [handler] + merged_config["loggers"]["uvicorn.access"]["handlers"] = [handler] + else: + merged_config["formatters"]["access"]["fmt"] = ( + "%(asctime)s.%(msecs)03d %(levelprefix)s " + '%(client_addr)s - "%(request_line)s" %(status_code)s' + ) + merged_config["formatters"]["default"]["fmt"] = DEFAULT_LOG_FORMAT + merged_config["formatters"]["default"]["datefmt"] = "%Y-%m-%d %H:%M:%S" + logging.config.dictConfig(merged_config) return merged_config From 9c5d7df1fd48f84467f5739bc69365fd804248be Mon Sep 17 00:00:00 2001 From: Sam Doran Date: Wed, 6 May 2026 11:02:14 -0400 Subject: [PATCH 07/28] Use __name__ --- src/a2a_storage/in_memory_context_store.py | 2 +- src/a2a_storage/postgres_context_store.py | 2 +- src/a2a_storage/sqlite_context_store.py | 2 +- src/a2a_storage/storage_factory.py | 2 +- src/app/database.py | 2 +- src/app/endpoints/a2a.py | 2 +- src/app/endpoints/authorized.py | 2 +- src/app/endpoints/config.py | 2 +- src/app/endpoints/conversations_v1.py | 2 +- src/app/endpoints/conversations_v2.py | 2 +- src/app/endpoints/feedback.py | 2 +- src/app/endpoints/health.py | 2 +- src/app/endpoints/info.py | 2 +- src/app/endpoints/mcp_auth.py | 2 +- src/app/endpoints/mcp_servers.py | 2 +- src/app/endpoints/models.py | 2 +- src/app/endpoints/prompts.py | 2 +- src/app/endpoints/providers.py | 2 +- src/app/endpoints/query.py | 2 +- src/app/endpoints/rags.py | 2 +- src/app/endpoints/responses.py | 2 +- src/app/endpoints/rlsapi_v1.py | 2 +- src/app/endpoints/root.py | 2 +- src/app/endpoints/shields.py | 2 +- src/app/endpoints/streaming_query.py | 2 +- src/app/endpoints/tools.py | 2 +- src/app/endpoints/vector_stores.py | 2 +- src/app/main.py | 2 +- src/authentication/__init__.py | 2 +- src/authentication/api_key_token.py | 2 +- src/authentication/jwk_token.py | 2 +- src/authentication/k8s.py | 2 +- src/authentication/noop.py | 2 +- src/authentication/noop_with_token.py | 2 +- src/authentication/rh_identity.py | 2 +- src/authorization/azure_token_manager.py | 2 +- src/authorization/middleware.py | 2 +- src/authorization/resolvers.py | 2 +- src/cache/cache_factory.py | 2 +- src/cache/in_memory_cache.py | 2 +- src/cache/noop_cache.py | 2 +- src/cache/postgres_cache.py | 2 +- src/cache/sqlite_cache.py | 2 +- src/client.py | 2 +- src/configuration.py | 2 +- src/lightspeed_stack.py | 2 +- src/llama_stack_configuration.py | 2 +- src/log.py | 8 +++++--- src/metrics/recording.py | 2 +- src/metrics/utils.py | 2 +- src/models/config.py | 2 +- src/observability/splunk.py | 2 +- src/quota/cluster_quota_limiter.py | 2 +- src/quota/connect_pg.py | 2 +- src/quota/connect_sqlite.py | 2 +- src/quota/quota_limiter.py | 2 +- src/quota/quota_limiter_factory.py | 2 +- src/quota/revokable_quota_limiter.py | 2 +- src/quota/token_usage_history.py | 2 +- src/quota/user_quota_limiter.py | 2 +- src/runners/quota_scheduler.py | 2 +- src/runners/uvicorn.py | 2 +- src/sentry.py | 2 +- src/telemetry/configuration_snapshot.py | 2 +- src/utils/endpoints.py | 2 +- src/utils/llama_stack_version.py | 2 +- src/utils/mcp_auth_headers.py | 2 +- src/utils/mcp_headers.py | 2 +- src/utils/mcp_oauth_probe.py | 2 +- src/utils/query.py | 2 +- src/utils/quota.py | 2 +- src/utils/responses.py | 2 +- src/utils/shields.py | 2 +- src/utils/stream_interrupts.py | 2 +- src/utils/token_counter.py | 2 +- src/utils/tool_formatter.py | 2 +- src/utils/transcripts.py | 2 +- src/utils/vector_search.py | 2 +- 78 files changed, 82 insertions(+), 80 deletions(-) diff --git a/src/a2a_storage/in_memory_context_store.py b/src/a2a_storage/in_memory_context_store.py index e053661d0..0699ccd03 100644 --- a/src/a2a_storage/in_memory_context_store.py +++ b/src/a2a_storage/in_memory_context_store.py @@ -6,7 +6,7 @@ from a2a_storage.context_store import A2AContextStore from log import get_logger -logger = get_logger(__file__) +logger = get_logger(__name__) class InMemoryA2AContextStore(A2AContextStore): diff --git a/src/a2a_storage/postgres_context_store.py b/src/a2a_storage/postgres_context_store.py index 900924409..2d630af9f 100644 --- a/src/a2a_storage/postgres_context_store.py +++ b/src/a2a_storage/postgres_context_store.py @@ -9,7 +9,7 @@ from a2a_storage.context_store import A2AContextStore from log import get_logger -logger = get_logger(__file__) +logger = get_logger(__name__) # Define the table metadata metadata = MetaData() diff --git a/src/a2a_storage/sqlite_context_store.py b/src/a2a_storage/sqlite_context_store.py index 2f94b0f77..6cdbabb23 100644 --- a/src/a2a_storage/sqlite_context_store.py +++ b/src/a2a_storage/sqlite_context_store.py @@ -8,7 +8,7 @@ from a2a_storage.context_store import A2AContextStore from log import get_logger -logger = get_logger(__file__) +logger = get_logger(__name__) # Define the table metadata metadata = MetaData() diff --git a/src/a2a_storage/storage_factory.py b/src/a2a_storage/storage_factory.py index 4a6f223cc..16870eb10 100644 --- a/src/a2a_storage/storage_factory.py +++ b/src/a2a_storage/storage_factory.py @@ -13,7 +13,7 @@ from log import get_logger from models.config import A2AStateConfiguration -logger = get_logger(__file__) +logger = get_logger(__name__) class A2AStorageFactory: diff --git a/src/app/database.py b/src/app/database.py index 53f0dec40..0b6881896 100644 --- a/src/app/database.py +++ b/src/app/database.py @@ -13,7 +13,7 @@ from models.config import PostgreSQLDatabaseConfiguration, SQLiteDatabaseConfiguration from models.database.base import Base -logger = get_logger(__file__) +logger = get_logger(__name__) # pylint: disable=invalid-name engine: Optional[Engine] = None diff --git a/src/app/endpoints/a2a.py b/src/app/endpoints/a2a.py index 589ebd8ad..99c53b8d6 100644 --- a/src/app/endpoints/a2a.py +++ b/src/app/endpoints/a2a.py @@ -61,7 +61,7 @@ from utils.suid import normalize_conversation_id, to_llama_stack_conversation_id from version import __version__ -logger = get_logger(__file__) +logger = get_logger(__name__) router = APIRouter(tags=["a2a"]) auth_dependency = get_auth_dependency() diff --git a/src/app/endpoints/authorized.py b/src/app/endpoints/authorized.py index 83d79e266..175c42a1f 100644 --- a/src/app/endpoints/authorized.py +++ b/src/app/endpoints/authorized.py @@ -15,7 +15,7 @@ ) from models.api.responses.successful import AuthorizedResponse -logger = get_logger(__file__) +logger = get_logger(__name__) router = APIRouter(tags=["authorized"]) authorized_responses: dict[int | str, dict[str, Any]] = { diff --git a/src/app/endpoints/config.py b/src/app/endpoints/config.py index fda13c41f..120180817 100644 --- a/src/app/endpoints/config.py +++ b/src/app/endpoints/config.py @@ -20,7 +20,7 @@ from models.config import Action from utils.endpoints import check_configuration_loaded -logger = get_logger(__file__) +logger = get_logger(__name__) router = APIRouter(tags=["config"]) diff --git a/src/app/endpoints/conversations_v1.py b/src/app/endpoints/conversations_v1.py index 4d7db1bed..4bc9237cb 100644 --- a/src/app/endpoints/conversations_v1.py +++ b/src/app/endpoints/conversations_v1.py @@ -55,7 +55,7 @@ to_llama_stack_conversation_id, ) -logger = get_logger(__file__) +logger = get_logger(__name__) router = APIRouter(tags=["conversations_v1"]) conversation_get_responses: dict[int | str, dict[str, Any]] = { diff --git a/src/app/endpoints/conversations_v2.py b/src/app/endpoints/conversations_v2.py index 3c9a94c35..1f61220da 100644 --- a/src/app/endpoints/conversations_v2.py +++ b/src/app/endpoints/conversations_v2.py @@ -33,7 +33,7 @@ from utils.endpoints import check_configuration_loaded from utils.suid import check_suid -logger = get_logger(__file__) +logger = get_logger(__name__) router = APIRouter(tags=["conversations_v2"]) diff --git a/src/app/endpoints/feedback.py b/src/app/endpoints/feedback.py index b6396cd23..f01e0fb16 100644 --- a/src/app/endpoints/feedback.py +++ b/src/app/endpoints/feedback.py @@ -31,7 +31,7 @@ from utils.endpoints import check_configuration_loaded, retrieve_conversation from utils.suid import get_suid -logger = get_logger(__file__) +logger = get_logger(__name__) router = APIRouter(prefix="/feedback", tags=["feedback"]) feedback_status_lock = threading.Lock() diff --git a/src/app/endpoints/health.py b/src/app/endpoints/health.py index 2174ad074..b718dc178 100644 --- a/src/app/endpoints/health.py +++ b/src/app/endpoints/health.py @@ -33,7 +33,7 @@ from models.config import Action from utils.degraded_mode import DegradedModeTracker -logger = get_logger(__file__) +logger = get_logger(__name__) router = APIRouter(tags=["health"]) diff --git a/src/app/endpoints/info.py b/src/app/endpoints/info.py index 2550b033a..52490e611 100644 --- a/src/app/endpoints/info.py +++ b/src/app/endpoints/info.py @@ -21,7 +21,7 @@ from models.config import Action from version import __version__ -logger = get_logger(__file__) +logger = get_logger(__name__) router = APIRouter(tags=["info"]) diff --git a/src/app/endpoints/mcp_auth.py b/src/app/endpoints/mcp_auth.py index 1a9e885cf..62aea7615 100644 --- a/src/app/endpoints/mcp_auth.py +++ b/src/app/endpoints/mcp_auth.py @@ -22,7 +22,7 @@ from models.config import Action from utils.endpoints import check_configuration_loaded -logger = get_logger(__file__) +logger = get_logger(__name__) router = APIRouter(prefix="/mcp-auth", tags=["mcp-auth"]) diff --git a/src/app/endpoints/mcp_servers.py b/src/app/endpoints/mcp_servers.py index 73d55c00b..045334a49 100644 --- a/src/app/endpoints/mcp_servers.py +++ b/src/app/endpoints/mcp_servers.py @@ -30,7 +30,7 @@ from models.config import Action, ModelContextProtocolServer from utils.endpoints import check_configuration_loaded -logger = get_logger(__file__) +logger = get_logger(__name__) router = APIRouter(tags=["mcp-servers"]) diff --git a/src/app/endpoints/models.py b/src/app/endpoints/models.py index 5dd76ef60..fa435a6f9 100644 --- a/src/app/endpoints/models.py +++ b/src/app/endpoints/models.py @@ -24,7 +24,7 @@ from models.config import Action from utils.endpoints import check_configuration_loaded -logger = get_logger(__file__) +logger = get_logger(__name__) router = APIRouter(tags=["models"]) diff --git a/src/app/endpoints/prompts.py b/src/app/endpoints/prompts.py index 625928e97..6c85603c8 100644 --- a/src/app/endpoints/prompts.py +++ b/src/app/endpoints/prompts.py @@ -33,7 +33,7 @@ from utils.query import handle_known_apistatus_errors from utils.suid import check_suid_prompt -logger = get_logger(__file__) +logger = get_logger(__name__) router = APIRouter(tags=["prompts"]) diff --git a/src/app/endpoints/providers.py b/src/app/endpoints/providers.py index d521b5483..e6cb8ed07 100644 --- a/src/app/endpoints/providers.py +++ b/src/app/endpoints/providers.py @@ -28,7 +28,7 @@ from models.config import Action from utils.endpoints import check_configuration_loaded -logger = get_logger(__file__) +logger = get_logger(__name__) router = APIRouter(tags=["providers"]) diff --git a/src/app/endpoints/query.py b/src/app/endpoints/query.py index 6a2cb2800..800b15374 100644 --- a/src/app/endpoints/query.py +++ b/src/app/endpoints/query.py @@ -77,7 +77,7 @@ from utils.suid import normalize_conversation_id from utils.vector_search import build_rag_context -logger = get_logger(__file__) +logger = get_logger(__name__) router = APIRouter(tags=["query"]) query_response: dict[int | str, dict[str, Any]] = { diff --git a/src/app/endpoints/rags.py b/src/app/endpoints/rags.py index bca41295d..8cf5c7679 100644 --- a/src/app/endpoints/rags.py +++ b/src/app/endpoints/rags.py @@ -27,7 +27,7 @@ from models.config import Action, ByokRag from utils.endpoints import check_configuration_loaded -logger = get_logger(__file__) +logger = get_logger(__name__) router = APIRouter(tags=["rags"]) diff --git a/src/app/endpoints/responses.py b/src/app/endpoints/responses.py index 1340f9b8d..6d0cd9b05 100644 --- a/src/app/endpoints/responses.py +++ b/src/app/endpoints/responses.py @@ -115,7 +115,7 @@ build_rag_context, ) -logger = get_logger(__file__) +logger = get_logger(__name__) router = APIRouter(tags=["responses"]) _USER_AGENT_MAX_LENGTH: Final[int] = 128 diff --git a/src/app/endpoints/rlsapi_v1.py b/src/app/endpoints/rlsapi_v1.py index 30e2ebcdd..7a354cbc7 100644 --- a/src/app/endpoints/rlsapi_v1.py +++ b/src/app/endpoints/rlsapi_v1.py @@ -64,7 +64,7 @@ from utils.shields import run_shield_moderation from utils.suid import get_suid -logger = get_logger(__file__) +logger = get_logger(__name__) router = APIRouter(tags=["rlsapi-v1"]) diff --git a/src/app/endpoints/root.py b/src/app/endpoints/root.py index 7d77396fe..956a6805b 100644 --- a/src/app/endpoints/root.py +++ b/src/app/endpoints/root.py @@ -17,7 +17,7 @@ ) from models.config import Action -logger = get_logger(__file__) +logger = get_logger(__name__) router = APIRouter(tags=["root"]) diff --git a/src/app/endpoints/shields.py b/src/app/endpoints/shields.py index 52ed8720b..641064234 100644 --- a/src/app/endpoints/shields.py +++ b/src/app/endpoints/shields.py @@ -23,7 +23,7 @@ from models.config import Action from utils.endpoints import check_configuration_loaded -logger = get_logger(__file__) +logger = get_logger(__name__) router = APIRouter(tags=["shields"]) diff --git a/src/app/endpoints/streaming_query.py b/src/app/endpoints/streaming_query.py index 14fec097b..fc7d740c5 100644 --- a/src/app/endpoints/streaming_query.py +++ b/src/app/endpoints/streaming_query.py @@ -139,7 +139,7 @@ from utils.suid import get_suid, normalize_conversation_id from utils.vector_search import build_rag_context -logger = get_logger(__file__) +logger = get_logger(__name__) router = APIRouter(tags=["streaming_query"]) # Tracks background topic summary tasks for graceful shutdown. diff --git a/src/app/endpoints/tools.py b/src/app/endpoints/tools.py index 46375f7e3..f0941a6a6 100644 --- a/src/app/endpoints/tools.py +++ b/src/app/endpoints/tools.py @@ -30,7 +30,7 @@ from utils.mcp_oauth_probe import check_mcp_auth from utils.tool_formatter import format_tools_list -logger = get_logger(__file__) +logger = get_logger(__name__) router = APIRouter(tags=["tools"]) diff --git a/src/app/endpoints/vector_stores.py b/src/app/endpoints/vector_stores.py index 6225d8046..ee55bc00e 100644 --- a/src/app/endpoints/vector_stores.py +++ b/src/app/endpoints/vector_stores.py @@ -49,7 +49,7 @@ from utils.endpoints import check_configuration_loaded from utils.query import handle_known_apistatus_errors -logger = get_logger(__file__) +logger = get_logger(__name__) router = APIRouter(tags=["vector-stores"]) diff --git a/src/app/main.py b/src/app/main.py index 28171a015..e54c730bc 100644 --- a/src/app/main.py +++ b/src/app/main.py @@ -30,7 +30,7 @@ from utils.degraded_mode import DegradedModeTracker from utils.llama_stack_version import check_llama_stack_version -logger = get_logger(__file__) +logger = get_logger(__name__) logger.info("Initializing app") diff --git a/src/authentication/__init__.py b/src/authentication/__init__.py index 434c69876..44e8ddc42 100644 --- a/src/authentication/__init__.py +++ b/src/authentication/__init__.py @@ -16,7 +16,7 @@ from configuration import LogicError, configuration from log import get_logger -logger = get_logger(__file__) +logger = get_logger(__name__) def get_auth_dependency( # pylint: disable=too-many-return-statements diff --git a/src/authentication/api_key_token.py b/src/authentication/api_key_token.py index 3dc5305ae..9a53363ff 100644 --- a/src/authentication/api_key_token.py +++ b/src/authentication/api_key_token.py @@ -21,7 +21,7 @@ from log import get_logger from models.config import APIKeyTokenConfiguration -logger = get_logger(__file__) +logger = get_logger(__name__) def _should_skip_auth(request: Request) -> bool: diff --git a/src/authentication/jwk_token.py b/src/authentication/jwk_token.py index 744e88903..3ac275cc7 100644 --- a/src/authentication/jwk_token.py +++ b/src/authentication/jwk_token.py @@ -26,7 +26,7 @@ from models.api.responses.error import UnauthorizedResponse from models.config import JwkConfiguration -logger = get_logger(__file__) +logger = get_logger(__name__) # Global JWK registry to avoid re-fetching JWKs for each request. Cached for 1 # hour, keys are unlikely to change frequently. diff --git a/src/authentication/k8s.py b/src/authentication/k8s.py index 42ff4fe16..b86953169 100644 --- a/src/authentication/k8s.py +++ b/src/authentication/k8s.py @@ -21,7 +21,7 @@ UnauthorizedResponse, ) -logger = get_logger(__file__) +logger = get_logger(__name__) CLUSTER_ID_LOCAL = "local" diff --git a/src/authentication/noop.py b/src/authentication/noop.py index c193c5ac8..6d32f45c3 100644 --- a/src/authentication/noop.py +++ b/src/authentication/noop.py @@ -11,7 +11,7 @@ ) from log import get_logger -logger = get_logger(__file__) +logger = get_logger(__name__) class NoopAuthDependency(AuthInterface): # pylint: disable=too-few-public-methods diff --git a/src/authentication/noop_with_token.py b/src/authentication/noop_with_token.py index 588ad195a..0656d952a 100644 --- a/src/authentication/noop_with_token.py +++ b/src/authentication/noop_with_token.py @@ -20,7 +20,7 @@ ) from log import get_logger -logger = get_logger(__file__) +logger = get_logger(__name__) class NoopWithTokenAuthDependency( diff --git a/src/authentication/rh_identity.py b/src/authentication/rh_identity.py index 9197758cd..ff0a560b7 100644 --- a/src/authentication/rh_identity.py +++ b/src/authentication/rh_identity.py @@ -20,7 +20,7 @@ ) from log import get_logger -logger = get_logger(__file__) +logger = get_logger(__name__) RH_INSIGHTS_REQUEST_ID_HEADER = "x-rh-insights-request-id" REQUEST_ID_HEADER = "x-request-id" diff --git a/src/authorization/azure_token_manager.py b/src/authorization/azure_token_manager.py index 28824bc18..702efe465 100644 --- a/src/authorization/azure_token_manager.py +++ b/src/authorization/azure_token_manager.py @@ -12,7 +12,7 @@ from log import get_logger from utils.types import Singleton -logger = get_logger(__file__) +logger = get_logger(__name__) # Refresh token before actual expiration to avoid edge cases TOKEN_EXPIRATION_LEEWAY = 30 # seconds diff --git a/src/authorization/middleware.py b/src/authorization/middleware.py index 9d267d823..93cb5e7e0 100644 --- a/src/authorization/middleware.py +++ b/src/authorization/middleware.py @@ -24,7 +24,7 @@ ) from models.config import Action -logger = get_logger(__file__) +logger = get_logger(__name__) @lru_cache(maxsize=1) diff --git a/src/authorization/resolvers.py b/src/authorization/resolvers.py index b4ee76dda..b848f8f34 100644 --- a/src/authorization/resolvers.py +++ b/src/authorization/resolvers.py @@ -12,7 +12,7 @@ from log import get_logger from models.config import AccessRule, Action, JsonPathOperator, JwtRoleRule -logger = get_logger(__file__) +logger = get_logger(__name__) UserRoles = set[str] diff --git a/src/cache/cache_factory.py b/src/cache/cache_factory.py index 93826fa36..cbc066a29 100644 --- a/src/cache/cache_factory.py +++ b/src/cache/cache_factory.py @@ -9,7 +9,7 @@ from log import get_logger from models.config import ConversationHistoryConfiguration -logger = get_logger(__file__) +logger = get_logger(__name__) # pylint: disable=R0903 diff --git a/src/cache/in_memory_cache.py b/src/cache/in_memory_cache.py index e87b6e6e6..302893a42 100644 --- a/src/cache/in_memory_cache.py +++ b/src/cache/in_memory_cache.py @@ -10,7 +10,7 @@ from models.config import InMemoryCacheConfig from utils.connection_decorator import connection -logger = get_logger(__file__) +logger = get_logger(__name__) class InMemoryCache(Cache): diff --git a/src/cache/noop_cache.py b/src/cache/noop_cache.py index ef4f7910c..a0bbb017d 100644 --- a/src/cache/noop_cache.py +++ b/src/cache/noop_cache.py @@ -9,7 +9,7 @@ from models.compaction import ConversationSummary from utils.connection_decorator import connection -logger = get_logger(__file__) +logger = get_logger(__name__) class NoopCache(Cache): diff --git a/src/cache/postgres_cache.py b/src/cache/postgres_cache.py index dd993e6ae..ea0661a3d 100644 --- a/src/cache/postgres_cache.py +++ b/src/cache/postgres_cache.py @@ -20,7 +20,7 @@ from models.config import PostgreSQLDatabaseConfiguration from utils.connection_decorator import connection -logger = get_logger(__file__) +logger = get_logger(__name__) class PostgresCache(Cache): diff --git a/src/cache/sqlite_cache.py b/src/cache/sqlite_cache.py index cc30cae26..6e6eae9d7 100644 --- a/src/cache/sqlite_cache.py +++ b/src/cache/sqlite_cache.py @@ -19,7 +19,7 @@ from models.config import SQLiteDatabaseConfiguration from utils.connection_decorator import connection -logger = get_logger(__file__) +logger = get_logger(__name__) class SQLiteCache(Cache): diff --git a/src/client.py b/src/client.py index eea7acbee..d66d5dfb3 100644 --- a/src/client.py +++ b/src/client.py @@ -25,7 +25,7 @@ from models.config import LlamaStackConfiguration from utils.types import Singleton -logger = get_logger(__file__) +logger = get_logger(__name__) class AsyncLlamaStackClientHolder(metaclass=Singleton): diff --git a/src/configuration.py b/src/configuration.py index 2fe677d65..e95e89083 100644 --- a/src/configuration.py +++ b/src/configuration.py @@ -40,7 +40,7 @@ from quota.quota_limiter_factory import QuotaLimiterFactory from quota.token_usage_history import TokenUsageHistory -logger = get_logger(__file__) +logger = get_logger(__name__) def replace_env_vars_preserving_native_override( diff --git a/src/lightspeed_stack.py b/src/lightspeed_stack.py index eccd19452..a40f63c65 100644 --- a/src/lightspeed_stack.py +++ b/src/lightspeed_stack.py @@ -17,7 +17,7 @@ from utils import schema_dumper setup_logging() -logger = get_logger(__file__) +logger = get_logger(__name__) def create_argument_parser() -> ArgumentParser: diff --git a/src/llama_stack_configuration.py b/src/llama_stack_configuration.py index ff5ed9ceb..e9caebe74 100644 --- a/src/llama_stack_configuration.py +++ b/src/llama_stack_configuration.py @@ -30,7 +30,7 @@ import constants from log import get_logger -logger = get_logger(__file__) +logger = get_logger(__name__) # Maps a UnifiedInferenceProvider.type (canonical, backend-agnostic vocabulary) # to the Llama Stack provider_type emitted by apply_high_level_inference. The diff --git a/src/log.py b/src/log.py index 68ff30bda..02f02581f 100644 --- a/src/log.py +++ b/src/log.py @@ -6,7 +6,6 @@ import sys import typing as t from functools import lru_cache -from pathlib import Path import uvicorn.config from pydantic.v1.utils import deep_update @@ -56,8 +55,11 @@ def resolve_log_level() -> int: return validated_level -def get_logger(file: str) -> logging.Logger: - return logging.getLogger(f"{DEFAULT_LOGGER_NAME}.{Path(file).stem}") +def get_logger(name: str) -> logging.Logger: + """Create a common logger for all modules in this package.""" + # Normally this is derived from the package name + return logging.getLogger(name) + # return logging.getLogger(f"{DEFAULT_LOGGER_NAME}.{name}") @lru_cache diff --git a/src/metrics/recording.py b/src/metrics/recording.py index 2013660f9..c41c105b5 100644 --- a/src/metrics/recording.py +++ b/src/metrics/recording.py @@ -12,7 +12,7 @@ import metrics from log import get_logger -logger = get_logger(__file__) +logger = get_logger(__name__) @contextmanager diff --git a/src/metrics/utils.py b/src/metrics/utils.py index fa6d44534..afb832d29 100644 --- a/src/metrics/utils.py +++ b/src/metrics/utils.py @@ -6,7 +6,7 @@ from log import get_logger from utils.endpoints import check_configuration_loaded -logger = get_logger(__file__) +logger = get_logger(__name__) async def setup_model_metrics() -> None: diff --git a/src/models/config.py b/src/models/config.py index 67b7d2fe0..0563047b5 100644 --- a/src/models/config.py +++ b/src/models/config.py @@ -32,7 +32,7 @@ from utils import checks from utils.mcp_auth_headers import resolve_authorization_headers -logger = get_logger(__file__) +logger = get_logger(__name__) class ConfigurationBase(BaseModel): diff --git a/src/observability/splunk.py b/src/observability/splunk.py index 95aa6dcc6..2763b0ef1 100644 --- a/src/observability/splunk.py +++ b/src/observability/splunk.py @@ -12,7 +12,7 @@ from log import get_logger from version import __version__ -logger = get_logger(__file__) +logger = get_logger(__name__) def _get_hostname() -> str: diff --git a/src/quota/cluster_quota_limiter.py b/src/quota/cluster_quota_limiter.py index ed08613b5..f378f2aef 100644 --- a/src/quota/cluster_quota_limiter.py +++ b/src/quota/cluster_quota_limiter.py @@ -4,7 +4,7 @@ from models.config import QuotaHandlersConfiguration from quota.revokable_quota_limiter import RevokableQuotaLimiter -logger = get_logger(__file__) +logger = get_logger(__name__) class ClusterQuotaLimiter(RevokableQuotaLimiter): diff --git a/src/quota/connect_pg.py b/src/quota/connect_pg.py index fef185b5e..e74700a5d 100644 --- a/src/quota/connect_pg.py +++ b/src/quota/connect_pg.py @@ -7,7 +7,7 @@ from log import get_logger from models.config import PostgreSQLDatabaseConfiguration -logger = get_logger(__file__) +logger = get_logger(__name__) def connect_pg(config: PostgreSQLDatabaseConfiguration) -> Any: diff --git a/src/quota/connect_sqlite.py b/src/quota/connect_sqlite.py index f6073d307..a745f57cb 100644 --- a/src/quota/connect_sqlite.py +++ b/src/quota/connect_sqlite.py @@ -6,7 +6,7 @@ from log import get_logger from models.config import SQLiteDatabaseConfiguration -logger = get_logger(__file__) +logger = get_logger(__name__) def connect_sqlite(config: SQLiteDatabaseConfiguration) -> Any: diff --git a/src/quota/quota_limiter.py b/src/quota/quota_limiter.py index d0f48adb7..9fdc8adbe 100644 --- a/src/quota/quota_limiter.py +++ b/src/quota/quota_limiter.py @@ -42,7 +42,7 @@ from quota.connect_pg import connect_pg from quota.connect_sqlite import connect_sqlite -logger = get_logger(__file__) +logger = get_logger(__name__) class QuotaLimiter(ABC): diff --git a/src/quota/quota_limiter_factory.py b/src/quota/quota_limiter_factory.py index 418ea0340..6e86e8d31 100644 --- a/src/quota/quota_limiter_factory.py +++ b/src/quota/quota_limiter_factory.py @@ -7,7 +7,7 @@ from quota.quota_limiter import QuotaLimiter from quota.user_quota_limiter import UserQuotaLimiter -logger = get_logger(__file__) +logger = get_logger(__name__) # pylint: disable=too-few-public-methods diff --git a/src/quota/revokable_quota_limiter.py b/src/quota/revokable_quota_limiter.py index d7dfa2a3a..8e51e18b1 100644 --- a/src/quota/revokable_quota_limiter.py +++ b/src/quota/revokable_quota_limiter.py @@ -20,7 +20,7 @@ ) from utils.connection_decorator import connection -logger = get_logger(__file__) +logger = get_logger(__name__) class RevokableQuotaLimiter(QuotaLimiter): diff --git a/src/quota/token_usage_history.py b/src/quota/token_usage_history.py index d3960ac94..0ac56f860 100644 --- a/src/quota/token_usage_history.py +++ b/src/quota/token_usage_history.py @@ -26,7 +26,7 @@ ) from utils.connection_decorator import connection -logger = get_logger(__file__) +logger = get_logger(__name__) class TokenUsageHistory: diff --git a/src/quota/user_quota_limiter.py b/src/quota/user_quota_limiter.py index 6bdbc7020..67cea6bfc 100644 --- a/src/quota/user_quota_limiter.py +++ b/src/quota/user_quota_limiter.py @@ -4,7 +4,7 @@ from models.config import QuotaHandlersConfiguration from quota.revokable_quota_limiter import RevokableQuotaLimiter -logger = get_logger(__file__) +logger = get_logger(__name__) class UserQuotaLimiter(RevokableQuotaLimiter): diff --git a/src/runners/quota_scheduler.py b/src/runners/quota_scheduler.py index 3d9d4bfda..de9ce7451 100644 --- a/src/runners/quota_scheduler.py +++ b/src/runners/quota_scheduler.py @@ -22,7 +22,7 @@ RESET_QUOTA_STATEMENT_SQLITE, ) -logger = get_logger(__file__) +logger = get_logger(__name__) # pylint: disable=R0912 diff --git a/src/runners/uvicorn.py b/src/runners/uvicorn.py index e857827ea..836a0e6c2 100644 --- a/src/runners/uvicorn.py +++ b/src/runners/uvicorn.py @@ -7,7 +7,7 @@ from log import get_logger, resolve_log_level, setup_logging from models.config import ServiceConfiguration -logger = get_logger(__file__) +logger = get_logger(__name__) def start_uvicorn( diff --git a/src/sentry.py b/src/sentry.py index 28c5d24a6..e8040b54c 100644 --- a/src/sentry.py +++ b/src/sentry.py @@ -18,7 +18,7 @@ ) from log import get_logger -logger = get_logger(__file__) +logger = get_logger(__name__) def sentry_traces_sampler(tracing_context: dict) -> float: diff --git a/src/telemetry/configuration_snapshot.py b/src/telemetry/configuration_snapshot.py index ccd37df36..e0e9a9fe2 100644 --- a/src/telemetry/configuration_snapshot.py +++ b/src/telemetry/configuration_snapshot.py @@ -21,7 +21,7 @@ from log import get_logger from models.config import Configuration -logger = get_logger(__file__) +logger = get_logger(__name__) # Masking output constants CONFIGURED: Literal["configured"] = "configured" diff --git a/src/utils/endpoints.py b/src/utils/endpoints.py index a4f837a51..5ea928b51 100644 --- a/src/utils/endpoints.py +++ b/src/utils/endpoints.py @@ -24,7 +24,7 @@ from utils.responses import create_new_conversation from utils.suid import normalize_conversation_id, to_llama_stack_conversation_id -logger = get_logger(__file__) +logger = get_logger(__name__) def delete_conversation(conversation_id: str) -> bool: diff --git a/src/utils/llama_stack_version.py b/src/utils/llama_stack_version.py index d38fa11eb..7075a94ec 100644 --- a/src/utils/llama_stack_version.py +++ b/src/utils/llama_stack_version.py @@ -15,7 +15,7 @@ ) from log import get_logger -logger = get_logger(__file__) +logger = get_logger(__name__) class InvalidLlamaStackVersionException(Exception): diff --git a/src/utils/mcp_auth_headers.py b/src/utils/mcp_auth_headers.py index c8d3ee58b..d89890477 100644 --- a/src/utils/mcp_auth_headers.py +++ b/src/utils/mcp_auth_headers.py @@ -5,7 +5,7 @@ import constants from log import get_logger -logger = get_logger(__file__) +logger = get_logger(__name__) def resolve_authorization_headers( diff --git a/src/utils/mcp_headers.py b/src/utils/mcp_headers.py index 809436a6a..980d7a421 100644 --- a/src/utils/mcp_headers.py +++ b/src/utils/mcp_headers.py @@ -12,7 +12,7 @@ from log import get_logger from models.config import ModelContextProtocolServer -logger = get_logger(__file__) +logger = get_logger(__name__) type McpHeaders = dict[str, dict[str, str]] diff --git a/src/utils/mcp_oauth_probe.py b/src/utils/mcp_oauth_probe.py index 73134556d..570e968eb 100644 --- a/src/utils/mcp_oauth_probe.py +++ b/src/utils/mcp_oauth_probe.py @@ -17,7 +17,7 @@ from models.api.responses.error import UnauthorizedResponse from utils.mcp_headers import McpHeaders, build_mcp_headers -logger = get_logger(__file__) +logger = get_logger(__name__) async def check_mcp_auth( diff --git a/src/utils/query.py b/src/utils/query.py index a49ea2a7a..4ccb3abeb 100644 --- a/src/utils/query.py +++ b/src/utils/query.py @@ -42,7 +42,7 @@ store_transcript, ) -logger = get_logger(__file__) +logger = get_logger(__name__) def is_context_length_error(error_message: str) -> bool: diff --git a/src/utils/quota.py b/src/utils/quota.py index e5e898088..b66d9b022 100644 --- a/src/utils/quota.py +++ b/src/utils/quota.py @@ -15,7 +15,7 @@ from quota.quota_limiter import QuotaLimiter from quota.token_usage_history import TokenUsageHistory -logger = get_logger(__file__) +logger = get_logger(__name__) # pylint: disable=R0913,R0917 diff --git a/src/utils/responses.py b/src/utils/responses.py index f578d9f65..3141742d8 100644 --- a/src/utils/responses.py +++ b/src/utils/responses.py @@ -124,7 +124,7 @@ from utils.suid import to_llama_stack_conversation_id from utils.token_counter import TokenCounter -logger = get_logger(__file__) +logger = get_logger(__name__) async def get_vector_store_ids( diff --git a/src/utils/shields.py b/src/utils/shields.py index abf58a7f6..5dca71ad3 100644 --- a/src/utils/shields.py +++ b/src/utils/shields.py @@ -32,7 +32,7 @@ ) from utils.query import handle_known_apistatus_errors -logger = get_logger(__file__) +logger = get_logger(__name__) async def get_available_shields(client: AsyncLlamaStackClient) -> list[str]: diff --git a/src/utils/stream_interrupts.py b/src/utils/stream_interrupts.py index 55fa0937b..5afaf92f8 100644 --- a/src/utils/stream_interrupts.py +++ b/src/utils/stream_interrupts.py @@ -26,7 +26,7 @@ from utils.shields import append_turn_to_conversation from utils.types import Singleton -logger = get_logger(__file__) +logger = get_logger(__name__) @dataclass diff --git a/src/utils/token_counter.py b/src/utils/token_counter.py index c439be8a5..94f0667d0 100644 --- a/src/utils/token_counter.py +++ b/src/utils/token_counter.py @@ -4,7 +4,7 @@ from log import get_logger -logger = get_logger(__file__) +logger = get_logger(__name__) @dataclass diff --git a/src/utils/tool_formatter.py b/src/utils/tool_formatter.py index 5619f9c45..4b55141ea 100644 --- a/src/utils/tool_formatter.py +++ b/src/utils/tool_formatter.py @@ -5,7 +5,7 @@ from log import get_logger -logger = get_logger(__file__) +logger = get_logger(__name__) def format_tool_response(tool_dict: dict[str, Any]) -> dict[str, Any]: diff --git a/src/utils/transcripts.py b/src/utils/transcripts.py index b4c9f473b..8f001c3ce 100644 --- a/src/utils/transcripts.py +++ b/src/utils/transcripts.py @@ -21,7 +21,7 @@ from models.common.turn_summary import TurnSummary from utils.suid import get_suid -logger = get_logger(__file__) +logger = get_logger(__name__) def _hash_user_id(user_id: str) -> str: diff --git a/src/utils/vector_search.py b/src/utils/vector_search.py index e4e6cf577..7267ddb92 100644 --- a/src/utils/vector_search.py +++ b/src/utils/vector_search.py @@ -24,7 +24,7 @@ from utils.reranker import apply_byok_rerank_boost, rerank_chunks_with_cross_encoder from utils.responses import resolve_vector_store_ids -logger = get_logger(__file__) +logger = get_logger(__name__) def _filter_documents_for_chunks( From 91ee4e895255b2bf737cd9638a1cdef8a2192933 Mon Sep 17 00:00:00 2001 From: Sam Doran Date: Wed, 6 May 2026 11:02:26 -0400 Subject: [PATCH 08/28] Change default logger name --- src/constants.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/constants.py b/src/constants.py index ed77219ed..9b660e140 100644 --- a/src/constants.py +++ b/src/constants.py @@ -248,7 +248,7 @@ # Environment variable name for configurable log level LIGHTSPEED_STACK_LOG_LEVEL_ENV_VAR: Final[str] = "LIGHTSPEED_STACK_LOG_LEVEL" # Default log level when environment variable is not set -DEFAULT_LOGGER_NAME = "lcs" +DEFAULT_LOGGER_NAME = "lightspeed_stack" DEFAULT_LOG_LEVEL: Final[str] = "INFO" # Default log format for plain-text logging in non-TTY environments DEFAULT_LOG_FORMAT: Final[str] = ( From d1664c2327e93c24475895e0c9c05321f7c03c70 Mon Sep 17 00:00:00 2001 From: Sam Doran Date: Fri, 8 May 2026 17:40:06 -0400 Subject: [PATCH 09/28] Go back to manually setting the logger name Add a description of the problem to be addressed in the future. --- src/log.py | 14 +++++++++++--- 1 file changed, 11 insertions(+), 3 deletions(-) diff --git a/src/log.py b/src/log.py index 02f02581f..392259e19 100644 --- a/src/log.py +++ b/src/log.py @@ -57,9 +57,17 @@ def resolve_log_level() -> int: def get_logger(name: str) -> logging.Logger: """Create a common logger for all modules in this package.""" - # Normally this is derived from the package name - return logging.getLogger(name) - # return logging.getLogger(f"{DEFAULT_LOGGER_NAME}.{name}") + # FIXME: Remove the need for this function. + # + # Normally this is derived from the package name (__name__). + # + # Since this program is sometimes called from from the entrypoint and + # sometimes called from src/lightspeed_stack.py, the value for __name__ + # does not contain a consistent root value. + # + # How the application is installed and run needs to be streamlined so that + # __name__ provides the expected value in all cases. + return logging.getLogger(f"{DEFAULT_LOGGER_NAME}.{name}") @lru_cache From 437afe5fc28ab53d4d28a08699eb88fd87592794 Mon Sep 17 00:00:00 2001 From: Sam Doran Date: Fri, 8 May 2026 17:41:09 -0400 Subject: [PATCH 10/28] Update tests --- tests/unit/runners/test_uvicorn_runner.py | 18 ++-- tests/unit/test_log.py | 106 +++++++--------------- 2 files changed, 45 insertions(+), 79 deletions(-) diff --git a/tests/unit/runners/test_uvicorn_runner.py b/tests/unit/runners/test_uvicorn_runner.py index 5c0ceb01e..66bd9d046 100644 --- a/tests/unit/runners/test_uvicorn_runner.py +++ b/tests/unit/runners/test_uvicorn_runner.py @@ -20,7 +20,7 @@ def test_start_uvicorn(mocker: MockerFixture) -> None: # don't start real Uvicorn server mocked_run = mocker.patch("uvicorn.run") - start_uvicorn(configuration) + start_uvicorn(configuration, log_config={}) mocked_run.assert_called_once_with( "app.main:app", host="localhost", @@ -32,6 +32,7 @@ def test_start_uvicorn(mocker: MockerFixture) -> None: ssl_keyfile_password="", use_colors=True, access_log=True, + log_config={}, ) @@ -43,7 +44,7 @@ def test_start_uvicorn_different_host_port(mocker: MockerFixture) -> None: # don't start real Uvicorn server mocked_run = mocker.patch("uvicorn.run") - start_uvicorn(configuration) + start_uvicorn(configuration, log_config={}) mocked_run.assert_called_once_with( "app.main:app", host="x.y.com", @@ -55,6 +56,7 @@ def test_start_uvicorn_different_host_port(mocker: MockerFixture) -> None: ssl_keyfile_password="", use_colors=True, access_log=True, + log_config={}, ) @@ -67,7 +69,7 @@ def test_start_uvicorn_empty_tls_configuration(mocker: MockerFixture) -> None: # don't start real Uvicorn server mocked_run = mocker.patch("uvicorn.run") - start_uvicorn(configuration) + start_uvicorn(configuration, log_config={}) mocked_run.assert_called_once_with( "app.main:app", host="x.y.com", @@ -79,6 +81,7 @@ def test_start_uvicorn_empty_tls_configuration(mocker: MockerFixture) -> None: ssl_keyfile_password="", use_colors=True, access_log=True, + log_config={}, ) @@ -95,7 +98,7 @@ def test_start_uvicorn_tls_configuration(mocker: MockerFixture) -> None: # don't start real Uvicorn server mocked_run = mocker.patch("uvicorn.run") - start_uvicorn(configuration) + start_uvicorn(configuration, log_config={}) mocked_run.assert_called_once_with( "app.main:app", host="x.y.com", @@ -107,6 +110,7 @@ def test_start_uvicorn_tls_configuration(mocker: MockerFixture) -> None: ssl_keyfile_password="tests/configuration/password", use_colors=True, access_log=True, + log_config={}, ) @@ -118,7 +122,7 @@ def test_start_uvicorn_with_root_path(mocker: MockerFixture) -> None: # don't start real Uvicorn server mocked_run = mocker.patch("uvicorn.run") - start_uvicorn(configuration) + start_uvicorn(configuration, log_config={}) mocked_run.assert_called_once_with( "app.main:app", host="localhost", @@ -130,6 +134,7 @@ def test_start_uvicorn_with_root_path(mocker: MockerFixture) -> None: ssl_keyfile_password="", use_colors=True, access_log=True, + log_config={}, ) @@ -170,7 +175,7 @@ def test_start_uvicorn_respects_debug_log_level( ) # pyright: ignore[reportCallIssue] mocked_run = mocker.patch("uvicorn.run") - start_uvicorn(configuration) + start_uvicorn(configuration, log_config={}) mocked_run.assert_called_once_with( "app.main:app", host="localhost", @@ -182,4 +187,5 @@ def test_start_uvicorn_respects_debug_log_level( ssl_keyfile_password="", use_colors=True, access_log=True, + log_config={}, ) diff --git a/tests/unit/test_log.py b/tests/unit/test_log.py index 0e47caf9b..a3aa0f417 100644 --- a/tests/unit/test_log.py +++ b/tests/unit/test_log.py @@ -3,34 +3,38 @@ import logging import pytest -from pytest_mock import MockerFixture -from rich.logging import RichHandler from constants import ( - DEFAULT_LOG_FORMAT, - LIGHTSPEED_STACK_DISABLE_RICH_HANDLER_ENV_VAR, + DEFAULT_LOGGER_NAME, LIGHTSPEED_STACK_LOG_LEVEL_ENV_VAR, ) -from log import create_log_handler, get_logger, resolve_log_level +from log import get_logger, resolve_log_level, setup_logging + + +@pytest.fixture(autouse=True) +def clear_logging_cache(): + setup_logging.cache_clear() def test_get_logger() -> None: """Check the function to retrieve logger.""" - logger_name = "foo" - logger = get_logger(logger_name) - assert logger is not None - assert logger.name == logger_name + setup_logging() - # at least one handler need to be set - assert len(logger.handlers) >= 1 + logger = get_logger(__name__) + + assert logger is not None + assert logger.name == f"{DEFAULT_LOGGER_NAME}.tests.unit.test_log" + assert logger.hasHandlers() def test_get_logger_invalid_env_var_fallback(monkeypatch: pytest.MonkeyPatch) -> None: """Test that invalid env var value falls back to INFO level.""" monkeypatch.setenv(LIGHTSPEED_STACK_LOG_LEVEL_ENV_VAR, "FOOBAR") - logger = get_logger("test_invalid") - assert logger.level == logging.INFO + setup_logging() + + logger = get_logger(__name__) + assert logger.getEffectiveLevel() == logging.INFO @pytest.mark.parametrize( @@ -59,16 +63,20 @@ def test_get_logger_log_level( """ monkeypatch.setenv(LIGHTSPEED_STACK_LOG_LEVEL_ENV_VAR, level_name) - logger = get_logger(f"test_{level_name}") - assert logger.level == expected_level + setup_logging() + + logger = get_logger(__name__) + assert logger.getEffectiveLevel() == expected_level def test_get_logger_default_log_level(monkeypatch: pytest.MonkeyPatch) -> None: """Test that get_logger() uses INFO level by default when env var is not set.""" monkeypatch.delenv(LIGHTSPEED_STACK_LOG_LEVEL_ENV_VAR, raising=False) - logger = get_logger("test_default") - assert logger.level == logging.INFO + setup_logging() + + logger = get_logger(__name__) + assert logger.getEffectiveLevel() == logging.INFO @pytest.mark.parametrize( @@ -88,73 +96,25 @@ def test_resolve_log_level( ) -> None: """Test that resolve_log_level correctly resolves valid level names.""" monkeypatch.setenv(LIGHTSPEED_STACK_LOG_LEVEL_ENV_VAR, level_name) + + setup_logging() + 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") + + setup_logging() + 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) + setup_logging() - -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 - - -def test_create_log_handler_disable_rich_with_tty( - mocker: MockerFixture, monkeypatch: pytest.MonkeyPatch -) -> None: - """Test that RichHandler is disabled when env var is set, even with TTY.""" - mocker.patch("sys.stderr.isatty", return_value=True) - monkeypatch.setenv(LIGHTSPEED_STACK_DISABLE_RICH_HANDLER_ENV_VAR, "1") - handler = create_log_handler() - assert isinstance(handler, logging.StreamHandler) - assert not isinstance(handler, RichHandler) - - -def test_create_log_handler_disable_rich_format( - mocker: MockerFixture, monkeypatch: pytest.MonkeyPatch -) -> None: - """Test that disabled RichHandler uses DEFAULT_LOG_FORMAT.""" - mocker.patch("sys.stderr.isatty", return_value=True) - monkeypatch.setenv(LIGHTSPEED_STACK_DISABLE_RICH_HANDLER_ENV_VAR, "true") - handler = create_log_handler() - assert handler.formatter is not None - # pylint: disable=protected-access - assert handler.formatter._fmt == DEFAULT_LOG_FORMAT - - -def test_create_log_handler_enable_rich_when_env_var_empty( - mocker: MockerFixture, monkeypatch: pytest.MonkeyPatch -) -> None: - """Test that RichHandler is used when env var is empty string.""" - mocker.patch("sys.stderr.isatty", return_value=True) - monkeypatch.setenv(LIGHTSPEED_STACK_DISABLE_RICH_HANDLER_ENV_VAR, "") - handler = create_log_handler() - assert isinstance(handler, RichHandler) + assert resolve_log_level() == logging.INFO From 967a3245bf32cf19d564e39d5d47b5b7004781eb Mon Sep 17 00:00:00 2001 From: Sam Doran Date: Mon, 11 May 2026 17:26:25 -0400 Subject: [PATCH 11/28] Add type hint --- src/constants.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/constants.py b/src/constants.py index 9b660e140..4c757a188 100644 --- a/src/constants.py +++ b/src/constants.py @@ -248,7 +248,7 @@ # Environment variable name for configurable log level LIGHTSPEED_STACK_LOG_LEVEL_ENV_VAR: Final[str] = "LIGHTSPEED_STACK_LOG_LEVEL" # Default log level when environment variable is not set -DEFAULT_LOGGER_NAME = "lightspeed_stack" +DEFAULT_LOGGER_NAME: Final[str] = "lightspeed_stack" DEFAULT_LOG_LEVEL: Final[str] = "INFO" # Default log format for plain-text logging in non-TTY environments DEFAULT_LOG_FORMAT: Final[str] = ( From 41a42815c2963661643ad7e4be9b3ee658aaa557 Mon Sep 17 00:00:00 2001 From: Sam Doran Date: Mon, 11 May 2026 17:32:48 -0400 Subject: [PATCH 12/28] Add custom formatter for RichHandler to output miliseconds The default .%f handling in RichHandler gives microseconds and strftime does not provide a milisecond format string. --- src/log.py | 9 ++++++++- 1 file changed, 8 insertions(+), 1 deletion(-) diff --git a/src/log.py b/src/log.py index 392259e19..e6bbe2497 100644 --- a/src/log.py +++ b/src/log.py @@ -5,10 +5,12 @@ import os import sys import typing as t +from datetime import datetime from functools import lru_cache import uvicorn.config from pydantic.v1.utils import deep_update +from rich.text import Text from constants import ( DEFAULT_LOG_FORMAT, @@ -19,6 +21,11 @@ ) +def _ms_time_format(dt: datetime) -> Text: + """Format datetime object with zero padded milliseconds.""" + return Text(dt.strftime("%Y-%m-%d %H:%M:%S.") + f"{dt.microsecond // 1000:03d}") + + def resolve_log_level() -> int: """ Resolve and validate the log level from environment variable. @@ -87,7 +94,7 @@ def setup_logging() -> dict[t.Any, t.Any]: "rich": { "()": "rich.logging.RichHandler", "show_time": True, - "log_time_format": "%Y-%m-%d %H:%M:%S.%f", + "log_time_format": _ms_time_format, "level": log_level, }, }, From fe047264a8923e1cf1a4167031455aa0baf7c825 Mon Sep 17 00:00:00 2001 From: Sam Doran Date: Mon, 11 May 2026 17:38:26 -0400 Subject: [PATCH 13/28] Update doc string with new parameter --- src/runners/uvicorn.py | 1 + 1 file changed, 1 insertion(+) diff --git a/src/runners/uvicorn.py b/src/runners/uvicorn.py index 836a0e6c2..ee2f4e3aa 100644 --- a/src/runners/uvicorn.py +++ b/src/runners/uvicorn.py @@ -19,6 +19,7 @@ def start_uvicorn( Parameters: ---------- configuration (ServiceConfiguration): Configuration providing host, + log_config (dict): Logging configuration, port, workers, and `tls_config` (including `tls_key_path`, `tls_certificate_path`, and `tls_key_password`). TLS fields may be None and will be forwarded to uvicorn.run as provided. From 6428f1c8dc2cc3f38b49515fdc7602e69d286d60 Mon Sep 17 00:00:00 2001 From: Sam Doran Date: Mon, 11 May 2026 17:53:15 -0400 Subject: [PATCH 14/28] Merge config into a deep copy of the uvicorn logging config --- src/log.py | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-) diff --git a/src/log.py b/src/log.py index e6bbe2497..ed3d38ba6 100644 --- a/src/log.py +++ b/src/log.py @@ -5,6 +5,7 @@ import os import sys import typing as t +from copy import deepcopy from datetime import datetime from functools import lru_cache @@ -112,7 +113,8 @@ def setup_logging() -> dict[t.Any, t.Any]: }, } - merged_config = deep_update(uvicorn.config.LOGGING_CONFIG, logging_conf) + # Create a deep copy of uvicorn's logging config to avoid mutating global state. + merged_config = deep_update(deepcopy(uvicorn.config.LOGGING_CONFIG), logging_conf) if handler == "rich": merged_config["loggers"]["uvicorn"]["handlers"] = [handler] From e77b1af80cb7cc6e4f43f48c7f44c69da416f845 Mon Sep 17 00:00:00 2001 From: Sam Doran Date: Mon, 11 May 2026 18:09:20 -0400 Subject: [PATCH 15/28] Fixup docs --- src/log.py | 2 +- tests/unit/test_log.py | 1 + 2 files changed, 2 insertions(+), 1 deletion(-) diff --git a/src/log.py b/src/log.py index ed3d38ba6..a835c7e36 100644 --- a/src/log.py +++ b/src/log.py @@ -65,7 +65,7 @@ def resolve_log_level() -> int: def get_logger(name: str) -> logging.Logger: """Create a common logger for all modules in this package.""" - # FIXME: Remove the need for this function. + # The need for this function should be removed in the future. # # Normally this is derived from the package name (__name__). # diff --git a/tests/unit/test_log.py b/tests/unit/test_log.py index a3aa0f417..1b1158a4a 100644 --- a/tests/unit/test_log.py +++ b/tests/unit/test_log.py @@ -13,6 +13,7 @@ @pytest.fixture(autouse=True) def clear_logging_cache(): + """Clear logging cache""" setup_logging.cache_clear() From f4f442c7084cbb9e0a996a466757ed3fd83e63b9 Mon Sep 17 00:00:00 2001 From: Sam Doran Date: Tue, 12 May 2026 16:13:03 -0400 Subject: [PATCH 16/28] Use caplop instead of creating a fake logging handler --- tests/unit/app/endpoints/test_rlsapi_v1.py | 65 +++++++++------------- 1 file changed, 27 insertions(+), 38 deletions(-) diff --git a/tests/unit/app/endpoints/test_rlsapi_v1.py b/tests/unit/app/endpoints/test_rlsapi_v1.py index f4465b140..cbc0c8168 100644 --- a/tests/unit/app/endpoints/test_rlsapi_v1.py +++ b/tests/unit/app/endpoints/test_rlsapi_v1.py @@ -6,7 +6,6 @@ # pylint: disable=too-many-arguments # pylint: disable=too-many-positional-arguments -import io import logging import re from collections.abc import Callable @@ -20,7 +19,6 @@ from pytest_mock import MockerFixture import constants -from app.endpoints import rlsapi_v1 from app.endpoints.rlsapi_v1 import ( AUTH_DISABLED, TemplateRenderError, @@ -633,12 +631,12 @@ async def test_infer_full_context_request( @pytest.mark.asyncio async def test_infer_info_logs_omit_user_supplied_content( - mocker: MockerFixture, mock_configuration: AppConfig, mock_llm_response: None, mock_auth_resolvers: None, mock_request_factory: Callable[..., Any], mock_background_tasks: Any, + caplog: pytest.LogCaptureFixture, ) -> None: """Test info logs include operational metadata without user content.""" infer_request = RlsapiV1InferRequest( @@ -653,26 +651,22 @@ async def test_infer_info_logs_omit_user_supplied_content( systeminfo=RlsapiV1SystemInfo(os="RHEL", version="9.3", arch="x86_64"), ), ) - log_stream = io.StringIO() - log_handler = logging.StreamHandler(log_stream) - mocker.patch.object(rlsapi_v1.logger, "handlers", [log_handler]) - await infer_endpoint( - infer_request=infer_request, - request=mock_request_factory(), - background_tasks=mock_background_tasks, - auth=MOCK_AUTH, - ) + with caplog.at_level(logging.INFO, logger="lightspeed_stack.app.endpoints.rlsapi_v1"): + await infer_endpoint( + infer_request=infer_request, + request=mock_request_factory(), + background_tasks=mock_background_tasks, + auth=MOCK_AUTH, + ) - log_handler.flush() - logs = log_stream.getvalue() - assert "Processing rlsapi v1 /infer request" in logs - assert "LLM call completed for rlsapi v1 request" in logs - assert "Completed rlsapi v1 /infer request" in logs - assert "sk-user-secret" not in logs - assert "super-secret" not in logs - assert "attachment-secret" not in logs - assert "PRIVATE terminal output" not in logs + assert "Processing rlsapi v1 /infer request" in caplog.text + assert "LLM call completed for rlsapi v1 request" in caplog.text + assert "Completed rlsapi v1 /infer request" in caplog.text + assert "sk-user-secret" not in caplog.text + assert "super-secret" not in caplog.text + assert "attachment-secret" not in caplog.text + assert "PRIVATE terminal output" not in caplog.text @pytest.mark.asyncio @@ -730,32 +724,27 @@ async def test_infer_api_connection_error_returns_503( @pytest.mark.asyncio async def test_infer_api_status_error_logs_class_without_private_text( - mocker: MockerFixture, mock_configuration: AppConfig, mock_api_status_error_with_private_text: None, mock_auth_resolvers: None, mock_request_factory: Callable[..., Any], mock_background_tasks: Any, + caplog: pytest.LogCaptureFixture, ) -> None: """Test API status error logs omit raw exception text.""" - log_stream = io.StringIO() - log_handler = logging.StreamHandler(log_stream) - mocker.patch.object(rlsapi_v1.logger, "handlers", [log_handler]) - - with pytest.raises(HTTPException) as exc_info: - await infer_endpoint( - infer_request=RlsapiV1InferRequest(question="Test question"), - request=mock_request_factory(), - background_tasks=mock_background_tasks, - auth=MOCK_AUTH, - ) + with caplog.at_level(logging.ERROR, logger="lightspeed_stack.app.endpoints.rlsapi_v1"): + with pytest.raises(HTTPException) as exc_info: + await infer_endpoint( + infer_request=RlsapiV1InferRequest(question="Test question"), + request=mock_request_factory(), + background_tasks=mock_background_tasks, + auth=MOCK_AUTH, + ) - log_handler.flush() - logs = log_stream.getvalue() assert exc_info.value.status_code == status.HTTP_500_INTERNAL_SERVER_ERROR - assert "APIStatusError" in logs - assert "sk-backend-secret" not in logs - assert "PRIVATE prompt" not in logs + assert "APIStatusError" in caplog.text + assert "sk-backend-secret" not in caplog.text + assert "PRIVATE prompt" not in caplog.text @pytest.mark.asyncio From 9fcbd4c9648231b0368a3480bda5f0b3a9d37725 Mon Sep 17 00:00:00 2001 From: Sam Doran Date: Tue, 12 May 2026 16:41:01 -0400 Subject: [PATCH 17/28] Get correct logger and do not mess with global state --- .../authorization/test_azure_token_manager.py | 18 ++++++-------- .../config/test_rlsapi_v1_configuration.py | 24 ++++++------------- 2 files changed, 14 insertions(+), 28 deletions(-) diff --git a/tests/unit/authorization/test_azure_token_manager.py b/tests/unit/authorization/test_azure_token_manager.py index d2c93d4e2..e216e9ed3 100644 --- a/tests/unit/authorization/test_azure_token_manager.py +++ b/tests/unit/authorization/test_azure_token_manager.py @@ -2,7 +2,6 @@ # pylint: disable=protected-access -import logging import time from collections.abc import Generator from typing import Any @@ -13,7 +12,6 @@ from pydantic import SecretStr from pytest_mock import MockerFixture -from authorization import azure_token_manager from authorization.azure_token_manager import ( TOKEN_EXPIRATION_LEEWAY, AzureEntraIDManager, @@ -150,15 +148,13 @@ def test_refresh_token_failure_logs_error( return_value=mock_credential_instance, ) - azure_logger = logging.getLogger(azure_token_manager.__name__) - azure_logger.propagate = True - try: - with caplog.at_level("WARNING"): - result = token_manager.refresh_token() - assert result is False - assert "Failed to retrieve Azure access token" in caplog.text - finally: - azure_logger.propagate = False + with caplog.at_level( + "WARNING", logger="lightspeed_stack.authorization.azure_token_manager" + ): + result = token_manager.refresh_token() + + assert result is False + assert "Failed to retrieve Azure access token" in caplog.text def test_token_expired_property_dynamic( self, token_manager: AzureEntraIDManager, mocker: MockerFixture diff --git a/tests/unit/models/config/test_rlsapi_v1_configuration.py b/tests/unit/models/config/test_rlsapi_v1_configuration.py index a36e68a8b..1bd15283c 100644 --- a/tests/unit/models/config/test_rlsapi_v1_configuration.py +++ b/tests/unit/models/config/test_rlsapi_v1_configuration.py @@ -133,15 +133,10 @@ def test_quota_subject_warns_when_no_limiters(caplog: pytest.LogCaptureFixture) authentication={"module": "noop"}, quota_handlers={}, ) - config_logger = logging.getLogger("models.config") - config_logger.propagate = True - try: - with caplog.at_level(logging.WARNING): - Configuration(**config_dict) + with caplog.at_level(logging.WARNING, logger="lightspeed_stack.models.config"): + Configuration(**config_dict) - assert "quota enforcement is not fully configured" in caplog.text - finally: - config_logger.propagate = False + assert "quota enforcement is not fully configured" in caplog.text def test_quota_subject_warns_when_no_storage_backend( @@ -163,12 +158,7 @@ def test_quota_subject_warns_when_no_storage_backend( ], }, ) - config_logger = logging.getLogger("models.config") - config_logger.propagate = True - try: - with caplog.at_level(logging.WARNING): - Configuration(**config_dict) - - assert "quota enforcement is not fully configured" in caplog.text - finally: - config_logger.propagate = False + with caplog.at_level(logging.WARNING, logger="lightspeed_stack.models.config"): + Configuration(**config_dict) + + assert "quota enforcement is not fully configured" in caplog.text From 2bcc500ef1d8dd9c72bc422f158ebbcd46248d01 Mon Sep 17 00:00:00 2001 From: Sam Doran Date: Tue, 12 May 2026 16:46:26 -0400 Subject: [PATCH 18/28] Use constant for default logger name --- tests/unit/app/endpoints/test_rlsapi_v1.py | 9 +++++++-- tests/unit/authorization/test_azure_token_manager.py | 4 +++- tests/unit/models/config/test_rlsapi_v1_configuration.py | 9 +++++++-- 3 files changed, 17 insertions(+), 5 deletions(-) diff --git a/tests/unit/app/endpoints/test_rlsapi_v1.py b/tests/unit/app/endpoints/test_rlsapi_v1.py index cbc0c8168..4270c5705 100644 --- a/tests/unit/app/endpoints/test_rlsapi_v1.py +++ b/tests/unit/app/endpoints/test_rlsapi_v1.py @@ -652,7 +652,9 @@ async def test_infer_info_logs_omit_user_supplied_content( ), ) - with caplog.at_level(logging.INFO, logger="lightspeed_stack.app.endpoints.rlsapi_v1"): + with caplog.at_level( + logging.INFO, logger=f"{constants.DEFAULT_LOGGER_NAME}..app.endpoints.rlsapi_v1" + ): await infer_endpoint( infer_request=infer_request, request=mock_request_factory(), @@ -732,7 +734,10 @@ async def test_infer_api_status_error_logs_class_without_private_text( caplog: pytest.LogCaptureFixture, ) -> None: """Test API status error logs omit raw exception text.""" - with caplog.at_level(logging.ERROR, logger="lightspeed_stack.app.endpoints.rlsapi_v1"): + with caplog.at_level( + logging.ERROR, + logger=f"{constants.DEFAULT_LOGGER_NAME}..app.endpoints.rlsapi_v1", + ): with pytest.raises(HTTPException) as exc_info: await infer_endpoint( infer_request=RlsapiV1InferRequest(question="Test question"), diff --git a/tests/unit/authorization/test_azure_token_manager.py b/tests/unit/authorization/test_azure_token_manager.py index e216e9ed3..89565bf95 100644 --- a/tests/unit/authorization/test_azure_token_manager.py +++ b/tests/unit/authorization/test_azure_token_manager.py @@ -17,6 +17,7 @@ AzureEntraIDManager, ) from configuration import AzureEntraIdConfiguration +from constants import DEFAULT_LOGGER_NAME @pytest.fixture(name="dummy_config") @@ -149,7 +150,8 @@ def test_refresh_token_failure_logs_error( ) with caplog.at_level( - "WARNING", logger="lightspeed_stack.authorization.azure_token_manager" + "WARNING", + logger=f"{DEFAULT_LOGGER_NAME}.authorization.azure_token_manager", ): result = token_manager.refresh_token() diff --git a/tests/unit/models/config/test_rlsapi_v1_configuration.py b/tests/unit/models/config/test_rlsapi_v1_configuration.py index 1bd15283c..f6edef64e 100644 --- a/tests/unit/models/config/test_rlsapi_v1_configuration.py +++ b/tests/unit/models/config/test_rlsapi_v1_configuration.py @@ -6,6 +6,7 @@ import pytest from pydantic import ValidationError +from constants import DEFAULT_LOGGER_NAME from models.config import Configuration, RlsapiV1Configuration # --- Test RlsapiV1Configuration --- @@ -133,7 +134,9 @@ def test_quota_subject_warns_when_no_limiters(caplog: pytest.LogCaptureFixture) authentication={"module": "noop"}, quota_handlers={}, ) - with caplog.at_level(logging.WARNING, logger="lightspeed_stack.models.config"): + with caplog.at_level( + logging.WARNING, logger=f"{DEFAULT_LOGGER_NAME}.models.config" + ): Configuration(**config_dict) assert "quota enforcement is not fully configured" in caplog.text @@ -158,7 +161,9 @@ def test_quota_subject_warns_when_no_storage_backend( ], }, ) - with caplog.at_level(logging.WARNING, logger="lightspeed_stack.models.config"): + with caplog.at_level( + logging.WARNING, logger=f"{DEFAULT_LOGGER_NAME}.models.config" + ): Configuration(**config_dict) assert "quota enforcement is not fully configured" in caplog.text From 2e0ea72b83dda38460d8b63e2a3b8998d57cc721 Mon Sep 17 00:00:00 2001 From: Sam Doran Date: Tue, 12 May 2026 17:02:55 -0400 Subject: [PATCH 19/28] Create a fixture used by all tests that ensure logging state is correct --- tests/unit/conftest.py | 30 ++++++++++++++++++++++++++++++ tests/unit/test_log.py | 6 ------ 2 files changed, 30 insertions(+), 6 deletions(-) diff --git a/tests/unit/conftest.py b/tests/unit/conftest.py index 374db348d..99d40b57f 100644 --- a/tests/unit/conftest.py +++ b/tests/unit/conftest.py @@ -2,6 +2,7 @@ from __future__ import annotations +import logging from collections.abc import Generator from pathlib import Path @@ -11,6 +12,8 @@ from pytest_mock import AsyncMockType, MockerFixture from configuration import AppConfig +from constants import DEFAULT_LOGGER_NAME +from log import setup_logging from models.common.responses.responses_api_params import ResponsesApiParams from models.config import SkillsConfiguration @@ -24,6 +27,33 @@ ] +@pytest.fixture(autouse=True) +def reset_logging_state(): + """Reset logging state before and after each test. + + Module-level calls to setup_logging() (such as from importing lightspeed_stack) + set propagate=False on the application logger, which prevents caplog from + capturing log records. + + This fixture ensures propagation is enabled during tests and restores the + original logger state afterward. It also clears the setup_logging lru_cache + so tests that call setup_logging() get a fresh configuration. + """ + setup_logging.cache_clear() + logger = logging.getLogger(DEFAULT_LOGGER_NAME) + original_propagate = logger.propagate + original_handlers = logger.handlers[:] + original_level = logger.level + logger.propagate = True + + yield + + setup_logging.cache_clear() + logger.propagate = original_propagate + logger.handlers = original_handlers + logger.level = original_level + + @pytest.fixture(name="prepare_agent_mocks", scope="function") def prepare_agent_mocks_fixture( mocker: MockerFixture, diff --git a/tests/unit/test_log.py b/tests/unit/test_log.py index 1b1158a4a..73ffe6d75 100644 --- a/tests/unit/test_log.py +++ b/tests/unit/test_log.py @@ -11,12 +11,6 @@ from log import get_logger, resolve_log_level, setup_logging -@pytest.fixture(autouse=True) -def clear_logging_cache(): - """Clear logging cache""" - setup_logging.cache_clear() - - def test_get_logger() -> None: """Check the function to retrieve logger.""" setup_logging() From 1085c1e0a234821e7f269eac4e4b4eef07f1c3fa Mon Sep 17 00:00:00 2001 From: Sam Doran Date: Tue, 12 May 2026 17:05:43 -0400 Subject: [PATCH 20/28] Fix doc string --- src/runners/uvicorn.py | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/src/runners/uvicorn.py b/src/runners/uvicorn.py index ee2f4e3aa..091a153f3 100644 --- a/src/runners/uvicorn.py +++ b/src/runners/uvicorn.py @@ -19,10 +19,10 @@ def start_uvicorn( Parameters: ---------- configuration (ServiceConfiguration): Configuration providing host, - log_config (dict): Logging configuration, - port, workers, and `tls_config` (including `tls_key_path`, - `tls_certificate_path`, and `tls_key_password`). TLS fields may be None - and will be forwarded to uvicorn.run as provided. + port, workers, and `tls_config` (including `tls_key_path`, + `tls_certificate_path`, and `tls_key_password`). TLS fields may be None + and will be forwarded to uvicorn.run as provided. + log_config (dict): Logging configuration. """ log_level = resolve_log_level() logger.info("Starting Uvicorn with log level %s", logging.getLevelName(log_level)) From 2f0699617f13a1abe0c7431091b06804e655db09 Mon Sep 17 00:00:00 2001 From: Sam Doran Date: Tue, 12 May 2026 17:17:00 -0400 Subject: [PATCH 21/28] Add a test case for the default logging configuration --- tests/unit/runners/test_uvicorn_runner.py | 13 +++++++++++++ 1 file changed, 13 insertions(+) diff --git a/tests/unit/runners/test_uvicorn_runner.py b/tests/unit/runners/test_uvicorn_runner.py index 66bd9d046..eef570565 100644 --- a/tests/unit/runners/test_uvicorn_runner.py +++ b/tests/unit/runners/test_uvicorn_runner.py @@ -189,3 +189,16 @@ def test_start_uvicorn_respects_debug_log_level( access_log=True, log_config={}, ) + + +def test_start_uvicorn_no_log_config(mocker: MockerFixture) -> None: + """Test that the default logging config is used when none is provided.""" + configuration = ServiceConfiguration( + host="localhost", port=8080, workers=1 + ) # pyright: ignore[reportCallIssue] + + mock_setup_logging = mocker.patch("runners.uvicorn.setup_logging") + mock_setup_logging.side_effect = ValueError("Raised intentionally") + + with pytest.raises(ValueError, match="Raised intentionally"): + start_uvicorn(configuration) From 7e641596cdeebe9039f8e8b28edc9bcef3e58ea2 Mon Sep 17 00:00:00 2001 From: Sam Doran Date: Thu, 21 May 2026 13:27:07 -0400 Subject: [PATCH 22/28] Update doc string --- src/runners/uvicorn.py | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/src/runners/uvicorn.py b/src/runners/uvicorn.py index 091a153f3..b86a370e7 100644 --- a/src/runners/uvicorn.py +++ b/src/runners/uvicorn.py @@ -22,7 +22,8 @@ def start_uvicorn( port, workers, and `tls_config` (including `tls_key_path`, `tls_certificate_path`, and `tls_key_password`). TLS fields may be None and will be forwarded to uvicorn.run as provided. - log_config (dict): Logging configuration. + log_config (dict | None): Logging configuration dictionary passed to + uvicorn.run. When None, defaults to the output of setup_logging(). """ log_level = resolve_log_level() logger.info("Starting Uvicorn with log level %s", logging.getLevelName(log_level)) From 14edc5ad2ca6ef65afa6084df063f91499b0d447 Mon Sep 17 00:00:00 2001 From: Sam Doran Date: Thu, 21 May 2026 16:09:11 -0400 Subject: [PATCH 23/28] Implement recursive dict merging to avoid external dependency This is a simpler implementation that still does what we need. --- src/log.py | 17 +++++++++++++++-- 1 file changed, 15 insertions(+), 2 deletions(-) diff --git a/src/log.py b/src/log.py index a835c7e36..5ac47623f 100644 --- a/src/log.py +++ b/src/log.py @@ -10,7 +10,6 @@ from functools import lru_cache import uvicorn.config -from pydantic.v1.utils import deep_update from rich.text import Text from constants import ( @@ -27,6 +26,20 @@ def _ms_time_format(dt: datetime) -> Text: return Text(dt.strftime("%Y-%m-%d %H:%M:%S.") + f"{dt.microsecond // 1000:03d}") +def _deep_merge( + mapping: dict[t.Any, t.Any], updates: dict[t.Any, t.Any] +) -> dict[t.Any, t.Any]: + """Recursively merge updates into mapping.""" + merged = mapping.copy() + for k, v in updates.items(): + if k in merged and isinstance(merged[k], dict) and isinstance(v, dict): + merged[k] = _deep_merge(merged[k], v) + else: + merged[k] = v + + return merged + + def resolve_log_level() -> int: """ Resolve and validate the log level from environment variable. @@ -114,7 +127,7 @@ def setup_logging() -> dict[t.Any, t.Any]: } # Create a deep copy of uvicorn's logging config to avoid mutating global state. - merged_config = deep_update(deepcopy(uvicorn.config.LOGGING_CONFIG), logging_conf) + merged_config = _deep_merge(deepcopy(uvicorn.config.LOGGING_CONFIG), logging_conf) if handler == "rich": merged_config["loggers"]["uvicorn"]["handlers"] = [handler] From 603396b3b2437e3b13e9042f79706168dfb88c85 Mon Sep 17 00:00:00 2001 From: Sam Doran Date: Thu, 21 May 2026 16:17:47 -0400 Subject: [PATCH 24/28] =?UTF-8?q?Properly=20set=20log=20level=20if=20?= =?UTF-8?q?=E2=80=94verbose=20flag=20is=20passed?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit There is no need to modify existing loggers since we are defining one logging config. Setting the env var, invalidating the cache, and calling setup_logging again are sufficient to set the log level properly at all levels. --- src/lightspeed_stack.py | 8 ++------ 1 file changed, 2 insertions(+), 6 deletions(-) diff --git a/src/lightspeed_stack.py b/src/lightspeed_stack.py index a40f63c65..c1858b4ee 100644 --- a/src/lightspeed_stack.py +++ b/src/lightspeed_stack.py @@ -4,7 +4,6 @@ main() function. """ -import logging import os from argparse import ArgumentParser @@ -107,11 +106,8 @@ def main() -> None: if args.verbose: os.environ[LIGHTSPEED_STACK_LOG_LEVEL_ENV_VAR] = "DEBUG" - logging.getLogger().setLevel(logging.DEBUG) - for logger_name in logging.Logger.manager.loggerDict: - existing_logger = logging.getLogger(logger_name) - if isinstance(existing_logger, logging.Logger): - existing_logger.setLevel(logging.DEBUG) + setup_logging.cache_clear() + setup_logging() configuration.load_configuration(args.config_file) logger.info("Configuration: %s", configuration.configuration) From 130408ab7fb3b98905130d645f048efb765ba930 Mon Sep 17 00:00:00 2001 From: Sam Doran Date: Wed, 27 May 2026 17:01:36 -0400 Subject: [PATCH 25/28] Do not force use of colors This forces colors even when the TTY is not capable of displaying them, which results in color escape sequences showing up in the output. --- src/runners/uvicorn.py | 1 - tests/unit/runners/test_uvicorn_runner.py | 6 ------ 2 files changed, 7 deletions(-) diff --git a/src/runners/uvicorn.py b/src/runners/uvicorn.py index b86a370e7..c62dba8bd 100644 --- a/src/runners/uvicorn.py +++ b/src/runners/uvicorn.py @@ -42,6 +42,5 @@ def start_uvicorn( ssl_keyfile=configuration.tls_config.tls_key_path, ssl_certfile=configuration.tls_config.tls_certificate_path, ssl_keyfile_password=str(configuration.tls_config.tls_key_password or ""), - use_colors=True, access_log=True, ) diff --git a/tests/unit/runners/test_uvicorn_runner.py b/tests/unit/runners/test_uvicorn_runner.py index eef570565..a1e4ace6d 100644 --- a/tests/unit/runners/test_uvicorn_runner.py +++ b/tests/unit/runners/test_uvicorn_runner.py @@ -30,7 +30,6 @@ def test_start_uvicorn(mocker: MockerFixture) -> None: ssl_certfile=None, ssl_keyfile=None, ssl_keyfile_password="", - use_colors=True, access_log=True, log_config={}, ) @@ -54,7 +53,6 @@ def test_start_uvicorn_different_host_port(mocker: MockerFixture) -> None: ssl_certfile=None, ssl_keyfile=None, ssl_keyfile_password="", - use_colors=True, access_log=True, log_config={}, ) @@ -79,7 +77,6 @@ def test_start_uvicorn_empty_tls_configuration(mocker: MockerFixture) -> None: ssl_certfile=None, ssl_keyfile=None, ssl_keyfile_password="", - use_colors=True, access_log=True, log_config={}, ) @@ -108,7 +105,6 @@ def test_start_uvicorn_tls_configuration(mocker: MockerFixture) -> None: ssl_certfile=Path("tests/configuration/server.crt"), ssl_keyfile=Path("tests/configuration/server.key"), ssl_keyfile_password="tests/configuration/password", - use_colors=True, access_log=True, log_config={}, ) @@ -132,7 +128,6 @@ def test_start_uvicorn_with_root_path(mocker: MockerFixture) -> None: ssl_certfile=None, ssl_keyfile=None, ssl_keyfile_password="", - use_colors=True, access_log=True, log_config={}, ) @@ -185,7 +180,6 @@ def test_start_uvicorn_respects_debug_log_level( ssl_certfile=None, ssl_keyfile=None, ssl_keyfile_password="", - use_colors=True, access_log=True, log_config={}, ) From 9b3498f344e1480f94eb28bf86dd0e4b1a019f3b Mon Sep 17 00:00:00 2001 From: Sam Doran Date: Thu, 28 May 2026 12:04:19 -0400 Subject: [PATCH 26/28] Separate logging config from logging setup Separate the logging configuration generation from the application of that config and do not cache the result. The logging configuration can change during initialization. This resulted in needing the clear the function cache in order to have a new config generated. The cache was hindering more than helping. There are certain places where the configuration is needed but without wanting to repapply it. That was the point of caching the result of setup_logging before. A cleaner approarch is to separate the two areas of concern, which is what this change does. --- src/lightspeed_stack.py | 1 - src/log.py | 11 ++++++----- src/runners/uvicorn.py | 4 ++-- tests/unit/conftest.py | 3 --- tests/unit/runners/test_uvicorn_runner.py | 2 +- 5 files changed, 9 insertions(+), 12 deletions(-) diff --git a/src/lightspeed_stack.py b/src/lightspeed_stack.py index c1858b4ee..a53d80a94 100644 --- a/src/lightspeed_stack.py +++ b/src/lightspeed_stack.py @@ -106,7 +106,6 @@ def main() -> None: if args.verbose: os.environ[LIGHTSPEED_STACK_LOG_LEVEL_ENV_VAR] = "DEBUG" - setup_logging.cache_clear() setup_logging() configuration.load_configuration(args.config_file) diff --git a/src/log.py b/src/log.py index 5ac47623f..803d9718c 100644 --- a/src/log.py +++ b/src/log.py @@ -7,7 +7,6 @@ import typing as t from copy import deepcopy from datetime import datetime -from functools import lru_cache import uvicorn.config from rich.text import Text @@ -91,8 +90,7 @@ def get_logger(name: str) -> logging.Logger: return logging.getLogger(f"{DEFAULT_LOGGER_NAME}.{name}") -@lru_cache -def setup_logging() -> dict[t.Any, t.Any]: +def build_logging_config() -> dict[t.Any, t.Any]: """Create logging configuration.""" handler = "default" log_level = resolve_log_level() @@ -140,6 +138,9 @@ def setup_logging() -> dict[t.Any, t.Any]: merged_config["formatters"]["default"]["fmt"] = DEFAULT_LOG_FORMAT merged_config["formatters"]["default"]["datefmt"] = "%Y-%m-%d %H:%M:%S" - logging.config.dictConfig(merged_config) - return merged_config + + +def setup_logging() -> None: + """Set up main logging configuration.""" + logging.config.dictConfig(build_logging_config()) diff --git a/src/runners/uvicorn.py b/src/runners/uvicorn.py index c62dba8bd..385616af6 100644 --- a/src/runners/uvicorn.py +++ b/src/runners/uvicorn.py @@ -4,7 +4,7 @@ import uvicorn -from log import get_logger, resolve_log_level, setup_logging +from log import build_logging_config, get_logger, resolve_log_level from models.config import ServiceConfiguration logger = get_logger(__name__) @@ -28,7 +28,7 @@ def start_uvicorn( log_level = resolve_log_level() logger.info("Starting Uvicorn with log level %s", logging.getLevelName(log_level)) if log_config is None: - log_config = setup_logging() + log_config = build_logging_config() # please note: # TLS fields can be None, which means we will pass those values as None to uvicorn.run diff --git a/tests/unit/conftest.py b/tests/unit/conftest.py index 99d40b57f..7c638ee8e 100644 --- a/tests/unit/conftest.py +++ b/tests/unit/conftest.py @@ -13,7 +13,6 @@ from configuration import AppConfig from constants import DEFAULT_LOGGER_NAME -from log import setup_logging from models.common.responses.responses_api_params import ResponsesApiParams from models.config import SkillsConfiguration @@ -39,7 +38,6 @@ def reset_logging_state(): original logger state afterward. It also clears the setup_logging lru_cache so tests that call setup_logging() get a fresh configuration. """ - setup_logging.cache_clear() logger = logging.getLogger(DEFAULT_LOGGER_NAME) original_propagate = logger.propagate original_handlers = logger.handlers[:] @@ -48,7 +46,6 @@ def reset_logging_state(): yield - setup_logging.cache_clear() logger.propagate = original_propagate logger.handlers = original_handlers logger.level = original_level diff --git a/tests/unit/runners/test_uvicorn_runner.py b/tests/unit/runners/test_uvicorn_runner.py index a1e4ace6d..a3457a5bd 100644 --- a/tests/unit/runners/test_uvicorn_runner.py +++ b/tests/unit/runners/test_uvicorn_runner.py @@ -191,7 +191,7 @@ def test_start_uvicorn_no_log_config(mocker: MockerFixture) -> None: host="localhost", port=8080, workers=1 ) # pyright: ignore[reportCallIssue] - mock_setup_logging = mocker.patch("runners.uvicorn.setup_logging") + mock_setup_logging = mocker.patch("runners.uvicorn.build_logging_config") mock_setup_logging.side_effect = ValueError("Raised intentionally") with pytest.raises(ValueError, match="Raised intentionally"): From 6225cb6fe251cfce068cd74769b713cedd016fcf Mon Sep 17 00:00:00 2001 From: Sam Doran Date: Thu, 28 May 2026 12:09:23 -0400 Subject: [PATCH 27/28] Reapply logging configuration after AsyncLlamaStackAsLibraryClient During initialization of AsyncLlamaStackAsLibraryClient, a logging configartion is generated and applied. We want the lightspeed-stack logging config to always be used. --- src/client.py | 17 ++++++++++++++++- 1 file changed, 16 insertions(+), 1 deletion(-) diff --git a/src/client.py b/src/client.py index d66d5dfb3..642504fb1 100644 --- a/src/client.py +++ b/src/client.py @@ -20,7 +20,7 @@ enrich_solr, synthesize_to_file, ) -from log import get_logger +from log import get_logger, setup_logging from models.api.responses.error import ServiceUnavailableResponse from models.config import LlamaStackConfiguration from utils.types import Singleton @@ -75,6 +75,11 @@ async def _load_library_client(self, config: LlamaStackConfiguration) -> None: await client.initialize() self._lsc = client + # Re-apply logging configuration after ogx's setup_logging() is called. + # This ensures the desired logging configuration is applied when + # using AsyncLlamaStackAsLibraryClient. + setup_logging() + def _synthesize_library_config(self) -> str: """Synthesize a unified-mode run.yaml and return its on-disk path. @@ -191,6 +196,11 @@ async def reload_library_client(self) -> AsyncLlamaStackClient: ) raise HTTPException(**error_response.model_dump()) from e self._lsc = client + # Re-apply logging configuration after ogx's setup_logging() is called. + # This ensures the desired logging configuration is applied when + # using AsyncLlamaStackAsLibraryClient. + setup_logging() + return client async def check_model_available(self, model_id: str) -> tuple[bool, str]: @@ -287,6 +297,11 @@ async def update_azure_token(self) -> AsyncLlamaStackClient: ) await client.initialize() self._lsc = client + # Re-apply logging configuration after ogx's setup_logging() is called. + # This ensures the desired logging configuration is applied when + # using AsyncLlamaStackAsLibraryClient. + setup_logging() + return client # Service client mode From 13842edff1b39c4ebd057ab5cf8f7c63fe4c39cd Mon Sep 17 00:00:00 2001 From: Sam Doran Date: Thu, 28 May 2026 12:43:37 -0400 Subject: [PATCH 28/28] Set datefmt for access log --- src/log.py | 1 + 1 file changed, 1 insertion(+) diff --git a/src/log.py b/src/log.py index 803d9718c..4fc20408a 100644 --- a/src/log.py +++ b/src/log.py @@ -135,6 +135,7 @@ def build_logging_config() -> dict[t.Any, t.Any]: "%(asctime)s.%(msecs)03d %(levelprefix)s " '%(client_addr)s - "%(request_line)s" %(status_code)s' ) + merged_config["formatters"]["access"]["datefmt"] = "%Y-%m-%d %H:%M:%S" merged_config["formatters"]["default"]["fmt"] = DEFAULT_LOG_FORMAT merged_config["formatters"]["default"]["datefmt"] = "%Y-%m-%d %H:%M:%S"