Skip to content

flaky: TestResolvedPathBackfill_WriteHoldUnderBudget_188 — wall-clock write-hold budget fails under CI load #267

Description

@dborup

Problem

TestResolvedPathBackfill_WriteHoldUnderBudget_188 in cmd/ingestor/resolved_path_backfill_188_test.go failed on master CI. The run was 37321760306 for 0572e7f9, in "Build and test Go ingestor (with coverage)":

max write hold per 500-row batch: 263.738039ms (budget 250ms)
max write hold 263.738039ms exceeds the budget 250ms

The test measures the wall-clock write-transaction hold of the slowest of 10 batches (5000 rows, batch size 500) and asserts it is under a fixed 250 ms. The result depends on runner load and coverage instrumentation, not only on the code. The commit under test changed only two unrelated test files, and the same test passed on master earlier the same day.

Proposed approach

Keep the guarantee the test protects: one backfill batch must not hold the single write connection for long enough to stall live ingest. Make the assertion robust:

  • Assert the structural property deterministically: rows per write transaction ≤ the batch size, one transaction per batch, and no work done while holding the transaction that could have been done before it (for example, resolution happens before BEGIN).
  • If a timing assertion stays, make it relative and tolerant. For example, compare the max hold against the median batch, or against a per-row budget calibrated in the same run. Alternatively, skip or relax it under -cover and -race, and keep a separate benchmark (BenchmarkResolvedPathBackfillBatch) that reports the hold.
  • Investigate first whether the 264 ms is real work inside the transaction that could be moved out, or only scheduling noise. Name the cause in the PR.

Acceptance

  • The cause of the overshoot is named in the PR, with evidence.
  • The test passes go test -count=50 -run TestResolvedPathBackfill_WriteHoldUnderBudget_188 -cover ./... in cmd/ingestor under parallel CPU load.
  • A mutant that moves the per-row resolution inside the write transaction, or that batches all rows in one transaction, still fails the test.

Activity

  1. added
    bugSomething isn't working
    type:bugSomething broken
    on Oct 5, 2026
  2. dborup-agent commented on Oct 5, 2026

    @dborup-agent
    Collaborator

    Plan — CS-pve-agent2 #267

    Initial findings. These are measured on 0572e7f9 with -cover, while two go test ./... loops on cmd/server run alongside (load avg ~5–6 on 4 cores). I timed each phase of 200 batches of 500 rows:

    phase median p95 max
    read (outside tx) 1.9 ms 2.4 ms 6.7 ms
    resolve (outside tx) 1.1 ms 1.6 ms 3.8 ms
    writerMu wait + BEGIN 0.03 ms 0.05 ms 0.3 ms
    500 UPDATEs + watermark 5.6 ms 7.9 ms 11.4 ms
    COMMIT 15.5 ms 30.3 ms 45.4 ms
    hold (total) 21.6 ms 36.3 ms 52.7 ms
    • COMMIT is about 75% of the hold. That is the WAL fsync (synchronous=2, FULL, the driver default).
    • With PRAGMA synchronous=OFF on the same load, the hold drops to a 3.1 ms median and a 12.8 ms max.
    • No auto-checkpoint fired in any batch.
    • Resolution is already outside the transaction.
    • Nothing in the transaction can be moved out without changing semantics: the UPDATEs, the watermark and the COMMIT must stay atomic.
    • So the overshoot is disk-flush latency on a loaded runner, not code inside the transaction.

    Plan:

    1. Leave the semantics of resolvedPathBackfillBatch unchanged. Add one test seam for the resolver call, in the same style as readProcSelfIOFn.
    2. Rewrite TestResolvedPathBackfill_WriteHoldUnderBudget_188 with deterministic structural assertions. Test-only SQLite triggers call a Go probe function, so the probe sees every row UPDATE and every watermark write inside the real transaction. The test asserts:
      • rows per write transaction ≤ the batch size;
      • exactly one write transaction (WriterTx) and one watermark write per batch;
      • no resolution while writerMu is held.
    3. Drop the absolute 250 ms wall-clock assertion. Log the hold, and add BenchmarkResolvedPathBackfillBatch, which reports the hold per batch. The PR explains why no timing assertion stays.
    4. Check two mutants: resolution moved into the WriterTx closure, and all rows in one transaction. Both must fail the new test. I will also show whether the old timing test catches them.
    5. Run -count=50 -cover under parallel CPU load at least twice, then -race on the whole package, go vet, gofmt, and test-all.sh. Then open a draft PR.

    Writes stay in the ingestor. No new map[string]interface{}. The workflow files are not touched.

  3. added a commit that references this issue on Oct 5, 2026
  4. dborup commented on Oct 5, 2026

    @dborup
    OwnerAuthor

    Fixed by #272 (merged as 6087a793). Review nits (test depends on statement order inside the tx; the writerMuHeld TryLock heuristic) are noted on #272 and left as they are.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    bugSomething isn't workingtype:bugSomething broken

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions