"""
Extended tests for utilities/log_utils.py logging utilities.

Tests cover:
- _get_research_id extraction from record extra, Flask g, and fallback to None
- database_sink queuing behavior for background threads and missing app context
- frontend_progress_sink skipping when no research_id and emitting when present
- flush_log_queue processing all queued entries
- config_logger enabling/disabling file logging based on LDR_ENABLE_FILE_LOGGING
"""

import os
import queue
import threading
from datetime import datetime
from unittest.mock import Mock, patch


class TestGetResearchIdExtended:
    """Extended tests for _get_research_id function."""

    def test_returns_none_when_no_record_and_no_app_context(self):
        """Should return None when record is None and no Flask app context."""
        from local_deep_research.utilities.log_utils import _get_research_id
        import local_deep_research.utilities.log_utils as module

        with patch.object(module, "has_app_context", return_value=False):
            result = _get_research_id(record=None)

        assert result is None

    def test_extracts_from_record_extra_research_id(self):
        """Should extract research_id from record['extra']['research_id']."""
        from local_deep_research.utilities.log_utils import _get_research_id

        record = {
            "extra": {"research_id": "abc-123-def"},
        }

        # Should not even need Flask context since record has the id
        with patch(
            "local_deep_research.utilities.log_utils.has_app_context",
            return_value=False,
        ):
            result = _get_research_id(record=record)

        assert result == "abc-123-def"

    def test_extracts_from_flask_g_when_no_record(self):
        """Should extract research_id from Flask g.research_id when no record."""
        from local_deep_research.utilities.log_utils import _get_research_id
        import local_deep_research.utilities.log_utils as module

        mock_g = Mock()
        mock_g.get.return_value = "flask-uuid-456"

        with patch.object(module, "has_app_context", return_value=True):
            with patch.object(module, "g", mock_g):
                result = _get_research_id(record=None)

        assert result == "flask-uuid-456"
        mock_g.get.assert_called_with("research_id")

    def test_extracts_from_flask_g_when_record_has_no_research_id(self):
        """Should fall back to Flask g when record exists but has no research_id in extra."""
        from local_deep_research.utilities.log_utils import _get_research_id
        import local_deep_research.utilities.log_utils as module

        record = {
            "extra": {"some_other_key": "value"},
        }

        mock_g = Mock()
        mock_g.get.return_value = "g-uuid-789"

        with patch.object(module, "has_app_context", return_value=True):
            with patch.object(module, "g", mock_g):
                result = _get_research_id(record=record)

        assert result == "g-uuid-789"

    def test_record_extra_takes_priority_over_flask_g(self):
        """Record extra research_id should be preferred over Flask g."""
        from local_deep_research.utilities.log_utils import _get_research_id
        import local_deep_research.utilities.log_utils as module

        record = {
            "extra": {"research_id": "record-id"},
        }

        mock_g = Mock()
        mock_g.get.return_value = "flask-id"

        with patch.object(module, "has_app_context", return_value=True):
            with patch.object(module, "g", mock_g):
                result = _get_research_id(record=record)

        # Record should take priority
        assert result == "record-id"
        # g.get should NOT have been called since record matched first
        mock_g.get.assert_not_called()

    def test_returns_none_when_record_has_empty_extra(self):
        """Should return None when record has empty extra and no app context."""
        from local_deep_research.utilities.log_utils import _get_research_id
        import local_deep_research.utilities.log_utils as module

        record = {"extra": {}}

        with patch.object(module, "has_app_context", return_value=False):
            result = _get_research_id(record=record)

        assert result is None

    def test_returns_none_when_record_has_no_extra_key(self):
        """Should return None when record dict does not contain 'extra'."""
        from local_deep_research.utilities.log_utils import _get_research_id
        import local_deep_research.utilities.log_utils as module

        record = {"message": "test"}

        with patch.object(module, "has_app_context", return_value=False):
            result = _get_research_id(record=record)

        assert result is None


def _make_mock_message(
    message="Test message",
    module_name="test_module",
    function_name="test_func",
    line=42,
    level_name="INFO",
    extra=None,
    time=None,
):
    """Helper to create a mock loguru Message with realistic record structure."""
    if extra is None:
        extra = {}
    if time is None:
        time = datetime.now()

    mock_level = Mock()
    mock_level.name = level_name

    mock_time = Mock()
    mock_time.isoformat.return_value = (
        time.isoformat() if isinstance(time, datetime) else str(time)
    )

    mock_msg = Mock()
    mock_msg.record = {
        "time": mock_time if not isinstance(time, datetime) else time,
        "message": message,
        "name": module_name,
        "function": function_name,
        "line": line,
        "level": mock_level,
        "extra": extra,
    }
    return mock_msg


class TestDatabaseSinkExtended:
    """Extended tests for database_sink queuing behavior."""

    def test_queues_log_when_not_in_main_thread(self):
        """Should queue the log entry when running in a background thread."""
        from local_deep_research.utilities.log_utils import database_sink
        import local_deep_research.utilities.log_utils as module

        mock_message = _make_mock_message(
            extra={"research_id": "bg-uuid", "username": "alice"}
        )

        mock_thread = Mock()
        mock_thread.name = "WorkerThread-1"

        with patch.object(module, "has_app_context", return_value=True):
            with patch.object(
                threading, "current_thread", return_value=mock_thread
            ):
                with patch.object(module, "_log_queue") as mock_queue:
                    database_sink(mock_message)

                    mock_queue.put_nowait.assert_called_once()
                    queued_entry = mock_queue.put_nowait.call_args[0][0]
                    assert queued_entry["message"] == "Test message"
                    assert queued_entry["research_id"] == "bg-uuid"
                    assert queued_entry["username"] == "alice"

    def test_queues_log_when_no_app_context(self):
        """Should queue the log entry when not in Flask app context."""
        from local_deep_research.utilities.log_utils import database_sink
        import local_deep_research.utilities.log_utils as module

        mock_message = _make_mock_message(extra={"research_id": "rid-1"})

        with patch.object(module, "has_app_context", return_value=False):
            with patch.object(module, "_log_queue") as mock_queue:
                database_sink(mock_message)

                mock_queue.put_nowait.assert_called_once()

    def test_writes_directly_in_main_thread_with_app_context(self):
        """Should write directly to database when in main thread with app context."""
        from local_deep_research.utilities.log_utils import database_sink
        import local_deep_research.utilities.log_utils as module

        mock_message = _make_mock_message(
            extra={"research_id": "direct-uuid", "username": "bob"}
        )

        mock_thread = Mock()
        mock_thread.name = "MainThread"

        with patch.object(module, "has_app_context", return_value=True):
            with patch.object(
                threading, "current_thread", return_value=mock_thread
            ):
                with patch.object(
                    module, "_write_log_to_database"
                ) as mock_write:
                    database_sink(mock_message)

                    mock_write.assert_called_once()
                    log_entry = mock_write.call_args[0][0]
                    assert log_entry["message"] == "Test message"
                    assert log_entry["research_id"] == "direct-uuid"

    def test_drops_log_when_queue_is_full(self):
        """Should silently drop the log when the queue is full."""
        from local_deep_research.utilities.log_utils import database_sink
        import local_deep_research.utilities.log_utils as module

        mock_message = _make_mock_message()

        with patch.object(module, "has_app_context", return_value=False):
            with patch.object(module, "_log_queue") as mock_queue:
                mock_queue.put_nowait.side_effect = queue.Full()

                # Should not raise
                database_sink(mock_message)

    def test_log_entry_contains_all_required_fields(self):
        """The queued log entry dict should contain all expected fields."""
        from local_deep_research.utilities.log_utils import database_sink
        import local_deep_research.utilities.log_utils as module

        mock_message = _make_mock_message(
            message="detailed log",
            module_name="my_module",
            function_name="my_func",
            line=99,
            level_name="WARNING",
            extra={"username": "charlie"},
        )

        with patch.object(module, "has_app_context", return_value=False):
            with patch.object(module, "_log_queue") as mock_queue:
                database_sink(mock_message)

                queued_entry = mock_queue.put_nowait.call_args[0][0]
                assert queued_entry["message"] == "detailed log"
                assert queued_entry["module"] == "my_module"
                assert queued_entry["function"] == "my_func"
                assert queued_entry["line_no"] == 99
                assert queued_entry["level"] == "WARNING"
                assert queued_entry["username"] == "charlie"
                assert "timestamp" in queued_entry
                assert "research_id" in queued_entry


class TestFrontendProgressSinkExtended:
    """Extended tests for frontend_progress_sink."""

    def test_does_nothing_when_no_research_id(self):
        """Should return early without emitting when no research_id."""
        from local_deep_research.utilities.log_utils import (
            frontend_progress_sink,
        )
        import local_deep_research.utilities.log_utils as module

        mock_message = _make_mock_message(extra={})

        with patch.object(module, "_get_research_id", return_value=None):
            with patch.object(module, "SocketIOService") as mock_socket_cls:
                frontend_progress_sink(mock_message)

                mock_socket_cls.return_value.emit_to_subscribers.assert_not_called()

    def test_emits_to_subscribers_when_research_id_present(self):
        """Should call emit_to_subscribers with correct args when research_id exists."""
        from local_deep_research.utilities.log_utils import (
            frontend_progress_sink,
        )
        import local_deep_research.utilities.log_utils as module

        mock_time = Mock()
        mock_time.isoformat.return_value = "2026-02-25T10:00:00"

        mock_level = Mock()
        mock_level.name = "INFO"

        mock_message = Mock()
        mock_message.record = {
            "message": "Step 3 of 5",
            "level": mock_level,
            "time": mock_time,
            "extra": {"research_id": "emit-uuid"},
        }

        with patch.object(module, "_get_research_id", return_value="emit-uuid"):
            with patch.object(module, "SocketIOService") as mock_socket_cls:
                mock_instance = Mock()
                mock_socket_cls.return_value = mock_instance

                frontend_progress_sink(mock_message)

                mock_instance.emit_to_subscribers.assert_called_once()
                args = mock_instance.emit_to_subscribers.call_args
                assert args[0][0] == "progress"
                assert args[0][1] == "emit-uuid"
                # Check the data structure
                data = args[0][2]
                assert "log_entry" in data
                assert data["log_entry"]["message"] == "Step 3 of 5"
                assert data["log_entry"]["type"] == "INFO"
                assert data["log_entry"]["time"] == "2026-02-25T10:00:00"
                # enable_logging should be False
                assert args[1]["enable_logging"] is False

    def test_emits_with_logging_disabled(self):
        """Should pass enable_logging=False to avoid deadlocks."""
        from local_deep_research.utilities.log_utils import (
            frontend_progress_sink,
        )
        import local_deep_research.utilities.log_utils as module

        mock_time = Mock()
        mock_time.isoformat.return_value = "2026-01-01T00:00:00"

        mock_level = Mock()
        mock_level.name = "DEBUG"

        mock_message = Mock()
        mock_message.record = {
            "message": "test",
            "level": mock_level,
            "time": mock_time,
            "extra": {},
        }

        with patch.object(module, "_get_research_id", return_value="some-id"):
            with patch.object(module, "SocketIOService") as mock_socket_cls:
                mock_instance = Mock()
                mock_socket_cls.return_value = mock_instance

                frontend_progress_sink(mock_message)

                call_kwargs = mock_instance.emit_to_subscribers.call_args[1]
                assert call_kwargs["enable_logging"] is False


class TestFlushLogQueueExtended:
    """Extended tests for flush_log_queue."""

    def test_processes_all_queued_entries(self):
        """Should process every entry from the queue until empty."""
        from local_deep_research.utilities.log_utils import flush_log_queue
        import local_deep_research.utilities.log_utils as module

        entries = [
            {
                "timestamp": datetime.now(),
                "message": f"Log {i}",
                "module": "mod",
                "function": "f",
                "line_no": i,
                "level": "INFO",
                "research_id": None,
                "username": "user1",
            }
            for i in range(3)
        ]

        with patch.object(module, "_log_queue") as mock_queue:
            mock_queue.empty.side_effect = [False, False, False, True]
            mock_queue.get_nowait.side_effect = entries

            with patch.object(module, "_write_log_to_database") as mock_write:
                flush_log_queue()

                assert mock_write.call_count == 3
                # Verify each entry was passed
                for i, call_obj in enumerate(mock_write.call_args_list):
                    assert call_obj[0][0]["message"] == f"Log {i}"

    def test_handles_empty_queue(self):
        """Should do nothing when queue is already empty."""
        from local_deep_research.utilities.log_utils import flush_log_queue
        import local_deep_research.utilities.log_utils as module

        with patch.object(module, "_log_queue") as mock_queue:
            mock_queue.empty.return_value = True

            with patch.object(module, "_write_log_to_database") as mock_write:
                flush_log_queue()

                mock_write.assert_not_called()

    def test_handles_queue_empty_exception_during_get(self):
        """Should handle queue.Empty raised during get_nowait gracefully."""
        from local_deep_research.utilities.log_utils import flush_log_queue
        import local_deep_research.utilities.log_utils as module

        with patch.object(module, "_log_queue") as mock_queue:
            mock_queue.empty.side_effect = [False, True]
            mock_queue.get_nowait.side_effect = queue.Empty()

            # Should not raise
            flush_log_queue()

    def test_handles_write_exception_and_continues(self):
        """Should catch exceptions from _write_log_to_database and continue."""
        from local_deep_research.utilities.log_utils import flush_log_queue
        import local_deep_research.utilities.log_utils as module

        entries = [
            {
                "timestamp": datetime.now(),
                "message": "will fail",
                "module": "m",
                "function": "f",
                "line_no": 1,
                "level": "INFO",
                "research_id": None,
                "username": None,
            },
            {
                "timestamp": datetime.now(),
                "message": "will succeed",
                "module": "m",
                "function": "f",
                "line_no": 2,
                "level": "INFO",
                "research_id": None,
                "username": None,
            },
        ]

        with patch.object(module, "_log_queue") as mock_queue:
            mock_queue.empty.side_effect = [False, False, True]
            mock_queue.get_nowait.side_effect = entries

            with patch.object(module, "_write_log_to_database") as mock_write:
                # First call raises, second succeeds
                mock_write.side_effect = [Exception("DB error"), None]

                # Should not raise
                flush_log_queue()

                assert mock_write.call_count == 2

    def test_logs_flush_count_when_entries_flushed(self):
        """Should log debug message with flushed count when entries are processed."""
        from local_deep_research.utilities.log_utils import flush_log_queue
        import local_deep_research.utilities.log_utils as module

        entry = {
            "timestamp": datetime.now(),
            "message": "log",
            "module": "m",
            "function": "f",
            "line_no": 1,
            "level": "INFO",
            "research_id": None,
            "username": None,
        }

        with patch.object(module, "_log_queue") as mock_queue:
            mock_queue.empty.side_effect = [False, True]
            mock_queue.get_nowait.return_value = entry

            with patch.object(module, "_write_log_to_database"):
                with patch.object(module, "logger") as mock_logger:
                    flush_log_queue()

                    mock_logger.debug.assert_called_once()
                    assert "1" in mock_logger.debug.call_args[0][0]


class TestConfigLoggerExtended:
    """Extended tests for config_logger file logging behavior."""

    def test_enables_file_logging_when_env_var_true(self):
        """Should add a file handler when LDR_ENABLE_FILE_LOGGING=true."""
        from local_deep_research.utilities.log_utils import config_logger
        import local_deep_research.utilities.log_utils as module

        with patch.dict(os.environ, {"LDR_ENABLE_FILE_LOGGING": "true"}):
            with patch.object(module, "logger") as mock_logger:
                config_logger("test_app")

                # Should have 4 add calls: stderr, database, frontend, file
                assert mock_logger.add.call_count == 4

                # The file handler should be the last one added
                file_add_call = mock_logger.add.call_args_list[3]
                # First arg should be a Path object (the log file path)
                log_file_path = file_add_call[0][0]
                assert "test_app.log" in str(log_file_path)

    def test_does_not_add_file_handler_by_default(self):
        """Should NOT add file handler when LDR_ENABLE_FILE_LOGGING is not set."""
        from local_deep_research.utilities.log_utils import config_logger
        import local_deep_research.utilities.log_utils as module

        with patch.dict(
            os.environ, {"LDR_ENABLE_FILE_LOGGING": ""}, clear=False
        ):
            with patch.object(module, "logger") as mock_logger:
                config_logger("test_app")

                # Should have exactly 3 add calls: stderr, database, frontend
                assert mock_logger.add.call_count == 3

    def test_does_not_add_file_handler_when_env_var_false(self):
        """Should NOT add file handler when LDR_ENABLE_FILE_LOGGING=false."""
        from local_deep_research.utilities.log_utils import config_logger
        import local_deep_research.utilities.log_utils as module

        with patch.dict(os.environ, {"LDR_ENABLE_FILE_LOGGING": "false"}):
            with patch.object(module, "logger") as mock_logger:
                config_logger("test_app")

                assert mock_logger.add.call_count == 3

    def test_enables_file_logging_case_insensitive(self):
        """LDR_ENABLE_FILE_LOGGING should be case-insensitive (TRUE, True, etc)."""
        from local_deep_research.utilities.log_utils import config_logger
        import local_deep_research.utilities.log_utils as module

        with patch.dict(os.environ, {"LDR_ENABLE_FILE_LOGGING": "TRUE"}):
            with patch.object(module, "logger") as mock_logger:
                config_logger("test_app")

                # Should add 4 sinks including file
                assert mock_logger.add.call_count == 4

    def test_debug_mode_sets_diagnose_true(self):
        """When debug=True, all sinks should have diagnose=True."""
        from local_deep_research.utilities.log_utils import config_logger
        import local_deep_research.utilities.log_utils as module

        with patch.dict(os.environ, {"LDR_ENABLE_FILE_LOGGING": ""}):
            with patch.object(module, "logger") as mock_logger:
                config_logger("test_app", debug=True)

                # Check that all three add calls used diagnose=True
                for add_call in mock_logger.add.call_args_list:
                    assert add_call[1].get("diagnose") is True

    def test_non_debug_mode_sets_diagnose_false(self):
        """When debug=False (default), all sinks should have diagnose=False."""
        from local_deep_research.utilities.log_utils import config_logger
        import local_deep_research.utilities.log_utils as module

        with patch.dict(os.environ, {"LDR_ENABLE_FILE_LOGGING": ""}):
            with patch.object(module, "logger") as mock_logger:
                config_logger("test_app", debug=False)

                for add_call in mock_logger.add.call_args_list:
                    assert add_call[1].get("diagnose") is False

    def test_creates_milestone_level(self):
        """Should create MILESTONE log level with level no=26."""
        from local_deep_research.utilities.log_utils import config_logger
        import local_deep_research.utilities.log_utils as module

        with patch.object(module, "logger") as mock_logger:
            config_logger("test_app")

            mock_logger.level.assert_called_with(
                "MILESTONE", no=26, color="<magenta><bold>"
            )

    def test_handles_existing_milestone_level(self):
        """Should not raise when MILESTONE level already exists."""
        from local_deep_research.utilities.log_utils import config_logger
        import local_deep_research.utilities.log_utils as module

        with patch.object(module, "logger") as mock_logger:
            mock_logger.level.side_effect = ValueError(
                "Level MILESTONE already exists"
            )

            # Should not raise
            config_logger("test_app")

    def test_removes_existing_handlers_before_adding(self):
        """Should call logger.remove() before adding new sinks."""
        from local_deep_research.utilities.log_utils import config_logger
        import local_deep_research.utilities.log_utils as module

        call_order = []

        with patch.object(module, "logger") as mock_logger:
            mock_logger.remove.side_effect = lambda: call_order.append("remove")
            mock_logger.add.side_effect = lambda *a, **kw: call_order.append(
                "add"
            )

            config_logger("test_app")

            # remove should come before any add
            assert call_order[0] == "remove"
            assert "add" in call_order[1:]

    def test_enables_local_deep_research_logger(self):
        """Should call logger.enable('local_deep_research')."""
        from local_deep_research.utilities.log_utils import config_logger
        import local_deep_research.utilities.log_utils as module

        with patch.object(module, "logger") as mock_logger:
            config_logger("test_app")

            mock_logger.enable.assert_called_with("local_deep_research")

    def test_file_logging_warns_about_unencrypted_logs(self):
        """When file logging is enabled, should log a warning about security."""
        from local_deep_research.utilities.log_utils import config_logger
        import local_deep_research.utilities.log_utils as module

        with patch.dict(os.environ, {"LDR_ENABLE_FILE_LOGGING": "true"}):
            with patch.object(module, "logger") as mock_logger:
                config_logger("test_app")

                # Should warn about unencrypted log files
                mock_logger.warning.assert_called_once()
                warning_msg = mock_logger.warning.call_args[0][0]
                assert (
                    "unencrypted" in warning_msg.lower()
                    or "WARNING" in warning_msg
                )
