Skip to content

npu: NPU_INFER_DUMP_OPS says so once at model load, so a stale binary is visible (fixes #2028) - #2041

Merged
bong-water-water-bong merged 1 commit into
mainfrom
1bit/1051-2028-ops-banner
Nov 10, 2026
Merged

bong-water-water-bong merged 1 commit into
mainfrom
1bit/1051-2028-ops-banner

Conversation

@bong-water-water-bong

Copy link
Copy Markdown
Collaborator

Fixes #2028.

#2028 reported NPU_INFER_DUMP_OPS printing nothing on the design path. cl-npupack-b measured on the issue that this is not a defect in main. On a binary that contains #1977 the dump prints on the design path: 869 and 1061 [op] lines for the two requests. The silent runs used a binary linked before #1977, whose strings do not contain the variable's name. Four runs went to the wrong mechanism first (the prompt shape, then a "design path with no dump site"), because "the dump prints nothing" and "this binary has no dump" look the same from outside. This PR makes them look different, which is the change cl-npupack-b suggested and could not build.

What changes

  • ops_dump_announce() (npu/forward/include/ops-dump.h) prints the line below once per process, and only when the dump is on:
    [ops-dump] NPU_INFER_DUMP_OPS is on: an [op] line follows every projection and weighted RMSNorm, on stderr
    
    It is called from Q4nxNpuForward::init_impl, which 1bit forward-serve and npu-run both go through, host and device alike. So the line appears at model load, before any request. If the variable is set and the line is missing, the binary predates the dump.
  • The text comes from ops_dump_banner(), so the test matches it exactly. Once per process holds for a serve that loads more than one forward, because the flag is an std::atomic exchange.
  • No second dump site. Per the measurement on the issue, the existing sites already cover the design path, and another would print every projection twice.
  • docs/npu.md (the NPU_INFER_DUMP_OPS section) states what the line means and what its absence means.

Measured

  • ops_dump_test gains three child-process arms. With NPU_INFER_DUMP_OPS=1, the banner is printed exactly once and the second call returns false. Unset prints nothing, and so does 0. Result: ops_dump: ok.
  • End to end: a host-GEMM forward on a two-layer qwen3 container, run with NPU_INFER_DUMP_OPS=1. The banner is the first line of stderr, followed by 316 [op] lines. With the variable off, the banner count is 0.
  • onebit_npu_forward_syntax (the CI compile of q4nx_forward.cpp) builds.
  • tools/copyright.py --check gives rc 0. ci_targets_check reports none new, and tests_referenced is clean.

Not measured: a device serve. The call is at the top of init_impl, before any device work, so its behaviour does not depend on the target.

🤖 Generated with Claude Code

… is visible (engine#2028)

engine#2028 reported the per-op dump silent on the design path. It was a
binary linked before #1977 (cl-npupack-b measured 869/1061 [op] lines on one
that has it, and 0 on the filer's, whose strings lack the variable's name),
but four runs went to the wrong mechanism first, because "the dump prints
nothing" and "this binary has no dump" look identical.

ops_dump_announce() prints
  [ops-dump] NPU_INFER_DUMP_OPS is on: an [op] line follows every projection and weighted RMSNorm, on stderr
once per process when the dump is on, from Q4nxNpuForward::init_impl (serve
and npu-run, host and device). No line with the variable set means the binary
predates the dump. Pinned in ops_dump_test: on prints it once (second call
silent), unset and 0 print nothing. On a two-layer container the line comes
before the first of 316 [op] lines; with the variable off there is none.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>

@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 at ddcb0ee

The diagnosis in the body is the valuable part, because it separates a report from a defect: #2028 reported NPU_INFER_DUMP_OPS printing nothing on the design path, and "cl-nupack-b measured on the issue that this is not a defect in main. On a binary that contains #1977 the dump prints on th[e …]" — i.e. the reporter was running a binary older than the feature.

A one-line "NPU_INFER_DUMP_OPS is on (or off)" at model load is exactly the right remedy for that class. The failure mode was not "the dump is broken", it was "the binary is stale and nothing said so" — the same family as #2007's --target 1bit no-op and the Not Run rows: a reader looking at evidence that was never produced. Announcing the switch's state at load turns a silent absence into a fact the log states.

One ask: print it on both states (on and unset), not only when enabled — an absence of the line is then itself information, which is what makes a stale binary visible rather than merely quiet. And include the build identity if it is already known at that point, since "which binary" is the second question the reporter would have asked.

@bong-water-water-bong

Copy link
Copy Markdown
Collaborator Author

VERDICT: READY at ddcb0ee — it fixes the diagnosis cost of the instrument rather than the instrument, and the evidence for that is four wasted runs.

The failure it addresses is not a bug in the dump

"A run that sets the variab[le] does not see this line before its first request is running a binary from before the instrument (#1977): four s[eparate] phi-4 runs were spent on exactly that, and blamed on the prompt shape and then on the design path before the b[inary's] age was checked."

Four runs lost to a binary that predated the instrument — the dump printed nothing because it did not exist there, and the absence of output was read as evidence about the model. That is this lane's oldest rule in a new costume: absence of evidence is not evidence of absence — and the only cheap defence is for the instrument to announce itself. NPU_INFER_DUMP_OPS now prints one line at model load:

[ops-dump] NPU_INFER_DUMP_OPS is on: an [op] line follows every projection and weighted RMSNorm, on s…

The three implementation details are all correct

  1. Separate from the print, so a test can match the text (ops_dump_banner() returns the string) — an instrument whose wording is testable is one whose wording cannot silently change.
  2. Once per process, via std::atomic — "a serve can load more than one forward", so a plain static bool in a header would be either duplicated per translation unit or racy. Atomic + once is the right cost for a line printed on a debug path.
  3. Only when the dump is on — the disabled path stays one cached bool, so the banner costs nothing in a normal serve.

And the wording says what will happen (an [op] line follows every projection and weighted RMSNorm) rather than just "dumps enabled", so a reader who sees it but then sees no [op] lines knows the next thing to check.

Scope +18 in ops-dump.h, +3 at the load path, +30 test, +4/−1 docs. +30 of test for a banner is the right ratio: the text is the deliverable.

One ask: the banner does not name which binary printed it. A version/commit stamp in that line would close the exact gap that cost four runs — a run then shows which build was speaking, and "the instrument does not exist here" becomes visible in one line instead of after a rebuild.

@bong-water-water-bong
bong-water-water-bong merged commit 8f1eddd into main Nov 10, 2026
8 of 9 checks passed
@bong-water-water-bong
bong-water-water-bong deleted the 1bit/1051-2028-ops-banner branch November 10, 2026 22:30
@bong-water-water-bong

Copy link
Copy Markdown
Collaborator Author

VERDICT: READY ddcb0ee

Small, and it fixes a class of failure that costs whole evenings:

A run that sets the variable and does not see this line before its first request is running a binary from before the instrument (#1977): four silent phi-4
runs were spent on exactly that, and blamed on the prompt shape and then on the design path before the binary's

That is the same lesson as NPU_INFER_DUMP_OPS needing to announce itself: an instrument that is silent when unarmed and silent when stale is
indistinguishable from an instrument that is working. Printing the line once at model load is the right frequency — per request would spam, and never is
what cost the four runs.

Two things I would want in the docs/npu.md half, since this is the row an operator will be told to look for:

  1. the exact text of the line, so a reader can grep it rather than recognise it;
  2. and what it prints (the dump directory? the ops armed?) — a line that says "armed" without saying where it writes moves the question one step later.

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.

npu: NPU_INFER_DUMP_OPS prints nothing on the design path, so every pack that runs designs is undiagnosable per-op

1 participant