diff --git a/api/admin/reporting.py b/api/admin/reporting.py index 7fa4b20..6e98144 100644 --- a/api/admin/reporting.py +++ b/api/admin/reporting.py @@ -23,10 +23,10 @@ def admin_report( ) -> None: admin_chat_id = environ.get("ADMIN_CHAT_ID") instance_name = environ.get("FRIENDLY_INSTANCE_NAME") - formatted_message = f"reporte admin desde {instance_name}: {message}" + formatted_message = f"admin report from {instance_name}: {message}" if extra_context: - context_details = "\n\ncontexto adicional:" + context_details = "\n\nadditional context:" for key, value in extra_context.items(): context_details += f"\n{key}: {_format_context_value(key, value)}" formatted_message += context_details @@ -45,12 +45,12 @@ def _format_context_value(key: str, value: Any) -> Any: units = int(value) except (TypeError, ValueError): return value - return f"{format_credit_units(units)} créditos ({units} unidades)" + return f"{format_credit_units(units)} credits ({units} units)" def _format_error(error: Exception, *, redact: Redactor) -> str: - details = f"\n\ntipo de error: {type(error).__name__}" - details += f"\nmensaje de error: {redact(str(error))}" + details = f"\n\nerror type: {type(error).__name__}" + details += f"\nerror message: {redact(str(error))}" if error.__traceback__ is not None: formatted_traceback = "".join( traceback.format_exception(type(error), error, error.__traceback__) diff --git a/api/ai/pricing.py b/api/ai/pricing.py index 03a6a46..41fd68f 100644 --- a/api/ai/pricing.py +++ b/api/ai/pricing.py @@ -16,6 +16,7 @@ CREDIT_UNIT_USD_MICROS = CREDIT_CEIL_DIVISOR_USD_MICROS // 10 CHAT_OUTPUT_TOKEN_LIMIT = 1024 +REASONING_CHAT_OUTPUT_TOKEN_LIMIT = 8192 VISION_OUTPUT_TOKEN_LIMIT = 512 IMAGE_CONTEXT_EXTRA_TOKENS_ESTIMATE = 1_200 WEB_SEARCH_USD_MICROS_PER_REQUEST = 1_660 @@ -36,6 +37,14 @@ } +def chat_output_token_limit(model: str) -> int: + """Return a larger budget only for chat models that use hidden reasoning.""" + + if str(model or "").split(":", 1)[0] == "deepseek/deepseek-v4-flash": + return REASONING_CHAT_OUTPUT_TOKEN_LIMIT + return CHAT_OUTPUT_TOKEN_LIMIT + + @dataclass class AIUsageResult: """Structured AI response with billing metadata.""" @@ -126,17 +135,22 @@ def estimate_chat_reserve_credits( *, system_message: Optional[Mapping[str, Any]], messages: Sequence[Mapping[str, Any]], - max_output_tokens: int = CHAT_OUTPUT_TOKEN_LIMIT, + max_output_tokens: Optional[int] = None, extra_input_tokens: int = 0, model: str = "deepseek/deepseek-v4-flash", ) -> int: pricing = MODEL_PRICING_USD_MICROS.get(model, MODEL_PRICING_USD_MICROS["deepseek/deepseek-v4-flash"]) + output_token_limit = ( + chat_output_token_limit(model) + if max_output_tokens is None + else max_output_tokens + ) input_tokens = estimate_message_tokens(messages) + extra_input_tokens if system_message: input_tokens += estimate_message_tokens([system_message]) usd_micros = ( input_tokens * pricing["input_per_million"] - + max_output_tokens * pricing["output_per_million"] + + output_token_limit * pricing["output_per_million"] ) // 1_000_000 return credit_units_from_usd_micros(usd_micros) diff --git a/api/index.py b/api/index.py index 86dbb88..9b8c0f0 100644 --- a/api/index.py +++ b/api/index.py @@ -127,15 +127,15 @@ extract_user_id as _billing_extract_user_id, ) from api.ai.pricing import ( - CHAT_OUTPUT_TOKEN_LIMIT, AIUsageResult, + MODEL_PRICING_USD_MICROS, VISION_OUTPUT_TOKEN_LIMIT, calculate_billing_for_segments, + chat_output_token_limit, + ensure_mapping, estimate_chat_reserve_credits, estimate_message_tokens, estimate_vision_reserve_credits, - ensure_mapping, - MODEL_PRICING_USD_MICROS, ) from api.links.agent_tools import fetch_url_content from api.core.constants import ADMIN_CONFIG_DENIAL_MESSAGE, PROMPT_NO_MARKDOWN @@ -708,7 +708,7 @@ def estimate_ai_base_reserve_credits( reserve = estimate_chat_reserve_credits( system_message=system_message, messages=messages, - max_output_tokens=CHAT_OUTPUT_TOKEN_LIMIT, + max_output_tokens=chat_output_token_limit(PRIMARY_CHAT_MODEL), extra_input_tokens=extra_input_tokens, model=PRIMARY_CHAT_MODEL, ) diff --git a/api/providers/openrouter.py b/api/providers/openrouter.py index 3a810c7..4580594 100644 --- a/api/providers/openrouter.py +++ b/api/providers/openrouter.py @@ -4,7 +4,7 @@ from typing import Any, Callable, Dict, Iterator, List, Optional -from api.ai.pricing import AIUsageResult, CHAT_OUTPUT_TOKEN_LIMIT +from api.ai.pricing import AIUsageResult, chat_output_token_limit from api.providers.runtime import ProviderRuntime, ProviderRuntimeDeps from api.tools.runtime import ToolRuntime from api.providers.base import StreamingAIProvider @@ -89,6 +89,7 @@ def stream( return has_tools = bool(extra_tools) or enable_web_search + output_token_limit = chat_output_token_limit(self._primary_model) try: if not has_tools: @@ -96,7 +97,7 @@ def stream( request_kwargs: Dict[str, Any] = { "model": self._primary_model, "messages": [system_message] + list(messages), - "max_tokens": max_tokens if max_tokens is not None else CHAT_OUTPUT_TOKEN_LIMIT, + "max_tokens": max_tokens if max_tokens is not None else output_token_limit, "stream": True, } @@ -113,7 +114,7 @@ def stream( request_kwargs = { "model": self._primary_model, "messages": [system_message] + list(messages), - "max_tokens": max_tokens if max_tokens is not None else CHAT_OUTPUT_TOKEN_LIMIT, + "max_tokens": max_tokens if max_tokens is not None else output_token_limit, "stream": True, "tools": [self._build_web_search_tool()], } @@ -143,7 +144,7 @@ def stream( request_kwargs = { "model": self._primary_model, "messages": [system_message] + final_messages, - "max_tokens": max_tokens if max_tokens is not None else CHAT_OUTPUT_TOKEN_LIMIT, + "max_tokens": max_tokens if max_tokens is not None else output_token_limit, "stream": True, } for chunk in client.chat.completions.create(**request_kwargs): diff --git a/api/providers/runtime.py b/api/providers/runtime.py index 71e6dbe..91f8067 100644 --- a/api/providers/runtime.py +++ b/api/providers/runtime.py @@ -11,7 +11,7 @@ from openai import APIConnectionError, APIStatusError, APITimeoutError, RateLimitError -from api.ai.pricing import AIUsageResult, CHAT_OUTPUT_TOKEN_LIMIT, ensure_mapping +from api.ai.pricing import AIUsageResult, chat_output_token_limit, ensure_mapping from api.core.logging import format_log_context, get_logger from api.providers.types import ( EmptyAssistantMessage, @@ -155,7 +155,7 @@ def _run_chat_completion( request_kwargs: Dict[str, Any] = { "model": self._deps.primary_model, "messages": [system_message] + current_messages, - "max_tokens": CHAT_OUTPUT_TOKEN_LIMIT, + "max_tokens": chat_output_token_limit(self._deps.primary_model), } tools_list: List[Dict[str, Any]] = [] @@ -169,7 +169,9 @@ def _run_chat_completion( try: for attempt in range(_MAX_RETRIES): try: - return client.chat.completions.create(**request_kwargs) + if attempt: + self._deps.increment_request_count() + response = client.chat.completions.create(**request_kwargs) except Exception as error: if _is_retryable_provider_error(error) and attempt < _MAX_RETRIES - 1: wait = 2**attempt @@ -193,6 +195,38 @@ def _run_chat_completion( time.sleep(wait) continue raise + choices = getattr(response, "choices", None) or [] + finish_reason = getattr(choices[0], "finish_reason", None) if choices else None + if ( + choices + and self._is_retryable_finish_response( + response, + choices[0], + finish_reason, + ) + and attempt < _MAX_RETRIES - 1 + ): + wait = 2**attempt + retry_context = dict(tool_context or {}) + retry_context.update( + { + "model": self._deps.primary_model, + "tool_round": round_idx + 1, + "finish_reason": finish_reason, + **self._response_diagnostics(response, choices[0]), + } + ) + logger.warning( + "openrouter: retryable finish_reason=%r retrying in %ss attempt=%d/%d%s", + finish_reason, + wait, + attempt + 1, + _MAX_RETRIES, + format_log_context(retry_context), + ) + time.sleep(wait) + continue + return response except Exception as error: error_context = dict(tool_context or {}) error_context.update( @@ -218,6 +252,95 @@ def _run_chat_completion( return None return None + def _is_retryable_finish_response( + self, + response: Any, + choice: Any, + finish_reason: Any, + ) -> bool: + diagnostics = self._response_diagnostics(response, choice) + if ( + diagnostics["has_content"] + or diagnostics["tool_call_count"] + or self._response_has_usage(response) + ): + return False + if finish_reason is None: + return True + if finish_reason != "error": + return False + + error = self._response_error(response, choice) + code = error.get("code") + try: + status_code = int(code) if code is not None else 0 + except (TypeError, ValueError): + status_code = 0 + if status_code in {408, 409, 429} or status_code >= 500: + return True + error_type = str((ensure_mapping(error.get("metadata")) or {}).get("error_type") or "") + return error_type in { + "rate_limit_exceeded", + "provider_overloaded", + "provider_unavailable", + "server", + "timeout", + } + + def _response_has_usage(self, response: Any) -> bool: + usage = self._deps.extract_usage_map(response) or {} + for key in ( + "cost", + "prompt_tokens", + "completion_tokens", + "total_tokens", + "input_tokens", + "output_tokens", + ): + try: + if float(usage.get(key) or 0) > 0: + return True + except (TypeError, ValueError): + continue + server_tool_use = ensure_mapping(usage.get("server_tool_use")) or {} + try: + return int(server_tool_use.get("web_search_requests") or 0) > 0 + except (TypeError, ValueError): + return False + + @staticmethod + def _response_error(response: Any, choice: Any) -> Dict[str, Any]: + return ( + ensure_mapping(getattr(choice, "error", None)) + or ensure_mapping(getattr(response, "error", None)) + or {} + ) + + @staticmethod + def _response_diagnostics(response: Any, choice: Any) -> Dict[str, Any]: + diagnostics: Dict[str, Any] = {} + fields = { + "response_id": getattr(response, "id", None), + "request_id": getattr(response, "_request_id", None), + "response_model": getattr(response, "model", None), + "provider": getattr(response, "provider", None), + "native_finish_reason": getattr(choice, "native_finish_reason", None), + } + diagnostics.update({key: value for key, value in fields.items() if value is not None}) + + error = ProviderRuntime._response_error(response, choice) + if error: + if error.get("code") is not None: + diagnostics["provider_error_code"] = error["code"] + metadata = ensure_mapping(error.get("metadata")) or {} + if metadata.get("error_type") is not None: + diagnostics["provider_error_type"] = metadata["error_type"] + + message = getattr(choice, "message", None) + diagnostics["has_content"] = bool(str(getattr(message, "content", "") or "").strip()) + diagnostics["tool_call_count"] = len(getattr(message, "tool_calls", None) or []) + return diagnostics + def _filter_known_calls( self, tool_calls: List[ToolCallLike], @@ -578,6 +701,8 @@ def _handle_stop_response( def _report_unexpected_finish( self, + response: Any, + choice: Any, finish_reason: Any, round_idx: int, *, @@ -586,7 +711,11 @@ def _report_unexpected_finish( ) -> None: unexpected_context = dict(tool_context or {}) unexpected_context.update( - {"model": self._deps.primary_model, "tool_round": round_idx + 1} + { + "model": self._deps.primary_model, + "tool_round": round_idx + 1, + **self._response_diagnostics(response, choice), + } ) logger.warning( "provider_runtime: unexpected finish_reason=%r%s", @@ -598,6 +727,8 @@ def _report_unexpected_finish( extra_context={ "model": self._deps.primary_model, "enable_web_search": enable_web_search, + "tool_round": round_idx + 1, + **self._response_diagnostics(response, choice), }, ) @@ -670,6 +801,8 @@ def _run_tool_rounds( ) self._report_unexpected_finish( + response, + choice, finish_reason, round_idx, enable_web_search=enable_web_search, diff --git a/tests/test_admin_reporting.py b/tests/test_admin_reporting.py index 5082880..cc94533 100644 --- a/tests/test_admin_reporting.py +++ b/tests/test_admin_reporting.py @@ -25,8 +25,9 @@ def test_admin_report_formats_error_traceback_from_exception(): index.app_runtime.admin.report("failed", captured_error) message = send_msg.call_args.args[1] - assert "tipo de error: RuntimeError" in message - assert "mensaje de error: boom" in message + assert message.startswith("admin report from test: failed") + assert "error type: RuntimeError" in message + assert "error message: boom" in message assert "RuntimeError: boom" in message assert "NoneType: None" not in message @@ -55,6 +56,31 @@ def test_admin_report_redacts_telegram_token_from_error_message_and_traceback(): assert "/bot/sendMessage" in message +def test_admin_report_formats_additional_context_in_english(): + with ( + patch.dict( + "api.admin.reporting.environ", + {"ADMIN_CHAT_ID": "1", "FRIENDLY_INSTANCE_NAME": "VPS"}, + clear=True, + ), + patch.object(index.app_runtime.telegram, "send_message") as send_msg, + ): + index.app_runtime.admin.report( + "OpenRouter unexpected finish_reason=None", + extra_context={ + "model": "deepseek/deepseek-v4-flash", + "enable_web_search": True, + }, + ) + + assert send_msg.call_args.args[1] == ( + "admin report from VPS: OpenRouter unexpected finish_reason=None" + "\n\nadditional context:" + "\nmodel: deepseek/deepseek-v4-flash" + "\nenable_web_search: True" + ) + + def test_telegram_request_redacts_token_in_error_log(capsys): fake_bot_auth = "123456" + ":" + "ABC-secret" error = requests.ConnectionError( diff --git a/tests/test_ai_billing_internal.py b/tests/test_ai_billing_internal.py index 6fb7870..c8ecfc9 100644 --- a/tests/test_ai_billing_internal.py +++ b/tests/test_ai_billing_internal.py @@ -8,7 +8,10 @@ from tests.support import make_ai_message_billing from api.billing.credit_units import whole_credits_to_units from api.ai.pricing import ( + CHAT_OUTPUT_TOKEN_LIMIT, + REASONING_CHAT_OUTPUT_TOKEN_LIMIT, calculate_billing_for_segments, + chat_output_token_limit, estimate_vision_reserve_credits, ) @@ -43,6 +46,16 @@ def test_build_insufficient_credits_message_mentions_group_balances(): assert "lo del grupo: 5.0" in message +def test_chat_output_token_limit_is_model_specific(): + assert ( + chat_output_token_limit("deepseek/deepseek-v4-flash") + == REASONING_CHAT_OUTPUT_TOKEN_LIMIT + == 8192 + ) + assert chat_output_token_limit("deepseek/deepseek-v4-flash:exacto") == 8192 + assert chat_output_token_limit("other/model") == CHAT_OUTPUT_TOKEN_LIMIT == 1024 + + def test_ai_message_billing_transcribe_success_response_prefixes(): billing = make_ai_message_billing( command="/transcribe", diff --git a/tests/test_ai_requests.py b/tests/test_ai_requests.py index 53c53e9..e941aa1 100644 --- a/tests/test_ai_requests.py +++ b/tests/test_ai_requests.py @@ -214,6 +214,9 @@ def test_estimate_ai_base_reserve_credits_uses_standard_chat_without_forced_sear monkeypatch, ): from api.index import estimate_ai_base_reserve_credits + from api.ai.pricing import chat_output_token_limit, estimate_chat_reserve_credits + + messages = [{"role": "user", "content": "CONTEXTO:\nMENSAJE:\nbuscá bitcoin hoy"}] monkeypatch.setattr("api.index.get_market_context", lambda: {}) monkeypatch.setattr("api.index.get_weather_context", lambda: {}) @@ -224,11 +227,15 @@ def test_estimate_ai_base_reserve_credits_uses_standard_chat_without_forced_sear lambda _context_data, **_kw: {"role": "system", "content": "sys"}, ) - reserve, metadata = estimate_ai_base_reserve_credits( - [{"role": "user", "content": "CONTEXTO:\nMENSAJE:\nbuscá bitcoin hoy"}] + reserve, metadata = estimate_ai_base_reserve_credits(messages) + expected_reserve = estimate_chat_reserve_credits( + system_message={"role": "system", "content": "sys"}, + messages=messages, + max_output_tokens=chat_output_token_limit(index.PRIMARY_CHAT_MODEL), + model=index.PRIMARY_CHAT_MODEL, ) - assert reserve == 3 + assert reserve == expected_reserve assert metadata == {} diff --git a/tests/test_provider_runtime.py b/tests/test_provider_runtime.py index 1db31fa..0ee0dfb 100644 --- a/tests/test_provider_runtime.py +++ b/tests/test_provider_runtime.py @@ -742,6 +742,185 @@ def _tool_then_stop_responses(): assert helper_execute_tool_fn.call_count == 2 +def _build_retry_runtime(responses, *, extract_usage=lambda _response: {}): + from api.ai.pricing import AIUsageResult + from api.providers.runtime import ProviderRuntime, ProviderRuntimeDeps + from api.tools.runtime import ToolRuntime + + client = _FakeClient(responses) + admin_report = MagicMock() + request_count = MagicMock() + runtime = ProviderRuntime( + ProviderRuntimeDeps( + get_client=lambda: client, + admin_report=admin_report, + increment_request_count=request_count, + build_web_search_tool=lambda: {"type": "web_search"}, + build_usage_result=lambda **kwargs: AIUsageResult( + kind=kwargs["kind"], + text=kwargs["text"], + model=kwargs["model"], + usage={}, + metadata=kwargs.get("metadata") or {}, + ), + extract_usage_map=extract_usage, + primary_model="deepseek/deepseek-v4-flash", + max_tool_rounds=5, + ), + ToolRuntime(), + ) + return runtime, client, admin_report, request_count + + +@pytest.mark.parametrize( + ("retryable_finish_reason", "error"), + [ + (None, None), + ( + "error", + { + "code": 503, + "metadata": {"error_type": "provider_unavailable"}, + }, + ), + ], +) +def test_provider_runtime_retries_invalid_finish_reason_then_returns_result( + retryable_finish_reason, + error, +): + from api.ai.pricing import chat_output_token_limit + + incomplete_choice = _FakeChoice( + retryable_finish_reason, + SimpleNamespace(content="", tool_calls=[], annotations=[]), + ) + incomplete_choice.error = error + incomplete_response = _FakeResponse([incomplete_choice]) + incomplete_response.id = "gen-incomplete" + incomplete_response._request_id = "req-incomplete" + incomplete_response.model = "upstream-model" + incomplete_response.provider = "upstream-provider" + complete_response = _FakeResponse( + [ + _FakeChoice( + "stop", + SimpleNamespace(content="done", tool_calls=[], annotations=[]), + ) + ] + ) + runtime, client, admin_report, request_count = _build_retry_runtime( + [incomplete_response, complete_response] + ) + + with patch("api.providers.runtime.time.sleep") as sleep: + result = runtime.complete( + {"role": "system", "content": "sys"}, + [{"role": "user", "content": "research this"}], + enable_web_search=True, + tool_context={"chat_id": "123"}, + ) + + assert result is not None + assert result.text == "done" + assert len(client.calls) == 2 + assert all( + call["max_tokens"] == chat_output_token_limit("deepseek/deepseek-v4-flash") + for call in client.calls + ) + assert request_count.call_count == 2 + sleep.assert_called_once_with(1) + admin_report.assert_not_called() + + +@pytest.mark.parametrize( + ("finish_reason", "error", "usage"), + [ + ( + "error", + {"code": 400, "metadata": {"error_type": "invalid_request"}}, + {}, + ), + (None, None, {"prompt_tokens": 10}), + ], +) +def test_provider_runtime_does_not_retry_permanent_or_billable_responses( + finish_reason, + error, + usage, +): + choice = _FakeChoice( + finish_reason, + SimpleNamespace(content="", tool_calls=[], annotations=[]), + ) + choice.error = error + response = _FakeResponse([choice]) + runtime, client, admin_report, request_count = _build_retry_runtime( + [response], + extract_usage=lambda _response: usage, + ) + + with patch("api.providers.runtime.time.sleep") as sleep: + result = runtime.complete( + {"role": "system", "content": "sys"}, + [{"role": "user", "content": "research this"}], + enable_web_search=True, + tool_context={"chat_id": "123"}, + ) + + assert result is None + assert len(client.calls) == 1 + assert request_count.call_count == 1 + sleep.assert_not_called() + admin_report.assert_called_once() + + +def test_provider_runtime_reports_null_finish_reason_after_retries_exhausted(): + responses = [] + for index in range(5): + choice = _FakeChoice( + None, + SimpleNamespace(content="", tool_calls=[], annotations=[]), + ) + choice.native_finish_reason = "upstream_null" + response = _FakeResponse([choice]) + response.id = f"gen-{index}" + response._request_id = f"req-{index}" + response.model = "upstream-model" + response.provider = "upstream-provider" + responses.append(response) + + runtime, client, admin_report, request_count = _build_retry_runtime(responses) + + with patch("api.providers.runtime.time.sleep") as sleep: + result = runtime.complete( + {"role": "system", "content": "sys"}, + [{"role": "user", "content": "research this"}], + enable_web_search=True, + tool_context={"chat_id": "123"}, + ) + + assert result is None + assert len(client.calls) == 5 + assert request_count.call_count == 5 + assert [call.args[0] for call in sleep.call_args_list] == [1, 2, 4, 8] + admin_report.assert_called_once() + assert admin_report.call_args.args[0] == "OpenRouter unexpected finish_reason=None" + report_context = admin_report.call_args.kwargs["extra_context"] + assert report_context == { + "model": "deepseek/deepseek-v4-flash", + "enable_web_search": True, + "tool_round": 1, + "response_id": "gen-4", + "request_id": "req-4", + "response_model": "upstream-model", + "provider": "upstream-provider", + "native_finish_reason": "upstream_null", + "has_content": False, + "tool_call_count": 0, + } + + def test_provider_runtime_retries_json_decode_errors_then_returns_result(): from api.ai.pricing import AIUsageResult from api.providers.runtime import ProviderRuntime, ProviderRuntimeDeps