TestSixteenThousandCookiesAreRefusedWellWithinTheTimeLimit in internal/discriminator/answertime_test.go measures wall time and failed the race pass of make check at a load average of about 170 on 48 cores. It answered after 1.36 seconds, while the test wants under 1 second, half the 2-second time limit. It passed in the -v rerun of the same step and in the next make check. Nothing in the branch under test touched the package (#307).
At that load the test can turn next red on its own. The fix is the test's to decide. For example, it could measure the work the request causes instead of wall time.
Model: opus-5-5
`TestSixteenThousandCookiesAreRefusedWellWithinTheTimeLimit` in `internal/discriminator/answertime_test.go` measures wall time and failed the race pass of `make check` at a load average of about 170 on 48 cores. It answered after 1.36 seconds, while the test wants under 1 second, half the 2-second time limit. It passed in the `-v` rerun of the same step and in the next `make check`. Nothing in the branch under test touched the package (https://git.eeqj.de/sneak/smallwebwaf/pulls/307).
At that load the test can turn `next` red on its own. The fix is the test's to decide. For example, it could measure the work the request causes instead of wall time.
Model: opus-5-5
Plan. In internal/discriminator's tests only: the test keeps checking that sixteen thousand cookies are refused well within the time limit, but no longer fails because the host is busy. Measure the work the request causes, or compare against a baseline request timed in the same run, rather than wall time against a fixed second. No test, request or value is removed; the 2-second limit stays. Follow AGENTS.md: checks only through make targets, apart from uncommitted repeated runs of this test. make fmt, then flock -w 1800 /srv/code/tmp/.gate-smallwebwaf.lock make check; a flock timeout also exits 1, so read the output. Push over SSH and post with tea. Title ending (closes #308).
Model: opus-5-5
**Plan.** In `internal/discriminator`'s tests only: the test keeps checking that sixteen thousand cookies are refused well within the time limit, but no longer fails because the host is busy. Measure the work the request causes, or compare against a baseline request timed in the same run, rather than wall time against a fixed second. No test, request or value is removed; the 2-second limit stays. Follow `AGENTS.md`: checks only through `make` targets, apart from uncommitted repeated runs of this test. `make fmt`, then `flock -w 1800 /srv/code/tmp/.gate-smallwebwaf.lock make check`; a `flock` timeout also exits 1, so read the output. Push over SSH and post with `tea`. Title ending ` (closes #308)`.
Model: opus-5-5
clawbot
self-assigned this 2026-11-10 23:58:22 +01:00
Built in #310. Both tests that send sixteen thousand cookies now ask discriminator in a synctest bubble, where only waiting moves the clock. The bound stays under half the 2-second limit. The check that the Core Rule Set never read the request still covers the slow work. The observe-mode test with the same wall-time check got the same fix.
Model: opus-5-5
Built in https://git.eeqj.de/sneak/smallwebwaf/pulls/310. Both tests that send sixteen thousand cookies now ask discriminator in a `synctest` bubble, where only waiting moves the clock. The bound stays under half the 2-second limit. The check that the Core Rule Set never read the request still covers the slow work. The observe-mode test with the same wall-time check got the same fix.
Model: opus-5-5
A question: why does a request carrying 16,000 cookies take so long to refuse? It should fail at once.
A direction: the discriminator needs basic sanity checks at the very start of its chain, before any costly work.
What happens next:
The question is answered here with measurements, not guesses: how long such a request takes at this host's usual load without the race detector, where in rproxy and the discriminator it is refused, and what work comes before the refusal. (The 1.36 seconds in this issue was a test under the race detector, on a host at about three and a half times its core count.)
The direction is its own unit, linked below once filed: the cheap checks run first, ahead of any lookup, rule file or the Core Rule Set.
#310, this issue's test fix, goes on; it keeps checking that the Core Rule Set never reads such a request.
Model: opus-5-5
**Reading of sneak's two comments above:**
- A question: why does a request carrying 16,000 cookies take so long to refuse? It should fail at once.
- A direction: the discriminator needs basic sanity checks at the very start of its chain, before any costly work.
**What happens next:**
- The question is answered here with measurements, not guesses: how long such a request takes at this host's usual load without the race detector, where in `rproxy` and the discriminator it is refused, and what work comes before the refusal. (The 1.36 seconds in this issue was a test under the race detector, on a host at about three and a half times its core count.)
- The direction is its own unit, linked below once filed: the cheap checks run first, ahead of any lookup, rule file or the Core Rule Set.
- https://git.eeqj.de/sneak/smallwebwaf/pulls/310, this issue's test fix, goes on; it keeps checking that the Core Rule Set never reads such a request.
Model: opus-5-5
The sanity checks are #311; its first step answers the question above here, with measurements.
Model: opus-5-5
The sanity checks are https://git.eeqj.de/sneak/smallwebwaf/issues/311; its first step answers the question above here, with measurements.
Model: opus-5-5
Answer to the question above. It is not slow. Without the race detector, at this host's usual load (load average 66 to 88 on 48 cores), a request with 16,000 cookies is refused in about 2.6 ms through rproxy. discriminator takes about 0.3 ms of that. Both are medians of 300 requests with a throwaway script.
The 1.36 s came from the race detector on a host at load 170. The same test took a median of 0.24 s with the race detector, up to 1.17 s, and 0.08 s without it.
Where it is refused: in discriminator, by the header limits (header_limits), with 431. rproxy passes the request on, since it fits under the 32 KiB limit on the request line and headers.
The checks today, in order:
rproxy: request line and headers at most 32 KiB, else 431. Cheap.
The question itself: client address, request id, body at most 64 KiB, else 400. Cheap.
SWW_ALLOW_NETS: in memory.
Tag lists: in memory.
RouteWatch tags: costly for a new client, since RouteWatch is asked in the background.
SWW_DENY_NETS, then bans: in memory.
The lookup: costly. The lookup database, or GeoJS asked in the background. A request over the header limits does not wait for GeoJS, but GeoJS is still asked.
Country list, blocklists, CrowdSec: in memory.
DNS blocklists: costly, a DNS query for a new client.
AbuseIPDB: costly, an HTTP query for a client with an offence.
Tag refusals: in memory.
Rate limits: in memory. They count the request.
Trap paths: in memory.
Rule files: costly, 12 regexes over path, query and user agent.
Header limits: cheap, counts of header fields (100) and cookies (50).
Core Rule Set: costly.
Tag refusals again: in memory.
So every costly step but the Core Rule Set runs before the header limits.
The fix:#311 moves the header limits to the front, right after SWW_ALLOW_NETS. A request over them then causes no lookup, no query and no rule. Three things change for such a request:
The rate limits no longer count it.
A banned or denied client gets 431 instead of its refusal.
In observe mode it gets no lookup, so no lookup headers.
Cheap checks that need a new limit, not built:
A request line or a header line over 8 KiB. One 30 KB query string or cookie keeps the Core Rule Set busy for 0.27 to 0.48 s (median of 30, at load 300). nginx refuses such lines by default, so real clients stay under 8 KiB. Recommendation: add both as fixed limits with no setting, answered 414 and 431, as the header limits are.
An announced body over SWRP_MAX_REQUEST_SIZE is an existing limit, but rproxy applies it only after discriminator allows the request. Refusing it before the question would leave no request log line. Recommendation: leave it.
Model: opus-5-5
**Answer to the question above.** It is not slow. Without the race detector, at this host's usual load (load average 66 to 88 on 48 cores), a request with 16,000 cookies is refused in about 2.6 ms through `rproxy`. `discriminator` takes about 0.3 ms of that. Both are medians of 300 requests with a throwaway script.
The 1.36 s came from the race detector on a host at load 170. The same test took a median of 0.24 s with the race detector, up to 1.17 s, and 0.08 s without it.
**Where it is refused:** in `discriminator`, by the header limits (`header_limits`), with `431`. `rproxy` passes the request on, since it fits under the 32 KiB limit on the request line and headers.
**The checks today, in order:**
- `rproxy`: request line and headers at most 32 KiB, else `431`. Cheap.
- The question itself: client address, request id, body at most 64 KiB, else `400`. Cheap.
- `SWW_ALLOW_NETS`: in memory.
- Tag lists: in memory.
- RouteWatch tags: costly for a new client, since RouteWatch is asked in the background.
- `SWW_DENY_NETS`, then bans: in memory.
- The lookup: costly. The lookup database, or GeoJS asked in the background. A request over the header limits does not wait for GeoJS, but GeoJS is still asked.
- Country list, blocklists, CrowdSec: in memory.
- DNS blocklists: costly, a DNS query for a new client.
- AbuseIPDB: costly, an HTTP query for a client with an offence.
- Tag refusals: in memory.
- Rate limits: in memory. They count the request.
- Trap paths: in memory.
- Rule files: costly, 12 regexes over path, query and user agent.
- Header limits: cheap, counts of header fields (100) and cookies (50).
- Core Rule Set: costly.
- Tag refusals again: in memory.
So every costly step but the Core Rule Set runs before the header limits.
**The fix:** https://git.eeqj.de/sneak/smallwebwaf/issues/311 moves the header limits to the front, right after `SWW_ALLOW_NETS`. A request over them then causes no lookup, no query and no rule. Three things change for such a request:
- The rate limits no longer count it.
- A banned or denied client gets `431` instead of its refusal.
- In `observe` mode it gets no lookup, so no lookup headers.
**Cheap checks that need a new limit, not built:**
- A request line or a header line over 8 KiB. One 30 KB query string or cookie keeps the Core Rule Set busy for 0.27 to 0.48 s (median of 30, at load 300). nginx refuses such lines by default, so real clients stay under 8 KiB. Recommendation: add both as fixed limits with no setting, answered `414` and `431`, as the header limits are.
- An announced body over `SWRP_MAX_REQUEST_SIZE` is an existing limit, but `rproxy` applies it only after `discriminator` allows the request. Refusing it before the question would leave no request log line. Recommendation: leave it.
Model: opus-5-5
Blocking a user prevents them from interacting with repositories, such as opening or commenting on pull requests or issues. Learn more about blocking a user.
TestSixteenThousandCookiesAreRefusedWellWithinTheTimeLimitininternal/discriminator/answertime_test.gomeasures wall time and failed the race pass ofmake checkat a load average of about 170 on 48 cores. It answered after 1.36 seconds, while the test wants under 1 second, half the 2-second time limit. It passed in the-vrerun of the same step and in the nextmake check. Nothing in the branch under test touched the package (#307).At that load the test can turn
nextred on its own. The fix is the test's to decide. For example, it could measure the work the request causes instead of wall time.Model: opus-5-5
Plan. In
internal/discriminator's tests only: the test keeps checking that sixteen thousand cookies are refused well within the time limit, but no longer fails because the host is busy. Measure the work the request causes, or compare against a baseline request timed in the same run, rather than wall time against a fixed second. No test, request or value is removed; the 2-second limit stays. FollowAGENTS.md: checks only throughmaketargets, apart from uncommitted repeated runs of this test.make fmt, thenflock -w 1800 /srv/code/tmp/.gate-smallwebwaf.lock make check; aflocktimeout also exits 1, so read the output. Push over SSH and post withtea. Title ending(closes #308).Model: opus-5-5
Built in #310. Both tests that send sixteen thousand cookies now ask discriminator in a
synctestbubble, where only waiting moves the clock. The bound stays under half the 2-second limit. The check that the Core Rule Set never read the request still covers the slow work. The observe-mode test with the same wall-time check got the same fix.Model: opus-5-5
why does it take so long? 16000 cookies should be instant fail, no?
there need to be basic sanity tests in the discriminator very early in the chain
Reading of sneak's two comments above:
What happens next:
rproxyand the discriminator it is refused, and what work comes before the refusal. (The 1.36 seconds in this issue was a test under the race detector, on a host at about three and a half times its core count.)Model: opus-5-5
The sanity checks are #311; its first step answers the question above here, with measurements.
Model: opus-5-5
Answer to the question above. It is not slow. Without the race detector, at this host's usual load (load average 66 to 88 on 48 cores), a request with 16,000 cookies is refused in about 2.6 ms through
rproxy.discriminatortakes about 0.3 ms of that. Both are medians of 300 requests with a throwaway script.The 1.36 s came from the race detector on a host at load 170. The same test took a median of 0.24 s with the race detector, up to 1.17 s, and 0.08 s without it.
Where it is refused: in
discriminator, by the header limits (header_limits), with431.rproxypasses the request on, since it fits under the 32 KiB limit on the request line and headers.The checks today, in order:
rproxy: request line and headers at most 32 KiB, else431. Cheap.400. Cheap.SWW_ALLOW_NETS: in memory.SWW_DENY_NETS, then bans: in memory.So every costly step but the Core Rule Set runs before the header limits.
The fix: #311 moves the header limits to the front, right after
SWW_ALLOW_NETS. A request over them then causes no lookup, no query and no rule. Three things change for such a request:431instead of its refusal.observemode it gets no lookup, so no lookup headers.Cheap checks that need a new limit, not built:
414and431, as the header limits are.SWRP_MAX_REQUEST_SIZEis an existing limit, butrproxyapplies it only afterdiscriminatorallows the request. Refusing it before the question would leave no request log line. Recommendation: leave it.Model: opus-5-5