"""Request-arrival/duration forensics for CI test runs (issue #4431).

The UI test shards intermittently fail with 60-second navigation
timeouts, and the server logs go silent for the same window — but the
app only logs explicit events, so a silent window cannot distinguish
"the request never reached the server" (connection-level stall: listen
backlog, docker-proxy, browser socket pool starved by engine.io polls)
from "the request reached Flask and hung" (app-level stall: lock, DB
pool, GIL hog).

This middleware settles that by logging every request's arrival and its
WSGI-call duration. It is wired up by app_factory ONLY when CI or
TESTING is set, so production logging is unaffected.

Log format (kept compact — engine.io polls arrive every ~5s/client):
    [req] > GET /chat/
    [req] < GET /chat/ 0.04s
Slow completions get a WARNING with the duration, which the CI workflow
log-grep surfaces.

Freeze thread-dump (dead-man's switch)
--------------------------------------
The arrival log proves *that* the pipeline froze, but not *what* it was
stuck on. So this middleware also arms ``faulthandler.dump_traceback_later``
and re-arms it on every request arrival. If no request arrives for
``FREEZE_DUMP_SECONDS`` (i.e. a freeze), faulthandler dumps ALL thread
stacks to stderr — and because it runs on a dedicated C timer thread it
fires even when the GIL is starved, which a Python watchdog thread could
not. During a ~60s freeze this yields 2-3 dumps showing exactly which
threads are blocked (werkzeug accept loop? a lock? a DB/SQLCipher call?
the scheduler?). Healthy operation re-arms the timer faster than it
fires, so no dumps appear. Captured in the CI server-log artifact.
"""

import faulthandler
import sys
import time

from loguru import logger

# Above this, completion is logged as a warning — the interesting cases.
SLOW_REQUEST_SECONDS = 2.0

# No request for this long ⇒ assume a freeze and dump all thread stacks.
# Smaller than the 60s navigation timeout so a freeze produces 2-3 dumps,
# larger than legitimate inter-test idle so healthy runs stay quiet-ish.
FREEZE_DUMP_SECONDS = 20.0


def _should_arm_freeze_dump():
    """Arm the dead-man's switch only for the real, long-running server.

    create_app() runs thousands of times under pytest (with CI=true), and
    arming a repeating faulthandler dump in each would spew stack traces
    across the whole pytest run. The freeze we care about only happens on
    the live UI-shard server, so skip arming when pytest is in the process.
    """
    return "pytest" not in sys.modules


def _arm_freeze_dump():
    if not _should_arm_freeze_dump():
        return
    try:
        faulthandler.enable()
        faulthandler.dump_traceback_later(
            FREEZE_DUMP_SECONDS, repeat=True, file=sys.stderr
        )
    except Exception as exc:  # noqa: silent-exception
        # Diagnostics must never take the server down.
        logger.debug(f"freeze thread-dump arm failed: {exc}")


class RequestTimingMiddleware:
    """Outermost WSGI wrapper that logs request arrival and duration.

    Duration covers the WSGI call (view execution), not response
    streaming — for stall forensics the arrival line is the signal that
    matters: its absence during a navigation timeout proves the request
    never reached the WSGI layer.
    """

    def __init__(self, wsgi_app):
        self.wsgi_app = wsgi_app
        # Arm the freeze thread-dump dead-man's switch (no-op under pytest).
        _arm_freeze_dump()

    def __call__(self, environ, start_response):
        # Re-arm the dead-man's switch: as long as requests keep arriving
        # the dump never fires; a freeze (no arrivals) lets it fire and
        # capture the stuck thread stacks.
        _arm_freeze_dump()

        method = environ.get("REQUEST_METHOD", "-")
        path = environ.get("PATH_INFO", "-")
        # engine.io transport/sid make poll churn correlatable. (sid is
        # logged on purpose for correlation; logs are CI-only artifacts.)
        if path.startswith("/socket.io"):
            query = environ.get("QUERY_STRING", "")
            path = f"{path}?{query}" if query else path
        # Strip CR/LF so a crafted PATH_INFO/QUERY_STRING can't inject fake
        # log lines (the forensics output is grep'd downstream).
        path = path.replace("\r", "\\r").replace("\n", "\\n")
        logger.info(f"[req] > {method} {path}")
        start = time.monotonic()
        try:
            return self.wsgi_app(environ, start_response)
        finally:
            elapsed = time.monotonic() - start
            if elapsed >= SLOW_REQUEST_SECONDS:
                logger.warning(f"[req] < {method} {path} {elapsed:.1f}s SLOW")
            else:
                logger.info(f"[req] < {method} {path} {elapsed:.2f}s")
