diff --git a/src/constants.py b/src/constants.py index e16a00f27..eea7ce8d6 100644 --- a/src/constants.py +++ b/src/constants.py @@ -230,10 +230,11 @@ # 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: 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] = ( - "%(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 diff --git a/src/lightspeed_stack.py b/src/lightspeed_stack.py index 858799c36..7de801080 100644 --- a/src/lightspeed_stack.py +++ b/src/lightspeed_stack.py @@ -6,37 +6,16 @@ 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, - ) - +setup_logging() logger = get_logger(__name__) diff --git a/src/log.py b/src/log.py index 389b32fca..a835c7e36 100644 --- a/src/log.py +++ b/src/log.py @@ -1,19 +1,32 @@ """Log utilities.""" import logging +import logging.config import os import sys +import typing as t +from copy import deepcopy +from datetime import datetime +from functools import lru_cache -from rich.logging import RichHandler +import uvicorn.config +from pydantic.v1.utils import deep_update +from rich.text import Text 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, ) +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. @@ -50,62 +63,70 @@ 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) + """Create a common logger for all modules in this package.""" + # The need for this function should be removed in the future. + # + # 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 +def setup_logging() -> dict[t.Any, t.Any]: + """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 + ): + handler = "rich" + + logging_conf = { + "version": 1, + "disable_existing_loggers": False, + "handlers": { + "rich": { + "()": "rich.logging.RichHandler", + "show_time": True, + "log_time_format": _ms_time_format, + "level": log_level, + }, + }, + "loggers": { + DEFAULT_LOGGER_NAME: { + "handlers": [handler], + "level": log_level, + "propagate": False, + }, + "llama_stack_client": { + "handlers": [handler], + "level": log_level, + "propagate": False, + }, + }, + } + + # 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] + 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" - # Skip reconfiguration if logger already has handlers from a prior call - if logger.handlers: - return logger + logging.config.dictConfig(merged_config) - logger.handlers = [create_log_handler()] - logger.propagate = False - logger.setLevel(resolve_log_level()) - return logger + return merged_config diff --git a/src/runners/uvicorn.py b/src/runners/uvicorn.py index 6e217095e..091a153f3 100644 --- a/src/runners/uvicorn.py +++ b/src/runners/uvicorn.py @@ -4,24 +4,30 @@ 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__) -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: ---------- configuration (ServiceConfiguration): Configuration providing host, - 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)) + 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 +36,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, diff --git a/tests/unit/app/endpoints/test_rlsapi_v1.py b/tests/unit/app/endpoints/test_rlsapi_v1.py index 38227cf4c..9c38fd17c 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,24 @@ 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=f"{constants.DEFAULT_LOGGER_NAME}..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 +780,30 @@ 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=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"), + 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 diff --git a/tests/unit/authorization/test_azure_token_manager.py b/tests/unit/authorization/test_azure_token_manager.py index f5b7d1fe6..83e8d816a 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,12 +12,12 @@ 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, ) from configuration import AzureEntraIdConfiguration +from constants import DEFAULT_LOGGER_NAME @pytest.fixture(name="dummy_config") @@ -138,15 +137,14 @@ 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=f"{DEFAULT_LOGGER_NAME}.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/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/models/config/test_rlsapi_v1_configuration.py b/tests/unit/models/config/test_rlsapi_v1_configuration.py index a36e68a8b..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,15 +134,12 @@ 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=f"{DEFAULT_LOGGER_NAME}.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 +161,9 @@ 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=f"{DEFAULT_LOGGER_NAME}.models.config" + ): + Configuration(**config_dict) + + assert "quota enforcement is not fully configured" in caplog.text diff --git a/tests/unit/runners/test_uvicorn_runner.py b/tests/unit/runners/test_uvicorn_runner.py index 5c0ceb01e..eef570565 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,18 @@ def test_start_uvicorn_respects_debug_log_level( ssl_keyfile_password="", use_colors=True, 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) diff --git a/tests/unit/test_log.py b/tests/unit/test_log.py index 0e47caf9b..73ffe6d75 100644 --- a/tests/unit/test_log.py +++ b/tests/unit/test_log.py @@ -3,34 +3,33 @@ 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 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() + + logger = get_logger(__name__) - # at least one handler need to be set - assert len(logger.handlers) >= 1 + 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 +58,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 +91,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