[mvanhorn]

feat(server): optional JSON lines for request start and end

What this changes

Default serve logging is unchanged: ip "GET / HTTP/1.1" 200 -, ended <id> reason=... prompt=N tokens=N after=Xs, and refused <id>: .... With serve --log-json, each request start and each request end is one compact JSON object on the existing [tensorfold] line (event start or end, the request id when one is already assigned, HTTP status when known, and prompt/tokens only when log.ended already has them). A refused request logs without inventing token counts. API keys, Authorization headers, and request bodies stay out of the line. GET /health is unchanged.

• Issue: n/a — not a new family, backend, or arithmetic; logging only.
• Stacked on: main
• atc overlap --json: ATC 0.9.6, run atc overlap --json --base origin/main at 4:23 AM PT, Fri Nov 13, 2026 (America/Los_Angeles) on head 2b88444. The snapshot was incomplete (complete: false; limitations: otherPullRequestsLimit, pullFilesUnavailable, pullRequestsLimit, timeLimit). changedFiles: 12. myPullRequests: none. Eighteen overlaps, all conflict: "unknown" (ATC could not run merge-tree). Most share zig/build/cuda_server_host.zig (this change only adds a test-request-log-host step) or zig/src/server/http_conn.zig (this change only adds a request id field and clears it on reuse). Open #2885 (serve --config FILE.toml) was not in the truncated snapshot; manual review: it shares README.md, zig/src/server/cli.zig, zig/src/server/main.zig, and zig/build/cuda_server_host.zig. The flag tables and README rows are in different regions and should merge cleanly. The usage_line in main.zig is the same concatenated string (this change appends [--log-json] after [--dashboard]; server: serve --config FILE.toml reads flags from a file #2885 prepends [--config FILE.toml]), so a textual conflict there is possible and is resolved by keeping both flags. No overlap with #3189 (config validate).

Checks on this head

• Head commit: 2b88444ec2539a7483acf337893d4d068b7789c6
• Lean checker, python3 tools/zig/lean_check.py, on the base and on this head: 341 problems on origin/main (c34ff56), 341 on this head, 0 new. None of the new findings are in the 12 changed files (the TENSORFOLD_LOG_TIME getenv report on log.zig:22 is pre-existing).
• Tests run, with the command and pass, fail and skip counts:
  • Fail before the JSON formatter: zig build test-request-log-host — 19 pass, 3 fail (nonzero). The three new JSON cases (start includes the id when known, end includes id and tokens; refused invents none, secrets stay out of the line) raised SyntaxError parsing the still-text lines. The default-text pin passed.
  • Pass after: DEMO_OUT=/tmp/osc-bulk-1113-demos/tensorfold-health-endpoint zig build test-request-log-host — 23 pass, 0 fail, 0 skip. Re-run on this head after review: the same step succeeded (Build Summary: 3/3 steps succeeded).
  • Host step that already runs on Linux without a GPU: zig build test-server-cpu — 1354 passed, 0 failed, 6 skipped (1360 total). The demo-capture case is one of those skips when DEMO_OUT is unset.
• CI: will run on this pull request. Not run from this Linux host.
• Not run, and why: GPU tests, a CUDA native product build, and test-cuda-host. This box has no GPU and the change only formats already-known log fields.

Receipt

n/a — this change only formats already-known request start and end fields. It cannot reach inference and does not change token arithmetic.

• Main against branch: n/a (cannot reach inference)
• Boxes it reaches: n/a (cannot reach inference)
• New switch? --log-json (store_true, default off). Off keeps today's text lines. On writes one JSON object a line for request start and end. Flag-only; no new environment variable.
• Environment, with the TensorFold commit, Zig and backend toolchain, machine and GPU, checkpoint and revision: Zig 0.17.0 host, commit 2b88444ec2539a7483acf337893d4d068b7789c6, no GPU, no checkpoint
• Paths and platforms the change reaches, which I ran and which I could not: Linux host zig build test-request-log-host and zig build test-server-cpu. Metal tensorfold and the CUDA product binary were not built here.
• Exactness, from tools/bench_concurrent.py --alone --serial or token_sha against "draft": false: n/a (cannot reach inference)
• Main against this branch, same machine and checkpoint, posted before asking for a run on our machines (or why you can't): n/a (cannot reach inference)
• Decode speed before and after, from tools/bench_openai.py: n/a (cannot reach inference)
• Prompt speed before and after: n/a (cannot reach inference)
• Licence of any new weights or drafter, or "n/a": n/a

Checklist

• The title and description match the head commit, including the receipt and the stack.
• New tests fail before the change, pass after it, and skip cleanly without their dependency.
• Comments and docstrings are one line. No measurements or history in the source.
• No personal data, machine names, internal hosts or local paths in the diff or its commits. No AI attribution lines.

Demo

Animated replay of real captured command output, not a live UI recording.

[ashhart]

Thanks @mvanhorn, --log-json is well contained. With the flag off, every log line is byte-for-byte what it was. The flag is set once before any thread starts. The JSON lines carry nothing the text lines don't, with no headers and no bodies.

Two fixes before it can land:

1. A long request line produces a JSON line that doesn't parse. jsonStart in zig/src/server/log.zig writes into an 8,192-byte buffer and stops when it's full, and line() cuts at 8,192 bytes too, but the server accepts request lines up to 65,536 bytes (http_conn.zig:10). So GET / followed by 9,000 as, sent with no key, logs {"event":"start",…,"request":"GET /aaaa… with no closing quote or brace. The same can happen on a refusal whose client text is mostly control bytes, since each one escapes to six. The smallest fix is to cut each string field the way refused already cuts its message, keeping room for the closing bytes, and to add a test with a request line over 8 KiB whose output parses.
2. The docs promise a start and an end line for each request, which the code doesn't do. The README row and RUNBOOK.md:466 say that.
   • A successful request writes no end: ended() runs only when the client left or the reply failed (chat.zig:280-288).
   • A refused request writes end before start, because the refusal is logged (openai.zig:249) before the response head writes the access line. For example, {"messages":5} to /v1/chat/completions logs end and then start with status 400.
   • Either name the events for what they are (for example access, ended, refused) or keep the names and document both facts.

Optional: the json request log: demo capture test writes files wherever DEMO_OUT points. Dropping it, and moving the new tests into a log_test.zig, would keep log.zig well under 600 lines.

• Synthena (Ash's Agent)

[mvanhorn]

Thanks, both check out against the diff.

1. Right, jsonStart copies c.requestline whole into the 8,192-byte buffer and only the refused path cuts its text, so a 9,000-byte request line (or a control-heavy client string at six bytes per escape) runs past the buffer and the closing quote and brace never get written. Cutting each string field with room left for the closing bytes, plus a test with a request line over 8 KiB that parses, is the fix I'd go with.

2. Agreed, start/end is the wrong promise. A completed request never calls ended(), and a refusal logs before the access line, so end comes first. Of your two options I'd rather name the events for what they are (access, ended, refused) than document an end that is sometimes missing and sometimes first, and fix the README and RUNBOOK rows to match.

On the optional point, fine by me to drop the DEMO_OUT demo capture test and move the tests to log_test.zig.

[ashhart]

Thanks @mvanhorn for checking both points against the diff, and for settling on event names. I agree that access, ended and refused are clearer than a start/end pair the code can't always produce.

The PR head is still 2b88444, though, and that commit doesn't have these changes yet, so both fixes are still open:

1. A long request line still produces a JSON line that doesn't parse (open). In zig/src/server/log.zig, jsonStart (line 209) writes c.requestline whole through jsonString into an 8,192-byte buffer and stops when the buffer is full, but the server accepts request lines up to 65,536 bytes (zig/src/server/http_conn.zig:10). I added a test in the style of "json request log: start includes the id when known", with GET /, 9,000 as and HTTP/1.1, and ran it with test-request-log-host. The line came out 8,193 bytes long and ended in aaa with no closing quote or brace, so std.json.parseFromSlice returned error.UnexpectedEndOfInput. As you said, the fix is to cut each string field (the refused message too, since a control byte escapes to six) and leave room for the closing bytes. Please add a test like that one that parses.
2. The README row and RUNBOOK.md:466 still promise a start and an end for each request (open). With the events renamed, please make both rows say when each line is written: access when the response starts, ended only when the client left or the reply failed, and refused for an error reply, logged before its access line.

Optional, as you offered: drop the json request log: demo capture test, which writes wherever DEMO_OUT points, and move the new tests into a log_test.zig. That keeps log.zig (576 lines with this PR) well under 600.

Main has moved since you opened this PR. The test-request-log-host line in zig/build/cuda_server_host.zig, the flag row in zig/src/server/cli.zig and the usage line in zig/src/server/main.zig (where --config FILE.toml has landed) no longer apply cleanly. That's ours to settle when it lands, so there's no need to rebase for it. On the current head with those placed, the five new tests pass and zig fmt is clean.

• Synthena (Ash's Agent)

[mvanhorn]

Pushed 0ce512a with both fixes, on top of d7f8544, which merges main into the branch.

1. Each JSON string now stops before an escape or character that would not fit, so the closing quote and brace always get written. The request line is cut at 4,096 bytes, and the refused message at the room left in its buffer. log_test.zig has a request line of GET /, 9,000 as and HTTP/1.1, and a 300-byte refusal of control bytes, and the test checks that both lines parse with std.json.parseFromSlice.
2. The events are now access, ended and refused. The README row and the RUNBOOK line say access is written when the response starts, ended only when the client left or the reply failed, and refused for an error reply, before its access line.

I also dropped the DEMO_OUT test and moved the tests to log_test.zig, so log.zig is 407 lines. In the merge I kept --log-json after --dashboard next to the new --config FILE.toml in the usage line, and the gone.conn.id = id line next to the new skip_request_log field.

On 0ce512a with Zig 0.17.0, zig build test-request-log-host test-vision-cli-host test-issue-934 passes, zig fmt --check is clean on the changed Zig files, and python3 tools/pr_check.py --base upstream/main --pr 3195 reports 0 errors.