"""
Utilities for logging.
"""

# Needed for loguru annotations
from __future__ import annotations

import inspect

# import logging - needed for InterceptHandler compatibility
import logging
import os
import queue
import sys
import threading
from functools import wraps
from typing import Any, Callable

import loguru
from flask import g, has_app_context
from loguru import logger

from ..config.paths import get_logs_directory
from ..database.models import ResearchLog
from ..web.services.socket_service import SocketIOService

_LOG_DIR = get_logs_directory()
_LOG_DIR.mkdir(parents=True, exist_ok=True)

# Thread-safe queue for database logs from background threads
_log_queue = queue.Queue(maxsize=1000)
_queue_processor_thread = None
_queue_processor_lock = threading.Lock()
_stop_queue = threading.Event()
"""
Default log directory to use.
"""

# Cap how much of a single log record's message we ship to the browser over
# socket.io. Some diagnostic log lines (e.g. ``[FETCH] page_text``) inline
# the full extracted page body — up to ~10 KB per call — which is useless
# in the UI (a single massive blob fills the viewport) and inflates both
# wire traffic and client-side state. Container-log/stderr, file, and DB
# sinks remain unchanged, so full diagnostics are preserved for grep/DB
# queries. The cap bounds the *prefix* preserved from the original message;
# the wire payload is the prefix plus a short truncation indicator (~100
# bytes), so it can exceed this value by that fixed overhead.
FRONTEND_MESSAGE_MAX_LENGTH = 2000

# Cap the size of messages persisted to ResearchLog. The DB column is
# unbounded TEXT, so a long langgraph run can accumulate thousands of
# 10 KB rows — paginated reads (PR #4037) hide the symptom but don't
# stop the storage growth. Same prefix-plus-indicator semantics as
# FRONTEND_MESSAGE_MAX_LENGTH; container-log/stderr/file sinks remain
# unchanged so full diagnostics are still preserved out-of-band.
DATABASE_MESSAGE_MAX_LENGTH = 5000


class InterceptHandler(logging.Handler):
    """
    Intercepts logging messages and forwards them to Loguru's logger.
    """

    def emit(self, record: logging.LogRecord) -> None:
        # Get corresponding Loguru level if it exists.
        try:
            level: str | int = logger.level(record.levelname).name
        except ValueError:
            level = record.levelno

        # Find caller from where originated the logged message.
        frame, depth = inspect.currentframe(), 0
        while frame:
            filename = frame.f_code.co_filename
            is_logging = filename == logging.__file__
            is_frozen = "importlib" in filename and "_bootstrap" in filename
            if depth > 0 and not (is_logging or is_frozen):
                break
            frame = frame.f_back
            depth += 1

        logger.opt(depth=depth, exception=record.exc_info).log(
            level, record.getMessage()
        )


def log_for_research(
    to_wrap: Callable[[str, ...], Any],
) -> Callable[[str, ...], Any]:
    """
    Decorator for a function that's part of the research process. It expects the function to
    take the research ID (UUID) as the first parameter, and configures all log
    messages made during this request to include the research ID.

    Args:
        to_wrap: The function to wrap. Should take the research ID as the first parameter.

    Returns:
        The wrapped function.

    """

    @wraps(to_wrap)
    def wrapped(research_id: str, *args: Any, **kwargs: Any) -> Any:
        g.research_id = research_id
        result = to_wrap(research_id, *args, **kwargs)
        g.pop("research_id")
        return result

    return wrapped


def _get_research_context_fallback() -> dict | None:
    """Read the per-thread research context, if any.

    Used as a fallback when individual log calls don't bind research_id/
    username via ``logger.bind``. The research thread sets this once at
    startup via ``set_search_context``, so every subsequent log call from
    the same thread picks up research_id, username, and user_password
    automatically — without requiring every call site to remember to bind.
    """
    try:
        from .thread_context import get_search_context

        return get_search_context()
    except Exception:
        return None


def _get_research_id(record=None) -> str | None:
    """
    Gets the current research ID (UUID), if present.

    Args:
        record: Optional loguru record that might contain bound research_id

    Returns:
        The current research ID (UUID), or None if it does not exist.

    """
    # First check if research_id is bound to the log record
    if record and "extra" in record and "research_id" in record["extra"]:
        return record["extra"]["research_id"]
    # Then check Flask context
    if has_app_context():
        gid = g.get("research_id")
        if gid:
            return gid
    # Fall back to per-thread research context — research-thread logger
    # calls without an explicit bind still get attributed correctly.
    ctx = _get_research_context_fallback()
    if ctx:
        return ctx.get("research_id")
    return None


# Counters for swallowed exceptions in the logging path. Bare except: pass
# is required here (logging errors must not propagate or recurse), but we
# write a stderr line on each new occurrence so silent failures aren't
# invisible — only active when LDR_APP_DEBUG=true so production stderr
# stays clean.
_silent_exc_counts: dict[str, int] = {}


def _report_silent_exception(
    where: str,
    exc_type_name: str,
    username: str | None = None,
    research_id: str | None = None,
    level: str | None = None,
) -> None:
    """Surface a swallowed logging-path exception to stderr.

    Bypasses ``logger`` to avoid recursing back through ``database_sink``.
    Rate-limited to first occurrence + every 100th repeat for the same
    ``where`` key, so a persistent failure mode doesn't flood the console.

    Note: takes the exception's TYPE NAME as a plain string (not the
    exception object). The caller does ``type(exc).__name__`` and passes
    the result. This is deliberate — CodeQL's taint analyzer treats any
    function frame holding a ``BaseException`` captured from a password-
    bearing call site as tainted, and flags every stderr write inside
    that frame. Receiving only a type-name string severs the flow at
    the boundary.
    """
    if os.environ.get("LDR_APP_DEBUG", "").lower() not in ("1", "true", "yes"):
        return
    n = _silent_exc_counts.get(where, 0) + 1
    _silent_exc_counts[where] = n
    if n != 1 and n % 100 != 0:
        return
    parts = []
    if username is not None:
        parts.append(f"username={username!r}")
    if research_id is not None:
        parts.append(f"research_id={research_id!r}")
    if level is not None:
        parts.append(f"level={level!r}")
    ctx = " ".join(parts)
    # CodeQL's py/clear-text-logging-sensitive-data may flag this stderr
    # write because the function frame is reachable from
    # _write_log_to_database which holds user_password locally. The data
    # actually written is only plain strings — `where` (literal),
    # `exc_type_name` (`type(exc).__name__`), and `username/research_id/level`
    # repr'd from the queue entry. No password value ever reaches the
    # formatter; the helper signature deliberately accepts only typed
    # primitives. If CodeQL flags this line, dismiss the alert as a
    # false positive in the Security tab with that justification.
    sys.stderr.write(
        f"[log-utils] {where} swallowed (count={n}): "
        f"{exc_type_name}{(' ' + ctx) if ctx else ''}\n"
    )
    sys.stderr.flush()


def _process_log_queue():
    """
    Process logs from the queue in a dedicated daemon thread.

    Safe to run off the main thread: ``_write_log_to_database`` uses
    ``get_user_db_session`` which yields a thread-local SQLAlchemy session,
    and the underlying SQLite engines are opened with
    ``check_same_thread=False``.
    """
    while not _stop_queue.is_set():
        try:
            # Wait for logs with timeout to check stop flag
            log_entry = _log_queue.get(timeout=0.1)

            # Skip if no entry
            if log_entry is None:
                continue

            # Write to database if we have app context
            if has_app_context():
                _write_log_to_database(log_entry)
            else:
                # If no app context, put it back in queue for later
                try:
                    _log_queue.put_nowait(log_entry)
                except queue.Full:
                    pass  # Drop log if queue is full

        except queue.Empty:
            continue
        except Exception as exc:
            # noqa: silent-exception — must not let logging errors crash the log processor thread.
            # Wrap the report itself: if stderr is closed (broken pipe etc.)
            # an IOError from inside an except handler propagates and would
            # kill the daemon thread, silently breaking all subsequent log
            # persistence for the rest of the process lifetime.
            try:
                _report_silent_exception(
                    "process_log_queue", type(exc).__name__
                )
            except Exception:
                pass  # noqa: silent-exception — broken stderr must not kill the daemon


def _write_log_to_database(log_entry: dict) -> None:
    """
    Write a log entry to the database. Should only be called from main thread.
    """
    from ..database.session_context import get_user_db_session

    try:
        username = log_entry.get("username")
        # Captured in the emitting thread (database_sink) from
        # ContextVar storage; the queue daemon thread can't read that itself.
        pw = log_entry.get("user_password")  # gitleaks:allow

        with get_user_db_session(
            username, password=pw
        ) as db_session:  # gitleaks:allow
            if db_session:
                db_log = ResearchLog(
                    timestamp=log_entry["timestamp"],
                    message=log_entry["message"],
                    module=log_entry["module"],
                    function=log_entry["function"],
                    line_no=log_entry["line_no"],
                    level=log_entry["level"],
                    research_id=log_entry["research_id"],
                )
                db_session.add(db_log)
                db_session.commit()
    except Exception as exc:
        # noqa: silent-exception — DB errors in the logging path must not propagate or recurse.
        # Wrap the report itself so a broken-stderr IOError can't escape and
        # be re-caught by an outer logging-aware handler somewhere upstream.
        try:
            _report_silent_exception(
                "write_log_to_database",
                type(exc).__name__,
                username=log_entry.get("username"),
                research_id=log_entry.get("research_id"),
                level=log_entry.get("level"),
            )
        except Exception:
            pass  # noqa: silent-exception — broken stderr must not bubble out of logging path


def database_sink(message: loguru.Message) -> None:
    """
    Sink that saves messages to the database.
    Queues logs from background threads for later processing.

    Args:
        message: The log message to save.

    """
    record = message.record
    research_id = _get_research_id(record)

    # Resolve username + password. The queue daemon thread can't read the
    # research thread's ContextVar storage and has no Flask request
    # context, so we capture both here in the emitting thread.
    #
    # Source priority:
    #   1. logger.bind(...) extras on the record itself
    #   2. per-thread research context (set once when the research thread
    #      starts, so every subsequent log call inherits it without
    #      requiring an explicit bind)
    #   3. Flask request session (for request-handler threads that
    #      tagged research_id via the @log_for_research decorator but
    #      didn't bind username — common for /api/research/<id>/* routes)
    username = record.get("extra", {}).get("username")
    user_password = None
    ctx = _get_research_context_fallback()
    if ctx:
        if not username:
            username = ctx.get("username")
        user_password = ctx.get("user_password")
    # Only consult Flask request state when the log already has a
    # research_id. ResearchLog is research-scoped by design — auth and
    # other system DEBUG logs (research_id=None) don't belong there. If
    # we attached a username to them via flask_session, they'd just churn
    # through the queue and fail at the daemon (where the encrypted DB
    # may not even be open yet for that user — e.g. right after a server
    # restart with a still-valid session cookie).
    if research_id is not None and has_app_context():
        try:
            from flask import session as flask_session, has_request_context

            if not username and has_request_context():
                username = flask_session.get("username")
            # Password is set on g.user_password by the request middleware
            # after authentication. The daemon thread can't read this, so
            # capture it here in the request thread.
            if not user_password and hasattr(g, "user_password"):
                user_password = g.user_password
        except Exception:
            pass  # noqa: silent-exception — must not fail logging on session lookup

    # Skip persistence for system logs that have no research context.
    # These can't be written to any per-user encrypted DB and would just
    # churn through the queue + daemon for no useful end state.
    if research_id is None and username is None:
        return

    # Create log entry dict
    log_entry = {
        "timestamp": record["time"],
        "message": _truncate_for_database(record["message"]),
        "module": record["name"],
        "function": record["function"],
        "line_no": int(record["line"]),
        "level": record["level"].name,
        "research_id": research_id,
        "username": username,
        "user_password": user_password,
    }

    # Check if we're in a background thread
    # Note: Socket.IO handlers run in separate threads even with app context
    if not has_app_context() or threading.current_thread().name != "MainThread":
        # Queue the log for later processing
        try:
            _log_queue.put_nowait(log_entry)
        except queue.Full:
            # Drop log if queue is full to avoid blocking
            pass
    else:
        # We're in the main thread with app context - write directly
        _write_log_to_database(log_entry)


def _truncate_for_database(message: str) -> str:
    """Bound the persisted size of a log message.

    ``DATABASE_MESSAGE_MAX_LENGTH`` is the preserved-prefix length;
    the stored string is at most that plus a ~100-char suffix that
    reports the original length so debug context is not lost. Full
    messages remain available in container-log/stderr/file sinks.
    """
    if len(message) <= DATABASE_MESSAGE_MAX_LENGTH:
        return message
    suffix = (
        f"… (truncated; full message in server logs; "
        f"original length: {len(message)} chars)"
    )
    return message[:DATABASE_MESSAGE_MAX_LENGTH] + suffix


def _truncate_for_frontend(message: str) -> str:
    """Bound the wire size of an outbound log message.

    ``FRONTEND_MESSAGE_MAX_LENGTH`` caps the *preserved prefix* of the
    original message. When truncation kicks in, a short indicator is
    appended that names the original length and points the user at the
    server-side logs for the full text, so the returned string is
    ``FRONTEND_MESSAGE_MAX_LENGTH`` plus the fixed indicator overhead
    (~100 bytes). Verbose diagnostic logs (e.g. ``[FETCH] page_text``
    which inlines the full extracted page body) are useless in the UI
    when displayed in full and inflate socket payloads + client-side
    memory; container-log/stderr, file, and DB sinks remain unchanged.
    """
    if len(message) <= FRONTEND_MESSAGE_MAX_LENGTH:
        return message
    suffix = (
        f"… (truncated; full message in server logs; "
        f"original length: {len(message)} chars)"
    )
    return message[:FRONTEND_MESSAGE_MAX_LENGTH] + suffix


def frontend_progress_sink(message: loguru.Message) -> None:
    """
    Sink that sends messages to the frontend.

    Args:
        message: The log message to send.

    """
    record = message.record
    research_id = _get_research_id(record)
    if research_id is None:
        # If we don't have a research ID, don't send anything.
        # Can't use logger here as it causes deadlock
        return

    # Defence in depth (R4-09): never forward policy-audit log lines
    # to WebSocket subscribers. They carry engine names + reason codes
    # which could leak the active scope to a cross-origin observer under
    # CORS=*. Today policy_audit logs don't bind research_id so the
    # research_id guard above already skips them; this filter is the
    # explicit guarantee in case a future call site binds both.
    if record.get("extra", {}).get("policy_audit"):
        return

    frontend_log = {
        "log_entry": {
            "message": _truncate_for_frontend(record["message"]),
            "type": record["level"].name,  # Keep original case
            "time": record["time"].isoformat(),
        },
    }
    SocketIOService().emit_to_subscribers(
        "progress", research_id, frontend_log, enable_logging=False
    )


def flush_log_queue():
    """
    Drain all pending logs from the queue to the database.

    Used at process exit (see ``flush_logs_on_exit`` in ``web/app.py``) to
    drain whatever the background daemon did not get to before it was
    stopped. The request path no longer calls this — the
    ``start_log_queue_processor`` daemon handles steady-state drainage so
    requests never block on DB writes.
    """
    flushed = 0
    while not _log_queue.empty():
        try:
            log_entry = _log_queue.get_nowait()
            _write_log_to_database(log_entry)
            flushed += 1
        except queue.Empty:
            break
        except Exception:
            pass  # noqa: silent-exception — DB errors during log flush must not propagate

    if flushed > 0:
        logger.debug(f"Flushed {flushed} queued log entries to database")


def start_log_queue_processor(app) -> threading.Thread:
    """Start the background daemon that drains the log queue into the DB.

    Runs ``_process_log_queue`` inside an application context so writes
    have a Flask context, and so the daemon can work independently of
    any in-flight request. Idempotent: calling twice is a no-op.

    Args:
        app: The Flask app whose context the daemon should push.

    Returns:
        The daemon thread (running).
    """
    global _queue_processor_thread
    with _queue_processor_lock:
        if (
            _queue_processor_thread is not None
            and _queue_processor_thread.is_alive()
        ):
            return _queue_processor_thread

        _stop_queue.clear()

        def _run():
            # Push an app context for the lifetime of the daemon so
            # the queue processor can call into DB code that requires
            # Flask g.
            with app.app_context():
                _process_log_queue()

        _queue_processor_thread = threading.Thread(
            target=_run,
            name="log-queue-processor",
            daemon=True,
        )
        _queue_processor_thread.start()
        thread = _queue_processor_thread
    logger.info("Log queue processor daemon started")
    return thread


def stop_log_queue_processor(timeout: float = 2.0) -> None:
    """Signal the log queue processor to stop and wait briefly for it."""
    global _queue_processor_thread
    _stop_queue.set()
    with _queue_processor_lock:
        thread = _queue_processor_thread
    if thread is not None:
        thread.join(timeout=timeout)
        # Only clear the reference if the thread actually exited. If join
        # timed out the daemon is still running, and clearing the ref would
        # let a subsequent start_log_queue_processor() spawn a second
        # daemon that drains the same queue concurrently. Re-check identity
        # under the lock so we don't accidentally null out a fresh thread
        # that another start spawned in the meantime.
        if not thread.is_alive():
            with _queue_processor_lock:
                if _queue_processor_thread is thread:
                    _queue_processor_thread = None


def config_logger(name: str, debug: bool = False) -> None:
    """
    Configures the default logger.

    Args:
        name: The name to use for the log file.
        debug: Whether to enable unsafe debug logging.

    """
    from ..security.log_sanitizer import strip_control_chars

    def _sanitize_record(record):
        record["message"] = strip_control_chars(record["message"])

    logger.configure(patcher=_sanitize_record)

    logger.enable("local_deep_research")
    logger.remove()

    # Log to console (stderr) and database
    stderr_level = "DEBUG" if debug else "INFO"

    # loguru's diagnose=True renders repr() of every local variable in every
    # traceback frame on exceptions. Under LDR_APP_DEBUG that would dump
    # credentials living in frame locals (api_key, SQLCipher password,
    # Authorization headers) into every sink. Gate diagnose behind a separate
    # explicit opt-in so enabling LDR_APP_DEBUG for general debug output does
    # not also enable localvar dumps. Default OFF even when debug is on.
    diagnose = debug and os.environ.get(
        "LDR_LOGURU_DIAGNOSE", ""
    ).strip().lower() in ("1", "true", "yes")

    # ``diagnose`` renders the repr() of every frame-local — which can
    # include the SQLCipher master password and other credentials — into
    # the rendered exception block. Allow it ONLY on the ephemeral, local
    # stderr sink the operator explicitly opted into. The database sink
    # PERSISTS into the user's own encrypted DB and the frontend sink
    # SHIPS to the browser, so they must NEVER render frame locals, even
    # under LDR_LOGURU_DIAGNOSE. This single chokepoint protects every
    # credential-bearing exception handler app-wide against the
    # frame-locals leak, independent of per-site logging discipline
    # (#4182).
    #
    # enqueue=True on stderr: loguru emits to an in-memory queue and a
    # single background thread does the actual stderr write, so a log call
    # never blocks on stderr I/O while holding the handler's lock. Without
    # it, under the werkzeug threading dev server every request thread logs
    # synchronously, and when stderr back-pressures (e.g. a slow/full
    # `docker logs` pipe in CI) the lock-holder blocks mid-write and ALL
    # logging threads — i.e. all request threads — pile up behind the lock,
    # freezing the whole request pipeline for ~60s (#4431). Captured
    # forensically: 3/5 server threads parked in loguru's _protected_lock
    # under load. The database/progress sinks keep their own
    # emitting-thread context capture and are left synchronous.
    logger.add(sys.stderr, level=stderr_level, diagnose=diagnose, enqueue=True)
    logger.add(database_sink, level="DEBUG", diagnose=False)
    logger.add(frontend_progress_sink, diagnose=False)

    if debug:
        logger.warning(
            "DEBUG logging is enabled (LDR_APP_DEBUG=true). "
            "Logs may contain sensitive data (queries, answers, API responses). "
            "Do NOT use in production."
        )

    if diagnose:
        logger.warning(
            "LDR_LOGURU_DIAGNOSE is enabled: exception tracebacks will include "
            "local variable values, which may contain credentials (API keys, "
            "passwords, tokens). Do NOT use in production."
        )

    # Optionally log to file if enabled (disabled by default for security)
    # Check environment variable first, then database setting
    enable_file_logging = (
        os.environ.get("LDR_ENABLE_FILE_LOGGING", "").lower() == "true"
    )

    # File logging is controlled only by environment variable for simplicity
    # Database settings are not available at logger initialization time

    if enable_file_logging:
        log_file = _LOG_DIR / f"{name}.log"
        logger.add(
            log_file,
            level="DEBUG",
            rotation="10 MB",
            retention="7 days",
            compression="zip",
            # diagnose=False: the file sink is persistent and unencrypted,
            # so — like the DB and frontend sinks — it must never render
            # frame-local credentials, even under LDR_LOGURU_DIAGNOSE.
            # Frame-local dumps go only to the ephemeral stderr sink, which
            # is what the policy comment above describes (#4182).
            diagnose=False,
        )
        logger.warning(
            f"File logging enabled - logs will be written to {log_file}. "
            "WARNING: Log files are unencrypted and may contain sensitive data!"
        )

    # Add a special log level for milestones.
    try:
        logger.level("MILESTONE", no=26, color="<magenta><bold>")
    except ValueError:
        # Level already exists, that's fine
        pass
