[OMEGA-423] Fix nginx proxy cutting off slow LLM responses (#321) - #351
Leul-Negash wants to merge 9 commits into
Conversation
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.
timur-ashkenov
left a comment
timur-ashkenov
left a comment
There was a problem hiding this comment.
@Leul-Negash Could we handle the final provider timeout explicitly?
After the configured timeout and exhausted retries, the agent should stop waiting and send the user a clear status message, such as: “LLM request timed out. Please try again later.” Returning an empty LLM result leaves the task silently abandoned.
paul-v-snet
changed the title
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.
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.
|
@timur-ashkenov Done in 4f9f90e. A timed-out request now returns a Verified in the image with the provider pointed at an endpoint answering 504 immediately: after the retries the agent runs Added One check: by "stop waiting" did you mean the total wait as well? Right now the route timeout plus two client retries can take up to ~30 minutes before the message goes out. I can shorten the client timeout or reduce the retries if you want that capped. |
@Leul-Negash , Yes, I meant the total wait should be bounded as well. Waiting up to ~30 minutes before notifying the user would still reproduce the poor user experience from the issue. I suggest keeping the 600-second timeout for one legitimately slow response, but avoiding additional retries after a timeout/504. The agent should send the timeout status once that first request reaches its limit. |
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.
|
@timur-ashkenov Understood, bounded in ed1ab86. The chat clients are now built with Verified against an endpoint answering 504 immediately: no retries logged, one request per cycle, and the message reaches the channel a second after the request fails. Two more tests check both the proxy and the direct client are built with a single attempt. |
@Leul-Negash Could we confirm that disabling retries globally is intentional?
I agree that the total wait must be bounded, but this changes retry behavior across all providers. Could we either document and explicitly accept this trade-off, or use a retry policy that preserves limited retries for non-timeout transient failures? |
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.
|
@timur-ashkenov Fair point, that was too broad. Fixed in 7bd71f8. Retries are back for transient failures and skipped only for timeouts. The SDK cannot split it that way: status retries go through Checked in the image: the endpoint answering 504 gives one attempt per cycle and the status message on the channel, the one answering 503 gives three attempts with the backoff and no status message. Tests cover the classification, the attempt limit, the budget, and that a timeout is attempted once. CI is green. |
|
Tested: images built from this PR at 7bd71f8 and from main 6657798, each started by scripts/omega with What I checked
529 and Retry-After now end in silenceA 529 followed by a normal answer: main retries and replies in 1.5 s. With the PR, the stub gets one request, the agent logs A 429 with Both come from TRANSIENT_STATUSES, which stops at 503, and from the fixed 0.5 s and 1 s sleeps, which do not read Retry-After. The comment above the list says it holds the statuses the SDK retries by default, but on main the SDK also retries 529 and 522. A second timeout in a row is droppedThe timeout message is the same text every time, and send drops a message equal to the last one it sent. Right after the 700 s case, the next message hit a 504. At 05:14:17, the agent logged A smaller issue: the message says "the retries were exhausted", while a timeout gets one request. Verdict: FAIL |
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.
|
@TossSky Thanks, all four are fixed in 1004c10. 529 and 522: the status list was mine and it stopped at 503. Classification now follows the same rule as the SDK, 409, 429 and any 5xx, with 408, 504 and 524 left to the timeout path so they are reported instead of retried. Retry-After: the sleeps were fixed at 0.5s and 1s. Second timeout in a row: right, the text was identical and
Rechecked in the image with a stub that scripts the answers: 529 then a normal answer is retried after 0.5s and the reply arrives; 429 with One thing worth flagging: with a gateway that answers 504 instantly the user gets a notice every cycle. In production a 504 means the proxy already waited 600s, so they are spaced out, and I left it uncapped rather than adding suppression back. Happy to add a minimum interval if you would rather have one. |
| sent, so without it a second timeout in a row would leave that turn silent, | ||
| which is the symptom this whole change is about. | ||
| """ | ||
| message = LLM_TIMEOUT_MESSAGE.format(time=time.strftime("%H:%M:%S")) |
There was a problem hiding this comment.
@Leul-Negash The timestamp is only precise to one second, so two immediate timeout/504 cycles within the same second still produce identical (send ...) commands. Since send drops a message equal to the previous one, the second user message can again be silently lost. Please use a per-notification unique value (for example, a monotonic nonce or sub-second timestamp).
There was a problem hiding this comment.
@timur-ashkenov Good catch, fixed in 76ef473.
The notice now carries the time to the millisecond, and the admin line carries a count that rises with every notice, so two of them differ even when the clock does not move between them. A test freezes the clock and checks that two notices in a row are still different; while checking by hand I hit the case for real, two notices inside the same millisecond, and they differ by the count.
Unit tests are at 39 in test_llm_timeout_message.py and 127 in the unit tier. CI is green.
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.
This branch has not been deployed
3 participants
Description
Fixes #321.
In the Docker image every LLM request goes through the nginx proxy. The LLM routes use the global 120s
proxy_read_timeout/proxy_send_timeout, so a response that takes longer comes back as 504. The OpenAI client retries twice, gets 504 again, andAIProvider.chatreturns"", so the agent never replies. That matches the two 504s two minutes apart in the #321 logs.This sets 600s on the six LLM routes (
anthropic,asicloud,openai,asione,openaiapi,openrouter), which is how long the OpenAI client waits and the same override the OpenClaw route got in 27979ed. Channel routes keep the 120s default.It also adds
Autotests/unit/test_nginx_llm_timeouts.py, which fails if an LLM route waits less than 600s, and registers it inrun_mandatory.How Has This Been Tested?
Ran the image with the
OpenAIAPIprovider pointed at a local OpenAI-compatible endpoint that answers after 150s, on thetestchannel:main: nginx loggedupstream timed outand returned 504 at 120s, three times, thenException while communicating with LLM: 504 Gateway Time-outand nothing was sent.The new test fails on
main(12 failed) and passes here (12 passed).Autotests/unit73 passed,tests/65 passed, andnginx -tpasses on the rendered template inside the image.I couldn't test against ASICloud directly. @olegryabchikov-dot, could you retest the Dune prompt on this branch when you have a chance?
Checklist