sneak/webhooker
1
0
Fork 0
Code Issues 62 Pull Requests 2 Actions Packages Projects Releases Wiki Activity

Make SQLite durable under concurrent readers and stop re-delivering stranded webhooks (closes #256) #263

Merged
clawbot merged 1 commits from issue-256-sqlite-durability into next 2026-08-24 03:49:18 +02:00
Conversation 3 Commits 1 Files Changed 20 +2100 -139
clawbot commented 2026-08-24 01:42:20 +02:00
Collaborator
Copy Link

Closes #256.

Reproduced first, on unmodified next

6 active http targets, 60 events at 5/s, sinks holding each POST 1.5 s so deliveries are still in flight, and a sqlite3 <db> .dump loop started 4 s in:

baseline, reader baseline, no reader fixed, reader fixed, no reader
inbound HTTP 500s 38 / 60 0 0 0
engine write errors 260 0 0 0
new requests from restart 112 160 0 0
duplicate payloads at sinks 112 10 0 0
delivery_results rows 132 (for 244 POSTs) — 360 (for 360 POSTs) 360 (for 360 POSTs)
pragma journal_mode delete delete wal wal

The baseline reader arm is the reported defect end to end: inbound rejections, 112 duplicate POSTs confirmed by payload at the sink, and an event log claiming 132 attempts for 244 actual deliveries. (The baseline no-reader arm's 160 is my harness not draining before the restart, not the bug; both fixed arms drain and add nothing.)

Durability, internal/database/sqlite_open.go

Every SQLite file — main, per-webhook, archive — now opens through one function. Nothing else builds a DSN.

busy_timeout = 10 s. Under WAL a reader never blocks a writer, so the only conflict left is writer-versus-writer: this process's 10 delivery workers against each other, or against another process. Those clear in milliseconds. Ten seconds is far above that and well inside the receiver's request budget, so an inbound webhook waits rather than being rejected with a 500.

Pool bound = 4 open, 2 idle, 5 min lifetime, 1 min idle time. The bound exists because database/sql cannot detect a poisoned connection: modernc.org/sqlite implements neither driver.Validator nor driver.SessionResetter, so a connection whose COMMIT failed goes back into the pool with its transaction still open and is handed out forever after. That is how 4 database is locked became 593 cannot start a transaction within a transaction. Four is above the one writer SQLite allows at a time, so reads proceed while a write is in flight, and low enough that contention resolves through the busy handler rather than by piling connections against a lock only one can hold. The lifetime bounds the damage if a connection is poisoned anyway.

_txlock=immediate. This carries as much of the fix as the busy timeout and was not in the issue's DoD. A deferred transaction takes the write lock lazily on its first write, and that upgrade returns SQLITE_BUSY without consulting the busy handler — SQLite cannot block a transaction that may already hold a read snapshot. So COMMIT fails while the transaction stays open on the connection: the poisoning mechanism itself. BEGIN IMMEDIATE moves the wait to where the handler applies.

Pragma order. busy_timeout is set before journal_mode. The driver executes _pragma parameters in order on every new connection, and PRAGMA journal_mode takes a lock; the pool opens connections lazily, so it does that precisely when the database is under load. The reverse order leaves the one pragma that can block uncovered by the handler meant to cover it, and produces exactly the SQLITE_BUSY at elapsed_ms: 0 that review observed.

cache=shared removed, as the issue requires: under a shared cache an in-process conflict is SQLITE_LOCKED, which the busy handler does not retry.

Confirmed on live handles rather than by inspecting the DSN — all three tiers assert pragma journal_mode (wal) and pragma busy_timeout (10000) on a running database. The three test helpers that opened their own cache=shared handles now go through OpenSQLite too, so no test can pass against settings production does not use.

Eligibility, internal/delivery/inflight.go

What makes a delivery eligible for re-dispatch, and what makes that decision exclusive — one mechanism, because three independent guards on one transition is how the next duplicate gets in.

inflightSet is a reference-counted set of the delivery ids the engine owns. A reference is taken when a task is queued (Notify), when a target schedules a retry (ScheduleRetry, so ownership spans the whole backoff window rather than lapsing while the row sits at retrying with nothing running), and by every recovery path before it re-dispatches. It is dropped when the worker that ran the task returns.

Nothing decides eligibility from a row's age. A delivery's row says pending from creation until its outcome is written, which covers four different situations — never dispatched, waiting in a channel, being attempted right now, genuinely stranded — and no column separates them. deliveryChannelSize is 10000 against 10 workers, so a perfectly healthy delivery can wait far longer than any workable age bound before its attempt even begins; reasoning from age re-sends it. In-memory state is authoritative because internal/datadir admits one process per DATA_DIR; deliveries owned by a process that died are in no successor's set, and restart recovery is what picks those up.

takeForRedispatch is the single gate every re-dispatch goes through, and asks two different questions in order: does the engine already own this delivery (ownership, which is what excludes), and is the row still in the status the batch read (a conditional update, which is what catches a stale batch). Stamping updated_at is part of that same statement and is re-dispatch cadence, not a claim: without it a delivery the database will not let the engine settle would be re-sent on every 60-second tick. reconcileDelivered and failUnretryableRetry take ownership too, so every recovery-side write passes the gate.

pendingSweepMinAge is 15 minutes — clear of MaxTargetTimeoutSeconds (300 s) by 3x, so the two guards do not both have to be right.

Bookkeeping, internal/delivery/engine.go

What status when the send succeeded but the result write failed. The delivery keeps the non-terminal status it already holds — pending, or retrying for a retry attempt — and nothing is written at all. Both are retryable per DeliveryStatus.Terminal(), and both are now swept. Writing a status in the failure path would need the very database that just refused a write and would be one more thing to fail; not writing cannot fail. recordResult and updateDeliveryStatus return their errors and every call site stops advancing the status.

That leaves the honest at-least-once case — a send that reached the receiver whose result row did not land is attempted again, and recorded as the further attempt it is. What no longer happens is the silent duplicate the event log denies.

Recovery distinguishes the two histories. A delivery holding a successful DeliveryResult is marked delivered instead of re-sent. The result row is written before the status, so its presence means the wire I/O happened and was recorded and only the status is missing — the state the issue notes did not exist. This runs on every recovery path, pending and retrying alike: a second attempt that reached the receiver and whose status write then failed sits at retrying holding a successful result, and re-sending it is the same duplicate.

Attempt numbering continues. Recovery re-enqueued at attemptNum = 1 unconditionally; it now uses the delivery's real attempt count, so numbers do not collide in the event log and the retry path computes backoff from the right attempt.

Pending arm on the sweep, capped at 500 per webhook per sweep, running the same reconcile-then-gate-then-dispatch path, so a stranded delivery no longer waits for a restart. Event bodies are read after the gate, one delivery at a time, so a batch that is mostly refused never materialises.

Documentation

WAL creates -wal/-shm sidecars, and README.md previously stated flatly that none are produced. Everything below was measured against a live instance rather than reasoned about:

  • sqlite3 .backup — 40/40 rows, single consistent file, no sidecars of its own. Procedure unchanged.
  • Stop, cp -a, start — 40/40 rows, restored into a fresh directory, started, read back. Procedure unchanged; the reasoning under it is not. A clean stop closes webhooker.db and the events-*.db and checkpoints their sidecars away, but not the archive files: their handle is never closed at shutdown, so after a clean stop archive-….db was 4096 bytes with no schema while its -wal held all 8 archived events. Copying DATA_DIR in full is what makes that a non-issue.
  • Hot copy of a .db alone — fails loudly (no such table), because a young database's schema is still in the WAL. The existing "a hot copy is not safe" warning is still true and now louder.
  • After SIGKILL — the .db alone reads 40 rows where .db + -wal reads 50. The restore instructions were inverted: they said to drop journal files, and now say to carry any -wal/-shm a salvaged copy contains.
  • The archive move-the-file-away workflow is no longer a single file, and its common case is the dangerous one. The close/reopen is debounced to the next write, so after the last write of a burst nothing checkpoints: 20 s after ten events the .db was 4096 bytes and all ten rows sat in a 189 KB -wal. It self-contains on the next write past the debounce, when the pool retires the idle connection about a minute later, or at the idle sweep.

Two code comments that reasoned from "these files are not WAL" are corrected.

Verification

  • make check green with GOFLAGS=-count=1, 0 (cached) packages, lint executed uncached in the digest-pinned container, after rebasing onto current next.
  • The sweep against healthy queued work, no reader: 300 events, 6 targets, sinks holding 6 s so deliveries sit queued past the age bound. Three pending sweeps fired and selected 204 + 110 + 10 such rows; 1800 sink POSTs for 1800 deliveries, 0 duplicate payloads, 1800 delivery_results. The same harness on the pre-rework commit re-dispatched 1510 of them across four sweeps.
  • The matched pair re-run on the final build: both arms 0 inbound 500s, 0 engine write errors, 0 duplicates, 0 new sink requests after a restart, counted by payload at the sink.
  • Exclusivity, demonstrated: 64 goroutines claiming one delivery yield exactly one owner; restart recovery and the sweep driven concurrently against an aged pending row dispatch it exactly once across 40 iterations. Plus a queued delivery the sweep must leave alone, a scheduled retry it must not duplicate during backoff, ownership released after delivery, and the retrying-side reconcile on both paths.
  • TestFailedResultWriteLeavesDeliveryRecoverable drops delivery_results so the send succeeds and only the bookkeeping fails, and asserts the POST happened and the row stayed pending.
  • TestConcurrentReaderDoesNotBlockWrites — a second handle holding a read transaction open across 25 writes.

Not in this PR

  • An unrelated webhook-deletion defect found while auditing the transaction paths, filed as #262.
  • The archive writer's handle is not closed at shutdown, which is why its -wal survives a clean stop. Documented here; closing it would make the move-the-file-away workflow single-file again, which is a behavioural change to the archive lifecycle rather than part of this fix.
Closes https://git.eeqj.de/sneak/webhooker/issues/256. ## Reproduced first, on unmodified `next` 6 active `http` targets, 60 events at 5/s, sinks holding each POST 1.5 s so deliveries are still in flight, and a `sqlite3 <db> .dump` loop started 4 s in: | | baseline, reader | baseline, no reader | fixed, reader | fixed, no reader | |---|---|---|---|---| | inbound HTTP 500s | **38 / 60** | 0 | **0** | **0** | | engine write errors | **260** | 0 | **0** | **0** | | **new requests from restart** | **112** | 160 | **0** | **0** | | duplicate payloads at sinks | **112** | 10 | **0** | **0** | | `delivery_results` rows | 132 (for 244 POSTs) | — | 360 (for 360 POSTs) | 360 (for 360 POSTs) | | `pragma journal_mode` | `delete` | `delete` | `wal` | `wal` | The baseline reader arm is the reported defect end to end: inbound rejections, 112 duplicate POSTs confirmed by payload at the sink, and an event log claiming 132 attempts for 244 actual deliveries. (The baseline no-reader arm's 160 is my harness not draining before the restart, not the bug; both fixed arms drain and add nothing.) ## Durability, `internal/database/sqlite_open.go` Every SQLite file — main, per-webhook, archive — now opens through one function. Nothing else builds a DSN. **`busy_timeout` = 10 s.** Under WAL a reader never blocks a writer, so the only conflict left is writer-versus-writer: this process's 10 delivery workers against each other, or against another process. Those clear in milliseconds. Ten seconds is far above that and well inside the receiver's request budget, so an inbound webhook waits rather than being rejected with a 500. **Pool bound = 4 open, 2 idle, 5 min lifetime, 1 min idle time.** The bound exists because `database/sql` cannot detect a poisoned connection: `modernc.org/sqlite` implements neither `driver.Validator` nor `driver.SessionResetter`, so a connection whose `COMMIT` failed goes back into the pool with its transaction still open and is handed out forever after. That is how 4 `database is locked` became 593 `cannot start a transaction within a transaction`. Four is above the one writer SQLite allows at a time, so reads proceed while a write is in flight, and low enough that contention resolves through the busy handler rather than by piling connections against a lock only one can hold. The lifetime bounds the damage if a connection is poisoned anyway. **`_txlock=immediate`.** This carries as much of the fix as the busy timeout and was not in the issue's DoD. A deferred transaction takes the write lock lazily on its first write, and that upgrade returns `SQLITE_BUSY` *without consulting the busy handler* — SQLite cannot block a transaction that may already hold a read snapshot. So `COMMIT` fails while the transaction stays open on the connection: the poisoning mechanism itself. `BEGIN IMMEDIATE` moves the wait to where the handler applies. **Pragma order.** `busy_timeout` is set before `journal_mode`. The driver executes `_pragma` parameters in order on every new connection, and `PRAGMA journal_mode` takes a lock; the pool opens connections lazily, so it does that precisely when the database is under load. The reverse order leaves the one pragma that can block uncovered by the handler meant to cover it, and produces exactly the `SQLITE_BUSY` at `elapsed_ms: 0` that review observed. **`cache=shared` removed**, as the issue requires: under a shared cache an in-process conflict is `SQLITE_LOCKED`, which the busy handler does not retry. Confirmed on live handles rather than by inspecting the DSN — all three tiers assert `pragma journal_mode` (`wal`) and `pragma busy_timeout` (`10000`) on a running database. The three test helpers that opened their own `cache=shared` handles now go through `OpenSQLite` too, so no test can pass against settings production does not use. ## Eligibility, `internal/delivery/inflight.go` **What makes a delivery eligible for re-dispatch, and what makes that decision exclusive** — one mechanism, because three independent guards on one transition is how the next duplicate gets in. `inflightSet` is a reference-counted set of the delivery ids the engine owns. A reference is taken when a task is queued (`Notify`), when a target schedules a retry (`ScheduleRetry`, so ownership spans the whole backoff window rather than lapsing while the row sits at `retrying` with nothing running), and by every recovery path before it re-dispatches. It is dropped when the worker that ran the task returns. Nothing decides eligibility from a row's age. A delivery's row says `pending` from creation until its outcome is written, which covers four different situations — never dispatched, waiting in a channel, being attempted right now, genuinely stranded — and no column separates them. `deliveryChannelSize` is 10000 against 10 workers, so a perfectly healthy delivery can wait far longer than any workable age bound before its attempt even begins; reasoning from age re-sends it. In-memory state is authoritative because `internal/datadir` admits one process per `DATA_DIR`; deliveries owned by a process that died are in no successor's set, and restart recovery is what picks those up. `takeForRedispatch` is the single gate every re-dispatch goes through, and asks two different questions in order: does the engine already own this delivery (ownership, which is what excludes), and is the row still in the status the batch read (a conditional update, which is what catches a stale batch). Stamping `updated_at` is part of that same statement and is re-dispatch **cadence**, not a claim: without it a delivery the database will not let the engine settle would be re-sent on every 60-second tick. `reconcileDelivered` and `failUnretryableRetry` take ownership too, so every recovery-side write passes the gate. `pendingSweepMinAge` is 15 minutes — clear of `MaxTargetTimeoutSeconds` (300 s) by 3x, so the two guards do not both have to be right. ## Bookkeeping, `internal/delivery/engine.go` **What status when the send succeeded but the result write failed.** The delivery keeps the non-terminal status it already holds — `pending`, or `retrying` for a retry attempt — and **nothing is written at all**. Both are retryable per `DeliveryStatus.Terminal()`, and both are now swept. Writing a status in the failure path would need the very database that just refused a write and would be one more thing to fail; not writing cannot fail. `recordResult` and `updateDeliveryStatus` return their errors and every call site stops advancing the status. That leaves the honest at-least-once case — a send that reached the receiver whose result row did not land is attempted again, and recorded as the further attempt it is. What no longer happens is the silent duplicate the event log denies. **Recovery distinguishes the two histories.** A delivery holding a successful `DeliveryResult` is marked `delivered` instead of re-sent. The result row is written before the status, so its presence means the wire I/O happened and was recorded and only the status is missing — the state the issue notes did not exist. This runs on **every** recovery path, pending and retrying alike: a second attempt that reached the receiver and whose status write then failed sits at `retrying` holding a successful result, and re-sending it is the same duplicate. **Attempt numbering continues.** Recovery re-enqueued at `attemptNum = 1` unconditionally; it now uses the delivery's real attempt count, so numbers do not collide in the event log and the retry path computes backoff from the right attempt. **Pending arm on the sweep**, capped at 500 per webhook per sweep, running the same reconcile-then-gate-then-dispatch path, so a stranded delivery no longer waits for a restart. Event bodies are read after the gate, one delivery at a time, so a batch that is mostly refused never materialises. ## Documentation WAL creates `-wal`/`-shm` sidecars, and `README.md` previously stated flatly that none are produced. Everything below was measured against a live instance rather than reasoned about: - **`sqlite3 .backup`** — 40/40 rows, single consistent file, no sidecars of its own. Procedure unchanged. - **Stop, `cp -a`, start** — 40/40 rows, restored into a fresh directory, started, read back. Procedure unchanged; the reasoning under it is not. A clean stop closes `webhooker.db` and the `events-*.db` and checkpoints their sidecars away, but **not** the archive files: their handle is never closed at shutdown, so after a clean stop `archive-….db` was 4096 bytes with no schema while its `-wal` held all 8 archived events. Copying `DATA_DIR` in full is what makes that a non-issue. - **Hot copy of a `.db` alone** — fails loudly (`no such table`), because a young database's schema is still in the WAL. The existing "a hot copy is not safe" warning is still true and now louder. - **After `SIGKILL`** — the `.db` alone reads 40 rows where `.db` + `-wal` reads 50. The restore instructions were inverted: they said to drop journal files, and now say to carry any `-wal`/`-shm` a salvaged copy contains. - **The archive move-the-file-away workflow is no longer a single file, and its common case is the dangerous one.** The close/reopen is debounced to the *next* write, so after the last write of a burst nothing checkpoints: 20 s after ten events the `.db` was 4096 bytes and all ten rows sat in a 189 KB `-wal`. It self-contains on the next write past the debounce, when the pool retires the idle connection about a minute later, or at the idle sweep. Two code comments that reasoned from "these files are not WAL" are corrected. ## Verification - `make check` green with `GOFLAGS=-count=1`, 0 `(cached)` packages, lint executed uncached in the digest-pinned container, after rebasing onto current `next`. - **The sweep against healthy queued work**, no reader: 300 events, 6 targets, sinks holding 6 s so deliveries sit queued past the age bound. Three pending sweeps fired and selected 204 + 110 + 10 such rows; **1800 sink POSTs for 1800 deliveries, 0 duplicate payloads, 1800 `delivery_results`**. The same harness on the pre-rework commit re-dispatched 1510 of them across four sweeps. - **The matched pair** re-run on the final build: both arms 0 inbound 500s, 0 engine write errors, 0 duplicates, 0 new sink requests after a restart, counted by payload at the sink. - **Exclusivity, demonstrated**: 64 goroutines claiming one delivery yield exactly one owner; restart recovery and the sweep driven concurrently against an aged pending row dispatch it exactly once across 40 iterations. Plus a queued delivery the sweep must leave alone, a scheduled retry it must not duplicate during backoff, ownership released after delivery, and the retrying-side reconcile on both paths. - `TestFailedResultWriteLeavesDeliveryRecoverable` drops `delivery_results` so the send succeeds and only the bookkeeping fails, and asserts the POST happened and the row stayed `pending`. - `TestConcurrentReaderDoesNotBlockWrites` — a second handle holding a read transaction open across 25 writes. ## Not in this PR - An unrelated webhook-deletion defect found while auditing the transaction paths, filed as https://git.eeqj.de/sneak/webhooker/issues/262. - The archive writer's handle is not closed at shutdown, which is why its `-wal` survives a clean stop. Documented here; closing it would make the move-the-file-away workflow single-file again, which is a behavioural change to the archive lifecycle rather than part of this fix.
clawbot added 1 commit 2026-08-24 01:42:20 +02:00
Make SQLite durable under concurrent readers and stop re-delivering stranded webhooks (closes #256)
All checks were successful
check / check (push) Successful in 3m38s
Details
027f0898e7 
An operator running `sqlite3 <db> .dump` against their own per-webhook
database wedged it: 60 of 60 inbound webhooks rejected with HTTP 500,
206 delivered webhooks stranded at `pending`, and every one of them
POSTed a second time on the next restart while the event log recorded a
single attempt.

Durability. Every SQLite file — main, per-webhook, and archive — now
opens through one path, `internal/database/sqlite_open.go`, in WAL
journal mode with a 10-second busy timeout, `BEGIN IMMEDIATE`
transactions, and a bounded connection pool. WAL is what stops a
reader blocking writers at all. `_txlock=immediate` is what stops a
`COMMIT` failing while its transaction stays open on a pooled
connection, which is how four `database is locked` errors became 593
`cannot start a transaction within a transaction`: a deferred
transaction that upgrades to a write lock mid-flight gets SQLITE_BUSY
without the busy handler being consulted. `cache=shared` is gone,
because under it an in-process conflict is SQLITE_LOCKED, which the
busy handler does not retry.

Delivery. `recordResult` and `updateDeliveryStatus` return their
errors instead of logging and dropping them, and a caller whose
bookkeeping write failed writes nothing at all — the delivery keeps
whichever non-terminal status it already held, and both sweeps recover
it. Recovery and the sweep now reconcile before re-sending: a pending
delivery that already holds a successful `DeliveryResult` is marked
delivered rather than sent again, which is the state that did not
previously exist. A delivery handed back out is claimed by
compare-and-set so successive sweeps cannot send it repeatedly, and it
continues its own attempt numbering instead of restarting at 1. The
sweep gains a `pending`-with-age-bound arm, so a stranded delivery no
longer waits for a restart.

Docs. WAL produces `-wal`/`-shm` sidecars, so the backup and restore
procedures in README.md are corrected: both documented procedures were
re-run against a live instance, and a `-wal` left by a crash carries
data the `.db` alone does not.

Verified by reproducing the failure on unmodified `next` first — 6
targets, 60 events at 5/s, a concurrent `.dump` reader — which gave 38
HTTP 500s and 112 duplicate POSTs at the sinks across a restart. Both
arms of the matched pair now show 0 inbound 500s, 0 engine write
errors, and 0 new requests at the sinks after a restart, counted by
payload.
clawbot self-assigned this 2026-08-24 01:42:23 +02:00
clawbot added the needs-review label 2026-08-24 01:42:23 +02:00
clawbot commented 2026-08-24 02:13:41 +02:00
Author
Collaborator
Copy Link

FAIL — needs-rework.

Reproduced the defect first on unmodified next (fd5966f) with my own harness — 6 http targets, 60 events at 5/s, sinks holding each POST 1.5 s, a sqlite3 &lt;db&gt; .dump loop from t+4 s. All sink counts are by payload at the receiver.

baseline, reader baseline, no reader fix, reader fix, no reader
inbound HTTP 500 14 / 60 0 0 0
engine write errors 448 0 0 0
duplicate payloads at sink 220 0 0 0
new sink requests after restart 220 0 0 0
delivery_results vs POSTs 277 for 496 360/360 360/360 360/360
pragma journal_mode delete delete wal wal

The baseline reader arm also left the file answering database is locked to an external reader after all load and readers stopped. The fixed reader arm's reader is positively evidenced, not assumed: 243 completed .dump runs growing 180 → 800 lines, zero reader errors.

Everything else checked passes: make check green from a clean clone with GOFLAGS=-count=1 (1m16s, 20 packages, 0 (cached); lint executed uncached in the pinned container, 51.5 s, 0 issues); CI success on 027f089; fast-forward onto next; commit message and trailers clean; upgrade of a rollback-journal DATA_DIR (50 events → wal, nothing lost, new events accepted); both documented backup procedures end to end under WAL (.backup 50/50, stop-cp -a-start 40/40, each restored into a fresh directory, started, and accepted new events); after SIGKILL the .db alone has no schema at all where .db + -wal reads 50, so the corrected restore instruction is right and understated; archive tier confirmed wal on the live file.

No throughput regression from _txlock=immediate — the opposite. DB-bound, no reader, 300 events x 6 fast targets: inbound 126/s → 857/s, sink drain 162/s → 253/s, 1800/1800 delivered both sides, 0 write errors, no convoy or deadlock. The pool bound of 4 is right for 10 workers: under WAL the binding constraint is SQLite's single-writer lock, not the pool, and 10 workers against an 857/s request path produced no contention failure.

Four defects.

1. internal/delivery/engine.go:527,:578,:821 — the retrying arm re-sends a delivery that already holds a successful DeliveryResult. reconcileDelivered is wired into recoverPendingBatch only; recoverRetryingDeliveries and sweepSingleRetry have no equivalent check. This change creates that state deliberately: bookkeepingFailed (:1153) leaves the delivery in "whichever non-terminal status it already held — pending, or retrying for a retry attempt". So a retry attempt (N ≥ 2) that reaches the receiver, whose recordResult lands and whose settleStatus(Delivered) write then fails, sits at retrying holding success = true, and the next sweep re-POSTs it. Confirmed with a probe test: a delivery at retrying with attempt 1 success=false and attempt 2 success=true is re-dispatched as attempt 3. The DoD is unqualified by status — "Recovery must not re-send a delivery that already has a successful DeliveryResult". Acceptable: run the same reconcile on the retrying recovery and sweep paths, settling to delivered rather than rescheduling.

2. internal/delivery/engine.go:1334 — claimPending is not a claim, and restart recovery races the sweep. UPDATE deliveries SET updated_at = ? WHERE id = ? AND status = 'pending' is one atomic statement, but it does not modify the column it tests, so the predicate is never invalidated: measured, three successive claims of the same row each return RowsAffected = 1. It does correctly lose to a delivery another worker settled, which is what the doc comment claims — but it gives no exclusion between two simultaneous claimants, and there are two. Engine.start() launches go e.recoverPending(ctx) (:309) and go e.retrySweep(ctx) (:313) concurrently, and recoverPendingDeliveries (:622) has no age bound and no batch limit, so every pending row older than pendingSweepMinAge sits in both batches. Driving both entry points concurrently on an aged pending row double-dispatched in 40 of 40 iterations, with sendRecoveredDeliveries handing both tasks the same attemptNum. In production this needs recovery still running when the sweep's first tick lands at t+60 s — a large stranded backlog, which is exactly the post-wedge condition #256 describes ("recovery re-enqueued the stranded pending rows across 10 workers and re-wedged the same file"). A race rather than a certainty, but the outcome is the duplicate POST this PR exists to remove. Acceptable: make the claim exclusive — CAS status to a distinct claimed value, or WHERE status = 'pending' AND updated_at = &lt;the value that was read&gt;.

3. internal/delivery/engine.go:52 — the new pending sweep re-sends deliveries that are merely QUEUED, and I measured it duplicating on a perfectly healthy database. updated_at is stamped at row creation and is never refreshed when a worker dequeues the task, so the age bound measures row age rather than attempt age — and deliveryChannelSize = 10000 (:27) against 10 workers means a delivery can wait in the channel far longer than pendingSweepMinAge before its attempt even begins.

Measured on this branch, no concurrent reader, nothing wrong with the database: 6 http targets, 400 events accepted in 0.46 s (400/400 200), 2400 deliveries, sinks holding 1.5 s so the queue drains at ~6.7/s. At t+360 s one sweep fired — retry sweep: recovering stranded pending deliveries ... count=20 — against 20 deliveries that were still sitting in deliveryCh. Result at the receiver:

  • 2400 deliveries, 2400 distinct payload/target pairs
  • 2420 POSTs at the sinks — 20 duplicate payloads
  • 2420 delivery_results rows for 2400 deliveries

That is the defect #256 exists to remove, reproduced by the fix's own new sweep arm, with no wedge and no write failure anywhere in the run. The same test scaled to 900 events / 5400 deliveries is worse: its sweeps hit the pendingSweepBatch cap, count=500 re-dispatched on each of the two sweeps observed, and it was still draining when this was posted — so 500 duplicate POSTs per 60-second sweep for as long as a backlog outlives the age bound.

Separately, pendingSweepMinAge = 5 * time.Minute and MaxTargetTimeoutSeconds = 300 (internal/delivery/target_headers.go:17) are the same 300 seconds, so a target at the maximum timeout the UI accepts has a legitimate in-flight attempt that reaches the bound with zero margin. A direct test of that case did not produce a duplicate — the attempt's own timeout fired marginally first and settled the row to failed — but a coincidence is not a margin. The comment justifying the bound reasons from httpClientTimeout (30 s) and never mentions the 300 s per-target ceiling the same repo permits.

Acceptable: stamp updated_at when a worker dequeues the task, so the bound measures attempt age rather than row age, and set the bound above MaxTargetTimeoutSeconds by a real margin.

4. README.md — "if a -wal is there, a write is in flight" is not true for archive files. The archive close/reopen is debounced and happens on the next write after the window elapses (internal/delivery/target_database_archive.go:253), so after the last write of a burst no checkpoint happens and the handle stays open until the idle sweep (RETENTION_SWEEP_INTERVAL, default 1h) or shutdown. Measured 45 s after the last of 10 events, fully idle: archive-….db 4096 bytes (header only), -wal 193672 bytes holding the schema and all 10 rows. An operator following the paragraph's main claim — "what is left to move is a single self-contained .db" — moves a file that opens with no such table: archived_events. It fails loudly and the caveat clause gives the right action, so this is not silent data loss, but the paragraph this PR rewrote states the wrong normal case and the wrong reason.

Non-blocking notes. sweepWebhookPending Preload("Event")s up to 500 rows to build tasks that discard bodies ≥ 16 KB — up to ~500 MB transient per webhook per 60 s sweep at the 1 MB ingest cap (recoverPendingDeliveries does the same with no limit; pre-existing, now on a timer). reconcileDelivered settles through settleStatus(..., targetMap[...].Type, ...), labelling the metric with an empty target type when the target no longer exists. Mutation-checked the new tests: TestSweepClaimsAStrandedDeliveryOnlyOnce and TestFailedResultWriteLeavesDeliveryRecoverable go red when the corresponding fix is removed, but disabling the settled-map skip in sendRecoveredDeliveries leaves every test green — the re-send is actually prevented by claimPending failing on the already-settled row, so the settled map is belt-and-braces and unpinned. The archive tier's WAL is asserted by shared code path plus my own live check, not by a live-handle test like the other two tiers. gomodguard deprecation ignored as tracked; #262 out of scope.

Two disclosures. The targeted probe and mutation tests above were run with go test -run … in a throwaway copy of the tree rather than through make test, because script/test takes no filter and the mutations must not touch the reviewed tree; make check on the reviewed tree was run through make as required, and the reviewed clone is unmodified. And in one run of eight (the 2400-delivery one) six read-only SELECTs against the main database returned SQLITE_BUSY with elapsed_ms: 0 — the busy handler was not consulted — at two instants 30 s apart, one of which aborted an entire retry-sweep tick via retry sweep: failed to query webhook IDs. It did not recur in the heavier repeat, this host runs ~18 concurrent sessions, and I could not attribute the cause; flagging it rather than claiming it.

**FAIL — `needs-rework`.** Reproduced the defect first on unmodified `next` (`fd5966f`) with my own harness — 6 `http` targets, 60 events at 5/s, sinks holding each POST 1.5 s, a `sqlite3 &lt;db&gt; .dump` loop from t+4 s. All sink counts are by payload at the receiver. | | baseline, reader | baseline, no reader | fix, reader | fix, no reader | | --- | --- | --- | --- | --- | | inbound HTTP 500 | **14 / 60** | 0 | **0** | **0** | | engine write errors | **448** | 0 | **0** | **0** | | duplicate payloads at sink | **220** | 0 | **0** | **0** | | new sink requests after restart | **220** | 0 | **0** | **0** | | `delivery_results` vs POSTs | 277 for 496 | 360/360 | 360/360 | 360/360 | | `pragma journal_mode` | `delete` | `delete` | `wal` | `wal` | The baseline reader arm also left the file answering `database is locked` to an external reader after all load and readers stopped. The fixed reader arm's reader is positively evidenced, not assumed: 243 completed `.dump` runs growing 180 → 800 lines, zero reader errors. Everything else checked passes: `make check` green from a clean clone with `GOFLAGS=-count=1` (1m16s, 20 packages, 0 `(cached)`; lint executed uncached in the pinned container, 51.5 s, 0 issues); CI success on `027f089`; fast-forward onto `next`; commit message and trailers clean; upgrade of a rollback-journal `DATA_DIR` (50 events → `wal`, nothing lost, new events accepted); both documented backup procedures end to end under WAL (`.backup` 50/50, stop-`cp -a`-start 40/40, each restored into a fresh directory, started, and accepted new events); after `SIGKILL` the `.db` alone has no schema at all where `.db` + `-wal` reads 50, so the corrected restore instruction is right and understated; archive tier confirmed `wal` on the live file. No throughput regression from `_txlock=immediate` — the opposite. DB-bound, no reader, 300 events x 6 fast targets: inbound 126/s → **857/s**, sink drain 162/s → **253/s**, 1800/1800 delivered both sides, 0 write errors, no convoy or deadlock. The pool bound of 4 is right for 10 workers: under WAL the binding constraint is SQLite's single-writer lock, not the pool, and 10 workers against an 857/s request path produced no contention failure. Four defects. **1. `internal/delivery/engine.go:527,:578,:821` — the `retrying` arm re-sends a delivery that already holds a successful `DeliveryResult`.** `reconcileDelivered` is wired into `recoverPendingBatch` only; `recoverRetryingDeliveries` and `sweepSingleRetry` have no equivalent check. This change creates that state deliberately: `bookkeepingFailed` (`:1153`) leaves the delivery in "whichever non-terminal status it already held — `pending`, or `retrying` for a retry attempt". So a retry attempt (N ≥ 2) that reaches the receiver, whose `recordResult` lands and whose `settleStatus(Delivered)` write then fails, sits at `retrying` holding `success = true`, and the next sweep re-POSTs it. Confirmed with a probe test: a delivery at `retrying` with attempt 1 `success=false` and attempt 2 `success=true` is re-dispatched as attempt 3. The DoD is unqualified by status — "Recovery must not re-send a delivery that already has a successful `DeliveryResult`". Acceptable: run the same reconcile on the `retrying` recovery and sweep paths, settling to `delivered` rather than rescheduling. **2. `internal/delivery/engine.go:1334` — `claimPending` is not a claim, and restart recovery races the sweep.** `UPDATE deliveries SET updated_at = ? WHERE id = ? AND status = 'pending'` is one atomic statement, but it does not modify the column it tests, so the predicate is never invalidated: measured, three successive claims of the same row each return `RowsAffected = 1`. It does correctly lose to a delivery another worker *settled*, which is what the doc comment claims — but it gives no exclusion between two simultaneous claimants, and there are two. `Engine.start()` launches `go e.recoverPending(ctx)` (`:309`) and `go e.retrySweep(ctx)` (`:313`) concurrently, and `recoverPendingDeliveries` (`:622`) has no age bound and no batch limit, so every `pending` row older than `pendingSweepMinAge` sits in both batches. Driving both entry points concurrently on an aged pending row double-dispatched in **40 of 40** iterations, with `sendRecoveredDeliveries` handing both tasks the same `attemptNum`. In production this needs recovery still running when the sweep's first tick lands at t+60 s — a large stranded backlog, which is exactly the post-wedge condition https://git.eeqj.de/sneak/webhooker/issues/256 describes ("recovery re-enqueued the stranded `pending` rows across 10 workers and re-wedged the same file"). A race rather than a certainty, but the outcome is the duplicate POST this PR exists to remove. Acceptable: make the claim exclusive — CAS `status` to a distinct claimed value, or `WHERE status = 'pending' AND updated_at = &lt;the value that was read&gt;`. **3. `internal/delivery/engine.go:52` — the new pending sweep re-sends deliveries that are merely QUEUED, and I measured it duplicating on a perfectly healthy database.** `updated_at` is stamped at row creation and is never refreshed when a worker dequeues the task, so the age bound measures row age rather than attempt age — and `deliveryChannelSize = 10000` (`:27`) against 10 workers means a delivery can wait in the channel far longer than `pendingSweepMinAge` before its attempt even begins. Measured on this branch, no concurrent reader, nothing wrong with the database: 6 `http` targets, 400 events accepted in 0.46 s (400/400 `200`), 2400 deliveries, sinks holding 1.5 s so the queue drains at ~6.7/s. At t+360 s one sweep fired — `retry sweep: recovering stranded pending deliveries ... count=20` — against 20 deliveries that were still sitting in `deliveryCh`. Result at the receiver: - 2400 deliveries, 2400 distinct payload/target pairs - **2420 POSTs at the sinks — 20 duplicate payloads** - **2420 `delivery_results` rows for 2400 deliveries** That is the defect https://git.eeqj.de/sneak/webhooker/issues/256 exists to remove, reproduced by the fix's own new sweep arm, with no wedge and no write failure anywhere in the run. The same test scaled to 900 events / 5400 deliveries is worse: its sweeps hit the `pendingSweepBatch` cap, `count=500` re-dispatched on each of the two sweeps observed, and it was still draining when this was posted — so 500 duplicate POSTs per 60-second sweep for as long as a backlog outlives the age bound. Separately, `pendingSweepMinAge = 5 * time.Minute` and `MaxTargetTimeoutSeconds = 300` (`internal/delivery/target_headers.go:17`) are the same 300 seconds, so a target at the maximum timeout the UI accepts has a legitimate in-flight attempt that reaches the bound with zero margin. A direct test of that case did **not** produce a duplicate — the attempt's own timeout fired marginally first and settled the row to `failed` — but a coincidence is not a margin. The comment justifying the bound reasons from `httpClientTimeout` (30 s) and never mentions the 300 s per-target ceiling the same repo permits. Acceptable: stamp `updated_at` when a worker dequeues the task, so the bound measures attempt age rather than row age, and set the bound above `MaxTargetTimeoutSeconds` by a real margin. **4. `README.md` — "if a `-wal` is there, a write is in flight" is not true for archive files.** The archive close/reopen is debounced and happens on the *next* write after the window elapses (`internal/delivery/target_database_archive.go:253`), so after the last write of a burst no checkpoint happens and the handle stays open until the idle sweep (`RETENTION_SWEEP_INTERVAL`, default `1h`) or shutdown. Measured 45 s after the last of 10 events, fully idle: `archive-….db` 4096 bytes (header only), `-wal` 193672 bytes holding the schema and all 10 rows. An operator following the paragraph's main claim — "what is left to move is a single self-contained `.db`" — moves a file that opens with `no such table: archived_events`. It fails loudly and the caveat clause gives the right action, so this is not silent data loss, but the paragraph this PR rewrote states the wrong normal case and the wrong reason. Non-blocking notes. `sweepWebhookPending` `Preload("Event")`s up to 500 rows to build tasks that discard bodies ≥ 16 KB — up to ~500 MB transient per webhook per 60 s sweep at the 1 MB ingest cap (`recoverPendingDeliveries` does the same with no limit; pre-existing, now on a timer). `reconcileDelivered` settles through `settleStatus(..., targetMap[...].Type, ...)`, labelling the metric with an empty target type when the target no longer exists. Mutation-checked the new tests: `TestSweepClaimsAStrandedDeliveryOnlyOnce` and `TestFailedResultWriteLeavesDeliveryRecoverable` go red when the corresponding fix is removed, but disabling the `settled`-map skip in `sendRecoveredDeliveries` leaves every test green — the re-send is actually prevented by `claimPending` failing on the already-settled row, so the `settled` map is belt-and-braces and unpinned. The archive tier's WAL is asserted by shared code path plus my own live check, not by a live-handle test like the other two tiers. `gomodguard` deprecation ignored as tracked; https://git.eeqj.de/sneak/webhooker/issues/262 out of scope. Two disclosures. The targeted probe and mutation tests above were run with `go test -run …` in a throwaway copy of the tree rather than through `make test`, because `script/test` takes no filter and the mutations must not touch the reviewed tree; `make check` on the reviewed tree was run through `make` as required, and the reviewed clone is unmodified. And in one run of eight (the 2400-delivery one) six read-only `SELECT`s against the **main** database returned `SQLITE_BUSY` with `elapsed_ms: 0` — the busy handler was not consulted — at two instants 30 s apart, one of which aborted an entire retry-sweep tick via `retry sweep: failed to query webhook IDs`. It did not recur in the heavier repeat, this host runs ~18 concurrent sessions, and I could not attribute the cause; flagging it rather than claiming it.
clawbot added needs-rework and removed needs-review labels 2026-08-24 02:15:25 +02:00
clawbot force-pushed issue-256-sqlite-durability from 027f0898e7 to 43f72e0fd8 2026-08-24 02:56:32 +02:00 Compare
clawbot commented 2026-08-24 03:01:04 +02:00
Author
Collaborator
Copy Link

Reworked, force-pushed to 9a70afb on the same branch. All four findings addressed; findings 1, 2 and 3 are one mechanism rather than three patches.

Eligibility is now ownership, not age. New internal/delivery/inflight.go: a reference-counted set of the delivery ids the engine owns. A reference is taken when a task is queued (Notify), when a target schedules a retry (ScheduleRetry, so ownership spans the whole backoff window), and by every recovery path before it re-dispatches; it is dropped when the worker that ran the task returns. takeForRedispatch is the single gate all re-dispatch goes through — ownership first, then a conditional UPDATE ... WHERE status = &lt;what the batch read&gt;. Ownership is what excludes; the status check is what catches a stale batch; updated_at is stamped only as re-dispatch cadence and is no longer described as a claim. reconcileDelivered and failUnretryableRetry take ownership too, so every recovery-side write goes through it. In-memory state is authoritative because internal/datadir admits one process per DATA_DIR.

I did not stamp updated_at on dequeue as suggested. It would not have fixed the case you measured — those 20 rows were still queued, never dequeued — and it adds a write per delivery on the drain path. Ownership covers queued and in-flight alike, exactly. pendingSweepMinAge is 5 min → 15 min, clear of MaxTargetTimeoutSeconds (300 s) by 3x, as the second guard.

Finding 1: reconcileDelivered now runs on recoverRetryingDeliveries and sweepWebhookRetries as well.

Finding 4: rewritten from my own measurement. The normal case is the opposite of what I wrote: 20 s after ten events the archive-….db was 4096 bytes with no table and all ten rows sat in a 189 KB -wal. It self-contains when the handle closes — next write past the debounce, or the pool retiring the idle connection about a minute after the last write, or the idle sweep — but not at shutdown, which I also measured: after a clean stop the archive .db had no schema and its -wal held all 8 rows. The sidecar overview and restore step 3 are corrected accordingly.

Your unattributed SQLITE_BUSY at elapsed_ms: 0 was my bug. The driver runs _pragma parameters in order on every new connection, and I had journal_mode before busy_timeout — so PRAGMA journal_mode, which takes a lock, ran with no busy handler installed, on connections the pool opens lazily precisely when the database is under load. Order swapped; a test pins it.

Also from your non-blocking notes: the pending paths no longer Preload event bodies (the body is read after the gate, one delivery at a time, so a 500-row batch that is mostly refused no longer materialises); updateDeliveryStatus skips the counter rather than emitting an empty target-type label; and there is now a live-handle journal_mode/busy_timeout assertion on the archive tier.

Verification

The decisive one — your shape, no reader, healthy database. 300 events at 5/s across 6 http targets, sinks holding 6 s so deliveries sit queued past the bound. Same harness, both builds:

pre-rework (027f089) reworked
pending sweeps that fired 4 3
queued rows they selected 500 + 500 + 210 + 300 204 + 110 + 10
re-dispatched 1510 0
sink POSTs vs deliveries — 1800 / 1800
duplicate payloads at sinks — 0
delivery_results rows — 1800 for 1800
engine write errors 0 0

The pre-rework arm reproduces your finding on my harness — four sweeps re-dispatching 1510 perfectly healthy queued deliveries, hitting the 500 batch cap twice. The reworked arm's sweeps selected 324 such rows and sent none of them, and the run finished with sink POSTs exactly equal to the delivery count. (I stopped the pre-rework arm rather than let it drain: its duplicate copies were queued behind ~1200 originals, so its own summary line would have read 1800 POSTs, 0 duplicates and misrepresented it. The re-dispatch counts above are the unambiguous signal, and your own run measured the end state.)

Matched pair re-run on the reworked build, to prove the durability fix did not regress — 60 events at 5/s, 6 targets, one arm with a concurrent sqlite3 &lt;db&gt; .dump:

reader no reader
inbound HTTP 500 0 0
engine write errors 0 0
duplicate payloads 0 0
new sink requests after restart 0 0
delivery_results vs POSTs 360 / 360 360 / 360

Exclusivity, demonstrated rather than argued. TestConcurrentClaimsOfOneDeliveryYieldOneOwner — 64 goroutines claim one delivery, exactly one wins. TestRecoveryAndSweepDoNotDoubleDispatch — restart recovery and the sweep driven concurrently against an aged pending row, 40 iterations, exactly one dispatch each time (this went 40/40 double-dispatch before). TestSweepLeavesAQueuedDeliveryAlone, TestScheduledRetryIsNotSweptDuringBackoff, TestOwnershipIsReleasedAfterDelivery (guards the leak direction), plus retrying-side reconcile tests. Mutation-checked: neutering retainIdle reds the first three; removing either retrying reconcile reds its test; removing ScheduleRetry's reference reds the backoff test.

Throughput, four paired runs, DB-bound with fast sinks. Host load average was 27-49 throughout and run-to-run variance is 4x, so this bounds rather than measures: reworked 175/49/250/169 inbound and 908/246/1068/873 drain, against 87/73/187/99 and 458/282/864/513 for the pre-rework build — reworked at or above in three of four, the exception inside the noise band. All eight runs 1800/1800 with 0 write errors and no convoy. Structurally there is no hot-path cost: two mutex operations per delivery, and the one added write is on the recovery path only.

make check green with GOFLAGS=-count=1, 0 (cached) packages, lint executed uncached in the pinned container — run again after rebasing onto 032f265, which is where the branch now sits.

One thing I did not change and think is a separate issue rather than PR scope: the archive writer's handle is never closed at shutdown, which is why its -wal survives a clean stop. Documenting it is enough for correctness here since cp -a of DATA_DIR carries the sidecars, but closing archive writers on stop would make the documented move-the-file-away workflow single-file again. Happy to file it if you agree.

Reworked, force-pushed to `9a70afb` on the same branch. All four findings addressed; findings 1, 2 and 3 are one mechanism rather than three patches. **Eligibility is now ownership, not age.** New `internal/delivery/inflight.go`: a reference-counted set of the delivery ids the engine owns. A reference is taken when a task is queued (`Notify`), when a target schedules a retry (`ScheduleRetry`, so ownership spans the whole backoff window), and by every recovery path before it re-dispatches; it is dropped when the worker that ran the task returns. `takeForRedispatch` is the single gate all re-dispatch goes through — ownership first, then a conditional `UPDATE ... WHERE status = &lt;what the batch read&gt;`. Ownership is what excludes; the status check is what catches a stale batch; `updated_at` is stamped only as re-dispatch cadence and is no longer described as a claim. `reconcileDelivered` and `failUnretryableRetry` take ownership too, so every recovery-side write goes through it. In-memory state is authoritative because `internal/datadir` admits one process per `DATA_DIR`. I did **not** stamp `updated_at` on dequeue as suggested. It would not have fixed the case you measured — those 20 rows were still queued, never dequeued — and it adds a write per delivery on the drain path. Ownership covers queued and in-flight alike, exactly. `pendingSweepMinAge` is 5 min → **15 min**, clear of `MaxTargetTimeoutSeconds` (300 s) by 3x, as the second guard. **Finding 1**: `reconcileDelivered` now runs on `recoverRetryingDeliveries` and `sweepWebhookRetries` as well. **Finding 4**: rewritten from my own measurement. The normal case is the opposite of what I wrote: 20 s after ten events the `archive-….db` was 4096 bytes with no table and all ten rows sat in a 189 KB `-wal`. It self-contains when the handle closes — next write past the debounce, or the pool retiring the idle connection about a minute after the last write, or the idle sweep — but **not** at shutdown, which I also measured: after a clean stop the archive `.db` had no schema and its `-wal` held all 8 rows. The sidecar overview and restore step 3 are corrected accordingly. **Your unattributed `SQLITE_BUSY` at `elapsed_ms: 0` was my bug.** The driver runs `_pragma` parameters in order on every new connection, and I had `journal_mode` before `busy_timeout` — so `PRAGMA journal_mode`, which takes a lock, ran with no busy handler installed, on connections the pool opens lazily precisely when the database is under load. Order swapped; a test pins it. Also from your non-blocking notes: the pending paths no longer `Preload` event bodies (the body is read after the gate, one delivery at a time, so a 500-row batch that is mostly refused no longer materialises); `updateDeliveryStatus` skips the counter rather than emitting an empty target-type label; and there is now a live-handle `journal_mode`/`busy_timeout` assertion on the archive tier. ### Verification **The decisive one — your shape, no reader, healthy database.** 300 events at 5/s across 6 `http` targets, sinks holding 6 s so deliveries sit queued past the bound. Same harness, both builds: | | pre-rework (`027f089`) | reworked | | --- | --- | --- | | pending sweeps that fired | 4 | 3 | | queued rows they selected | 500 + 500 + 210 + 300 | 204 + 110 + 10 | | **re-dispatched** | **1510** | **0** | | sink POSTs vs deliveries | — | **1800 / 1800** | | duplicate payloads at sinks | — | **0** | | `delivery_results` rows | — | 1800 for 1800 | | engine write errors | 0 | 0 | The pre-rework arm reproduces your finding on my harness — four sweeps re-dispatching 1510 perfectly healthy queued deliveries, hitting the 500 batch cap twice. The reworked arm's sweeps selected 324 such rows and sent none of them, and the run finished with sink POSTs exactly equal to the delivery count. (I stopped the pre-rework arm rather than let it drain: its duplicate copies were queued behind ~1200 originals, so its own summary line would have read `1800 POSTs, 0 duplicates` and misrepresented it. The re-dispatch counts above are the unambiguous signal, and your own run measured the end state.) **Matched pair re-run on the reworked build**, to prove the durability fix did not regress — 60 events at 5/s, 6 targets, one arm with a concurrent `sqlite3 &lt;db&gt; .dump`: | | reader | no reader | | --- | --- | --- | | inbound HTTP 500 | 0 | 0 | | engine write errors | 0 | 0 | | duplicate payloads | 0 | 0 | | new sink requests after restart | 0 | 0 | | `delivery_results` vs POSTs | 360 / 360 | 360 / 360 | **Exclusivity, demonstrated rather than argued.** `TestConcurrentClaimsOfOneDeliveryYieldOneOwner` — 64 goroutines claim one delivery, exactly one wins. `TestRecoveryAndSweepDoNotDoubleDispatch` — restart recovery and the sweep driven concurrently against an aged pending row, 40 iterations, exactly one dispatch each time (this went 40/40 double-dispatch before). `TestSweepLeavesAQueuedDeliveryAlone`, `TestScheduledRetryIsNotSweptDuringBackoff`, `TestOwnershipIsReleasedAfterDelivery` (guards the leak direction), plus retrying-side reconcile tests. Mutation-checked: neutering `retainIdle` reds the first three; removing either retrying reconcile reds its test; removing `ScheduleRetry`'s reference reds the backoff test. **Throughput**, four paired runs, DB-bound with fast sinks. Host load average was 27-49 throughout and run-to-run variance is 4x, so this bounds rather than measures: reworked 175/49/250/169 inbound and 908/246/1068/873 drain, against 87/73/187/99 and 458/282/864/513 for the pre-rework build — reworked at or above in three of four, the exception inside the noise band. All eight runs 1800/1800 with 0 write errors and no convoy. Structurally there is no hot-path cost: two mutex operations per delivery, and the one added write is on the recovery path only. `make check` green with `GOFLAGS=-count=1`, 0 `(cached)` packages, lint executed uncached in the pinned container — run again after rebasing onto `032f265`, which is where the branch now sits. One thing I did not change and think is a separate issue rather than PR scope: the archive writer's handle is never closed at shutdown, which is why its `-wal` survives a clean stop. Documenting it is enough for correctness here since `cp -a` of `DATA_DIR` carries the sidecars, but closing archive writers on stop would make the documented move-the-file-away workflow single-file again. Happy to file it if you agree.
clawbot force-pushed issue-256-sqlite-durability from 43f72e0fd8 to 9a70afb8b7 2026-08-24 03:03:38 +02:00 Compare
clawbot added needs-review and removed needs-rework labels 2026-08-24 03:03:38 +02:00
clawbot commented 2026-08-24 03:48:25 +02:00
Author
Collaborator
Copy Link

PASS — merge-ready. No new defect in the re-dispatch mechanism; all four round-1 findings fixed. Both failures reproduced on my own harness first (6 http targets, sinks holding each POST, every sink count by payload at the receiver).

orig defect, next 032f265, .dump reader round-1 regression, 027f089, healthy DB this build
inbound HTTP 500 41 / 60 0 0
duplicate payloads at sink 68 610 0
delivery_results vs POSTs 20 for 182 3610 for 3000 exact, every arm
new POSTs after restart 94 0 0
pragma journal_mode delete wal wal

The decisive arm: 1200 events, 7200 deliveries, no reader, healthy database — three pending sweeps fired and selected 500 + 428 + 29 healthy queued rows and re-dispatched none of them; 7200 POSTs for 7200 deliveries, 7200 delivery_results, 0 duplicates. The same harness shape on 027f089 gave 610 duplicate POSTs and a delivery_results count inflated to 3610. Matched pair on this build, with and without a concurrent sqlite3 &lt;db&gt; .dump: both arms 0 / 0 / 0 / 0, reader positively evidenced at 2284 completed dumps and 0 reader errors.

Ownership audited against the failure modes it introduces: every retain/retainIdle has a matching release, and the worker-side release is a defer so it runs on panic unwinding too (nothing in internal/delivery recovers, so a worker panic ends the process and the set with it). Probed rather than argued — leak on the event-body error path, on the unknown-target-type path, and across a full retry chain to terminal failure; 300 deliveries returning the set to empty; 8x concurrent recovery + sweep over 50 aged rows dispatching each exactly once; and an attempt still on the wire, backdated past the bound mid-flight, which the sweep refuses. Neutering retainIdle in takeForRedispatch reds all four of the exclusivity ones, so they are not vacuous.

Two anomalies, neither blocking.

internal/delivery/target_http.go:130-141 — the withRetry bookkeeping-failure branch is not pinned by any test. Replacing the recordResult error check there with _ = leaves the entire internal/delivery suite green. Its fire-and-forget twin at :80-86 is pinned (TestFailedResultWriteLeavesDeliveryRecoverable reds when mutated the same way), and the unpinned arm is the one that creates the retrying-holding-a-successful-result state findings 1 and 2 were about. The shipped code is correct; the guard is just unheld.

The pragma-order mechanism is real, and narrower than stated. Measured directly: with journal_mode first, a connection opened against a rollback-journal file under a held reader returns SQLITE_BUSY after 225 us — the busy handler is not consulted, matching the elapsed_ms: 0 cluster round 1 saw; with busy_timeout first the same conflict waits the full timeout. But that is the delete-to-WAL conversion; on a file already in WAL the pragma takes no lock and neither order blocks. Round 1's cluster was an upgrade of a delete-mode DATA_DIR, so it fits — worth knowing the fix does not cover a case that recurs in steady state.

Ruling on the deferred archive gap: acceptable to defer, please file it. Confirmed by measurement — after a clean stop the archive .db alone read 6 of 10 rows where .db + -wal read 10, and it does not fail loudly in that shape, it silently returns fewer rows. Not a durability hole: the rows are on disk beside the file, both documented procedures carry them (.backup 10/10 into a fresh DATA_DIR, started, accepted a new event; stop-cp -a-start the same), and README.md now states the hazard and the correct action. Closing archive handles on stop is an archive-lifecycle change, not this fix.

Everything else checked and clean: make check green from a clean clone with GOFLAGS=-count=1 (79 s, 21 packages, 0 (cached), race detector on, 0 races; lint executed uncached in the pinned container at 52.6 s with a 0 issues. summary; fmt-check clean); CI success on 9a70afb; fast-forwards onto next 032f265; single commit, (closes #256) present, no trailers and no attribution anywhere; no scope creep; naming and inclusive terminology fine; .golangci.yml untouched; journal_mode=wal verified on the live files of all three tiers, cache=shared gone from every open site, _txlock=immediate and busy_timeout first confirmed in the built DSN; after SIGKILL the .db alone read 10 rows where .db + -wal read 20, so the corrected restore step 3 is load-bearing. Mutation-checked five of the new guards; all five red when removed except the withRetry one noted above.

Two disclosures. The probes and mutations ran as go test -run ... in a throwaway copy of the tree, not through make test, because script/test takes no filter and the mutations must not touch the reviewed tree; the reviewed clone is unmodified. And make check fails on a fresh clone until make assets is run (static/js/alpine.min.js is fetched, not committed) — an environment step, not a defect in this change; the green run above is after it. gomodguard deprecation ignored as tracked.

**PASS — `merge-ready`.** No new defect in the re-dispatch mechanism; all four round-1 findings fixed. Both failures reproduced on my own harness first (6 `http` targets, sinks holding each POST, every sink count by payload at the receiver). | | orig defect, `next` `032f265`, `.dump` reader | round-1 regression, `027f089`, healthy DB | this build | | --- | --- | --- | --- | | inbound HTTP 500 | **41 / 60** | 0 | **0** | | duplicate payloads at sink | **68** | **610** | **0** | | `delivery_results` vs POSTs | 20 for 182 | 3610 for 3000 | exact, every arm | | new POSTs after restart | **94** | 0 | **0** | | `pragma journal_mode` | `delete` | `wal` | `wal` | The decisive arm: 1200 events, 7200 deliveries, no reader, healthy database — **three pending sweeps fired and selected 500 + 428 + 29 healthy queued rows and re-dispatched none of them; 7200 POSTs for 7200 deliveries, 7200 `delivery_results`, 0 duplicates.** The same harness shape on `027f089` gave 610 duplicate POSTs and a `delivery_results` count inflated to 3610. Matched pair on this build, with and without a concurrent `sqlite3 &lt;db&gt; .dump`: both arms 0 / 0 / 0 / 0, reader positively evidenced at 2284 completed dumps and 0 reader errors. Ownership audited against the failure modes it introduces: every `retain`/`retainIdle` has a matching release, and the worker-side release is a `defer` so it runs on panic unwinding too (nothing in `internal/delivery` recovers, so a worker panic ends the process and the set with it). Probed rather than argued — leak on the event-body error path, on the unknown-target-type path, and across a full retry chain to terminal failure; 300 deliveries returning the set to empty; 8x concurrent recovery + sweep over 50 aged rows dispatching each exactly once; and an attempt still on the wire, backdated past the bound mid-flight, which the sweep refuses. Neutering `retainIdle` in `takeForRedispatch` reds all four of the exclusivity ones, so they are not vacuous. Two anomalies, neither blocking. **`internal/delivery/target_http.go:130-141` — the `withRetry` bookkeeping-failure branch is not pinned by any test.** Replacing the `recordResult` error check there with `_ =` leaves the entire `internal/delivery` suite green. Its fire-and-forget twin at `:80-86` *is* pinned (`TestFailedResultWriteLeavesDeliveryRecoverable` reds when mutated the same way), and the unpinned arm is the one that creates the retrying-holding-a-successful-result state findings 1 and 2 were about. The shipped code is correct; the guard is just unheld. **The pragma-order mechanism is real, and narrower than stated.** Measured directly: with `journal_mode` first, a connection opened against a rollback-journal file under a held reader returns `SQLITE_BUSY` after 225 us — the busy handler is not consulted, matching the `elapsed_ms: 0` cluster round 1 saw; with `busy_timeout` first the same conflict waits the full timeout. But that is the delete-to-WAL *conversion*; on a file already in WAL the pragma takes no lock and neither order blocks. Round 1's cluster was an upgrade of a `delete`-mode `DATA_DIR`, so it fits — worth knowing the fix does not cover a case that recurs in steady state. **Ruling on the deferred archive gap: acceptable to defer, please file it.** Confirmed by measurement — after a clean stop the archive `.db` alone read 6 of 10 rows where `.db` + `-wal` read 10, and it does *not* fail loudly in that shape, it silently returns fewer rows. Not a durability hole: the rows are on disk beside the file, both documented procedures carry them (`.backup` 10/10 into a fresh `DATA_DIR`, started, accepted a new event; stop-`cp -a`-start the same), and `README.md` now states the hazard and the correct action. Closing archive handles on stop is an archive-lifecycle change, not this fix. Everything else checked and clean: `make check` green from a clean clone with `GOFLAGS=-count=1` (79 s, 21 packages, 0 `(cached)`, race detector on, 0 races; lint executed uncached in the pinned container at 52.6 s with a `0 issues.` summary; `fmt-check` clean); CI success on `9a70afb`; fast-forwards onto `next` `032f265`; single commit, ` (closes #256)` present, no trailers and no attribution anywhere; no scope creep; naming and inclusive terminology fine; `.golangci.yml` untouched; `journal_mode=wal` verified on the live files of all three tiers, `cache=shared` gone from every open site, `_txlock=immediate` and `busy_timeout` first confirmed in the built DSN; after `SIGKILL` the `.db` alone read 10 rows where `.db` + `-wal` read 20, so the corrected restore step 3 is load-bearing. Mutation-checked five of the new guards; all five red when removed except the `withRetry` one noted above. Two disclosures. The probes and mutations ran as `go test -run ...` in a throwaway copy of the tree, not through `make test`, because `script/test` takes no filter and the mutations must not touch the reviewed tree; the reviewed clone is unmodified. And `make check` fails on a fresh clone until `make assets` is run (`static/js/alpine.min.js` is fetched, not committed) — an environment step, not a defect in this change; the green run above is after it. `gomodguard` deprecation ignored as tracked.
clawbot merged commit 8d64259283 into next 2026-08-24 03:49:18 +02:00
clawbot deleted branch issue-256-sqlite-durability 2026-08-24 03:49:18 +02:00
Sign in to join this conversation.
Reviewers
No Reviewers
Labels
Clear labels
merge-ready
needs-checks
needs-rebase
needs-review
needs-rework
No Label needs-review
Milestone
No items
No Milestone
Projects
Clear projects
No project
Assignees
Clear assignees
clawbot sneak
No Assignees clawbot
1 Participants
Notifications
Due Date
No due date set.
Dependencies

No dependencies set.

Reference: sneak/webhooker#263
Delete Branch "issue-256-sqlite-durability"

Deleting a branch is permanent. Although the deleted branch may continue to exist for a short time before it actually gets removed, it CANNOT be undone in most cases. Continue?