diff --git a/gateway/run.py b/gateway/run.py index be4e2560b5..84604b303b 100644 --- a/gateway/run.py +++ b/gateway/run.py @@ -908,16 +908,27 @@ def _approval_send_outcome(future, timeout: float) -> str: and do NOT re-send or fall back — the boundary rule is that only a DEFINITIVE failure (error result / non-timeout exception / no future) re-asks. + + Definitive failures log their detail here (scheduling exception text or + the SendResult error) so callers sharing this classifier keep the + diagnostic breadcrumb the old inline code had. """ if future is None: + logger.warning("Prompt send failed: no scheduling future (loop unavailable)") return "failed" try: result = future.result(timeout=timeout) except concurrent.futures.TimeoutError: return "ambiguous" - except Exception: + except Exception as exc: + logger.warning("Prompt send failed: %s", exc) return "failed" - return "sent" if getattr(result, "success", False) else "failed" + if getattr(result, "success", False): + return "sent" + logger.warning( + "Prompt send failed: %s", getattr(result, "error", None) or "unknown error" + ) + return "failed" def _clarify_send_disposition(fut, *, session_key: str, clarify_mod) -> "str | None": @@ -950,6 +961,28 @@ def _clarify_send_disposition(fut, *, session_key: str, clarify_mod) -> "str | N return None +def _clarify_send_then_wait(fut, *, clarify_id: str, session_key: str, clarify_mod) -> str: + """Resolve a clarify prompt: send disposition, then the bounded wait. + + The full caller contract in one testable seam: a definitive send failure + returns the undeliverable sentinel (registration torn down); ``sent`` and + ``ambiguous`` both proceed to ``wait_for_response`` with the configured + timeout — for ambiguous, the registration stays armed so a late reply to + the (probably rendered) card still resolves. + """ + abort = _clarify_send_disposition( + fut, session_key=session_key, clarify_mod=clarify_mod + ) + if abort is not None: + return abort + timeout = clarify_mod.get_clarify_timeout() + response = clarify_mod.wait_for_response(clarify_id, timeout=float(timeout)) + if response is None or response == "": + # Timeout or session-boundary cancellation + return f"[user did not respond within {int(timeout / 60)}m]" + return response + + def _resolve_progress_thread_id( platform: Any, source_thread_id: Any, @@ -5983,20 +6016,12 @@ class TurnRunner: # AMBIGUOUS — the card may have posted with a late ack. Only a # definitive failure tears down the registration; ambiguous # falls through to the bounded wait so a late reply resolves. - _abort = _clarify_send_disposition( + return _clarify_send_then_wait( fut, + clarify_id=clarify_id, session_key=ctx.session_key or "", clarify_mod=_clarify_mod, ) - if _abort is not None: - return _abort - - timeout = _clarify_mod.get_clarify_timeout() - response = _clarify_mod.wait_for_response(clarify_id, timeout=float(timeout)) - if response is None or response == "": - # Timeout or session-boundary cancellation - return f"[user did not respond within {int(timeout / 60)}m]" - return response agent.clarify_callback = _clarify_callback_sync diff --git a/tests/gateway/test_clarify_send_timeout_ambiguity.py b/tests/gateway/test_clarify_send_timeout_ambiguity.py index 27b5ddc859..a226a89774 100644 --- a/tests/gateway/test_clarify_send_timeout_ambiguity.py +++ b/tests/gateway/test_clarify_send_timeout_ambiguity.py @@ -17,7 +17,7 @@ today's teardown + sentinel behavior. import concurrent.futures from unittest.mock import MagicMock -from gateway.run import _clarify_send_disposition +from gateway.run import _clarify_send_disposition, _clarify_send_then_wait SENTINEL = "[clarify prompt could not be delivered]" @@ -83,3 +83,93 @@ def test_missing_future_tears_down_and_aborts(): == SENTINEL ) clarify_mod.clear_session.assert_called_once_with("sk") + + +# --- Caller-path contract: the disposition feeds the bounded wait --------- + + +def test_ambiguous_send_reaches_wait_for_response(): + """The full caller contract, not just the classifier: on a send timeout + the flow must proceed to wait_for_response with the generated clarify_id + and the configured timeout — the late reply to the (probably rendered) + card resolves through that wait.""" + fut = MagicMock() + fut.result.side_effect = concurrent.futures.TimeoutError() + clarify_mod = MagicMock() + clarify_mod.get_clarify_timeout.return_value = 600 + clarify_mod.wait_for_response.return_value = "user picked B" + + out = _clarify_send_then_wait( + fut, clarify_id="cid123", session_key="sk", clarify_mod=clarify_mod + ) + + assert out == "user picked B" + clarify_mod.clear_session.assert_not_called() + clarify_mod.wait_for_response.assert_called_once_with("cid123", timeout=600.0) + + +def test_sent_reaches_wait_for_response(): + fut = MagicMock() + fut.result.return_value = _Result(True) + clarify_mod = MagicMock() + clarify_mod.get_clarify_timeout.return_value = 600 + clarify_mod.wait_for_response.return_value = "answer" + + assert ( + _clarify_send_then_wait( + fut, clarify_id="cid123", session_key="sk", clarify_mod=clarify_mod + ) + == "answer" + ) + clarify_mod.wait_for_response.assert_called_once_with("cid123", timeout=600.0) + + +def test_definitive_failure_never_waits(): + fut = MagicMock() + fut.result.return_value = _Result(False, "relay prompt op unavailable") + clarify_mod = MagicMock() + + assert ( + _clarify_send_then_wait( + fut, clarify_id="cid123", session_key="sk", clarify_mod=clarify_mod + ) + == SENTINEL + ) + clarify_mod.wait_for_response.assert_not_called() + clarify_mod.clear_session.assert_called_once_with("sk") + + +def test_no_response_returns_timeout_sentinel(): + fut = MagicMock() + fut.result.return_value = _Result(True) + clarify_mod = MagicMock() + clarify_mod.get_clarify_timeout.return_value = 600 + clarify_mod.wait_for_response.return_value = None + + assert ( + _clarify_send_then_wait( + fut, clarify_id="cid123", session_key="sk", clarify_mod=clarify_mod + ) + == "[user did not respond within 10m]" + ) + + +# --- Definitive failures keep their diagnostic detail in the log ---------- + + +def test_failed_send_exception_detail_is_logged(caplog): + fut = MagicMock() + fut.result.side_effect = RuntimeError("loop unavailable") + clarify_mod = MagicMock() + with caplog.at_level("WARNING", logger="gateway.run"): + _clarify_send_disposition(fut, session_key="sk", clarify_mod=clarify_mod) + assert "loop unavailable" in caplog.text + + +def test_failed_send_result_error_detail_is_logged(caplog): + fut = MagicMock() + fut.result.return_value = _Result(False, "relay prompt op unavailable") + clarify_mod = MagicMock() + with caplog.at_level("WARNING", logger="gateway.run"): + _clarify_send_disposition(fut, session_key="sk", clarify_mod=clarify_mod) + assert "relay prompt op unavailable" in caplog.text