notify-bridge/packages/server/tests/test_command_event_logging.py

"""Bot command invocations must be logged to ``EventLog``.

Covers the three branches in ``handle_command``:

* ``command_handled`` — a successful invocation (here exercised via the
  helper directly so the test stays focused on the persistence shape).
* ``command_rate_limited`` — caller hit the cooldown.
* ``command_failed`` — an exception bubbled out of dispatch.

The dashboard reads these rows via ``GET /api/status`` so the test also
asserts the row is filterable by ``event_type=command_*``.
"""

from __future__ import annotations

import pytest
from fastapi.testclient import TestClient
from sqlmodel import select
from sqlmodel.ext.asyncio.session import AsyncSession


def _bootstrap_app():
    """Bring up the app once so migrations run against the temp DB."""
    from notify_bridge_server.main import app

    return app


async def _seed_user_and_bot(name: str = "Test bot"):
    """Create a User + TelegramBot, return the bot row."""
    from notify_bridge_server.database.engine import get_engine
    from notify_bridge_server.database.models import TelegramBot, User

    engine = get_engine()
    async with AsyncSession(engine) as session:
        user = User(username=f"u_{name}", hashed_password="x")
        session.add(user)
        await session.commit()
        await session.refresh(user)

        bot = TelegramBot(user_id=user.id, name=name, token="dummy")
        session.add(bot)
        await session.commit()
        await session.refresh(bot)
        return bot


async def _read_events(event_type: str, bot_id: int):
    """Filter by bot_id so tests don't leak rows into each other.

    The temp DB is shared across tests in this module — without this
    filter a row left by an earlier test would make the next assertion
    flaky depending on collection order.
    """
    from notify_bridge_server.database.engine import get_engine
    from notify_bridge_server.database.models import EventLog

    engine = get_engine()
    async with AsyncSession(engine) as session:
        result = await session.exec(
            select(EventLog)
            .where(EventLog.event_type == event_type)
            .where(EventLog.telegram_bot_id == bot_id)
        )
        return list(result.all())


def test_format_command_subject_no_args(tmp_data_dir) -> None:  # noqa: ARG001
    from notify_bridge_server.commands.handler import _format_command_subject

    assert _format_command_subject("latest", "") == "/latest"
    assert _format_command_subject("help", None) == "/help"


def test_format_command_subject_with_args(tmp_data_dir) -> None:  # noqa: ARG001
    from notify_bridge_server.commands.handler import _format_command_subject

    assert _format_command_subject("search", "sunset") == "/search sunset"
    # Trailing whitespace must not leak into the dashboard label.
    assert _format_command_subject("search", "sunset  ") == "/search sunset"


def test_normalize_issuer_keeps_identity_drops_extras(tmp_data_dir) -> None:  # noqa: ARG001
    """Telegram ``from`` is whitelisted to identity fields only."""
    from notify_bridge_server.commands.handler import _normalize_issuer

    assert _normalize_issuer(None) is None
    assert _normalize_issuer({}) is None
    raw = {
        "id": 1234,
        "username": "alex",
        "first_name": "Alex",
        "last_name": "",
        "language_code": "ru",  # already captured separately — must drop
        "is_premium": True,      # must not leak into our log
    }
    assert _normalize_issuer(raw) == {
        "id": 1234,
        "username": "alex",
        "first_name": "Alex",
    }


def test_log_command_handled_persists_row(tmp_data_dir) -> None:  # noqa: ARG001
    """``command_handled`` row carries bot + provenance + media count."""
    import asyncio

    from notify_bridge_server.commands.base import CommandResponse
    from notify_bridge_server.commands.handler import _log_command_event

    app = _bootstrap_app()
    with TestClient(app):
        async def run() -> None:
            bot = await _seed_user_and_bot("HandledBot")
            await _log_command_event(
                bot=bot,
                chat_id="123456",
                cmd="latest",
                args="",
                locale="en",
                event_type="command_handled",
                responses=[CommandResponse(text="ok", media=[{"type": "photo"}])],
                ctx_tuples=[],  # universal command path: no tracker context
            )
            rows = await _read_events("command_handled", bot.id)
            assert len(rows) == 1
            row = rows[0]
            assert row.user_id == bot.user_id
            assert row.telegram_bot_id == bot.id
            assert row.bot_name == "HandledBot"
            assert row.collection_id == "123456"
            assert row.collection_name == "/latest"
            assert row.assets_count == 1
            assert row.details["command"] == "latest"
            assert row.details["chat_id"] == "123456"
            assert row.details["responses_count"] == 1

        asyncio.run(run())


def test_log_command_rate_limited_carries_wait_seconds(tmp_data_dir) -> None:  # noqa: ARG001
    import asyncio

    from notify_bridge_server.commands.base import CommandResponse
    from notify_bridge_server.commands.handler import _log_command_event

    app = _bootstrap_app()
    with TestClient(app):
        async def run() -> None:
            bot = await _seed_user_and_bot("ThrottledBot")
            await _log_command_event(
                bot=bot,
                chat_id="42",
                cmd="random",
                args="",
                locale="en",
                event_type="command_rate_limited",
                responses=[CommandResponse(text="cooldown")],
                ctx_tuples=[],
                extra_details={"wait_seconds": 7},
            )
            rows = await _read_events("command_rate_limited", bot.id)
            assert len(rows) == 1
            assert rows[0].details["wait_seconds"] == 7
            assert rows[0].assets_count == 0  # text-only response

        asyncio.run(run())


def test_log_command_failed_records_error(tmp_data_dir) -> None:  # noqa: ARG001
    import asyncio

    from notify_bridge_server.commands.handler import _log_command_event

    app = _bootstrap_app()
    with TestClient(app):
        async def run() -> None:
            bot = await _seed_user_and_bot("BrokenBot")
            await _log_command_event(
                bot=bot,
                chat_id="9",
                cmd="albums",
                args="",
                locale="ru",
                event_type="command_failed",
                responses=[],
                ctx_tuples=[],
                extra_details={"error": "RuntimeError: boom"},
            )
            rows = await _read_events("command_failed", bot.id)
            assert len(rows) == 1
            assert rows[0].details["error"] == "RuntimeError: boom"
            assert rows[0].details["locale"] == "ru"

        asyncio.run(run())


def test_log_command_event_handles_db_error_gracefully(tmp_data_dir, monkeypatch) -> None:  # noqa: ARG001
    """A logging failure must NOT raise — the user still gets their reply."""
    import asyncio

    from notify_bridge_server.commands import handler as handler_mod
    from notify_bridge_server.commands.base import CommandResponse

    app = _bootstrap_app()
    with TestClient(app):
        async def run() -> None:
            bot = await _seed_user_and_bot("StillRepliesBot")

            def boom() -> object:
                raise RuntimeError("db gone")

            monkeypatch.setattr(handler_mod, "get_engine", boom)

            # Must not raise.
            await handler_mod._log_command_event(
                bot=bot,
                chat_id="1",
                cmd="help",
                args="",
                locale="en",
                event_type="command_handled",
                responses=[CommandResponse(text="hi")],
                ctx_tuples=[],
            )

        asyncio.run(run())