Files
vocero-client/demo/server.py
T
2026-08-26 17:42:00 -04:00

2315 lines
108 KiB
Python
Raw Blame History

This file contains ambiguous Unicode characters
This file contains Unicode characters that might be confused with other characters. If you think that this is intentional, you can safely ignore this warning. Use the Escape button to reveal them.
"""
Tiny server for the speech-to-speech demo.
The demo used to ship as a `sdk: static` Space, but the web-search tool needs a
search key the browser must NOT see. A static Space has no runtime process, so it
can't hold a secret the front-end uses. This server fixes that: it serves the
unchanged front-end AND exposes a same-origin `/api/search` proxy that holds the
Serper key server-side (see docs/adr/0001).
Everything lives in one container; the speech-to-speech backend stays a separate,
load-balanced service the browser talks to over WebSocket as before. The load
balancer's address is a secret too (like the Serper key): the browser never sees
it. `/api/session` proxies the session handshake server-side so only the
per-session compute URL the LB hands back (which the browser must dial) is exposed.
On the deployed Space the server also meters conversation time by HF login tier
(anonymous / signed-in / PRO) — see `limiter.py` and `auth.py`. That whole feature
is off unless BOTH `LOAD_BALANCER_URL` and `SPACE_ID` are set, so it runs only on
the live Space, never locally (even with the LB exported for testing).
`SPEECH_TO_SPEECH_URL` overrides everything: when set, the LB logic above is
disabled entirely (no session proxy, no queue, no metering, no sign-in) and the
browser connects directly to that URL, shown read-only in Settings.
Endpoints:
GET /api/config -> { search, lb, allowDirect, s2sUrl, auth }
GET /api/me -> login + tier + remaining budget (LB mode only)
POST /api/search -> { results, answer } Google via Serper.dev
POST /api/session -> proxies <LB>/session: a grant, or a queue ticket
GET /api/queue/{id} -> proxies <LB>/queue/{id}: position, or a grant on claim
DELETE /api/queue/{id} -> leave the queue (explicit "Leave queue" button)
POST /api/queue/end -> leave the queue (sendBeacon on teardown)
POST /api/session/heartbeat-> extend the reservation; { expired }
POST /api/session/end -> reconcile + refund (sendBeacon on teardown)
/* -> static files (index.html, main.js, ...)
When every compute slot is busy the load balancer hands back a queue ticket
instead of a grant; the browser polls /api/queue/{id} until it reaches the front
and a slot frees. Waiting reserves nothing — the daily budget is only reserved at
the moment a slot is actually claimed (a grant), never while queued.
"""
import asyncio
from datetime import datetime, timezone
import json
import logging
import os
import re
from urllib.parse import parse_qsl, urlencode, urlsplit, urlunsplit
import httpx
import websockets
from dotenv import load_dotenv
from fastapi import FastAPI, HTTPException, Request, WebSocket, WebSocketDisconnect
from fastapi.responses import JSONResponse
from fastapi.staticfiles import StaticFiles
from pydantic import BaseModel
import auth
import limiter
logger = logging.getLogger("s2s")
_logging_configured = False
if not _logging_configured:
_handler = logging.StreamHandler()
_handler.setFormatter(logging.Formatter(
"%(asctime)s %(levelname)-7s [%(name)s] %(message)s",
datefmt="%Y-%m-%d %H:%M:%S",
))
logging.basicConfig(level=logging.DEBUG, handlers=[_handler], force=True)
_lvl_env = (os.environ.get("LOG_LEVEL") or os.environ.get("S2S_LOG_LEVEL") or "INFO").strip().upper()
_is_debug = _lvl_env in {"DEBUG", "TRACE", "10"}
# Logger rumorosi: a meno che LOG_LEVEL=debug esplicito, tienili quiet.
logging.getLogger("httpx").setLevel(logging.DEBUG if _is_debug else logging.WARNING)
logging.getLogger("websockets").setLevel(logging.DEBUG if _is_debug else logging.INFO)
logging.getLogger("uvicorn").setLevel(logging.DEBUG if _is_debug else logging.INFO)
logging.getLogger("uvicorn.access").setLevel(logging.DEBUG if _is_debug else logging.INFO)
logging.getLogger("httpcore").setLevel(logging.DEBUG if _is_debug else logging.WARNING)
logger.setLevel(logging.DEBUG if _is_debug else logging.DEBUG) # s2s sempre almeno DEBUG in dev
_logging_configured = True
logger.debug(
"LOG_LEVEL env=%s — noisy-logger levels: httpx=%s uvicorn=%s websockets=%s",
_lvl_env,
logging.getLevelName(logging.getLogger("httpx").level),
logging.getLevelName(logging.getLogger("uvicorn").level),
logging.getLevelName(logging.getLogger("websockets").level),
)
ROOT_DIR = os.path.abspath(os.path.join(os.path.dirname(__file__), ".."))
load_dotenv(os.path.join(ROOT_DIR, ".env"), override=False)
logger.debug("Loaded .env from %s", ROOT_DIR)
def _normalize_reasoning_type(value: str) -> str:
normalized = (value or "").strip().strip('"').strip("'").replace("-", "_").upper()
if normalized == "OPENAI":
return "OPENAI"
if normalized in {"NODE_RED", "NODERED"}:
return "NODE_RED"
return "PROXY"
SERPER_KEY = os.environ.get("SERPER_API_KEY", "").strip()
S2S_PRIMARY_PROMPT = os.environ.get("S2S_PRIMARY_PROMPT", "").strip()
if S2S_PRIMARY_PROMPT:
S2S_PRIMARY_PROMPT = S2S_PRIMARY_PROMPT.replace("\\n", "\n")
S2S_AGENT_PROFILE = os.environ.get("S2S_AGENT_PROFILE", "").strip()
S2S_TOOL_EXECUTION_MCP_URL = os.environ.get("S2S_TOOL_EXECUTION_MCP_URL", "").strip()
S2S_TOOL_EXECUTION_MCP_API_KEY = os.environ.get("S2S_TOOL_EXECUTION_MCP_API_KEY", "").strip()
S2S_TOOL_EXECUTION_MCP_API_SECRET = os.environ.get("S2S_TOOL_EXECUTION_MCP_API_SECRET", "").strip()
# ⚙️ MASTER SWITCH MCP EXECUTION: Disabilita TUTTA la funzionalità MCP quando
# S2S_TOOL_EXECUTION_MCP_URL non è presente / è commentata / è vuota in .env.
# - Non viene caricato il catalogo 79 tool dal profilo agente Aquachile
# - Non viene injettato tools[] / tool_choice nel session.update WS
# - POST /api/mcp/tool risponde 503 con log [MCP DISABLED]
MCP_EXEC_ENABLED = bool(S2S_TOOL_EXECUTION_MCP_URL)
VOCERO_USER_PHONE_AUTH_URL = os.environ.get(
"VOCERO_USER_PHONE_AUTH_URL",
os.environ.get("S2S_USER_PHONE_AUTH_URL", ""),
).strip()
S2S_INSIGHTS_URL = os.environ.get("S2S_INSIGHTS_URL", "").strip()
# Credenziali opzionali per endpoint insights (stesso pattern di MCP execution;
# endpoint Aquachile attualmente è pubblico ma lasciamo predisposto per auth futura).
S2S_INSIGHTS_API_KEY = os.environ.get("S2S_INSIGHTS_API_KEY", "").strip() or os.environ.get("S2S_TOOL_EXECUTION_MCP_API_KEY", "").strip()
S2S_INSIGHTS_API_SECRET = os.environ.get("S2S_INSIGHTS_API_SECRET", "").strip() or os.environ.get("S2S_TOOL_EXECUTION_MCP_API_SECRET", "").strip()
# 🧠 Master switch per caricamento insights diario all'inizio della sessione.
# Se S2S_INSIGHTS_URL è valorizzato → GET oggi e append blocco a instructions agente.
INSIGHTS_ENABLED = bool(S2S_INSIGHTS_URL)
# Numero massimo di insights serializzati nel prompt (evita esplosione contesto).
MAX_INSIGHTS_IN_CONTEXT = 20
S2S_SEARCH_MCP = os.environ.get("S2S_SEARCH_MCP", "").strip().lower() == "true"
S2S_REASONING_TYPE = _normalize_reasoning_type(os.environ.get("S2S_REASONING_TYPE", "PROXY"))
OPENAI_API_KEY = os.environ.get("OPENAI_API_KEY", "").strip()
OPENAI_BASE_URL = os.environ.get("OPENAI_BASE_URL", "https://api.openai.com/v1").strip().rstrip("/")
OPENAI_REASONING_MODEL = os.environ.get("OPENAI_REASONING_MODEL", "gpt-4.1-mini").strip()
OPENAI_ORGANIZATION = os.environ.get("OPENAI_ORGANIZATION", "").strip()
OPENAI_PROJECT = os.environ.get("OPENAI_PROJECT", "").strip()
# Node-RED reasoning engine endpoint (modalità NODE_RED).
# Es.: http://localhost:1881 oppure http://s2s-reasoning:1880 (rete docker)
NODE_RED_REASONING_URL = os.environ.get("S2S_REASONING_NODE_RED_URL", "").strip().rstrip("/")
# Speech-to-speech load balancer URL. When set, the browser POSTs /api/session
# (which proxies <lb>/session here, server-side) and connects to the URL the LB
# returns (the original flow). The LB address itself is never sent to the browser.
# When empty, the user may instead set a direct s2s server URL in Settings and the
# browser connects to it straight (no load balancer).
LOAD_BALANCER_URL = os.environ.get("LOAD_BALANCER_URL", "").strip()
# Direct s2s server URL pinned by the deploy. Takes priority over the load
# balancer: when set, ALL LB logic is disabled (no /api/session proxy, no queue,
# no limiter, no sign-in) and the browser connects to this URL directly. Unlike
# the LB address it is NOT a secret — /api/config sends it to the client, which
# shows it read-only in Settings.
SPEECH_TO_SPEECH_URL = os.environ.get("SPEECH_TO_SPEECH_URL", "").strip()
# Optional same-origin WebSocket relay target. When set, the browser dials this
# app over ws(s)://<this-app>/v1/realtime and the server relays frames to the
# upstream speech-to-speech endpoint, keeping the internal host private.
S2S_PROXY_TARGET = os.environ.get("S2S_PROXY_TARGET", "").strip()
if SPEECH_TO_SPEECH_URL or S2S_PROXY_TARGET:
LOAD_BALANCER_URL = ""
# HF injects SPACE_ID ("owner/space") into every Space runtime; it's absent
# locally and on a plain `docker run`. We meter conversation time ONLY on the
# deployed Space — i.e. when BOTH the LB is configured AND we're on a Space.
# Off-Space (local dev, even with the LB exported) the app still proxies the LB,
# but nothing is metered: no budget, no reservations, no sign-in gating.
SPACE_ID = os.environ.get("SPACE_ID", "").strip()
LIMITER_ENABLED = bool(LOAD_BALANCER_URL) and bool(SPACE_ID)
SERPER_URL = "https://google.serper.dev/search"
# Cap results so the tool output stays small enough to feed back to the model.
MAX_RESULTS = 5
HERE = os.path.dirname(os.path.abspath(__file__))
app = FastAPI(title="s2s-demo")
# Wire HF OAuth before the app serves (no-op unless the OAuth env is present).
# Sign-in only matters when we're metering (prod Space), so gate it on that.
AUTH_ENABLED = LIMITER_ENABLED and auth.attach(app)
logger.debug(
"[STARTUP] Aquachile endpoints configured — profile=%s mcp=%s userAuth=%s powerbiCatalog=%s",
bool(S2S_AGENT_PROFILE),
MCP_EXEC_ENABLED,
bool(VOCERO_USER_PHONE_AUTH_URL),
bool(os.environ.get("S2S_PRELOAD_DATA_ENDPOINT", "").strip()),
)
if MCP_EXEC_ENABLED:
logger.info(
"[MCP MASTER] ENABLED — S2S_TOOL_EXECUTION_MCP_URL=%s; tool catalog will be injected via WS session.update tools[] and /api/mcp/tool proxy is active.",
S2S_TOOL_EXECUTION_MCP_URL,
)
else:
logger.warning(
"[MCP MASTER] ⛔ DISABLED — S2S_TOOL_EXECUTION_MCP_URL is empty/commented in .env. "
"Tool execution is OFF: no tools[] injection in WS session.update, /api/mcp/tool returns 503. "
"To enable, uncomment or set S2S_TOOL_EXECUTION_MCP_URL and restart the container.",
)
if INSIGHTS_ENABLED:
logger.info(
"[INSIGHTS MASTER] ENABLED — S2S_INSIGHTS_URL=%s. At every new WS realtime session we will GET today's insights (start_date=end_date=YYYY-MM-DD today) and append a summary block to the agent instructions so the assistant has today's operational context. MAX_INSIGHTS_IN_CONTEXT=%d apiKey=%s",
S2S_INSIGHTS_URL,
MAX_INSIGHTS_IN_CONTEXT,
"set" if S2S_INSIGHTS_API_KEY else "not-set (public endpoint OK)",
)
else:
logger.debug(
"[INSIGHTS MASTER] DISABLED — S2S_INSIGHTS_URL is empty/commented in .env. "
"Agent instructions will NOT include today's insights context."
)
logger.debug(
"[STARTUP] Other externals — searchMcp=%s reasoning=%s nodeRed=%s serper=%s lb=%s s2sProxy=%s s2sDirect=%s auth=%s",
S2S_SEARCH_MCP,
S2S_REASONING_TYPE,
NODE_RED_REASONING_URL or "-",
bool(SERPER_KEY),
bool(LOAD_BALANCER_URL),
bool(S2S_PROXY_TARGET),
bool(SPEECH_TO_SPEECH_URL),
AUTH_ENABLED,
)
logger.debug(
"[STARTUP] Runtime config — SPACE_ID=%s LIMITER_ENABLED=%s MAX_RESULTS=%d",
bool(SPACE_ID), LIMITER_ENABLED, MAX_RESULTS,
)
async def _report_server_debug(hypothesis_id: str, location: str, msg: str, data: dict | None = None) -> None:
return
def _realtime_event_summary(raw: str) -> dict | None:
try:
payload = json.loads(raw)
except Exception:
return None
if not isinstance(payload, dict):
return None
event_type = payload.get("type")
if not isinstance(event_type, str):
return None
summary = {"type": event_type}
if event_type == "session.update":
session = payload.get("session") if isinstance(payload.get("session"), dict) else {}
tools = session.get("tools") if isinstance(session.get("tools"), list) else []
summary["toolCount"] = len(tools)
summary["toolNames"] = [tool.get("name") for tool in tools if isinstance(tool, dict)]
summary["toolChoice"] = session.get("tool_choice")
summary["instructionLength"] = len(session.get("instructions") or "")
elif event_type in {"response.function_call_arguments.done", "error", "session.updated"}:
for key in ("name", "call_id", "code", "message", "response_id"):
if key in payload:
summary[key] = payload.get(key)
# --- INPUT (user speech → STT transcript) ---
# Can arrive from upstream (server-side STT) — match either direction.
elif event_type == "conversation.item.input_audio_transcription.completed":
summary["transcript"] = payload.get("transcript", "")
summary["item_id"] = payload.get("item_id")
elif event_type == "conversation.item.created":
item = payload.get("item") if isinstance(payload.get("item"), dict) else None
if isinstance(item, dict):
summary["item_id"] = item.get("id")
summary["role"] = item.get("role")
summary["item_type"] = item.get("type")
summary["status"] = item.get("status")
content_parts = []
for c in (item.get("content") or []):
if isinstance(c, dict):
if c.get("type") in {"input_text", "text"} and isinstance(c.get("text"), str):
content_parts.append(c["text"])
elif c.get("type") == "transcript" and isinstance(c.get("transcript"), str):
content_parts.append(c["transcript"])
if content_parts:
summary["text"] = " ".join(content_parts)
# --- OUTPUT (agent text/speech generation) ---
elif event_type == "response.output_item.done":
item = payload.get("item") if isinstance(payload.get("item"), dict) else None
if isinstance(item, dict):
summary["item_id"] = item.get("id")
summary["role"] = item.get("role")
summary["status"] = item.get("status")
content_parts = []
for c in (item.get("content") or []):
if isinstance(c, dict):
if c.get("type") == "text" and isinstance(c.get("text"), str) and c["text"]:
content_parts.append(c["text"])
elif c.get("type") == "audio" and isinstance(c.get("transcript"), str) and c["transcript"]:
content_parts.append(c["transcript"])
if content_parts:
summary["text"] = " ".join(content_parts)
elif event_type == "response.content_part.done":
part = payload.get("part") if isinstance(payload.get("part"), dict) else None
if isinstance(part, dict):
summary["response_id"] = payload.get("response_id")
summary["item_id"] = payload.get("item_id")
summary["output_index"] = payload.get("output_index")
summary["content_index"] = payload.get("content_index")
if part.get("type") == "text":
summary["text"] = part.get("text", "")
elif part.get("type") == "audio":
if isinstance(part.get("transcript"), str) and part["transcript"]:
summary["text"] = part["transcript"]
# Variante standard OpenAI:
elif event_type == "response.audio_transcript.done":
summary["response_id"] = payload.get("response_id")
summary["item_id"] = payload.get("item_id")
summary["text"] = payload.get("transcript", "")
# Variante upstream custom (osservato nel log dell'utente):
elif event_type == "response.output_audio_transcript.done":
summary["response_id"] = payload.get("response_id")
summary["item_id"] = payload.get("item_id")
summary["output_index"] = payload.get("output_index")
# Try field names in order of likelihood
text = ""
for key in ("transcript", "text", "output_text", "audio_text",
"output_transcript", "final_transcript", "output_audio_text",
"content", "message", "utterance"):
v = payload.get(key)
if isinstance(v, str) and v.strip():
text = v.strip()
break
# Se text ancora vuoto, cerca all'interno di eventuali sotto-oggetti noti
if not text:
for container in ("item", "part", "content", "output", "delta", "audio"):
sub = payload.get(container)
if isinstance(sub, dict):
for key in ("transcript", "text", "output_text"):
v = sub.get(key)
if isinstance(v, str) and v.strip():
text = v.strip()
break
if text:
break
if not text:
# Ultima risorsa: content[] array
arr = payload.get("content")
if isinstance(arr, list):
parts = []
for c in arr:
if isinstance(c, dict):
for key in ("transcript", "text"):
v = c.get(key)
if isinstance(v, str) and v.strip():
parts.append(v.strip())
if parts:
text = " ".join(parts)
summary["text"] = text
# Se non abbiamo ancora trovato testo, salva un'anteprima del raw
# per capire dove lo sta emettendo l'upstream custom.
if not text:
preview = raw[:800]
try:
pretty = json.dumps(payload, ensure_ascii=True)[:800]
except Exception:
pretty = preview
summary["_raw_preview"] = pretty
elif event_type == "response.function_call_arguments.done":
summary["arguments"] = payload.get("arguments")
# Questo evento è il KEY CHECK della Strategia B: se lo vediamo =
# ai-server ha accettato tools[] nativi e chiama MCP Aquachile via protocollo.
_tool_name = payload.get("name") if isinstance(payload.get("name"), str) else ""
_call_id = payload.get("call_id") if isinstance(payload.get("call_id"), str) else ""
_args_json = payload.get("arguments") if isinstance(payload.get("arguments"), str) else "{}"
logger.info(
"[MCP INJECT] ✓ UPSTREAM ha emesso response.function_call_arguments.done! "
"tool=%s callId=%s argsLen=%d argsPreview=%s",
_tool_name or "(empty)",
_call_id or "-",
len(_args_json),
_args_json[:200],
)
try:
_args_parsed = json.loads(_args_json or "{}")
logger.info(
"[MCP INJECT] ✓ Tool call parsed argsKeys=%s",
sorted(_args_parsed.keys()) if isinstance(_args_parsed, dict) else "N/A",
)
except Exception:
pass
return summary
# Eventi realtime ad alta frequenza da silenziare nel log dettagliato (rumore).
# Essi vengono comunque tracciati dal report_server_debug interno se abilitato.
_NOISY_REALTIME_EVENT_TYPES = frozenset({
"response.output_audio.delta",
"response.audio.delta",
"conversation.item.input_audio_transcription.delta",
"response.text.delta",
"response.output_text.delta",
"rate_limits.updated",
})
# Eventi realtime silenziati anche quando arrivano dal lato cliente (input_audio_buffer.append ecc.).
_NOISY_CLIENT_EVENT_TYPES = frozenset({
"input_audio_buffer.append",
"input_audio_buffer.commit",
"input_audio_buffer.clear",
"input_audio_buffer.speech_started",
"input_audio_buffer.speech_stopped",
})
@app.on_event("startup")
async def _startup():
"""Stand up the usage DB and a periodic sweeper — metered (prod Space) only."""
if not LIMITER_ENABLED:
return
limiter.init()
asyncio.create_task(_sweeper())
async def _sweeper():
while True:
await asyncio.sleep(limiter.REAP_AFTER_SEC)
try:
await asyncio.to_thread(limiter.sweep)
except Exception as exc: # pragma: no cover - defensive
logger.warning("usage sweep failed: %r", exc)
class SearchRequest(BaseModel):
query: str
# Optional user-supplied key (fallback when the deploy has no server key).
# Used for this request only; never stored.
key: str | None = None
class McpToolCallRequest(BaseModel):
name: str
arguments: dict = {}
class ReasoningRequest(BaseModel):
transcript: str
instructions: str = ""
language: str = ""
user_context: str = ""
# Phone number of the caller (same as URL param). When present and the
# reasoning mode is NODE_RED, it is forwarded to Node-RED so that flows
# can fetch the caller profile via Aquachile /auth/user-by-phone.
phoneNumber: str | None = None
_agent_profile_lock = asyncio.Lock()
_agent_profile_cached: tuple[float, str, list[dict]] = (0.0, "", [])
_insights_lock = asyncio.Lock()
# cache: (cached_at_seconds, cache_date_str_YYYY_MM_DD, list[dict] | None, formatted_prompt_block_str)
_insights_cached: tuple[float, str, list[dict] | None, str] = (0.0, "", None, "")
async def _agent_profile_data() -> tuple[str, list[dict]]:
if not S2S_AGENT_PROFILE:
logger.debug("[EXT][AQUACHILE] agent_profile: endpoint not configured, skipping")
return "", []
now = asyncio.get_running_loop().time()
cached_at, cached_prompt, cached_tools = _agent_profile_cached
if (cached_prompt or cached_tools) and (now - cached_at) < 60:
logger.debug(
"[EXT][AQUACHILE] agent_profile: cache HIT age=%.1fs promptLen=%d toolCount=%d",
now - cached_at, len(cached_prompt), len(cached_tools),
)
return cached_prompt, cached_tools
async with _agent_profile_lock:
cached_at, cached_prompt, cached_tools = _agent_profile_cached
if (cached_prompt or cached_tools) and (now - cached_at) < 60:
return cached_prompt, cached_tools
logger.debug("[EXT][AQUACHILE] agent_profile GET %s (cache miss)", S2S_AGENT_PROFILE)
try:
async with httpx.AsyncClient(timeout=10.0) as http:
resp = await http.get(S2S_AGENT_PROFILE)
logger.debug(
"[EXT][AQUACHILE] agent_profile RESP status=%s len=%dB",
resp.status_code, len(resp.content or b""),
)
if resp.status_code != 200:
logger.warning("Agent profile fetch failed %s: %s", resp.status_code, resp.text[:300])
_set_agent_profile_cache(now, "", [])
return "", []
data = resp.json()
except Exception as exc:
logger.warning("Agent profile fetch failed: %r", exc)
_set_agent_profile_cache(now, "", [])
return "", []
prompt = _extract_agent_prompt(data)
tools = _extract_agent_tools(data)
logger.debug(
"[EXT][AQUACHILE] agent_profile PARSED promptLen=%d toolCount=%d toolNames=%s",
len(prompt), len(tools), [t.get("name") for t in tools if isinstance(t, dict)],
)
_set_agent_profile_cache(now, prompt, tools)
return prompt, tools
def _set_agent_profile_cache(ts: float, prompt: str, tools: list[dict]) -> None:
global _agent_profile_cached
_agent_profile_cached = (ts, prompt, tools)
def _set_insights_cache(ts: float, date_str: str, entries: list[dict] | None, formatted_block: str) -> None:
global _insights_cached
_insights_cached = (ts, date_str, entries, formatted_block)
def _format_insights_for_prompt(entries: list[dict]) -> str:
"""
Serializza una lista di insight Aquachile in formato testo leggibile
da appendere alle agent instructions. Priorità visuale: HIGH → MEDIUM → LOW.
Es. output:
### Contexto operativo del día (2026-08-25) — 18 insights:
1. [HIGH · Operations · Center: Arica · Jaula: C-07] Título breve
- Descrizione del insight (trunc 200c).
- Recomendación: azione consigliata (trunc 200c).
...
"""
if not entries:
return ""
today_str = datetime.now(timezone.utc).strftime("%Y-%m-%d")
_priority_order = {"HIGH": 0, "MEDIUM": 1, "LOW": 2}
try:
sorted_entries = sorted(
entries,
key=lambda e: (
_priority_order.get((e.get("priority") or "").upper(), 99),
e.get("createdAt") or "",
),
reverse=False,
)
except Exception:
sorted_entries = list(entries)
lines: list[str] = []
total = len(sorted_entries)
lines.append(f"### Contexto operativo del día ({today_str}) — {total} insights:")
for idx, e in enumerate(sorted_entries[:MAX_INSIGHTS_IN_CONTEXT], start=1):
if not isinstance(e, dict):
continue
priority = str(e.get("priority") or "UNKNOWN").upper()
audience = e.get("audience")
if isinstance(audience, list):
audience_str = "/".join(str(a) for a in audience if a)[:40]
elif isinstance(audience, str):
audience_str = audience[:40]
else:
audience_str = "General"
center = str(e.get("center") or "—")[:40]
jaula = str(e.get("jaula") or "—")[:24]
title = (e.get("title") or "(No title)").strip()
description = (e.get("description") or "").strip()
recommendation = (e.get("recommendation") or "").strip()
header = f"{idx}. [{priority} · {audience_str} · Centro: {center} · Jaula: {jaula}] {title}"
lines.append(header)
if description:
desc_trunc = description if len(description) <= 240 else description[:237] + "..."
lines.append(f" • Situación: {desc_trunc}")
if recommendation:
rec_trunc = recommendation if len(recommendation) <= 200 else recommendation[:197] + "..."
lines.append(f" • Recomendación: {rec_trunc}")
if total > MAX_INSIGHTS_IN_CONTEXT:
lines.append(
f" … ({total - MAX_INSIGHTS_IN_CONTEXT} insights adicionales omitidos para mantener el contexto compacto. "
f"Si el usuario necesita más detalles, puede consultarlos explícitamente via tool call list_recent_reports.)"
)
return "\n".join(lines).strip()
async def _fetch_insights_for_today() -> tuple[list[dict] | None, str]:
"""
Fetch diario degli insights Aquachile via GET S2S_INSIGHTS_URL con
start_date == end_date == oggi (UTC). Cache 60s TTL con anti-thundering-herd
lock, esattamente come _agent_profile_data. Ritorna (entries_list o None,
formatted_block_str). Se fallisce → ritorna (None, "") e logga WARNING
ma NON solleva eccezioni (never-block-audio).
"""
if not INSIGHTS_ENABLED:
return None, ""
today_str = datetime.now(timezone.utc).strftime("%Y-%m-%d")
now = asyncio.get_running_loop().time()
cached_at, cached_date, cached_entries, cached_block = _insights_cached
# Cache HIT solo se: stessa data di oggi e age < 60s
if cached_date == today_str and cached_block and (now - cached_at) < 60:
logger.debug(
"[INSIGHTS FETCH] cache HIT date=%s age=%.1fs entries=%d blockLen=%d",
cached_date, now - cached_at, len(cached_entries or []), len(cached_block),
)
return cached_entries, cached_block
async with _insights_lock:
cached_at, cached_date, cached_entries, cached_block = _insights_cached
if cached_date == today_str and cached_block and (now - cached_at) < 60:
return cached_entries, cached_block
url = S2S_INSIGHTS_URL.rstrip("/")
params = {"start_date": today_str, "end_date": today_str}
headers = {"Accept": "application/json"}
if S2S_INSIGHTS_API_KEY:
headers["X-API-KEY"] = S2S_INSIGHTS_API_KEY
if S2S_INSIGHTS_API_SECRET:
headers["X-API-SECRET"] = S2S_INSIGHTS_API_SECRET
logger.info(
"[INSIGHTS FETCH] → GET today=%s url=%s params=%s apiKey=%s",
today_str, url, json.dumps(params, ensure_ascii=True),
"set" if S2S_INSIGHTS_API_KEY else "not-set (public OK)",
)
try:
async with httpx.AsyncClient(timeout=15.0) as http:
resp = await http.get(url, params=params, headers=headers)
except Exception as exc:
logger.warning("[INSIGHTS FETCH] ERROR (continuo senza insights, non blocco audio): %r", exc)
_set_insights_cache(now, today_str, None, "")
return None, ""
logger.debug(
"[INSIGHTS FETCH] ← RESP status=%s len=%dB",
resp.status_code, len(resp.content or b""),
)
if resp.status_code != 200:
logger.warning(
"[INSIGHTS FETCH] HTTP %s (non 200, skip — non blocco audio). Preview body: %s",
resp.status_code, (resp.text or "")[:300],
)
_set_insights_cache(now, today_str, None, "")
return None, ""
try:
data = resp.json()
except Exception as exc:
logger.warning("[INSIGHTS FETCH] JSON parse fallito: %r. Body preview=%s", exc, (resp.text or "")[:300])
_set_insights_cache(now, today_str, None, "")
return None, ""
if isinstance(data, dict) and isinstance(data.get("insights"), list):
entries = [e for e in data["insights"] if isinstance(e, dict)]
elif isinstance(data, list):
entries = [e for e in data if isinstance(e, dict)]
else:
logger.warning(
"[INSIGHTS FETCH] formato response inatteso (keys=%s). Skip senza errori.",
sorted(data.keys()) if isinstance(data, dict) else type(data).__name__,
)
_set_insights_cache(now, today_str, None, "")
return None, ""
# Ordina e formatta per injection nel prompt.
priority_counts: dict[str, int] = {}
for e in entries:
p = str(e.get("priority") or "UNKNOWN").upper()
priority_counts[p] = priority_counts.get(p, 0) + 1
formatted_block = _format_insights_for_prompt(entries)
logger.info(
"[INSIGHTS FETCH] ✓ PARSED OK today=%s total=%d byPriority=%s formattedLen=%d maxCap=%d (truncated=%s)",
today_str,
len(entries),
json.dumps(priority_counts, ensure_ascii=True),
len(formatted_block),
MAX_INSIGHTS_IN_CONTEXT,
"YES" if len(entries) > MAX_INSIGHTS_IN_CONTEXT else "NO",
)
# Log dettaglio anteprima lista insights (title/priority/center) per auditoria
# INFO level: sempre visibile nel container (audit quali insights sono stati considerati).
_preview_cap = min(10, len(entries))
_preview_list = []
for e in entries[:_preview_cap]:
_preview_list.append(
{
"priority": str(e.get("priority") or "?").upper(),
"center": str(e.get("center") or "?")[:30],
"jaula": str(e.get("jaula") or "?")[:20],
"title": (str(e.get("title") or "?")[:80]),
}
)
# 👉 Pattern singolo %s + f-string: nessun rischio che % dentro agli insights
# (es. -1.65%) vengano interpretati come placeholder da logging — BUG FIX.
_msg_preview = (
f"[INSIGHTS FETCH] PREVIEW lista primi {_preview_cap}/{len(entries)} insights "
f"JSON={json.dumps(_preview_list, ensure_ascii=True)}"
)
logger.info("%s", _msg_preview)
_set_insights_cache(now, today_str, entries, formatted_block)
return entries, formatted_block
def _extract_agent_prompt(data) -> str:
try:
if isinstance(data, dict):
agent = data.get("agent")
if isinstance(agent, dict):
desc = agent.get("instructions")
if isinstance(desc, str):
return desc.strip()
desc = agent.get("description")
if isinstance(desc, str):
return desc.strip()
desc = data.get("instructions")
if isinstance(desc, str):
return desc.strip()
desc = data.get("description")
if isinstance(desc, str):
return desc.strip()
except Exception:
return ""
return ""
def _extract_agent_tools(data) -> list[dict]:
try:
if isinstance(data, dict):
agent = data.get("agent")
if isinstance(agent, dict):
tools = agent.get("tools")
if isinstance(tools, list):
return [tool for tool in tools if isinstance(tool, dict) and tool.get("enabled", True)]
except Exception:
return []
return []
def _normalize_tools_for_realtime(raw_tools: list[dict]) -> list[dict]:
"""
Converte tool definitions Aquachile (qualsiasi variante di struttura) in
formato OpenAI Realtime API GA standard, valido per session.update -> tools[].
Formato atteso Realtime API (ogni tool):
{
"type": "function", # fisso, unico supportato oggi
"name": "snake_case_tool_name", # <64 chars, a-z0-9_
"description": "frase che spiega quando usarlo", # stringa, NOT null
"parameters": { # JSON Schema Object, MAY BE {} vuoto
"type": "object",
"properties": { "arg1": {"type":"string","description":"…"}, … },
"required": ["arg1"] # (opzionale, array di stringhe)
}
}
Ritorna SEMPRE list[dict] (non torna mai None, non alza eccezioni).
Tool invalidi vengono saltati con logger.warning ma non bloccano gli altri.
"""
normalized: list[dict] = []
seen_names: set[str] = set()
if not isinstance(raw_tools, list):
return normalized
for idx, tool in enumerate(raw_tools):
if not isinstance(tool, dict):
logger.warning("[MCP TOOLS] skip tool at index %s: not a dict (got %s)", idx, type(tool).__name__)
continue
name = ""
for key in ("name", "function_name", "toolName", "id"):
val = tool.get(key)
if isinstance(val, str) and val.strip():
name = val.strip()
break
if not name:
logger.warning("[MCP TOOLS] skip tool at index %s: missing name keys=%s", idx, sorted(tool.keys()))
continue
# sanitize nome -> solo [a-z0-9_] (regex OpenAI)
clean_name = re.sub(r"[^a-zA-Z0-9_]", "_", name).lower().strip("_")
if not clean_name:
clean_name = f"tool_{idx}"
if clean_name in seen_names:
clean_name = f"{clean_name}_{idx}"
seen_names.add(clean_name)
description = ""
for key in ("description", "desc", "summary", "instructions", "purpose"):
val = tool.get(key)
if isinstance(val, str) and val.strip():
description = val.strip()
break
if not description:
description = f"Tool {clean_name}"
# parameters JSON Schema
raw_params = None
for key in ("parameters", "params", "input_schema", "schema", "argument_schema"):
val = tool.get(key)
if isinstance(val, dict) and val:
raw_params = val
break
parameters: dict
if raw_params:
parameters = dict(raw_params)
parameters.setdefault("type", "object")
if "properties" not in parameters or not isinstance(parameters["properties"], dict):
parameters["properties"] = {}
if "required" in parameters and not isinstance(parameters["required"], list):
parameters["required"] = []
else:
# parametri assenti: oggetto vuoto permesso da Realtime API
parameters = {"type": "object", "properties": {}}
normalized.append({
"type": "function",
"name": clean_name,
"description": description,
"parameters": parameters,
})
logger.debug(
"[MCP TOOLS] normalized count=%d raw_count=%d names=%s",
len(normalized), len(raw_tools), [t["name"] for t in normalized][:10],
)
return normalized
def _mcp_headers() -> dict[str, str]:
headers = {
"Content-Type": "application/json",
"Accept": "application/json, text/event-stream",
}
if S2S_TOOL_EXECUTION_MCP_API_KEY:
headers["X-API-KEY"] = S2S_TOOL_EXECUTION_MCP_API_KEY
if S2S_TOOL_EXECUTION_MCP_API_SECRET:
headers["X-API-SECRET"] = S2S_TOOL_EXECUTION_MCP_API_SECRET
return headers
def _parse_mcp_response(body: str) -> dict:
text = (body or "").strip()
if not text:
return {}
if text.startswith("{"):
try:
parsed = json.loads(text)
return parsed if isinstance(parsed, dict) else {}
except Exception:
return {}
for chunk in text.split("\n\n"):
for line in chunk.splitlines():
if line.startswith("data: "):
payload = line[6:].strip()
try:
parsed = json.loads(payload)
return parsed if isinstance(parsed, dict) else {}
except Exception:
return {}
return {}
def _url_with_query(url: str, **params: str) -> str:
target = urlsplit(url)
merged_query = dict(parse_qsl(target.query, keep_blank_values=True))
for key, value in params.items():
if value:
merged_query[key] = value
return urlunsplit(
(
target.scheme,
target.netloc,
target.path,
urlencode(merged_query, doseq=True),
target.fragment,
)
)
def _openai_headers() -> dict[str, str]:
if not OPENAI_API_KEY:
raise RuntimeError("OPENAI_API_KEY is not configured.")
headers = {
"Authorization": f"Bearer {OPENAI_API_KEY}",
"Content-Type": "application/json",
}
if OPENAI_ORGANIZATION:
headers["OpenAI-Organization"] = OPENAI_ORGANIZATION
if OPENAI_PROJECT:
headers["OpenAI-Project"] = OPENAI_PROJECT
return headers
def _effective_s2s_url(request: Request) -> str:
return SPEECH_TO_SPEECH_URL or _proxy_public_url(request)
@app.get("/api/config")
async def config(request: Request):
"""Client bootstrap: whether web search is available, whether the deploy runs
behind a load balancer (so the browser uses the /api/session proxy + limiter),
whether HF sign-in is available, and whether the user may instead set a direct
s2s server URL. The LB address itself is intentionally NOT included."""
logger.debug("[INTERNAL] /api/config requested client=%s", request.client.host if request.client else "?")
agent_prompt, agent_tools_raw = await _agent_profile_data()
# ⛔ MCP MASTER DISABLE: se S2S_TOOL_EXECUTION_MCP_URL non è in .env
# nascondi catalogo 79 tool ANCHE lato client (evita ranking/pulsanti che fallirebbero 503)
if MCP_EXEC_ENABLED:
agent_tools_for_client = agent_tools_raw
search_mcp_for_client = bool(S2S_SEARCH_MCP)
else:
agent_tools_for_client = []
search_mcp_for_client = False
primary_prompt = agent_prompt or S2S_PRIMARY_PROMPT
out = {
"search": bool(SERPER_KEY),
"lb": bool(LOAD_BALANCER_URL),
"allowDirect": not LOAD_BALANCER_URL,
# Deploy-pinned direct s2s URL (empty when unset). Not a secret: the
# browser dials it itself, and Settings shows it locked.
"s2sUrl": _effective_s2s_url(request),
"primaryPrompt": primary_prompt,
"agentProfile": S2S_AGENT_PROFILE,
"agentTools": agent_tools_for_client,
"searchMcp": search_mcp_for_client,
"reasoningType": S2S_REASONING_TYPE,
"auth": AUTH_ENABLED,
}
logger.debug(
"[INTERNAL] /api/config returned promptLen=%d toolCount=%d (raw=%d before master gate) reasoning=%s searchMcp=%s MCP_EXEC_ENABLED=%s",
len(primary_prompt),
len(agent_tools_for_client),
len(agent_tools_raw),
S2S_REASONING_TYPE,
search_mcp_for_client,
MCP_EXEC_ENABLED,
)
return out
@app.get("/api/user/phone")
async def user_by_phone(phoneNumber: str = ""):
phone_number = phoneNumber.strip()
if not phone_number:
raise HTTPException(status_code=400, detail="phoneNumber is required.")
if not VOCERO_USER_PHONE_AUTH_URL:
raise HTTPException(status_code=503, detail="VOCERO_USER_PHONE_AUTH_URL is not configured.")
target_url = _url_with_query(VOCERO_USER_PHONE_AUTH_URL, phoneNumber=phone_number)
logger.info("[Vocero USER AUTH] phoneNumber=%s target=%s", phone_number, target_url)
logger.debug("[EXT][AQUACHILE] user_by_phone GET %s", target_url)
try:
async with httpx.AsyncClient(timeout=20.0) as http:
resp = await http.get(target_url, headers={"Accept": "application/json"})
except httpx.RequestError as exc:
logger.warning("User phone auth failed: %r", exc)
raise HTTPException(status_code=502, detail="User phone auth unreachable.")
logger.debug(
"[EXT][AQUACHILE] user_by_phone RESP status=%s len=%dB",
resp.status_code, len(resp.content or b""),
)
if resp.status_code != 200:
logger.warning("User phone auth failed %s: %s", resp.status_code, resp.text[:400])
raise HTTPException(status_code=502, detail=f"User phone auth failed ({resp.status_code}).")
try:
payload = resp.json()
except Exception:
logger.warning("User phone auth returned invalid JSON: %s", resp.text[:400])
raise HTTPException(status_code=502, detail="User phone auth returned invalid JSON.")
logger.info("[Vocero USER AUTH] phoneNumber=%s preview=%s", phone_number, json.dumps(payload, ensure_ascii=True)[:800])
if isinstance(payload, dict):
logger.debug(
"[EXT][AQUACHILE] user_by_phone PARSED keys=%s",
sorted(payload.keys()),
)
return JSONResponse({"result": payload})
@app.post("/api/mcp/tool")
async def mcp_tool(req: McpToolCallRequest):
if not MCP_EXEC_ENABLED:
logger.warning(
"[MCP DISABLED] ⛔ /api/mcp/tool called but S2S_TOOL_EXECUTION_MCP_URL is empty/commented in .env. "
"Rejecting with 503. name=%s args=%s",
req.name,
json.dumps(req.arguments or {}, ensure_ascii=True)[:200],
)
raise HTTPException(
status_code=503,
detail="MCP tool execution is disabled: S2S_TOOL_EXECUTION_MCP_URL is not configured in .env.",
)
target = S2S_TOOL_EXECUTION_MCP_URL.rstrip("/") + "/"
body = {
"jsonrpc": "2.0",
"id": 1,
"method": "tools/call",
"params": {
"name": req.name,
"arguments": req.arguments or {},
},
}
args_json = json.dumps(req.arguments or {}, ensure_ascii=True)
logger.info(
"[Vocero MCP CALL] name=%s target=%s args=%s",
req.name, target, args_json[:800],
)
logger.debug(
"[EXT][AQUACHILE] mcp_tool POST %s method=%s tool=%s argsLen=%dB body=%s",
target, body["method"], req.name, len(args_json),
json.dumps(body, ensure_ascii=True)[:800],
)
try:
async with httpx.AsyncClient(timeout=45.0) as http:
resp = await http.post(
target,
headers=_mcp_headers(),
json=body,
)
except httpx.RequestError as exc:
logger.warning("MCP tool call failed: %r", exc)
raise HTTPException(status_code=502, detail="MCP tool execution unreachable.")
logger.info("[Vocero MCP HTTP] name=%s status=%s", req.name, resp.status_code)
logger.debug(
"[EXT][AQUACHILE] mcp_tool RESP tool=%s status=%s len=%dB raw=%s",
req.name, resp.status_code, len(resp.content or b""), (resp.text or "")[:800],
)
if resp.status_code != 200:
logger.warning("MCP tool call failed %s: %s", resp.status_code, resp.text[:400])
raise HTTPException(status_code=502, detail=f"MCP tool execution failed ({resp.status_code}).")
payload = _parse_mcp_response(resp.text)
if payload.get("error"):
message = payload["error"].get("message") if isinstance(payload["error"], dict) else "MCP tool execution failed."
logger.warning("[Vocero MCP OUT] name=%s error=%s", req.name, message)
raise HTTPException(status_code=502, detail=message or "MCP tool execution failed.")
result = payload.get("result")
result_json = json.dumps(result, ensure_ascii=True) if result is not None else "null"
logger.info("[Vocero MCP OUT] name=%s preview=%s", req.name, result_json[:800])
logger.debug(
"[EXT][AQUACHILE] mcp_tool PARSED tool=%s resultKeys=%s resultLen=%dB",
req.name,
sorted(result.keys()) if isinstance(result, dict) else "N/A",
len(result_json),
)
return JSONResponse({"result": result})
@app.post("/api/reasoning")
async def reasoning(req: ReasoningRequest):
if S2S_REASONING_TYPE == "PROXY":
raise HTTPException(status_code=409, detail="Reasoning endpoint is disabled in PROXY mode.")
transcript = (req.transcript or "").strip()
if not transcript:
raise HTTPException(status_code=400, detail="transcript is required.")
# ────────────────────────────────────────────────────────────────────
# Modalità A: NODE_RED — inoltra TUTTO il payload a Node-RED
# Il flow Node-RED decide autonomamente.
# FASE 1 (LOG-ONLY): Node-RED risponde con {answer: "", log_only: true}
# => il client (main.js) NON interferisce, lascia parlare il backend S2S.
# FASI successive: Node-RED produce {answer: "...", log_only: false}
# Risposta attesa: {answer, log_only?, usage, debug, latency_ms, …}
# ────────────────────────────────────────────────────────────────────
if S2S_REASONING_TYPE == "NODE_RED":
if not NODE_RED_REASONING_URL:
raise HTTPException(
status_code=503,
detail="S2S_REASONING_NODE_RED_URL is not configured. Set the env var to the Node-RED endpoint (e.g. http://localhost:1881).",
)
upstream_body = {
"transcript": transcript,
"instructions": (req.instructions or "").strip(),
"language": (req.language or "").strip(),
"user_context": (req.user_context or "").strip(),
"phoneNumber": (req.phoneNumber or "").strip() or None,
}
_instructions_str = upstream_body["instructions"] or ""
_has_mcp_search_hint = "Available MCP tools:" in _instructions_str
_has_ranking_hint = "Client-side ranking hint only:" in _instructions_str
_top3_suggested = []
if _has_ranking_hint:
_rank_chunk = None
for _sep in [". Use this hint", " Use this hint", " — Use this hint", ". Use it only", "\nUser profile:", "\nCurrent date:", " Use "]:
_pos = _instructions_str.find(_sep, _instructions_str.find("Client-side ranking hint only:"))
if _pos > 0:
_start = _instructions_str.find("Client-side ranking hint only:") + len("Client-side ranking hint only:")
_rank_chunk = _instructions_str[_start:_pos].strip(" \n\t:-—.")
break
if _rank_chunk is None:
_start = _instructions_str.find("Client-side ranking hint only:") + len("Client-side ranking hint only:")
_rank_chunk = _instructions_str[_start:_start + 1500].strip()
for _rm in re.finditer(r"\s*(\d+)\.\s*([^::]+?)[::]\s*", _rank_chunk):
_rn = int(_rm.group(1))
_nm = _rm.group(2).strip(" \n\t`*•")
_rest_start = _rm.end()
_rest_chunk = _rank_chunk[_rest_start:_rest_start + 300]
_next_match = re.search(r"\s*\d+\.\s*[^::]+?[::]\s*", _rest_chunk)
if _next_match:
_descr = _rest_chunk[:_next_match.start()].strip(" \n\t;.,—-")
else:
_descr = _rest_chunk.strip(" \n\t;.,—-")
if _nm:
_top3_suggested.append({"rank": _rn, "name": _nm, "description": _descr[:80]})
_mcp_catalog_len = 0
if _has_mcp_search_hint:
_cat_start = _instructions_str.find("Available MCP tools:") + len("Available MCP tools:")
_cat_end_candidates = [
_instructions_str.find(_s, _cat_start) for _s in
[" Current user request:", "\nCurrent user request:", " Current user request\n", " User profile:", "\nUser profile:", " When the user's request", " Use "]
]
_cat_end_candidates = [_p for _p in _cat_end_candidates if _p > _cat_start]
_cat_end = min(_cat_end_candidates) if _cat_end_candidates else (_cat_start + 20000)
_cat_chunk = _instructions_str[_cat_start:_cat_end].strip(" \n\t:.,—-")
_semicolon_count = _cat_chunk.count("; ")
if _semicolon_count:
_mcp_catalog_len = _semicolon_count + 1
else:
_tool_mentions = re.findall(r"\b[a-zA-Z_][a-zA-Z0-9_]{2,50}\b\s*:\s", _cat_chunk)
_mcp_catalog_len = len(_tool_mentions)
logger.info(
"[MCP RANK] reasoning payload transcript=%s instructionsLen=%d hasMcpCatalogHint=%s hasRankingHint=%s mcpCatalogTools=%d top3Suggested=%s",
transcript[:200],
len(_instructions_str),
_has_mcp_search_hint,
_has_ranking_hint,
_mcp_catalog_len,
json.dumps(_top3_suggested, ensure_ascii=True) if _top3_suggested else "none",
)
logger.debug(
"[EXT][NODE_RED] reasoning POST %s/api/reasoning lang=%s transcriptLen=%d phone=%s",
NODE_RED_REASONING_URL,
(req.language or "")[:20] or "auto",
len(transcript),
(req.phoneNumber or "")[:16] or "none",
)
try:
async with httpx.AsyncClient(timeout=120.0) as http:
resp = await http.post(
f"{NODE_RED_REASONING_URL}/api/reasoning",
json=upstream_body,
headers={
"Content-Type": "application/json",
"X-S2S-Caller": "demo-server",
},
)
except httpx.RequestError as exc:
logger.warning("[EXT][NODE_RED] unreachable: %r", exc)
raise HTTPException(status_code=502, detail="Node-RED reasoning engine is unreachable.")
logger.debug(
"[EXT][NODE_RED] reasoning RESP status=%s len=%dB",
resp.status_code, len(resp.content or b""),
)
if resp.status_code != 200:
logger.warning("[EXT][NODE_RED] failed %s: %s", resp.status_code, resp.text[:500])
raise HTTPException(
status_code=502,
detail=f"Node-RED reasoning failed (HTTP {resp.status_code}).",
)
try:
payload = resp.json()
except Exception:
logger.warning("[EXT][NODE_RED] invalid JSON: %s", resp.text[:500])
raise HTTPException(status_code=502, detail="Node-RED returned invalid JSON.")
answer = payload.get("answer") if isinstance(payload, dict) else None
log_only = bool(isinstance(payload, dict) and payload.get("log_only") is True)
if not isinstance(answer, str):
logger.warning("[EXT][NODE_RED] invalid answer type: %s", json.dumps(payload, ensure_ascii=True)[:800])
raise HTTPException(status_code=502, detail="Node-RED returned invalid answer field.")
answer_stripped = answer.strip()
# ── Log-only mode: answer vuota + flag log_only sono L'INTENZIONE ──
# Non solleviamo errore; il flag viene inoltrato al client.
if not answer_stripped and not log_only:
logger.warning("[EXT][NODE_RED] empty answer and !log_only: %s", json.dumps(payload, ensure_ascii=True)[:800])
raise HTTPException(status_code=502, detail="Node-RED returned no answer without log_only flag.")
usage = payload.get("usage") if isinstance(payload, dict) else None
if isinstance(usage, dict):
logger.debug(
"[EXT][NODE_RED] reasoning USAGE prompt=%d completion=%d total=%d",
usage.get("prompt_tokens", 0), usage.get("completion_tokens", 0), usage.get("total_tokens", 0),
)
extra = {}
for key in ("latency_ms", "intent", "mcp_tools_used", "caller_profile_keys", "debug"):
if isinstance(payload, dict) and key in payload:
extra[key] = payload[key]
if log_only:
logger.info(
"[Vocero REASONING] engine=NODE_RED mode=LOG_ONLY transcript=%s extra=%s",
transcript[:300],
json.dumps({k: v for k, v in extra.items() if k != "debug"}, ensure_ascii=True)[:400],
)
else:
logger.info(
"[Vocero REASONING] engine=NODE_RED transcript=%s answer=%s extra=%s",
transcript[:300], answer_stripped[:500],
json.dumps({k: v for k, v in extra.items() if k != "debug"}, ensure_ascii=True)[:400],
)
out = {"answer": answer_stripped}
if log_only:
out["log_only"] = True
if usage:
out["usage"] = usage
out.update({k: v for k, v in extra.items() if k != "debug" or logger.level <= logging.DEBUG})
return JSONResponse(out)
# ────────────────────────────────────────────────────────────────────
# Modalità B: OPENAI — chiamata diretta a OpenAI Chat Completions
# ────────────────────────────────────────────────────────────────────
if not OPENAI_API_KEY:
raise HTTPException(status_code=503, detail="OPENAI_API_KEY is not configured.")
system_parts = []
instructions = (req.instructions or "").strip()
if instructions:
system_parts.append(instructions)
if req.user_context.strip():
system_parts.append(f"User context:\n{req.user_context.strip()}")
if req.language.strip():
system_parts.append(
"Reply only with the final assistant answer text. "
f"Keep the answer natural and concise in this language: {req.language.strip()}."
)
else:
system_parts.append("Reply only with the final assistant answer text. Keep the answer natural and concise.")
body = {
"model": OPENAI_REASONING_MODEL,
"messages": [
{"role": "system", "content": "\n\n".join(system_parts)},
{"role": "user", "content": transcript},
],
}
logger.debug(
"[EXT][OPENAI] reasoning POST %s/chat/completions model=%s systemLen=%d transcriptLen=%d language=%s",
OPENAI_BASE_URL, OPENAI_REASONING_MODEL,
len(system_parts[0]) if system_parts else 0, len(transcript),
(req.language or "")[:20] or "auto",
)
try:
async with httpx.AsyncClient(timeout=30.0) as http:
resp = await http.post(
f"{OPENAI_BASE_URL}/chat/completions",
headers=_openai_headers(),
json=body,
)
except httpx.RequestError as exc:
logger.warning("OpenAI reasoning unreachable: %r", exc)
raise HTTPException(status_code=502, detail="OpenAI reasoning unreachable.")
logger.debug(
"[EXT][OPENAI] reasoning RESP status=%s len=%dB",
resp.status_code, len(resp.content or b""),
)
if resp.status_code != 200:
logger.warning("OpenAI reasoning failed %s: %s", resp.status_code, resp.text[:400])
raise HTTPException(status_code=502, detail=f"OpenAI reasoning failed ({resp.status_code}).")
try:
payload = resp.json()
except Exception:
logger.warning("OpenAI reasoning returned invalid JSON: %s", resp.text[:400])
raise HTTPException(status_code=502, detail="OpenAI reasoning returned invalid JSON.")
answer = ""
choices = payload.get("choices")
if isinstance(choices, list) and choices:
message = choices[0].get("message") if isinstance(choices[0], dict) else None
if isinstance(message, dict):
content = message.get("content")
if isinstance(content, str):
answer = content.strip()
usage = payload.get("usage")
if isinstance(usage, dict):
logger.debug(
"[EXT][OPENAI] reasoning USAGE prompt=%d completion=%d total=%d",
usage.get("prompt_tokens", 0), usage.get("completion_tokens", 0), usage.get("total_tokens", 0),
)
if not answer:
logger.warning("OpenAI reasoning returned empty answer: %s", json.dumps(payload, ensure_ascii=True)[:800])
raise HTTPException(status_code=502, detail="OpenAI reasoning returned no answer.")
logger.info("[Vocero REASONING] engine=OPENAI transcript=%s answer=%s", transcript[:300], answer[:500])
return JSONResponse({"answer": answer})
async def _forward_agent_text_to_nodered(payload: dict) -> None:
"""Fire-and-forget: inoltra la risposta TTS del backend nativo a Node-RED
(endpoint /api/log/system-response) per il logging della FASE 1.
Se Node-RED è down o non è configurato: silent ignore, non propagare errori
al realtime loop (non vogliamo bloccare la connessione WS)."""
if S2S_REASONING_TYPE != "NODE_RED" or not NODE_RED_REASONING_URL:
return
url = f"{NODE_RED_REASONING_URL}/api/log/system-response"
logger.debug(
"[EXT][NODE_RED] forward system-response POST %s len=%d source=%s",
NODE_RED_REASONING_URL,
len(str(payload.get("tts", "")) or 0),
payload.get("source_event") or "-",
)
try:
async with httpx.AsyncClient(timeout=5.0) as http:
resp = await http.post(
url,
json=payload,
headers={
"Content-Type": "application/json",
"X-S2S-Caller": "demo-server",
},
)
if resp.status_code != 200:
logger.debug(
"[EXT][NODE_RED] forward system-response non-200 status=%s body=%s",
resp.status_code,
(resp.text or "")[:300],
)
except httpx.RequestError as exc:
logger.debug("[EXT][NODE_RED] forward system-response unreachable: %r", exc)
except Exception as exc: # noqa: BLE001 — vogliamo non bloccare mai
logger.debug("[EXT][NODE_RED] forward system-response unexpected: %r", exc)
@app.websocket("/v1/realtime")
async def realtime_proxy(ws: WebSocket):
"""Relay the browser's same-origin realtime WebSocket to the configured upstream."""
client_ip = ws.client.host if ws.client else "?"
if not S2S_PROXY_TARGET:
logger.debug("[EXT][S2S-PROXY] client=%s rejected: S2S_PROXY_TARGET not configured", client_ip)
await ws.accept()
await ws.close(code=1013, reason="Realtime proxy not configured.")
return
await ws.accept()
upstream_url = _proxy_upstream_url(ws)
subprotocols = _subprotocols(ws)
logger.debug(
"[EXT][S2S-PROXY] client=%s CONNECT upstream=%s subprotocols=%s",
client_ip, upstream_url, subprotocols,
)
try:
async with websockets.connect(
upstream_url,
subprotocols=subprotocols or None,
open_timeout=15,
max_size=None,
) as upstream:
logger.debug("[EXT][S2S-PROXY] client=%s upstream TUNNEL ESTABLISHED", client_ip)
# ── Inject strumenti MCP Aquachile + istruzioni agente a S2S upstream ──
# Prima dei task di streaming: session.update con tools[] e instructions
# native. Se l'upstream supporta il formato → emette response.function_call_arguments.done
# e la catena toolcall nativa del client si attiva automaticamente.
#
# ★ FORMATO CORRETTO OpenAI Realtime GA Standard:
# {"type":"session.update","session":{"instructions":"…","tools":[…],"tool_choice":"auto"}}
# I campi sono SEMPRE annidati dentro "session": Pydantic strict reject extra fields
# se li metti alla radice, causando "Unknown or invalid event: session.update".
try:
_agent_prompt, _agent_raw_tools = await _agent_profile_data()
if MCP_EXEC_ENABLED:
_realtime_tools = _normalize_tools_for_realtime(_agent_raw_tools)
else:
_realtime_tools = []
logger.info(
"[MCP INJECT] ⛔ SKIPPED tool injection (MCP_EXEC_ENABLED=False — S2S_TOOL_EXECUTION_MCP_URL not set in .env). "
"Sending only instructions, no tools[]. Agent prompt length=%d.",
len(_agent_prompt or ""),
)
# --- Insight diario Aquachile → append a instructions ---
_insights_entries: list[dict] | None = None
_insights_block: str = ""
if INSIGHTS_ENABLED:
try:
_insights_entries, _insights_block = await _fetch_insights_for_today()
except Exception as _insights_err:
# NON bloccare mai la sessione audio per fallimento insights fetch
logger.warning(
"[INSIGHTS APPEND] eccezione in _fetch_insights_for_today (ignorata, continuo senza insights): %r",
_insights_err,
)
_insights_entries, _insights_block = None, ""
else:
logger.debug(
"[INSIGHTS APPEND] skipped (INSIGHTS_ENABLED=False — S2S_INSIGHTS_URL vuoto/non settato in .env)."
)
# --- Merge finale instructions: profilo agente + insights diario ---
if _agent_prompt and _insights_block:
_final_instructions = (
_agent_prompt.rstrip() + "\n\n" + _insights_block + "\n"
)
elif _agent_prompt:
_final_instructions = _agent_prompt.strip()
elif _insights_block:
_final_instructions = _insights_block
else:
_final_instructions = ""
_insights_count_for_log = len(_insights_entries) if _insights_entries else 0
if _insights_block:
logger.info(
"[INSIGHTS APPEND] ✓ aggiunti %d insights al contesto agente (blockLen=%d, truncated=%s). "
"Ora l'assistente dispone del contexto operativo del día UTC=%s.",
_insights_count_for_log,
len(_insights_block),
"YES" if _insights_entries and len(_insights_entries) > MAX_INSIGHTS_IN_CONTEXT else "NO",
datetime.now(timezone.utc).strftime("%Y-%m-%d"),
)
# 📝 Log ESATTO del blocco che viene passato nel session.instructions
# (prime ~45 righe o ~3500 chars per auditoria; non tronca MAI l'header).
_all_ins_lines = _insights_block.splitlines()
_cap_chars = 3500
_cap_lines = min(45, len(_all_ins_lines))
_truncated_preview = False
_joined = "\n".join(_all_ins_lines[:_cap_lines])
if len(_joined) > _cap_chars:
_joined = _joined[:_cap_chars].rsplit("\n", 1)[0]
if len(_all_ins_lines) > _cap_lines or len(_insights_block) > _cap_chars:
_truncated_preview = True
_shown_lines = _cap_lines if _truncated_preview else len(_all_ins_lines)
_shown_chars = len(_joined) if _truncated_preview else len(_insights_block)
_trunc_msg = (
" [TRUNCATED — per vedere tutto imposta MAX_INSIGHTS_IN_CONTEXT maggiore "
"oppure consulta endpoint /api/v1/insights]"
if _truncated_preview else ""
)
# 👉 Pattern singolo %s + f-string: ELIMINA DEFUNTIVAMENTE il bug
# TypeError: not enough arguments for format string (mismatch args/placeholder)
# e protegge da qualsiasi % dentro gli insights (es. "-1.65%" -36.34%").
_msg_append = (
f"[INSIGHTS APPEND] 📋 TESTO INJETTATO NEL PROMPT agent instructions"
f"{_trunc_msg} "
f"(lines={_shown_lines}/{len(_all_ins_lines)}, "
f"chars={_shown_chars}/{len(_insights_block)}, "
f"capChunks=45lines/3500chars):"
f"\n{_joined}"
)
logger.info("%s", _msg_append)
elif INSIGHTS_ENABLED:
logger.info(
"[INSIGHTS APPEND] SKIP (INSIGHTS_ENABLED=True ma nessun insight disponibile oggi "
"oppure fetch fallito per endpoint non raggiungibile. Non è un errore bloccante: "
"le istruzioni agente contengono solo il profilo standard)."
)
# unisci instructions: profilo agente Aquachile + default esistente da client
# (il client manderà un secondo session.update con le proprie;
# upstream le mergea. Per sicurezza mandiamo prima il profilo server-side)
_inject_payload: dict = {"type": "session.update", "session": {}}
_session_inner = _inject_payload["session"]
if _final_instructions.strip():
_session_inner["instructions"] = _final_instructions.strip()
if _realtime_tools:
_session_inner["tools"] = _realtime_tools
_session_inner["tool_choice"] = "auto"
# cap: se 100+ tool upstream potrebbe rifiutare: log warning ma non falliamo
if len(_realtime_tools) > 80:
logger.warning(
"[MCP INJECT] troppi tools (%d) — upstream potrebbe rifiutare. "
"Se non vedi response.function_call_arguments.done prova a ridurre con S2S_REASONING_NODE_RED_MAX_TOOLS o filtro lato Aquachile.",
len(_realtime_tools),
)
logger.info(
"[MCP INJECT] session.update upstream → client=%s tools=%d hasAgentPrompt=%s tool_choice=%s insights=%d fmt=nested_session",
client_ip,
len(_realtime_tools),
bool(_agent_prompt.strip()),
_session_inner.get("tool_choice", "none"),
_insights_count_for_log,
)
if _realtime_tools:
logger.debug(
"[MCP INJECT] tool names preview=%s",
json.dumps([t["name"] for t in _realtime_tools][:20], ensure_ascii=True),
)
await upstream.send(json.dumps(_inject_payload, ensure_ascii=True))
logger.info("[MCP INJECT] ✓ session.update upstream inviato (tools=%d, insights=%d, fmt=nested_session OK)", len(_realtime_tools), _insights_count_for_log)
except Exception as _inject_err:
# NON blocchiamo mai l'audio per fallimento inject tools
logger.warning(
"[MCP INJECT] FAILED (ignored, continuo senza tools nativi): %r",
_inject_err,
)
session_ctx = {
"last_user_transcript": "",
"last_item_id": None,
# 🔥 FIX RACE CONDITION session.update: servono a _client_to_upstream
# per mergiare profile+insights+tools IN OGNI session.update CHE
# ARRIVA DAL CLIENT (invece di fare solo inject upfront che
# viene SOVRASCRITTO dal 2ndo session.update del browser 200ms dopo).
"mcp_agent_prompt": _agent_prompt or "",
"mcp_insights_block": _insights_block or "",
"mcp_realtime_tools": _realtime_tools,
}
client_to_upstream = asyncio.create_task(
_client_to_upstream(ws, upstream, client_ip, session_ctx)
)
upstream_to_client = asyncio.create_task(
_upstream_to_client(ws, upstream, client_ip, session_ctx)
)
done, pending = await asyncio.wait(
{client_to_upstream, upstream_to_client},
return_when=asyncio.FIRST_COMPLETED,
)
for task in pending:
task.cancel()
await asyncio.gather(*pending, return_exceptions=True)
for task in done:
exc = task.exception()
if exc:
raise exc
except WebSocketDisconnect:
logger.debug("[EXT][S2S-PROXY] client=%s disconnected (WSDisconnect)", client_ip)
return
except Exception as exc:
logger.warning("Realtime proxy failed: %r", exc)
logger.debug("[EXT][S2S-PROXY] client=%s ERROR %s", client_ip, type(exc).__name__)
try:
await ws.close(code=1011, reason="Upstream realtime unavailable.")
except Exception:
pass
finally:
logger.debug("[EXT][S2S-PROXY] client=%s TUNNEL CLOSED", client_ip)
@app.get("/api/me")
async def me(request: Request):
"""Login state, tier, and remaining daily budget. Only meaningful in LB mode;
sets the anonymous tracking cookie when first seen."""
client_ip = request.client.host if request.client else "?"
logger.debug(
"[INTERNAL] /api/me client=%s LIMITER=%s",
client_ip, LIMITER_ENABLED,
)
if not LIMITER_ENABLED:
return {"enabled": False}
view = auth.user_view(request)
tier, keys, set_cookie = auth.resolve_identity(request)
unlimited = limiter.budget_for(tier) is None
rem = None if unlimited else await asyncio.to_thread(limiter.remaining, keys, tier)
logger.debug(
"[INTERNAL] /api/me client=%s tier=%s unlimited=%s remaining=%s setCookie=%s",
client_ip, tier, unlimited, rem, bool(set_cookie),
)
out = {
"enabled": True,
"auth": AUTH_ENABLED,
**view,
"remainingSec": rem,
"limitSec": limiter.budget_for(tier),
"loginUrl": auth.OAUTH_LOGIN_PATH if AUTH_ENABLED else None,
"logoutUrl": auth.OAUTH_LOGOUT_PATH if AUTH_ENABLED else None,
}
resp = JSONResponse(out)
if set_cookie:
auth.set_anon_cookie(resp, set_cookie)
return resp
@app.post("/api/search")
async def search(req: SearchRequest):
"""Proxy a Google search via Serper.dev. The key stays on the server unless
the user brought their own (then theirs is used for this request only)."""
query = (req.query or "").strip()
if not query:
raise HTTPException(status_code=400, detail="Empty query.")
key = (req.key or "").strip() or SERPER_KEY
has_user_key = bool((req.key or "").strip())
if not key:
# No server key and the user didn't supply one — search is unavailable.
raise HTTPException(status_code=503, detail="Search is not configured.")
headers = {"X-API-KEY": key, "Content-Type": "application/json"}
payload = {"q": query, "num": MAX_RESULTS}
logger.debug(
"[EXT][SERPER] search POST %s query=%s userKey=%s num=%d",
SERPER_URL, json.dumps(query, ensure_ascii=True)[:200], has_user_key, MAX_RESULTS,
)
try:
async with httpx.AsyncClient(timeout=12.0) as http:
resp = await http.post(SERPER_URL, headers=headers, json=payload)
except httpx.RequestError as exc:
logger.warning("Serper unreachable: %r", exc)
raise HTTPException(status_code=502, detail="Search provider unreachable.")
logger.debug(
"[EXT][SERPER] search RESP status=%s len=%dB",
resp.status_code, len(resp.content or b""),
)
if resp.status_code != 200:
# Serper's error body carries the real reason (e.g. "Not enough
# credits") and contains no key, so it's safe to log and relay.
body = resp.text[:300]
logger.warning("Serper error %s: %s", resp.status_code, body)
msg = None
try:
msg = resp.json().get("message")
except Exception:
pass
detail = f"Search provider error ({resp.status_code})"
if msg:
detail += f": {msg}"
raise HTTPException(status_code=502, detail=detail)
data = resp.json()
results = []
for item in (data.get("organic") or [])[:MAX_RESULTS]:
results.append(
{
"title": item.get("title", ""),
"snippet": item.get("snippet", ""),
"url": item.get("link", ""),
}
)
# A direct answer when Google has one — saves the model a hop.
box = data.get("answerBox") or {}
answer = box.get("answer") or box.get("snippet") or None
if not answer:
kg = data.get("knowledgeGraph") or {}
answer = kg.get("description") or None
logger.debug(
"[EXT][SERPER] search PARSED hasAnswer=%s resultCount=%d titles=%s",
bool(answer), len(results), [r.get("title", "")[:40] for r in results],
)
return JSONResponse({"query": query, "answer": answer, "results": results})
@app.post("/api/session")
async def session(request: Request):
"""Proxy the session handshake to the load balancer, keeping its URL secret,
and meter conversation time by tier.
The browser POSTs here (same-origin); we resolve the caller's tier, refuse if
today's budget is already spent (402), otherwise POST <LOAD_BALANCER_URL>/session
and relay the JSON back. The LB body carries a per-session `connect_url`
(compute host + short-lived token) the browser must dial directly — that one
URL is unavoidably exposed, but the stable load-balancer address is not. On a
successful grant we reserve the first time chunk against the day's budget."""
client_ip = request.client.host if request.client else "?"
if not LOAD_BALANCER_URL:
# No LB configured — this deploy is direct-mode only; the browser should
# never call this. 404 so it's indistinguishable from a missing route.
raise HTTPException(status_code=404, detail="Not found.")
tier, keys, set_cookie = auth.resolve_identity(request)
# Metering runs only on the deployed Space; off-Space the LB still proxies but
# nothing is tracked. Within metering, unlimited tiers (pro, org) aren't either.
tracked = LIMITER_ENABLED and limiter.budget_for(tier) is not None
logger.debug(
"[EXT][LB] session: client=%s tier=%s tracked=%s LIMITER=%s",
client_ip, tier, tracked, LIMITER_ENABLED,
)
# Refuse before troubling the LB if the day's budget is already gone. Done
# here (at enqueue) so we never put a user who can't talk into the queue.
if tracked:
rem = await asyncio.to_thread(limiter.remaining, keys, tier)
logger.debug("[EXT][LB] session: client=%s budget remaining=%s", client_ip, rem)
if rem is not None and rem <= 0:
resp = JSONResponse(
{"tier": tier, "reason": "limit", "remainingSec": 0}, status_code=402
)
if set_cookie:
auth.set_anon_cookie(resp, set_cookie)
return resp
url = f"{LOAD_BALANCER_URL.rstrip('/')}/session"
logger.debug("[EXT][LB] session POST %s (handshake)", url)
try:
async with httpx.AsyncClient(timeout=15.0) as http:
lb = await http.post(url, headers={"Content-Type": "application/json"}, content="{}")
except httpx.RequestError as exc:
logger.warning("Load balancer unreachable: %r", exc)
raise HTTPException(status_code=502, detail="Speech service unreachable.")
logger.debug(
"[EXT][LB] session RESP status=%s len=%dB",
lb.status_code, len(lb.content or b""),
)
# The queue is full: the LB replies 503 {state:"at_capacity"}. Relay it as-is
# so the client shows a soft "try again shortly", not a hard error.
if lb.status_code == 503:
body = _safe_json(lb)
if body.get("state") == "at_capacity":
logger.debug("[EXT][LB] session: at_capacity — queue full")
resp = JSONResponse({"state": "at_capacity"}, status_code=503)
if set_cookie:
auth.set_anon_cookie(resp, set_cookie)
return resp
if lb.status_code != 200:
# The LB's error body may name the reason (e.g. capacity); it carries no
# secret, so relay a trimmed copy.
logger.warning("Session handshake failed %s: %s", lb.status_code, lb.text[:300])
raise HTTPException(status_code=502, detail=f"Session handshake failed ({lb.status_code}).")
data = lb.json()
state = data.get("state", "?")
connect_url = (data.get("connect_url") or data.get("connectUrl") or "")[:120]
session_id = data.get("session_id") or data.get("sessionId")
logger.debug(
"[EXT][LB] session PARSED state=%s sessionId=%s hasConnectUrl=%s connectUrl=%s",
state, session_id, bool(connect_url), connect_url,
)
# Busy pool: the LB queued us. Relay the ticket untouched — crucially with NO
# reservation, so waiting in line never costs the day's budget.
if data.get("state") == "queued":
data["tier"] = tier
logger.debug("[EXT][LB] session: queued queueId=%s position=%s",
data.get("queue_id") or data.get("queueId"),
data.get("position"))
resp = JSONResponse(data)
if set_cookie:
auth.set_anon_cookie(resp, set_cookie)
return resp
# A slot was free: reserve the first chunk now and return the grant.
return await _finalize_grant(data, keys, tier, tracked, set_cookie)
@app.get("/api/queue/{queue_id}")
async def queue_status(queue_id: str, request: Request):
"""Poll a waiting ticket: relay the position, or — when the head of the line
claims a freed slot — reserve the budget now and return the grant. Re-checks the
daily budget at claim, since a multi-minute wait could have spent it elsewhere."""
client_ip = request.client.host if request.client else "?"
if not LOAD_BALANCER_URL:
raise HTTPException(status_code=404, detail="Not found.")
tier, keys, set_cookie = auth.resolve_identity(request)
tracked = LIMITER_ENABLED and limiter.budget_for(tier) is not None
logger.debug(
"[EXT][LB] queue poll: client=%s queueId=%s tier=%s",
client_ip, queue_id[:16], tier,
)
url = f"{LOAD_BALANCER_URL.rstrip('/')}/queue/{queue_id}"
logger.debug("[EXT][LB] queue GET %s", url)
try:
async with httpx.AsyncClient(timeout=15.0) as http:
lb = await http.get(url)
except httpx.RequestError as exc:
logger.warning("Load balancer unreachable: %r", exc)
raise HTTPException(status_code=502, detail="Speech service unreachable.")
logger.debug(
"[EXT][LB] queue RESP status=%s len=%dB",
lb.status_code, len(lb.content or b""),
)
if lb.status_code == 404:
# Ticket unknown/expired (reaped after we stopped polling). Tell the client
# to start over rather than spin.
logger.debug("[EXT][LB] queue: queueId=%s EXPIRED (404)", queue_id[:16])
resp = JSONResponse({"state": "expired"}, status_code=404)
if set_cookie:
auth.set_anon_cookie(resp, set_cookie)
return resp
if lb.status_code != 200:
logger.warning("Queue poll failed %s: %s", lb.status_code, lb.text[:300])
raise HTTPException(status_code=502, detail=f"Queue poll failed ({lb.status_code}).")
data = lb.json()
state = data.get("state", "?")
position = data.get("position")
logger.debug(
"[EXT][LB] queue PARSED queueId=%s state=%s position=%s sessionId=%s",
queue_id[:16], state, position,
data.get("session_id") or data.get("sessionId"),
)
if data.get("state") == "queued":
data["tier"] = tier
resp = JSONResponse(data)
if set_cookie:
auth.set_anon_cookie(resp, set_cookie)
return resp
# Claimed a slot. Re-check the budget: it may have been spent in another tab
# during the wait. If so, refuse — the just-claimed slot is now a pending
# session on the LB and its pending-timeout reaper reclaims it shortly.
if tracked:
rem = await asyncio.to_thread(limiter.remaining, keys, tier)
logger.debug(
"[EXT][LB] queue CLAIMED queueId=%s budget remaining=%s",
queue_id[:16], rem,
)
if rem is not None and rem <= 0:
resp = JSONResponse(
{"tier": tier, "reason": "limit", "remainingSec": 0}, status_code=402
)
if set_cookie:
auth.set_anon_cookie(resp, set_cookie)
return resp
return await _finalize_grant(data, keys, tier, tracked, set_cookie)
@app.delete("/api/queue/{queue_id}")
async def queue_leave(queue_id: str):
"""Leave the queue from the explicit 'Leave queue' button (a real fetch)."""
if not LOAD_BALANCER_URL:
raise HTTPException(status_code=404, detail="Not found.")
logger.debug("[EXT][LB] queue LEAVE (button) queueId=%s", queue_id[:16])
await _lb_leave(queue_id)
return {"ok": True}
@app.post("/api/queue/end")
async def queue_end(request: Request):
"""Leave the queue on teardown/tab-close (navigator.sendBeacon, which can only
POST). Body: { queueId }. Best-effort; the LB reaps the ticket on TTL anyway."""
if not LOAD_BALANCER_URL:
raise HTTPException(status_code=404, detail="Not found.")
qid = await _queue_id(request)
if qid:
logger.debug("[EXT][LB] queue LEAVE (teardown) queueId=%s", qid[:16])
await _lb_leave(qid)
return {"ok": True}
async def _finalize_grant(data, keys, tier, tracked, set_cookie):
"""Shared grant tail (fast path or queue claim): reserve the first chunk, attach
the metering fields the client needs, and set the anon cookie."""
remaining = None
session_id = data.get("session_id")
if tracked and session_id:
logger.debug(
"[EXT][LB] grant FINALIZE sessionId=%s tier=%s tracked=%s",
session_id, tier, tracked,
)
await asyncio.to_thread(limiter.begin, session_id, keys, tier)
remaining = await asyncio.to_thread(limiter.remaining, keys, tier)
logger.debug(
"[EXT][LB] grant RESERVED sessionId=%s remaining=%s",
session_id, remaining,
)
data.update({
"tier": tier,
"limited": tracked,
"remainingSec": remaining,
"heartbeatSec": limiter.HEARTBEAT_SEC,
})
resp = JSONResponse(data)
if set_cookie:
auth.set_anon_cookie(resp, set_cookie)
return resp
async def _lb_leave(queue_id: str) -> None:
"""Best-effort: tell the LB to drop a waiting ticket."""
url = f"{LOAD_BALANCER_URL.rstrip('/')}/queue/{queue_id}"
logger.debug("[EXT][LB] queue DELETE %s", url)
try:
async with httpx.AsyncClient(timeout=5.0) as http:
resp = await http.delete(url)
logger.debug(
"[EXT][LB] queue DELETE RESP queueId=%s status=%s",
queue_id[:16], resp.status_code,
)
except httpx.RequestError as exc:
logger.warning("Queue leave failed: %r", exc)
def _safe_json(response) -> dict:
try:
body = response.json()
except Exception:
return {}
return body if isinstance(body, dict) else {}
def _proxy_public_url(request: Request) -> str:
if not S2S_PROXY_TARGET:
return ""
forwarded_proto = (request.headers.get("x-forwarded-proto") or request.url.scheme).split(",")[0].strip()
forwarded_host = (request.headers.get("x-forwarded-host") or request.headers.get("host") or request.url.netloc).split(",")[0].strip()
ws_scheme = "wss" if forwarded_proto in {"https", "wss"} else "ws"
root_path = (request.scope.get("root_path") or "").rstrip("/")
return f"{ws_scheme}://{forwarded_host}{root_path}/v1/realtime"
def _augment_client_session_update(
event: dict,
agent_prompt: str,
insights_block: str,
realtime_tools: list[dict],
) -> tuple[dict, bool, dict]:
"""
🔥 FIX RACE: intercetta ogni session.update proveniente dal browser client
PRIMA che venga mandato a ai-server e ne MENGIA istruzioni lato client
con: server profile Aquachile + insights diario oggi + tools catalog MCP.
Regola merge per instructions (ordine significativo, prima = più basso peso in LLM):
[1] istruzioni client originali ("Eres el asistente de voz oficial de Aquachile..." + Voice Rules)
[2] "\n\n## Aquachile Agent Profile Server-Side" + profile
[3] "\n\n" + insights_block già formattato con ### Contexto operativo del día
Tools + tool_choice: imposto solo se realtime_tools non vuoto (MCP_EXEC_ENABLED=True e 79 tool disponibili).
Ritorna:
(event_patched, was_patched, stats_dict)
- event_patched: dict modificato, o lo stesso oggetto originario se niente da mergiare
- was_patched: True solo se abbiamo toccato il dict
"""
stats = {"merged_instructions_len": 0, "appended_profile": False, "appended_insights": False, "tools_injected_count": 0}
if not isinstance(event, dict) or event.get("type") != "session.update":
return event, False, stats
_has_anything = bool(agent_prompt or insights_block or realtime_tools)
if not _has_anything:
return event, False, stats
# Assicura session wrapper esista (standard GA nested)
if not isinstance(event.get("session"), dict):
event["session"] = {}
sess = event["session"]
base_instructions = sess.get("instructions") or ""
if isinstance(base_instructions, str):
base = base_instructions.strip()
else:
base = ""
extra_parts: list[str] = []
if agent_prompt and agent_prompt.strip():
extra_parts.append(
"## Aquachile Agent Profile (injected by S2S proxy server-side)\n"
+ agent_prompt.strip()
)
stats["appended_profile"] = True
if insights_block and insights_block.strip():
extra_parts.append(insights_block.strip())
stats["appended_insights"] = True
if base and extra_parts:
merged = base + "\n\n" + "\n\n".join(extra_parts)
elif base:
merged = base
elif extra_parts:
merged = "\n\n".join(extra_parts)
else:
merged = ""
merged = merged.strip()
if merged:
sess["instructions"] = merged
stats["merged_instructions_len"] = len(merged)
if realtime_tools:
sess["tools"] = realtime_tools
sess["tool_choice"] = "auto"
stats["tools_injected_count"] = len(realtime_tools)
was_patched = bool(stats["merged_instructions_len"] or stats["tools_injected_count"])
return event, was_patched, stats
def _proxy_upstream_url(ws: WebSocket) -> str:
target = urlsplit(S2S_PROXY_TARGET)
merged_query = dict(parse_qsl(target.query, keep_blank_values=True))
merged_query.update(parse_qsl(ws.url.query, keep_blank_values=True))
return urlunsplit(
(
target.scheme,
target.netloc,
target.path or "/v1/realtime",
urlencode(merged_query, doseq=True),
target.fragment,
)
)
def _subprotocols(ws: WebSocket) -> list[str]:
raw = ws.headers.get("sec-websocket-protocol", "")
return [item.strip() for item in raw.split(",") if item.strip()]
async def _client_to_upstream(ws: WebSocket, upstream, client_ip: str, session_ctx: dict) -> None:
while True:
message = await ws.receive()
if message["type"] == "websocket.disconnect":
# #region debug-point B:client-disconnect
await _report_server_debug(
"B",
"server.py:_client_to_upstream",
"client websocket disconnected",
{"code": message.get("code")},
)
# #endregion
logger.debug(
"[EXT][S2S-PROXY] client=%s client→upstream DISCONNECT code=%s",
client_ip, message.get("code"),
)
await upstream.close()
return
if message.get("text") is not None:
# #region debug-point B:client-text-forward
summary = _realtime_event_summary(message["text"])
if summary:
await _report_server_debug(
"B",
"server.py:_client_to_upstream",
"forwarding client event to upstream",
summary,
)
event_type = summary.get("type")
# --- INPUT UTENTE lato client (text typed / inserted items) ---
user_text = ""
if event_type == "conversation.item.created" and summary.get("role") == "user":
user_text = (summary.get("text") or "").strip()
if user_text:
logger.info(
"[INPUT UTENTE] client=%s text=%s",
client_ip, user_text,
)
if (event_type not in _NOISY_CLIENT_EVENT_TYPES
and event_type not in _NOISY_REALTIME_EVENT_TYPES):
logger.debug(
"[EXT][S2S-PROXY] client=%s →UPSTREAM text event=%s summary=%s",
client_ip, event_type, json.dumps(summary, ensure_ascii=True)[:300],
)
# #endregion
# --- 🔥 FIX RACE: PATCH SESSION.UPDATE CLIENT PRIMA DI INOLTRE A UPSTREAM ---
# Il browser manda un suo session.update (con instructions base + voice)
# POCHI ms DOPO il nostro inject upfront. Senza questo patch, quello
# del client SOVRASCRIVE instructions e tools completamente (handle_session_update
# usa deep merge: instructions campo scalare viene sovrascritto, non concatenato).
_raw_text = message["text"]
_forward_this = _raw_text
_was_patched = False
try:
_evt_client = json.loads(_raw_text)
if (
isinstance(_evt_client, dict)
and _evt_client.get("type") == "session.update"
):
_a_prompt = session_ctx.get("mcp_agent_prompt", "") or ""
_a_insights = session_ctx.get("mcp_insights_block", "") or ""
_a_tools: list[dict] = session_ctx.get("mcp_realtime_tools") or []
_evt_patched, _was_patched, _patch_stats = _augment_client_session_update(
_evt_client, _a_prompt, _a_insights, _a_tools
)
if _was_patched:
_forward_this = json.dumps(_evt_patched, ensure_ascii=True)
logger.info(
"[MCP INJECT] PATCHED client session.update →UPSTREAM: "
"mergedInstructions=%dB appendedProfile=%s appendedInsights=%s "
"toolsInjected=%s (prima era senza insights/tools — era la causa del "
"PROMPT LLM senza insights in ai-server log).",
_patch_stats["merged_instructions_len"],
bool(_patch_stats["appended_profile"]),
bool(_patch_stats["appended_insights"]),
_patch_stats["tools_injected_count"] or "NONE",
)
else:
logger.info(
"[MCP INJECT] PASSTHROUGH client session.update →UPSTREAM: "
"no server data to merge (nothing enabled / empty profile / insights disabled).",
)
except Exception as _patch_err:
# NEVER-BREAK-AUDIO: qualunque errore nel parsing o nel patching,
# inoltro il messaggio originale così com'era.
logger.warning(
"[MCP INJECT] errore non bloccante in patching client session.update "
"(fallback to passthrough original message): %r",
_patch_err,
)
_forward_this = _raw_text
_was_patched = False
await upstream.send(_forward_this)
elif message.get("bytes") is not None:
# #region debug-point B:client-bytes-forward
await _report_server_debug(
"B",
"server.py:_client_to_upstream",
"forwarding client binary frame to upstream",
{"bytes": len(message["bytes"])},
)
logger.debug(
"[EXT][S2S-PROXY] client=%s →UPSTREAM bytes=%dB",
client_ip, len(message["bytes"]),
)
# #endregion
await upstream.send(message["bytes"])
async def _upstream_to_client(ws: WebSocket, upstream, client_ip: str, session_ctx: dict) -> None:
async for message in upstream:
if isinstance(message, bytes):
# #region debug-point B:upstream-bytes-forward
await _report_server_debug(
"B",
"server.py:_upstream_to_client",
"forwarding upstream binary frame to client",
{"bytes": len(message)},
)
logger.debug(
"[EXT][S2S-PROXY] client=%s UPSTREAM→ bytes=%dB",
client_ip, len(message),
)
# #endregion
await ws.send_bytes(message)
else:
# #region debug-point B:upstream-text-forward
summary = _realtime_event_summary(message)
if summary:
await _report_server_debug(
"B",
"server.py:_upstream_to_client",
"forwarding upstream event to client",
summary,
)
event_type = summary.get("type")
# --- INPUT UTENTE (server-side STT emesso dall'upstream) ---
user_text = ""
if event_type == "conversation.item.input_audio_transcription.completed":
user_text = (summary.get("transcript") or "").strip()
item_id = summary.get("item_id")
if user_text:
logger.info(
"[INPUT UTENTE] client=%s stt=%s",
client_ip, user_text,
)
session_ctx["last_user_transcript"] = user_text
if item_id:
session_ctx["last_item_id"] = item_id
elif event_type == "conversation.item.created" and summary.get("role") == "user":
user_text = (summary.get("text") or "").strip()
item_id = summary.get("item_id") or summary.get("id")
if user_text:
logger.info(
"[INPUT UTENTE] client=%s text=%s",
client_ip, user_text,
)
session_ctx["last_user_transcript"] = user_text
if item_id:
session_ctx["last_item_id"] = item_id
# --- OUTPUT AGENTE: tutte le varianti ---
agent_text = ""
response_id = summary.get("response_id") or summary.get("id")
item_id = summary.get("item_id")
if event_type in {"response.audio_transcript.done",
"response.output_audio_transcript.done"}:
agent_text = (summary.get("text") or "").strip()
if agent_text:
logger.info(
"[OUTPUT AGENTE] client=%s tts=%s",
client_ip, agent_text,
)
# ── Forward fire-and-forget a Node-RED (FASE 1 LOG-ONLY) ──
asyncio.create_task(_forward_agent_text_to_nodered({
"tts": agent_text,
"response_id": response_id,
"item_id": item_id,
"client_ip": client_ip,
"role": "assistant",
"source_event": event_type,
"user_transcript": session_ctx.get("last_user_transcript") or "",
}))
else:
# Ispezione: questo evento custom non emette testo nel campo atteso
raw_preview = summary.get("_raw_preview") or json.dumps(summary, ensure_ascii=True)
logger.debug(
"[OUTPUT AGENTE][ISPEZIONE] client=%s %s ha summary=%s raw=%s",
client_ip, event_type,
json.dumps(summary, ensure_ascii=True)[:400],
raw_preview[:800],
)
elif event_type == "response.content_part.done":
agent_text = (summary.get("text") or "").strip()
if agent_text:
logger.info(
"[OUTPUT AGENTE] client=%s content_part=%s",
client_ip, agent_text,
)
asyncio.create_task(_forward_agent_text_to_nodered({
"tts": agent_text,
"response_id": response_id,
"item_id": item_id,
"client_ip": client_ip,
"role": "assistant",
"source_event": event_type,
"user_transcript": session_ctx.get("last_user_transcript") or "",
}))
elif event_type == "response.output_item.done" and summary.get("role") == "assistant":
agent_text = (summary.get("text") or "").strip()
if agent_text:
logger.info(
"[OUTPUT AGENTE] client=%s output_item=%s",
client_ip, agent_text,
)
asyncio.create_task(_forward_agent_text_to_nodered({
"tts": agent_text,
"response_id": response_id,
"item_id": item_id,
"client_ip": client_ip,
"role": "assistant",
"source_event": event_type,
"user_transcript": session_ctx.get("last_user_transcript") or "",
}))
elif event_type == "conversation.item.created" and summary.get("role") == "assistant":
agent_text = (summary.get("text") or "").strip()
if agent_text:
logger.info(
"[OUTPUT AGENTE] client=%s created=%s",
client_ip, agent_text,
)
asyncio.create_task(_forward_agent_text_to_nodered({
"tts": agent_text,
"response_id": response_id,
"item_id": item_id,
"client_ip": client_ip,
"role": "assistant",
"source_event": event_type,
"user_transcript": session_ctx.get("last_user_transcript") or "",
}))
# Log dettagliato evento solo se non è un tipo rumoroso
if event_type not in _NOISY_REALTIME_EVENT_TYPES:
logger.debug(
"[EXT][S2S-PROXY] client=%s UPSTREAM→ event=%s summary=%s",
client_ip, event_type, json.dumps(summary, ensure_ascii=True)[:300],
)
# ── Upstream error filter: non propagare al browser errori interni
# causati dal nostro inject di tools[] (sono noise per l'utente finale).
# (strategy B non funziona attualmente (ai-server non supporta tools[]).
#
# Formati errore upstream gestiti (entrambi con controllo su message e su type annidato):
# (A) Wrapper standard (OSSERVATO NEI LOG REALI):
# {"type":"error","error":{"message":"Unknown or invalid event: session.update","type":"unknown_or_invalid_event","code":null,...}}
# (B) Flat fallback (per altri upstream compatibili):
# {"type":"error","message":"...","code":"..."}
if isinstance(message, str):
try:
_evt = json.loads(message)
except Exception:
_evt = None
if isinstance(_evt, dict):
_evt_type = _evt.get("type")
if _evt_type == "error":
# ── Estrazione robusta message + error_type: wrapper annidato PRIORITARIO
_err_msg = ""
_err_type = ""
_inner = _evt.get("error")
if isinstance(_inner, dict):
for _k in ("message", "error", "msg"):
_v = _inner.get(_k)
if isinstance(_v, str) and _v.strip():
_err_msg = _v.strip()
break
_t = _inner.get("type")
if isinstance(_t, str):
_err_type = _t
# Fallback flat se non abbiamo trovato nel wrapper
if not _err_msg:
for _k in ("message", "error", "msg"):
_v = _evt.get(_k)
if isinstance(_v, str) and _v.strip():
_err_msg = _v.strip()
break
if not _err_type:
_t = _evt.get("code")
if isinstance(_t, str):
_err_type = _t
# ── Decisioni soppressione
_suppress = False
_suppress_reason = ""
if "Unknown or invalid event: session.update" in _err_msg:
_suppress = True
_suppress_reason = (
"rifiuto del nostro inject session.update con tools[] — ai-server attualmente non supporta "
"tools[]. Modifica richiesta in arrivo. Loggo solo server-side e non inoltro al browser."
)
elif "session.update" in _err_msg and ("tool" in _err_msg.lower() or "invalid" in _err_msg.lower()):
_suppress = True
_suppress_reason = (
f"rifiuto di session.update da upstream (message): {_err_msg[:160]}. Non inoltro al browser."
)
elif _err_type == "unknown_or_invalid_event" and "session.update" in _err_msg:
_suppress = True
_suppress_reason = (
f"rifiuto di session.update da upstream (type=unknown_or_invalid_event): {_err_msg[:160]}. Non inoltro al browser."
)
if _suppress:
logger.info(
"[MCP INJECT] suppressed upstream error (non mandato al browser): %s",
_suppress_reason,
)
logger.debug(
"[MCP INJECT] full upstream suppressed error payload=%s",
json.dumps(_evt, ensure_ascii=True)[:600],
)
return
# ── Log ispezione: se arriviamo qua l'errore NON è stato soppresso.
# Facciamo sempre vedere message+type per capire se aggiungere nuove regole.
logger.debug(
"[MCP INJECT] upstream error NOT suppressed (passthrough to browser) — "
"evt.error.message=%s evt.error.type=%s evtTopKeys=%s",
_err_msg[:200] if _err_msg else "(empty)",
_err_type or "(none)",
sorted(_evt.keys()),
)
# #endregion
await ws.send_text(message)
async def _queue_id(request: Request) -> str:
"""Pull `queueId` from a JSON body, tolerating sendBeacon's blob posts."""
try:
data = await request.json()
except Exception:
return ""
return (data or {}).get("queueId", "") if isinstance(data, dict) else ""
async def _session_id(request: Request) -> str:
"""Pull `sessionId` from a JSON body, tolerating sendBeacon's blob posts."""
try:
data = await request.json()
except Exception:
return ""
return (data or {}).get("sessionId", "") if isinstance(data, dict) else ""
@app.post("/api/session/heartbeat")
async def session_heartbeat(request: Request):
"""Extend the live reservation one chunk at a time. `expired` once the day's
budget is spent — the client then tears down."""
client_ip = request.client.host if request.client else "?"
if not LIMITER_ENABLED:
raise HTTPException(status_code=404, detail="Not found.")
sid = await _session_id(request)
alive = bool(sid) and await asyncio.to_thread(limiter.heartbeat, sid)
logger.debug(
"[INTERNAL] /api/session/heartbeat client=%s sessionId=%s alive=%s",
client_ip, (sid or "")[:16], alive,
)
return {"expired": not alive}
@app.post("/api/session/end")
async def session_end(request: Request):
"""Clean teardown: reconcile to real elapsed time and refund the unused
chunk. Sent via navigator.sendBeacon, so it must succeed without a response."""
client_ip = request.client.host if request.client else "?"
if not LIMITER_ENABLED:
raise HTTPException(status_code=404, detail="Not found.")
sid = await _session_id(request)
logger.debug(
"[INTERNAL] /api/session/end client=%s sessionId=%s",
client_ip, (sid or "")[:16],
)
if sid:
await asyncio.to_thread(limiter.end, sid)
return {"ok": True}
@app.middleware("http")
async def no_cache_static_assets(request: Request, call_next):
response = await call_next(request)
path = request.url.path or ""
nocache_ext = (".html", ".js", ".mjs", ".css", ".wasm", ".worklet.js")
if any(path.endswith(ext) for ext in nocache_ext) or path == "/" or path.endswith("/"):
response.headers["Cache-Control"] = "no-cache, no-store, must-revalidate, max-age=0"
response.headers["Pragma"] = "no-cache"
response.headers["Expires"] = "0"
return response
# Static front-end. Registered last so the /api routes win. `html=True` serves
# index.html at "/". The repo is public anyway, so serving the dir is fine.
app.mount("/", StaticFiles(directory=HERE, html=True), name="static")