"""Silent observer — records the whole bot pipeline into Postgres (phase 1). Design rules (final plan v5): - DB is the single source of truth; no external tools, no dashboards here. - ZERO extra LLM tokens: we only persist values that already exist in code. - Never raises, never blocks the reply path (fire-and-forget like runtime._log). - Never deletes anything (no retention/cleanup tasks exist by policy). - `_jsonable` guarantees JSONB-safety for UUID/datetime/Decimal/... payloads. Stages captured (see plan §4.3): input.text, input.voice, stt.run, stt.result, nlu.request, nlu.result, entities.extracted, jev.request, jev.result, routing.decision, ambiguity.sent, ambiguity.user_choice, user_choice.pick, draft.render, draft.edit, draft.commit, draft.cancel. """ import asyncio import logging import uuid from datetime import date, datetime, time from decimal import Decimal from enum import Enum from pathlib import Path from sqlalchemy import select, update from app.config import settings from app.db import SessionLocal from app.models import BotTrace, BotTraceEvent logger = logging.getLogger("bot.obs") _bg_tasks: set = set() def _fire(coro) -> None: """Schedule a coroutine without awaiting; keep a ref so it is not GC'd.""" try: task = asyncio.get_running_loop().create_task(coro) _bg_tasks.add(task) task.add_done_callback(_bg_tasks.discard) except RuntimeError: # No running loop (should not happen inside the bot) — drop silently but log. logger.warning("obs: no running loop; dropped %r", coro) def _jsonable(obj): """Recursively make any Python object JSONB-safe (UUID/datetime/Decimal/…).""" if obj is None or isinstance(obj, (bool, int, float, str)): return obj if isinstance(obj, (uuid.UUID, Path)): return str(obj) if isinstance(obj, (datetime, date, time)): return obj.isoformat() if isinstance(obj, Decimal): return str(obj) # دقت حفظ می‌شود؛ در تحلیل با ::numeric قابل تبدیل است if isinstance(obj, Enum): return _jsonable(obj.value) if isinstance(obj, dict): return {str(k): _jsonable(v) for k, v in obj.items()} if isinstance(obj, (list, tuple, set, frozenset)): return [_jsonable(v) for v in obj] if hasattr(obj, "model_dump"): # pydantic v2 return _jsonable(obj.model_dump()) if hasattr(obj, "__dataclass_fields__"): return _jsonable(vars(obj)) return str(obj) # تور نهایی — هرگز raise نمی‌کند # --------------------------------------------------------------------------- # traces # --------------------------------------------------------------------------- async def trace_start(chat_id: int, message_id: int | None, kind: str, source: str = "bale") -> str | None: """Open a new trace; returns its id (str) or None on failure.""" try: async with SessionLocal() as s: t = BotTrace(chat_id=chat_id, message_id=message_id, kind=kind, source=source) s.add(t) await s.commit() return str(t.id) except Exception: logger.exception("obs: trace_start failed") return None async def link_draft(trace_id: str | None, draft_id, draft_kind: str | None) -> None: """Attach a draft to its originating trace (so later button clicks can find it).""" if not trace_id: return try: async with SessionLocal() as s: await s.execute( update(BotTrace) .where(BotTrace.id == trace_id) .values(draft_id=str(draft_id), draft_kind=draft_kind) ) await s.commit() except Exception: logger.exception("obs: link_draft failed") async def latest_trace_for_draft(draft_id) -> str | None: """Newest trace that produced this draft — used by button/render flows.""" try: async with SessionLocal() as s: row = (await s.execute( select(BotTrace.id) .where(BotTrace.draft_id == str(draft_id)) .order_by(BotTrace.created_at.desc()) .limit(1) )).scalar() return str(row) if row else None except Exception: logger.exception("obs: latest_trace_for_draft failed") return None async def set_trace_status(trace_id: str | None, status: str, committed_quote_id: str | None = None) -> None: if not trace_id: return try: async with SessionLocal() as s: values = {"status": status} if committed_quote_id: values["committed_quote_id"] = str(committed_quote_id) await s.execute(update(BotTrace).where(BotTrace.id == trace_id).values(**values)) await s.commit() except Exception: logger.exception("obs: set_trace_status failed") # --------------------------------------------------------------------------- # events # --------------------------------------------------------------------------- async def event(trace_id, stage: str, *, ok: bool = True, latency_ms: int | None = None, model: str | None = None, field: str | None = None, payload: dict | None = None) -> None: """Append one pipeline event. Never raises; failures are loud in the log.""" if not trace_id or not settings.OBS_ENABLED: return try: async with SessionLocal() as s: s.add(BotTraceEvent( trace_id=str(trace_id), stage=stage, ok=ok, latency_ms=latency_ms, model=model, field=field, payload=_jsonable(payload or {}), )) await s.commit() except Exception: logger.exception("obs: event %s failed", stage) # خطای خاموش نمی‌ماند async def log_resolution(trace_id, field: str, mention, status: str, candidates: list) -> None: """Record one matching attempt (difflib baseline / fallback paths).""" await event(trace_id, "routing.decision", field=field, payload={ "source": "difflib", "mention": mention, "status": status, "candidates": candidates[:4], }) class span: """with span('stt.run', trace_id=t, provider='whisper'): ... → one DB event with latency/ok.""" def __init__(self, name: str, trace_id: str | None = None, **attrs): self.name, self.trace_id, self.attrs = name, trace_id, attrs self._t0 = None def __enter__(self): import time as _t self._t0 = _t.perf_counter_ns() return self def __exit__(self, exc_type, exc, tb): import time as _t try: _fire(event( self.trace_id, self.name, ok=exc_type is None, latency_ms=int((_t.perf_counter_ns() - self._t0) / 1e6), model=self.attrs.get("model"), field=self.attrs.get("field"), payload=self.attrs, )) except Exception: logger.exception("obs: span %s failed", self.name) return False # استثنا هرگز بلعیده نمی‌شود # --------------------------------------------------------------------------- # voice persistence (never deleted) # --------------------------------------------------------------------------- def save_voice(trace_id: str | None, message_id: int, content: bytes, ext: str = ".ogg") -> str | None: """Persist a voice note under OBS_VOICE_DIR; creates the day folder safely.""" try: day = datetime.utcnow().strftime("%Y%m%d") base = Path(settings.OBS_VOICE_DIR) / day base.mkdir(parents=True, exist_ok=True) # الزام سخت‌سازی: مسیر همیشه ساخته می‌شود path = base / f"{trace_id}_{message_id}{ext}" path.write_bytes(content) return str(path) except Exception: logger.warning("obs: save_voice failed for trace %s", trace_id, exc_info=True) return None def save_enhanced_voice(trace_id: str | None, message_id: int, content: bytes, ext: str = ".ogg") -> str | None: """Persist an enhanced voice note under OBS_VOICE_DIR/{YYYYMMDD}/{trace_id}_{message_id}_enhanced{ext}.""" try: day = datetime.utcnow().strftime("%Y%m%d") base = Path(settings.OBS_VOICE_DIR) / day base.mkdir(parents=True, exist_ok=True) if ext and not ext.startswith("."): ext = f".{ext}" path = base / f"{trace_id}_{message_id}_enhanced{ext or '.ogg'}" path.write_bytes(content) return str(path) except Exception: logger.warning("obs: save_enhanced_voice failed for trace %s", trace_id, exc_info=True) return None