Files
tatlock/tests/core/test_logging_config.py
T
jpmschweitzerandClaude 78066fab1b style: apply ruff's automatic fixes and formatter
Mechanical only, and separated from the judgment calls that follow so the
reviewable changes are not buried in a 98-file whitespace diff.

227 automatic fixes: 60 blank lines carrying whitespace, 60 unsorted import
blocks, 34 Optional[X] to X | None, 28 unused imports, 16 deprecated typing
imports, 12 datetime.timezone.utc to datetime.UTC, and assorted smaller
modernisations. Then `ruff format` over src and tests: 98 files reformatted,
35 already conforming.

No file among the unused-import findings defines __all__ or is an __init__.py,
so nothing here removes a re-export.

`make test`: 658 passed, unchanged from HEAD.

Two things observed while verifying, neither addressed here:

`pytest tests/` cannot collect — tests/e2e/test_orchestration_e2e.py uses an
`e2e` marker that is not registered, and the config is strict about markers.
This fails identically at HEAD, so it predates this change; `make test` passes
because it ignores tests/e2e, tests/integration and tests/contracts.

test_tatlock_tool_call_logging_calculator is flaky. It failed once in a full run
with these changes and passed on the next, passes in isolation with them, and
fails in isolation at HEAD. It is order- or timing-dependent, not a regression
from this commit — established by running the full suite both ways rather than
by reasoning about which change could have caused it.

Co-Authored-By: Claude <noreply@anthropic.com>
2026-08-11 17:25:18 +02:00

254 lines
8.0 KiB
Python

"""
Tests for structured logging configuration.
Tests logging setup, context management, and FastAPI integration.
"""
import logging
from unittest.mock import patch
import pytest
from src.core.logging_config import (
add_log_level,
add_timestamp,
get_logger,
get_uvicorn_log_config,
log_operation,
)
class TestLoggingProcessors:
"""Test logging processor functions."""
def test_add_timestamp(self):
"""Test timestamp processor adds ISO timestamp."""
event_dict = {}
result = add_timestamp(None, "info", event_dict)
assert "timestamp" in result
assert isinstance(result["timestamp"], str)
# Should be ISO 8601 format
assert "T" in result["timestamp"] or "-" in result["timestamp"]
def test_add_log_level(self):
"""Test log level processor."""
event_dict = {}
result = add_log_level(None, "info", event_dict)
assert result["level"] == "INFO"
result = add_log_level(None, "error", {})
assert result["level"] == "ERROR"
class TestGetLogger:
"""Test logger retrieval."""
def test_get_logger_returns_bound_logger(self):
"""Test get_logger returns structlog BoundLogger."""
logger = get_logger("test")
# Logger should have standard logging methods
assert hasattr(logger, "info")
assert hasattr(logger, "debug")
assert hasattr(logger, "warning")
assert hasattr(logger, "error")
def test_get_logger_with_module_name(self):
"""Test logger with module name."""
logger = get_logger(__name__)
assert logger is not None
def test_logger_has_standard_methods(self):
"""Test logger has standard logging methods."""
logger = get_logger("test")
assert hasattr(logger, "debug")
assert hasattr(logger, "info")
assert hasattr(logger, "warning")
assert hasattr(logger, "error")
assert hasattr(logger, "exception")
class TestLogOperation:
"""Test log_operation context manager."""
@pytest.mark.asyncio
async def test_log_operation_success(self):
"""Test log_operation for successful operation."""
logger = get_logger("test")
async with log_operation("test_operation", {"user_id": "123"}) as ctx:
# Can update context during operation
ctx["result_count"] = 5
# Context should have been updated with success info
assert ctx["success"] is True
assert ctx["result_count"] == 5
assert "duration_seconds" in ctx
@pytest.mark.asyncio
async def test_log_operation_failure(self):
"""Test log_operation for failed operation."""
logger = get_logger("test")
with pytest.raises(ValueError):
async with log_operation("test_operation") as ctx:
raise ValueError("Test error")
# Context should have failure info
assert ctx["success"] is False
assert ctx["error"] == "Test error"
assert ctx["error_type"] == "ValueError"
assert "duration_seconds" in ctx
@pytest.mark.asyncio
async def test_log_operation_timing(self):
"""Test log_operation records duration."""
import asyncio
async with log_operation("test_operation") as ctx:
await asyncio.sleep(0.01) # Small delay
# Should have measurable duration
assert ctx["duration_seconds"] > 0
assert ctx["duration_seconds"] < 1.0 # Should be quick
@pytest.mark.asyncio
async def test_log_operation_initial_context(self):
"""Test log_operation with initial context."""
initial = {"request_id": "abc123", "user": "test_user"}
async with log_operation("test_operation", initial) as ctx:
pass
# Initial context should be preserved
assert ctx["request_id"] == "abc123"
assert ctx["user"] == "test_user"
assert ctx["operation"] == "test_operation"
class TestUvicornLogConfig:
"""Test uvicorn logging configuration."""
def test_get_uvicorn_log_config_returns_dict(self):
"""Test uvicorn config returns valid dict."""
config = get_uvicorn_log_config()
assert isinstance(config, dict)
assert "version" in config
assert "formatters" in config
assert "handlers" in config
assert "loggers" in config
def test_uvicorn_log_config_has_required_loggers(self):
"""Test config includes uvicorn loggers."""
config = get_uvicorn_log_config()
loggers = config["loggers"]
assert "uvicorn" in loggers
assert "uvicorn.error" in loggers
assert "uvicorn.access" in loggers
def test_uvicorn_log_config_format_selection(self):
"""Test config format changes based on environment."""
# Just test that the config is valid, format is determined by environment
config = get_uvicorn_log_config()
# Should have required structure
assert "version" in config
assert "formatters" in config
assert "handlers" in config
assert "loggers" in config
class TestLoggingIntegration:
"""Test logging integration with standard library."""
def test_standard_logging_works(self):
"""Test standard logging.getLogger works."""
logger = logging.getLogger("test.standard")
# Should not raise
logger.info("Test message")
def test_structlog_and_stdlib_coexist(self):
"""Test structlog and stdlib can coexist."""
struct_logger = get_logger("test.struct")
std_logger = logging.getLogger("test.std")
# Both should work
struct_logger.info("Structured log")
std_logger.info("Standard log")
@pytest.mark.asyncio
async def test_logging_in_async_context(self):
"""Test logging works in async context."""
logger = get_logger("test.async")
async def async_function():
logger.info("Async log message", task="async_task")
await async_function()
class TestLoggingOutput:
"""Test actual logging output."""
def test_logger_outputs_structured_data(self):
"""Test logger can output structured data."""
logger = get_logger("test.output")
# Log with structured data
logger.info(
"user_action",
user_id="123",
action="login",
success=True,
)
# Should not raise, output tested in integration tests
def test_logger_handles_exceptions(self):
"""Test logger handles exception logging."""
logger = get_logger("test.exceptions")
try:
raise ValueError("Test error")
except ValueError:
logger.exception("Error occurred", extra_field="value")
# Should not raise
def test_different_log_levels(self):
"""Test different log levels."""
logger = get_logger("test.levels")
logger.debug("Debug message", level="debug")
logger.info("Info message", level="info")
logger.warning("Warning message", level="warning")
logger.error("Error message", level="error")
# Should not raise
class TestLoggingConfiguration:
"""Test logging configuration behavior."""
def test_logging_respects_environment(self):
"""Test logging format changes with environment."""
from src.core.config import Environment, config
# In development, should use console format
if config.ENVIRONMENT == Environment.DEVELOPMENT:
assert config.log_format == "console"
# Mock production environment
with patch.object(config, "ENVIRONMENT", Environment.PRODUCTION):
assert config.log_format == "json"
def test_multiple_loggers_independent(self):
"""Test multiple loggers are independent."""
logger1 = get_logger("test.logger1")
logger2 = get_logger("test.logger2")
assert logger1 is not logger2
# Both should work independently
logger1.info("Logger 1 message")
logger2.info("Logger 2 message")