Keep counts not written by the request's deadline in memory (closes #224) #235

Open
clawbot wants to merge 1 commits from issue-224-test-parallelism into next
Collaborator

Closes #224.

Cause. Past its deadline, the request in TestService_Get_ReturnsByItsDeadline still waited, with no deadline, to write its miss count, in pixad for the one database connection every request shares.

Fix. Each count write keeps the request's deadline but not its cancellation, so a request with time left writes its counts itself. A count not written by the deadline is added to sums the Cache keeps in memory, which Stats includes. One goroutine of the Cache writes those sums one UPDATE at a time, so at most that write waits for the database. Stats and that write hold one mutex, so Stats counts each write once. The handlers' stop hook lets a write under way finish, then writes what is left before the database closes.

-parallel 4 stays: a test per CPU at once still starves a timed request on a busy host (#224 (comment)).

Not in the diff. On next's code each new test fails once the two new Cache methods are stubbed out.

Disclosures:

  • Deviation: the canonical test command in REPO_POLICIES.md has no -parallel.
  • Judgement call: sums unwritten when the shutdown time runs out are logged with their values, and lost unless their write is under way; pixad exits with 1.
  • Judgement call: a write the SQLite driver reports failed as its deadline passes, just after it committed, is counted twice.
  • Unverified: counts a processing adds after the last write at shutdown, such as one still fetching after its request left, are lost.
  • Unverified by a test: Stats counts each write once.

Model: opus-5-5

Closes https://git.eeqj.de/sneak/pixa/issues/224. **Cause.** Past its deadline, the request in `TestService_Get_ReturnsByItsDeadline` still waited, with no deadline, to write its miss count, in pixad for the one database connection every request shares. **Fix.** Each count write keeps the request's deadline but not its cancellation, so a request with time left writes its counts itself. A count not written by the deadline is added to sums the `Cache` keeps in memory, which `Stats` includes. One goroutine of the `Cache` writes those sums one `UPDATE` at a time, so at most that write waits for the database. `Stats` and that write hold one mutex, so `Stats` counts each write once. The handlers' stop hook lets a write under way finish, then writes what is left before the database closes. `-parallel 4` stays: a test per CPU at once still starves a timed request on a busy host (https://git.eeqj.de/sneak/pixa/issues/224#issuecomment-133078). **Not in the diff.** On `next`'s code each new test fails once the two new `Cache` methods are stubbed out. Disclosures: - Deviation: the canonical test command in `REPO_POLICIES.md` has no `-parallel`. - Judgement call: sums unwritten when the shutdown time runs out are logged with their values, and lost unless their write is under way; pixad exits with 1. - Judgement call: a write the SQLite driver reports failed as its deadline passes, just after it committed, is counted twice. - Unverified: counts a processing adds after the last write at shutdown, such as one still fetching after its request left, are lost. - Unverified by a test: `Stats` counts each write once. Model: opus-5-5
clawbot added the needs-review label 2026-10-08 14:30:59 +02:00
clawbot self-assigned this 2026-10-08 14:30:59 +02:00
Author
Collaborator
  1. internal/imgcache/service.go:182: the request can return late in pixad itself, not only in the test process. After its deadline, Get still writes the miss count with no deadline (context.WithoutCancel). So the request waits for pixad's one database connection (internal/database/database.go:271), which every request's queries and the eviction loop share. Go hands a freed connection to a waiting caller picked at random, so under load that wait has no limit. The upstream fetch count (line 456) and the transform count (line 538) do the same on the path that the request running the processing waits for after its deadline. In this case the definition of done of #224 asks for a code fix. The PR body's judgement call to keep the write as it is describes this defect. Acceptable: after its deadline the request waits for no database write. A count it has not written by then is still written afterwards, without the request waiting for it, so no count is lost (#56). Existing tests stay unchanged. A new test holds the database connection while a request with a held fetch reaches its deadline. It checks that the request returns soon after, and that its miss is counted once the connection is free.
  2. Dockerfile:35-39 and TODO.md:33-40: both say the SQLite wait happens only in the test process. But the SQLite call the late request waits on after its deadline is the miss count write from item 1, and pixad waits on it too. Acceptable: once item 1 is fixed, the comment and the entry give only the reason for -parallel 4 that still holds (tests waiting to be scheduled), and the commit message and PR body name the cause the same way.

Judgement call: the deviation from the test command in REPO_POLICIES.md is accepted. That document requires the rerun with -v, -count=1 and -timeout 90s, which the command keeps, and gives the other flags only as an example.
Judgement call: a request that runs a conversion still waits for it after its deadline, since the image processor does not stop a conversion under way. That is outside this issue's held-fetch case and is not counted here.

Model: opus-5-5

1. `internal/imgcache/service.go:182`: the request can return late in pixad itself, not only in the test process. After its deadline, `Get` still writes the miss count with no deadline (`context.WithoutCancel`). So the request waits for pixad's one database connection (`internal/database/database.go:271`), which every request's queries and the eviction loop share. Go hands a freed connection to a waiting caller picked at random, so under load that wait has no limit. The upstream fetch count (line 456) and the transform count (line 538) do the same on the path that the request running the processing waits for after its deadline. In this case the definition of done of https://git.eeqj.de/sneak/pixa/issues/224 asks for a code fix. The PR body's judgement call to keep the write as it is describes this defect. Acceptable: after its deadline the request waits for no database write. A count it has not written by then is still written afterwards, without the request waiting for it, so no count is lost (https://git.eeqj.de/sneak/pixa/issues/56). Existing tests stay unchanged. A new test holds the database connection while a request with a held fetch reaches its deadline. It checks that the request returns soon after, and that its miss is counted once the connection is free. 2. `Dockerfile:35-39` and `TODO.md:33-40`: both say the SQLite wait happens only in the test process. But the SQLite call the late request waits on after its deadline is the miss count write from item 1, and pixad waits on it too. Acceptable: once item 1 is fixed, the comment and the entry give only the reason for `-parallel 4` that still holds (tests waiting to be scheduled), and the commit message and PR body name the cause the same way. Judgement call: the deviation from the test command in `REPO_POLICIES.md` is accepted. That document requires the rerun with `-v`, `-count=1` and `-timeout 90s`, which the command keeps, and gives the other flags only as an example. Judgement call: a request that runs a conversion still waits for it after its deadline, since the image processor does not stop a conversion under way. That is outside this issue's held-fetch case and is not counted here. Model: opus-5-5
clawbot added needs-rework and removed needs-review labels 2026-10-08 15:03:56 +02:00
clawbot force-pushed issue-224-test-parallelism from bd700650e0 to df7fff0ce1 2026-10-08 15:29:11 +02:00 Compare
clawbot force-pushed issue-224-test-parallelism from df7fff0ce1 to 2a7af1b1be 2026-10-08 15:33:47 +02:00 Compare
clawbot changed title from Run at most 4 tests of a package at once in the test phase (closes #224) to Stop waiting for count writes after a request's deadline (closes #224) 2026-10-08 15:44:14 +02:00
Author
Collaborator

Rework, one line per finding:

  1. Fixed: each count write (hit, miss, upstream fetch, transform) runs through writeCount, which the request waits for only until its deadline; cleanShutdown waits for those writes within ShutdownTimeout and reports any left. The new tests are in internal/imgcache/count_writes_internal_test.go; the existing tests are unchanged.
  2. Fixed: the Dockerfile comment, the TODO.md entry, the commit message and the PR body name the miss count write as the cause and give scheduling as the one reason -parallel 4 stays.

Model: opus-5-5

Rework, one line per finding: 1. Fixed: each count write (hit, miss, upstream fetch, transform) runs through `writeCount`, which the request waits for only until its deadline; `cleanShutdown` waits for those writes within `ShutdownTimeout` and reports any left. The new tests are in `internal/imgcache/count_writes_internal_test.go`; the existing tests are unchanged. 2. Fixed: the `Dockerfile` comment, the `TODO.md` entry, the commit message and the PR body name the miss count write as the cause and give scheduling as the one reason `-parallel 4` stays. Model: opus-5-5
clawbot added needs-review and removed needs-rework labels 2026-10-08 15:44:22 +02:00
Author
Collaborator
  1. internal/imgcache/service.go:293: writeCount adds to countWrites while WaitForCountWrites (line 225) may be waiting on it. sync.WaitGroup does not allow an add from zero while a wait is under way, and Go panics when it catches one ("WaitGroup is reused before previous Wait has returned"), so pixad can crash at shutdown instead of exiting with its error. In pixad, count writes start during that wait from requests still running once ShutdownTimeout has passed (WaitForCountWrites returns, but its Wait keeps running), and from the processing that goes on after its request left (lines 383-386), which neither wait at shutdown covers. Acceptable: once the wait at shutdown has begun, no count write is added to what it waits on, on either path; a design with no such wait, as in item 2, also meets this. The PR body's "Unverified" disclosure then says what that path does.
  2. internal/imgcache/service.go:290-313: nothing limits how many count writes wait for pixad's one database connection. Each count not written by its request's deadline stays behind as a goroutine waiting for that connection, beside new requests' reads. When the database falls behind, the case this change is about, every request that times out adds more, so under sustained load they and their memory grow without limit. Acceptable: however many requests pass their deadline, the count writes waiting for the database stay bounded and no count is lost; for example, the counts not yet written are added up in memory (CODE_STYLEGUIDE_GO.md names sync/atomic for counters) and one goroutine at a time writes the sums, which shutdown writes once more before the database closes.
  3. internal/imgcache/service.go:229-234: given a context that has already ended, WaitForCountWrites reports counts unwritten even when none are pending, as the select sees the context end before its goroutine runs. So whenever the HTTP server's shutdown uses up ShutdownTimeout, pixad logs "counts still being written at shutdown" and exits 1 although no count is being written. Acceptable: it reports unwritten counts only when some are pending, with a test for an ended context and nothing pending.
  4. PR body: about 270 words. Acceptable: under about 250, with the disclosures kept.

Judgement call: the processing that goes on after its request left can still write its counts after the database has closed, as it could before this change; not counted here.

Model: opus-5-5

1. `internal/imgcache/service.go:293`: `writeCount` adds to `countWrites` while `WaitForCountWrites` (line 225) may be waiting on it. `sync.WaitGroup` does not allow an add from zero while a wait is under way, and Go panics when it catches one ("WaitGroup is reused before previous Wait has returned"), so pixad can crash at shutdown instead of exiting with its error. In pixad, count writes start during that wait from requests still running once `ShutdownTimeout` has passed (`WaitForCountWrites` returns, but its `Wait` keeps running), and from the processing that goes on after its request left (lines 383-386), which neither wait at shutdown covers. Acceptable: once the wait at shutdown has begun, no count write is added to what it waits on, on either path; a design with no such wait, as in item 2, also meets this. The PR body's "Unverified" disclosure then says what that path does. 2. `internal/imgcache/service.go:290-313`: nothing limits how many count writes wait for pixad's one database connection. Each count not written by its request's deadline stays behind as a goroutine waiting for that connection, beside new requests' reads. When the database falls behind, the case this change is about, every request that times out adds more, so under sustained load they and their memory grow without limit. Acceptable: however many requests pass their deadline, the count writes waiting for the database stay bounded and no count is lost; for example, the counts not yet written are added up in memory (`CODE_STYLEGUIDE_GO.md` names `sync/atomic` for counters) and one goroutine at a time writes the sums, which shutdown writes once more before the database closes. 3. `internal/imgcache/service.go:229-234`: given a context that has already ended, `WaitForCountWrites` reports counts unwritten even when none are pending, as the `select` sees the context end before its goroutine runs. So whenever the HTTP server's shutdown uses up `ShutdownTimeout`, pixad logs "counts still being written at shutdown" and exits 1 although no count is being written. Acceptable: it reports unwritten counts only when some are pending, with a test for an ended context and nothing pending. 4. PR body: about 270 words. Acceptable: under about 250, with the disclosures kept. Judgement call: the processing that goes on after its request left can still write its counts after the database has closed, as it could before this change; not counted here. Model: opus-5-5
clawbot added needs-rework and removed needs-review labels 2026-10-08 16:23:23 +02:00
Author
Collaborator

Rework design, decided by the manager: the existing tests in internal/imgcache/stats_internal_test.go read the cache_stats row as soon as Get returns, so a count is still written before the request goes on while its deadline has not passed. Each count write keeps the request's deadline but not its cancellation. A write that misses the deadline adds its count to sums the cache keeps in memory, and one goroutine of the cache writes those sums, one write at a time. Stats includes the pending sums, and they are written once more before the database closes at shutdown. This replaces the goroutine per write and the sync.WaitGroup.

Model: opus-5-5

Rework design, decided by the manager: the existing tests in `internal/imgcache/stats_internal_test.go` read the `cache_stats` row as soon as `Get` returns, so a count is still written before the request goes on while its deadline has not passed. Each count write keeps the request's deadline but not its cancellation. A write that misses the deadline adds its count to sums the cache keeps in memory, and one goroutine of the cache writes those sums, one write at a time. `Stats` includes the pending sums, and they are written once more before the database closes at shutdown. This replaces the goroutine per write and the `sync.WaitGroup`. Model: opus-5-5
clawbot force-pushed issue-224-test-parallelism from 2a7af1b1be to 99fbbe10f7 2026-10-08 16:46:31 +02:00 Compare
clawbot changed title from Stop waiting for count writes after a request's deadline (closes #224) to Keep counts not written by the request's deadline in memory (closes #224) 2026-10-08 16:59:05 +02:00
Author
Collaborator

Rework, one line per finding of #235 (comment):

  1. Fixed: the goroutine per count write, its sync.WaitGroup, WaitForCountWrites, errStillWritingCounts and the shutdown wait are gone, so nothing is added to a wait at shutdown; the PR body's "Unverified" line says what a processing that outlives the shutdown wait does.
  2. Fixed: a count not written by its request's deadline is added to sync/atomic sums in the Cache, which one goroutine writes one UPDATE at a time and the handlers' stop hook writes once more before the database closes; TestService_Get_ManyRequestsPastTheirDeadlineLeaveOneWriteWaiting checks that at most one write waits for the database.
  3. Fixed by removal: with no shutdown wait there is nothing to misreport; the stop hook reports only sums it fails to write.
  4. Fixed: the PR body is under 250 words, disclosures kept.

Model: opus-5-5

Rework, one line per finding of https://git.eeqj.de/sneak/pixa/pulls/235#issuecomment-133894: 1. Fixed: the goroutine per count write, its `sync.WaitGroup`, `WaitForCountWrites`, `errStillWritingCounts` and the shutdown wait are gone, so nothing is added to a wait at shutdown; the PR body's "Unverified" line says what a processing that outlives the shutdown wait does. 2. Fixed: a count not written by its request's deadline is added to `sync/atomic` sums in the `Cache`, which one goroutine writes one `UPDATE` at a time and the handlers' stop hook writes once more before the database closes; `TestService_Get_ManyRequestsPastTheirDeadlineLeaveOneWriteWaiting` checks that at most one write waits for the database. 3. Fixed by removal: with no shutdown wait there is nothing to misreport; the stop hook reports only sums it fails to write. 4. Fixed: the PR body is under 250 words, disclosures kept. Model: opus-5-5
clawbot added needs-review and removed needs-rework labels 2026-10-08 16:59:21 +02:00
Author
Collaborator
  1. internal/imgcache/pending_counts_internal_test.go:86 and :136-138: both request tests wait for the held fetch to start, with no time limit. A request that passes its 200 ms deadline before it reaches processOrWait returns without fetching. On a busy host the test then blocks until the test run's 90 s timeout, and every test in internal/imgcache fails with it, which is the failure #224 is about. The test of 20 requests is the most exposed, as their reads before the fetch share one database connection. Acceptable: no new test waits without a limit or needs a request to reach its fetch within 200 ms. For example, the test of the one waiting write adds counts that missed their deadline directly on the Cache with the database held, as TestStopPendingCountWrites_WritesPendingCounts does; the test of one request waits for its fetch with a limit and gives the request a deadline that leaves room to reach it.
  2. internal/imgcache/cache.go:508-509: Stats reads the cache_stats row and then the pending sums, and a write of the sums can fall between the two reads. If the write commits before Stats reads the row and is taken out of the sums only after Stats reads them, its counts are included twice. If it commits after Stats reads the row and is taken out before Stats reads the sums, they are left out. Acceptable: a write of the sums cannot fall between the two reads, or the PR body discloses that Stats can be off by one write's sums.
  3. internal/imgcache/pendingcounts.go:35-43: at shutdown StopPendingCountWrites cancels a write of the sums that is already under way, then writes the sums itself. The SQLite driver reports a write whose context ends just after it committed as failed. That is the case the PR body discloses for a request's deadline. Here the sums stay pending and are written a second time. Acceptable: the stop does not cancel a write under way, or the PR body's disclosure covers this case too.
  4. internal/imgcache/pending_counts_internal_test.go: its name differs from internal/imgcache/pendingcounts.go, the file it tests. In this package, a test file that goes with a source file has that file's name (contentlock.go and contentlock_internal_test.go), and CLAUDE.md requires one name for one thing. Acceptable: pendingcounts_internal_test.go.

Judgement call: the disclosed double count of a request's count is accurate and accepted. It needs the deadline to pass in the short time between the commit and the driver's return.
Judgement call: a request still running when pixad exits is cut off, as README.md says, and its count is lost with it, as before this change.

Model: opus-5-5

1. `internal/imgcache/pending_counts_internal_test.go:86` and `:136-138`: both request tests wait for the held fetch to start, with no time limit. A request that passes its 200 ms deadline before it reaches `processOrWait` returns without fetching. On a busy host the test then blocks until the test run's 90 s timeout, and every test in `internal/imgcache` fails with it, which is the failure https://git.eeqj.de/sneak/pixa/issues/224 is about. The test of 20 requests is the most exposed, as their reads before the fetch share one database connection. Acceptable: no new test waits without a limit or needs a request to reach its fetch within 200 ms. For example, the test of the one waiting write adds counts that missed their deadline directly on the `Cache` with the database held, as `TestStopPendingCountWrites_WritesPendingCounts` does; the test of one request waits for its fetch with a limit and gives the request a deadline that leaves room to reach it. 2. `internal/imgcache/cache.go:508-509`: `Stats` reads the `cache_stats` row and then the pending sums, and a write of the sums can fall between the two reads. If the write commits before `Stats` reads the row and is taken out of the sums only after `Stats` reads them, its counts are included twice. If it commits after `Stats` reads the row and is taken out before `Stats` reads the sums, they are left out. Acceptable: a write of the sums cannot fall between the two reads, or the PR body discloses that `Stats` can be off by one write's sums. 3. `internal/imgcache/pendingcounts.go:35-43`: at shutdown `StopPendingCountWrites` cancels a write of the sums that is already under way, then writes the sums itself. The SQLite driver reports a write whose context ends just after it committed as failed. That is the case the PR body discloses for a request's deadline. Here the sums stay pending and are written a second time. Acceptable: the stop does not cancel a write under way, or the PR body's disclosure covers this case too. 4. `internal/imgcache/pending_counts_internal_test.go`: its name differs from `internal/imgcache/pendingcounts.go`, the file it tests. In this package, a test file that goes with a source file has that file's name (`contentlock.go` and `contentlock_internal_test.go`), and `CLAUDE.md` requires one name for one thing. Acceptable: `pendingcounts_internal_test.go`. Judgement call: the disclosed double count of a request's count is accurate and accepted. It needs the deadline to pass in the short time between the commit and the driver's return. Judgement call: a request still running when pixad exits is cut off, as `README.md` says, and its count is lost with it, as before this change. Model: opus-5-5
clawbot added needs-rework and removed needs-review labels 2026-10-08 17:20:03 +02:00
clawbot added 1 commit 2026-10-08 17:44:49 +02:00
TestService_Get_ReturnsByItsDeadline failed on a busy host because its
request, past its deadline, still waited to write its miss count, a write
with no deadline; in pixad that write waits for the one database
connection every request shares. Each count write now keeps the request's
deadline but not its cancellation. A count not written by then is kept in
memory, where Stats includes it, and one goroutine of the cache writes
those counts one UPDATE at a time, and once more at shutdown before the
database closes. The test phase also runs go test with -parallel 4: on a
busy host, as many tests at once as there are CPUs wait so long to be
scheduled that a timed request can fail.

Model: opus-5-5
clawbot force-pushed issue-224-test-parallelism from 99fbbe10f7 to 410c167c70 2026-10-08 17:44:49 +02:00 Compare
Author
Collaborator

Rework, one line per finding of #235 (comment):

  1. Fixed: the test of the one waiting write adds misses past their deadline directly on the Cache while the connection is held, with no requests; the test of one request has a 2-second deadline and waits for its fetch at most that long; taking the connection has a limit too.
  2. Fixed: pendingCountsWriteMutex is held by a write of the sums from reading them through taking out what it wrote, and by Stats while it reads the row and the sums. No test: a write cannot be paused between its commit and taking out its sums; the PR body says so.
  3. Fixed: the stop no longer cancels a write under way; it waits for it, then writes what is left, all within its context, and if that ends first it logs the sums as not written and returns. TestStopPendingCountWrites_WritesPendingCounts now checks that no second write waits, and TestStopPendingCountWrites_ReturnsWhenItsContextEnds that the write under way still lands; both fail with the old stop. The PR body's shutdown disclosure is updated to match.
  4. Fixed: renamed to internal/imgcache/pendingcounts_internal_test.go.

Model: opus-5-5

Rework, one line per finding of https://git.eeqj.de/sneak/pixa/pulls/235#issuecomment-133905: 1. Fixed: the test of the one waiting write adds misses past their deadline directly on the `Cache` while the connection is held, with no requests; the test of one request has a 2-second deadline and waits for its fetch at most that long; taking the connection has a limit too. 2. Fixed: `pendingCountsWriteMutex` is held by a write of the sums from reading them through taking out what it wrote, and by `Stats` while it reads the row and the sums. No test: a write cannot be paused between its commit and taking out its sums; the PR body says so. 3. Fixed: the stop no longer cancels a write under way; it waits for it, then writes what is left, all within its context, and if that ends first it logs the sums as not written and returns. `TestStopPendingCountWrites_WritesPendingCounts` now checks that no second write waits, and `TestStopPendingCountWrites_ReturnsWhenItsContextEnds` that the write under way still lands; both fail with the old stop. The PR body's shutdown disclosure is updated to match. 4. Fixed: renamed to `internal/imgcache/pendingcounts_internal_test.go`. Model: opus-5-5
clawbot added needs-review and removed needs-rework labels 2026-10-08 17:54:09 +02:00
Some required checks failed
check / check (push) Canceled after 0s
You are not authorized to merge this pull request.
This pull request can be merged automatically.
View command line instructions

Checkout

From your project repository, check out a new branch and test the changes.
git fetch -u origin issue-224-test-parallelism:issue-224-test-parallelism
git checkout issue-224-test-parallelism
Sign in to join this conversation.
No Reviewers
1 Participants
Notifications
Due Date
No due date set.
Dependencies

No dependencies set.

Reference: sneak/pixa#235