chadtmiller.com/knotless
git that lives in your Atmosphere account
A long poll is never slow, in the request log or the usage stats
MergedThis adds a hand-kept list of long-poll routes (awaitSpaceWrites, getDelegation). Served gains a waits flag that observe sets from that list. The request log then keeps a long poll at info however long it takes. The usage tally also skips over_half and over_two for those routes. I found no bugs.
- Usage tally: it matches on the route string
surfacereturns. For these routes that string is the matched pattern unchanged, so the comparison is sound. - Failures: a 5xx long poll still logs at error, because only the slow branch is bypassed.
- Changeset:
Servedis incrates/knotless/src, but the body has theChangeset: noneline, whichcheckaccepts. - Docs:
deploy/README.mdanddocs/observability.mdare updated. - Tests: there is one for the request log and one for the tally.
I did not look at the checks, and the pull's body leaves the build and tests to CI. The one thing that could still fail there is the served_and_summarized assertions. The new fifth line shifts later indices if the test reads them.
The pull keeps long-poll routes (awaitSpaceWrites, getDelegation) at info in the request log and out of the slow tallies. The logic is sound. A 5xx long poll still logs at error, and the docs are updated.
One test will fail, though. My round-1 review flagged this risk. The new fifth request line in served_and_summarized pushes the "cache fill failed" line from index 4 to 5, but the assertion still reads lines[4]. The test and check runs are still queued or running, so CI hasn't caught it yet.
crates/knotless/src/telemetry.rsline 926Outdated
assert_eq!(&levels[..5], ["DEBUG", "INFO", "ERROR", "WARN", "INFO"]); | |
assert_eq!(lines[2]["error"], "PDS down"); | |
assert_eq!(lines[2]["http.route"], "/{authority}/{repo}"); | |
assert_eq!(lines[1]["http.response.status_code"], 200); |
This line now reads the long-poll request line, which is at INFO, not the cache failure. The served loop writes five lines, so "cache fill failed" is at lines[5]. This assertion will fail. Change it to lines[5], or find the line by message as summary does.
My earlier request is done. The long-poll log assertion now lives in its own test, long_polls_are_not_slow. served_and_summarized is back to four requests, so lines[4] still points at "cache fill failed". The logic is unchanged and I found no new problems. CI had not finished when I looked, so the test and check runs are untested.
8 passed, 2 skipped
What changes
A request to a route that waits on purpose, a long poll (
awaitSpaceWrites,getDelegation), is logged at info however long it takes, and the usage stats count it but never as over half a second or two.knotless::telemetry::Servedgainswaits, which knotless-serve sets from its list of such routes.Why
awaitSpaceWritesholds each request 25 seconds by design. On prod it was 4,025 of the 4,533requestlines at warn in the last 14 hours, and each counted over two seconds in the stats' slow routes and slow hours, so what was really slow was hard to see.How it was checked
A unit test each: the request log puts a long poll at info, and the usage tally counts one with no slow requests. The rest is left to CI.
Shortcomings
The list of routes is kept by hand; a new long poll has to be added to it.
Changeset: none
🤖 Generated with Claude Code