amadan

carlos / platform Public

Keep failure-storm snapshots stable without blocking recording

Paul Campbell pushed by paul@keymail.dev c0d60af8e6e4027a86412d9cfae480ebe7d1468a parent 665bcb7
3 files changed, +92 −18
  • implementation/carloku-paid-launch/AGENT_HANDOFF.md +5 −5
  • internal/usage/durabilityfailures_test.go +50 −0
  • internal/usage/durabilityledger.go +37 −13

CI passed — run details

diff --git a/implementation/carloku-paid-launch/AGENT_HANDOFF.md b/implementation/carloku-paid-launch/AGENT_HANDOFF.md
index ffb65a7d4..b5e01c53e 100644
--- a/implementation/carloku-paid-launch/AGENT_HANDOFF.md
+++ b/implementation/carloku-paid-launch/AGENT_HANDOFF.md
@@ -1,6 +1,6 @@
# Agent pickup instructions — Carloku paid launch
-CURRENT GATE: local build, vet and `make test` GREEN after fixing the intermittent durability snapshot failure. Amadan CI passed on the first fix commit; the reviewed amendment still needs its own CI run. This remains a checkpoint of unfinished work.
+CURRENT GATE: local build, vet and `make test` GREEN after fixing the intermittent durability snapshot failure and sustained-drain fallback. Amadan CI passed on the preceding commit; the final reviewed change needs its own CI run. This remains a checkpoint of unfinished work.
This file is context and instructions for the next coding agent. The branch is a work-in-progress checkpoint, not a release candidate. Do not merge, deploy, enable billing, or infer that the overnight launch goal was achieved.
@@ -40,8 +40,8 @@ Read `AGENTS.md` and `docs/superpowers/specs/2026-09-07-carloku-pricing-plans-de
- Quantity/checkout/membership audit tests passed `-race` (49.015s), before the final invoice lock changes. Log: `quantity-complete-root-race.txt`.
- New host ownership, locked-ledger timeout, shutdown/publication and actual fake-HTTP SDK List/Copy/Delete-to-ledger tests passed `-race` (1.551s). Log: `host-durability-sdk-root-race.txt`.
- New activator meter selection plus existing staging-restore tests passed `-race` (1.032s). Log: `activator-metering-root-race.txt`.
-- The prior intermittent failure was real: a snapshot could read SQLite before a background failure drain, then read the latch after that drain cleared it. The fix retries when a committed drain crosses the read and checks the final latch state under the writer mutex, which spans commit and subtraction. A forced-interleaving regression, an arrival-during-read regression, and the original late-failure test passed `-race -count=20`; the original also passed `-count=30` without race instrumentation. The complete local gate (`go build ./...`, `go vet ./...`, `make test` with JS parity) passed twice on 2026-09-18. Amadan CI passed on both the previous handoff commit `099586ea` and the first fix commit `eea00ee`, demonstrating why a single green run did not settle this intermittent bug. The reviewed amendment needs a fresh CI run.
-- An Opus review found that retrying on every arriving failure could starve publication during a recording outage. The amendment retries only when a committed drain clears the latch; a second Opus review confirmed the missed-failure race remains closed. Remaining risk: eight consecutive drain commits during one snapshot still return an error. Because that can leave an older complete-looking publication in the bucket, production billing needs a safe publication/freeze response before attestation or charges turn on. The reviewer also noted a pre-existing unsynchronized read of `l.state.epoch` in the snapshot; it has not been addressed here.
+- The prior intermittent failure was real: a snapshot could read SQLite before a background failure drain, then read the latch after that drain cleared it. The fix retries when a committed drain crosses the read and checks the final latch state under the writer mutex, which spans commit and subtraction. A forced-interleaving regression, an arrival-during-read regression, a sustained-drain regression, and the original late-failure test passed repeated `-race` runs. The complete local gate (`go build ./...`, `go vet ./...`, `make test` with JS parity) passed on the final code on 2026-09-18. Amadan CI passed on the previous handoff commit `099586ea`, first fix commit `eea00ee`, and first reviewed amendment `665bcb7`. A single green run did not settle this intermittent bug; CI on the final code is pending.
+- Opus reviews found and verified three follow-up corrections: arriving failures do not cause retries; after eight crossed drains a ninth snapshot holds a dedicated drain lock so publication gets a stable view; the drainer waits without holding the ordinary recording lock. The ninth-read test proves `Start`/`Finish` still progress and a new failure is counted. Final Opus review found no deadlock or data loss in this diff. Low residual risk: `Close(ctx)` and `Seal` can wait on a fallback read without a context bound, and a long fallback delays drain persistence; this does not block ordinary recording. A reviewer also noted a pre-existing unsynchronized read of `l.state.epoch` in the snapshot; it has not been addressed here.
- CURRENT tree passed all five cross-builds (Darwin arm64/amd64, Linux arm64, Windows amd64/arm64). Log: `handoff-cross.txt`.
- Final whole-branch Fable review and production/authority Opus review remain outstanding. All three Claude agents stopped at the shared usage limit, which reports reset at05:50 Europe/Dublin on2026-09-17 (04:50UTC). No agents remain running. That reset time has now passed; availability has not been rechecked for this handoff. Relevant task briefs/reports are in scratch, especially `durability-host-integration-brief.txt`, `opus-durability-integration-design.txt`, `quantity-history-hardening-brief.txt` and the invoice reports. The older design's arbitrary five-minute late-callback slack is NOT accepted proof.
@@ -78,8 +78,8 @@ A scratch SQLite experiment was also found replacing local root main.go. It was
## Next agent actions
-1. Read Amadan CI for the new durability-fix commit and inspect the complete branch diff as WIP. The local gate is green, but that does not make the launch ready.
-2. Resolve the sustained-drain publication error and review the host wiring: `bindingFailed` is set on unmetered fallbacks but currently only the permanently false attestation prevents billing. Finish per-route move/checkpoint tests and client inventory, source completeness folding, scoped external-client exclusion, crash/late-callback/restart proof, bounded ledger retention and real-disk latency measurement. Keep unattested usage unbillable until proved.
+1. Read Amadan CI for the final durability-fix commit and inspect the complete branch diff as WIP. The local gate is green, but that does not make the launch ready.
+2. Review host wiring: `bindingFailed` is set on unmetered fallbacks but currently only the permanently false attestation prevents billing. Finish per-route move/checkpoint tests and client inventory, source completeness folding, scoped external-client exclusion, crash/late-callback/restart proof, bounded ledger retention and real-disk latency measurement. Keep unattested usage unbillable until proved.
3. Implement P5 collector with durable deduplication, immutable historical bucket ownership and a settled transfer contract. Prepare exact scoped logging activation before seeking production approval.
4. Complete partial-month billing, quantity/proration collection, operator review/house doors, Free enrollment/caps/idle/flush-only, dormancy warnings/archive and revenue-pool accounting required by the spec. Use the requirements audit rather than treating these as optional follow-ups.
5. After external prerequisites and copy approvals, provision/verify Stripe catalog, run the real sandbox purchase/webhook/portal flow, obtain independent reviews, pass Amadan CI and release gates, then land/deploy through the required reviewed path and verify live behaviour. No main merge or deployment is part of this handoff.
diff --git a/internal/usage/durabilityfailures_test.go b/internal/usage/durabilityfailures_test.go
index 06d3c5119..98dee44c9 100644
--- a/internal/usage/durabilityfailures_test.go
+++ b/internal/usage/durabilityfailures_test.go
@@ -95,6 +95,56 @@ func TestDurabilitySnapshotCountsFailureArrivingDuringRead(t *testing.T) {
}
}
+func TestDurabilitySnapshotCompletesDuringSustainedDrain(t *testing.T) {
+ clock := newLedgerClock(ledgerDay0)
+ l := openTestLedger(t, t.TempDir(), "box1", clock, true)
+ defer l.Close(context.Background(), nil)
+ c, err := l.Bind(tenantAttr)
+ if err != nil {
+ t.Fatal(err)
+ }
+ date := DayOf(ledgerDay0)
+ reads := 0
+ l.snapshotPause = func(string) {
+ reads++
+ if reads > 8 {
+ // The fallback must count this failure from the latch even
+ // though its drainer is waiting for the snapshot to finish.
+ l.latchFailure(ledgerDay0)
+ // The waiting drainer must not hold the normal recording lock.
+ recorded := make(chan error, 1)
+ go func() {
+ token, err := c.Start("PutObject", ledgerDay0)
+ if err == nil {
+ err = c.Finish(token, RequestOutcome{At: ledgerDay0.Add(time.Second), Status: 200, Answered: true})
+ }
+ recorded <- err
+ }()
+ select {
+ case err := <-recorded:
+ if err != nil {
+ t.Fatal(err)
+ }
+ case <-time.After(2 * time.Second):
+ t.Fatal("recording blocked behind the snapshot fallback")
+ }
+ return
+ }
+ l.latchFailure(ledgerDay0)
+ deadline := time.Now().Add(5 * time.Second)
+ for !l.latch.empty() && time.Now().Before(deadline) {
+ time.Sleep(time.Millisecond)
+ }
+ if !l.latch.empty() {
+ t.Fatal("failure did not drain during the snapshot read")
+ }
+ }
+ content, err := l.Snapshot(date)
+ if err != nil || content.RecordingFailures != 9 || reads != 9 {
+ t.Fatalf("snapshot under sustained drains: failures=%d reads=%d err=%v", content.RecordingFailures, reads, err)
+ }
+}
+
// ---- Recording failures: the non-blocking latch and its proofs ------------
//
// Incomplete is called from the request path with a 25 ms budget around
diff --git a/internal/usage/durabilityledger.go b/internal/usage/durabilityledger.go
index b8891a258..2c27cde45 100644
--- a/internal/usage/durabilityledger.go
+++ b/internal/usage/durabilityledger.go
@@ -91,9 +91,12 @@ type DurabilityLedger struct {
now func() time.Time
lock *os.File
- mu sync.Mutex // serialises every database access and the state below
- pubMu sync.Mutex // serialises Publish (never held while waiting for mu's holder)
- db *sql.DB
+ mu sync.Mutex // serialises every database access and the state below
+ // drainMu spans a failure drain's commit and latch subtraction. A
+ // fallback snapshot holds it without blocking ordinary Start/Finish.
+ drainMu sync.Mutex
+ pubMu sync.Mutex // serialises Publish (never held while waiting for mu's holder)
+ db *sql.DB
// rdb is a second connection used ONLY to read: a snapshot is built
// inside one read transaction on it, so a day's scan never queues a
// Start or Finish behind it (WAL readers do not block the writer). The
@@ -1302,6 +1305,8 @@ func (l *DurabilityLedger) drainLatch() {
// drainOnce files the latch's current contents in one transaction.
// False when the ledger is closed (nothing more will be written here).
func (l *DurabilityLedger) drainOnce() bool {
+ l.drainMu.Lock()
+ defer l.drainMu.Unlock()
l.mu.Lock()
defer l.mu.Unlock()
if l.closed {
@@ -1501,6 +1506,8 @@ func (l *DurabilityLedger) SetAttestation(a DurabilityAttestation, at time.Time)
// an idle box republishes once an hour rather than every tick, and a
// crash on one leaves at most an hour of coverage unclaimed.
func (l *DurabilityLedger) Seal() error {
+ l.drainMu.Lock()
+ defer l.drainMu.Unlock()
l.mu.Lock()
defer l.mu.Unlock()
if l.closed {
@@ -1509,7 +1516,7 @@ func (l *DurabilityLedger) Seal() error {
return l.seal(false)
}
-// seal is Seal under l.mu.
+// seal runs with drainMu and l.mu held, in that order.
func (l *DurabilityLedger) seal(force bool) error {
now := l.now().UTC()
// A marker that appeared after this open: something recorded outside.
@@ -1639,7 +1646,7 @@ func (l *DurabilityLedger) Snapshot(date string) (DurabilityContent, error) {
func (l *DurabilityLedger) snapshot(ctx context.Context, date string) (DurabilityContent, dayLineage, error) {
for range 8 {
_, before := l.latch.pendingAt(date)
- content, lineage, err := l.snapshotOnce(ctx, date, before)
+ content, lineage, err := l.snapshotOnce(ctx, date, before, false)
if errors.Is(err, errSnapshotLatchChanged) {
continue
}
@@ -1648,7 +1655,17 @@ func (l *DurabilityLedger) snapshot(ctx context.Context, date string) (Durabilit
}
return content, lineage, nil
}
- return DurabilityContent{}, dayLineage{}, errors.New("usage ledger: failure drains crossed eight snapshot attempts")
+ // A sustained drain can cross every optimistic read. Take one read
+ // under the drain lock so publication cannot leave an older complete
+ // day in place. Ordinary recording and Incomplete can still proceed.
+ l.drainMu.Lock()
+ defer l.drainMu.Unlock()
+ _, before := l.latch.pendingAt(date)
+ content, lineage, err := l.snapshotOnce(ctx, date, before, true)
+ if errors.Is(err, errSnapshotLatchChanged) {
+ return DurabilityContent{}, dayLineage{}, errors.New("usage ledger: failure drain changed during locked snapshot")
+ }
+ return content, lineage, err
}
var errSnapshotLatchChanged = errors.New("usage ledger: failure drain crossed snapshot")
@@ -1656,11 +1673,12 @@ var errSnapshotLatchChanged = errors.New("usage ledger: failure drain crossed sn
// snapshotOnce builds the content and reads the day's publication lineage in
// ONE read transaction on the reader connection: the watermark is the
// ledger's next_seq as that transaction sees it, so every row with a
-// lower sequence is in the snapshot and none with a higher one. It holds
-// no ledger mutex: a Start or Finish commits beside it, and is simply
-// above the watermark. Latched failures are added after the read; they
-// only ever make a snapshot more incomplete.
-func (l *DurabilityLedger) snapshotOnce(ctx context.Context, date string, before uint64) (DurabilityContent, dayLineage, error) {
+// lower sequence is in the snapshot and none with a higher one. Optimistic
+// reads hold no ledger mutex: a Start or Finish commits beside them and
+// is simply above the watermark. The fallback holds the drain mutex to
+// stop repeated drains from crossing the read. Latched failures are added
+// after the read; they only ever make a snapshot more incomplete.
+func (l *DurabilityLedger) snapshotOnce(ctx context.Context, date string, before uint64, drainLocked bool) (DurabilityContent, dayLineage, error) {
start, end, err := DayBounds(date)
if err != nil {
return DurabilityContent{}, dayLineage{}, fmt.Errorf("usage ledger: %q is not a date", date)
@@ -1821,9 +1839,13 @@ func (l *DurabilityLedger) snapshotOnce(ctx context.Context, date string, before
// The writer holds l.mu through both commit and latch subtraction.
// Checking under it cannot observe a committed row alongside its
// not-yet-subtracted latch entry.
- l.mu.Lock()
+ if !drainLocked {
+ l.mu.Lock()
+ }
pending, after := l.latch.pendingAt(date)
- l.mu.Unlock()
+ if !drainLocked {
+ l.mu.Unlock()
+ }
if after != before {
return DurabilityContent{}, dayLineage{}, errSnapshotLatchChanged
}
@@ -1868,6 +1890,7 @@ func (l *DurabilityLedger) Close(ctx context.Context, store release.Store) error
l.closing = true
l.mu.Unlock()
waitErr := l.waitInflight(ctx)
+ l.drainMu.Lock()
l.mu.Lock()
l.closed = true
left := l.pending
@@ -1884,6 +1907,7 @@ func (l *DurabilityLedger) Close(ctx context.Context, store release.Store) error
l.latch.closed = true
l.latch.mu.Unlock()
l.mu.Unlock()
+ l.drainMu.Unlock()
if undrained {
// The rows will not be written now. The marker carries the
// earliest day they named, so the next open's gap reaches it.