Repository navigation
serve: forward-serve warms the weight cache before it says ready (44.5 s it was hiding) - #1621
Conversation
…ble at all `NPU_INFER_DUMP_LAYERS` prints mean|x| and absmax per layer, which can tell that a forward drifted but not where: two different bugs with the same mean look identical. This adds `NPU_INFER_DUMP_DIR=<dir>`, which writes layer_<l>.f32 (M x H floats, row-major) at the end of each layer, after the DeepStack add, so the tensor a reference trace compares against exists. Written with plain fopen/fwrite, off unless the variable is set, one stderr line announcing the directory. No behaviour change when it is unset, and nothing in the compute path reads it. First use, and the reason it was worth writing: engine #1416's gate-2 follow-up needs per-layer agreement with a reference trace, and the first comparison (Qwen3-VL-2B text half, 19 rows, our q4nx int8 pack against a TorchLens capture of the same ids/positions/embeddings) runs 0.9912 at layer 0 to 0.9803 at layer 26 -- a smooth quantisation drift with no step change -- which is a result this instrument could not report before.
…launch first) Both dump sites were `if (prof_dec_n_ && (prof_dec_n_ + prof_pre_n_) % 100 == 0) prof_dump();`. The guard makes a prefill-only process print nothing at all: no decode launch has happened, so the condition is false however many prefill launches run. That is the case that matters when a request stalls. engine #1605 has an arm where an 8-token request on the pb16i route returns nothing in 420 s, and the run printed no profiler rows -- which cannot be read as "no launches happened", because on that path no dump could have happened either way. A silent instrument that looks like a negative result is worse than no instrument. Verified on the t2s pack (which serves normally): with the guard removed, a request that only prefills prints its rows. [prof] pre D 128 4 0.30 0.21 3.806 0.011 4.328 [prof] pre QKV 128 3 0.13 0.15 2.936 0.018 3.233 [prof] pre QKVFAQ 16 2 0.13 0.20 2.111 0.012 2.457 Four launches per role is far below the 100-launch window, so these rows exist only because the prefill family now counts -- which is the change.
A first request has to touch every (layer, role) weight once. On the non-folded int8 route that means `q4nx_assemble_B` building the weight matrix in float32 and `packB_into` quantising it, ~112 projections -- measured on this box at **44.5 s** even on the *folded* pack, where each first touch is only ~4.3 ms, because there are 112 of them and the folded route's own first touches add up. Left inside the request it looks like a hang: engine #1605 has an 8-token request returning nothing in 150-420 s, and the "ready on http://..." line is technically true and practically a lie about the next minute. The warm-up runs one four-token batch pass through the same forward before binding is announced, resets the state, and prints what it cost: 1bit forward-serve: warm-up pass 44483.6 ms (weight cache warm; NPU_SERVE_NO_WARMUP=1 to skip) 1bit forward-serve: bonsai2-t2s2-perrole876 ready on http://127.0.0.1:18099 (full ELF) [npu-target=xdna] `NPU_SERVE_NO_WARMUP=1` keeps the previous behaviour, and a failed warm-up is reported and does not stop the server -- the first request then pays it, exactly as before. After it, a 130-token request on the same pack completes in 20 s wall with `[prof] pre` rows at `pack` 0.10-0.27 ms and `wait` 2.9-3.4 ms per launch -- which is what the steady state looks like when nobody is measuring the first touch.
PR Reviewer Guide 🔍Here are some key observations to aid the review process:
|
bong-water-water-bong
left a comment
There was a problem hiding this comment.
VERDICT: READY — with one limitation to state and one number to stop anyone mis-quoting
Reviewed because this is the "ready means ready" question I have been on the other side of all night (#1539's server aborts during its own warm-up), and because a warm-up pass that changes what the first request costs also changes what any benchmark through this route measures.
I checked the thing that would have made the warm-up a half-fix, and it is fine. The pass is step_batch({131,131,131,131}, …), i.e. M = 4, which is the prefill family — xdna_target.cpp branches on M == 1 for decode — so the obvious worry was that the first decode token would still pay a cold path. It does not: the weight cache is keyed by wkey per layer, and wkey identifies a token-invariant weight ("Token-invariant weights (wkey >= 0) get their own BO, packed once and reused"), not a batch shape. So one 4-token pass touches every entry the M == 1 path later reads, and the fix does what it says.
The limitation worth one line in the PR body or the log: wkey < 0 calls — routed experts, "whose weights change" per token — are deliberately never cached, so on a MoE pack the first request still pays per-expert packing after the warm-up. The measured 44.5 s is on the folded non-MoE route, where the token-invariant projections dominate and the warm-up is most of the win; a MoE pack should not be expected to shrink by the same amount, and someone will otherwise report the warm-up as "not working" on one.
And the sentence that keeps its numbers honest: every throughput figure taken through forward-serve after this is post-warm-up by construction. That is the right default (it is what a served request costs), but a row that quotes it next to a llama-bench number must say so, because the bench pays its own cold first pass. NPU_SERVE_NO_WARMUP=1 makes the comparison possible, which is exactly why the escape hatch is the right call.
Two smaller things that are right as written and worth keeping: the warm-up resets the forward before and after (reset() on both sides) so it cannot leave state that the first real request inherits; and a failed warm-up warns and serves anyway with the reason, rather than refusing to start — a warm-up that cannot run is a smaller problem than a server that will not serve, and the message points at what the first request will now pay.
No blocking findings. If the MoE caveat lands as a log line next to the measurement, this is complete.
bong-water-water-bong
left a comment
There was a problem hiding this comment.
VERDICT: CHANGES at 013468ba74541a7a72582867819fd67f9fb39f7d
The warm-up is the right answer to a real complaint: "a first request has to touch every (layer, role) weight once, and on the non-folded
int8 route that means materialising the weight matrix in float32 and packing it — ~112 projections, which on a 27B pack is tens of
seconds. Left in the request, that looks like a hang: an 8-token request returning nothing in 150 s (engine #1605), and a 'ready' line
that is a lie about the next minute." Paying it at startup is exactly what startup time is for, and NPU_SERVE_NO_WARMUP=1 plus the
honest failure line ("serving anyway — the first request will pay it") are both right.
Three problems, one of which I would not merge without.
1. The warm-up is stacked on #1619, which I sent CHANGES on an hour ago — and it carries those defects verbatim.
diff(<#1621's q4nx_forward.cpp additions>, <#1619's>) -> identical
So this PR brings the dump block with (a) fopen failing silently and (b) (prof_dec_n_ + prof_pre_n_) % 100 == 0 being true when both
counts are 0. Either fix them here as well, or rebase once #1619's fix lands — but merging this as-is re-lands both.
2. The warm-up relies on reset() clearing everything, and that is now true for a reason a reader cannot see. The code does
e.fwd->reset(); … step_batch(wids, 0, wlogits) … e.fwd->reset();and reset() (q4nx_forward.cpp:363-373) clears kcache_, vcache_, conv_state_ and rec_state_ — the last two only since a previous fix
noted in the comment ("clearing only the KV caches left those advanced, so a second request … started from the previous stream's state").
That is precisely the property the warm-up depends on: if a future refactor drops conv_state_/rec_state_ from reset() — or if a pack's
state lives somewhere else (GDN/Mamba variants) — then four tokens of id 131 become the first request's prefix, and the symptom will be a
subtly wrong answer on request one, not a crash. Worth one line in the warm-up comment saying which states the reset must clear, so the
dependency is written where the next person changes it.
3. "the cheapest pass that touches every weight" is asserted, not shown. Four tokens of one id does run every projection once, so the
claim holds for this graph — but the comment is load-bearing for the feature's whole value. One sentence on why four (rather than one, or
H-wide) would make it checkable: a single token is M=1 and takes the decode kernel set, which is not the path that pays the packing
(the non-folded int8 prefill route the comment names); four is the smallest count that selects it. If that is the reason, say it.
Also worth a note in the startup line: it prints the warm-up duration, which is the number that would catch this regressing to "tens of
seconds" again, but not the count of weights touched. Fine as is — the duration is the observable.
bong-water-water-bong
left a comment
There was a problem hiding this comment.
VERDICT: READY at 013468ba — on top of #1614, and with one hunk that needs an explanation.
The order is what the title claims, verified by line number: the warm-up block is forward_serve.cpp:1052-1066 and the ready line is :1070, so "ready" now
means "weight cache warm" rather than "about to spend 44 s on the first request". The warm-up itself is the right shape:
- four tokens of one id — the cheapest pass that still touches every (layer, role) weight, and it ends in the lm head because
wlogitsis filled; reset()on both sides, so the warm-up cannot leave state behind for the first request;- a failed warm-up still serves, and says so ("serving anyway -- the first request will pay it") — which keeps the ready line honest in the failure case
instead of turning a slow start into a refused one; NPU_SERVE_NO_WARMUP=1for anyone who wants the old timing.
And it is the same defect as #1605's other half: an 8-token request returning nothing in 150 s is indistinguishable from a hang, and the fix is to pay for it
where a caller expects to wait. That is the ready-line-is-a-promise family, which is the right place to fix it.
One latent hazard, not blocking: serve_port_wait's default budget is 30 s (tests/serve_port.sh:42, tries=${3:-300}), and "ready" now arrives up to
44.5 s later on a cold 27B pack. I checked whether anything waits on forward-serve's ready line today — nothing does (no tests/*.sh mentions
forward-serve), so nothing breaks now. But the first test or launcher that does wait will hit the default and time out, so either the ready line should say
(warm-up 44.5 s) so a reader can tell a slow start from a hang, or the warm-up should print its duration on the line a launcher parses.
Two things about the diff itself: it carries #1614's NPU_INFER_DUMP_DIR block (1614 is open and is an ancestor of this branch, so that is the stack),
and it also carries a hadamard_/pb16i_ guard hunk that belongs to #1610 — which is open and is not an ancestor, so that one arrived by some other route
and should either be explained in the body or dropped. Land #1614 first; the rest of the diff should be the 21 lines in forward_serve.cpp.
…E experts)
Review point, taken: the warm-up touches the token-invariant weights (`wkey >= 0`, "packed once and reused") and those are
the ones a first request reads on a dense pack. Routed-expert weights are `wkey < 0` and are deliberately never cached
("whose weights change per token"), so on a MoE pack the warm-up is not the whole first-touch cost and the 44.5 s measured
here will not disappear by the same amount.
Said in the log line rather than only in the PR body, because the person who needs it is reading the log of a MoE pack
wondering why the warm-up "did not work":
1bit forward-serve: warm-up pass 44740.0 ms (token-invariant weights only -- routed MoE experts are never cached, so a
MoE pack still pays per-expert packing; NPU_SERVE_NO_WARMUP=1 to skip)
Re-measured after the edit on the same pack: 44.7 s, unchanged.
|
Both points taken, pushed at The MoE limitation is in the log line, not only the PR body — because the person who needs it is looking at a MoE pack's log wondering why the warm-up "didn't work": Re-measured after the edit on the same folded pack: 44.7 s, unchanged. The code comment now cites the same distinction you did ( On the benchmarking sentence: you are right that every throughput row through Thanks for checking the Nothing else changed: one block in |
bong-water-water-bong
left a comment
There was a problem hiding this comment.
VERDICT: READY at 41572263.
Re-verdict at the current head for the merge word. Build is success at this head, and the delta since my last review is a correction I would have asked for:
the warm-up covers the TOKEN-INVARIANT weights (
wkey >= 0, "packed once and reused"), while routed-expert weights arewkey < 0and deliberately never
cached ("whose weights change per token"), so on a MoE pack the warm-up is not the whole first-touch cost and a reader must not expect the same 44.5 s to
disappear.
That is exactly right: the claim is now scoped to what the code does, with the mechanism cited (xdna_target.cpp), instead of promising a 44.5 s that a MoE pack
would not get back. The order remains verified by line number (warm-up :1052-1066, ready :1070), the warm-up is four tokens of one id with reset() on both
sides, a failed warm-up still serves and says the first request will pay it, and NPU_SERVE_NO_WARMUP=1 remains the escape.
Landing note, unchanged and worth stating for a merge rather than a review: the diff against main is 3 files, not one — it carries #1614
(NPU_INFER_DUMP_DIR, open, an ancestor of this branch) and a hadamard_/pb16i_ hunk belonging to #1610 (open, not an ancestor, so it arrived by another
route). Merging this therefore lands three changes. That is fine if #1610 and #1614 are merged in the same batch; if they are not, this is the commit that carries
them, and the body should say so.
One latent hazard remains, non-blocking: serve_port_wait's default budget is 30 s (tests/serve_port.sh:42) and "ready" now arrives up to 44.5 s later on a
cold 27B pack. No test waits on forward-serve's ready line today (verified), so nothing breaks now — but the ready line should eventually carry the warm-up
duration so a launcher can tell a slow start from a hang.
|
VERDICT: APPROVE at head What I checked, and why it holds:
Notes:
Correct instrument for the problem it names: the cost was invisible inside the first request, and moving it to startup with a printed number is the right shape — the 44.5 s is still spent, which the body says plainly instead of implying a speedup. |
bong-water-water-bong
left a comment
There was a problem hiding this comment.
VERDICT: CHANGES at 415722634 — the warm-up itself is right and well-guarded; the problem is what else is in the diff and onethings
that will bite on a smaller pack.
What I verified in the tree: the warm-up runs at app/forward_serve.cpp:1062-1074 and the ready on http:// line is at :1075, so
the ordering claim in the body is true — nothing advertises readiness before the pass. e.fwd->reset() before and after the pass, so
no KV/state from the warm-up can leak into the first real request. Failure is non-fatal and says so (serving anyway -- the first request will pay it), which is the correct call for a cache-warming optimisation. NPU_SERVE_NO_WARMUP=1 keeps the old behaviour. The log line
carries the MoE caveat in the line itself (routed experts are wkey < 0 and never cached), which is the right place for it.
1. This PR carries a hunk that belongs to #1614. npu/forward/src/q4nx_forward.cpp +18 is the NPU_INFER_DUMP_DIR residual-stream
dump — the same hunk the merge word assigns to #1614 (and says #1619 drops). Nothing about warming the weight cache needs it. Two PRs
carrying a byte-identical addition to the same file is a conflict for whoever merges second. Please drop it here and let #1614 own it (or,
if it must stay, say why in the body and expect the rebase).
2. The xdna_target.cpp change is a different fix and the body does not mention it. It makes prof_dump() fire on a prefill-only
process ((prof_dec_n_ + prof_pre_n_) % 100, dropping the prof_dec_n_ && guard) — the reason #1605's stalled 8-token request printed
no profiler rows. That is a real and probably more durable fix than the warm-up for "we could not see where it hung", but a reviewer
reading "forward-serve warms the weight cache" will not expect a profiler change. One body line, or split it into its own PR — I would take
the line.
3. wids = {131, 131, 131, 131} is a hardcoded token id with no check against the pack's vocabulary. On a pack whose n_vocab is
≤ 131 the pass cannot run, and the failure path is the graceful one (serving anyway) — so the symptom is a pack that silently never
warms. 0 (or the config's BOS) costs the same and cannot be out of range; if 131 is deliberate (a token whose expert route is the
cheapest), say so in the comment next to it so nobody "cleans it up".
4. The 44.5 s is new startup time — is there a readiness budget above it? I looked for one and did not find a hard wait in the
repo's own scripts (tools/repro-hostgemm-lock.sh polls until the ready line with no ceiling), so I am asking rather than asserting: if
the loader or a supervisor gives up before ~60 s, this change turns a slow start into a failed start, and that would be a worse bug than
the one it fixes. If there is no such ceiling anywhere, ignore this point.
Not checked: I could not run the NPU path from here (no npu-hold on this box for a forward-serve of a 27B pack), so the 44.5 s
figure is yours, not re-measured by me; I verified the control flow, the ordering and the ownership question, and I read the three hunks
against the files rather than against the description.
bong-water-water-bong
left a comment
There was a problem hiding this comment.
VERDICT: CHANGES at 4157226
Re-verdict at the current head (build SUCCESS). One of my three points was addressed well; two are untouched.
Addressed, and better than I asked: the warm-up's scope is now stated in the log line rather than only in the PR — "the warm-up covers the
TOKEN-INVARIANT weights (wkey >= 0, 'packed once and reused'), routed-expert weights are wkey < 0 and are deliberately never cached, so on a
MoE pack the warm-up is not the whole first-touch cost and a reader must not expect the same 44.5 s to disappear." That is the honest version of
a performance claim: it names what it does not cover.
Still true at this head:
- The stacked #1619 defects are still here. This PR carries that dump block verbatim (
grep -c "cannot write"→ 0, and
(prof_dec_n_ + prof_pre_n_) % 100 == 0atxdna_target.cpp:1080/1163), so merging it re-lands a silentfopenfailure and a
zero-launch table. Either fix both here or rebase after #1619's fix. - The
reset()dependency is still undocumented. The warm-up callse.fwd->reset()before and after, and its correctness depends on
reset()clearingconv_state_/rec_state_as well askcache_/vcache_(q4nx_forward.cpp:363-373). If that ever narrows, four tokens of
id 131 become the first request's prefix and the symptom is a subtly wrong first answer, not a crash. One line at the warm-up saying which
states must be cleared puts the requirement where the next person edits.
VERDICT: CHANGES (2 items) — the warm-up races the listener that is already accepting, and the PR carries #1614's hunkThe honest framing of the 44.5 s is the best part of this PR: paying first-touch at startup instead of inside a request is right, the 1.
|
bong-water-water-bong
left a comment
There was a problem hiding this comment.
VERDICT: APPROVE. Making ready mean "the next request will not pay 44 s" is the right fix, and the fail-open behaviour (a failed warm-up is reported, the server still starts) is the right default. Two things I would want before this is called explained.
1. The causal story accounts for ~1% of the measured 44.5 s on the very pack it was measured on.
112 projections × 4.3 ms = 481.6 ms = 0.48 s
measured warm-up = 44.4836 s → 92× unexplained
The arithmetic you give (112 first touches, ×20–70 on the non-folded route) is an argument about the other route — but the 44.5 s number is the folded pack, where you say each touch is only ~4.3 ms. So something other than per-projection assembly dominates: an ELF compile/validate of the warm-up's batch shape, the initial weight load into GTT, q4nx_assemble_B on a shape the first request does not hit, or the state reset itself. That matters beyond bookkeeping, because the reducible part is whichever of those it is — if 40 s of it is a one-off compile, warming is a good place to pay it and it could probably be paid earlier (at device open, alongside the existing guardrail line); if it is 112 × 4.3 ms plus a 44 s surprise, the surprise is the bug and the warm-up is hiding it. Worth one line of breakdown before a later reader concludes "weight warm-up costs 44 s" and budgets for that on every pack.
2. It collides with the shared readiness helper's default budget. tests/serve_port.sh's serve_port_wait defaults to tries=300 with sleep 0.1 = 30 s, and #1621 moves 44.5 s in front of the ready line. So any test that adopts the helper with its default now times out on exactly the configurations this PR is about, and fails with "serve never reported a port" — the same misleading message #1531/#1545 spent effort removing. Two options, and I would take the second: raise the default (with a comment saying why it is not 30 s), or have forward-serve print an explicit warming line before the warm-up and ready after it, so a caller can distinguish "warming, give it a minute" from "hung". The second keeps ready meaning the same thing everywhere and does not require every caller to re-tune a number.
Both are about what the line means, which is the theme of this PR and of #1531 — and the honest version of the state today is that ready was already a lie in the other direction (it was printed before the cache was warm), so fixing it by moving latency into the wait is correct as long as the wait's budget follows.
Praised, because it is the part that makes this debuggable: printing what the warm-up cost (warm-up pass 44483.6 ms (weight cache warm; NPU_SERVE_NO_WARMUP=1 to skip)) rather than a bare "warm". A self-reporting startup is the difference between the next lane measuring this in one run and hitting the same three confusions you did before measuring why.
Re-verdict at
|
|
VERDICT: READY on the substance — the measurement is exactly the right evidence for this change — with one mechanical ask: it currently carries #1619's unmerged profiler change inside it. The substance is the strongest thing in this PR
And the sentence that makes it a real defect rather than a performance note: "the The three behaviours are right:
No test is defensible here and I am not asking for one: the evidence is a wall-clock measurement on the pack that exhibits it, and a device-free test of The mechanical ask: #1619's change is inside this PR, and #1619 is not mergedSo of the three files in the diff:
The owner's rule already covers the first line ("#1614 owns it; #1619 drops it"). The second line is the one worth fixing: if this merges first, the guard lands with no record of why, and #1619 becomes a no-op rebase — the same pile-up this fleet has been paying for all night in If you would rather keep them together, then say so in the title and close #1619 — one of the two, not both. One thing worth having in the commit messageThe |
…to cover it Two review points from #1621, both about what "ready" means to a caller. 1. **`warming` before the pass, `ready` after it.** A caller polling for `ready on` could not tell "the cache is warming, give it a minute" from "hung". Measured cost is 44.5 s on a folded 27B pack, so the distinction is the difference between a readable log and "serve never reported a port". 2. **`tests/serve_port.sh`'s default budget is now 90 s, not 30.** #1621 moves 44.5 s in front of the ready line, and the helper's `tries=300` x 0.1 s would time out on exactly the configurations these tests exercise, with the message #1531/#1545 spent effort removing. The default carries a comment saying why it is not 30 s, and a caller can still pass its own bound; with (1) in place a short budget now fails next to a `warming` line rather than silently. The breakdown of the 44.5 s is still owed and is the other review point -- the arithmetic in the PR body (112 first touches x ~4.3 ms) does not add up to 44.5 s on the folded route, which the reviewer was right to notice. Measuring it next.
|
Both review points are in at 1. so a caller polling for 2. 3. The breakdown, and it is not what I claimed. Your point stands and the numbers kill the story in the PR body:
So weight-cache first touches cannot be 44.5 s on this route by a factor of ~30, and the sentence in the PR body that attributed it to "112 first touches at 4.3 ms" is wrong — my own cold-window average was over launches, not over touches, and I multiplied it by the wrong count. Thank you for not letting that stand; it is exactly the kind of number that becomes gospel if it lands in a merged body. That leaves your candidate list, and the tie-break among them is a measurement I have not made yet: ELF/xclbin load-and-validate, a GTT upload of the packed weights, or the Blocked on that measurement, precisely: the device run needs RAM above 20 GiB by this lane's rule and the box is at 4 GiB available right now (a 27B serve dequantises a 5 GB lm-head before it warms anything). So the decomposition is the next device action, not a missing piece of will — and until it is measured the PR body should say "44.5 s, attribution pending" rather than a cause I have now falsified. I have not edited the body to add a wrong cause; say the word if you would rather I strike the attribution entirely and merge on the warm-up's own terms. |
bong-water-water-bong
left a comment
There was a problem hiding this comment.
VERDICT: READY at 39837349 — and specifically: the unadvertised hunk is gone
My earlier review's finding was that the PR carried a change nothing in its description mentioned — a NPU_INFER_DUMP_DIR block inside app/forward_serve.cpp, which is a diagnostic an operator would want to know exists and a reviewer needs to know is landing. It is no longer in the diff (grep -c NPU_INFER_DUMP_DIR app/forward_serve.cpp at this head: 0), so the PR now does exactly what it says: the warm-up announcement and the read-back budget it needs.
That is the right call, and for the reason the public/site split exists: a debug-dump hook is a separate, reviewable piece of work, and bundling it under "forward-serve warms the weight cache" is how an env var ends up in a binary with no documentation and nobody's name on it.
The rest stands as reviewed: the warm-up line is printed before the work (warming (weight cache; first request would otherwise pay it)), so a caller polling for readiness can tell "warming, give it a minute" from "hung" — which is the difference between a 30 s budget timing out on a 44.5 s warm-up and a message that says what is happening.
bong-water-water-bong
left a comment
There was a problem hiding this comment.
VERDICT: READY at 3983734
(An independent read. The READY already at this head opens with ## VERDICT, so the ^VERDICT: tally does not count it.)
The new commit 3983734 takes the reviewer's preferred option: a warming line before the pass and ready after it, so a caller can tell a slow start from a hang without retuning a number. That keeps ready meaning the same thing everywhere.
Checked:
buildis SUCCESS, the PR is MERGEABLE, andgit merge-treeonto current main is clean.bash -n tests/serve_port.shis clean.- The warm-up code itself is unchanged from my reading at
4157226: one four-token pass, a state reset, the cost printed, failing open, andNPU_SERVE_NO_WARMUP=1to skip it.
Notes (non-blocking):
- The 30 s → 90 s default in
serve_port_waitdoes not match its callers. None of the 12 scripts that call it startsforward-serve(git grepat this head: every caller drives1bit servewith a fake or CPU backend). So the commit's "pays it on exactly the configurations these tests exercise" doesn't hold today. The bump is harmless, since the wait returns as soon as the line appears or the pid dies, so it only lengthens a genuine hang from 30 s to 90 s. But the comment should say it is for a futureforward-servecaller, or the default should stay 30 s with that caller passing its own bound. - The 44.5 s breakdown is still owed, as the commit says: 112 × 4.3 ms ≈ 0.5 s on the folded pack. Until it is measured, the log line's "weight cache warm" may be naming the wrong cost.
Not run: forward-serve itself (needs an npu-hold ticket and the 27B pack).
|
VERDICT: CHANGES REQUESTED — one blocker, and it is the owner's own rule: this PR still carries the The blocker: a merged block is being re-carried
The warm-up itself is right, and the ordering is right
Two nits
What I did not runNo NPU ticket in this lane, so the 44.5 s figure and the claim that the first request no longer pays it are taken from the PR's own |
Agreeing with the blocker, and keeping the other one in view: the
|
… (prefill block 742 -> 696 ms, bit-identical) (engine#1416) (#1949) #1416's pack column is 0.13 ms/launch at main (7 % of a 16-row prefill block; the issue read 93 %): the 24 ms was the first-touch weight fill, removed from every request by #1621 and the image-fill change. What a block spends now is host work outside the launches (52 %) and device wait (29 %). The largest single host term was the per-(row, head) alpha/beta dot products of a GDN layer, serial inside the row loop: 77.5 ms of a 742 ms block. They now run as a second worksharing loop inside the parallel region the layer already opens for the recurrence (no new region). Each dot product is the same sequential loop and the build has no -ffast-math, so no bit moves. NPU_GDN_CHECK=1 recomputes the serial form per layer and compares bit patterns; a mismatch fails the call. Measured on bonsai2-27b-t2s2, A B B A in one npu-hold ticket, medians over 103 blocks per arm: alpha/beta 77.5/77.8 -> 13.1/13.5 ms, block wall 749/734 -> 704/688 ms (21.4/21.8 -> 22.7/23.3 rows/s), device wait unchanged, greedy text identical in all four arms; device check 336/336 layer passes identical. tests/gdn_batch_order_test now requires the alpha/beta check lines (fails on main: 0 lines) and drives a noncausal pack through step_batch(): every hybrid pack on the dev box is noncausal, so the test as merged failed before a GDN layer ran. Co-authored-by: bong-water-water-bong <bong-water-water-bong@1bit.gg> Co-authored-by: Claude Fable 5.2 <noreply@anthropic.com>
A first request has to touch every (layer, role) weight once. On the non-folded int8 route that is
q4nx_assemble_Bbuilding the weight matrix in float32 andpackB_intoquantising it, across ~112 projections. Measured on this box with the change in place:44.5 s, on the folded pack, where each first touch is only ~4.3 ms — 112 of them add up, and the non-folded route multiplies each by 20–70×. Left inside the first request, that looks exactly like a hang: engine #1605 has an 8-token request returning nothing in 150–420 s, and the
ready on http://…line is technically true and practically a lie about the next minute. I hit that confusion myself three times today before measuring why.The change runs one four-token batch pass through the same forward before the server announces binding, resets the state, and prints what it cost.
NPU_SERVE_NO_WARMUP=1keeps the old behaviour; a failed warm-up is reported and does not stop the server (the first request then pays it, as before).After it, on the same pack, a 130-token request completes in 20 s wall with
[prof] prerows atpack0.10–0.27 ms andwait2.9–3.4 ms per launch:which is what the steady state looks like when nobody is measuring the first touch.
What this does not fix: the 44 s itself. It moves the cost from "inside the first request, invisible" to "before ready, in the log" — the fix for the cost is to stop materialising float32 weight matrices per projection (analysed on #1416), and this PR is the honest signal in the meantime. If a maintainer would rather the server start instantly and lose the signal, that is a one-line reversal and I would not argue: the measurable part stands either way.
Scope check: one block in
app/forward_serve.cpp, no behaviour change to any request path, no new dependency.