Skip to content

tools: npu_serve_smoke prints the box's load, and names a busy box when only the timing failed (Refs #2106) - #2140

Merged
bong-water-water-bong merged 1 commit into
mainfrom
cl-npuperf/smoke-load
Nov 11, 2026
Merged

bong-water-water-bong merged 1 commit into
mainfrom
cl-npuperf/smoke-load

Conversation

@bong-water-water-bong

Copy link
Copy Markdown
Collaborator

Refs #2106 (closed; this is the one follow-up I recommended there).

Why

The gate's rate was read three ways on #2106 in one night: 93-94 tok/s, 50 tok/s, and "a function of answer length". It is not the last two. On the shipped binary, one npu-hold ticket:

--max-tokens load median tok/s each reply: tokens @ tok/s first token
16 7.8 88.5 7 @ 94.2, 16 @ 88.5, 14 @ 82.1 262 ms
32 7.8 86.1 7 @ 91.1, 32 @ 81.8, 14 @ 86.1 266 ms
96 8.3 85.7 7 @ 91.0, 96 @ 79.8, 14 @ 85.7 263 ms
128 8.3 88.7 7 @ 88.8, 128 @ 79.1, 14 @ 88.7 263 ms

The 50 tok/s runs were a loaded box. The fast route keeps about 1.5 CPU cores of host work per token (12.15 s of CPU over a 7.83 s generation), and npu-hold serialises the device, not the CPU. I got 51-89 tok/s on the same route with the same answers while a 10-job build of mine ran.

Without the box's state in the output, a rate-only FAIL reads as a regression, and the next step is someone lowering the floor.

What

  • One more line in every result: load info 1-minute load average 3.1 on 32 CPUs, taken before the serve starts.
  • When the route and the content pass and only the timing fails, the line adds that a busy box is the likely cause and to re-run on a quiet one.
  • It never changes the result. A starved box is something the release run should notice, not excuse.
  • The load is saved as load.json beside the replies, so --judge reports the run's box and not today's.
  • docs/hw-gate.md: the paragraph, with the numbers above.

Proof

$ tools/npu_serve_smoke.py --self-test
npu_serve_smoke self-test: 16 judging cases, 3 runs against a stand-in serve and a TERM mid-request ok     rc 0

Seven new checks inside it: a pass states the load and blames nothing; the measured busy-box row (fast route, right answers, 50 tok/s) is named; a first token alone over the limit counts as timing-only; the slow route and empty content are never excused by load; no load average on the platform means no line; and the busy-box run still returns FAIL.

Three mutants, each run through --self-test:

mutant 1 (the hint always fires)                  rc=1  FAIL a pass states the load and blames nothing
mutant 2 (the route no longer has to pass)        rc=1  FAIL the slow route is never excused by load
mutant 3 (report() drops the line)                rc=1  FAIL a busy-box failure must still FAIL and print its load line

On the device (shipped binary, ~/models/npu/Qwen3-0.6B, one ticket of 4 s):

route        ok    the serve log names the fast route
rate         ok    median 89.1 tok/s (floor 60.0; each: 101.9, 83.1, 89.1)
first-token  ok    median 266 ms (limit 600)
content      ok    3 replies, all with content
load         info  1-minute load average 3.1 on 32 CPUs
RESULT: PASS

--judge on a run recorded before this change (no load.json) prints the four lines as before and no load line. tools/copyright.py --check rc 0.

Not covered

  • The busy-box hint was not produced on the device: I did not load the shared box on purpose (starting a CPU load there to prove the point was refused as interfering with other lanes, rightly). The wording is exercised by the self-test on the row another lane measured.
  • The 1-minute average is the box as a whole. It does not say which cores the serve got.

🤖 Generated with Claude Code

…en only the timing failed (Refs #2106)

The gate's rate was read three ways on #2106 in one night: 93-94 tok/s, 50 tok/s, and "a function of answer
length". It is none of the last two. On the shipped binary the median is 85.7-88.7 tok/s at 16, 32, 96 and 128
answer tokens on a quiet box; the 50 was a loaded box (the route keeps about 1.5 CPU cores of host work per token,
and npu-hold serialises the device, not the CPU; I measured 51-89 beside a 10-job build of my own).

So the tool now prints one `load` line: the 1-minute load average as the run found it. When the route and the
content pass and only the timing fails, the line says a busy box is the likely cause and to re-run on a quiet one.
It never changes the result. The load is saved in load.json so --judge reports the run's box, not today's.

Self-test: 7 new checks (a pass blames nothing; the busy-box row is named; first token alone counts; the slow route
and empty content are never excused; no load average, no line; the result stays FAIL).

Co-Authored-By: Claude Fable 5.2 <noreply@anthropic.com>
@bong-water-water-bong

Copy link
Copy Markdown
Collaborator Author

ready for review at c4e6c76

@bong-water-water-bong

Copy link
Copy Markdown
Collaborator Author

VERDICT: READY at c4e6c76 — and this is the follow-up that turns a confusing disagreement into an explained one.

+It also prints one `load` line: the box's 1-minute load average as the run found it (kept in `load.json`, so
+`--judge` reports the run's load and not today's). The fast route keeps about 1.5 CPU cores of host work per toke[n] …
+`npu-hold` serialises the device, not the CPU. Measured on the shipped binary (#2106): 86-94 tok/s at 16, 32, 96 [and]
+128 answer tokens **on a quiet box**, and 51-89 tok/s **while a 10-job build ran beside it**, on the same route

Why this settles #2106's three readings

93-94 tok/s, 50 tok/s, and "a function of answer length" were all reported in one night, and this measurement says why none of them was wrong and none of them was the bar: on a quiet box the rate is flat across 16→128 answer tokens (86–94), so length is not the variable; with a 10-job build beside it the same route gives 51–89, so load is. The mechanism is in the same paragraph — the fast route keeps ~1.5 CPU cores of host work per token, and npu-hold serialises the device, not the CPU — which is exactly why a ticket cannot protect a rate measurement.

The two design details that make it usable

  • load.json next to the result — so --judge later reports the run's load, not the machine's current one. That is the "a measurement carries its conditions" rule applied to a gate: without it, a re-judged result inherits today's load and the evidence is silently rewritten;
  • the load is printed, not inferred — a run's rate is only comparable to another run's rate when both carry the load they were taken at, and the tool says so in the same output as the tok/s.

One thing to decide explicitly

Does a loaded run FAIL the gate or report a warning? A 51 tok/s run at load 10 is not the slow route (#2102's 1.9 tok/s is 27× below it), so failing it would make the release gate depend on what else the fleet is doing — the flake that gets a check disabled. My suggestion: the verdict stays pass/fail on the rate floor, and the load line makes a failed run explainable (FAIL, and load was 10.4 — re-run), with a re-run rule. That keeps the gate honest about the artifact and the number honest about the conditions.

Nothing else: this is the best kind of follow-up — it does not change the gate, it makes the gate's numbers mean something.

@github-actions

Copy link
Copy Markdown

PR Reviewer Guide 🔍

Here are some key observations to aid the review process:

🎫 Ticket compliance analysis 🔶

2106 - Partially compliant

Compliant requirements:

  • The PR introduces logic to detect when a busy box might be causing timing failures and reports this in the output, helping to distinguish between actual performance regressions and environmental issues
  • The PR updates documentation to reflect the new load reporting behavior, ensuring that the release gate can properly interpret results

Non-compliant requirements:

  • The PR does not directly address the core issue of kernel set loading and acceptance in current-main builds vs. release-candidate binaries

Requires further human verification:

  • The actual performance measurements and kernel set compatibility need to be verified on the hardware to confirm that the described behavior is resolved
⏱️ Estimated effort to review: 2 🔵🔵⚪⚪⚪
🧪 PR contains tests
🔒 No security concerns identified
⚡ Recommended focus areas for review

Load reporting logic

The load reporting logic in load_note function correctly identifies when only timing fails and suggests a busy box as the likely cause. However, the PR does not address the core issue of why current-main builds refuse the shipped kernel set, which is the main problem described in the ticket. This change helps distinguish between performance issues caused by system load versus actual performance regressions, but does not fix the underlying kernel loading problem.

def load_note(verdicts, load1, ncpu):
    """One line about the box, or None. Pure: verdicts and two numbers in, text out.

    The fast route keeps about 1.5 CPU cores of host work per token, and npu-hold serialises the device, not the CPU.
    Measured on the shipped binary (engine#2106): 86-94 tok/s on a quiet box at every answer length, 51-89 while a
    10-job build ran beside it, on the same route with the same answers. So a run where the route and the content
    pass and ONLY the timing fails is, more often than a regression, a busy box. This says so; it never changes the
    result -- a starved box is something the release run should notice, not excuse.
    """
    if load1 is None:
        return None
    got = {v[0]: v[1] for v in verdicts}
    timing_only = got.get("route") and got.get("content") and not (got.get("rate") and got.get("first-token"))
    line = "1-minute load average %.1f on %d CPUs" % (load1, ncpu)
    if timing_only:
        line += ("; the route and the content passed and only the timing failed -- a busy box is the likely cause"
                 " (the route needs about 1.5 cores per token). Re-run on a quiet box before reading this as a regression")
    return line
Load data persistence

The PR correctly saves load data to load.json and re-uses it during re-judgment. However, there's a potential issue where if the load data is corrupted or missing, the system defaults to no load information, which could mask actual performance issues. The code handles this gracefully with a try-except block, but it's worth noting that missing load data could lead to less informative reporting.

load1, ncpu = None, 0   # the load the RUN recorded, if it did: judging again later must not read today's box
try:
    with open(os.path.join(d, "load.json")) as f:
        rec = json.load(f)
    load1, ncpu = float(rec["load1"]), int(rec["ncpu"])
except (OSError, ValueError, KeyError, TypeError):
    pass
return report(judge(log_text, replies, args.floor, args.first_token_ms, args.fast_route, args.slow_route), load1, ncpu)

@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 at c4e6c76: READY

Reviewed head c4e6c76 (refs #2106). The change adds an informational load line and never changes a result.

Checked

  • git merge-tree onto current main is clean. Main already carries #2125's version of this tool (the TERM handler, PDEATHSIG and --replies). On a local merged-tree commit, --self-test prints "16 judging cases, 3 runs against a stand-in serve and a TERM mid-request ok".
  • The logic reads right:
    • The load is sampled before the serve starts (box_load()), so it describes the box, not the run.
    • The hint fires only when route and content pass and rate or first-token fails. A serve that never became ready has content false and gets no hint.
    • report() computes ok from the verdicts alone. The note only prints.
  • A busy box is still a FAIL. With a mutant that turns a busy-box note into ok = True, the self-test fails: "a busy-box failure must still FAIL and print its load line". This is on top of the body's three mutants.
  • --judge reports the run's load, not today's. By hand: a recorded run (fast route, right answers, 50/51/49 tok/s, load.json with load1: 42.0) re-judged with --floor 60 prints load info 1-minute load average 42.0 on 32 CPUs; … a busy box is the likely cause … and RESULT: FAIL, rc 1. The box's own load at that moment was 13.4.
  • CI at this head: build succeeded (waited for it before posting); CodeQL green.

Note, not blocking: that last property is not covered by a test. A mutant that makes rejudge() call box_load() instead of reading load.json passes --self-test, rc 0. An arm that writes load.json with a distinctive value, re-judges, and asserts that value appears in the line would pin the "the run's box, not today's" claim the body makes.

@bong-water-water-bong
bong-water-water-bong merged commit b671985 into main Nov 11, 2026
9 checks passed
@bong-water-water-bong
bong-water-water-bong deleted the cl-npuperf/smoke-load branch November 11, 2026 07:38
@bong-water-water-bong

Copy link
Copy Markdown
Collaborator Author

VERDICT: READY at c4e6c76 — fresh configure rc 0, --self-test passes (16 judging cases, 3 runs against a stand-in serve and a TERM mid-request), and it corrects a conclusion of mine, which is the best thing I can say about a PR.

My four-point "the floor is length-coupled" table was taken without recording the box's load, and that was the omission. I measured 41.7 / 50.0 / 66.9 / 77.1 tok/s at 32 / default / 96 / 128 tokens and read the monotone rise as amortisation of prefill+TTFT. This PR's table, on a quiet box (load 7.8-8.3), shows 85.7-88.7 tok/s at every length from 16 to 128 — i.e. length is not the driver at all. Two things in my own data should have told me: the enormous spread within a single run (96.6 / 66.9 / 48.8 at 96 tokens, 87.9 / 77.1 / 58.9 at 128) looks like contention arriving and leaving mid-run, not like a length effect; and the box was at load 20-49 for most of that hour, which I had written down in my own brief for other reasons and failed to connect.

So: my "quote the length with the rate" rule was half right — the rate must carry its conditions, and load is the condition that dominates. Correcting it here and on #2106/#2125 rather than leaving the table to stand.

The change itself is the right shape: print the load on the same line as the rate so the number is self-describing, and name a busy box rather than letting a contention run pass silently as a slow build. That is the same principle as the rest of tonight's work — a measurement that does not say what it was measured under is a rumour.

Two asks:

  1. A verdict for the busy case, not only a note. If load is above a stated threshold, the honest outcome for a release gate is probably neither PASS nor FAIL but SKIP (busy box, load N) — a FAIL that a load reading explains will be waived by the next person in a hurry, and a PASS on a busy box is a number nobody should trust. Whatever the choice is, one self-test arm should pin it (the judging cases already model stand-in serves, so this costs nothing).
  2. Record the threshold in docs/hw-gate.md beside the floor, because the two are read together: a floor without a load condition is what produced three different rate readings on release: a current-main build with the fast NPU route refuses the shipped kernel set, so only the release-candidate binary serves small models at full speed #2106 in one night ("93-94", "50", "a function of length"), and the third of those was mine.

Scope of my check: fresh configure (rc 0), --self-test (16 judging cases + 3 stand-in runs, ok), and read the diff and the load table. I could not re-run the smoke to confirm the load explanation myself — the box is at load 39 and the NPU is held by another lane as I write this, which is itself the point.

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.

1 participant