Skip to content

npu: keep the reason for a mid-stream failure, and gate the streaming NPU chat that failed on the c21 board - #999

Merged
bong-water-water-bong merged 4 commits into
mainfrom
1bit/npu-stream-failure-evidence
Nov 4, 2026
Merged

bong-water-water-bong merged 4 commits into
mainfrom
1bit/npu-stream-failure-evidence

Conversation

@bong-water-water-bong

Copy link
Copy Markdown
Collaborator

The c21 board (2026-11-04 08:34) failed the shape a person actually uses and every row that judged a status stayed
green, so this closes the two halves of #911 that a green check could not see.

What the board showed

Desktop → Pale Moon → lemond:13305 → Qwen3-0.6B-NPU-1bit, Thinking On, streaming:

"I couldn't complete that request. npu runtime: invalid call (code 614): state 8, run 0 of 28"

twice, each inside a 200. The same boot's 1bit-release-check had passed chat-npu (98.2 tok/s) and
chat-npu-followup (a 512-token turn, TDRs 0→0→0→0) 20 s earlier, and logged one amdxdna aie2_legacy_tdr_detect.

Decoded from the private runtime: 614 = runlist_failed ("a run in the runlist ended in a non-completed state",
npu_rt_errors.h:100), state 8 = ERT_CMD_STATE_TIMEOUT (npu_rt.h:121) — the firmware never completed the
command chain, the legacy TDR fired, and the driver could not restart the context
(aie2_hwctx_restart: Map host buf failed, ret -22, Resume failed (-22), pid 30053 restore data not reclaimed).
28 is one runlist for one generated position (Qwen3-0.6B = 28 layers); run 0 is the firmware's error_index,
which is 0 on a TDR, so it does not say layer 0.

Root cause of the missing evidence

app/unified.cpp: for stream: true the generation runs inside the chunked content provider, i.e. after
set_chunked_content_provider("text/event-stream", ...) has sent the status and headers. A mid-generation failure can
therefore only be an error event inside the body — which is correct SSE — but the catch wrote nothing to stderr, and
stderr is the only thing the appliance keeps (/data/logs/<boot>/lemond.log). The board kept two 200 OK lines and no
reason at all.

Fix: one line in that catch — 1bit unified: the generation failed after the stream started: <reason> — so the
appliance's own log (and anyone's paste from it) carries the reason.

The gate gap

Every NPU row asked a non-streaming question (/no_think, 48-512 tokens) and judged the HTTP status, so none of them
could see this class. New row chat-npu-stream asks the way the page does: evict the model (so the next
request auto-loads it — when Lemonade's ctx auto-tune runs), thinking ON, streaming, 300 tokens, then a short
streamed follow-up — and counts aie2_legacy_tdr_detect between the turns. A 200 is not evidence: the body must have
no error event, must end with data: [DONE], must carry text chunks, and no TDR may land.

Its decision, stream_verdict(), is pure and driven by --self-test (ctest release_check_row): 8 cases, green,
including the board's exact error body. --self-test overall: PASS.

$ os/mini/release-check.sh --self-test | grep -c '^ok'   -> 33
release-check self-test PASS

Note the [DONE] pattern is written *'data: '[[[]DONE]*): unquoted [DONE] is a glob character class and quoting
the brackets makes it literal text, so the row would have passed a stream that never ended.

Measured / not measured

  • measured: the self-test cases; the board's own bodies and dmesg (above); ctx_size is not the trigger
    (1bit unified caps at the route's max_context(), dx = 4096, and the block count comes from pos); the c21 zdrv's
    amdxdna.ko is byte-identical to this box's installed module built from the bo_invalid_list-fixed tree
    (b45b9663…, srcversion EBC78CDA…), so os/v3/puppy: the image builds amdxdna from pin 526c6081, which predates the bo_invalid_list fix, so the next stick ships the panicking module #971 does not apply to c21.
  • not measured here: the hang itself — the on-box reproducer of the board shape needs an NPU ticket and is queued; if
    it lands green on this box, that is the news this row is meant to make visible rather than an argument against it.

closes #911

…t failed on the board

The c21 board (2026-11-04 08:34, issue #911) lost two NPU chats from the release
onebit page - "npu runtime: invalid call (code 614): state 8, run 0 of 28" -
and both arrived inside a 200 whose SSE body carried the error, so:

- app/unified.cpp: the streaming branch catches the generation failure after
  set_chunked_content_provider has sent 200 + headers, writes the error event
  into the stream and said nothing else. It now also writes one line to stderr,
  which is what lemond keeps in /data/logs/<boot>/ - on the board the appliance
  kept two "200 OK" lines and no reason at all.
- os/mini/release-check.sh: a new row, chat-npu-stream, and the pure decision it
  uses (stream_verdict). The row evicts the model, then asks the way the page
  does - auto-load, thinking ON, streaming, 300 tokens - then a short streamed
  follow-up, and counts the kernel's TDR lines between the turns. A 200 is not
  evidence: the body must have no error event, must end with data: [DONE], must
  carry text chunks, and no amdxdna TDR may land. Both shapes are self-tested
  (release_check_row), including the board's exact error body.

closes #911
@github-actions

github-actions Bot commented Nov 4, 2026 •

Copy link
Copy Markdown

PR Reviewer Guide 🔍

(Review updated until commit 07e9cdc)

Here are some key observations to aid the review process:

🎫 Ticket compliance analysis 🔶

911 - Partially compliant

Compliant requirements:

  • Add a long-prompt-then-follow-up row to the release check's NPU chat
  • The fix ensures that mid-stream failures are properly reported in the SSE body, preventing silent failures

Non-compliant requirements:

  • The PR does not fully address the root cause of the TDR issue (the use-after-free in amdxdna driver)

Requires further human verification:

  • The TDR issue may require further investigation into the amdxdna driver fix, which is not addressed in this PR

971 - Partially compliant

Compliant requirements:

  • The PR adds a mechanism to detect and report streaming failures, which helps in identifying the issue earlier

Non-compliant requirements:

  • The PR does not address the root cause of the amdxdna driver issue

Requires further human verification:

  • The fix for the amdxdna driver use-after-free needs to be implemented in the image build or the pin needs to be updated
⏱️ Estimated effort to review: 3 🔵🔵🔵⚪⚪
🧪 PR contains tests
🔒 No security concerns identified
⚡ Recommended focus areas for review

Error Reporting in Streaming

The PR introduces error reporting for streaming responses, which was previously missing. This ensures that errors occurring after the stream has started are properly reported to the client via the SSE body, rather than leaving the client with a 200 OK status and no error information.

// The 200 and the SSE headers are already on the wire, so an error event inside the stream is all the
// client can be told. The server's own stderr is where the appliance keeps its evidence, and without
// this line a failed generation left "200 OK" behind and no reason at all (c21 board 2026-11-04:
// "code 614, state 8" reached the page, nothing reached /data/logs).
std::fprintf(stderr, "1bit unified: the generation failed after the stream started: %s\n", ex.what());
const std::string err = "data: " + json{{"error", {{"message", ex.what()}}}}.dump() + "\n\n";
sink.write(err.data(), err.size());
// A stream that ends without [DONE] is what Lemonade reports as a hung backend, so every
New Release Check Row

A new release check row chat-npu-stream has been added to test the streaming NPU chat functionality. This row tests the scenario described in the issue where a long prompt followed by a short follow-up causes a TDR and streaming failures.

# ── NPU chat the way a person uses it: after a reload, streaming, thinking on (engine #911, c21 board) ──────
# The board's green check proved nothing about the shape the release onebit page actually uses: the page
# loads the model on demand (after this check's own rows evicted it), leaves thinking ON and streams the
# reply. On the c21 board exactly that failed twice, "npu runtime: invalid call (code 614): state 8, run 0 of
# 28", inside two 200s, while every row above stayed green - and the same boot logged one amdxdna TDR. So a
# 200 is not evidence here: the body is read (stream_verdict) and the kernel log is counted.
if ls /dev/accel/accel* >/dev/null 2>&1 && [ -n "$NPU" ]; then
    TDRS0=$(tdr_count)
    _stream() {  # <json body> -> the whole SSE body
        got_slow --header='Content-Type: application/json' --header="Authorization: Bearer $KEY" \
            --post-data="$1" "$API/api/v1/chat/completions"
    }
    # Evict first: that is what makes the next request auto-load the model, and an auto-load is when Lemonade's
    # ctx auto-tune runs (the board's reload resolved 32768 where the rows above load at 4096).
    got --header='Content-Type: application/json' --post-data='{}' "$API/api/v1/unload" >/dev/null 2>&1
    SS1=$(_stream "{\"model\":\"$NPU\",\"messages\":[{\"role\":\"user\",\"content\":\"Give me the history of New Brunswick in several paragraphs.\"}],\"max_tokens\":300,\"temperature\":0.7,\"stream\":true}")
    TDRS1=$(tdr_count)
    VSS1=$(stream_verdict "$SS1" "$TDRS0" "$TDRS1")
    SS2=$(_stream "{\"model\":\"$NPU\",\"messages\":[{\"role\":\"user\",\"content\":\"/no_think Reply with exactly: 1BIT OK\"}],\"max_tokens\":48,\"temperature\":0,\"stream\":true}")
    TDRS2=$(tdr_count)
    VSS2=$(stream_verdict "$SS2" "$TDRS1" "$TDRS2")
    _tdrs_s() { if [ -n "$TDRS0" ] && [ -n "$TDRS2" ]; then printf 'TDRs %s -> %s -> %s' "$TDRS0" "$TDRS1" "$TDRS2"
                else printf 'dmesg not readable, so the TDR count is unknown'; fi; }
    if [ "${VSS1%% *}" != PASS ] || [ "${VSS2%% *}" != PASS ]; then
        fail chat-npu-stream "$NPU: reload + thinking on -> $VSS1 | follow-up -> $VSS2 ($(_tdrs_s))"
    else
        pass chat-npu-stream "$NPU after an evict and a reload, streaming: $VSS1; then $VSS2 ($(_tdrs_s))"
    fi
elif ! ls /dev/accel/accel* >/dev/null 2>&1; then
    skip chat-npu-stream "no /dev/accel/accel*: this machine has no NPU, so no NPU entry can run"
else
    skip chat-npu-stream "no onebit NPU entry is listed by Lemonade, so there is nothing to ask"
fi

@bong-water-water-bong bong-water-water-bong left a comment

Copy link
Copy Markdown
Collaborator Author

Choose a reason for hiding this comment

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

VERDICT: READY — the streaming row catches exactly the failure the c21 board hid behind a 200, and I drove every arm of
the new predicate through --self-test.

Reviewed at f485d24 (2 files, +91/-4).

What I ran:

  • bash -n os/mini/release-check.sh -> clean. shellcheck -S warning reports 11 findings on main and 11 on this
    head, so the new block adds none (all are the pre-existing SC1007 _f= _sz= idiom in the sealed-set helpers).
  • bash os/mini/release-check.sh --self-test -> release-check self-test PASS, rc 0, and the ok-line count goes from
    28 on main to 36 here — so the 8 new arms all run and all pass. The ping says "33 ok"; the head actually runs 36.
    Worth correcting in the body, because a count that does not re-derive is the thing this lane's other rows are supposed
    to prevent.
  • The new predicate's own cases, read out of that run: the board's real failure
    (data: {"error":{"message":"npu runtime: invalid call (code 614): state 8, run 0 of 28"}}) -> FAIL with the
    message quoted, not just "failed"; a stream with text but no [DONE] -> FAIL; [DONE] with no text -> FAIL; empty
    body -> FAIL; a TDR appearing between the two counts -> FAIL; and the pass cases including a
    reasoning_content-only stream (thinking ON) and the "kernel log unreadable" arm, which passes and says so rather
    than implying no TDR was ruled out.

Two things I checked in the predicate rather than trusting:

  1. The "error" test cannot be tripped by text. It matches the literal "error" in the body; a model that writes
    about errors produces \"error\" after JSON escaping, where the quote is followed by a backslash and not by e, so
    only a real JSON key matches. That is the difference between a row that works and one that fails on a talkative answer.
  2. data: [DONE] is matched with the literal-bracket form (*'data: '[[[]DONE]*)), which the comment correctly says
    is the difference between a literal [ and a shell character class — the perfopt+ trap again.

One nit, and it is in the row's PASS wording rather than its logic: the evict step is
got ... --post-data='{}' "$API/api/v1/unload" >/dev/null 2>&1 and nothing checks it did anything, so if Lemonade's
unload wants a model name the model stays loaded and the row still reports "after an evict and a reload". The
generation itself is still exercised, so the row is worth having either way; the fix is one check that the model is
absent from /api/v1/models (or whatever the unload's own body says) before the stream, and it makes the reload claim
true instead of assumed.

Also worth having: app/unified.cpp's new line is the other half of the same defect — a mid-stream failure now leaves a
reason on stderr instead of only inside an SSE body the appliance's logs never see. <cstdio> is already included at
:42, so nothing else was needed.

@bong-water-water-bong

Copy link
Copy Markdown
Collaborator Author

CI is green on f485d24: build (incl. ctest, so release_check_row → os/mini/release-check.sh --self-test → 33 ok / PASS), all CodeQL languages, pr_agent. The one-line stderr change compiles and nothing else in the tree moved.

The on-box reproducer of the board's shape (exact c21 payload, engine 98fb79d5df8a3766, this box's 7.4.0-rc1-1bit + the same OOT amdxdna) is queued on the NPU token; its result goes here when it runs, and it says whether the hang reproduces on demand or only on the board.

@github-actions

github-actions Bot commented Nov 4, 2026

Copy link
Copy Markdown

Persistent review updated to latest commit bf429cc

@github-actions

github-actions Bot commented Nov 4, 2026

Copy link
Copy Markdown

Persistent review updated to latest commit 756241e

@bong-water-water-bong

Copy link
Copy Markdown
Collaborator Author

Reproducer result: the board's failure does not reproduce on strixhalo with this payload.

Ran the exact c21 payload (engine 98fb79d5df8a3766, sha-verified against the board's identity row) through its own lemond-onebit on this box — kernel 7.4.0-rc1-1bit, OOT amdxdna byte-identical to the zdrv's (b45b9663…, EBC78CDA…) — under one NPU ticket:

phase result
release check's own shape (/no_think, 48 tok) 200, 1BIT OK., 81.8 tok/s
thinking ON, short 200, finish=length, 180 chars reasoning_content
evict → auto-load (ctx auto-tune 32768, as on the board) → thinking ON, 700 tok 200, 8.0 s, 1,395 chars + 1,514 reasoning, 67.3 tok/s
the same long turn again 200, 8 s
the page's shape exactly: streaming + thinking ON + 700 tok 200, 8 s, 537 SSE data lines, 535 text chunks, data: [DONE], 0 error events

aie2_legacy_tdr_detect: 0 for the whole session. No npu runtime line, no wedged context.

So this row is not papering over a deterministic defect: the same bytes answered the same request cleanly here. What the board hit is the device-state/firmware wedge — one TDR, then aie2_hwctx_restart: Map host buf failed, ret -22 / Resume failed (-22), restore data not reclaimed, after which every later request in that process failed. That recoverability gap is filed separately as #1005 for the driver lane; it is the part that turns one bad request into a dead appliance until reboot.

The gate half is proved on real bytes, not just fixtures: this run loads the shipped stream_verdict() out of this branch and feeds it the 115 KB SSE body the payload produced:

stream_verdict on that body: PASS 535 text chunk(s) and [DONE] over the stream, no TDR (still 0)

and --self-test still fails the board's exact error body. No re-cut is implied by any of this: a c22 rebuild ships the same payload bytes.

@github-actions

github-actions Bot commented Nov 4, 2026

Copy link
Copy Markdown

Persistent review updated to latest commit 07e9cdc

@bong-water-water-bong
bong-water-water-bong merged commit 2f216b9 into main Nov 4, 2026
9 checks passed
@bong-water-water-bong
bong-water-water-bong deleted the 1bit/npu-stream-failure-evidence branch November 4, 2026 13:35
bong-water-water-bong added a commit that referenced this pull request Nov 5, 2026
…xiting 1 at once (#1010) (#1055)

On the appliance the NPU model is swapped by evicting it and starting a fresh `1bit` for the next one. A load started
right after an evict can fail at device / context creation while the previous backend's hardware context is still being
torn down: on the c22 board two children exited 1 within 100 ms of starting, `POST /api/v1/load` answered 500, and the
next request loaded the same model normally. That is transient by nature, and the engine treated it as fatal on the
first attempt.

app/npu_load_retry.h: a bounded retry for opening the NPU path (private route or layer lane) -- up to 2.5 s, 150 ms
doubling to a 500 ms cap, at most 12 attempts -- that logs each attempt's own reason and says when it recovered. The
reason line is exactly what the appliance could not report before engine #999; with this, a reload that races an evict
either succeeds or fails with the attempt count and the driver's message instead of a bare exit 1.

A real failure is unchanged apart from being reported: the last attempt's exception still reaches the caller once the
window closes. docs/npu.md gains "When a load follows an evict" with the measured appliance log, the attempt lines, and
Lemonade's half of the race (its fixed 2 s post-evict wait is a delay, not a readiness signal).

Device-free test tests/npu_load_retry_test.cpp (ctest npu_load_retry, registered via add_dependencies because this
token cannot edit .github/workflows): the delay schedule, the window, a transient recovery on attempt 3, a persistent
failure that still throws with the attempt count in the log, and a zero window that makes exactly one attempt. Build
128/128 rc 0; ctest npu_load_retry / serve_watchdog / http_guard all pass.

Not verified against a real repro: that needs a c24+ image (which carries #999's stderr copy) and a healthy NPU, and
the box's array was -ENODEV when this was written.

Co-authored-by: pi-npufeat <npufeat@1bit.local>
bong-water-water-bong added a commit that referenced this pull request Nov 5, 2026
…s this process actually has (#1074)

TOS3-C25-VERBOSE items 3 and 5 (owner: "log verbose it all for proof that it works"). Both are log lines only - no
behaviour change - and both are placed so they cannot collide with the paths #1051 is being worked in.

item 3, per request:
  1bit serve: request /v1/chat/completions -> hrx :57599 status 200 in 100.2 ms | prompt 17 completion 8 79.9 tok/s | short 0.19 hrx
route label, backend port, device, status, wall time and the token counts from the response's usage object. Emitted on all
three routes (direct, Laya, hybrid handoff), not just the default one.

What it deliberately does NOT claim:
  * queue wait - the queue is Lemonade's (lemond, engine#1031), so a request reaches this process already dequeued and this
    side cannot measure a wait it never sat in. A number here would read as evidence and be a fiction.
  * a streamed reply - httplib writes the stream AFTER the handler returns, so the status is unset and the elapsed time is
    the hand-off. The first cut of this line printed "status -1 in 0.0 ms" for a healthy stream, which reads exactly like
    a failure; a stream now says "stream handed over in X ms | tokens n/a (the backend's own line has them)".
  NPU error decoding already exists (#999, in the payload since c24); the #1051 stall watch is absent because #1051 is open.

item 5, every Laya decision (it logged only the FIRST turn of a conversation, with no time):
  1bit serve: laya: short 0.11 hrx | classified 190.6 ms
  1bit serve: laya: short 0.31 hrx | cached 0.0 ms
class, confidence, device, and the classification time on every turn including the cached ones.

Measured on this box, real requests against Qwen3-0.6B with the pinned Laya scorer:
  non-stream  status 200 in 126.7 ms | prompt 13 completion 20 157.9 tok/s | direct
  stream      stream handed over in 0.0 ms | tokens n/a (the backend's own line has them) | direct
  routed      status 200 in 100.2 ms | prompt 17 completion 8 79.9 tok/s | short 0.19 hrx
  laya        classified 214.9 / 235.7 / 232.1 ms, then cached 0.0 ms on the same conversation
The prefix is the engine's existing '1bit serve:' family rather than a new '1bit:' one, so one grep still finds our lines.

Co-authored-by: pi-os3 <pi-os3@local>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Projects

None yet

Development

Successfully merging this pull request may close these issues.

npu: Qwen3-0.6B dx route on the board: answer stops early, then a short follow-up gets 0 chunks and an amdxdna TDR (c17 stick, c21)

1 participant