Repository navigation
analytics: say when a stream read came back at the cap - #1704
Merged
Merged
Conversation
The windows log already reports read and served. A field log showed why that is not enough: hr[read=1792781 served=1939063] against rr[read=3727610 served=93980] on the same cold pass — one stream splicing half its rows, the other almost none — with no way to tell which of the three refusal causes fired. One of those causes is also a bug. The reads are ORDER BY ts ASC LIMIT, so a read that comes back at the cap has dropped its NEWEST rows, and the day is then scored on a window missing its tail. The window already computes that (`nowTruncated`) to decide whether the buffer may be spliced; it simply never said so. The same log has a strap at 192,680 rows against the 200,000 cap — 96% — so this is not a hypothetical for that device. A counter beside rowsRead and rowsServed, and two fields on the line: analyzeRecent windows hr[read=… served=… truncated=0] rr[read=… served=… truncated=17] A truncated EXTENSION that the splice recovers by re-reading the window whole is deliberately NOT counted. Nothing is lost on that path, and counting it would cry wolf on the one number here that means a score may be wrong rather than merely slow. This detects; it does not cure. Whether the answer is paginating past the cap or raising it should not be picked before knowing whether truncation fires at all, and for which stream. Both twins live in Packages/StrandAnalytics, so both sides are covered by default CI without app-build. Verified: 4,713 Android tests, 0 failures with --rerun-tasks --no-build-cache, including the analyzeRecentOnCpu bytecode budget guard; the Swift logLine compiled standalone and printed strings byte-identical to the Kotlin expectations. The Swift package suite itself cannot run in WSL (GRDB needs sqlite3.h), so it rides on swift-packages.yml.
… tested Two re-review passes over the counter itself. The first pass shipped it untested. SlidingStreamWindowTest existed on both platforms with exactly the right harness — window(limit) forces truncation — and the only new test asserted the log line's string format, not that the counter ever moves. Covered now on both sides, and the two suites pin an identical set of seven cases. The second pass found the comment justifying the design was false. It said a truncated extension "recovers by re-reading whole, nothing was lost there, so it is deliberately NOT counted". But the extension's range is a SUBSET of the window it re-reads, so head.size >= limit forces full.size >= limit: that path always ends truncated, and the case the comment described cannot occur. The third pass found the test written to fix the second was vacuous. A truncated read makes cachedTruncated true, which is the planner's FIRST guard, so the follow-up call is a plain full read and the Extend branch is never reached. It passed for the wrong reason, and the corrected comment then cited it as proof of something it did not test. That branch turns out to be unreachable from a uniform backward walk at all: reaching it needs a buffer that is valid AND an extension that overruns the cap, and a truncated read never leaves a valid buffer. Renamed to eachTruncatedWindowCountsSeparately, which is what the test genuinely pins — the counter is windows-that-lost-rows, not passes — and both source comments now state the reachability limit rather than imply coverage that does not exist. Also checked this pass, no changes needed: nothing anywhere parses the windows line, so the format change breaks no tooling; failedRead leaves all three counters alone, consistent with rowsRead and rowsServed; and the windows are built per pass, which is what makes the number readable. Verified: 4,715 Android tests, 0 failures with --rerun-tasks --no-build-cache, including the analyzeRecentOnCpu bytecode budget guard.
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
1 participant
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Found while reading a field strap log. Small, diagnostic-only, both platforms.
The gap
The windows line already reports
readandserved. That log showed why it is not enough — one cold pass:Same cap, near-identical per-window demand, wildly different outcomes, and no way to tell which of the three refusal causes fired — truncation, an owner flip, or a gap left by a dayCache hit. I could not determine it from the log, and that is the instrumentation's fault, not the log's.
Why truncation specifically
One of those three causes is also a bug. The reads are
ORDER BY ts ASC LIMIT, so a read returning the cap has dropped its newest rows, and the day is then scored on a window missing its tail with nothing anywhere saying so.The same log has that device at 192,680 rows against the 200,000 cap — 96% — with
rawRowsstill climbing across the day. So this is not hypothetical for that strap; it is a few weeks of data away.The window already computes the fact (
nowTruncated) in order to decide whether the buffer may be spliced. It just never reported it.The change
A counter beside
rowsRead/rowsServed, and two fields on the line:A truncated extension that the splice recovers by re-reading the window whole is deliberately not counted. Nothing is lost on that path, and counting it would cry wolf on the one number here that means a score may be wrong rather than merely slow.
Nothing on the scoring path moves — it is a counter, so it cannot change a number.
Scope
This detects; it does not cure. Whether the answer is paginating past the cap or raising it should not be chosen before knowing whether truncation fires at all, and on which stream. Same order the REM funnel and the offload diagnostics were done in.
Verified
Both twins live in
Packages/StrandAnalytics, so both sides are covered by default CI — no app-build needed.--rerun-tasks --no-build-cache, including theanalyzeRecentOnCpubytecode budget guard (the call site grew, so that one matters here).logLinecompiled standalone and printed exactly them.sqlite3.h), so that half rides onswift-packages.ymlin this PR.