From 348f65752e155e25540ce1bc3c86f951cebdfd62 Mon Sep 17 00:00:00 2001 From: Leul Negash Date: Tue, 15 Sep 2026 11:43:16 +0300 Subject: [PATCH 01/11] Stop the proxy cutting off slow LLM responses (#321) Every LLM request in the Docker image goes through the nginx proxy, and the LLM routes used the global 120s proxy_read_timeout and proxy_send_timeout. When a response takes longer, nginx returns 504, the OpenAI client retries twice with the same result, and AIProvider.chat ends up returning "", so the agent never answers. The OpenAI client waits up to 600s, so set 600s on the anthropic, asicloud, openai, asione, openaiapi and openrouter routes, the same override the OpenClaw route already has. The channel routes keep the 120s default. Add a unit test that reads the template and fails when an LLM route waits less than 600s, and register it in run_mandatory. --- Autotests/run_mandatory | 1 + Autotests/unit/test_nginx_llm_timeouts.py | 62 +++++++++++++++++++++++ proxy/nginx.conf.template | 12 +++++ 3 files changed, 75 insertions(+) create mode 100644 Autotests/unit/test_nginx_llm_timeouts.py diff --git a/Autotests/run_mandatory b/Autotests/run_mandatory index 8c76355af..1bc9fb2d7 100644 --- a/Autotests/run_mandatory +++ b/Autotests/run_mandatory @@ -41,3 +41,4 @@ unit/test_fileio_verified_writes.py unit/test_fileio_verified_deletes.py unit/test_helper_parsing.py unit/test_openclaw_unit.py +unit/test_nginx_llm_timeouts.py diff --git a/Autotests/unit/test_nginx_llm_timeouts.py b/Autotests/unit/test_nginx_llm_timeouts.py new file mode 100644 index 000000000..3425f2236 --- /dev/null +++ b/Autotests/unit/test_nginx_llm_timeouts.py @@ -0,0 +1,62 @@ +"""Unit tests for the LLM provider routes in proxy/nginx.conf.template. + +In the Docker image every LLM request goes through this proxy. When a route +gives up before the provider answers, nginx returns 504, the provider call +fails and the agent sends nothing back to the user (#321). The OpenAI client +used by the providers waits up to 600 seconds, so each LLM route has to wait +at least as long. + +No container, no network: the template is read as text. +""" +import os +import re + +import pytest + +_REPO_ROOT = os.path.normpath(os.path.join(os.path.dirname(__file__), "..", "..")) +_TEMPLATE = os.path.join(_REPO_ROOT, "proxy", "nginx.conf.template") + +LLM_ROUTES = ["anthropic", "asicloud", "openai", "asione", "openaiapi", "openrouter"] +CLIENT_TIMEOUT_SECONDS = 600 + +_UNITS = {"s": 1, "m": 60, "h": 3600} + + +def _seconds(value): + match = re.fullmatch(r"(\d+)([smh]?)", value) + assert match, f"unsupported nginx time value: {value}" + return int(match.group(1)) * _UNITS.get(match.group(2) or "s") + + +def _directive(text, name): + match = re.search(rf"^\s*{name}\s+(\S+);", text, re.MULTILINE) + return match.group(1) if match else None + + +@pytest.fixture(scope="module") +def template(): + with open(_TEMPLATE, encoding="utf-8") as f: + return f.read() + + +def _route_block(template, route): + match = re.search(rf"location /{route}/ \{{\n(.*?)\n\s*\}}\n", template, re.DOTALL) + assert match, f"no location block for /{route}/" + return match.group(1) + + +def _effective(template, route, name): + http_defaults = template.split("server {", 1)[0] + value = _directive(_route_block(template, route), name) or _directive(http_defaults, name) + assert value, f"{name} is not set for /{route}/" + return _seconds(value) + + +@pytest.mark.parametrize("route", LLM_ROUTES) +def test_llm_route_waits_as_long_as_the_client_for_a_response(template, route): + assert _effective(template, route, "proxy_read_timeout") >= CLIENT_TIMEOUT_SECONDS + + +@pytest.mark.parametrize("route", LLM_ROUTES) +def test_llm_route_waits_as_long_as_the_client_to_send_the_request(template, route): + assert _effective(template, route, "proxy_send_timeout") >= CLIENT_TIMEOUT_SECONDS diff --git a/proxy/nginx.conf.template b/proxy/nginx.conf.template index f569ea97b..88dfcb7ef 100644 --- a/proxy/nginx.conf.template +++ b/proxy/nginx.conf.template @@ -35,6 +35,8 @@ http { proxy_ssl_server_name on; proxy_ssl_protocols TLSv1.2 TLSv1.3; proxy_http_version 1.1; + proxy_read_timeout 600s; + proxy_send_timeout 600s; } location /asicloud/ { @@ -45,6 +47,8 @@ http { proxy_ssl_server_name on; proxy_ssl_protocols TLSv1.2 TLSv1.3; proxy_http_version 1.1; + proxy_read_timeout 600s; + proxy_send_timeout 600s; } location /openai/ { @@ -55,6 +59,8 @@ http { proxy_ssl_server_name on; proxy_ssl_protocols TLSv1.2 TLSv1.3; proxy_http_version 1.1; + proxy_read_timeout 600s; + proxy_send_timeout 600s; } location /asione/ { @@ -65,6 +71,8 @@ http { proxy_ssl_server_name on; proxy_ssl_protocols TLSv1.2 TLSv1.3; proxy_http_version 1.1; + proxy_read_timeout 600s; + proxy_send_timeout 600s; } location /openaiapi/ { @@ -74,6 +82,8 @@ http { proxy_ssl_server_name on; proxy_ssl_protocols TLSv1.2 TLSv1.3; proxy_http_version 1.1; + proxy_read_timeout 600s; + proxy_send_timeout 600s; } # OpenClaw Gateway: inject Bearer token, upstream is set at container @@ -97,6 +107,8 @@ http { proxy_ssl_server_name on; proxy_ssl_protocols TLSv1.2 TLSv1.3; proxy_http_version 1.1; + proxy_read_timeout 600s; + proxy_send_timeout 600s; } # Telegram: rewrite URL to inject bot token in path. From 4f9f90e7bbe67507adede322fb334cdf8388f28a Mon Sep 17 00:00:00 2001 From: Leul Negash Date: Wed, 23 Sep 2026 20:00:23 +0300 Subject: [PATCH 02/11] Tell the user when the LLM request times out (#321) After a provider request runs out of time and the client's retries are gone, chat() returned an empty string. The loop then had no command to run, so the turn ended without a word and the task looked abandoned, which is the symptom reported in #321. A timeout now comes back as a (send ...) command carrying a short status message, the same shape the token-limit case already uses, so the loop delivers it on the channel the user is on. It covers the client's own timeout and the 408/504/524 statuses a gateway returns when the upstream did not answer in time; every other failure still returns an empty string, as before. Add unit tests for which failures count as a timeout, what chat() returns in each case, and that the message parses into a single send command. --- Autotests/run_mandatory | 1 + Autotests/unit/test_llm_timeout_message.py | 112 +++++++++++++++++++++ providers/asione.py | 2 + providers/lib_llm_ext.py | 29 ++++++ providers/openai.py | 2 + 5 files changed, 146 insertions(+) create mode 100644 Autotests/unit/test_llm_timeout_message.py diff --git a/Autotests/run_mandatory b/Autotests/run_mandatory index dee4dbe77..2a00de98f 100644 --- a/Autotests/run_mandatory +++ b/Autotests/run_mandatory @@ -42,4 +42,5 @@ unit/test_fileio_verified_deletes.py unit/test_helper_parsing.py unit/test_openclaw_unit.py unit/test_nginx_llm_timeouts.py +unit/test_llm_timeout_message.py import_knowledge/test_import_knowledge.py diff --git a/Autotests/unit/test_llm_timeout_message.py b/Autotests/unit/test_llm_timeout_message.py new file mode 100644 index 000000000..370dbb4b2 --- /dev/null +++ b/Autotests/unit/test_llm_timeout_message.py @@ -0,0 +1,112 @@ +"""Unit tests for the provider timeout status message. + +When a provider request runs out of time and the client's retries are gone, the +provider used to return an empty string. The loop then had nothing to run, so +the turn ended without a word to the user and the task looked abandoned (#321). +The timeout now comes back as a `send` command carrying a status message, the +same way a reply cut off by the token limit already does. + +No container, no network, no API key: the client is replaced by a stub that +raises the error under test. +""" +import importlib.util +import os +import sys + +import httpx +import openai +import pytest + +_REPO_ROOT = os.path.normpath(os.path.join(os.path.dirname(__file__), "..", "..")) +for path in (_REPO_ROOT, os.path.join(_REPO_ROOT, "src")): + if path not in sys.path: + sys.path.insert(0, path) + + +def _load(name, relative_path): + spec = importlib.util.spec_from_file_location(name, os.path.join(_REPO_ROOT, relative_path)) + module = importlib.util.module_from_spec(spec) + spec.loader.exec_module(module) + return module + + +@pytest.fixture(scope="module") +def llm(): + return _load("lib_llm_ext_under_test", os.path.join("providers", "lib_llm_ext.py")) + + +@pytest.fixture(scope="module") +def helper(): + return _load("helper_under_test", os.path.join("src", "helper.py")) + + +class _RaisingClient: + """Minimal stand-in for openai.OpenAI whose chat call always fails.""" + + def __init__(self, error): + completions = type("_Completions", (), {"create": lambda _self, **kwargs: (_ for _ in ()).throw(error)})() + self.chat = type("_Chat", (), {"completions": completions})() + + +def _provider(llm, error): + provider = llm.AIProvider("OpenAIAPI", "OPENAIAPI_API_KEY", "test-model", "http://localhost/v1/") + provider._client = _RaisingClient(error) + return provider + + +def _timeout_error(): + return openai.APITimeoutError(request=httpx.Request("POST", "http://gateway/openaiapi/chat/completions")) + + +# --- which failures count as a timeout --------------------------------------- + +def test_client_timeout_is_a_timeout(llm): + assert llm._is_timeout_error(_timeout_error()) + + +@pytest.mark.parametrize("status", [408, 504, 524]) +def test_gateway_timeout_statuses_are_a_timeout(llm, status): + error = Exception("gateway timeout") + error.status_code = status + assert llm._is_timeout_error(error) + + +@pytest.mark.parametrize("status", [400, 429, 500, 502]) +def test_other_statuses_are_not_a_timeout(llm, status): + error = Exception("other failure") + error.status_code = status + assert not llm._is_timeout_error(error) + + +def test_a_plain_error_is_not_a_timeout(llm): + assert not llm._is_timeout_error(ValueError("boom")) + + +# --- what chat() returns ------------------------------------------------------ + +def test_chat_tells_the_user_when_the_request_times_out(llm): + result = _provider(llm, _timeout_error()).chat("prompt") + assert result == llm._llm_timeout_command() + assert "timed out" in result + + +def test_chat_tells_the_user_when_the_gateway_times_out(llm): + error = openai.InternalServerError( + "504 Gateway Time-out", + response=httpx.Response(504, request=httpx.Request("POST", "http://gateway/openaiapi/chat/completions")), + body=None, + ) + assert _provider(llm, error).chat("prompt") == llm._llm_timeout_command() + + +def test_chat_still_returns_nothing_for_other_failures(llm): + assert _provider(llm, ValueError("boom")).chat("prompt") == "" + + +# --- the message has to survive the parser the loop runs it through ---------- + +def test_the_timeout_command_parses_into_one_send(llm, helper): + parsed = helper.balance_parentheses(llm._llm_timeout_command()) + assert parsed.startswith('((send "') + assert parsed.endswith('"))') + assert parsed.count("(send ") == 1 diff --git a/providers/asione.py b/providers/asione.py index 371ecaca3..80e38b3ef 100644 --- a/providers/asione.py +++ b/providers/asione.py @@ -81,4 +81,6 @@ def chat(self, content: str, max_tokens: int = 6000, reasoning: str = "medium", return resp except Exception as e: logger.exception(f"[ASIOneProviderImpl.chat]: Exception while communicating with LLM: {e}") + if llm._is_timeout_error(e): + return llm._llm_timeout_command() return "" diff --git a/providers/lib_llm_ext.py b/providers/lib_llm_ext.py index 28590cb7a..810269b15 100644 --- a/providers/lib_llm_ext.py +++ b/providers/lib_llm_ext.py @@ -21,6 +21,18 @@ "reasoning levels need a higher token limit." ) +LLM_TIMEOUT_MESSAGE = ( + "LLM request timed out. Please try again later." + "\n\n" + "If you are the Omega administrator: the provider did not answer within the " + "request timeout and the retries were exhausted. The failed request is in " + "the agent log; check the provider status and, if its answers are simply " + "slow, raise the timeout of its route in the proxy configuration." +) + +# Statuses a gateway returns when the upstream did not answer in time. +GATEWAY_TIMEOUT_STATUSES = (408, 504, 524) + logger = get_logger(__name__) @@ -67,6 +79,21 @@ def _llm_empty_response_command() -> str: """ return f"(send {quote_arg(LLM_EMPTY_RESPONSE_MESSAGE)})" +def _is_timeout_error(error: BaseException) -> bool: + """True when the request ran out of time rather than failing outright: the + client's own timeout, or a timeout status from the gateway in front of the + provider (the proxy answers 504 when the upstream is still thinking). + """ + if isinstance(error, openai.APITimeoutError): + return True + return getattr(error, "status_code", None) in GATEWAY_TIMEOUT_STATUSES + +def _llm_timeout_command() -> str: + """Return a status message as a MeTTa `send` command when the request times + out, so the turn ends with the user told instead of in silence. + """ + return f"(send {quote_arg(LLM_TIMEOUT_MESSAGE)})" + def _split_system_user(content: str) -> Tuple[str, str]: """ MeTTa sends: @@ -194,6 +221,8 @@ def chat(self, content: str, max_tokens: int = 6000, reasoning: str = "medium", return resp except Exception as e: logger.exception(f"[AIProvider.chat]: Exception while communicating with LLM: {e}") + if _is_timeout_error(e): + return _llm_timeout_command() return "" def _clean_text(self, text: str) -> str: diff --git a/providers/openai.py b/providers/openai.py index 8d0513539..7862a40ba 100644 --- a/providers/openai.py +++ b/providers/openai.py @@ -67,4 +67,6 @@ def chat(self, content: str, max_tokens: int = 6000, reasoning: str = "medium", return self._clean_text(raw) except Exception as e: logger.exception(f"[OpenAIProviderImpl.chat]: Exception while communicating with LLM: {e}") + if llm._is_timeout_error(e): + return llm._llm_timeout_command() return "" From 3b49db11ba55e36d371f14faef71295135bcc7b5 Mon Sep 17 00:00:00 2001 From: Leul Negash Date: Wed, 23 Sep 2026 20:12:04 +0300 Subject: [PATCH 03/11] Stub the provider SDK in the timeout tests The unit tier runs on the CI runner with plain pytest, where openai and httpx are not installed, so importing them collected as an error and the job failed. Stub openai and the configuration module before loading lib_llm_ext, the same way test_openclaw_unit.py does, and drop the httpx import. --- Autotests/unit/test_llm_timeout_message.py | 90 ++++++++++++++-------- 1 file changed, 57 insertions(+), 33 deletions(-) diff --git a/Autotests/unit/test_llm_timeout_message.py b/Autotests/unit/test_llm_timeout_message.py index 370dbb4b2..d250e6391 100644 --- a/Autotests/unit/test_llm_timeout_message.py +++ b/Autotests/unit/test_llm_timeout_message.py @@ -6,46 +6,83 @@ The timeout now comes back as a `send` command carrying a status message, the same way a reply cut off by the token limit already does. -No container, no network, no API key: the client is replaced by a stub that -raises the error under test. +No container, no network, no API key, and no provider SDK: `openai` and the +configuration module are stubbed before the module under test is loaded, the +same pattern as test_openclaw_unit.py. """ import importlib.util import os import sys +import types -import httpx -import openai import pytest _REPO_ROOT = os.path.normpath(os.path.join(os.path.dirname(__file__), "..", "..")) -for path in (_REPO_ROOT, os.path.join(_REPO_ROOT, "src")): - if path not in sys.path: - sys.path.insert(0, path) +_LIB_LLM_EXT_PATH = os.path.join(_REPO_ROOT, "providers", "lib_llm_ext.py") +_HELPER_PATH = os.path.join(_REPO_ROOT, "src", "helper.py") +# lib_llm_ext.py does `from src.helper import quote_arg` (repo-root package). +if _REPO_ROOT not in sys.path: + sys.path.insert(0, _REPO_ROOT) -def _load(name, relative_path): - spec = importlib.util.spec_from_file_location(name, os.path.join(_REPO_ROOT, relative_path)) + +class _StubAPITimeoutError(Exception): + """Stands in for openai.APITimeoutError: the client's own timeout.""" + + +def _install_stubs(): + config_stub = types.ModuleType("config") + config_stub.config_get_by_key = lambda key, default=None: None + sys.modules["config"] = config_stub + + openai_stub = types.ModuleType("openai") + openai_stub.APITimeoutError = _StubAPITimeoutError + openai_stub.OpenAI = object # only referenced in a type annotation + sys.modules["openai"] = openai_stub + + +def _load(name, path): + spec = importlib.util.spec_from_file_location(name, path) module = importlib.util.module_from_spec(spec) + sys.modules[spec.name] = module spec.loader.exec_module(module) return module @pytest.fixture(scope="module") def llm(): - return _load("lib_llm_ext_under_test", os.path.join("providers", "lib_llm_ext.py")) + saved = {name: sys.modules.get(name) for name in ("config", "openai")} + _install_stubs() + try: + yield _load("lib_llm_ext_under_test", _LIB_LLM_EXT_PATH) + finally: + for name, module in saved.items(): + if module is None: + sys.modules.pop(name, None) + else: + sys.modules[name] = module @pytest.fixture(scope="module") def helper(): - return _load("helper_under_test", os.path.join("src", "helper.py")) + return _load("helper_under_test", _HELPER_PATH) + + +def _gateway_error(status): + error = Exception(f"{status} Gateway Time-out") + error.status_code = status + return error class _RaisingClient: - """Minimal stand-in for openai.OpenAI whose chat call always fails.""" + """Stand-in for the OpenAI client whose chat call always fails.""" def __init__(self, error): - completions = type("_Completions", (), {"create": lambda _self, **kwargs: (_ for _ in ()).throw(error)})() - self.chat = type("_Chat", (), {"completions": completions})() + def create(**kwargs): + raise error + + completions = types.SimpleNamespace(create=create) + self.chat = types.SimpleNamespace(completions=completions) def _provider(llm, error): @@ -54,28 +91,20 @@ def _provider(llm, error): return provider -def _timeout_error(): - return openai.APITimeoutError(request=httpx.Request("POST", "http://gateway/openaiapi/chat/completions")) - - # --- which failures count as a timeout --------------------------------------- def test_client_timeout_is_a_timeout(llm): - assert llm._is_timeout_error(_timeout_error()) + assert llm._is_timeout_error(_StubAPITimeoutError("timed out")) @pytest.mark.parametrize("status", [408, 504, 524]) def test_gateway_timeout_statuses_are_a_timeout(llm, status): - error = Exception("gateway timeout") - error.status_code = status - assert llm._is_timeout_error(error) + assert llm._is_timeout_error(_gateway_error(status)) @pytest.mark.parametrize("status", [400, 429, 500, 502]) def test_other_statuses_are_not_a_timeout(llm, status): - error = Exception("other failure") - error.status_code = status - assert not llm._is_timeout_error(error) + assert not llm._is_timeout_error(_gateway_error(status)) def test_a_plain_error_is_not_a_timeout(llm): @@ -84,19 +113,14 @@ def test_a_plain_error_is_not_a_timeout(llm): # --- what chat() returns ------------------------------------------------------ -def test_chat_tells_the_user_when_the_request_times_out(llm): - result = _provider(llm, _timeout_error()).chat("prompt") +def test_chat_tells_the_user_when_the_client_times_out(llm): + result = _provider(llm, _StubAPITimeoutError("timed out")).chat("prompt") assert result == llm._llm_timeout_command() assert "timed out" in result def test_chat_tells_the_user_when_the_gateway_times_out(llm): - error = openai.InternalServerError( - "504 Gateway Time-out", - response=httpx.Response(504, request=httpx.Request("POST", "http://gateway/openaiapi/chat/completions")), - body=None, - ) - assert _provider(llm, error).chat("prompt") == llm._llm_timeout_command() + assert _provider(llm, _gateway_error(504)).chat("prompt") == llm._llm_timeout_command() def test_chat_still_returns_nothing_for_other_failures(llm): From ed1ab862bb1935002ed2069ec6d33f2fcd48848e Mon Sep 17 00:00:00 2001 From: Leul Negash Date: Thu, 24 Sep 2026 11:30:17 +0300 Subject: [PATCH 04/11] Report the timeout after the first request instead of retrying (#321) The client retried a timed-out request twice before raising, so with the 600s route timeout a user could wait about half an hour before the status message went out. Build the chat clients with max_retries=0, so one request runs to its timeout and the message goes out then. The loop asks again on its next iteration anyway. Embeddings are untouched, they build their own clients in src/rag.py. Add tests that both the proxy and the direct client are built with a single attempt. --- Autotests/unit/test_llm_timeout_message.py | 29 ++++++++++++++++++++++ providers/lib_llm_ext.py | 10 +++++++- providers/openrouter.py | 4 ++- 3 files changed, 41 insertions(+), 2 deletions(-) diff --git a/Autotests/unit/test_llm_timeout_message.py b/Autotests/unit/test_llm_timeout_message.py index d250e6391..2c419d4ba 100644 --- a/Autotests/unit/test_llm_timeout_message.py +++ b/Autotests/unit/test_llm_timeout_message.py @@ -134,3 +134,32 @@ def test_the_timeout_command_parses_into_one_send(llm, helper): assert parsed.startswith('((send "') assert parsed.endswith('"))') assert parsed.count("(send ") == 1 + + +# --- one attempt, so the timeout is reported when the first request gives up -- + +def _client_kwargs(llm, monkeypatch, gateway): + captured = {} + + def recorder(**kwargs): + captured.update(kwargs) + return object() + + monkeypatch.setattr(llm.openai, "OpenAI", recorder) + monkeypatch.setattr( + llm, "config_get_by_key", + lambda key, default=None: gateway if key == "GATEWAY_URL" else default, + ) + if gateway is None: + monkeypatch.setenv("OPENAIAPI_API_KEY", "dummy") + provider = llm.AIProvider("OpenAIAPI", "OPENAIAPI_API_KEY", "test-model", "http://localhost/v1/") + assert provider._create_client() is not None + return captured + + +def test_the_proxy_client_makes_one_attempt(llm, monkeypatch): + assert _client_kwargs(llm, monkeypatch, "http://localhost:8080")["max_retries"] == 0 + + +def test_the_direct_client_makes_one_attempt(llm, monkeypatch): + assert _client_kwargs(llm, monkeypatch, None)["max_retries"] == 0 diff --git a/providers/lib_llm_ext.py b/providers/lib_llm_ext.py index 810269b15..adb3a1f80 100644 --- a/providers/lib_llm_ext.py +++ b/providers/lib_llm_ext.py @@ -33,6 +33,12 @@ # Statuses a gateway returns when the upstream did not answer in time. GATEWAY_TIMEOUT_STATUSES = (408, 504, 524) +# One attempt per chat request. The client's own retries would multiply the +# request timeout before the user hears anything, and the loop asks again on its +# next iteration anyway, so a timeout is reported as soon as the first request +# reaches its limit. +CHAT_MAX_RETRIES = 0 + logger = get_logger(__name__) @@ -172,9 +178,11 @@ def _create_client(self) -> Optional[openai.OpenAI]: return openai.OpenAI( api_key="proxy", base_url=base_url, + max_retries=CHAT_MAX_RETRIES, ) if self._var_name in os.environ: - return openai.OpenAI(api_key=os.environ.get(self._var_name), base_url=self._base_url) + return openai.OpenAI(api_key=os.environ.get(self._var_name), base_url=self._base_url, + max_retries=CHAT_MAX_RETRIES) return None diff --git a/providers/openrouter.py b/providers/openrouter.py index 332ce88a5..782e79e84 100644 --- a/providers/openrouter.py +++ b/providers/openrouter.py @@ -40,9 +40,11 @@ def _create_client(self) -> Optional[openai.OpenAI]: return openai.OpenAI( api_key="proxy", base_url=base_url, + max_retries=llm.CHAT_MAX_RETRIES, ) if self._var_name in os.environ: - return openai.OpenAI(api_key=os.environ.get(self._var_name), base_url=self._base_url) + return openai.OpenAI(api_key=os.environ.get(self._var_name), base_url=self._base_url, + max_retries=llm.CHAT_MAX_RETRIES) return None From 7bd71f84f65b1495e70a41a4095c26f5f7870c1b Mon Sep 17 00:00:00 2001 From: Leul Negash Date: Thu, 24 Sep 2026 13:30:12 +0300 Subject: [PATCH 05/11] Retry transient provider failures but not timeouts (#321) Turning the SDK retries off bounded the wait, but it also removed their recovery for transient failures on every provider. The SDK cannot express the split: it decides status retries in _should_retry, yet repeats a timed-out request unconditionally. So the decision moves into _retrying(). Transient failures (409, 429, 500, 502, 503 and connection errors) get up to three attempts with a short backoff. A timeout, or a gateway timeout status, is never retried: it already spent the request timeout and the user is waiting. Nothing is retried once a 60-second budget is gone, so a failure that already cost minutes does not restart the wait. All three chat implementations go through it. Embeddings keep the client defaults, they build their own clients in src/rag.py. Add tests for the classification, the attempt limit, the budget, and that a timeout is attempted once. --- Autotests/unit/test_llm_timeout_message.py | 79 ++++++++++++++++++++++ providers/asione.py | 23 ++++--- providers/lib_llm_ext.py | 66 +++++++++++++++--- providers/openai.py | 2 +- 4 files changed, 149 insertions(+), 21 deletions(-) diff --git a/Autotests/unit/test_llm_timeout_message.py b/Autotests/unit/test_llm_timeout_message.py index 2c419d4ba..44afd17b1 100644 --- a/Autotests/unit/test_llm_timeout_message.py +++ b/Autotests/unit/test_llm_timeout_message.py @@ -30,6 +30,10 @@ class _StubAPITimeoutError(Exception): """Stands in for openai.APITimeoutError: the client's own timeout.""" +class _StubAPIConnectionError(Exception): + """Stands in for openai.APIConnectionError: the request never got an answer.""" + + def _install_stubs(): config_stub = types.ModuleType("config") config_stub.config_get_by_key = lambda key, default=None: None @@ -37,6 +41,7 @@ def _install_stubs(): openai_stub = types.ModuleType("openai") openai_stub.APITimeoutError = _StubAPITimeoutError + openai_stub.APIConnectionError = _StubAPIConnectionError openai_stub.OpenAI = object # only referenced in a type annotation sys.modules["openai"] = openai_stub @@ -163,3 +168,77 @@ def test_the_proxy_client_makes_one_attempt(llm, monkeypatch): def test_the_direct_client_makes_one_attempt(llm, monkeypatch): assert _client_kwargs(llm, monkeypatch, None)["max_retries"] == 0 + + +# --- which failures are worth another attempt -------------------------------- + +@pytest.mark.parametrize("status", [409, 429, 500, 502, 503]) +def test_transient_statuses_are_retried(llm, status): + assert llm._is_transient_error(_gateway_error(status)) + + +@pytest.mark.parametrize("status", [408, 504, 524]) +def test_timeout_statuses_are_not_retried(llm, status): + assert not llm._is_transient_error(_gateway_error(status)) + + +def test_a_client_timeout_is_not_retried(llm): + assert not llm._is_transient_error(_StubAPITimeoutError("timed out")) + + +def test_a_connection_error_is_retried(llm): + assert llm._is_transient_error(_StubAPIConnectionError("no answer")) + + +def test_a_plain_error_is_not_retried(llm): + assert not llm._is_transient_error(ValueError("boom")) + + +# --- how _retrying behaves ---------------------------------------------------- + +def _counting_call(errors): + """Raise each error in turn, then return a sentinel. Records the attempts.""" + calls = [] + + def call(): + calls.append(len(calls) + 1) + if calls[-1] <= len(errors): + raise errors[calls[-1] - 1] + return "answer" + + return call, calls + + +def test_a_transient_failure_is_retried_until_it_succeeds(llm, monkeypatch): + monkeypatch.setattr(llm.time, "sleep", lambda seconds: None) + call, calls = _counting_call([_gateway_error(503)]) + assert llm._retrying(call, "OpenAIAPI") == "answer" + assert len(calls) == 2 + + +def test_a_timeout_is_attempted_once(llm, monkeypatch): + monkeypatch.setattr(llm.time, "sleep", lambda seconds: None) + call, calls = _counting_call([_StubAPITimeoutError("timed out")] * 3) + with pytest.raises(_StubAPITimeoutError): + llm._retrying(call, "OpenAIAPI") + assert len(calls) == 1 + + +def test_transient_failures_stop_at_the_attempt_limit(llm, monkeypatch): + monkeypatch.setattr(llm.time, "sleep", lambda seconds: None) + call, calls = _counting_call([_gateway_error(503)] * 5) + with pytest.raises(Exception): + llm._retrying(call, "OpenAIAPI") + assert len(calls) == llm.CHAT_ATTEMPTS + + +def test_a_slow_transient_failure_is_not_retried(llm, monkeypatch): + """A failure that already took longer than the budget is not transient in + any useful sense, so the caller hears about it instead of waiting again.""" + monkeypatch.setattr(llm.time, "sleep", lambda seconds: None) + clock = iter([0, llm.CHAT_RETRY_BUDGET_SECONDS + 1]) + monkeypatch.setattr(llm.time, "monotonic", lambda: next(clock)) + call, calls = _counting_call([_gateway_error(503)] * 3) + with pytest.raises(Exception): + llm._retrying(call, "OpenAIAPI") + assert len(calls) == 1 diff --git a/providers/asione.py b/providers/asione.py index 80e38b3ef..59f4e2a9d 100644 --- a/providers/asione.py +++ b/providers/asione.py @@ -57,16 +57,19 @@ def chat(self, content: str, max_tokens: int = 6000, reasoning: str = "medium", sysmsg, usermsg = content.split(":-:-:-:") thinking_budget = _reasoning_budget(max_tokens, reasoning) try: - response = self._client.chat.completions.create( - model=self._model_name, - messages=[{"role": "system", "content": sysmsg}, - {"role": "user", "content": usermsg}], - max_tokens=max_tokens, - extra_body={ - "enable_thinking": thinking_budget > 0, - "thinking_budget": thinking_budget - }, - **kwargs + response = llm._retrying( + lambda: self._client.chat.completions.create( + model=self._model_name, + messages=[{"role": "system", "content": sysmsg}, + {"role": "user", "content": usermsg}], + max_tokens=max_tokens, + extra_body={ + "enable_thinking": thinking_budget > 0, + "thinking_budget": thinking_budget + }, + **kwargs + ), + self._name, ) raw = response.choices[0].message.content or "" diff --git a/providers/lib_llm_ext.py b/providers/lib_llm_ext.py index adb3a1f80..91a479d6c 100644 --- a/providers/lib_llm_ext.py +++ b/providers/lib_llm_ext.py @@ -1,4 +1,4 @@ -import os, hashlib +import os, hashlib, time import openai from typing import Optional, Tuple, Dict, Any from config import config_get_by_key @@ -33,12 +33,22 @@ # Statuses a gateway returns when the upstream did not answer in time. GATEWAY_TIMEOUT_STATUSES = (408, 504, 524) -# One attempt per chat request. The client's own retries would multiply the -# request timeout before the user hears anything, and the loop asks again on its -# next iteration anyway, so a timeout is reported as soon as the first request -# reaches its limit. +# One attempt per chat request inside the SDK. Its retry loop repeats a timed-out +# request unconditionally, which would multiply the request timeout before the +# user hears anything. Transient failures are retried by _retrying() below +# instead, where a timeout can be excluded. CHAT_MAX_RETRIES = 0 +# Failures worth trying again right away: the statuses the SDK retries by +# default, minus the timeout ones, plus a connection that never got an answer. +TRANSIENT_STATUSES = (409, 429, 500, 502, 503) +# First attempt plus two retries, and only while the whole call stays inside the +# budget: a failure that already cost minutes is not "transient", and the user is +# waiting for an answer. +CHAT_ATTEMPTS = 3 +CHAT_RETRY_BUDGET_SECONDS = 60 +CHAT_RETRY_BACKOFF_SECONDS = 0.5 + logger = get_logger(__name__) @@ -100,6 +110,39 @@ def _llm_timeout_command() -> str: """ return f"(send {quote_arg(LLM_TIMEOUT_MESSAGE)})" +def _is_transient_error(error: BaseException) -> bool: + """True for a failure that another attempt may get past. A timeout is not + one of them: it already spent the request timeout, so retrying it only keeps + the user waiting. + """ + if _is_timeout_error(error): + return False + if isinstance(error, openai.APIConnectionError): + return True + return getattr(error, "status_code", None) in TRANSIENT_STATUSES + +def _retrying(call, provider: str): + """Run call(), retrying only transient failures and only briefly. + + The SDK's own retries are off (CHAT_MAX_RETRIES), so this is the single place + that decides what gets another attempt: transient failures do, a timeout does + not, and nothing is retried once the budget is spent. + """ + started = time.monotonic() + for attempt in range(1, CHAT_ATTEMPTS + 1): + try: + return call() + except Exception as error: + spent = time.monotonic() - started + if (attempt == CHAT_ATTEMPTS + or spent >= CHAT_RETRY_BUDGET_SECONDS + or not _is_transient_error(error)): + raise + delay = CHAT_RETRY_BACKOFF_SECONDS * (2 ** (attempt - 1)) + logger.warning( + f"[{provider}.chat]: transient failure, retrying in {delay:.1f}s: {error}") + time.sleep(delay) + def _split_system_user(content: str) -> Tuple[str, str]: """ MeTTa sends: @@ -210,11 +253,14 @@ def chat(self, content: str, max_tokens: int = 6000, reasoning: str = "medium", raise RuntimeError(f"{self.name} not configured (set {self._var_name})") try: - response = self._client.chat.completions.create( - model=self._model_name, - messages=self._build_messages(content), - max_tokens=max_tokens, - **kwargs + response = _retrying( + lambda: self._client.chat.completions.create( + model=self._model_name, + messages=self._build_messages(content), + max_tokens=max_tokens, + **kwargs + ), + self._name, ) raw = response.choices[0].message.content or "" diff --git a/providers/openai.py b/providers/openai.py index 7862a40ba..bca53ce4f 100644 --- a/providers/openai.py +++ b/providers/openai.py @@ -53,7 +53,7 @@ def chat(self, content: str, max_tokens: int = 6000, reasoning: str = "medium", create_kwargs.update(kwargs) - response = self._client.responses.create(**create_kwargs) + response = llm._retrying(lambda: self._client.responses.create(**create_kwargs), self._name) raw = response.output_text or "" incomplete_details = getattr(response, "incomplete_details", None) From 1004c10866ce3151909122a59fa68e7b1a5978c2 Mon Sep 17 00:00:00 2001 From: Leul Negash Date: Fri, 25 Sep 2026 11:58:11 +0300 Subject: [PATCH 06/11] Fix the gaps QA found in the timeout handling (#321) Retry classification followed a hand-written status list that stopped at 503, so 529 and 522 were reported as failures instead of retried. It now follows the same rule as the SDK, 409, 429 and any 5xx, with the timeout statuses left to _is_timeout_error so they are reported rather than retried. The wait between attempts ignored Retry-After, so a 429 asking for five seconds got three attempts inside 1.5s and then silence. _retry_delay uses Retry-After when the provider sends one in seconds, falls back to the backoff for the HTTP-date form, and refuses a retry whose wait would not fit in the budget. The timeout notice was the same text every time, and send drops a message equal to the last one it sent, so a second timeout in a row left that turn silent. The notice now carries the time. Classifying an error no longer reads the exception classes off the client module directly. With a client that does not define them the lookup raised inside the except block and masked the error being classified. Also drop the claim that the retries were exhausted, since a timeout is attempted once. Add tests for the 5xx rule, Retry-After in seconds and as a date, a wait that exceeds the budget, and two notices in a row differing. --- Autotests/unit/test_llm_timeout_message.py | 64 ++++++++++++++++++++-- providers/lib_llm_ext.py | 59 ++++++++++++++------ 2 files changed, 102 insertions(+), 21 deletions(-) diff --git a/Autotests/unit/test_llm_timeout_message.py b/Autotests/unit/test_llm_timeout_message.py index 44afd17b1..65119efd7 100644 --- a/Autotests/unit/test_llm_timeout_message.py +++ b/Autotests/unit/test_llm_timeout_message.py @@ -118,14 +118,16 @@ def test_a_plain_error_is_not_a_timeout(llm): # --- what chat() returns ------------------------------------------------------ +def _is_timeout_notice(result): + return result.startswith('(send "LLM request timed out at ') and result.endswith('")') + + def test_chat_tells_the_user_when_the_client_times_out(llm): - result = _provider(llm, _StubAPITimeoutError("timed out")).chat("prompt") - assert result == llm._llm_timeout_command() - assert "timed out" in result + assert _is_timeout_notice(_provider(llm, _StubAPITimeoutError("timed out")).chat("prompt")) def test_chat_tells_the_user_when_the_gateway_times_out(llm): - assert _provider(llm, _gateway_error(504)).chat("prompt") == llm._llm_timeout_command() + assert _is_timeout_notice(_provider(llm, _gateway_error(504)).chat("prompt")) def test_chat_still_returns_nothing_for_other_failures(llm): @@ -172,7 +174,7 @@ def test_the_direct_client_makes_one_attempt(llm, monkeypatch): # --- which failures are worth another attempt -------------------------------- -@pytest.mark.parametrize("status", [409, 429, 500, 502, 503]) +@pytest.mark.parametrize("status", [409, 429, 500, 502, 503, 522, 529]) def test_transient_statuses_are_retried(llm, status): assert llm._is_transient_error(_gateway_error(status)) @@ -242,3 +244,55 @@ def test_a_slow_transient_failure_is_not_retried(llm, monkeypatch): with pytest.raises(Exception): llm._retrying(call, "OpenAIAPI") assert len(calls) == 1 + + +# --- the wait between attempts follows Retry-After ---------------------------- + +def _retry_after_error(status, value): + error = _gateway_error(status) + error.response = types.SimpleNamespace(headers={"retry-after": value}) + return error + + +def test_retry_after_in_seconds_is_honoured(llm): + assert llm._retry_delay(_retry_after_error(429, "5"), 1) == 5.0 + + +def test_retry_after_as_a_date_falls_back_to_the_backoff(llm): + delay = llm._retry_delay(_retry_after_error(429, "Wed, 21 Oct 2026 07:28:00 GMT"), 1) + assert delay == llm.CHAT_RETRY_BACKOFF_SECONDS + + +def test_without_retry_after_the_backoff_grows(llm): + assert llm._retry_delay(_gateway_error(503), 1) == llm.CHAT_RETRY_BACKOFF_SECONDS + assert llm._retry_delay(_gateway_error(503), 2) == llm.CHAT_RETRY_BACKOFF_SECONDS * 2 + + +def test_the_retry_waits_as_long_as_the_provider_asked(llm, monkeypatch): + slept = [] + monkeypatch.setattr(llm.time, "sleep", slept.append) + call, calls = _counting_call([_retry_after_error(429, "5")]) + assert llm._retrying(call, "OpenAIAPI") == "answer" + assert slept == [5.0] + assert len(calls) == 2 + + +def test_a_retry_after_beyond_the_budget_is_not_waited_out(llm, monkeypatch): + monkeypatch.setattr(llm.time, "sleep", lambda seconds: None) + call, calls = _counting_call([_retry_after_error(429, str(llm.CHAT_RETRY_BUDGET_SECONDS + 10))] * 3) + with pytest.raises(Exception): + llm._retrying(call, "OpenAIAPI") + assert len(calls) == 1 + + +# --- two timeouts in a row must both reach the user -------------------------- + +def test_the_notice_carries_the_time_so_repeats_are_not_identical(llm, monkeypatch): + """`send` drops a message equal to the last one it sent, so two notices in a + row have to differ or the second turn goes unanswered.""" + clock = iter(["05:14:17", "05:15:52"]) + monkeypatch.setattr(llm.time, "strftime", lambda fmt: next(clock)) + first = llm._llm_timeout_command() + second = llm._llm_timeout_command() + assert "05:14:17" in first and "05:15:52" in second + assert first != second diff --git a/providers/lib_llm_ext.py b/providers/lib_llm_ext.py index 91a479d6c..b463e2985 100644 --- a/providers/lib_llm_ext.py +++ b/providers/lib_llm_ext.py @@ -22,12 +22,12 @@ ) LLM_TIMEOUT_MESSAGE = ( - "LLM request timed out. Please try again later." + "LLM request timed out at {time}. Please try again later." "\n\n" "If you are the Omega administrator: the provider did not answer within the " - "request timeout and the retries were exhausted. The failed request is in " - "the agent log; check the provider status and, if its answers are simply " - "slow, raise the timeout of its route in the proxy configuration." + "request timeout, and a timed-out request is not retried. The failed request " + "is in the agent log; check the provider status and, if its answers are " + "simply slow, raise the timeout of its route in the proxy configuration." ) # Statuses a gateway returns when the upstream did not answer in time. @@ -39,9 +39,11 @@ # instead, where a timeout can be excluded. CHAT_MAX_RETRIES = 0 -# Failures worth trying again right away: the statuses the SDK retries by -# default, minus the timeout ones, plus a connection that never got an answer. -TRANSIENT_STATUSES = (409, 429, 500, 502, 503) +# Failures worth trying again right away. The SDK retries 409, 429 and any 5xx, +# so keep that rule rather than a list that misses one (529 and 522 both reach +# here); the timeout statuses are excluded by _is_timeout_error above, so they are +# reported instead of retried. +TRANSIENT_STATUSES = (409, 429) # First attempt plus two retries, and only while the whole call stays inside the # budget: a failure that already cost minutes is not "transient", and the user is # waiting for an answer. @@ -100,15 +102,22 @@ def _is_timeout_error(error: BaseException) -> bool: client's own timeout, or a timeout status from the gateway in front of the provider (the proxy answers 504 when the upstream is still thinking). """ - if isinstance(error, openai.APITimeoutError): + # The classes are looked up rather than referenced: classifying a failure must + # never raise one of its own, whatever the installed client exposes. + if isinstance(error, getattr(openai, "APITimeoutError", ())): return True return getattr(error, "status_code", None) in GATEWAY_TIMEOUT_STATUSES def _llm_timeout_command() -> str: """Return a status message as a MeTTa `send` command when the request times out, so the turn ends with the user told instead of in silence. + + The message carries the time. `send` drops a message equal to the last one it + sent, so without it a second timeout in a row would leave that turn silent, + which is the symptom this whole change is about. """ - return f"(send {quote_arg(LLM_TIMEOUT_MESSAGE)})" + message = LLM_TIMEOUT_MESSAGE.format(time=time.strftime("%H:%M:%S")) + return f"(send {quote_arg(message)})" def _is_transient_error(error: BaseException) -> bool: """True for a failure that another attempt may get past. A timeout is not @@ -117,9 +126,26 @@ def _is_transient_error(error: BaseException) -> bool: """ if _is_timeout_error(error): return False - if isinstance(error, openai.APIConnectionError): + if isinstance(error, getattr(openai, "APIConnectionError", ())): return True - return getattr(error, "status_code", None) in TRANSIENT_STATUSES + status = getattr(error, "status_code", None) + if status is None: + return False + return status in TRANSIENT_STATUSES or status >= 500 + +def _retry_delay(error: BaseException, attempt: int) -> float: + """How long to wait before the next attempt: the provider's Retry-After when + it sends one in seconds, otherwise a short exponential backoff. A Retry-After + given as an HTTP date falls back to the backoff. + """ + headers = getattr(getattr(error, "response", None), "headers", None) + value = headers.get("retry-after") if hasattr(headers, "get") else None + if value is not None: + try: + return max(0.0, float(value)) + except (TypeError, ValueError): + pass + return CHAT_RETRY_BACKOFF_SECONDS * (2 ** (attempt - 1)) def _retrying(call, provider: str): """Run call(), retrying only transient failures and only briefly. @@ -133,12 +159,13 @@ def _retrying(call, provider: str): try: return call() except Exception as error: - spent = time.monotonic() - started - if (attempt == CHAT_ATTEMPTS - or spent >= CHAT_RETRY_BUDGET_SECONDS - or not _is_transient_error(error)): + if attempt == CHAT_ATTEMPTS or not _is_transient_error(error): + raise + delay = _retry_delay(error, attempt) + if time.monotonic() - started + delay >= CHAT_RETRY_BUDGET_SECONDS: + logger.warning( + f"[{provider}.chat]: retry budget spent, giving up: {error}") raise - delay = CHAT_RETRY_BACKOFF_SECONDS * (2 ** (attempt - 1)) logger.warning( f"[{provider}.chat]: transient failure, retrying in {delay:.1f}s: {error}") time.sleep(delay) From 76ef473ceb55b9cb60b4173b9944e9939cc025bc Mon Sep 17 00:00:00 2001 From: Leul Negash Date: Mon, 28 Sep 2026 06:34:35 +0300 Subject: [PATCH 07/11] Make every timeout notice unique (#321) The notice carried the time to the second, so two cycles failing inside the same second rendered the same message, and send drops a message equal to the last one it sent: that turn went silent again. The notice now carries the time to the millisecond and a count that rises with every notice, so two of them differ even when the clock does not move. The test freezes the clock and checks exactly that. --- Autotests/unit/test_llm_timeout_message.py | 16 ++++++++++----- providers/lib_llm_ext.py | 23 +++++++++++++++------- 2 files changed, 27 insertions(+), 12 deletions(-) diff --git a/Autotests/unit/test_llm_timeout_message.py b/Autotests/unit/test_llm_timeout_message.py index 65119efd7..7c4ef0b47 100644 --- a/Autotests/unit/test_llm_timeout_message.py +++ b/Autotests/unit/test_llm_timeout_message.py @@ -12,6 +12,7 @@ """ import importlib.util import os +import re import sys import types @@ -287,12 +288,17 @@ def test_a_retry_after_beyond_the_budget_is_not_waited_out(llm, monkeypatch): # --- two timeouts in a row must both reach the user -------------------------- -def test_the_notice_carries_the_time_so_repeats_are_not_identical(llm, monkeypatch): +def test_the_notice_carries_the_time_to_the_millisecond(llm): + assert re.search(r"timed out at \d{2}:\d{2}:\d{2}\.\d{3}", llm._llm_timeout_command()) + + +def test_two_notices_differ_even_inside_the_same_millisecond(llm, monkeypatch): """`send` drops a message equal to the last one it sent, so two notices in a - row have to differ or the second turn goes unanswered.""" - clock = iter(["05:14:17", "05:15:52"]) - monkeypatch.setattr(llm.time, "strftime", lambda fmt: next(clock)) + row have to differ or the second turn goes unanswered. The clock alone cannot + guarantee that, so the count has to carry it.""" + frozen = types.SimpleNamespace(strftime=lambda fmt: "05:14:17.000000") + monkeypatch.setattr(llm, "datetime", types.SimpleNamespace(now=lambda: frozen)) first = llm._llm_timeout_command() second = llm._llm_timeout_command() - assert "05:14:17" in first and "05:15:52" in second + assert "05:14:17.000" in first and "05:14:17.000" in second assert first != second diff --git a/providers/lib_llm_ext.py b/providers/lib_llm_ext.py index b463e2985..48137c3bc 100644 --- a/providers/lib_llm_ext.py +++ b/providers/lib_llm_ext.py @@ -1,4 +1,5 @@ import os, hashlib, time +from datetime import datetime import openai from typing import Optional, Tuple, Dict, Any from config import config_get_by_key @@ -25,9 +26,10 @@ "LLM request timed out at {time}. Please try again later." "\n\n" "If you are the Omega administrator: the provider did not answer within the " - "request timeout, and a timed-out request is not retried. The failed request " - "is in the agent log; check the provider status and, if its answers are " - "simply slow, raise the timeout of its route in the proxy configuration." + "request timeout, and a timed-out request is not retried. This is timeout " + "notice {count} since the agent started. The failed request is in the agent " + "log; check the provider status and, if its answers are simply slow, raise " + "the timeout of its route in the proxy configuration." ) # Statuses a gateway returns when the upstream did not answer in time. @@ -108,15 +110,22 @@ def _is_timeout_error(error: BaseException) -> bool: return True return getattr(error, "status_code", None) in GATEWAY_TIMEOUT_STATUSES +_timeout_notices = 0 + def _llm_timeout_command() -> str: """Return a status message as a MeTTa `send` command when the request times out, so the turn ends with the user told instead of in silence. - The message carries the time. `send` drops a message equal to the last one it - sent, so without it a second timeout in a row would leave that turn silent, - which is the symptom this whole change is about. + `send` drops a message equal to the last one it sent, so two notices must + never render the same: a second timeout would leave that turn silent, which is + the symptom this whole change is about. The time alone does not guarantee it, + since two cycles can fail inside the same second, so the notice carries the + time to the millisecond and a count that rises with every notice. """ - message = LLM_TIMEOUT_MESSAGE.format(time=time.strftime("%H:%M:%S")) + global _timeout_notices + _timeout_notices += 1 + stamp = datetime.now().strftime("%H:%M:%S.%f")[:-3] + message = LLM_TIMEOUT_MESSAGE.format(time=stamp, count=_timeout_notices) return f"(send {quote_arg(message)})" def _is_transient_error(error: BaseException) -> bool: From ef917ebb56432ccc5afdb7c6aef69ba65b01bb7a Mon Sep 17 00:00:00 2001 From: Leul Negash Date: Thu, 1 Oct 2026 12:57:04 +0300 Subject: [PATCH 08/11] Report a timeout once per run, not once per cycle (#321) The loop calls the provider up to maxNewInputLoops times after startup and again after each message, and every timed-out call sent its own notice: with an instant 504 that put 50 notices on the channel in 50 seconds. A provider now reports a timeout once per run of them. The run ends when a call succeeds, or when a prompt carries a human message, since that turn is waiting for an answer of its own. In between the timeout is logged and nothing is sent. The notice also suggested raising the route timeout in the proxy, but the client kept its own 600 s default, so the request ended there regardless. The client is now created with that timeout explicitly, and the notice names the number and says both limits have to be raised to allow longer answers. --- Autotests/unit/test_llm_timeout_message.py | 84 ++++++++++++++++++++++ providers/asione.py | 4 +- providers/lib_llm_ext.py | 58 +++++++++++++-- providers/openai.py | 4 +- 4 files changed, 141 insertions(+), 9 deletions(-) diff --git a/Autotests/unit/test_llm_timeout_message.py b/Autotests/unit/test_llm_timeout_message.py index 7c4ef0b47..21a5da2bc 100644 --- a/Autotests/unit/test_llm_timeout_message.py +++ b/Autotests/unit/test_llm_timeout_message.py @@ -302,3 +302,87 @@ def test_two_notices_differ_even_inside_the_same_millisecond(llm, monkeypatch): second = llm._llm_timeout_command() assert "05:14:17.000" in first and "05:14:17.000" in second assert first != second + + +# --- one notice per run of timeouts ------------------------------------------ + +SYSTEM_PART = "PROMPT: you are an agent" + + +def _prompt(human=""): + return f"{SYSTEM_PART} :-:-:-: {human}" + + +def _reply(text='(send "hello")'): + message = types.SimpleNamespace(content=text) + return types.SimpleNamespace(choices=[types.SimpleNamespace(message=message, finish_reason="stop")], + usage=None) + + +class _ScriptedClient: + """Chat client that walks a list of steps: an exception is raised, anything + else is returned. The last step repeats.""" + + def __init__(self, steps): + self.calls = 0 + + def create(**kwargs): + self.calls += 1 + step = steps[min(self.calls, len(steps)) - 1] + if isinstance(step, BaseException): + raise step + return step + + self.chat = types.SimpleNamespace(completions=types.SimpleNamespace(create=create)) + + +def _scripted_provider(llm, steps): + provider = llm.AIProvider("OpenAIAPI", "OPENAIAPI_API_KEY", "test-model", "http://localhost/v1/") + provider._client = _ScriptedClient(steps) + return provider + + +def test_only_the_first_timeout_of_a_run_is_reported(llm): + provider = _scripted_provider(llm, [_gateway_error(504)]) + assert _is_timeout_notice(provider.chat(_prompt())) + assert provider.chat(_prompt()) == "" + assert provider.chat(_prompt()) == "" + + +def test_a_successful_answer_starts_a_new_run(llm): + provider = _scripted_provider(llm, [_gateway_error(504), _reply(), _gateway_error(504)]) + assert _is_timeout_notice(provider.chat(_prompt())) + assert provider.chat(_prompt()) == '(send "hello")' + assert _is_timeout_notice(provider.chat(_prompt())) + + +def test_a_new_human_message_starts_a_new_run(llm): + """The user who just wrote deserves an answer, even if the previous cycle + already reported a timeout.""" + provider = _scripted_provider(llm, [_gateway_error(504)]) + assert _is_timeout_notice(provider.chat(_prompt("HUMAN-MSG: first"))) + assert provider.chat(_prompt()) == "" + assert _is_timeout_notice(provider.chat(_prompt("HUMAN-MSG: second"))) + assert provider.chat(_prompt()) == "" + + +def test_every_prompt_carrying_a_message_gets_its_own_notice(llm): + """The loop puts the message in the prompt only on the cycle where it is new, + so a tail here always means a turn that is waiting for an answer.""" + provider = _scripted_provider(llm, [_gateway_error(504)]) + assert _is_timeout_notice(provider.chat(_prompt("HUMAN-MSG: same"))) + assert provider.chat(_prompt()) == "" + assert _is_timeout_notice(provider.chat(_prompt("HUMAN-MSG: same"))) + + +# --- the client enforces the timeout the notice names ------------------------ + +def test_the_client_enforces_the_request_timeout(llm, monkeypatch): + assert _client_kwargs(llm, monkeypatch, "http://localhost:8080")["timeout"] == llm.CHAT_REQUEST_TIMEOUT_SECONDS + assert llm.CHAT_REQUEST_TIMEOUT_SECONDS == 600 + + +def test_the_notice_names_the_limit_and_both_places_that_hold_it(llm): + notice = llm._llm_timeout_command() + assert "600 s request timeout" in notice + assert "raising both" in notice diff --git a/providers/asione.py b/providers/asione.py index 59f4e2a9d..4f91ae109 100644 --- a/providers/asione.py +++ b/providers/asione.py @@ -49,6 +49,7 @@ def __init__(self, name: str, var_name: str, model_name: str, base_url: str): def chat(self, content: str, max_tokens: int = 6000, reasoning: str = "medium", **kwargs) -> str: """Send chat request, initializing client if needed.""" + self._start_of_turn(content) self._ensure_client() if self._client is None: @@ -72,6 +73,7 @@ def chat(self, content: str, max_tokens: int = 6000, reasoning: str = "medium", self._name, ) + self._answered() raw = response.choices[0].message.content or "" finish_reason = getattr(response.choices[0], "finish_reason", None) llm._log_raw(self._name, self._model_name, raw) @@ -85,5 +87,5 @@ def chat(self, content: str, max_tokens: int = 6000, reasoning: str = "medium", except Exception as e: logger.exception(f"[ASIOneProviderImpl.chat]: Exception while communicating with LLM: {e}") if llm._is_timeout_error(e): - return llm._llm_timeout_command() + return self._timeout_reply() return "" diff --git a/providers/lib_llm_ext.py b/providers/lib_llm_ext.py index 48137c3bc..d2f9291cd 100644 --- a/providers/lib_llm_ext.py +++ b/providers/lib_llm_ext.py @@ -26,15 +26,21 @@ "LLM request timed out at {time}. Please try again later." "\n\n" "If you are the Omega administrator: the provider did not answer within the " - "request timeout, and a timed-out request is not retried. This is timeout " - "notice {count} since the agent started. The failed request is in the agent " - "log; check the provider status and, if its answers are simply slow, raise " - "the timeout of its route in the proxy configuration." + "{timeout} s request timeout, and a timed-out request is not retried. This is " + "timeout notice {count} since the agent started. The failed request is in the " + "agent log; check the provider status. The limit is enforced by the client and " + "by the provider\'s route in the proxy, so allowing longer answers means " + "raising both." ) # Statuses a gateway returns when the upstream did not answer in time. GATEWAY_TIMEOUT_STATUSES = (408, 504, 524) +# The request timeout the client enforces. It matches the proxy route timeout, so +# a slow answer is cut once, by whichever limit is reached first, and the notice +# can name a single number. +CHAT_REQUEST_TIMEOUT_SECONDS = 600 + # One attempt per chat request inside the SDK. Its retry loop repeats a timed-out # request unconditionally, which would multiply the request timeout before the # user hears anything. Transient failures are retried by _retrying() below @@ -125,7 +131,8 @@ def _llm_timeout_command() -> str: global _timeout_notices _timeout_notices += 1 stamp = datetime.now().strftime("%H:%M:%S.%f")[:-3] - message = LLM_TIMEOUT_MESSAGE.format(time=stamp, count=_timeout_notices) + message = LLM_TIMEOUT_MESSAGE.format( + time=stamp, count=_timeout_notices, timeout=CHAT_REQUEST_TIMEOUT_SECONDS) return f"(send {quote_arg(message)})" def _is_transient_error(error: BaseException) -> bool: @@ -241,6 +248,39 @@ def __init__(self, name: str, var_name: str, model_name: str, base_url: str): self._model_name = model_name self._base_url = base_url self._client = None # lazy initialization + self._timeout_notice_sent = False + + def _start_of_turn(self, content: str) -> None: + """A prompt carrying a human message starts a fresh turn, which deserves + its own answer even if the previous cycle already timed out. + + The tail is read straight from the prompt rather than through + _split_system_user, which substitutes a placeholder when it is empty. The + loop fills the tail only on the cycle where the message is new, so any + tail here means a turn of its own. + """ + _, delimiter, tail = content.partition(PROMPT_DELIMITER) + if (tail if delimiter else content).strip(): + self._timeout_notice_sent = False + + def _answered(self) -> None: + """The provider answered, so the next timeout is a new run.""" + self._timeout_notice_sent = False + + def _timeout_reply(self) -> str: + """The notice for a timed-out request, once per run of timeouts. + + The loop keeps calling for up to maxNewInputLoops cycles, so a notice per + cycle would fill the chat with the same text. The run ends when a call + succeeds or a new human message arrives; until then the timeout is logged + and nothing is sent. + """ + if self._timeout_notice_sent: + logger.warning( + f"[{self.name}.chat]: timed out again, the user was already told") + return "" + self._timeout_notice_sent = True + return _llm_timeout_command() def _ensure_client(self): """Initialize client on first use.""" @@ -258,10 +298,12 @@ def _create_client(self) -> Optional[openai.OpenAI]: api_key="proxy", base_url=base_url, max_retries=CHAT_MAX_RETRIES, + timeout=CHAT_REQUEST_TIMEOUT_SECONDS, ) if self._var_name in os.environ: return openai.OpenAI(api_key=os.environ.get(self._var_name), base_url=self._base_url, - max_retries=CHAT_MAX_RETRIES) + max_retries=CHAT_MAX_RETRIES, + timeout=CHAT_REQUEST_TIMEOUT_SECONDS) return None @@ -283,6 +325,7 @@ def _build_messages(self, content: str): def chat(self, content: str, max_tokens: int = 6000, reasoning: str = "medium", **kwargs) -> str: """Send chat request, initializing client if needed.""" + self._start_of_turn(content) self._ensure_client() if self._client is None: @@ -299,6 +342,7 @@ def chat(self, content: str, max_tokens: int = 6000, reasoning: str = "medium", self._name, ) + self._answered() raw = response.choices[0].message.content or "" finish_reason = getattr(response.choices[0], "finish_reason", None) _log_raw(self._name, self._model_name, raw) @@ -312,7 +356,7 @@ def chat(self, content: str, max_tokens: int = 6000, reasoning: str = "medium", except Exception as e: logger.exception(f"[AIProvider.chat]: Exception while communicating with LLM: {e}") if _is_timeout_error(e): - return _llm_timeout_command() + return self._timeout_reply() return "" def _clean_text(self, text: str) -> str: diff --git a/providers/openai.py b/providers/openai.py index bca53ce4f..831c17940 100644 --- a/providers/openai.py +++ b/providers/openai.py @@ -31,6 +31,7 @@ class OpenAIProviderImpl(llm.AIProvider): def chat(self, content: str, max_tokens: int = 6000, reasoning: str = "medium", **kwargs) -> str: """Send chat request via the Responses API, initializing client if needed.""" + self._start_of_turn(content) self._ensure_client() if self._client is None: @@ -55,6 +56,7 @@ def chat(self, content: str, max_tokens: int = 6000, reasoning: str = "medium", response = llm._retrying(lambda: self._client.responses.create(**create_kwargs), self._name) + self._answered() raw = response.output_text or "" incomplete_details = getattr(response, "incomplete_details", None) incomplete_reason = getattr(incomplete_details, "reason", None) @@ -68,5 +70,5 @@ def chat(self, content: str, max_tokens: int = 6000, reasoning: str = "medium", except Exception as e: logger.exception(f"[OpenAIProviderImpl.chat]: Exception while communicating with LLM: {e}") if llm._is_timeout_error(e): - return llm._llm_timeout_command() + return self._timeout_reply() return "" From 84a452025dc2064221372596508f4b35ccaa3feb Mon Sep 17 00:00:00 2001 From: Leul Negash Date: Thu, 1 Oct 2026 14:32:58 +0300 Subject: [PATCH 09/11] Start a new timeout run only on a tagged human message (#321) _start_of_turn treated any non-empty prompt tail as a new message. With spamShield on, the loop puts its reminder there on every follow-up cycle, which reset the run and brought back one notice per cycle. The reset now requires the loop's HUMAN-MSG: tag, however the tail wraps it, so the reminder and the empty tail leave the run alone. The OpenRouter client is created with the request timeout as well; it overrides _create_client, so it was the one client still relying on the library default while the notice named that limit. Tests cover the reminder not starting a run, the tag starting one in each form the tail can take, and the OpenRouter client carrying the timeout. --- Autotests/unit/test_llm_timeout_message.py | 20 +++++++++++++++++--- providers/lib_llm_ext.py | 20 +++++++++++++------- providers/openrouter.py | 4 +++- 3 files changed, 33 insertions(+), 11 deletions(-) diff --git a/Autotests/unit/test_llm_timeout_message.py b/Autotests/unit/test_llm_timeout_message.py index 21a5da2bc..e56bf08ae 100644 --- a/Autotests/unit/test_llm_timeout_message.py +++ b/Autotests/unit/test_llm_timeout_message.py @@ -366,15 +366,29 @@ def test_a_new_human_message_starts_a_new_run(llm): assert provider.chat(_prompt()) == "" -def test_every_prompt_carrying_a_message_gets_its_own_notice(llm): - """The loop puts the message in the prompt only on the cycle where it is new, - so a tail here always means a turn that is waiting for an answer.""" +def test_every_tagged_message_gets_its_own_notice(llm): provider = _scripted_provider(llm, [_gateway_error(504)]) assert _is_timeout_notice(provider.chat(_prompt("HUMAN-MSG: same"))) assert provider.chat(_prompt()) == "" assert _is_timeout_notice(provider.chat(_prompt("HUMAN-MSG: same"))) +def test_the_tagged_message_is_recognised_however_the_loop_wraps_it(llm): + provider = _scripted_provider(llm, [_gateway_error(504)]) + assert _is_timeout_notice(provider.chat(_prompt("(HUMAN-MSG: hello)"))) + assert provider.chat(_prompt()) == "" + assert _is_timeout_notice(provider.chat(_prompt("['HUMAN-MSG:', 'hello']"))) + + +def test_the_spamshield_reminder_is_not_a_new_turn(llm): + """With spamShield on, the loop puts this in the tail on every follow-up + cycle. Taking it for a message would restore one notice per cycle.""" + provider = _scripted_provider(llm, [_gateway_error(504)]) + assert _is_timeout_notice(provider.chat(_prompt("HUMAN-MSG: hello"))) + for _ in range(3): + assert provider.chat(_prompt(" DO NOT RE-SEND OR SPAM!")) == "" + + # --- the client enforces the timeout the notice names ------------------------ def test_the_client_enforces_the_request_timeout(llm, monkeypatch): diff --git a/providers/lib_llm_ext.py b/providers/lib_llm_ext.py index d2f9291cd..6e88c17b9 100644 --- a/providers/lib_llm_ext.py +++ b/providers/lib_llm_ext.py @@ -7,6 +7,10 @@ from src.logger import get_logger PROMPT_DELIMITER = ":-:-:-:" +# The loop tags the human message it appends after the delimiter. Everything else +# that can land there, the spamShield reminder or nothing at all, is not a turn of +# its own. +HUMAN_MESSAGE_MARKER = "HUMAN-MSG:" LLM_EMPTY_RESPONSE_MESSAGE = ( "The agent didn\'t return an answer: reasoning exceeded the token limit for " "this response before it could produce one." @@ -29,7 +33,7 @@ "{timeout} s request timeout, and a timed-out request is not retried. This is " "timeout notice {count} since the agent started. The failed request is in the " "agent log; check the provider status. The limit is enforced by the client and " - "by the provider\'s route in the proxy, so allowing longer answers means " + "by the provider's route in the proxy, so allowing longer answers means " "raising both." ) @@ -49,7 +53,7 @@ # Failures worth trying again right away. The SDK retries 409, 429 and any 5xx, # so keep that rule rather than a list that misses one (529 and 522 both reach -# here); the timeout statuses are excluded by _is_timeout_error above, so they are +# here). The timeout statuses are excluded by _is_timeout_error, so they are # reported instead of retried. TRANSIENT_STATUSES = (409, 429) # First attempt plus two retries, and only while the whole call stays inside the @@ -254,13 +258,15 @@ def _start_of_turn(self, content: str) -> None: """A prompt carrying a human message starts a fresh turn, which deserves its own answer even if the previous cycle already timed out. - The tail is read straight from the prompt rather than through - _split_system_user, which substitutes a placeholder when it is empty. The - loop fills the tail only on the cycle where the message is new, so any - tail here means a turn of its own. + Only a tagged message counts. The tail also carries the spamShield + reminder on every follow-up cycle when that option is on, and treating + that as a turn would bring back one notice per cycle. The tail is read + straight from the prompt rather than through _split_system_user, which + substitutes a placeholder when it is empty. """ _, delimiter, tail = content.partition(PROMPT_DELIMITER) - if (tail if delimiter else content).strip(): + tail = (tail if delimiter else content).lstrip(" ([\"'") + if tail.startswith(HUMAN_MESSAGE_MARKER): self._timeout_notice_sent = False def _answered(self) -> None: diff --git a/providers/openrouter.py b/providers/openrouter.py index 782e79e84..2b7bb40e6 100644 --- a/providers/openrouter.py +++ b/providers/openrouter.py @@ -41,10 +41,12 @@ def _create_client(self) -> Optional[openai.OpenAI]: api_key="proxy", base_url=base_url, max_retries=llm.CHAT_MAX_RETRIES, + timeout=llm.CHAT_REQUEST_TIMEOUT_SECONDS, ) if self._var_name in os.environ: return openai.OpenAI(api_key=os.environ.get(self._var_name), base_url=self._base_url, - max_retries=llm.CHAT_MAX_RETRIES) + max_retries=llm.CHAT_MAX_RETRIES, + timeout=llm.CHAT_REQUEST_TIMEOUT_SECONDS) return None From 4afcfa50cd600610622e986faf7cd72c704e3881 Mon Sep 17 00:00:00 2001 From: Leul Negash Date: Thu, 1 Oct 2026 14:35:55 +0300 Subject: [PATCH 10/11] Check the OpenRouter client carries the request timeout It overrides _create_client, so the limits it passes are worth a test of their own rather than being assumed from the base provider. --- Autotests/unit/test_llm_timeout_message.py | 42 ++++++++++++++++++++++ 1 file changed, 42 insertions(+) diff --git a/Autotests/unit/test_llm_timeout_message.py b/Autotests/unit/test_llm_timeout_message.py index e56bf08ae..7151d47cc 100644 --- a/Autotests/unit/test_llm_timeout_message.py +++ b/Autotests/unit/test_llm_timeout_message.py @@ -400,3 +400,45 @@ def test_the_notice_names_the_limit_and_both_places_that_hold_it(llm): notice = llm._llm_timeout_command() assert "600 s request timeout" in notice assert "raising both" in notice + + +# --- every chat client carries the same limits ------------------------------- + +@pytest.fixture(scope="module") +def openrouter(llm): + """OpenRouter overrides _create_client, so it needs checking on its own.""" + providers_stub = types.ModuleType("providers") + providers_stub.LLMProvider = object + providers_stub.registerLLMProvider = lambda name, provider: None + saved = {name: sys.modules.get(name) for name in ("providers", "lib_llm_ext", "openai", "config")} + sys.modules["providers"] = providers_stub + sys.modules["lib_llm_ext"] = llm + sys.modules["openai"] = llm.openai + config_stub = types.ModuleType("config") + config_stub.config_get_by_key = lambda key, default=None: default + sys.modules["config"] = config_stub + try: + yield _load("openrouter_under_test", os.path.join(_REPO_ROOT, "providers", "openrouter.py")) + finally: + for name, module in saved.items(): + if module is None: + sys.modules.pop(name, None) + else: + sys.modules[name] = module + + +def test_the_openrouter_client_carries_the_same_limits(openrouter, llm, monkeypatch): + captured = {} + + def recorder(**kwargs): + captured.update(kwargs) + return object() + + monkeypatch.setattr(llm.openai, "OpenAI", recorder) + monkeypatch.setattr(openrouter, "config_get_by_key", + lambda key, default=None: "http://localhost:8080" if key == "GATEWAY_URL" else default) + provider = openrouter.OpenRouterProviderImpl("OpenRouter", "OPENROUTER_API_KEY", "z-ai/glm-5.2", + "https://openrouter.ai/api/v1") + assert provider._create_client() is not None + assert captured["max_retries"] == llm.CHAT_MAX_RETRIES + assert captured["timeout"] == llm.CHAT_REQUEST_TIMEOUT_SECONDS From 7d72e81af6b70aa463667d5dbe149cec5f13ddfa Mon Sep 17 00:00:00 2001 From: Leul Negash Date: Thu, 1 Oct 2026 14:39:48 +0300 Subject: [PATCH 11/11] Check the duplicated limits against their source (#321) Two values were written in more than one place and could drift apart without anything noticing: the request timeout, which the proxy route has to match, and the HUMAN-MSG: tag, which the notice reset keys off. The route test now reads CHAT_REQUEST_TIMEOUT_SECONDS out of the provider source instead of repeating the number, and a test checks the marker against the tag the loop actually writes. The source is read rather than imported, since the provider SDK is not installed where this suite runs. --- Autotests/unit/test_llm_timeout_message.py | 11 +++++++++++ Autotests/unit/test_nginx_llm_timeouts.py | 17 ++++++++++++++++- 2 files changed, 27 insertions(+), 1 deletion(-) diff --git a/Autotests/unit/test_llm_timeout_message.py b/Autotests/unit/test_llm_timeout_message.py index 7151d47cc..52aab0388 100644 --- a/Autotests/unit/test_llm_timeout_message.py +++ b/Autotests/unit/test_llm_timeout_message.py @@ -442,3 +442,14 @@ def recorder(**kwargs): assert provider._create_client() is not None assert captured["max_retries"] == llm.CHAT_MAX_RETRIES assert captured["timeout"] == llm.CHAT_REQUEST_TIMEOUT_SECONDS + + + +# --- the tag the reset depends on must stay the tag the loop writes ---------- + +def test_the_marker_matches_the_tag_the_loop_writes(llm): + """_start_of_turn keys off this tag. If the loop ever renames it, the reset + would quietly stop working, so the two are checked against each other.""" + with open(os.path.join(_REPO_ROOT, "src", "loop.metta"), encoding="utf-8") as f: + loop = f.read() + assert llm.HUMAN_MESSAGE_MARKER in loop diff --git a/Autotests/unit/test_nginx_llm_timeouts.py b/Autotests/unit/test_nginx_llm_timeouts.py index 3425f2236..efc9a0611 100644 --- a/Autotests/unit/test_nginx_llm_timeouts.py +++ b/Autotests/unit/test_nginx_llm_timeouts.py @@ -17,7 +17,22 @@ _TEMPLATE = os.path.join(_REPO_ROOT, "proxy", "nginx.conf.template") LLM_ROUTES = ["anthropic", "asicloud", "openai", "asione", "openaiapi", "openrouter"] -CLIENT_TIMEOUT_SECONDS = 600 +_PROVIDER_SOURCE = os.path.join(_REPO_ROOT, "providers", "lib_llm_ext.py") + + +def _client_timeout_seconds(): + """The timeout the providers give their client, read from the source rather + than repeated here: the route has to wait at least as long, and the two must + not drift apart. The module itself is not imported, since the provider SDK is + not installed where this suite runs. + """ + with open(_PROVIDER_SOURCE, encoding="utf-8") as f: + match = re.search(r"^CHAT_REQUEST_TIMEOUT_SECONDS\s*=\s*(\d+)", f.read(), re.MULTILINE) + assert match, "providers/lib_llm_ext.py no longer defines CHAT_REQUEST_TIMEOUT_SECONDS" + return int(match.group(1)) + + +CLIENT_TIMEOUT_SECONDS = _client_timeout_seconds() _UNITS = {"s": 1, "m": 60, "h": 3600}