From e5ec49bbfa6a99018cca122edb1d27492668adb1 Mon Sep 17 00:00:00 2001 From: Sam Doran Date: Mon, 4 May 2026 17:36:11 -0400 Subject: [PATCH 01/21] 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 858799c36..47e53cf81 100644 --- a/src/lightspeed_stack.py +++ b/src/lightspeed_stack.py @@ -6,38 +6,17 @@ import logging import os -import sys from argparse import ArgumentParser 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 4de615731e349dd1b4a25866c81320a6ccdb453f Mon Sep 17 00:00:00 2001 From: Sam Doran Date: Mon, 4 May 2026 17:39:13 -0400 Subject: [PATCH 02/21] 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 e16a00f27..fff2593c7 100644 --- a/src/constants.py +++ b/src/constants.py @@ -230,6 +230,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 5b4d6c7fb5efc1880d8001bb4b89ea4f0d3ccdc6 Mon Sep 17 00:00:00 2001 From: Sam Doran Date: Mon, 4 May 2026 18:05:58 -0400 Subject: [PATCH 03/21] 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 e3a4cf9f9..50260154e 100644 --- a/src/app/endpoints/a2a.py +++ b/src/app/endpoints/a2a.py @@ -54,7 +54,7 @@ from utils.suid import normalize_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 21dea5097..9adf8fd76 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 9ba282072..7ba507247 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 7d591e581..af2b76ac4 100644 --- a/src/app/endpoints/health.py +++ b/src/app/endpoints/health.py @@ -29,7 +29,7 @@ from models.common import HealthStatus, ProviderHealthStatus from models.config import Action -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 2acd89b03..659f6e7a3 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 e094992ef..e064b70e2 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 fc35da82f..6c0989530 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 0d7592ae0..a17347722 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 7b985e9c0..534d98fbe 100644 --- a/src/app/endpoints/query.py +++ b/src/app/endpoints/query.py @@ -70,7 +70,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 c60c6db64..32cbd69d7 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 2705a27dd..80f47bc73 100644 --- a/src/app/endpoints/responses.py +++ b/src/app/endpoints/responses.py @@ -111,7 +111,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 08555a4d5..0ca6c001f 100644 --- a/src/app/endpoints/rlsapi_v1.py +++ b/src/app/endpoints/rlsapi_v1.py @@ -60,7 +60,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 45d7d4bb6..3a57d013f 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 480e02d50..cce3e2ffd 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 6079d2aa4..c64117935 100644 --- a/src/app/endpoints/streaming_query.py +++ b/src/app/endpoints/streaming_query.py @@ -120,7 +120,7 @@ from utils.token_counter import TokenCounter 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 222e1fc7a..1f537da24 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 af42dd9f5..196eaf0c6 100644 --- a/src/app/main.py +++ b/src/app/main.py @@ -28,7 +28,7 @@ from utils.common import register_mcp_servers_async 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 8803c57ca..9b13fae54 100644 --- a/src/authentication/__init__.py +++ b/src/authentication/__init__.py @@ -15,7 +15,7 @@ from configuration import LogicError, configuration from log import get_logger -logger = get_logger(__name__) +logger = get_logger(__file__) def get_auth_dependency( diff --git a/src/authentication/api_key_token.py b/src/authentication/api_key_token.py index 2b9b27900..10aea80dc 100644 --- a/src/authentication/api_key_token.py +++ b/src/authentication/api_key_token.py @@ -20,7 +20,7 @@ from log import get_logger from models.config import APIKeyTokenConfiguration -logger = get_logger(__name__) +logger = get_logger(__file__) class APIKeyTokenAuthDependency( diff --git a/src/authentication/jwk_token.py b/src/authentication/jwk_token.py index 7cc15870b..24920f9c7 100644 --- a/src/authentication/jwk_token.py +++ b/src/authentication/jwk_token.py @@ -25,7 +25,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 f772ae9e5..dae14e11c 100644 --- a/src/authentication/rh_identity.py +++ b/src/authentication/rh_identity.py @@ -19,7 +19,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 bc1cf323d..da3f397e2 100644 --- a/src/authorization/azure_token_manager.py +++ b/src/authorization/azure_token_manager.py @@ -13,7 +13,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 2aaa8d415..cb0bca4d0 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 cf2b85a76..2871d921e 100644 --- a/src/cache/in_memory_cache.py +++ b/src/cache/in_memory_cache.py @@ -7,7 +7,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 e7426885b..95662ee11 100644 --- a/src/cache/noop_cache.py +++ b/src/cache/noop_cache.py @@ -6,7 +6,7 @@ from models.common import ConversationData 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 b51b06893..1489859c3 100644 --- a/src/cache/postgres_cache.py +++ b/src/cache/postgres_cache.py @@ -18,7 +18,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 ee1c4c2e4..f564c56c5 100644 --- a/src/cache/sqlite_cache.py +++ b/src/cache/sqlite_cache.py @@ -17,7 +17,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 a503c0094..b06bed51b 100644 --- a/src/client.py +++ b/src/client.py @@ -17,7 +17,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 c6a376327..60c437442 100644 --- a/src/configuration.py +++ b/src/configuration.py @@ -37,7 +37,7 @@ from quota.quota_limiter_factory import QuotaLimiterFactory from quota.token_usage_history import TokenUsageHistory -logger = get_logger(__name__) +logger = get_logger(__file__) class LogicError(Exception): diff --git a/src/llama_stack_configuration.py b/src/llama_stack_configuration.py index dab8e163e..1d8f0f587 100644 --- a/src/llama_stack_configuration.py +++ b/src/llama_stack_configuration.py @@ -19,7 +19,7 @@ import constants from log import get_logger -logger = get_logger(__name__) +logger = get_logger(__file__) class YamlDumper(yaml.Dumper): # pylint: disable=too-many-ancestors diff --git a/src/metrics/recording.py b/src/metrics/recording.py index a9b35d208..f76a6f8f1 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 806e7a336..802e3d311 100644 --- a/src/metrics/utils.py +++ b/src/metrics/utils.py @@ -11,7 +11,7 @@ from utils.common import run_once_async from utils.endpoints import check_configuration_loaded -logger = get_logger(__name__) +logger = get_logger(__file__) @run_once_async diff --git a/src/models/config.py b/src/models/config.py index ba3671ba0..e5542e9a2 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 a9d2a5754..8491199fc 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 885dfdf52..c0d62f8c7 100644 --- a/src/utils/llama_stack_version.py +++ b/src/utils/llama_stack_version.py @@ -12,7 +12,7 @@ ) from log import get_logger -logger = get_logger(__name__) +logger = get_logger(__file__) # Retry settings for waiting on Llama Stack readiness during startup. # When LCS runs as a sidecar alongside Llama Stack, both containers start 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 9daa086aa..42e2f2ecd 100644 --- a/src/utils/query.py +++ b/src/utils/query.py @@ -49,7 +49,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 0ed7477bc..b5fe93d87 100644 --- a/src/utils/responses.py +++ b/src/utils/responses.py @@ -123,7 +123,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 1ce0c1058..28ac5a238 100644 --- a/src/utils/stream_interrupts.py +++ b/src/utils/stream_interrupts.py @@ -10,7 +10,7 @@ from log import get_logger 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 beaa4e862..8479e386e 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 77c2e0d77a86cc041416ef8617f6382fd33e0146 Mon Sep 17 00:00:00 2001 From: Sam Doran Date: Mon, 4 May 2026 18:09:11 -0400 Subject: [PATCH 04/21] 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 29e13ad65a704b629917e32f7da3d487a259010a Mon Sep 17 00:00:00 2001 From: Sam Doran Date: Mon, 4 May 2026 18:09:31 -0400 Subject: [PATCH 05/21] 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 fff2593c7..fdd61a0f6 100644 --- a/src/constants.py +++ b/src/constants.py @@ -234,7 +234,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 aa7d197cc4b3ba1191f2cdd281f560a138c6439d Mon Sep 17 00:00:00 2001 From: Sam Doran Date: Tue, 5 May 2026 00:40:06 -0400 Subject: [PATCH 06/21] 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 b913dbf8a4e6b550745b7e2d93efc2145e1140bd Mon Sep 17 00:00:00 2001 From: Sam Doran Date: Wed, 6 May 2026 11:02:14 -0400 Subject: [PATCH 07/21] 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 50260154e..e3a4cf9f9 100644 --- a/src/app/endpoints/a2a.py +++ b/src/app/endpoints/a2a.py @@ -54,7 +54,7 @@ from utils.suid import normalize_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 9adf8fd76..21dea5097 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 7ba507247..9ba282072 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 af2b76ac4..7d591e581 100644 --- a/src/app/endpoints/health.py +++ b/src/app/endpoints/health.py @@ -29,7 +29,7 @@ from models.common import HealthStatus, ProviderHealthStatus from models.config import Action -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 659f6e7a3..2acd89b03 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 e064b70e2..e094992ef 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 6c0989530..fc35da82f 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 a17347722..0d7592ae0 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 534d98fbe..7b985e9c0 100644 --- a/src/app/endpoints/query.py +++ b/src/app/endpoints/query.py @@ -70,7 +70,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 32cbd69d7..c60c6db64 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 80f47bc73..2705a27dd 100644 --- a/src/app/endpoints/responses.py +++ b/src/app/endpoints/responses.py @@ -111,7 +111,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 0ca6c001f..08555a4d5 100644 --- a/src/app/endpoints/rlsapi_v1.py +++ b/src/app/endpoints/rlsapi_v1.py @@ -60,7 +60,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 3a57d013f..45d7d4bb6 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 cce3e2ffd..480e02d50 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 c64117935..6079d2aa4 100644 --- a/src/app/endpoints/streaming_query.py +++ b/src/app/endpoints/streaming_query.py @@ -120,7 +120,7 @@ from utils.token_counter import TokenCounter 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 1f537da24..222e1fc7a 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 196eaf0c6..af42dd9f5 100644 --- a/src/app/main.py +++ b/src/app/main.py @@ -28,7 +28,7 @@ from utils.common import register_mcp_servers_async 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 9b13fae54..8803c57ca 100644 --- a/src/authentication/__init__.py +++ b/src/authentication/__init__.py @@ -15,7 +15,7 @@ from configuration import LogicError, configuration from log import get_logger -logger = get_logger(__file__) +logger = get_logger(__name__) def get_auth_dependency( diff --git a/src/authentication/api_key_token.py b/src/authentication/api_key_token.py index 10aea80dc..2b9b27900 100644 --- a/src/authentication/api_key_token.py +++ b/src/authentication/api_key_token.py @@ -20,7 +20,7 @@ from log import get_logger from models.config import APIKeyTokenConfiguration -logger = get_logger(__file__) +logger = get_logger(__name__) class APIKeyTokenAuthDependency( diff --git a/src/authentication/jwk_token.py b/src/authentication/jwk_token.py index 24920f9c7..7cc15870b 100644 --- a/src/authentication/jwk_token.py +++ b/src/authentication/jwk_token.py @@ -25,7 +25,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 dae14e11c..f772ae9e5 100644 --- a/src/authentication/rh_identity.py +++ b/src/authentication/rh_identity.py @@ -19,7 +19,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 da3f397e2..bc1cf323d 100644 --- a/src/authorization/azure_token_manager.py +++ b/src/authorization/azure_token_manager.py @@ -13,7 +13,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 cb0bca4d0..2aaa8d415 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 2871d921e..cf2b85a76 100644 --- a/src/cache/in_memory_cache.py +++ b/src/cache/in_memory_cache.py @@ -7,7 +7,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 95662ee11..e7426885b 100644 --- a/src/cache/noop_cache.py +++ b/src/cache/noop_cache.py @@ -6,7 +6,7 @@ from models.common import ConversationData 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 1489859c3..b51b06893 100644 --- a/src/cache/postgres_cache.py +++ b/src/cache/postgres_cache.py @@ -18,7 +18,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 f564c56c5..ee1c4c2e4 100644 --- a/src/cache/sqlite_cache.py +++ b/src/cache/sqlite_cache.py @@ -17,7 +17,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 b06bed51b..a503c0094 100644 --- a/src/client.py +++ b/src/client.py @@ -17,7 +17,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 60c437442..c6a376327 100644 --- a/src/configuration.py +++ b/src/configuration.py @@ -37,7 +37,7 @@ from quota.quota_limiter_factory import QuotaLimiterFactory from quota.token_usage_history import TokenUsageHistory -logger = get_logger(__file__) +logger = get_logger(__name__) class LogicError(Exception): diff --git a/src/lightspeed_stack.py b/src/lightspeed_stack.py index 47e53cf81..7de801080 100644 --- a/src/lightspeed_stack.py +++ b/src/lightspeed_stack.py @@ -16,7 +16,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 1d8f0f587..dab8e163e 100644 --- a/src/llama_stack_configuration.py +++ b/src/llama_stack_configuration.py @@ -19,7 +19,7 @@ import constants from log import get_logger -logger = get_logger(__file__) +logger = get_logger(__name__) class YamlDumper(yaml.Dumper): # pylint: disable=too-many-ancestors 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 f76a6f8f1..a9b35d208 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 802e3d311..806e7a336 100644 --- a/src/metrics/utils.py +++ b/src/metrics/utils.py @@ -11,7 +11,7 @@ from utils.common import run_once_async from utils.endpoints import check_configuration_loaded -logger = get_logger(__file__) +logger = get_logger(__name__) @run_once_async diff --git a/src/models/config.py b/src/models/config.py index e5542e9a2..ba3671ba0 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 8491199fc..a9d2a5754 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 c0d62f8c7..885dfdf52 100644 --- a/src/utils/llama_stack_version.py +++ b/src/utils/llama_stack_version.py @@ -12,7 +12,7 @@ ) from log import get_logger -logger = get_logger(__file__) +logger = get_logger(__name__) # Retry settings for waiting on Llama Stack readiness during startup. # When LCS runs as a sidecar alongside Llama Stack, both containers start 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 42e2f2ecd..9daa086aa 100644 --- a/src/utils/query.py +++ b/src/utils/query.py @@ -49,7 +49,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 b5fe93d87..0ed7477bc 100644 --- a/src/utils/responses.py +++ b/src/utils/responses.py @@ -123,7 +123,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 28ac5a238..1ce0c1058 100644 --- a/src/utils/stream_interrupts.py +++ b/src/utils/stream_interrupts.py @@ -10,7 +10,7 @@ from log import get_logger 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 8479e386e..beaa4e862 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 0905eb5d2ce050111bc1375b68ef269385b5946f Mon Sep 17 00:00:00 2001 From: Sam Doran Date: Wed, 6 May 2026 11:02:26 -0400 Subject: [PATCH 08/21] 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 fdd61a0f6..fe2a24f70 100644 --- a/src/constants.py +++ b/src/constants.py @@ -230,7 +230,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 40a2df01f15995d010e5de1be5f08b36bb52ffdd Mon Sep 17 00:00:00 2001 From: Sam Doran Date: Fri, 8 May 2026 17:40:06 -0400 Subject: [PATCH 09/21] 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 8bf81576aec0bb8dacecb8cb45110a65bbe2be55 Mon Sep 17 00:00:00 2001 From: Sam Doran Date: Fri, 8 May 2026 17:41:09 -0400 Subject: [PATCH 10/21] 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 c72642fd2bd8f049680ebedbf452c32c9635a141 Mon Sep 17 00:00:00 2001 From: Sam Doran Date: Mon, 11 May 2026 17:26:25 -0400 Subject: [PATCH 11/21] 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 fe2a24f70..eea7ce8d6 100644 --- a/src/constants.py +++ b/src/constants.py @@ -230,7 +230,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 0e5128bbe606dda30e6af87b14826bb0220ff88c Mon Sep 17 00:00:00 2001 From: Sam Doran Date: Mon, 11 May 2026 17:32:48 -0400 Subject: [PATCH 12/21] 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 d1280fe1e5e17dcefdbcf71afecfb9607711cb6c Mon Sep 17 00:00:00 2001 From: Sam Doran Date: Mon, 11 May 2026 17:38:26 -0400 Subject: [PATCH 13/21] 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 1f103958be402d41b74856419cb6e08f6485afa5 Mon Sep 17 00:00:00 2001 From: Sam Doran Date: Mon, 11 May 2026 17:53:15 -0400 Subject: [PATCH 14/21] 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 237530ce9a9a54b81432a656164eae6a34f1d8eb Mon Sep 17 00:00:00 2001 From: Sam Doran Date: Mon, 11 May 2026 18:09:20 -0400 Subject: [PATCH 15/21] 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 56206b4bc28727559fab2fd9a209adb93cae62ac Mon Sep 17 00:00:00 2001 From: Sam Doran Date: Tue, 12 May 2026 16:13:03 -0400 Subject: [PATCH 16/21] 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 38227cf4c..d80870ea6 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, @@ -687,12 +685,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( @@ -707,26 +705,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 @@ -784,32 +778,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 67b4fbbf53c9f67996f7fa9957495eb0d58a578a Mon Sep 17 00:00:00 2001 From: Sam Doran Date: Tue, 12 May 2026 16:41:01 -0400 Subject: [PATCH 17/21] 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 f5b7d1fe6..09422b387 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, @@ -138,15 +136,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 c32fc26656d89221c0d40ac144cea9378704a336 Mon Sep 17 00:00:00 2001 From: Sam Doran Date: Tue, 12 May 2026 16:46:26 -0400 Subject: [PATCH 18/21] 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 d80870ea6..9c38fd17c 100644 --- a/tests/unit/app/endpoints/test_rlsapi_v1.py +++ b/tests/unit/app/endpoints/test_rlsapi_v1.py @@ -706,7 +706,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(), @@ -786,7 +788,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 09422b387..83e8d816a 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") @@ -137,7 +138,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 083936054a8959920ff449b364d6da38b8b90e36 Mon Sep 17 00:00:00 2001 From: Sam Doran Date: Tue, 12 May 2026 17:02:55 -0400 Subject: [PATCH 19/21] 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 cf741b9e8..32faba42a 100644 --- a/tests/unit/conftest.py +++ b/tests/unit/conftest.py @@ -2,12 +2,15 @@ from __future__ import annotations +import logging from collections.abc import Generator import pytest from pytest_mock import AsyncMockType, MockerFixture from configuration import AppConfig +from constants import DEFAULT_LOGGER_NAME +from log import setup_logging type AgentFixtures = Generator[ tuple[ @@ -19,6 +22,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 b3b10594602109400805828b1c39124b40960c13 Mon Sep 17 00:00:00 2001 From: Sam Doran Date: Tue, 12 May 2026 17:05:43 -0400 Subject: [PATCH 20/21] 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 c0ac8e1390a82559730b3586d495780ba9ab01c8 Mon Sep 17 00:00:00 2001 From: Sam Doran Date: Tue, 12 May 2026 17:17:00 -0400 Subject: [PATCH 21/21] 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)