Files
vocero-client/s2s_client/services/reasoning.py
T

961 lines
49 KiB
Python

from __future__ import annotations
import json
import logging
from typing import Any
import httpx
from fastapi import HTTPException
from fastapi.responses import JSONResponse
from s2s_client.core import config as settings
from s2s_client.core import logging as app_logging
from s2s_client.models import requests as models_requests
from s2s_client.providers import apipilot as providers_apipilot
from s2s_client.providers import caller as providers_caller
from s2s_client.services import context as services_context
from s2s_client.services import tool_context as services_tool_context
def _openai_headers() -> dict[str, str]:
if not settings.OPENAI_API_KEY:
raise RuntimeError("OPENAI_API_KEY is not configured.")
headers = {
"Authorization": f"Bearer {settings.OPENAI_API_KEY}",
"Content-Type": "application/json",
}
if settings.OPENAI_ORGANIZATION:
headers["OpenAI-Organization"] = settings.OPENAI_ORGANIZATION
if settings.OPENAI_PROJECT:
headers["OpenAI-Project"] = settings.OPENAI_PROJECT
return headers
async def reasoning(req: models_requests.ReasoningRequest) -> JSONResponse:
if settings.S2S_REASONING_TYPE == "PROXY":
raise HTTPException(status_code=409, detail="El servicio de razonamiento está deshabilitado en el modo PROXY.")
transcript = (req.transcript or "").strip()
if not transcript:
raise HTTPException(status_code=400, detail="Se requiere el campo transcript.")
# ── S2S_INJECT_PROFILE: resolve podcast episode + caller profile + reports list + latest summary ──
# (When S2S_INJECT_PROFILE=false this entire block is a no-op; user_context
# and instructions are taken verbatim from the request body.)
inject_episode_text = ""
inject_profile_text = ""
inject_reports_text = ""
inject_summary_text = ""
phone = (req.phoneNumber or "").strip()
episode_id = (req.episode_id or "").strip()
if not settings.S2S_INJECT_PROFILE:
app_logging.logger.info(
"[INJECT-PROFILE] ⏭️ REASONING: skipped (S2S_INJECT_PROFILE=false). "
"Using verbatim request body; no fetch, no augmentation."
)
else:
needs_phone_authed = bool(settings.VOCERO_USER_PHONE_AUTH_URL.strip())
# 2026-09-11 user fix: remove mass injection of scheduled reports.
# treats S2S_REPORT_LIST as "need to fetch reports" ONLY when BOTH the URL is
# configured AND the new opt-in S2S_INJECT_REPORTS flag is true. When
# S2S_INJECT_REPORTS=false (default) needs_reports stays False here → we skip
# the branch entirely, no HTTP call, no context string, no prompt bloat.
needs_reports = bool(settings.S2S_REPORT_LIST.strip()) and settings.S2S_INJECT_REPORTS
needs_summary = bool(settings.S2S_LATEST_SUMMARY.strip()) or bool(settings.S2S_LATEST_SUMMARY_TEXT)
needs_login = bool(settings.S2S_LOGIN_BY_PHONE.strip())
can_inject = needs_phone_authed or needs_reports or needs_summary or needs_login or bool(episode_id)
if (
(not needs_phone_authed)
and (not needs_reports)
and (not needs_summary)
and (not needs_login)
and (not episode_id)
):
app_logging.logger.info(
"[INJECT-PROFILE] ⏭️ REASONING: skipped (VOCERO_USER_PHONE_AUTH_URL, S2S_REPORT_LIST, S2S_LATEST_SUMMARY/S2S_LATEST_SUMMARY_TEXT and S2S_LOGIN_BY_PHONE all empty, AND no episode_id in request; OR S2S_INJECT_REPORTS is false so reports injection is globally disabled). "
"Set at least one AND set S2S_INJECT_REPORTS=true (if you want scheduled reports) to enable login / fetch episode/profile/reports/summary for REASONING endpoint."
)
elif (not phone) and (not needs_reports) and (not episode_id) and (not settings.S2S_LATEST_SUMMARY_TEXT):
app_logging.logger.info(
"[INJECT-PROFILE] ⏭️ REASONING: skipped (phoneNumber missing from request body AND no episode_id). "
"Browser-side issue: check VoiceController passes phoneNumber and/or episode_id in the JSON body. (Note: S2S_REPORT_LIST fetch works even without phone.)"
)
elif not can_inject:
app_logging.logger.info(
"[INJECT-PROFILE] ⏭️ REASONING: skipped (env for phone empty and no reports/summary/login API and no episode_id)."
)
else:
# ###################################################################
# 0) Login-by-phone (optional — only if S2S_LOGIN_BY_PHONE env set)
# Obtains a bearer token that will be forwarded for profile/reports/summary fetches.
# ###################################################################
login_token = None
if settings.S2S_LOGIN_BY_PHONE and phone:
login_token, _login_resp = await providers_caller._login_by_phone(phone)
# ###################################################################
# 0.5) Podcast episode fetch (independent of phone — uses req.episode_id)
# ###################################################################
if episode_id:
if settings.S2S_DEBUG_PROMPT:
app_logging.logger.info(
"[INJECT-EPISODE] starting REASONING fetch podcast episode episodeId=%.80s...",
episode_id,
)
episode_raw = await providers_caller._fetch_podcast_episode(episode_id)
inject_episode_text = services_context._resolve_episode_context(episode_raw)
if inject_episode_text.strip():
app_logging.logger.info(
"[INJECT-EPISODE] ✅ REASONING: PODCAST EPISODE READY episodeId=%.80s wrappedLen=%d -> augmenting instructions + user_context before sending upstream.",
episode_id,
len(inject_episode_text),
)
else:
app_logging.logger.info(
"[INJECT-EPISODE] ⏭️ REASONING: episode skipped (context empty / upstream returned empty / fetch failed)."
)
# ###################################################################
# 1) Profile fetch (optional — only if env is configured)
# ###################################################################
if needs_phone_authed and phone:
profile_obj = await providers_caller._fetch_user_profile_for_phone(phone, auth_token=login_token)
inject_profile_text = services_context._resolve_user_context_text(phone, profile_obj, loaded=True)
if inject_profile_text.strip():
app_logging.logger.info(
"[INJECT-PROFILE] ✅ REASONING: profile READY phoneLen=%d contextLen=%d -> augmenting instructions + user_context before sending upstream.",
len(phone),
len(inject_profile_text),
)
else:
app_logging.logger.info(
"[INJECT-PROFILE] ⏭️ REASONING: profile fetch OK but resolved context empty."
)
# ###################################################################
# 1.5) Scheduled reports / podcast scripts list (optional — S2S_REPORT_LIST)
# ###################################################################
if needs_reports:
if settings.S2S_DEBUG_PROMPT:
app_logging.logger.info(
"[INJECT-REPORTS] starting REASONING fetch S2S_REPORT_LIST (phoneLen=%s, bearer=%s)...",
len(phone) if phone else "none",
"yes" if login_token else "no",
)
reports_raw = await providers_caller._fetch_reports_list(
phone_number=phone if phone else None, auth_token=login_token
)
inject_reports_text = services_context._resolve_reports_context(reports_raw)
if inject_reports_text.strip():
app_logging.logger.info(
"[INJECT-REPORTS] ✅ REASONING: reports list READY wrappedLen=%d -> augmenting instructions + user_context before sending upstream.",
len(inject_reports_text),
)
else:
app_logging.logger.info(
"[INJECT-REPORTS] ⏭️ REASONING: reports list skipped (context empty / upstream returned empty list / fetch failed)."
)
# ###################################################################
# 2) Latest summary fetch (optional — only if env is configured)
# ###################################################################
if needs_summary and (phone or settings.S2S_LATEST_SUMMARY_TEXT):
if settings.S2S_DEBUG_PROMPT:
app_logging.logger.info(
"[INJECT-SUMMARY] starting REASONING fetch (reasoning summary... S2S_LATEST_SUMMARY=%s S2S_LATEST_SUMMARY_TEXT=%s phoneLen=%s.",
bool(settings.S2S_LATEST_SUMMARY),
bool(settings.S2S_LATEST_SUMMARY_TEXT),
len(phone) if phone else "none",
)
latest_summary_raw = await providers_caller._fetch_latest_summary_for_phone(
phone, auth_token=login_token
)
inject_summary_text = services_context._resolve_latest_summary_context(latest_summary_raw)
if inject_summary_text.strip():
app_logging.logger.info(
"[INJECT-SUMMARY] ✅ REASONING: latest summary READY phoneLen=%s summaryTextOverride=%s wrappedLen=%d -> augmenting instructions + user_context before sending upstream.",
len(phone) if phone else "none",
bool(settings.S2S_LATEST_SUMMARY_TEXT),
len(inject_summary_text),
)
else:
app_logging.logger.info(
"[INJECT-SUMMARY] ⏭️ REASONING: latest summary skipped (context empty / upstream returned empty summary / fetch failed.)"
)
# Load dynamic ApiPilot tools before building context, independently of
# S2S_INJECT_PROFILE.
needs_apipilot = bool(settings.S2S_APIPILOT_TOOLS_URL) or bool(settings.S2S_APIPILOT_TOOLS_EXECUTE_URL)
apipilot_tools_pass1: list[dict] = []
apipilot_auth_header: str | None = None
if isinstance(login_token, str) and login_token.strip():
tk = login_token.strip()
if tk.lower().startswith("bearer "):
apipilot_auth_header = tk
else:
apipilot_auth_header = f"Bearer {tk}"
# S2S_LOGIN_BY_PHONE resolves an AquaPortal JWT, used for requires_auth=true
# execution. S2S_APIPILOT_SERVICE_TOKEN overrides it when configured.
if settings.S2S_APIPILOT_SERVICE_TOKEN:
_svc = settings.S2S_APIPILOT_SERVICE_TOKEN.strip()
if _svc:
apipilot_auth_header = f"Bearer {_svc}" if not _svc.lower().startswith("bearer ") else _svc
if needs_apipilot:
try:
apipilot_t0 = providers_apipilot._monotonic_now()
apipilot_tools_pass1 = await providers_apipilot._apipilot_fetch_tools(
auth_header=apipilot_auth_header,
demo_session=None,
force_refresh=False,
)
app_logging.logger.info(
"[APIPILOT] REASONING PASS-1: tool list ready N=%d t=%dms auth=%s",
len(apipilot_tools_pass1),
int((providers_apipilot._monotonic_now() - apipilot_t0) * 1000),
"Y" if apipilot_auth_header else "-",
)
except Exception as exc:
app_logging.logger.warning("[APIPILOT] REASONING: tool-list fetch failed, ignoring: %s", exc)
apipilot_tools_pass1 = []
inject_apipilot_text_pass1 = services_tool_context._resolve_apipilot_reasoning_context_block(
apipilot_tools_pass1,
call_result=None,
)
user_context_parts: list[str] = []
# ─── USER FIX BUG 3: TODAY fixed context block → PREPEND to user_context too
# (the same anti-hallucination block gets prefixed in the SYSTEM instructions
# path via _augment_instructions_with_profile; we also prepend here so the
# OPENAI/ANYSCALE messages[] array (where caller context is user_message[0])
# ALSO gets the same guard.)
# ─── USER FIX 2026-09-11 HALLUCINATION: voice_lock_block FIRST position
voice_lock_block = services_context._build_voice_rules_head_lock_block(profile=profile_obj)
if voice_lock_block.strip():
user_context_parts.append(voice_lock_block)
today_block = services_context._build_today_fixed_context_block()
if today_block.strip():
user_context_parts.append(today_block)
if inject_episode_text:
user_context_parts.append(inject_episode_text)
if inject_profile_text:
user_context_parts.append(inject_profile_text)
if inject_reports_text:
user_context_parts.append(inject_reports_text)
if inject_summary_text:
user_context_parts.append(inject_summary_text)
if inject_apipilot_text_pass1:
user_context_parts.append(inject_apipilot_text_pass1)
original_user_context = (req.user_context or "").strip()
if original_user_context:
user_context_parts.append(original_user_context)
user_context_parts = services_context._dedup_context_blocks_by_type(user_context_parts)
if original_user_context:
server_injected_types_in_client_ctx: set = set()
for part in user_context_parts:
if original_user_context and (part or "").strip() == original_user_context:
continue
tid = services_context._classify_context_block(part)
if tid is None:
continue
for marker_tid, marker in services_context._CONTEXT_DEDUPE_MARKERS:
if marker_tid == tid and marker and marker in original_user_context:
server_injected_types_in_client_ctx.add(tid)
break
if server_injected_types_in_client_ctx:
new_parts: list[str] = []
for part in user_context_parts:
if (part or "").strip() == original_user_context:
new_parts.append(part)
continue
tid = services_context._classify_context_block(part)
if tid in server_injected_types_in_client_ctx:
continue
new_parts.append(part)
if settings.S2S_DEBUG_PROMPT and new_parts != user_context_parts:
app_logging.logger.info(
"[INJECT-DEDUPE] dropped server-injected profile/episode/reports/summary because the same block type was already present in req.user_context client-side context=%s kept=%d",
", ".join(sorted(server_injected_types_in_client_ctx)),
len(new_parts),
)
user_context_parts = new_parts
# ─── 2026-09-11 MARKER LEAK GUARD: strip invisible internal sentinels from EACH part.
stripped_parts: list[str] = []
for p in user_context_parts:
sp = services_context._strip_internal_markers(p)
if sp:
stripped_parts.append(sp)
user_context_parts = stripped_parts
effective_user_context = "\n\n".join(user_context_parts)
if settings.S2S_INJECT_PROFILE:
any_injected = bool(inject_episode_text or inject_profile_text or inject_reports_text or inject_summary_text)
if any_injected:
app_logging.logger.info(
"[INJECT-PROFILE] REASONING user_context final parts=%d serverEpisodeLen=%d serverProfileLen=%d serverReportsLen=%d serverSummaryLen=%d browserUserCtxLen=%d joinedLen=%d",
len(user_context_parts),
len(inject_episode_text),
len(inject_profile_text),
len(inject_reports_text),
len(inject_summary_text),
len(original_user_context),
len(effective_user_context),
)
if settings.S2S_DEBUG_PROMPT and voice_lock_block.strip():
app_logging.logger.info(
"[DEBUG-VOICELOCK][REASONING augment] FULL voice lock block (len=%d):\n%s\n",
len(voice_lock_block),
services_context._strip_internal_markers(voice_lock_block),
)
if settings.S2S_DEBUG_PROMPT and inject_episode_text.strip():
app_logging.logger.info(
"[DEBUG-EPISODE][REASONING augment] FULL podcast episode block (len=%d):\n%s\n",
len(inject_episode_text),
services_context._strip_internal_markers(inject_episode_text),
)
if settings.S2S_DEBUG_PROMPT and today_block.strip():
app_logging.logger.info(
"[DEBUG-TODAY][REASONING augment] FULL today block (len=%d):\n%s\n",
len(today_block),
services_context._strip_internal_markers(today_block),
)
if settings.S2S_DEBUG_PROMPT and inject_reports_text.strip():
app_logging.logger.info(
"[DEBUG-REPORTS][REASONING augment] FULL reports list block (len=%d):\n%s\n",
len(inject_reports_text),
services_context._strip_internal_markers(inject_reports_text),
)
if settings.S2S_DEBUG_PROMPT and inject_summary_text.strip():
app_logging.logger.info(
"[DEBUG-SUMMARY][REASONING augment] FULL latest summary block (len=%d):\n%s\n",
len(inject_summary_text),
services_context._strip_internal_markers(inject_summary_text),
)
if settings.S2S_DEBUG_PROMPT and inject_profile_text.strip():
app_logging.logger.info(
"[DEBUG-PROFILE][REASONING augment] FULL profile block (len=%d):\n%s\n",
len(inject_profile_text),
services_context._strip_internal_markers(inject_profile_text),
)
if settings.S2S_DEBUG_PROMPT and inject_apipilot_text_pass1.strip():
app_logging.logger.info(
"[DEBUG-APIPILOT][REASONING augment] FULL ApiPilot tools list block (len=%d):\n%s\n",
len(inject_apipilot_text_pass1),
services_context._strip_internal_markers(inject_apipilot_text_pass1),
)
if needs_apipilot and inject_apipilot_text_pass1.strip():
app_logging.logger.info(
"[INJECT-APIPILOT] REASONING PASS-1: inject tool list (len=%d, Ntools=%d) into instructions and user_context.",
len(inject_apipilot_text_pass1),
len(apipilot_tools_pass1),
)
effective_instructions = services_context._augment_instructions_with_profile(
req.instructions or "",
inject_profile_text,
inject_reports_text,
inject_summary_text,
inject_episode_text,
profile_obj=profile_obj,
)
if inject_apipilot_text_pass1.strip():
effective_instructions = (
effective_instructions + "\n\n" if effective_instructions else ""
) + inject_apipilot_text_pass1
else:
effective_instructions = (req.instructions or "").strip()
if inject_apipilot_text_pass1.strip():
app_logging.logger.info(
"[INJECT-APIPILOT] REASONING PASS-1: inject tool list (len=%d, Ntools=%d) into instructions (inject_profile=false).",
len(inject_apipilot_text_pass1),
len(apipilot_tools_pass1),
)
effective_instructions = (
effective_instructions + "\n\n" if effective_instructions else ""
) + inject_apipilot_text_pass1
if settings.S2S_DEBUG_PROMPT and inject_apipilot_text_pass1.strip():
app_logging.logger.info(
"[DEBUG-APIPILOT][REASONING augment] FULL ApiPilot tools list block (len=%d):\n%s\n",
len(inject_apipilot_text_pass1),
services_context._strip_internal_markers(inject_apipilot_text_pass1),
)
# ────────────────────────────────────────────────────────────────────
# Mode A: NODE_RED forwards the complete payload; the flow decides behavior.
# Stage 1 (log-only) returns {answer: "", log_only: true}, allowing the browser
# to leave speech generation to the S2S backend. Later stages can return
# {answer: "...", log_only: false}. Expected response fields include answer,
# log_only, usage, debug and latency_ms.
# ────────────────────────────────────────────────────────────────────
if settings.S2S_REASONING_TYPE == "NODE_RED":
if not settings.NODE_RED_REASONING_URL:
raise HTTPException(
status_code=503,
detail="S2S_REASONING_NODE_RED_URL no está configurado. Configure esta variable de entorno con la dirección de Node-RED (por ejemplo, http://localhost:1881).",
)
app_logging.logger.info(
"[INJECT-PROFILE] REASONING->NODE_RED body fields. instructionsLen=%d userCtxLen=%d phoneLen=%d episodeIdLen=%d",
len(effective_instructions),
len(effective_user_context),
len(phone),
len(episode_id),
)
upstream_body = {
"transcript": transcript,
"instructions": effective_instructions,
"language": (req.language or "").strip(),
"user_context": effective_user_context,
}
if settings.S2S_DEBUG_PROMPT:
app_logging.logger.info(
"[DEBUG-PROMPT][REASONING → NODE_RED] FULL upstream_body JSON:\n%s\n",
json.dumps(upstream_body, ensure_ascii=False, indent=2),
)
app_logging.logger.debug(
"[EXT][NODE_RED] reasoning POST %s/api/reasoning lang=%s transcriptLen=%d",
settings.NODE_RED_REASONING_URL,
(req.language or "")[:20] or "auto",
len(transcript),
)
try:
async with httpx.AsyncClient(timeout=120.0) as http:
resp = await http.post(
f"{settings.NODE_RED_REASONING_URL}/api/reasoning",
json=upstream_body,
headers={
"Content-Type": "application/json",
"X-S2S-Caller": "demo-server",
},
)
except httpx.RequestError as exc:
app_logging.logger.warning("[EXT][NODE_RED] unreachable: %r", exc)
raise HTTPException( # noqa: B904
status_code=502, detail="No se puede conectar con el motor de razonamiento de Node-RED."
)
app_logging.logger.debug(
"[EXT][NODE_RED] reasoning RESP status=%s len=%dB",
resp.status_code,
len(resp.content or b""),
)
if resp.status_code != 200:
app_logging.logger.warning("[EXT][NODE_RED] failed %s: %s", resp.status_code, resp.text[:500])
raise HTTPException(
status_code=502,
detail=f"El razonamiento de Node-RED falló (HTTP {resp.status_code}).",
)
try:
payload = resp.json()
except Exception:
app_logging.logger.warning("[EXT][NODE_RED] invalid JSON: %s", resp.text[:500])
raise HTTPException(status_code=502, detail="Node-RED devolvió un JSON no válido.") # noqa: B904
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):
app_logging.logger.warning(
"[EXT][NODE_RED] invalid answer type: %s", json.dumps(payload, ensure_ascii=True)[:800]
)
raise HTTPException(status_code=502, detail="Node-RED devolvió un campo answer no válido.")
answer_stripped = answer.strip()
# An empty answer is intentional in log-only mode; forward the flag.
if not answer_stripped and not log_only:
app_logging.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 no devolvió una respuesta ni la marca log_only.")
usage = payload.get("usage") if isinstance(payload, dict) else None
if isinstance(usage, dict):
app_logging.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", "caller_profile_keys", "debug"):
if isinstance(payload, dict) and key in payload:
extra[key] = payload[key]
if log_only:
app_logging.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:
app_logging.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: dict[str, Any] = {"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 app_logging.logger.level <= logging.DEBUG})
# Capture the ApiPilot marker, execute its tool and run reasoning pass 2.
tool_name_p1, tool_args_p1 = services_tool_context._apipilot_parse_call_marker(answer_stripped)
if tool_name_p1:
app_logging.logger.info(
"[APIPILOT-CALL-NAME] USE=NODE_RED_PASS2_TRIGGER name=%r argsKeys=%s",
tool_name_p1,
sorted(list((tool_args_p1 or {}).keys())),
)
app_logging.logger.info(
"[APIPILOT] REASONING PASS-2 trigger NODE_RED marker name=%s args=%s",
tool_name_p1,
json.dumps(tool_args_p1 or {}, ensure_ascii=True)[:300],
)
app_logging.logger.info(
"[APIPILOT-CALL-NAME] USE=NODE_RED_PASS2_EXEC_HELPER name=%r → forward to _apipilot_execute_tool",
tool_name_p1,
)
tool_env_p1 = await providers_apipilot._apipilot_execute_tool(
auth_header=apipilot_auth_header,
demo_session=None,
name=tool_name_p1,
arguments=tool_args_p1 or {},
)
is_tool_err = not bool(tool_env_p1.get("success"))
tool_data = tool_env_p1.get("data")
if isinstance(tool_data, str):
tool_text_p1 = tool_data
elif tool_data is None:
tool_text_p1 = ""
else:
try:
tool_text_p1 = json.dumps(tool_data, ensure_ascii=False, indent=2)
except Exception:
tool_text_p1 = str(tool_data)
if is_tool_err and isinstance(tool_env_p1.get("error"), dict):
err = tool_env_p1["error"]
err_head = f"[{err.get('code')}] {err.get('message')}"
tool_text_p1 = (err_head + ("\n" + tool_text_p1 if tool_text_p1.strip() else "")).strip()
inject_apipilot_text_pass2 = services_tool_context._resolve_apipilot_reasoning_context_block(
[],
call_result={
"name": tool_name_p1,
"text": tool_text_p1,
"error": is_tool_err,
},
)
app_logging.logger.info(
"[APIPILOT] REASONING PASS-2 execute name=%s success=%s httpResultLen=%d trigger second Node-RED call",
tool_name_p1,
str(not is_tool_err).lower(),
len(tool_text_p1),
)
# Pass-2 context replaces the tool list with the execution result,
# preserving voice/date/profile context.
user_ctx_parts_2: list[str] = []
if voice_lock_block.strip():
user_ctx_parts_2.append(voice_lock_block)
if today_block.strip():
user_ctx_parts_2.append(today_block)
if inject_episode_text:
user_ctx_parts_2.append(inject_episode_text)
if inject_profile_text:
user_ctx_parts_2.append(inject_profile_text)
if inject_reports_text:
user_ctx_parts_2.append(inject_reports_text)
if inject_summary_text:
user_ctx_parts_2.append(inject_summary_text)
if inject_apipilot_text_pass2:
user_ctx_parts_2.append(inject_apipilot_text_pass2)
if original_user_context:
user_ctx_parts_2.append(original_user_context)
user_ctx_parts_2 = services_context._dedup_context_blocks_by_type(user_ctx_parts_2)
stripped_2: list[str] = []
for p in user_ctx_parts_2:
sp = services_context._strip_internal_markers(p)
if sp:
stripped_2.append(sp)
user_ctx_parts_2 = stripped_2
effective_user_ctx_2 = "\n\n".join(user_ctx_parts_2)
# Preserve augmentation without CALL-marker instructions; the result
# block supplies the pass-2 response instructions.
if settings.S2S_INJECT_PROFILE:
eff_inst_2 = services_context._augment_instructions_with_profile(
req.instructions or "",
inject_profile_text,
inject_reports_text,
inject_summary_text,
inject_episode_text,
profile_obj=profile_obj,
)
else:
eff_inst_2 = (req.instructions or "").strip()
if inject_apipilot_text_pass2.strip():
eff_inst_2 = (eff_inst_2 + "\n\n" if eff_inst_2 else "") + inject_apipilot_text_pass2
upstream_body_2 = {
"transcript": transcript,
"instructions": eff_inst_2,
"language": (req.language or "").strip(),
"user_context": effective_user_ctx_2,
}
if settings.S2S_DEBUG_PROMPT:
app_logging.logger.info(
"[DEBUG-PROMPT][REASONING → NODE_RED PASS-2] FULL upstream_body_2 JSON:\n%s\n",
json.dumps(upstream_body_2, ensure_ascii=False, indent=2),
)
try:
async with httpx.AsyncClient(timeout=120.0) as http2:
resp2 = await http2.post(
f"{settings.NODE_RED_REASONING_URL}/api/reasoning",
json=upstream_body_2,
headers={
"Content-Type": "application/json",
"X-S2S-Caller": "demo-server-pass2",
},
)
except httpx.RequestError as exc:
app_logging.logger.warning("[EXT][NODE_RED PASS-2] unreachable: %r", exc)
raise HTTPException( # noqa: B904
status_code=502,
detail="No se puede conectar con el motor de razonamiento de Node-RED (segunda pasada).",
)
if resp2.status_code != 200:
app_logging.logger.warning("[EXT][NODE_RED PASS-2] failed %s: %s", resp2.status_code, resp2.text[:500])
raise HTTPException(
status_code=502,
detail=f"La segunda pasada del razonamiento de Node-RED falló (HTTP {resp2.status_code}).",
)
try:
payload2 = resp2.json()
except Exception:
app_logging.logger.warning("[EXT][NODE_RED PASS-2] invalid JSON: %s", resp2.text[:500])
raise HTTPException(status_code=502, detail="Node-RED devolvió un JSON no válido (segunda pasada).") # noqa: B904
final_ans = payload2.get("answer") if isinstance(payload2, dict) else None
if not isinstance(final_ans, str):
# Fallback: the first message and raw result.
app_logging.logger.warning("[EXT][NODE_RED PASS-2] invalid answer, falling back to raw result text")
final_ans = tool_text_p1 or answer_stripped
final_stripped = final_ans.strip()
# Pass 2 always sets log_only=False: its final answer is ready for speech.
out2: dict = {"answer": final_stripped}
usage2 = payload2.get("usage") if isinstance(payload2, dict) else None
if usage2:
out2["usage_pass2"] = usage2
out2["apipilot_invoked"] = {
"name": tool_name_p1,
"success": not is_tool_err,
"result_length": len(tool_text_p1),
}
app_logging.logger.info(
"[Vocero REASONING] engine=NODE_RED PASS-2 transcript=%s finalAnswer=%s apipilot=%s",
transcript[:300],
final_stripped[:500],
json.dumps(out2["apipilot_invoked"], ensure_ascii=True),
)
return JSONResponse(out2)
# Without a marker, return the original pass-1 answer.
return JSONResponse(out)
# ────────────────────────────────────────────────────────────────────
# Mode B: OPENAI calls OpenAI Chat Completions directly.
# ────────────────────────────────────────────────────────────────────
if not settings.OPENAI_API_KEY:
raise HTTPException(status_code=503, detail="OPENAI_API_KEY no está configurado.")
system_parts = []
instructions = effective_instructions or ((req.instructions or "").strip())
if instructions:
system_parts.append(instructions)
if effective_user_context.strip():
system_parts.append(f"User context:\n{effective_user_context.strip()}")
if inject_apipilot_text_pass1:
system_parts.append(inject_apipilot_text_pass1)
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.")
app_logging.logger.info(
"[INJECT-PROFILE] REASONING->OPENAI system message parts=%d instructionsLen=%d userCtxLen=%d phoneLen=%d episodeIdLen=%d",
len(system_parts),
len(effective_instructions),
len(effective_user_context),
len(phone),
len(episode_id),
)
system_msg = "\n\n".join(system_parts)
body = {
"model": settings.OPENAI_REASONING_MODEL,
"messages": [
{"role": "system", "content": system_msg},
{"role": "user", "content": transcript},
],
}
if settings.S2S_DEBUG_PROMPT:
app_logging.logger.info(
"[DEBUG-PROMPT][REASONING → OPENAI] FULL SYSTEM message (len=%d):\n%s\n",
len(system_msg),
system_msg,
)
app_logging.logger.info(
"[DEBUG-PROMPT][REASONING → OPENAI] USER transcript (len=%d):\n%s\n",
len(transcript),
transcript,
)
app_logging.logger.debug(
"[EXT][OPENAI] reasoning POST %s/chat/completions model=%s systemLen=%d transcriptLen=%d language=%s",
settings.OPENAI_BASE_URL,
settings.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"{settings.OPENAI_BASE_URL}/chat/completions",
headers=_openai_headers(),
json=body,
)
except httpx.RequestError as exc:
app_logging.logger.warning("OpenAI reasoning unreachable: %r", exc)
raise HTTPException(status_code=502, detail="No se puede conectar con el servicio de razonamiento de OpenAI.") # noqa: B904
app_logging.logger.debug(
"[EXT][OPENAI] reasoning RESP status=%s len=%dB",
resp.status_code,
len(resp.content or b""),
)
if resp.status_code != 200:
app_logging.logger.warning("OpenAI reasoning failed %s: %s", resp.status_code, resp.text[:400])
raise HTTPException(status_code=502, detail=f"El razonamiento de OpenAI falló ({resp.status_code}).")
try:
payload = resp.json()
except Exception:
app_logging.logger.warning("OpenAI reasoning returned invalid JSON: %s", resp.text[:400])
raise HTTPException(status_code=502, detail="El servicio de razonamiento de OpenAI devolvió un JSON no válido.") # noqa: B904
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):
app_logging.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:
app_logging.logger.warning(
"OpenAI reasoning returned empty answer: %s", json.dumps(payload, ensure_ascii=True)[:800]
)
raise HTTPException(status_code=502, detail="El servicio de razonamiento de OpenAI no devolvió una respuesta.")
app_logging.logger.info("[Vocero REASONING] engine=OPENAI transcript=%s answer=%s", transcript[:300], answer[:500])
# Capture the ApiPilot marker, execute its tool and run OpenAI pass 2.
tool_name_p1_oai, tool_args_p1_oai = services_tool_context._apipilot_parse_call_marker(answer)
if tool_name_p1_oai:
app_logging.logger.info(
"[APIPILOT-CALL-NAME] USE=OPENAI_PASS2_TRIGGER name=%r argsKeys=%s",
tool_name_p1_oai,
sorted(list((tool_args_p1_oai or {}).keys())),
)
app_logging.logger.info(
"[APIPILOT] REASONING PASS-2 trigger OPENAI marker name=%s args=%s",
tool_name_p1_oai,
json.dumps(tool_args_p1_oai or {}, ensure_ascii=True)[:300],
)
app_logging.logger.info(
"[APIPILOT-CALL-NAME] USE=OPENAI_PASS2_EXEC_HELPER name=%r → forward to _apipilot_execute_tool",
tool_name_p1_oai,
)
tool_env_oai_p1 = await providers_apipilot._apipilot_execute_tool(
auth_header=apipilot_auth_header,
demo_session=None,
name=tool_name_p1_oai,
arguments=tool_args_p1_oai or {},
)
is_tool_err_oai = not bool(tool_env_oai_p1.get("success"))
tool_data_oai = tool_env_oai_p1.get("data")
if isinstance(tool_data_oai, str):
tool_text_oai = tool_data_oai
elif tool_data_oai is None:
tool_text_oai = ""
else:
try:
tool_text_oai = json.dumps(tool_data_oai, ensure_ascii=False, indent=2)
except Exception:
tool_text_oai = str(tool_data_oai)
if is_tool_err_oai and isinstance(tool_env_oai_p1.get("error"), dict):
err_oai = tool_env_oai_p1["error"]
err_oai_head = f"[{err_oai.get('code')}] {err_oai.get('message')}"
tool_text_oai = (err_oai_head + ("\n" + tool_text_oai if tool_text_oai.strip() else "")).strip()
inject_apipilot_pass2_oai = services_tool_context._resolve_apipilot_reasoning_context_block(
[],
call_result={
"name": tool_name_p1_oai,
"text": tool_text_oai,
"error": is_tool_err_oai,
},
)
app_logging.logger.info(
"[APIPILOT] REASONING PASS-2 OPENAI execute name=%s success=%s resultLen=%d → second chat/completions call",
tool_name_p1_oai,
str(not is_tool_err_oai).lower(),
len(tool_text_oai),
)
# Build pass 2 with the same instructions/context structure, replacing
# inject_apipilot_text_pass1 with the result block inject_apipilot_pass2_oai.
user_ctx_oai_2: list[str] = []
if voice_lock_block.strip():
user_ctx_oai_2.append(voice_lock_block)
if today_block.strip():
user_ctx_oai_2.append(today_block)
if inject_episode_text:
user_ctx_oai_2.append(inject_episode_text)
if inject_profile_text:
user_ctx_oai_2.append(inject_profile_text)
if inject_reports_text:
user_ctx_oai_2.append(inject_reports_text)
if inject_summary_text:
user_ctx_oai_2.append(inject_summary_text)
if inject_apipilot_pass2_oai:
user_ctx_oai_2.append(inject_apipilot_pass2_oai)
if original_user_context:
user_ctx_oai_2.append(original_user_context)
user_ctx_oai_2 = services_context._dedup_context_blocks_by_type(user_ctx_oai_2)
stripped_oai_2: list[str] = []
for p in user_ctx_oai_2:
sp = services_context._strip_internal_markers(p)
if sp:
stripped_oai_2.append(sp)
user_ctx_oai_2 = stripped_oai_2
eff_user_ctx_oai_2 = "\n\n".join(user_ctx_oai_2)
if settings.S2S_INJECT_PROFILE:
eff_inst_oai_2 = services_context._augment_instructions_with_profile(
req.instructions or "",
inject_profile_text,
inject_reports_text,
inject_summary_text,
inject_episode_text,
profile_obj=profile_obj,
)
else:
eff_inst_oai_2 = (req.instructions or "").strip()
sys_parts_oai_2: list[str] = []
instr_oai_2 = eff_inst_oai_2 or ((req.instructions or "").strip())
if instr_oai_2:
sys_parts_oai_2.append(instr_oai_2)
if eff_user_ctx_oai_2.strip():
sys_parts_oai_2.append(f"User context:\n{eff_user_ctx_oai_2.strip()}")
if inject_apipilot_pass2_oai:
sys_parts_oai_2.append(inject_apipilot_pass2_oai)
if req.language.strip():
sys_parts_oai_2.append(
"Reply only with the final assistant answer text. "
f"Keep the answer natural and concise in this language: {req.language.strip()}."
)
else:
sys_parts_oai_2.append(
"Reply only with the final assistant answer text. Keep the answer natural and concise."
)
system_msg_oai_2 = "\n\n".join(sys_parts_oai_2)
body_oai_2 = {
"model": settings.OPENAI_REASONING_MODEL,
"messages": [
{"role": "system", "content": system_msg_oai_2},
{"role": "user", "content": transcript},
],
}
if settings.S2S_DEBUG_PROMPT:
app_logging.logger.info(
"[DEBUG-PROMPT][REASONING → OPENAI PASS-2] FULL SYSTEM message (len=%d):\n%s\n",
len(system_msg_oai_2),
system_msg_oai_2,
)
try:
async with httpx.AsyncClient(timeout=30.0) as http_oai2:
resp_oai_2 = await http_oai2.post(
f"{settings.OPENAI_BASE_URL}/chat/completions",
headers=_openai_headers(),
json=body_oai_2,
)
except httpx.RequestError as exc:
app_logging.logger.warning("[EXT][OPENAI PASS-2] unreachable: %r", exc)
raise HTTPException( # noqa: B904
status_code=502,
detail="No se puede conectar con el servicio de razonamiento de OpenAI (segunda pasada).",
)
if resp_oai_2.status_code != 200:
app_logging.logger.warning(
"[EXT][OPENAI PASS-2] failed %s: %s", resp_oai_2.status_code, resp_oai_2.text[:400]
)
raise HTTPException(
status_code=502,
detail=f"La segunda pasada del razonamiento de OpenAI falló ({resp_oai_2.status_code}).",
)
try:
payload_oai_2 = resp_oai_2.json()
except Exception:
app_logging.logger.warning("[EXT][OPENAI PASS-2] invalid JSON: %s", resp_oai_2.text[:400])
raise HTTPException( # noqa: B904
status_code=502,
detail="El servicio de razonamiento de OpenAI devolvió un JSON no válido (segunda pasada).",
)
final_oai_ans = ""
choices_oai_2 = payload_oai_2.get("choices")
if isinstance(choices_oai_2, list) and choices_oai_2:
msg_oai_2 = choices_oai_2[0].get("message") if isinstance(choices_oai_2[0], dict) else None
if isinstance(msg_oai_2, dict):
content_oai_2 = msg_oai_2.get("content")
if isinstance(content_oai_2, str):
final_oai_ans = content_oai_2.strip()
usage_oai_2 = payload_oai_2.get("usage")
if not final_oai_ans:
# Last-resort fallback: raw tool-result text.
app_logging.logger.warning("[EXT][OPENAI PASS-2] empty answer, falling back to raw tool-result text")
final_oai_ans = (tool_text_oai or answer).strip()
final_out_oai: dict = {"answer": final_oai_ans}
if usage_oai_2:
final_out_oai["usage_pass2"] = usage_oai_2
final_out_oai["apipilot_invoked"] = {
"name": tool_name_p1_oai,
"success": not is_tool_err_oai,
"result_length": len(tool_text_oai),
}
app_logging.logger.info(
"[Vocero REASONING] engine=OPENAI PASS-2 transcript=%s finalAnswer=%s apipilot=%s",
transcript[:300],
final_oai_ans[:500],
json.dumps(final_out_oai["apipilot_invoked"], ensure_ascii=True),
)
return JSONResponse(final_out_oai)
# Without a marker, return the original pass-1 answer.
return JSONResponse({"answer": answer})
async def _forward_agent_text_to_nodered(payload: dict) -> None:
"""Forward native-backend TTS responses to Node-RED's stage-1 logging endpoint.
Ignore unavailable or unconfigured Node-RED so the realtime loop continues.
"""
if settings.S2S_REASONING_TYPE != "NODE_RED" or not settings.NODE_RED_REASONING_URL:
return
url = f"{settings.NODE_RED_REASONING_URL}/api/log/system-response"
app_logging.logger.debug(
"[EXT][NODE_RED] forward system-response POST %s len=%d source=%s",
settings.NODE_RED_REASONING_URL,
len(str(payload.get("tts", "")) or 0), # type: ignore[arg-type] # Preserve the legacy empty-TTS failure.
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:
app_logging.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:
app_logging.logger.debug("[EXT][NODE_RED] forward system-response unreachable: %r", exc)
except Exception as exc: # noqa: BLE001 — never interrupt the realtime loop
app_logging.logger.debug("[EXT][NODE_RED] forward system-response unexpected: %r", exc)