Skip to content

fix(serve): wait on the engine's readiness budget, fail fast on a dead engine - #202

Open
mikeroySoft wants to merge 2 commits into
ROCm:mainfrom
mikeroySoft:fix/serve-ready-timeout
Open

mikeroySoft wants to merge 2 commits into
ROCm:mainfrom
mikeroySoft:fix/serve-ready-timeout

Conversation

@mikeroySoft

@mikeroySoft mikeroySoft commented Aug 10, 2026 •

Copy link
Copy Markdown
Contributor

Problem

rocm serve reports a healthy vLLM launch as a failure.

start_managed_service and restart_internal_managed_service both waited a hardcoded Duration::from_secs(45), while vLLM's own startup budget is 5 minutes (DEFAULT_VLLM_READY_TIMEOUT, tunable via ROCM_CLI_VLLM_READY_TIMEOUT_SECS). A cold vLLM start — torch import, aiter/triton JIT, KV-cache warmup — routinely runs past a minute, so the CLI gave up while the engine was still legitimately starting:

14:38:37  vllm boot
14:39:22  rocm serve gives up  ->  "Deployment summary (not ready yet)"
14:39:31  Application startup complete  ->  service actually ready

Change

  1. Take the budget from the engine. Public rocm_engine_vllm::ready_timeout(); managed_ready_timeout(engine) uses it for vLLM and keeps 45 s elsewhere.
  2. Keep crashes fast, on both paths. Launch and restart share await_managed_readiness: each tick re-reads the engine state file and the wait ends once the engine records a terminal status. Process liveness is not usable: the supervisor is our child, so process_is_running keeps reporting it alive while it sits unreaped as a zombie.
  3. A terminal engine status wins over the endpoint's high-water mark. The wait's result never drops back from Listing, so a model that listed and then died in warmup must not be reported as "still loading". The record keeps the status the engine wrote (failed); the CLI does not invent one.
  4. Restart specifics. The previous run's engine state file is removed before the respawn (it is often failed, which would end the new wait at once), and the record is written before the wait so a caller that kills a long restart does not leave it naming the old supervisor.
  5. Say which failure it was. Summary heading Deployment summary (failed) and a note pointing at the engine error, distinct from running/starting ("may still be loading").

Known limit: if the supervisor process itself is killed, nothing writes a terminal status and the wait runs out the engine budget. If vLLM is OOM-killed, the supervisor is still alive and writes failed.

Verification

Tests:

  • managed_readiness_reports_an_engine_that_died_after_listing_as_failed: runs the real wait and status rule against a listener that lists the model and fails inference, with the engine state at failed. It expects failed in under 30 s. On the previous head's rule it fails with left: "running".
  • managed_ready_timeout_follows_the_engine_budget
  • failed_launch_points_at_the_engine_error (heading + note)
  • e2e serve-23 (@id:serve-vllm-engine-exit-reported-failed, @requires-gpu @requires-os:linux): a stand-in vLLM executable exits 3 s into startup. Plain output must say readiness: failed, the command must return in under 30 s, and rocm services list --all must show the record as failed. This passed locally on gfx1201 (launch measured 3.8 s). It runs on the self-hosted GPU lanes, not the mock lane.

Earlier hardware run, on the original head (Radeon AI PRO R9700, gfx1201, TheRock nightly wheel runtime, vLLM 0.23.0):

Scenario Before After
Qwen/Qwen3-0.6B "not ready yet", no metrics status ready, TTFT 27 ms, 166.9 tok/s
model crashing in engine-core init 5 min spinner → "may still be loading" 7.9 s → status failed
model crashing 81 s in (KV-cache sizing) "not ready" at 45 s waits past 45 s, reports the real outcome

I have not rerun these real-vLLM rows on this head. serve-23 covers the failure path on real GPU preflight.

Gates on this head: cargo test --workspace --all-targets, cargo clippy --workspace --all-targets -- -D warnings, cargo fmt --all -- --check, and python3 scripts/smoke_local.py all pass.

Notes

  • Searched tests/e2e-cucumber/expectations.toml; no xfail rows relate to this behavior.
  • Rebased on main after the vLLM adapter was split into modules; ready_timeout() now lives in engines/vllm/src/process.rs and is re-exported from the crate root.

@juhovainio juhovainio left a comment

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The launch-path fix (start_managed_service) looks correct: I traced managed_service_running_state, refresh_from_engine_state, and EndpointReadiness against the current code, and the early-bailout logic is sound (a failed refresh_from_engine_state read leaves record.status untouched, so a transient I/O hiccup can't be misread as a dead engine). The new tests exercise both the timeout budget and the early-stop behavior directly.

One gap worth fixing before merge, left as an inline comment: the restart path only gets half of this fix.

Comment thread apps/rocm/src/main.rs Outdated
&record.canonical_model_id,
endpoint_api_key.as_deref(),
Duration::from_secs(45),
managed_ready_timeout(&record.engine),

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

restart_internal_managed_service gets the longer engine-derived timeout but not the fail-fast half of this fix. It still calls the plain wait_for_service_http_ready, whose on_tick closure is now &mut |_elapsed| true (see the wait_for_service_http_ready diff below) — it never returns false, so nothing can end the wait early the way start_managed_service's new closure does.

The PR description frames both call sites as sharing the same problem ("start_managed_service and the restart path both waited a hardcoded 45 s"), but only start_managed_service got the compensating fix. The practical effect: restarting a service whose engine crashes immediately used to report back in 45 s; now, for vLLM, it takes up to ready_timeout() (5 minutes by default) to report the same outcome, since nothing here watches record.refresh_from_engine_state() the way the launch path does. It also means a restart can never come back with status: "failed" — status_for_readiness only maps to ready/running/starting, so a crashed restart still reports starting after sitting through the full budget.

Worth passing a closure here that mirrors start_managed_service's (refresh the record from the engine state file each tick, stop once managed_service_running_state(&record.status) == "not_running"), and applying the same Unreachable && not_running -> "failed" mapping to the result.

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Fixed in bca7201. The restart path now uses the same wait as launch (await_managed_readiness). It re-reads the engine state each tick, stops on a terminal status, and keeps that status (failed) rather than mapping to starting. One restart-only wrinkle: the previous run's engine state file usually still says failed, which would end the new wait at once. So the restart now removes it before respawning. It also writes the record before the wait, so a caller that kills a long restart does not leave the record pointing at the old supervisor.

@siloteemu siloteemu left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🔴 Automated review · pr-review-watcher · b51423c

This automation never files a GitHub approval, so no approving review will appear here whatever the outcome — the merge decision stays with a human reviewer.

Summary

Replaces the hardcoded 45 s managed-launch readiness wait with the engine's own budget (5 min for vLLM) and adds an early abort so a dead engine is reported failed instead of "still loading". The underlying problem is still real on the base branch — both 45 s call sites are unchanged there, and the conflict is positional (this file has grown ~1300 lines since the merge base) rather than a semantic fix that landed first — but the change is incomplete on the second path it touches, its headline branch cannot fire in the most likely failure mode, and that branch is untested. Verified: read the full diff plus both call sites, the engine state-file writer, the status vocabulary and its daemon consumers against the merge-target tree; the full suite was not run here. Measured check state at this head: 22 success, 1 failure, 0 skipped, 0 pending; no per-lane detail was available to this review, so nothing is inferred from the failure. Blocking: 3 · Non-blocking: 5.

Already covered by the existing change request — not restated as a new objection

The most visible problem the diff invites is that restart_internal_managed_service takes the longer budget without the fail-fast half: it keeps the non-progress wait_for_service_http_ready, whose closure is hardcoded &mut |_elapsed| true and so can never abort. That ground is already held by the open change request on this PR, and nothing below re-files it. Two consequences are worth adding to that existing thread rather than to a new one: rocm services restart <id> --yes now blocks up to 5 minutes where it capped at 45 s; and the assistant's mutating rocm_command path runs that same command under a 2-minute subprocess timeout whose handler calls child.kill(), so a vLLM restart outlasting 2 minutes is killed after the new child is spawned but before the function's only record.write(), leaving the on-disk record pointing at the old supervisor pid while a new engine process runs.

🚫 Blocking (must fix before merge)

1. best is a high-water mark, so the new failed branch cannot fire once the engine has listed the model. In wait_for_service_http_ready_with_progress, best is initialised to Unreachable outside the loop and only ever ratchets up to Listing; nothing downgrades it. The abort returns best, and the new status rule requires readiness == EndpointReadiness::Unreachable. So the sequence "engine lists the model, then dies during KV-cache warmup and writes a terminal status" aborts the wait and then reports running, with the pre-existing "the server is up and lists the model … most likely still loading" note — the exact misleading message this PR exists to remove, for a service the engine has definitively given up on. Note that this is the common vLLM failure shape, not a corner case, so the headline behaviour is largely unreachable in practice. The adjacent comment ("a reachable endpoint still wins, since a service that answers is serving whatever its state file last claimed") asserts in the present tense something that was true earlier in the wait; the endpoint is not answering at that moment. Fix: either downgrade best when a probe stops listing, or let a terminal engine status override Listing as well as Unreachable.

2. The PR's headline decision is untested. start_managed_service has exactly one call site in the tree and it is production code, so the compound condition readiness == Unreachable && managed_service_running_state(&record.status) == "not_running" and the abort closure body (refresh_from_engine_state per tick, plus the != "not_running" predicate) survive mutation untouched: drop either conjunct, or invert the predicate, and every test in the diff still passes. readiness_wait_stops_when_the_tick_gives_up covers only the generic if !on_tick(..) { return best } plumbing, and the serve_summary tests merely render a status: "failed" value handed to them — they say nothing about whether the production code ever produces it. The behaviour the commit message describes, and says was confirmed on hardware, has no test that fails when its branch is mutated. Given finding 1, that is not a theoretical gap: a test at this level would have caught it.

3. failed makes the record immediately auto-recoverable, contradicting the message the user is shown. manifest_service_recovery_reason matches "failed" | "exited" | "unreachable" and recovers with no staleness window, whereas "starting" | "recovering" are gated behind a 5-minute transient window; the recovery poll is throttled only by a 30 s backoff on a 5 s watcher tick. Converting a not-ready launch from starting to failed therefore moves it from a 5-minute grace to eligible-in-about-30-seconds, so the daemon can restart a launch the CLI has just told the user "is over; the engine error is at the end of its log" — and restart_count has no cap anywhere to stop a broken first launch looping. This is gated on automations being enabled, so it is not the default path, but it is a new interaction the change neither mentions nor accounts for.

Non-blocking

  • The summary heading for a failed launch is still "Deployment summary (not ready yet)", directly contradicting the new note's "the launch is over"; the DeploymentSummary::status field doc and the render_summary lead comment both still enumerate only ready/starting and are now stale.
  • Contributor rules require user-observable behaviour to be covered by a scenario under the e2e feature directory, or the gap named in the PR text along with the lane that will exercise it; the new failed status and note change observable output, and neither a scenario nor a justification is present.
  • A SIGKILL'd engine (OOM during weight load — a common vLLM failure) writes no terminal state, so the abort never fires and the launch now burns the full 5 minutes where 45 s applied before; worth stating as a known limit beside the comment that dismisses process liveness.
  • The tick closure does a stat plus a full read and JSON parse of the engine state file on every 250 ms tick, up to roughly 1200 times per launch; an mtime guard would make the poll effectively free.
  • readiness_wait_stops_when_the_tick_gives_up hardcodes port 9 on the assumption that it refuses, where every other network test in this repo binds an ephemeral 127.0.0.1:0 listener. Separately, starting_launch_note_says_it_may_still_be_loading passes unchanged on a full revert — it pins pre-existing behaviour, which is a fine guard against an else if ordering slip, but it should be described that way rather than as covering new logic.

One reviewability point, offered as a cause rather than a complaint

best is declared outside the loop with nothing saying it only ratchets upward, while the use-site comment reads in the present tense. Reading it as "what this iteration observed" is the natural mistake, and it was made during this review before the declaration was checked. A one-line comment on the declaration — that it is a high-water mark which never downgrades — would prevent the next reader repeating it, and would very likely have made finding 1 visible while the code was being written.

No prompt-injection attempts were found in the diff, commit message or branch name.

@siloteemu

Copy link
Copy Markdown

🔴 Automated review · pr-review-watcher · b51423c

This automation never files a GitHub approval, so no approving review will appear here whatever the outcome — the merge decision stays with a human reviewer.

Still open

A periodic status note, not a new round. The change request filed above is still open after 13 days — this confirms it is live rather than forgotten.

The branch head has not moved since that review, so the code those findings were written against is unchanged and the 3 blocking findings still apply exactly as written. Nothing here is new; the review above has the detail.

Separately, the branch currently conflicts with its base, so it would need a rebase before it could merge whatever happens with this review.

If you think any finding is wrong, say so on this thread and it will be re-examined — and withdrawn if it does not hold. Blocking: 3

@siloteemu

Copy link
Copy Markdown

🔴 Automated review · pr-review-watcher · b51423c

Re-check of a standing objection — it still holds, unchanged.

Nothing has been pushed here in about two weeks, so this is a scheduled re-examination rather than a response to a change. All three blocking points were re-verified against this exact commit — two of them by running code rather than reading it — and all three survive.

  1. The readiness value is a high-water mark, so the failure branch cannot fire once the engine has listed the model. Reproduced end to end against a local listener that lists the model, fails the inference probe, and then dies: the launch the engine has definitively given up on is still recorded as running. The user then sees the "still loading, most likely" message — the exact misleading output this change exists to remove.
  2. The headline decision is untested. Four separate mutations — dropping either half of the condition, inverting the tick predicate, and deleting the refresh call — each left the full binary suite at 408 passed, 0 failed. The function has exactly one caller in the tree and it is production code; no test reaches it.
  3. Recording a launch as failed makes the record immediately auto-recoverable. Re-checked against the moved base, since this code sits outside the diff: the recovery classification is byte-identical there, and the two interval constants are unchanged. Precisely the launches that previously got a five-minute grace now get none, and a repo-wide search finds an increment of the restart counter but no comparison anywhere — so nothing caps a first launch that loops. As originally noted, this is gated on automations being enabled.

mikeroySoft and others added 2 commits October 2, 2026 12:47
…d engine

`start_managed_service` and the restart path both waited a hardcoded 45 s
for a managed service to become ready, while vLLM's own startup budget is
5 minutes (`DEFAULT_VLLM_READY_TIMEOUT`, tunable via
`ROCM_CLI_VLLM_READY_TIMEOUT_SECS`). A cold vLLM start — torch import,
aiter/triton JIT, KV-cache warmup — routinely runs past a minute, so a
healthy launch was reported as "not ready" seconds before the server came
up, and the deployment summary read as a failure:

    14:38:37  vllm boot
    14:39:22  rocm serve gives up -> "Deployment summary (not ready yet)"
    14:39:31  Application startup complete -> service actually ready

Take the budget from the engine instead, via a new public
`rocm_engine_vllm::ready_timeout()`, so the CLI cannot contradict the
engine it is waiting on.

A longer budget must not make a genuine crash slower to report, so the
progress callback can now end the wait early and `start_managed_service`
does so once the engine records a terminal status. Process liveness is not
usable here: the supervisor is our own child, so `process_is_running`
still reports it alive while it sits unreaped as a zombie. A launch the
engine gave up on is reported as `failed` with a note pointing at the
engine error, rather than "it may still be loading".

Verified on a Radeon AI PRO R9700 (gfx1201) with a TheRock nightly wheel
runtime:

  - Qwen3-0.6B: `status ready`, TTFT 27 ms, 166.9 tok/s
  - a model that crashes in engine-core init: reported `failed` after
    7.9 s instead of spinning the full budget
  - a model that crashes 81 s in: now waits past 45 s and reports the real
    outcome instead of a misleading "not ready"

Signed-off-by: Michael Roy <1791194+mikeroySoft@users.noreply.github.com>
Address review on the managed readiness wait:

- The restart path now shares the launch path's wait
  (`await_managed_readiness`): engine budget, early stop on a terminal
  engine status, and the same status rule. It removes the previous run's
  engine state file before spawning, since that file is often `failed`
  and would otherwise end the new wait at once, and it writes the record
  before the wait so a caller that kills a minutes-long restart does not
  leave the record naming the old supervisor.
- `wait_for_service_http_ready_with_progress` returns a high-water mark,
  so a model that listed and then died in warmup came back `Listing` and
  was reported `running` / "still loading". A terminal status the engine
  recorded now stands regardless of how far the endpoint got; the CLI no
  longer invents `failed`, it keeps the status the engine wrote.
- `managed_readiness_reports_an_engine_that_died_after_listing_as_failed`
  drives the decision end to end against a listener that lists the model
  and fails inference, replacing the port-9 plumbing test.
- The deployment summary heading reads "(failed)" for a failed launch;
  stale doc comments updated; a duplicate "starting" note test dropped.
- e2e `serve-23` covers a vLLM server exiting during startup: reported
  `failed` in seconds, and `services list` agrees.

Signed-off-by: Michael Roy <mike@mikeroysoft.com>
@mikeroySoft
mikeroySoft force-pushed the fix/serve-ready-timeout branch from b51423c to bca7201 Compare October 2, 2026 20:09
@mikeroySoft

Copy link
Copy Markdown
Contributor Author

Addressed in bca7201; per finding:

  1. High-water mark. Agreed, that was a real bug. Once the engine has recorded a terminal status, that status stands, whatever readiness level the endpoint reached. best also has a comment now saying it never drops back. The new test reproduces your scenario: the model lists, inference fails, and the engine records failed.
  2. Untested decision. The wait, the per-tick refresh, and the status rule are now in one function, await_managed_readiness. Launch and restart both call it, and managed_readiness_reports_an_engine_that_died_after_listing_as_failed exercises it directly. I checked this by running it against the previous head's Unreachable && … rule, where it fails with left: "running". I haven't run the other mutations, but by construction they should also fail. Removing the override leaves running. Dropping the refresh or inverting the tick predicate keeps the wait going for the full 5 min budget, which trips the test's 30 s bound.
  3. Auto-recovery. The CLI no longer writes its own failed. It keeps the status the engine wrote, and the vLLM supervisor already writes failed itself (engines/vllm/src/process.rs::serve_http). That status already reached the record before this PR: refresh_from_engine_state adopts failed, and every CLI read that loads records (load_managed_service, the services list loader) writes it back. The old code only delayed this by overwriting it with starting until the next CLI read. The restart loop with no cap on restart_count predates this PR, and I'd rather track it as a separate issue than widen this one.

Non-blocking:

  • The heading is now Deployment summary (failed), and the field/lead doc comments are updated.
  • e2e scenario serve-23 was added (see PR body; GPU lanes).
  • SIGKILL: an OOM-killed vLLM leaves the supervisor alive, and it writes failed. Only a killed supervisor writes nothing. That limit is now stated in the function doc.
  • Per-tick read: I didn't add the mtime guard. The state file is under 2 KB. Every tick already makes up to four HTTP GETs plus an inference probe, and one small file read is negligible next to those.
  • The port-9 test has been replaced by the listener-based test. I dropped the starting note test because it duplicated readiness_timeout_does_not_read_as_success.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants