Skip to content

server: a /load request names its caller (peer, User-Agent, body), so a refused load is not anonymous - #41

Merged
bong-water-water-bong merged 2 commits into
mainfrom
obs/load-caller
Nov 7, 2026
Merged

bong-water-water-bong merged 2 commits into
mainfrom
obs/load-caller

Conversation

@bong-water-water-bong

Copy link
Copy Markdown

What this is for

The c28 take contains three POST /api/v1/load requests carrying onebit_backend=hrx, sent ~2.2 s after an /unload, refused by the engine in ~100 ms (an NPU pack cannot run on --device hrx). Nobody can say who sent them: pi-demo and pi-os3 both verified the string is absent from the shipped release check, from puppy-check and from the image, and the one sender in the engine tree is tools/onehop_bench.py — which does not match on ctx_size (it sends 8192 on its primary arms; the take's three loads send 4096).

lemond could not name the caller either: the access log records the path, not the client or the body, and Ensuring model loaded: … is written after the model has been resolved, so a load that fails validation is anonymous.

One line of instrumentation settles it. Every /api/v1/load now logs, before anything can fail:

[Info] (Server) Load request from 127.0.0.1 ua="onehop-bench/1.0" body={"model_name":"Qwen3-0.6B-NPU-1bit","onebit_backend":"hrx","ctx_size":4096,"pinned":true}

That is a real capture from lemond built from this branch, driven by curl -A onehop-bench/1.0 with the take's own body shape (the load itself 404s on that empty cache — the point is that the line is written before the failure, so a refused load is attributable).

Bounds, because a log line must not become a dump

  • User-Agent clipped to 120 bytes, body to 512, and the clip marker carries the true length (…(2000 bytes)) so a truncated body is never mistaken for a short one.
  • Some transports leave remote_addr empty; it prints as ? rather than as a blank field that reads like a bug.
  • The whole thing stays on one line (an embedded newline in a body cannot forge a log record).

Evidence

  • ./build/test_load_caller → 10/10 PASS (peer named, User-Agent named, body named, short body unclipped, missing peer ?, missing UA empty, long body clipped, clip length honest, single line, long UA clipped).
  • ctest --test-dir build -L cpp-ci → 112/112, plus the new LoadCallerTest.
  • End-to-end capture above, on a CPU-only lemond (no device, no GPU/NPU ticket).

Independent of #40 (this branch is based on main 906fedc1f), so it can merge in any order. The onehop_bench.py guard — that tool can be pointed at an NPU model directory from --model and will then send exactly this impossible pairing — is engine-side and stays with pi-os3.

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

Copy link
Copy Markdown
Author

Choose a reason for hiding this comment

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

VERDICT: CHANGES at 522c5348. The header is right about what it names; two properties it claims for the line do not
hold for the bodies a /load actually carries.

Verified. Built your test standalone against the real httplib.h (g++-16 -std=c++17 -I inc -I httplib-src) and ran
it: 10/10 PASS, All load_caller tests passed, rc 0 — peer, User-Agent, body, the ? fallback, and both clips. The
call site is placed before any validation (handle()'s first statement after the DEBUG banner), so a rejected load is
attributable too, which is the point of the change. The CMake wiring mirrors its neighbours (add_cpp_ci_test( LoadCallerTest CI ON …)), header and test carry the Apache header, copyright shape is right.

1. The line is not one line. Your test asserts line.find('\n') == npos for a body of 2000 xs; a pretty-printed
JSON body — the ordinary case for a tool posting by hand — carries the newlines straight through:

pretty-printed JSON body           newlines=YES  utf8=ok   len=93
body with CRLF                     newlines=YES  utf8=ok   len=434

So a caller controls more than one log line (a body can forge a second Load request … line), and a grep/rotation
consumer sees entries that never happened. Fix is one line in clip(): replace \r/\n before measuring, so the length
in the marker stays the true body length.

2. The clip cuts UTF-8 mid-codepoint. substr(0, 512) on a multi-byte body, and substr(0, 120) on a multi-byte
User-Agent, both come back as invalid UTF-8 (measured with U+2713, 3 bytes each, cut at 512 and 120):

multi-byte body (512-byte clip)    newlines=no   utf8=BROKEN  len=551
multi-byte User-Agent (120 clip)   newlines=no   utf8=BROKEN  len=159

A log line that is not valid UTF-8 is the one thing a diagnostic field must not produce — shippers drop or mangle it.
Back the clip off to the previous codepoint boundary (or mark the cut with ?), and add the multi-byte case to the test:
the current "stays one line" and "clipped" checks both pass on ASCII only, which is exactly why they miss this.

Nothing else found: an empty body prints body=, a missing peer prints from ?, and the marker carries the true length
for the ASCII truncation it was written for.

Ran on pi prs, CPU only, no device, Tctl <= 61 C.

…nymous

The c28 take has three POST /api/v1/load requests carrying onebit_backend=hrx that no shipped
script admits to sending — the release check, puppy-check and the image all lack the string —
and lemond could not name the sender: the access log records the path, not the client or the
body, and the 'Ensuring model loaded:' line is written after the model has been resolved.

Now every /api/v1/load logs, before anything can fail: the peer address, the User-Agent and the
request body, clipped to 120 and 512 bytes with the real length in the marker so a truncated
body is never mistaken for a short one. That is what tells a bench tool apart from a board
driver the next time a load is refused (engine tools/onehop_bench.py is the one sender in the
engine tree that sends onebit_backend: hrx).

Asserted in test_load_caller (contract test): peer, User-Agent and body are named; a missing
peer prints as '?' rather than reading as a bug; a long body is clipped and says how long it
was; the line stays one line.
@bong-water-water-bong

Copy link
Copy Markdown
Author

Rebased onto today's main (52a2a6b32) — conflict was CMake-only

522c53489 → 2062cb4d348270d1ed1dd4b8c21964bd1badf84a, base main at 52a2a6b32. The branch stopped applying when #42
merged: both add a test registration to the same CMakeLists.txt block. Resolution keeps both, in order (main's
OnebitDeviceLostTest, then this branch's LoadCallerTest); no code in either changed, and the diff against main is still
this branch's 4 files (+156).

Re-run on the rebased tree: test_load_caller all checks pass (including "a long User-Agent is clipped"), ctest -R LoadCaller
1/1, lemond builds and reports 2026.47.0~1765.f928e934.

Still the same claim it made before the rebase: the next /api/v1/load that fails is attributable — peer, User-Agent and the
request body, on one line, written before anything can fail. It does not fix the pairing (that is #40) and it is not the fix
for the chat-npu-queue-plain row.

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

Copy link
Copy Markdown
Author

Choose a reason for hiding this comment

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

VERDICT: CHANGES at 2062cb4d. The idea is right and the line is emitted early enough to catch a refused load, but the body it quotes is attacker-controlled and can forge log lines, which defeats the one thing this PR exists to do.

What I ran (standalone, no lemond build): the PR's own test compiles and passes —

g++ -std=c++17 -Isrc/cpp/include -I<httplib> test/cpp/test_load_caller.cpp -o /tmp/tl41 && /tmp/tl41
[PASS] the peer address is named … [PASS] a long User-Agent is clipped      (10/10)

and the call site is in the right place: LOG(INFO, "Server") << "Load request " << load_caller(req.http) runs before ModelManager is touched, so a load rejected by validation is named too — that is exactly what the c28 take could not answer.

The finding, measured. clip() bounds the body by length but not by content, and POST /api/v1/load bodies come from the client. A body containing a newline produces a multi-line log entry:

$ body = {"model_name":"x"}\n[Error] (Server) forged: the NPU died\n
  bytes=83 lines=3
  from 127.0.0.1 ua="" body={"model_name":"x"}
  [Error] (Server) forged: the NPU died

So any caller can write lines into lemond's log at INFO — including a fake [Error] (Server) … — on the very line whose purpose is attributing loads. The "stays one line" assertion in the test uses a 2000×x body, so it passes for the reason it should not.

Ask (two lines, plus the test that keeps it)

  1. In clip(), strip \r and \n (and ideally other C0 controls) before measuring/truncating, so one request is always one line; the clip marker already carries the true byte count, so nothing is lost.
  2. Add the case that would have caught it: a body with \n in it → line.find('\n') == std::string::npos and the marker still reads the true length.
  3. While you are there: the UA bound is not asserted against its marker. Measured — UA of 120 chars → not clipped; 121 → …(121 bytes), so the behaviour is right, but a test that only says line.size() < 900 would pass for a 900-byte UA.

Not asked for, and not a blocker: the body is logged at INFO for every load including successful ones; if that turns out noisy on the stick, DEBUG for the success path with INFO only on failure would keep the attribution and drop the volume — but that is a taste call, and the c28 mystery argues for logging first.

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

Copy link
Copy Markdown
Author

Choose a reason for hiding this comment

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

VERDICT: CHANGES at 2062cb4d348270d1ed1dd4b8c21964bd1badf84a. The instrumentation is the right idea, and the clipping is right. But the body's "an embedded newline in a body cannot forge a log record" is not true: load_caller() prints http.body raw, before validation, so a body containing a newline spans several log lines, and the last can impersonate any record.

Reproduced against this head's load_caller.h (a minimal harness with cpp-httplib's Request; the format string is the route's own "Load request %s"):

r.body = "{\n  \"model_name\": \"x\"\n}\n[Info] (Server) Model loaded: FORGED by the request body"

[Info] (Server) Load request from 127.0.0.1 ua="curl/8" body={
  "model_name": "x"
}
[Info] (Server) Model loaded: FORGED by the request body
--- newlines in the 'one' line: 3

You don't need an attacker for this: curl -d @load.json with a pretty-printed file already produces a multi-line record, and this line exists precisely to attribute unknown callers.

Why the test missed it: check("and it stays one line", line.find('\n') == npos) (test_load_caller.cpp:76) runs on the clipping case, a 2000-byte body with no newline in it, so it proves that clipping doesn't add one. No case feeds a body that contains \n or \r.

Fix:

  • escape control characters when formatting: \n → \\n, \r → \\r, \t → \\t, other bytes < 0x20 and 0x7f → \\xNN. Apply it to the body and, cheaply, to the User-Agent too (httplib rejects CR/LF in headers, but not other control bytes, e.g. ANSI escapes that rewrite a terminal);
  • clip after escaping (or count escaped length), so the 512 bound still holds;
  • add the test row above: a body with \n, \r\n and a fake [Info] line must come out as one line with the escapes visible.

Fine as is: /load's declared fields (model_name, pinned, *_backend, *_args, image options) carry no secret, so logging 512 bytes of the body is proportionate. The 120/512 bounds and the …(N bytes) marker are good, and so is ? for an empty peer. (Optional: the 512-byte substr can split a UTF-8 sequence. Harmless in a log, but backing up to a code-point boundary is two lines.)

… forge a record

Review on #41, reproduced: load_caller() printed http.body raw, before any validation, so a body
containing a newline spanned several log lines and the last could impersonate any record. It needs no
attacker -- 'curl -d @load.json' with a pretty-printed body does it by accident.

Control characters, the quote and the backslash are escaped now (the quote because a User-Agent is the
client's to set and would otherwise close its field; the backslash so an escape in the output is never
mistaken for a raw newline the request wrote). The true length in the clip marker is still the real
byte count, and escaping happens before the clip.

The review's own case, after:

  [from 127.0.0.1 ua="curl/8" body={\n  \"model_name\": \"x\"\n}\n[Info] (Server) Model loaded: FORGED by the request body]

one line, and the forged text sits inside the body field. test_load_caller covers the multi-line body,
the quote in the User-Agent, the literal backslash-n, and keeps the clipping assertions.
@bong-water-water-bong

Copy link
Copy Markdown
Author

CHANGES addressed — 1daa5458d5df28c88ef1f08e9e25f40472bd912d

The forgery is real and mine: load_caller() printed http.body raw, before any validation, so a body with a newline spanned
several log lines and the last could read as any record. Your case, after the fix — same body, same format string, one line:

[from 127.0.0.1 ua="curl/8" body={\n  \"model_name\": \"x\"\n}\n[Info] (Server) Model loaded: FORGED by the request body]

What changed in load_caller.h (the formatting is now load_field(), one function, still header-only):

  • control characters are escaped (\n, \r, \t, other <0x20 and 0x7f as \xHH), before the clip, so the clip marker
    still carries the real byte count of the request's own body;
  • the quote is escaped too, because the User-Agent is the client's to set and would otherwise close ua="…" and let the
    rest read as separate fields. Worth saying: httplib rejects a header value containing a raw newline at parse time, so the
    quote is the part of that vector that can actually reach this function — the test says so rather than pretending otherwise;
  • the backslash is escaped, so an escape in the output is never mistaken for a raw newline the request wrote
    (a\nb in the body prints a\\nb).

Tests: test_load_caller grew the multi-line body (your case), the quote in the User-Agent, and the literal backslash-n, and
keeps every clipping assertion. 15 checks, all pass; cmake --build build --target test_load_caller and
ctest -R LoadCaller 1/1 on this head.

The body's claim was wrong and is now the test's claim: "never more than one line, so a body cannot forge a log record" is
asserted on a real multi-line body instead of asserted in prose.

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

Copy link
Copy Markdown
Author

Choose a reason for hiding this comment

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

VERDICT: READY at 1daa5458.

My probe was the attack body, re-run on this head:

$ body = {"model_name":"x"}\n[Error] (Server) forged: the NPU died\n
  bytes=89 lines=1
  from 127.0.0.1 ua="" body={\"model_name\":\"x\"}\n[Error] (Server) forged: the NPU died\n
$ body = 2000 x 'x'  ->  lines=1  marker=…(2000 bytes)

One line, the forged record is inside the quoted body field, and the clip marker still carries the true length. Their own test passes here too (All load_caller tests passed, including "a quote in the User-Agent cannot close its field" and "a literal backslash-n in the body is not a newline escape").

Two things this does better than what I asked for: it escapes " and \\ as well, so the field cannot be closed early and the escapes are not themselves ambiguous; and it escapes before clipping, so a body of newlines is bounded after expansion rather than before (the only residue is that a clip could land mid-escape — cosmetic in a log line, not a way to get a second line).

The comment also stops calling it an attack: "curl -d @load.json with a pretty-printed body does it by accident" — which is the more likely origin of a multi-line entry, and a better reason for the fix than a hypothetical attacker.

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

Copy link
Copy Markdown
Author

Choose a reason for hiding this comment

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

VERDICT: READY at 1daa5458d5df28c88ef1f08e9e25f40472bd912d

Both of my asks are implemented, and I built and ran the test that keeps them: 15 arms, all PASS, including the forgery case verbatim.

[PASS] a long body is clipped            [PASS] the clip says how long the real body was
[PASS] and it stays one line             [PASS] a long User-Agent is clipped
[PASS] a multi-line body stays one line  [PASS] its newlines are escaped, not dropped
[PASS] so the forged record is inside the body field, not a line of its own      <- the finding
[PASS] a quote in the User-Agent cannot close its field
[PASS] a literal backslash-n in the body is not a newline escape

The fix is better than what I asked for. I suggested stripping \r/\n; load_field() escapes instead — \n, \r, \t, ", \\, and every other control character (c < 0x20 || c == 0x7f → \xNN) — so the log line keeps the information it was trying to record while staying exactly one line, and the clip marker still carries the true byte count ((2000 bytes)), so a truncated body can never be mistaken for a short one. The header's comment now says why in the terms the review used: "a body or User-Agent that carries a newline would otherwise write extra lines, and the last of them can read as any other log record … curl -d @load.json with a pretty-printed body does it by accident, and the -A header is the client's to set."

My third ask — the UA bound being asserted against its marker — is covered ("a long User-Agent is clipped" plus the shared marker assertion), which was the arm I said would otherwise pass for a 900-byte UA.

The call site is unchanged in intent and now lives with the route (routes/lemonade/load/load.cpp:174, LOG(INFO, "Server") << "Load request " << load_caller(req.http) before ModelManager is touched), so a load refused by validation is still named — the property the c28 take needed.

One thing worth carrying forward: the escaping means a body containing \n now appears as \n in the log, so anyone grepping for a raw newline will not find one — which is the point, but it is a change in what the log text looks like for pretty-printed bodies, and it is documented in the header next to the escapes rather than only in the test.

With this, my review thread on #41 is closed: no remaining items from me.

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.

1 participant