Simplenote MCP Server

"""Tests for logger factory and standardized logging schema.

This module tests the logger factory system that creates loggers with
standardized schemas and contextual fields for consistent logging.
"""

from simplenote_mcp.server.logger_factory import (
    LogCategory,
    LogContext,
    LoggerFactory,
    create_contextual_logger,
    get_auth_logger,
    get_cache_logger,
    get_error_logger,
    get_logger_factory,
    get_performance_logger,
    get_request_logger,
    get_security_logger,
    get_simplenote_logger,
    get_tool_logger,
    with_logging_context,
)
from simplenote_mcp.server.logging import StructuredLogAdapter


class TestLogCategory:
    """Test log category enumeration."""

    def test_all_categories_present(self):
        """Test that all expected categories are defined."""
        expected_categories = [
            "authentication",
            "authorization",
            "cache",
            "configuration",
            "database",
            "error_handling",
            "metrics",
            "network",
            "performance",
            "request",
            "response",
            "security",
            "server",
            "simplenote_api",
            "tool",
            "validation",
            "general",
        ]

        actual_categories = [cat.value for cat in LogCategory]

        for expected in expected_categories:
            assert expected in actual_categories

    def test_category_values(self):
        """Test specific category values."""
        assert LogCategory.AUTHENTICATION.value == "authentication"
        assert LogCategory.SECURITY.value == "security"
        assert LogCategory.PERFORMANCE.value == "performance"
        assert LogCategory.TOOL.value == "tool"


class TestLogContext:
    """Test log context functionality."""

    def test_basic_initialization(self):
        """Test basic context initialization."""
        context = LogContext(
            user_id="test_user",
            operation="test_operation",
            category=LogCategory.AUTHENTICATION,
        )

        assert context.user_id == "test_user"
        assert context.operation == "test_operation"
        assert context.category == LogCategory.AUTHENTICATION
        assert context.request_id is not None
        assert context.trace_id is not None
        assert context.timestamp is not None

    def test_auto_component_detection(self):
        """Test automatic component name detection."""
        context = LogContext()

        # Should detect component from calling module
        assert context.component is not None
        # In test context, might be 'test_logger_factory' or similar
        assert isinstance(context.component, str)

    def test_context_to_dict(self):
        """Test conversion of context to dictionary."""
        context = LogContext(
            user_id="test_user",
            session_id="test_session",
            operation="test_op",
            category=LogCategory.SECURITY,
            extra={"custom_field": "custom_value"},
        )

        context_dict = context.to_dict()

        assert context_dict["user_id"] == "test_user"
        assert context_dict["session_id"] == "test_session"
        assert context_dict["operation"] == "test_op"
        assert context_dict["category"] == "security"
        assert context_dict["custom_field"] == "custom_value"
        assert "request_id" in context_dict
        assert "trace_id" in context_dict
        assert "timestamp" in context_dict

    def test_context_with_operation(self):
        """Test creating new context with updated operation."""
        original = LogContext(user_id="test_user", operation="original_op")
        updated = original.with_operation("new_operation")

        assert original.operation == "original_op"
        assert updated.operation == "new_operation"
        assert updated.user_id == "test_user"
        assert updated.request_id == original.request_id

    def test_context_with_user(self):
        """Test creating new context with user information."""
        original = LogContext(operation="test_op")
        updated = original.with_user("new_user")

        assert original.user_id is None
        assert updated.user_id == "new_user"
        assert updated.operation == "test_op"

    def test_context_with_extra(self):
        """Test creating new context with additional fields."""
        original = LogContext(user_id="test_user")
        updated = original.with_extra(custom_field="custom_value", another_field=123)

        assert updated.user_id == "test_user"
        assert updated.extra["custom_field"] == "custom_value"
        assert updated.extra["another_field"] == 123
        assert len(original.extra) == 0  # Original unchanged

    def test_context_optional_fields(self):
        """Test that optional fields are handled correctly."""
        context = LogContext()
        context_dict = context.to_dict()

        # Optional fields should not be included if None
        assert "user_id" not in context_dict
        assert "session_id" not in context_dict
        assert "operation" not in context_dict

        # Required fields should always be present
        assert "request_id" in context_dict
        assert "trace_id" in context_dict
        assert "category" in context_dict
        assert "timestamp" in context_dict


class TestLoggerFactory:
    """Test logger factory functionality."""

    def test_factory_initialization(self):
        """Test factory initialization."""
        factory = LoggerFactory()
        assert factory._default_context is not None
        assert isinstance(factory._default_context, LogContext)

    def test_create_basic_logger(self):
        """Test creating a basic logger."""
        factory = LoggerFactory()
        logger = factory.create_logger("test")

        assert isinstance(logger, StructuredLogAdapter)
        assert logger.logger.name == "simplenote_mcp.test"

    def test_create_logger_with_context(self):
        """Test creating logger with context object."""
        factory = LoggerFactory()
        context = LogContext(
            user_id="test_user",
            operation="test_operation",
            category=LogCategory.AUTHENTICATION,
        )

        logger = factory.create_logger("auth", context)

        assert isinstance(logger, StructuredLogAdapter)
        assert logger.extra["user_id"] == "test_user"
        assert logger.extra["operation"] == "test_operation"
        assert logger.extra["category"] == "authentication"

    def test_create_logger_with_kwargs(self):
        """Test creating logger with keyword arguments."""
        factory = LoggerFactory()
        logger = factory.create_logger("test", user_id="test_user", operation="test_op")

        assert logger.extra["user_id"] == "test_user"
        assert logger.extra["operation"] == "test_op"

    def test_authentication_logger(self):
        """Test creating authentication logger."""
        factory = LoggerFactory()
        logger = factory.create_authentication_logger(
            user_id="auth_user", operation="login", client_ip="192.168.1.1"
        )

        assert logger.extra["user_id"] == "auth_user"
        assert logger.extra["operation"] == "login"
        assert logger.extra["category"] == "authentication"
        assert logger.extra["component"] == "auth"
        assert logger.extra["client_ip"] == "192.168.1.1"

    def test_request_logger(self):
        """Test creating request logger."""
        factory = LoggerFactory()
        logger = factory.create_request_logger(
            request_id="req_123", user_id="request_user", operation="create_note"
        )

        assert logger.extra["request_id"] == "req_123"
        assert logger.extra["user_id"] == "request_user"
        assert logger.extra["operation"] == "create_note"
        assert logger.extra["category"] == "request"
        assert logger.extra["component"] == "request_handler"

    def test_security_logger(self):
        """Test creating security logger."""
        factory = LoggerFactory()
        logger = factory.create_security_logger(
            user_id="security_user",
            operation="failed_login",
            threat_level="high",
            attack_type="brute_force",
        )

        assert logger.extra["user_id"] == "security_user"
        assert logger.extra["operation"] == "failed_login"
        assert logger.extra["category"] == "security"
        assert logger.extra["component"] == "security"
        assert logger.extra["threat_level"] == "high"
        assert logger.extra["attack_type"] == "brute_force"

    def test_performance_logger(self):
        """Test creating performance logger."""
        factory = LoggerFactory()
        logger = factory.create_performance_logger(
            operation="search_notes", duration=0.25, memory_usage=1024
        )

        assert logger.extra["operation"] == "search_notes"
        assert logger.extra["category"] == "performance"
        assert logger.extra["component"] == "metrics"
        assert logger.extra["duration_seconds"] == 0.25
        assert logger.extra["memory_usage"] == 1024

    def test_tool_logger(self):
        """Test creating tool logger."""
        factory = LoggerFactory()
        logger = factory.create_tool_logger(
            tool_name="create_note",
            user_id="tool_user",
            operation="execute",
            tool_version="1.0",
        )

        assert logger.extra["tool_name"] == "create_note"
        assert logger.extra["user_id"] == "tool_user"
        assert logger.extra["operation"] == "execute"
        assert logger.extra["category"] == "tool"
        assert logger.extra["component"] == "tool_handler"
        assert logger.extra["tool_version"] == "1.0"

    def test_simplenote_logger(self):
        """Test creating Simplenote API logger."""
        factory = LoggerFactory()
        logger = factory.create_simplenote_logger(
            operation="get_note", note_id="note_123", api_version="v2"
        )

        assert logger.extra["operation"] == "get_note"
        assert logger.extra["note_id"] == "note_123"
        assert logger.extra["category"] == "simplenote_api"
        assert logger.extra["component"] == "simplenote_client"
        assert logger.extra["api_version"] == "v2"

    def test_cache_logger(self):
        """Test creating cache logger."""
        factory = LoggerFactory()
        logger = factory.create_cache_logger(
            operation="cache_hit",
            cache_key="notes:user_123",
            hit_rate=0.85,
            cache_size=1000,
        )

        assert logger.extra["operation"] == "cache_hit"
        assert logger.extra["cache_key"] == "notes:user_123"
        assert logger.extra["category"] == "cache"
        assert logger.extra["component"] == "cache"
        assert logger.extra["hit_rate"] == 0.85
        assert logger.extra["cache_size"] == 1000

    def test_error_logger(self):
        """Test creating error logger."""
        factory = LoggerFactory()
        logger = factory.create_error_logger(
            error_type="ValidationError",
            error_code="VAL_001",
            user_id="error_user",
            operation="validate_input",
            stack_trace="line 1\nline 2",
        )

        assert logger.extra["error_type"] == "ValidationError"
        assert logger.extra["error_code"] == "VAL_001"
        assert logger.extra["user_id"] == "error_user"
        assert logger.extra["operation"] == "validate_input"
        assert logger.extra["category"] == "error_handling"
        assert logger.extra["component"] == "error_handler"
        assert logger.extra["stack_trace"] == "line 1\nline 2"

    def test_set_get_default_context(self):
        """Test setting and getting default context."""
        factory = LoggerFactory()
        default_context = LogContext(user_id="default_user", operation="default_op")

        factory.set_default_context(default_context)
        retrieved_context = factory.get_default_context()

        assert retrieved_context == default_context
        assert retrieved_context.user_id == "default_user"
        assert retrieved_context.operation == "default_op"


class TestGlobalFactoryFunctions:
    """Test global factory convenience functions."""

    def test_get_logger_factory_singleton(self):
        """Test that get_logger_factory returns singleton."""
        factory1 = get_logger_factory()
        factory2 = get_logger_factory()

        assert factory1 is factory2
        assert isinstance(factory1, LoggerFactory)

    def test_get_auth_logger(self):
        """Test convenience auth logger function."""
        logger = get_auth_logger(user_id="auth_test", operation="logout")

        assert isinstance(logger, StructuredLogAdapter)
        assert logger.extra["user_id"] == "auth_test"
        assert logger.extra["operation"] == "logout"
        assert logger.extra["category"] == "authentication"

    def test_get_request_logger(self):
        """Test convenience request logger function."""
        logger = get_request_logger(user_id="req_test", operation="search")

        assert isinstance(logger, StructuredLogAdapter)
        assert logger.extra["user_id"] == "req_test"
        assert logger.extra["operation"] == "search"
        assert logger.extra["category"] == "request"

    def test_get_security_logger(self):
        """Test convenience security logger function."""
        logger = get_security_logger(
            user_id="sec_test", operation="block_request", threat_level="critical"
        )

        assert isinstance(logger, StructuredLogAdapter)
        assert logger.extra["user_id"] == "sec_test"
        assert logger.extra["threat_level"] == "critical"
        assert logger.extra["category"] == "security"

    def test_get_performance_logger(self):
        """Test convenience performance logger function."""
        logger = get_performance_logger(operation="query", duration=1.5)

        assert isinstance(logger, StructuredLogAdapter)
        assert logger.extra["operation"] == "query"
        assert logger.extra["duration_seconds"] == 1.5
        assert logger.extra["category"] == "performance"

    def test_get_tool_logger(self):
        """Test convenience tool logger function."""
        logger = get_tool_logger("search_notes", user_id="tool_test")

        assert isinstance(logger, StructuredLogAdapter)
        assert logger.extra["tool_name"] == "search_notes"
        assert logger.extra["user_id"] == "tool_test"
        assert logger.extra["category"] == "tool"

    def test_get_simplenote_logger(self):
        """Test convenience Simplenote logger function."""
        logger = get_simplenote_logger(operation="sync", note_id="note_456")

        assert isinstance(logger, StructuredLogAdapter)
        assert logger.extra["operation"] == "sync"
        assert logger.extra["note_id"] == "note_456"
        assert logger.extra["category"] == "simplenote_api"

    def test_get_cache_logger(self):
        """Test convenience cache logger function."""
        logger = get_cache_logger(operation="evict", cache_key="expired_key")

        assert isinstance(logger, StructuredLogAdapter)
        assert logger.extra["operation"] == "evict"
        assert logger.extra["cache_key"] == "expired_key"
        assert logger.extra["category"] == "cache"

    def test_get_error_logger(self):
        """Test convenience error logger function."""
        logger = get_error_logger(
            error_type="NetworkError", error_code="NET_001", operation="api_call"
        )

        assert isinstance(logger, StructuredLogAdapter)
        assert logger.extra["error_type"] == "NetworkError"
        assert logger.extra["error_code"] == "NET_001"
        assert logger.extra["operation"] == "api_call"
        assert logger.extra["category"] == "error_handling"


class TestContextualLogging:
    """Test contextual logging functionality."""

    def test_create_contextual_logger_with_context_object(self):
        """Test creating contextual logger with LogContext object."""
        context = LogContext(
            user_id="contextual_user",
            operation="contextual_op",
            category=LogCategory.VALIDATION,
        )

        logger = create_contextual_logger("contextual", context)

        assert isinstance(logger, StructuredLogAdapter)
        assert logger.extra["user_id"] == "contextual_user"
        assert logger.extra["operation"] == "contextual_op"
        assert logger.extra["category"] == "validation"

    def test_create_contextual_logger_with_dict(self):
        """Test creating contextual logger with dictionary context."""
        context_dict = {
            "user_id": "dict_user",
            "operation": "dict_op",
            "category": LogCategory.NETWORK,
        }

        logger = create_contextual_logger("contextual", context_dict)

        assert isinstance(logger, StructuredLogAdapter)
        assert logger.extra["user_id"] == "dict_user"
        assert logger.extra["operation"] == "dict_op"
        assert logger.extra["category"] == "network"

    def test_create_contextual_logger_with_extra_kwargs(self):
        """Test creating contextual logger with extra keyword arguments."""
        context = LogContext(user_id="base_user")

        logger = create_contextual_logger(
            "contextual", context, extra_field="extra_value", another_field=42
        )

        assert logger.extra["user_id"] == "base_user"
        assert logger.extra["extra_field"] == "extra_value"
        assert logger.extra["another_field"] == 42

    def test_with_logging_context_decorator(self):
        """Test logging context decorator."""

        @with_logging_context(category=LogCategory.TOOL, operation="decorated_function")
        def test_function(x, y, logger=None):
            assert logger is not None
            assert isinstance(logger, StructuredLogAdapter)
            assert logger.extra["category"] == "tool"
            assert logger.extra["operation"] == "decorated_function"
            return x + y

        result = test_function(2, 3)
        assert result == 5

    def test_with_logging_context_decorator_custom_logger(self):
        """Test logging context decorator with custom logger."""
        custom_logger = get_auth_logger(user_id="custom_user")

        @with_logging_context(category=LogCategory.AUTHENTICATION)
        def test_function(logger=custom_logger):
            # Should use provided logger, not create new one
            assert logger == custom_logger
            return "success"

        result = test_function()
        assert result == "success"


class TestLogSchemaConsistency:
    """Test logging schema consistency across different logger types."""

    def test_all_loggers_have_required_fields(self):
        """Test that all logger types include required fields."""
        factory = get_logger_factory()

        # Test all logger creation methods
        loggers = [
            factory.create_authentication_logger(user_id="test"),
            factory.create_request_logger(user_id="test"),
            factory.create_security_logger(user_id="test"),
            factory.create_performance_logger(operation="test"),
            factory.create_tool_logger("test_tool"),
            factory.create_simplenote_logger(operation="test"),
            factory.create_cache_logger(operation="test"),
            factory.create_error_logger(error_type="TestError"),
        ]

        required_fields = ["request_id", "trace_id", "category", "timestamp"]

        for logger in loggers:
            for field in required_fields:
                assert field in logger.extra, (
                    f"Missing {field} in {type(logger)} logger"
                )

    def test_category_consistency(self):
        """Test that each logger type has correct category."""
        factory = get_logger_factory()

        logger_categories = [
            (factory.create_authentication_logger(), "authentication"),
            (factory.create_request_logger(), "request"),
            (factory.create_security_logger(), "security"),
            (factory.create_performance_logger(), "performance"),
            (factory.create_tool_logger("test"), "tool"),
            (factory.create_simplenote_logger(), "simplenote_api"),
            (factory.create_cache_logger(), "cache"),
            (factory.create_error_logger(), "error_handling"),
        ]

        for logger, expected_category in logger_categories:
            assert logger.extra["category"] == expected_category

    def test_component_consistency(self):
        """Test that each logger type has expected component."""
        factory = get_logger_factory()

        logger_components = [
            (factory.create_authentication_logger(), "auth"),
            (factory.create_request_logger(), "request_handler"),
            (factory.create_security_logger(), "security"),
            (factory.create_performance_logger(), "metrics"),
            (factory.create_tool_logger("test"), "tool_handler"),
            (factory.create_simplenote_logger(), "simplenote_client"),
            (factory.create_cache_logger(), "cache"),
            (factory.create_error_logger(), "error_handler"),
        ]

        for logger, expected_component in logger_components:
            assert logger.extra["component"] == expected_component

    def test_trace_id_consistency(self):
        """Test that trace IDs are properly propagated."""
        context = LogContext(trace_id="test_trace_123")
        factory = get_logger_factory()

        logger = factory.create_logger("test", context)
        assert logger.extra["trace_id"] == "test_trace_123"

        # Create derived logger with same context
        derived_logger = factory.create_authentication_logger(
            user_id="test", **context.to_dict()
        )

        # Should have same trace ID
        assert derived_logger.extra["trace_id"] == "test_trace_123"

    def test_timestamp_format(self):
        """Test that timestamps are in consistent format."""
        import re

        context = LogContext()
        # ISO 8601 format pattern
        iso_pattern = r"^\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}(\.\d+)?$"

        assert re.match(iso_pattern, context.timestamp)

        factory = get_logger_factory()
        logger = factory.create_logger("test", context)

        assert re.match(iso_pattern, logger.extra["timestamp"])