Skip to content

fix(serve): keep startup progress until the server is ready or stalled - #817

Open
rominf wants to merge 1 commit into
mainfrom
fix/serve-startup-progress
Open

rominf wants to merge 1 commit into
mainfrom
fix/serve-startup-progress

Conversation

@rominf

@rominf rominf commented Oct 30, 2026

Copy link
Copy Markdown
Collaborator

Summary

  • Interactive rocm serve stopped after 45 seconds with a static not-ready summary while a download or load was still moving. The status line now follows the engine log until the endpoint can serve or that progress stalls. A failure names rocm logs --service <service-id> and rocm services stop <service-id> --yes. Piped output keeps the 45-second status budget.
  • There is no default-lane Gherkin scenario. The status line is a TTY spinner, the harness does not allocate a PTY, and a live engine would be @requires-gpu. The state matrix is decide_serve_startup and wait_for_serve_startup in apps/rocm/src/serve_progress.rs, noted in tests/e2e-cucumber/features/model_serving.feature.

Test plan

  • cargo test -p rocm --bin rocm serve_progress passed locally (25 tests). recovery_leaves_a_live_startup_alone_and_still_restarts_a_dead_one passed.
  • CI unit tests cover serve_progress and that recovery test. No default-lane scenario. A live serve remains @requires-gpu and was not run here.
  • Full workspace cargo test and clippy were not run. This worktree was not rebuilt with cargo build --workspace --all-targets. A later build of the origin/main checkout does not prove this branch compiles.

Interactive rocm serve stopped after 45 seconds with a static not-ready summary while a download or load was still moving. The status line now follows the engine log until the endpoint can serve or that progress stalls, and a failure names the logs and stop commands.

Signed-off-by: Roman Inflianskas <roman.inflianskas@amd.com>
@rominf
rominf requested a review from a team as a code owner October 30, 2026 16:29
@rominf
rominf requested a review from volen-silo October 30, 2026 16:29
notes: Vec::new(),
};
let rendered = crate::serve_summary::render_summary(&summary);
assert!(rendered.contains(&hint), "{rendered}");

@nowycondro nowycondro 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.

🤖 Automated review (Claude Code) · 0557c5d

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.

Review — needs work

Full review of the whole change. No ticket named in the PR description.

Blocking

  • Commit is not GitHub-"Verified"; the commit-signatures/verify-commits gate fails — head commit 0557c5db. This repo's own AGENTS.md §2 states signing/sign-off are enforced (not advisory): "a blocking CI gate (commit-signatures) re-checks every PR with GitHub 'Verified' status." The job output names the fix directly: sign off (git commit -s --amend / git rebase --signoff <base>) or enable commit signing and re-sign, then re-push.
    Confidence 100 · mechanical · Fix: sign and/or sign off the commit per the job's own remediation text, then force-push.

  • clippy fails the build: clippy::missing_const_for_fn on recorded_status_after_stop, apps/rocm/src/serve_progress.rs:479, under this repo's -D warnings gate — the job output shows this is not advisory, it aborts compilation ("could not compile rocm (bin "rocm") due to 1 previous error").
    Confidence 100 · mechanical · Fix: see the next finding — fixing that dead branch naturally resolves this too (const fn becomes valid once the unreachable arm is simplified).

  • New CodeQL alert rust/cleartext-logging (security_severity: high), apps/rocm/src/serve_progress.rs:1068 — flags assert!(rendered.contains(&hint), "{rendered}") in the new test failure_message_names_the_same_logs_command_as_the_summary as writing api_key to a log sink. In this specific call api_key: None, so no real secret is exposed today, but the scanner is reacting to the general shape: formatting a whole DeploymentSummary (which legitimately carries a real API key when Some) into a test-failure message is exactly the pattern that would leak one in a future test built the same way. This is a new, currently-open, failing required check on this commit.
    Confidence 90 · architectural · Fix: assert a narrower, non-secret-bearing condition (e.g. compare just the logs-hint substring location without echoing the whole rendered block on failure), or justify/dismiss the alert explicitly if the team considers test-only None data out of scope.

  • recorded_status_after_stop's _ => "starting" arm is dead, untested code — apps/rocm/src/serve_progress.rs:479-485. Tracing decide_serve_startup (same file, ~line 403): the !process_alive branch always returns ProcessExited before any of DownloadStalled/Silent/SilentLoad/Deadline can be reached, so every ServeStartupStop this module ever constructs with one of those four reasons necessarily has process_alive == true. The function's only producer is stop_decision, and no test ever builds a non-terminal-reason stop with process_alive: false to reach the final arm.
    Confidence 85 · logic · Fix: collapse to _ => "running" with a debug_assert!(stop.process_alive) (or a comment) documenting the invariant — this also makes the function trivially const fn, resolving the clippy failure above.

  • apps/rocm/src/serve_summary.rs:180 hand-rolls rocm logs --service {} instead of calling the sibling helper service_logs_hint that this same PR introduces and that the very same function already calls correctly two lines earlier (line 143). service_hints.rs's doc comment states the helper's entire purpose: "Shared so a startup failure and the deployment summary cannot name two different log commands." The two strings are byte-identical today, but nothing ties them together going forward — exactly the drift class the helper exists to prevent, violated within the PR that introduces it.
    Confidence 85 · mechanical · Fix: replace the inline format! at line 180 with crate::service_hints::service_logs_hint(&summary.service_id).

  • apps/rocm/src/serve_cmd.rs:977: return Err(error.context(helper)) makes the secondary daemon-helper failure the headline, demoting the real startup failure — anyhow::Error::context(self, context) keeps self (the startup failure, built from ServeStartupStop::user_message, which names rocm logs/rocm services stop) as the cause and makes context (the helper failure) the new top-level Display message. main.rs prints errors via {e:?} (Debug), so the original message survives in the chain, but it's no longer the first line the user reads — backwards from the two errors' relative importance, and only reachable in the rare case ensure_background_helper_running_quiet itself fails right after a startup stop.
    Confidence 73 · logic · Fix: reverse the composition (e.g. helper.context(error)) so the serve-startup failure stays the headline.

Non-blocking

  • State-matrix doc table omits the deadline as an exit for "downloading"/"loading" rows — apps/rocm/src/serve_progress.rs:19-20. decide_serve_startup checks the overall deadline unconditionally before any phase-specific stall check (confirmed by the existing test wait_keeps_a_changing_download_alive_past_the_stall_limit, whose own comment says "a moving download must hit the deadline, not the stall limit"), so these two rows do exit on the deadline too — the unreachable row's column correctly lists both ("silent limit, or the deadline"), these two don't. Code and tests are correct; only the table is incomplete.
    Confidence 78 · mechanical · Fix: add "(or the deadline)" to both rows, matching the unreachable row's phrasing.

  • wait_for_serve_startup calls observe()+step() twice per 250 ms poll tick (once before the HTTP probe, once after), duplicating ~15 lines of near-identical logic. Correctness is unaffected (a terminal decision from the first call returns immediately, so the second never double-fires a stop/ready), but it can call on_view twice with the same label in one tick and is a simplification opportunity.
    Confidence 70 · mechanical · Fix: factor the shared "observe, compute token/timing, step" sequence into one helper called twice, or restructure to a single call per iteration.

Decisions for the author

  • rocm_core::SERVE_STARTUP_DEADLINE (30 minutes) is shared verbatim between the interactive CLI wait's give-up deadline and rocmd's background-recovery watcher's "don't restart a live, still-starting process" grace window (live_startup_still_in_progress) — tradeoff. This couples two independently-motivated concerns (interactive UX patience vs. background recovery safety) to one constant: tuning one later (e.g. shortening the interactive wait for snappier UX) would silently also shrink the watcher's grace window for every managed service, not just ones started interactively. Confirm this coupling is intentional rather than incidental.
  • The stall/silent timers are fixed global constants (DOWNLOAD_STALL = 3 min, SILENT_UNREACHABLE = 2 min, SILENT_LOAD = 5 min), not configurable per engine — tradeoff. If any of the three supported engines (lemonade/vllm/aim) can legitimately go quiet longer than 5 minutes during a real (non-hung) load step, that engine would now hit a false "stalled" error under the new interactive path, where previously it was never an error (the old 45-second behavior only ever printed a time-boxed summary). Worth confirming this was checked against all three engines' real log cadence, not just the synthetic timings the unit tests use.

Positive signals

  • decide_serve_startup is a pure function fully decoupled from I/O/timing, letting every lifecycle row be driven directly by a unit test with exact phase/label/reason assertions rather than weak substring checks — and the tests do this well.
  • The "readiness never downgrades" invariant (the best variable in wait_for_serve_startup, documented at lines 374-376) is an explicit, well-reasoned guard against flicker: one refused connection after the model has listed does not regress the status line.
  • probe_service_http_readiness is shared between the interactive wait and the historical polling path specifically so the status line and the real readiness check "cannot disagree about ready" — a clean elimination of a split-brain bug class.
  • service_launch.rs's start_managed_service always persists the updated ManagedServiceRecord (status, inference_verified_at, audit log) before ever branching to bail! on a startup stop — there is no path that mutates state and fails to persist it.
  • Interactive vs. piped mode is correctly gated on IsTerminal::is_terminal(&stdout()) (serve_cmd.rs:845), so none of the new stall-detection/hard-error behavior reaches a script or CI pipe — the lenient 45-second status-budget path is untouched for non-interactive callers.
  • The PR's own test-plan is unusually candid about what wasn't validated locally ("Full workspace cargo test and clippy were not run"), and that disclosure correctly predicted the CI failures found above.

Deployment notes

The shared SERVE_STARTUP_DEADLINE constant changes rocmd's recovery-watcher behavior for any managed service (not only ones started under the new interactive path) that is less than 30 minutes old, still "running" with a live pid, but endpoint-unreachable: it will no longer be auto-recovered during that window, where it may have been before this change. This looks intentional (it's exactly what the new recovery_leaves_a_live_startup_alone_and_still_restarts_a_dead_one test pins), but it's worth calling out explicitly for anyone operating rocmd in production, since it widens the window before automatic recovery kicks in for any stuck or slow-starting service, not just ones launched interactively.

What this covered

Read completely: apps/rocm/src/serve_progress.rs (new, 1447 lines, including all tests), serve_cmd.rs, serve_summary.rs, service_launch.rs, service_hints.rs, engine_runtime_select.rs, main.rs, apps/rocmd/src/watchers.rs, crates/rocm-core/src/lib.rs and net.rs, xtask/src/ascii_output_contract.rs, README.md, docs/architecture.md, docs/manual-testing.md, docs/testing.md, tests/e2e-cucumber/features/model_serving.feature, and this repo's AGENTS.md in full. Diff resolved against cc56179c…0557c5db by fetching the PR head read-only (git fetch https://github.com/ROCm/rocm-cli.git pull/817/head); the PR was never checked out. Work was split across three independent, blind, file-scoped fan-out workers (core state-machine module; wiring/integration layer; supporting infra + docs), then consolidated and every surviving finding re-verified against the source here, plus a design-review pass and a check of this PR's live CI status (get_check_runs) and code-scanning alerts.

Did not run: cargo build/test/clippy locally (relied on CI's own run, which failed — see Blocking); the e2e-cucumber/GPU-gated suite (no GPU available here, and the PR itself states none was run); a direct check of the three serving engines' (lemonade/vllm/aim) real log cadence against the new silent-load/download-stall timers (raised as an open question under Decisions for the author instead, since it can't be settled from the diff alone). The history/prior-changes passes were done lightly (confirmed these files' recent history is module-extraction refactors with no directly relevant prior review threads surfaced), not exhaustively. Not reconciled against any PR discussion or comments — the existing github-advanced-security[bot] comment was read only for its CodeQL alert detail, not treated as review discussion.

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