diff --git a/.gitignore b/.gitignore index 8f17090..b4dbcab 100644 --- a/.gitignore +++ b/.gitignore @@ -36,3 +36,4 @@ pxy_bots.zip pxy_bots (2).zip pxy_bots.zip pxy_bots.zip +pxy_bots.zip diff --git a/polisplexity/settings.py b/polisplexity/settings.py index db6754d..66a1cc1 100644 --- a/polisplexity/settings.py +++ b/polisplexity/settings.py @@ -226,3 +226,28 @@ REST_FRAMEWORK = { } AGENTS_INTERNAL_BASE = "http://127.0.0.1:8000" + +LOGGING = { + # ... keep your existing handlers/formatters ... + "version": 1, + "disable_existing_loggers": False, + "handlers": { + "console": { + "class": "logging.StreamHandler", + }, + }, + "loggers": { + "pxy_bots": { # package logger + "handlers": ["console"], + "level": "INFO", # or "DEBUG" + "propagate": False, + }, + # make sure __name__ in router resolves here; if your module path is different, use that + "pxy_bots.router": { + "handlers": ["console"], + "level": "INFO", + "propagate": False, + }, + }, +} + diff --git a/pxy_bots.zip b/pxy_bots.zip index 6823993..89c555b 100644 Binary files a/pxy_bots.zip and b/pxy_bots.zip differ diff --git a/pxy_bots/router.py b/pxy_bots/router.py index 800a483..08cdc35 100644 --- a/pxy_bots/router.py +++ b/pxy_bots/router.py @@ -1,6 +1,7 @@ # pxy_bots/router.py import json import logging +import time # <-- add from typing import Dict, Optional, Tuple from urllib.parse import urlparse @@ -45,26 +46,36 @@ def pick_db_route(bot_name: str, canon: Dict) -> Optional[Dict]: try: # Lazy import to avoid circulars at startup from .models import CommandRoute, Connection, TelegramBot # noqa + bot = TelegramBot.objects.filter(name=bot_name, is_active=True).first() if not bot: + logger.info("router.no_bot bot=%s", bot_name) return None trigger = ((canon.get("command") or {}).get("trigger")) or "message" cmd = ((canon.get("command") or {}).get("name")) or None cmd = (cmd or "").strip().lstrip("/").lower() or None + logger.info("router.lookup bot=%s trigger=%s cmd=%s", bot.username, trigger, cmd or "") + qs = ( CommandRoute.objects .select_related("connection") .filter(bot=bot, enabled=True, connection__is_active=True, trigger=trigger) .order_by("priority", "id") ) + # Log a small snapshot of candidates + snapshot = list(qs.values("command_name", "trigger", "priority", "path", "connection__name")[:10]) + logger.info("router.candidates n=%s sample=%s", qs.count(), snapshot) # Prefer exact command; then default (blank/null) - route = qs.filter(command_name=cmd).first() \ - or qs.filter(command_name__isnull=True).first() \ + route = ( + qs.filter(command_name=cmd).first() + or qs.filter(command_name__isnull=True).first() or qs.filter(command_name="").first() + ) if not route: + logger.info("router.no_match bot=%s trigger=%s cmd=%s", bot.username, trigger, cmd or "") return None conn: Connection = route.connection @@ -72,14 +83,22 @@ def pick_db_route(bot_name: str, canon: Dict) -> Optional[Dict]: ok, why = _is_allowed(url, conn.allowed_host_set()) if not ok: - logger.warning("router.db.reject url=%s reason=%s allowed=%s", url, why, conn.allowed_host_set()) + logger.warning( + "router.db.reject url=%s reason=%s allowed=%s route_conn=%s", + url, why, conn.allowed_host_set(), conn.name + ) return None headers = {} headers.update(conn.auth_headers()) headers.update(conn.extra_headers()) + logger.info( + "router.route_ok bot=%s trigger=%s cmd=%s url=%s conn=%s timeout=%ss", + bot.username, trigger, cmd or "", url, conn.name, conn.timeout_s + ) return {"url": url, "headers": headers, "timeout": conn.timeout_s} + except Exception as e: logger.exception("router.db.error: %s", e) return None @@ -96,28 +115,41 @@ def post_json(url: str, payload: Dict, timeout: float = 4.0, headers: Optional[D """ hdrs = {"Content-Type": "application/json", **(headers or {})} data = json.dumps(payload, ensure_ascii=False).encode("utf-8") + t0 = time.perf_counter() if _HAS_REQUESTS: try: r = requests.post(url, data=data, headers=hdrs, timeout=timeout) + dt = (time.perf_counter() - t0) * 1000 try: body = r.json() + preview = str(body)[:200].replace("\n", " ") except Exception: body = {"text": r.text[:2000]} + preview = body["text"][:200].replace("\n", " ") + logger.info("router.http requests url=%s status=%s t_ms=%.1f body~=%s", url, r.status_code, dt, preview) return r.status_code, body except Exception as e: - logger.exception("router.requests_failed url=%s", url) + dt = (time.perf_counter() - t0) * 1000 + logger.exception("router.requests_failed url=%s t_ms=%.1f err=%s", url, dt, e.__class__.__name__) return 502, {"ok": False, "error": f"requests_failed:{e.__class__.__name__}"} else: try: req = urllib.request.Request(url, data=data, headers=hdrs, method="POST") with urllib.request.urlopen(req, timeout=timeout) as resp: # nosec raw = resp.read(65536) + dt = (time.perf_counter() - t0) * 1000 try: body = json.loads(raw.decode("utf-8")) + preview = str(body)[:200].replace("\n", " ") except Exception: - body = {"text": raw.decode("utf-8", errors="replace")[:2000]} - return getattr(resp, "status", 200), body + txt = raw.decode("utf-8", errors="replace")[:2000] + body = {"text": txt} + preview = txt[:200].replace("\n", " ") + status = getattr(resp, "status", 200) + logger.info("router.http urllib url=%s status=%s t_ms=%.1f body~=%s", url, status, dt, preview) + return status, body except Exception as e: - logger.exception("router.urllib_failed url=%s", url) + dt = (time.perf_counter() - t0) * 1000 + logger.exception("router.urllib_failed url=%s t_ms=%.1f err=%s", url, dt, e.__class__.__name__) return 502, {"ok": False, "error": f"urllib_failed:{e.__class__.__name__}"} diff --git a/pxy_contracts.zip b/pxy_contracts.zip deleted file mode 100644 index b1d0ba7..0000000 Binary files a/pxy_contracts.zip and /dev/null differ diff --git a/pxy_de.zip b/pxy_de.zip deleted file mode 100644 index 64097e0..0000000 Binary files a/pxy_de.zip and /dev/null differ diff --git a/pxy_routing.zip b/pxy_routing.zip deleted file mode 100644 index 4e4b3e2..0000000 Binary files a/pxy_routing.zip and /dev/null differ