test(e2e): bound the post-/model/new servable wait at 40s - #35020
Conversation
_await_model_servable used poll_timeout (120s), the spend/log read-back budget. A stuck model reload therefore stalled every suite that creates a deployment for two minutes before failing Give create_model a fixed harness middle ground: model_servable_timeout=40s, polled every 2s, with each /v1/models call capped at 5s and clamped to the remaining deadline so one slow GET cannot overrun the wait. Happy path still returns on the first listing. Not derived from proxy general_settings or env Transport.get accepts an optional per-call timeout for that clamp. Unit tests cover the deadline arithmetic and clamp without a live proxy (cherry picked from commit c082a0e)
create_model returned after the first /v1/models hit that listed the model, so chat could still land on a cold gateway worker (numWorkers>1 / peer pod) and 400 Invalid model name. Require continuous listing for the product default add_deployment interval (30s) after first sight so every worker has synced from the DB; first listing still bounded at 40s (cherry picked from commit 7d1ee2f)
Keep the create_model DB-sync wait in the harness; the pure-function unit file is not needed for this PR (cherry picked from commit 8920465)
When less than one full poll interval remained in the first-listing budget, the pre-sleep check returned NotServable without another /v1/models call. Sleep only min(interval, time left) so a model that becomes listable in the last seconds of the timeout still gets a clamped final poll (cherry picked from commit 8439195)
A poll may start with remaining budget and still return after started+timeout if the transport overruns its clamp. Recheck the first-listing deadline after the response so a late listing does not open the continuous DB-sync phase (cherry picked from commit 7ff2bcb)
![greptile-apps[bot]](https://avatars.githubusercontent.com/in/867647?s=60&v=4){kind=small}
| ) | ||
| t = now() | ||
| if not listed: | ||
| first_seen_at = None |
There was a problem hiding this comment.
When a model is listed within 40 seconds but a later poll lands on a worker that has not reloaded, clearing first_seen_at restores the already-expired first-listing deadline. The next iteration immediately returns NotServable, causing create_model to fail instead of restarting the continuous synchronization window.
| f"model {model_name!r} was created but never became servable on the data " | ||
| f"plane within {timeout}s of first listing (plus {db_sync_seconds}s continuous " | ||
| f"DB sync) after /model/new (control/data-plane propagation or " | ||
| f"STORE_MODEL_IN_DB reload issue){last_error}" |
There was a problem hiding this comment.
The message describes timeout as running “of first listing,” although this value is the budget before first listing. This misidentifies the failed phase in E2E output, especially when the model was never listed or failed during the continuous synchronization window.
Note: If this suggestion doesn't match your team's coding style, reply to this and let me know. I'll remember it for next time!
Greptile SummaryThis PR bounds the E2E model-readiness wait and adds per-request timeout overrides.
Confidence Score: 3/5This PR should not merge until transient listing misses restart the continuous synchronization window without reviving an expired first-listing deadline. A realistic multi-worker response sequence can list the model once and later omit it; after 40 seconds, that miss makes the poller fail immediately even though the model can recover and satisfy a new continuous-listing window. The resulting diagnostic also labels the timeout phase incorrectly. Files Needing Attention: tests/e2e/proxy_client.py
|
| Filename | Overview |
|---|---|
| tests/e2e/proxy_client.py | Adds bounded two-phase model readiness polling, but a transient miss after the initial deadline prematurely terminates synchronization and the failure message reverses the timeout phase. |
| tests/e2e/transport.py | Consistently adds and forwards an optional per-call GET timeout across the protocol and concrete transports. |
Reviews (1): Last reviewed commit: "fix(e2e): reject first listing that retu..." | Re-trigger Greptile
Codecov Report✅ All modified and coverable lines are covered by tests. 📢 Thoughts on this report? Let us know! |
4 participants
TLDR
Problem this solves:
/v1/modelshit can land on an already-hot worker/chatthen hits a cold worker and 400sHow it solves it:
/v1/modelslisting at 40s instead of 120smainofflitellm_hotfix_*, per the main-branch guardRelevant issues
Hotfix promotion of #35012 to
main. Same change, cherry-picked verbatim offmain; #35012 still carries it intolitellm_internal_stagingLinear ticket
Pre-Submission checklist
Please complete all items before asking a LiteLLM maintainer to review your PR
@greptileaito re-request a review after pushing changes)The "meaningful tests" box is unchecked deliberately. #35012's third commit (
89204651) removedtests/e2e/test_proxy_client_model_servable.py, so the final diff ships no unit coverage forawait_servable. This hotfix is a verbatim promotion of that diff and does not add the file back; the coverage question belongs on #35012, which owns the changeDelays in PR merge?
If you're seeing a delay in your PR being merged, ping the LiteLLM Team on Slack (#pr-review).
Screenshots / Proof of Fix
Carried over from #35012, captured by its author at commit
c082a0e(the first commit of the series) against a live proxy (python litellm/proxy/proxy_cli.py --config litellm/proxy/dev_config.yaml), timing the wait against a model name the data plane never servesBefore, on the old budget (
poll_timeout=120s,poll_interval=5s), atc082a0e's parent:After, at
c082a0e(model_servable_timeout=40s,model_servable_interval=2s,model_servable_request_timeout=5s):Two caveats a reviewer should carry into the runbook below rather than take from the numbers above. That capture predates
5aa66ea(7d1ee2fon #35012), which added the 30s continuous-listing window, so the happy-path timing quoted on #35012 (2.31s, one poll) no longer describes this diff: a successfulcreate_modelnow holds formodel_servable_db_sync_secondsbefore returning. And the failure-path capture is from the same earlier commit, so the message text it shows differs from the one this diff emits, which names both the 40s first-listing budget and the 30s sync windowType
✅ Test
Changes
_await_model_servablepolled/v1/modelstopoll_timeout, which exists for eventually-consistent read-backs like spend rows. Model readiness is a different wait: after/model/newthe data plane must list the model before callers can invoke it. Sharing the spend read-back budget meant a broken reload was absorbed as a two-minute stall per model rather than reportedFixed harness constants:
model_servable_timeout(40s) for first listing,model_servable_db_sync_seconds(30s, the product defaultproxy_config_reload_interval_seconds) of continuous listing after first sight,model_servable_interval(2s), andmodel_servable_request_timeout(5s, clamped to the remaining budget). None of these are read from live proxy config. A single/v1/modelssuccess is not enough on a multi-worker gateway: only the writer reloads immediately, and peers sync on theadd_deploymentjobThe poll loop is extracted as
await_servable, a pure function over an injected clock and sleep plus alist_modelscallback taking the per-poll request timeout, returning aServable | NotServableunion.Transport.getgains an optional per-calltimeoutso the poller can pass a deadline shorter than the transport-wide oneScope note: this changes only how long the harness waits before reporting. It does not make a model propagate faster, and it does not fix any test that fails after the wait succeeds. Read it as latency-of-failure, not as a fix for model-propagation failures
Why this is on
mainand not only on staging:.github/workflows/guard-main-branch.ymlaccepts PRs tomainfromlitellm_internal_stagingor alitellm_hotfix_*branch, so this branch is cut frommainand carries #35012's five commits withcherry-pick -x.tests/e2e/proxy_client.pyandtests/e2e/transport.pywere identical onmainandlitellm_internal_stagingat9ead580, so the picks applied with no conflict and both blobs match #35012's head exactlyQA runbook
ProxyClient._await_model_servable- a model the data plane never lists fails in ~40s instead of ~120s, with the diagnostic preservedpython litellm/proxy/proxy_cli.py --config litellm/proxy/dev_config.yaml(needsSTORE_MODEL_IN_DB=Trueand a reachableDATABASE_URL)/model/newwith the master key and a real deployment, then immediately POST/chat/completionsagainst that model name; expect 200, proving the happy path still resolvescreate_model; expect roughly 30s, not the sub-second first-poll return, because the DB-sync window now holds before returningProxyClient._await_model_servable("model-that-will-never-be-listed")and time it; expect an AssertionError in ~40s naming the model, the 40.0s first-listing budget, and the 30.0s sync windowgeneral_settings) and are not hand-wavey or potentially flakyTransport.get(..., timeout=...)- the new per-call override, so one slow/v1/modelscannot outlast the remaining budget/v1/models, or drop the first-listing budget below 5s, and confirm total wall time still respects the budget rather than the transport-widerequest_timeoutawait_servableto pass the full 5s cap while ignoring the remaining budget should make the wait overrun its deadlineFinal Attestation
Left unchecked for the same reason as the tests box: the diff this promotes ships no unit coverage for
await_servable, so there is nothing here that would fail if the deadline arithmetic or the request-timeout clamp regressed