"""Tests for logging timing utilities."""

from __future__ import annotations

import asyncio
from typing import TYPE_CHECKING
from unittest.mock import MagicMock, patch

import pytest

from noteflow.infrastructure.logging.timing import log_timing, timed

if TYPE_CHECKING:
    from collections.abc import Generator


# Constants for test assertions
OPERATION_NAME = "test_operation"
EXPECTED_START_EVENT = f"{OPERATION_NAME}_started"
EXPECTED_COMPLETE_EVENT = f"{OPERATION_NAME}_completed"
EXPECTED_TIMEOUT_EVENT = f"{OPERATION_NAME}_timeout"
EXPECTED_FAILED_EVENT = f"{OPERATION_NAME}_failed"


@pytest.fixture
def mock_timing_logger() -> Generator[MagicMock, None, None]:
    """Provide mock logger for timing module tests."""
    with patch("noteflow.infrastructure.logging.timing.get_logger") as mock_get:
        mock_log = MagicMock()
        mock_get.return_value = mock_log
        yield mock_log


class TestLogTiming:
    """Test log_timing context manager."""

    def test_logs_start_and_complete_on_success(self, mock_timing_logger: MagicMock) -> None:
        """Verify start and complete events logged on successful operation."""
        with log_timing(OPERATION_NAME):
            pass

        assert mock_timing_logger.info.call_count == 2
        start_call = mock_timing_logger.info.call_args_list[0]
        assert start_call[0][0] == EXPECTED_START_EVENT

        complete_call = mock_timing_logger.info.call_args_list[1]
        assert complete_call[0][0] == EXPECTED_COMPLETE_EVENT
        assert "duration_ms" in complete_call[1]

    def test_includes_context_in_logs(self, mock_timing_logger: MagicMock) -> None:
        """Verify context kwargs passed to log events."""
        with log_timing(OPERATION_NAME, host="localhost", port=8080):
            pass

        start_call = mock_timing_logger.info.call_args_list[0]
        assert start_call[1]["host"] == "localhost"
        assert start_call[1]["port"] == 8080

        complete_call = mock_timing_logger.info.call_args_list[1]
        assert complete_call[1]["host"] == "localhost"
        assert complete_call[1]["port"] == 8080

    def test_filters_none_context_values(self, mock_timing_logger: MagicMock) -> None:
        """Verify None context values are filtered out."""
        with log_timing(OPERATION_NAME, host="localhost", optional=None):
            pass

        start_call = mock_timing_logger.info.call_args_list[0]
        assert start_call[1]["host"] == "localhost"
        assert "optional" not in start_call[1]

    def test_logs_warning_on_timeout(self, mock_timing_logger: MagicMock) -> None:
        """Verify timeout logged as warning with duration."""
        with pytest.raises(TimeoutError), log_timing(OPERATION_NAME):
            raise TimeoutError("Connection timed out")

        mock_timing_logger.info.assert_called_once()
        assert mock_timing_logger.info.call_args[0][0] == EXPECTED_START_EVENT

        mock_timing_logger.warning.assert_called_once()
        timeout_call = mock_timing_logger.warning.call_args
        assert timeout_call[0][0] == EXPECTED_TIMEOUT_EVENT
        assert "duration_ms" in timeout_call[1]

    def test_logs_error_on_exception(self, mock_timing_logger: MagicMock) -> None:
        """Verify general exception logged as error with details."""
        with pytest.raises(ValueError, match="test error"), log_timing(OPERATION_NAME):
            raise ValueError("test error")

        mock_timing_logger.error.assert_called_once()
        error_call = mock_timing_logger.error.call_args
        assert error_call[0][0] == EXPECTED_FAILED_EVENT
        assert "duration_ms" in error_call[1]
        assert error_call[1]["error"] == "test error"
        assert error_call[1]["error_type"] == "ValueError"

    def test_duration_is_positive(self, mock_timing_logger: MagicMock) -> None:
        """Verify duration_ms is a positive number."""
        with log_timing(OPERATION_NAME):
            pass

        complete_call = mock_timing_logger.info.call_args_list[1]
        duration = complete_call[1]["duration_ms"]
        assert isinstance(duration, float)
        assert duration >= 0


class TestTimedDecorator:
    """Test @timed decorator for sync and async functions."""

    def test_decorates_sync_function(self, mock_timing_logger: MagicMock) -> None:
        """Verify sync function wrapped with timing."""

        @timed(OPERATION_NAME)
        def sync_func(x: int) -> int:
            return x * 2

        result = sync_func(5)

        assert result == 10
        assert mock_timing_logger.info.call_count == 2
        assert mock_timing_logger.info.call_args_list[0][0][0] == EXPECTED_START_EVENT
        assert mock_timing_logger.info.call_args_list[1][0][0] == EXPECTED_COMPLETE_EVENT

    def test_decorates_async_function(self, mock_timing_logger: MagicMock) -> None:
        """Verify async function wrapped with timing."""

        @timed(OPERATION_NAME)
        async def async_func(x: int) -> int:
            await asyncio.sleep(0.001)
            return x * 2

        result = asyncio.run(async_func(5))

        assert result == 10
        assert mock_timing_logger.info.call_count == 2
        assert mock_timing_logger.info.call_args_list[0][0][0] == EXPECTED_START_EVENT
        assert mock_timing_logger.info.call_args_list[1][0][0] == EXPECTED_COMPLETE_EVENT

    def test_sync_function_logs_error_on_exception(self, mock_timing_logger: MagicMock) -> None:
        """Verify sync function exception logged as error."""

        @timed(OPERATION_NAME)
        def failing_func() -> None:
            raise RuntimeError("sync failure")

        with pytest.raises(RuntimeError, match="sync failure"):
            failing_func()

        mock_timing_logger.error.assert_called_once()
        error_call = mock_timing_logger.error.call_args
        assert error_call[0][0] == EXPECTED_FAILED_EVENT
        assert error_call[1]["error_type"] == "RuntimeError"

    def test_async_function_logs_error_on_exception(self, mock_timing_logger: MagicMock) -> None:
        """Verify async function exception logged as error."""

        @timed(OPERATION_NAME)
        async def failing_async() -> None:
            raise RuntimeError("async failure")

        with pytest.raises(RuntimeError, match="async failure"):
            asyncio.run(failing_async())

        mock_timing_logger.error.assert_called_once()
        error_call = mock_timing_logger.error.call_args
        assert error_call[0][0] == EXPECTED_FAILED_EVENT
        assert error_call[1]["error_type"] == "RuntimeError"

    def test_async_function_logs_warning_on_timeout(self, mock_timing_logger: MagicMock) -> None:
        """Verify async function timeout logged as warning."""

        @timed(OPERATION_NAME)
        async def timeout_async() -> None:
            raise TimeoutError("connection timeout")

        with pytest.raises(TimeoutError, match="connection timeout"):
            asyncio.run(timeout_async())

        mock_timing_logger.warning.assert_called_once()
        warning_call = mock_timing_logger.warning.call_args
        assert warning_call[0][0] == EXPECTED_TIMEOUT_EVENT

    def test_preserves_function_metadata(self) -> None:
        """Verify decorated function preserves name and docstring."""

        @timed(OPERATION_NAME)
        def documented_func() -> None:
            """Function docstring."""

        assert documented_func.__name__ == "documented_func"
        assert documented_func.__doc__ == "Function docstring."

    def test_preserves_async_function_metadata(self) -> None:
        """Verify decorated async function preserves name and docstring."""

        @timed(OPERATION_NAME)
        async def async_documented() -> None:
            """Async function docstring."""

        assert async_documented.__name__ == "async_documented"
        assert async_documented.__doc__ == "Async function docstring."
