Assert the access-log encoded-byte charge against every Unicode code point #172

Closed
opened 2026-08-18 00:32:55 +02:00 by clawbot · 2 comments
Collaborator

Recommended by the final independent review of #155. Deliberately NOT milestoned 1.0.0 — see the disagreement note at the end.

#146 states a hard per-line bound of 2,560 bytes for the access log, in README.md, in middleware.MaxAccessLogLineBytes and in maxCappedLineBytes. That bound holds only if encodedLogFieldBytes charges each rune at least what the log handler actually emits for it. That property is currently established by two independent exhaustive audits — but both lived in throwaway probes. The in-repo defence for an entire rune class is one subtest on one hand-picked code point (U+1000C).

That is the same recursion that broke that PR three times: a claim asserted at one level, unverified one level down. And headroom does not rescue it — a 4-byte-per-rune undercharge took a single field from 523 to 861 bytes in round 3, so three fields breach 2,560 outright.

Definition of done

  • A test asserts, for every one of the 1,112,064 code points, that encodedLogFieldBytes(r) is at least what the real handler emits — against BOTH slog.NewJSONHandler and slog.NewTextHandler, since they escape differently and that difference is exactly what broke round 3.
  • It fails when escapedAstralRuneBytes is reverted from 10 to 6, reporting a non-zero undercharge count.
  • It adds under 3 seconds to make test under -race.

Build the batched form, not the naive one

The reviewer measured both, and this is the detail worth carrying over: a batched version — 4,096 code points per handler call, 272 calls, comparing summed charge against summed emitted bytes — runs in 0.31s plain and 2.02s under -race, comfortably inside the suite's 30s timeout. The naive per-rune form takes 23 seconds and does not fit. Someone building the slow one first could reasonably conclude the test is infeasible; it is not.

Measure the MARGINAL emitted bytes of the real handler — a two-rune string minus a one-rune string — rather than modelling the escaper. That cancels the text handler's quoting flip and all per-call constants, and it means the test verifies the handler rather than a second copy of the assumptions under test.

Known-good reference values, so a correct implementation can be recognised: JSON 0 / TEXT 0 undercharged at present; reverting the astral charge to 6 gives TEXT 955086 with a max delta of 4. Surrogates are unreachable (CESU-8 decodes to RuneError with size 1 and the loop drops them). U+10000 is printable, so the !IsPrint && r >= 0x10000 guard is the right shape.

Why not 1.0.0, against the reviewer's recommendation

They argued for milestoning it. I am leaving it out, on the same test I applied to everything else in this milestone: this guards against a FUTURE regression in slog's escaping or in encodedLogFieldBytes, not against any present defect. The ceiling is correct today and that is established by two exhaustive audits built by different methods. Nothing scheduled before the tag touches this code. The guard earns its keep after 1.0, when a Go version bump could change strconv.Quote, which is precisely when nobody will be re-auditing by hand.

Implementation requirements

  • Branch from next, PR based on next, single commit, title ending (closes #N).
  • Do not modify TODO.md (see #112).
  • Run make bootstrap in a fresh clone before gating — browser assets are fetched at build time and not committed.
  • Gate on make check plus the Docker lint path with the cache defeated. All linting runs in Docker, never on the host.
Recommended by the final independent review of https://git.eeqj.de/sneak/webhooker/pulls/155. Deliberately NOT milestoned 1.0.0 — see the disagreement note at the end. https://git.eeqj.de/sneak/webhooker/issues/146 states a hard per-line bound of 2,560 bytes for the access log, in `README.md`, in `middleware.MaxAccessLogLineBytes` and in `maxCappedLineBytes`. That bound holds only if `encodedLogFieldBytes` charges each rune at least what the log handler actually emits for it. That property is currently established by two independent exhaustive audits — but both lived in throwaway probes. **The in-repo defence for an entire rune class is one subtest on one hand-picked code point** (`U+1000C`). That is the same recursion that broke that PR three times: a claim asserted at one level, unverified one level down. And headroom does not rescue it — a 4-byte-per-rune undercharge took a single field from 523 to 861 bytes in round 3, so three fields breach 2,560 outright. ## Definition of done - A test asserts, for every one of the 1,112,064 code points, that `encodedLogFieldBytes(r)` is at least what the real handler emits — against BOTH `slog.NewJSONHandler` and `slog.NewTextHandler`, since they escape differently and that difference is exactly what broke round 3. - It fails when `escapedAstralRuneBytes` is reverted from 10 to 6, reporting a non-zero undercharge count. - It adds under 3 seconds to `make test` under `-race`. ## Build the batched form, not the naive one The reviewer measured both, and this is the detail worth carrying over: a **batched** version — 4,096 code points per handler call, 272 calls, comparing summed charge against summed emitted bytes — runs in **0.31s plain and 2.02s under `-race`**, comfortably inside the suite's 30s timeout. The naive per-rune form takes **23 seconds** and does not fit. Someone building the slow one first could reasonably conclude the test is infeasible; it is not. Measure the MARGINAL emitted bytes of the real handler — a two-rune string minus a one-rune string — rather than modelling the escaper. That cancels the text handler's quoting flip and all per-call constants, and it means the test verifies the handler rather than a second copy of the assumptions under test. Known-good reference values, so a correct implementation can be recognised: JSON 0 / TEXT 0 undercharged at present; reverting the astral charge to 6 gives TEXT 955086 with a max delta of 4. Surrogates are unreachable (CESU-8 decodes to `RuneError` with size 1 and the loop drops them). `U+10000` is printable, so the `!IsPrint && r >= 0x10000` guard is the right shape. ## Why not 1.0.0, against the reviewer's recommendation They argued for milestoning it. I am leaving it out, on the same test I applied to everything else in this milestone: this guards against a FUTURE regression in slog's escaping or in `encodedLogFieldBytes`, not against any present defect. The ceiling is correct today and that is established by two exhaustive audits built by different methods. Nothing scheduled before the tag touches this code. The guard earns its keep after 1.0, when a Go version bump could change `strconv.Quote`, which is precisely when nobody will be re-auditing by hand. ## Implementation requirements - Branch from `next`, PR based on `next`, single commit, title ending ` (closes #N)`. - Do not modify `TODO.md` (see https://git.eeqj.de/sneak/webhooker/issues/112). - Run `make bootstrap` in a fresh clone before gating — browser assets are fetched at build time and not committed. - Gate on `make check` plus the Docker lint path with the cache defeated. All linting runs in Docker, never on the host.
clawbot self-assigned this 2026-08-18 00:32:55 +02:00
Author
Collaborator

Plan. On next the function is logfield.EncodedBytes in internal/logfield, and TestEncodedBytes_ChargesAtLeastWhatTheHandlersEmit checks it against both handlers for every code point below a dense ceiling, a list of chosen ones, and a stride sample above. Make that test cover every code point (surrogates skipped), in the batched form the issue describes: many code points per handler call, summed charge against the marginal bytes the real handler emits. It must fail, with a count of undercharged code points, when escapedAstralRuneBytes goes back to 6, and add under 3 seconds to make test under -race. The sampling code it replaces goes. Ignore the issue's old notes on make bootstrap and the 30s timeout.

Model: opus-5-5

Plan. On `next` the function is `logfield.EncodedBytes` in `internal/logfield`, and `TestEncodedBytes_ChargesAtLeastWhatTheHandlersEmit` checks it against both handlers for every code point below a dense ceiling, a list of chosen ones, and a stride sample above. Make that test cover every code point (surrogates skipped), in the batched form the issue describes: many code points per handler call, summed charge against the marginal bytes the real handler emits. It must fail, with a count of undercharged code points, when `escapedAstralRuneBytes` goes back to 6, and add under 3 seconds to `make test` under `-race`. The sampling code it replaces goes. Ignore the issue's old notes on `make bootstrap` and the 30s timeout. Model: opus-5-5
Author
Collaborator

Built in #442. TestEncodedBytes_ChargesAtLeastWhatTheHandlersEmit now checks logfield.EncodedBytes against every code point for both handlers, 4,096 code points to a logged value. It measures what the real handler writes for each batch as a line carrying the batch twice, less one carrying it once. A failing batch is measured again per code point, so the failure gives a count and names the first undercharged code point. The sampling is gone. The charges are worked out once, shared by both handlers. Test change only.

  • Judgement call: a batch's sum can hide one undercharged code point behind overcharged ones in the same batch, which is the cost of the batched form.
  • Judgement call: a failing run is slow (about 25 seconds), because failing batches are measured again one code point at a time to count them.

Model: opus-5-5

Built in https://git.eeqj.de/sneak/webhooker/pulls/442. `TestEncodedBytes_ChargesAtLeastWhatTheHandlersEmit` now checks `logfield.EncodedBytes` against every code point for both handlers, 4,096 code points to a logged value. It measures what the real handler writes for each batch as a line carrying the batch twice, less one carrying it once. A failing batch is measured again per code point, so the failure gives a count and names the first undercharged code point. The sampling is gone. The charges are worked out once, shared by both handlers. Test change only. - Judgement call: a batch's sum can hide one undercharged code point behind overcharged ones in the same batch, which is the cost of the batched form. - Judgement call: a failing run is slow (about 25 seconds), because failing batches are measured again one code point at a time to count them. Model: opus-5-5
Sign in to join this conversation.
1 Participants
Notifications
Due Date
No due date set.
Dependencies

No dependencies set.

Reference: sneak/webhooker#172