From 7e19f4138b5c07db8d9db6ec0fa8564e8d45ed20 Mon Sep 17 00:00:00 2001 From: teknium1 <127238744+teknium1@users.noreply.github.com> Date: Sat, 3 Oct 2026 10:45:39 -0700 Subject: [PATCH] fix(telemetry): record auxiliary model calls with their real outcome Every failed auxiliary model_route row read error_class=unknown because the aux logical scope only carried outcome/model/provider and the projection hard-coded unknown for any non-success. Every exception escaping call_llm, including Hermes' own aborts (Ctrl+C / /stop mid-compression, interrupted aux streams, task cancellation), was recorded as failed. - classify the error that ended an aux call (and the last one a successful call recovered from) with agent.error_classifier; HTTP-200 bodies that carry a provider error object are classified from that object - Hermes aborts (non-Exception BaseExceptions, InterruptedError) close the call as cancelled/none, matching the contract - MoA aggregator streams report the same way - aux calls that finish under the turn's own live scopes (title generation runs beside the turn) were never counted: the scope could not be popped and the turn-close drain closed it as an orphan without a route. The drain now closes it with the stored real result. --- agent/auxiliary_call_outcome.py | 60 +++++++++ agent/auxiliary_client.py | 86 ++++++++---- agent/relay_llm.py | 40 ++++-- agent/relay_runtime.py | 23 +++- .../observability/shared_metrics_contract.py | 12 +- tests/agent/test_auxiliary_relay.py | 122 +++++++++++++++++- .../developer-guide/relay-shared-metrics.md | 11 +- 7 files changed, 305 insertions(+), 49 deletions(-) create mode 100644 agent/auxiliary_call_outcome.py diff --git a/agent/auxiliary_call_outcome.py b/agent/auxiliary_call_outcome.py new file mode 100644 index 0000000000..a36d547e5f --- /dev/null +++ b/agent/auxiliary_call_outcome.py @@ -0,0 +1,60 @@ +"""How one auxiliary logical call ended, for its Relay ``hermes.logical_llm_call`` scope. + +The scope's ``outcome`` + ``error_class`` become the shared-metrics ``model_route`` row of an +auxiliary call, under the same contract as a primary call: a failure carries the classifier's +``FailoverReason`` for the error that ended it, a Hermes-side abort (``/stop``, Ctrl+C, an +interrupt, shutdown) is ``cancelled`` rather than ``failed``, and a success keeps the last +attempt error it recovered from (a retried timeout, a fallback past a 429). +""" + +from __future__ import annotations + +import logging +from typing import Any + +logger = logging.getLogger(__name__) + +# Attribute an aux "invalid response" error carries when the HTTP-200 body held a provider +# ``error`` object instead of choices (aggregators relay upstream failures this way). +PROVIDER_ERROR_ATTR = "provider_error" + + +class _EmbeddedProviderError(Exception): + """An HTTP-200 ``error`` object reshaped so ``classify_api_error`` reads it as an SDK body.""" + + def __init__(self, error: dict[str, Any]) -> None: + super().__init__(str(error.get("message") or "")) + self.body = {"error": error} + + +def embedded_provider_error(response: Any) -> dict[str, Any] | None: + """The ``error`` object of an HTTP-200 body that carried no choices, else None.""" + error = response.get("error") if isinstance(response, dict) else getattr(response, "error", None) + if isinstance(error, dict): + return error or None + if error is None or not (hasattr(error, "message") or hasattr(error, "code")): + return None + fields = {"message": getattr(error, "message", None), "code": getattr(error, "code", None)} + return {k: v for k, v in fields.items() if v is not None} or None + + +def is_cancellation(error: BaseException) -> bool: + """Hermes aborted the call (explicit cancel, interrupt, Ctrl+C, task cancel, shutdown): + everything that is not an ``Exception``, plus the ``InterruptedError`` aux streams raise.""" + return not isinstance(error, Exception) or isinstance(error, InterruptedError) + + +def error_class(error: BaseException, *, provider: str = "", model: str = "") -> str: + """The classifier's reason for one aux attempt error; ``unknown`` when it cannot say. + Never raises: telemetry must not replace the caller's exception.""" + if not isinstance(error, Exception): + return "unknown" + try: + from agent.error_classifier import classify_api_error + + embedded = getattr(error, PROVIDER_ERROR_ATTR, None) + target = _EmbeddedProviderError(embedded) if isinstance(embedded, dict) else error + return classify_api_error(target, provider=provider, model=model).reason.value + except Exception: + logger.debug("Auxiliary error classification failed", exc_info=True) + return "unknown" diff --git a/agent/auxiliary_client.py b/agent/auxiliary_client.py index b6f7bf1b9a..75bff11af1 100644 --- a/agent/auxiliary_client.py +++ b/agent/auxiliary_client.py @@ -2584,8 +2584,8 @@ def _relay_aux_call_scope(args: tuple, kwargs: dict): }) try: yield - except BaseException: - _fail_relay_auxiliary_call() + except BaseException as exc: + _fail_relay_auxiliary_call(exc) raise finally: _RELAY_AUX_CALL_CONTEXT.reset(token) @@ -2666,15 +2666,19 @@ def _relay_sync_completion( from agent import relay_llm from agent.auxiliary_hooks import run_with_aux_hooks model_name = str(kwargs.get("model") or fallback_model) - return run_with_aux_hooks( - lambda: relay_llm.execute_current( - kwargs, lambda request: _run_protected_sync_provider_call(callback, request), - name=provider_name, model_name=model_name, metadata=metadata, - defer_logical_completion=True, - ), - aux_task=str(metadata.get("auxiliary_task") or ""), metadata=metadata, client=client, kwargs=kwargs, - provider=provider_name, model=model_name, api_mode=str(metadata.get("api_mode") or ""), - ) + try: + return run_with_aux_hooks( + lambda: relay_llm.execute_current( + kwargs, lambda request: _run_protected_sync_provider_call(callback, request), + name=provider_name, model_name=model_name, metadata=metadata, + defer_logical_completion=True, + ), + aux_task=str(metadata.get("auxiliary_task") or ""), metadata=metadata, client=client, kwargs=kwargs, + provider=provider_name, model=model_name, api_mode=str(metadata.get("api_mode") or ""), + ) + except Exception as exc: + _note_relay_auxiliary_error(exc) + raise async def _relay_async_completion( @@ -2693,14 +2697,18 @@ async def _relay_async_completion( from agent import relay_llm from agent.auxiliary_hooks import arun_with_aux_hooks model_name = str(kwargs.get("model") or fallback_model) - return await arun_with_aux_hooks( - lambda: relay_llm.execute_current_async( - kwargs, callback, name=provider_name, model_name=model_name, - metadata=metadata, defer_logical_completion=True, - ), - aux_task=str(metadata.get("auxiliary_task") or ""), metadata=metadata, client=client, kwargs=kwargs, - provider=provider_name, model=model_name, api_mode=str(metadata.get("api_mode") or ""), - ) + try: + return await arun_with_aux_hooks( + lambda: relay_llm.execute_current_async( + kwargs, callback, name=provider_name, model_name=model_name, + metadata=metadata, defer_logical_completion=True, + ), + aux_task=str(metadata.get("auxiliary_task") or ""), metadata=metadata, client=client, kwargs=kwargs, + provider=provider_name, model=model_name, api_mode=str(metadata.get("api_mode") or ""), + ) + except Exception as exc: + _note_relay_auxiliary_error(exc) + raise def _relay_sync_stream( @@ -6877,17 +6885,26 @@ def _validate_llm_response( except (AttributeError, TypeError, IndexError) as exc: recovered = _recover_aux_response_message(response) if recovered is None: - raise RuntimeError( + invalid = RuntimeError( f"Auxiliary {task or 'call'}: LLM returned invalid response (type={type(response).__name__}): " f"{str(response)[:120]!r}. Expected object with .choices[0].message — check provider " f"adapter or custom endpoint compatibility." - ) from exc + ) + # An HTTP-200 body carrying a provider ``error`` (aggregators relay upstream failures + # this way): keep it for the classifier without changing how the ladder routes this. + from agent import auxiliary_call_outcome + setattr(invalid, auxiliary_call_outcome.PROVIDER_ERROR_ATTR, + auxiliary_call_outcome.embedded_provider_error(response)) + _note_relay_auxiliary_error(invalid) + raise invalid from exc response = recovered from agent.transports.chat_completions import is_router_timeout_shim if is_router_timeout_shim(response): # HTTP-200 router failure shim (#68396): invalid like a malformed shape so the # auxiliary fallback chain moves to the next candidate instead of titling with it. - raise RuntimeError(f"Auxiliary {task or 'call'}: provider returned a timeout shim instead of a completion") + shim = RuntimeError(f"Auxiliary {task or 'call'}: provider returned a timeout shim instead of a completion") + _note_relay_auxiliary_error(shim) + raise shim # Retain the provider-reported model for terminal relay route attribution. context = _RELAY_AUX_CALL_CONTEXT.get() if context is not None: @@ -6898,8 +6915,9 @@ def _validate_llm_response( return response -def _complete_relay_auxiliary_call(*, outcome: str = "success") -> None: - """Close one auxiliary logical call after acceptance or terminal failure.""" +def _complete_relay_auxiliary_call(*, outcome: str = "success", error_class: Optional[str] = None) -> None: + """Close one auxiliary logical call after acceptance or terminal failure. A success + reports the last attempt error it recovered from (``none`` when the first attempt held).""" context = _RELAY_AUX_CALL_CONTEXT.get() if context is None: return @@ -6909,12 +6927,28 @@ def _complete_relay_auxiliary_call(*, outcome: str = "success") -> None: model_name=str(context.get("model") or "unknown"), provider_name=str(context.get("provider") or "auxiliary"), response_model_name=context.get("response_model"), + error_class=error_class or context.get("error_class") or "none", ) -def _fail_relay_auxiliary_call() -> None: - """Close a terminally failed call without replacing its original error.""" +def _note_relay_auxiliary_error(exc: BaseException) -> None: + """Remember one failed attempt's classified reason on the logical call.""" + context = _RELAY_AUX_CALL_CONTEXT.get() + if context is not None and isinstance(exc, Exception): + from agent import auxiliary_call_outcome + context["error_class"] = auxiliary_call_outcome.error_class( + exc, provider=str(context.get("provider") or ""), model=str(context.get("model") or "")) + + +def _fail_relay_auxiliary_call(exc: BaseException) -> None: + """Close a call that ended in ``exc`` without replacing it: a Hermes abort is ``cancelled``, + anything else ``failed`` with the classifier's reason for the error that ended it.""" try: + from agent import auxiliary_call_outcome + if auxiliary_call_outcome.is_cancellation(exc): + _complete_relay_auxiliary_call(outcome="cancelled", error_class="none") + return + _note_relay_auxiliary_error(exc) _complete_relay_auxiliary_call(outcome="failed") except Exception: logger.warning("Relay auxiliary failure finalization failed", exc_info=True) diff --git a/agent/relay_llm.py b/agent/relay_llm.py index 526829194a..85f52be258 100644 --- a/agent/relay_llm.py +++ b/agent/relay_llm.py @@ -422,7 +422,7 @@ class ManagedLlmStream(Iterator[Any]): return try: if self._loop is not None: - self._finish_logical("cancelled" if _is_cancellation(exc) else "failed") + self._finish_logical("cancelled" if _is_cancellation(exc) else "failed", error=exc) self._loop.close() finally: self._loop = None @@ -460,14 +460,23 @@ class ManagedLlmStream(Iterator[Any]): ) return recoverable - def _finish_logical(self, outcome: str) -> None: - """Complete the logical LLM scope unless the caller deferred it.""" + def _finish_logical(self, outcome: str, error: BaseException | None = None) -> None: + """Complete the logical LLM scope unless the caller deferred it. An auxiliary stream + that ended in ``error`` reports it like a deferred auxiliary call does.""" if self._defer_logical_completion: return + error_class = None + if error is not None and self._logical_model_name is not None: + from agent import auxiliary_call_outcome + if auxiliary_call_outcome.is_cancellation(error): + outcome = "cancelled" + else: + error_class = auxiliary_call_outcome.error_class( + error, provider=self._logical_provider_name or "", model=self._logical_model_name) _complete_logical( self._logical, outcome=outcome, model_name=self._logical_model_name, provider_name=self._logical_provider_name, response_model_name=self._logical_response_model_name, - operation_lease=self._runtime_lease, + operation_lease=self._runtime_lease, error_class=error_class, ) self._logical = None @@ -497,12 +506,12 @@ class ManagedLlmStream(Iterator[Any]): except BaseException as exc: callback_error = self._callback_error if callback_error is not None and relay_runtime._is_relay_wrapped_callback_error(exc, callback_error): - self._close(logical_outcome="failed") + self._close(logical_outcome="failed", error=callback_error) raise callback_error if self._recoverable_relay_failure(exc): self._preserve_pending_provider_chunks() return next(self) - self._close(logical_outcome="cancelled" if _is_cancellation(exc) else "failed") + self._close(logical_outcome="cancelled" if _is_cancellation(exc) else "failed", error=exc) raise for index, (encoded, raw) in enumerate(self._raw_chunks): if _json_equal(chunk, encoded): @@ -558,7 +567,7 @@ class ManagedLlmStream(Iterator[Any]): self._keep_first_close_error(exc) logger.debug("Provider stream cleanup failed", exc_info=True) - def _close(self, *, logical_outcome: str) -> None: + def _close(self, *, logical_outcome: str, error: BaseException | None = None) -> None: if self._closed: return self._closed = True @@ -573,7 +582,7 @@ class ManagedLlmStream(Iterator[Any]): close_loop = _aclose_on_loop(loop, self._stream) except Exception as exc: self._keep_first_close_error(exc) - self._finish_logical(logical_outcome) + self._finish_logical(logical_outcome, error) if close_loop: loop.close() finally: @@ -693,6 +702,7 @@ def _logical_parent( def _complete_logical( logical: _LogicalCall | None, *, outcome: str, model_name: str | None = None, provider_name: str | None = None, response_model_name: str | None = None, operation_lease: relay_runtime.RelayOperationLease | None = None, + error_class: str | None = None, ) -> None: if logical is None: return @@ -705,6 +715,8 @@ def _complete_logical( output.update({"model": model_name, "provider": provider_name}) if response_model_name is not None: output["response_model"] = response_model_name + if error_class is not None: + output["error_class"] = error_class with turn.finalize_lock: with turn.logical_llm_lock: if turn.logical_llm_calls.get(request_id) is not handle: @@ -726,8 +738,11 @@ def _complete_logical( logger.warning("Hermes Relay logical LLM finalization failed", exc_info=True) return if popped is False: + # A call running beside the turn (title generation) finishes under the turn's own + # live scopes; keep its result so the drain reports it instead of an orphan. + lease.host.defer_scope_output(handle, output) logger.debug( - "Left logical LLM scope %s under a concurrent turn's scope; session close drains it", + "Left logical LLM scope %s under a concurrent scope; the drain closes it with its result", request_id, ) with turn.logical_llm_lock: @@ -742,8 +757,11 @@ def _is_cancellation(error: BaseException) -> bool: def complete_logical_call( api_request_id: str, *, outcome: str, model_name: str | None = None, provider_name: str | None = None, response_model_name: str | None = None, + error_class: str | None = None, ) -> None: - """Complete the active turn's logical LLM call after caller validation.""" + """Complete the active turn's logical LLM call after caller validation. ``error_class`` + (a classifier reason) rides on a call that reports its route: the error that ended a + failed call, or the last one a successful call recovered from.""" turn = relay_runtime.active_turn() if turn is None or not api_request_id: return @@ -752,7 +770,7 @@ def complete_logical_call( if handle is not None: _complete_logical( (turn, handle, api_request_id), outcome=outcome, model_name=model_name, - provider_name=provider_name, response_model_name=response_model_name, + provider_name=provider_name, response_model_name=response_model_name, error_class=error_class, ) diff --git a/agent/relay_runtime.py b/agent/relay_runtime.py index c2bc16df23..4c8871b986 100644 --- a/agent/relay_runtime.py +++ b/agent/relay_runtime.py @@ -408,6 +408,10 @@ class RelayRuntime: self._subagent_parents: dict[str, str] = {} self._subagent_parent_handles: dict[str, Any] = {} self._execution_consumers: set[str] = set() + # Outputs of scopes that finished under a concurrent scope (pop_relay_scope_if_top said no), + # keyed by handle uuid: the drain that later reclaims the scope closes it with this output. + self._deferred_scope_outputs: dict[str, dict[str, Any]] = {} + self._deferred_scope_outputs_lock = threading.Lock() self._closing = self._shutdown_started = False self._shutdown_complete, self._operations_idle = threading.Event(), threading.Event() self._operations_idle.set() @@ -422,6 +426,21 @@ class RelayRuntime: def _plugins_active(self) -> bool: return self._plugin_configuration_state is _RelayPluginConfigurationState.ACTIVE + def defer_scope_output(self, handle: Any, output: dict[str, Any]) -> None: + """Keep the real output of a finished scope that could not be popped yet because a + concurrent scope sits above it; the orphan drain closes it with this instead.""" + key = getattr(handle, "uuid", None) + if key is not None: + with self._deferred_scope_outputs_lock: + self._deferred_scope_outputs[str(key)] = output + + def _take_deferred_scope_output(self, handle: Any) -> dict[str, Any] | None: + key = getattr(handle, "uuid", None) + if key is None: + return None + with self._deferred_scope_outputs_lock: + return self._deferred_scope_outputs.pop(str(key), None) + def retain_managed_execution(self, consumer: str) -> None: """Keep managed LLM and tool execution active for one consumer.""" if not consumer: @@ -709,7 +728,9 @@ class RelayRuntime: if session_root is not None and _same_handle(top, session_root) and handle is not session_root: break try: - orphan_output = {"outcome": "cancelled", "hermes.orphan_drain": True} + orphan_output = self._take_deferred_scope_output(top) or { + "outcome": "cancelled", "hermes.orphan_drain": True, + } pop_relay_scope(self.relay, top, output=orphan_output, metadata=metadata) drained += 1 except Exception: diff --git a/hermes_cli/observability/shared_metrics_contract.py b/hermes_cli/observability/shared_metrics_contract.py index 08d739e4a0..ec897bfd78 100644 --- a/hermes_cli/observability/shared_metrics_contract.py +++ b/hermes_cli/observability/shared_metrics_contract.py @@ -1129,15 +1129,17 @@ def _auxiliary_model_call_dimensions(event: Any) -> dict[str, str] | None: scope_category="end", category_profile=None, ) or not isinstance(data, dict) - or set(data) - {"response_model"} != {"model", "outcome", "provider"} + or set(data) - {"response_model", "error_class"} != {"model", "outcome", "provider"} or data.get("outcome") not in _LEGACY_MODEL_OUTCOMES ): return None outcome = data["outcome"] - dimensions = model_route_fields( - data, call_role="auxiliary", outcome=outcome, - error_class="none" if outcome == "success" else "unknown", - ) + # Same reading as a primary call: a cancelled call reports ``none``, a failure without a + # classified reason ``unknown``, a success the last error it recovered from. + error_class = "none" if outcome == "cancelled" else data.get("error_class") or "none" + if outcome == "failed" and error_class == "none": + error_class = "unknown" + dimensions = model_route_fields(data, call_role="auxiliary", outcome=outcome, error_class=error_class) return dimensions if counter_dimensions_are_valid(MODEL_ROUTE_METRIC, dimensions) else None diff --git a/tests/agent/test_auxiliary_relay.py b/tests/agent/test_auxiliary_relay.py index 65b5b68c5e..3701fbc61b 100644 --- a/tests/agent/test_auxiliary_relay.py +++ b/tests/agent/test_auxiliary_relay.py @@ -57,8 +57,10 @@ def test_auxiliary_retries_share_logical_relay_identity(monkeypatch): monkeypatch.setattr( relay_llm, "complete_logical_call", - lambda request_id, *, outcome, model_name, provider_name, response_model_name: logical_completions.append( - (request_id, outcome, model_name, provider_name, response_model_name) + lambda request_id, *, outcome, model_name, provider_name, response_model_name, error_class: ( + logical_completions.append( + (request_id, outcome, model_name, provider_name, response_model_name, error_class) + ) ), ) @@ -101,6 +103,7 @@ def test_auxiliary_retries_share_logical_relay_identity(monkeypatch): "test-model", "openrouter", None, + "unknown", # recovered from the unclassifiable invalid first response ) ] @@ -173,6 +176,7 @@ def test_auxiliary_provider_fallback_closes_one_real_logical_call( assert turn.logical_llm_calls == {} assert logical_outputs == [ { + "error_class": "unknown", "model": "openrouter/test-model", "outcome": "success", "provider": "openrouter", @@ -254,7 +258,8 @@ def test_auxiliary_provider_fallback_records_one_terminal_model_route( assert snapshot[0]["resource"]["hermes_version"] == "test-version" assert snapshot[0]["dimensions"] == { "call_role": "auxiliary", - "error_class": "none", + # The success keeps the error it recovered from; an invalid shape classifies as unknown. + "error_class": "unknown", "model": "accepted/model", "outcome": "success", "provider": "openrouter", @@ -264,6 +269,107 @@ def test_auxiliary_provider_fallback_records_one_terminal_model_route( assert snapshot[0]["packaged_value"] == 0 +class _ProviderStatusError(Exception): + def __init__(self, status_code, message): + super().__init__(message) + self.status_code = status_code + + +def _aux_route_rows(relay_turn, tmp_path, run): + """Run ``run`` inside the turn with a real shared-metrics subscriber; the stored route rows.""" + relay, turn = relay_turn + store = SharedMetricsStore(tmp_path / "metrics.sqlite3", tmp_path / "outbox") + subscriber = SharedMetricsSubscriber(store, "test-version", runtime_id=turn.lease.host.runtime_id) + relay.subscribers.register("test.auxiliary-route-rows", subscriber) + turn.lease.host.retain_managed_execution("test.auxiliary-route-rows") + try: + run() + relay.subscribers.flush() + finally: + turn.lease.host.release_managed_execution("test.auxiliary-route-rows") + relay.subscribers.deregister("test.auxiliary-route-rows") + return sorted( + (row["dimensions"]["outcome"], row["dimensions"]["error_class"], row["value"]) + for row in store.counter_snapshot() if row["metric_name"] == MODEL_ROUTE_METRIC + ) + + +def _aux_attempts(*outcomes): + """A client whose successive attempts raise or answer, in order.""" + pending = iter(outcomes) + + def create(**_kwargs): + outcome = next(pending) + if isinstance(outcome, BaseException): + raise outcome + return SimpleNamespace(model="m", choices=[SimpleNamespace(message=SimpleNamespace(content=outcome))]) + + return SimpleNamespace(chat=SimpleNamespace(completions=SimpleNamespace(create=create))) + + +@auxiliary_client._relay_auxiliary_call +def _aux_call(task, client, attempts): + auxiliary_client._set_relay_auxiliary_route("openrouter", "m", "chat_completions") + for _ in range(attempts - 1): + try: + return auxiliary_client._validate_llm_response( + auxiliary_client._relay_sync_completion(client, {"model": "m", "messages": []}), task) + except Exception: + continue + return auxiliary_client._validate_llm_response( + auxiliary_client._relay_sync_completion(client, {"model": "m", "messages": []}), task) + + +def test_auxiliary_model_routes_carry_classified_error_class(relay_turn, tmp_path): + """A failed aux call reports the classifier's reason for the error that ended it, and a + recovered one the error it recovered from, never a blanket ``unknown``/``none``.""" + def run(): + _aux_call("title_generation", _aux_attempts(_ProviderStatusError(429, "Rate limit exceeded"), "ok"), 2) + with pytest.raises(_ProviderStatusError): + _aux_call("title_generation", _aux_attempts( + _ProviderStatusError(404, "The model `m` does not exist")), 1) + + assert _aux_route_rows(relay_turn, tmp_path, run) == [ + ("failed", "model_not_found", 1), + ("success", "rate_limit", 1), + ] + + +@pytest.mark.parametrize("abort", [ + auxiliary_client.AuxiliaryExplicitCancellation(), InterruptedError("aux stream interrupted"), KeyboardInterrupt(), +]) +def test_aborted_auxiliary_call_is_cancelled_not_failed(relay_turn, tmp_path, abort): + """A Hermes abort (/stop, interrupt, Ctrl+C) mid aux call is not a provider failure.""" + def run(): + with pytest.raises(type(abort)): + _aux_call("compression", _aux_attempts(abort), 1) + + assert _aux_route_rows(relay_turn, tmp_path, run) == [("cancelled", "none", 1)] + + +def test_auxiliary_call_finishing_under_the_turns_live_scope_is_counted(relay_turn, tmp_path): + """Title generation runs beside the turn, so the turn's own work is usually on top of its + logical scope when it finishes. Its result must still become the route row.""" + relay, turn = relay_turn + host, session = turn.lease.host, turn.lease.session + turn_work = [] + + @auxiliary_client._relay_auxiliary_call + def title(task): + auxiliary_client._set_relay_auxiliary_route("openrouter", "m", "chat_completions") + response = auxiliary_client._relay_sync_completion(_aux_attempts("A title"), {"model": "m", "messages": []}) + turn_work.append(host.run_in_session( + session, relay.scope.push, "test.turn_work", relay.ScopeType.Function, handle=turn.handle, input={})) + return auxiliary_client._validate_llm_response(response, task) + + def run(): + title("title_generation") + host.run_in_session(session, relay_runtime.pop_relay_scope, relay, turn_work[0], output={}) + relay_runtime.SESSION_COORDINATOR.end_turn(turn, outcome="success") + + assert _aux_route_rows(relay_turn, tmp_path, run) == [("success", "none", 1)] + + @pytest.mark.asyncio async def test_async_auxiliary_attempt_uses_inherited_relay_adapter(monkeypatch): captured = {} @@ -291,8 +397,10 @@ async def test_async_auxiliary_attempt_uses_inherited_relay_adapter(monkeypatch) monkeypatch.setattr( relay_llm, "complete_logical_call", - lambda request_id, *, outcome, model_name, provider_name, response_model_name: logical_completions.append( - (request_id, outcome, model_name, provider_name, response_model_name) + lambda request_id, *, outcome, model_name, provider_name, response_model_name, error_class: ( + logical_completions.append( + (request_id, outcome, model_name, provider_name, response_model_name, error_class) + ) ), ) @@ -324,6 +432,7 @@ async def test_async_auxiliary_attempt_uses_inherited_relay_adapter(monkeypatch) "claude-test", "anthropic", None, + "none", ) ] @@ -424,6 +533,7 @@ def test_partial_auxiliary_stream_failure_closes_before_recovery( assert caught.value is provider_error assert logical_outputs == [ { + "error_class": "unknown", "model": "test-model", "outcome": "failed", "provider": "openrouter", @@ -436,11 +546,13 @@ def test_partial_auxiliary_stream_failure_closes_before_recovery( assert result.choices[0].message.content == "recovered" assert logical_outputs == [ { + "error_class": "unknown", "model": "test-model", "outcome": "failed", "provider": "openrouter", }, { + "error_class": "none", "model": "test-model", "outcome": "success", "provider": "openrouter", diff --git a/website/docs/developer-guide/relay-shared-metrics.md b/website/docs/developer-guide/relay-shared-metrics.md index 5a711ef820..fb9be1d292 100644 --- a/website/docs/developer-guide/relay-shared-metrics.md +++ b/website/docs/developer-guide/relay-shared-metrics.md @@ -181,7 +181,16 @@ also carries `call_role` (`primary` or `auxiliary`), `outcome` (`success`, `failed`, `cancelled`) and `error_class`: the error classifier's own `FailoverReason` value (`rate_limit`, `auth`, `context_overflow`, ...) for the last failed attempt of that logical call, or `none`. A `success` row with a -non-`none` class is a call that recovered after that error. The previous +non-`none` class is a call that recovered after that error. Auxiliary calls +(titles, compression, vision, ...) follow the same rules: one row per logical +call however many fallback attempts it took, classified by the same classifier +(an HTTP-200 body carrying a provider `error` object is classified from that +object), `cancelled` with `none` when Hermes aborted it (`/stop`, Ctrl+C, an +interrupt, shutdown), and `unknown` only when the classifier cannot name the +failure. An auxiliary call that runs beside the turn (title generation) and +finishes under the turn's own live scopes is still counted: its result closes +the scope when the turn drains it. Auxiliary rows report `ttft_bucket` +`unknown`: most auxiliary calls are not streamed. The previous `hermes.model_call.count` contract remains readable only so pending local counters created by older builds can be exported without losing data.