DEV Community

Ace Meridian
Ace Meridian

Posted on Originally published at Medium

Count Rows, Not Errors: 7 Data Bugs I Reproduced

To find out whether a write path loses data, count rows in the source of truth after a forced failure or a concurrent run; the error rate will not tell you. In seven bugs I reproduced over the past week, every call that lost or duplicated data returned success, and one independent count caught each bug.

This story was written with the assistance of an AI writing program. Each case ran on the real software (PostgreSQL 16.4, Kafka 4.4.0, Elasticsearch 7.17.29, Redis 8.10.2, SQLite 3.46.1); only the external payment and webhook providers were simulated. Each section ends with the check that caught the bug.

1. A Caught Exception Rolled Back the Row It Protected

A migration dual-writes in one Spring @Transactional method: insert into the legacy table, then into the new one inside a try/catch that counts failures and queues the id for repair. I left out the new table's December partition and recorded 20 events, 10 in December.

All 20 calls returned normally, and nothing was logged at WARN or ERROR. The legacy table, the source of truth, held 10 rows: PostgreSQL aborts the whole transaction when one statement fails, so COMMIT silently rolled back (pgjdbc 42.7.8 and 42.2.5). None of the 10 queued ids existed in legacy, so repair had nothing to copy.

// as written: 20 calls OK, the legacy table keeps 10 of 20 rows
@Transactional
public void record(OrderEvent e) {
  legacyInsert(e);
  try { v2Insert(e); } catch (DataAccessException ex) { caught(e, ex); }
}
// fix: nested is a TransactionTemplate with PROPAGATION_NESTED (a savepoint)
@Transactional
public void recordNested(OrderEvent e) {
  legacyInsert(e);
  try { nested.executeWithoutResult(s -> v2Insert(e)); } catch (DataAccessException ex) { caught(e, ex); }
}
Enter fullscreen mode Exit fullscreen mode

The savepoint kept all 20 legacy rows, as did autosave=always on the JDBC URL. 2,000 clean writes took 3,150/3,005 ms instead of 2,646/2,850.

Check: after a forced failure, count the legacy table, not the failure counter.

2. Exactly-Once Kafka Paid 20 of 40 Payouts Twice

One partition, 40 payouts, read_committed, one transaction per poll of 20. Nothing crashed. One provider call took 12 s, past max.poll.interval.ms (10 s), so a second consumer took the partition and restarted at offset 0. The first, still alive, paid the other 14 payouts of its batch after the handover; its CommitFailedException came about 8 s later.

With a fresh UUID as the idempotency key per attempt, 20 of 40 payouts were paid twice, in both runs and under KIP-848. Kafka looked perfect: committed offset 40, 40 output records. A key derived from the payout, "payout:" + payoutId, turned 60 provider calls into 40 transfers.

Check: count transfers per payout id at the provider.

3. A Conditional UPDATE Protected the Row, Not the Charge

Two checkouts of one order, 0 to 20 ms apart, each read pending, called the provider, then ran UPDATE ... WHERE status = 'pending'. The loser's UPDATE matched 0 rows after its charge went out: 100 of 100 orders were charged twice. Claiming before the call brought it to 0:

def claim(conn, oid):
    attempt = uuid.uuid4().hex
    cur = conn.execute("UPDATE orders SET status = 'charging', attempt_id = %s WHERE id = %s AND status = 'pending'", (attempt, oid))
    if cur.rowcount == 0:
        return 'skip'
    provider(oid)
    cur = conn.execute("UPDATE orders SET status = 'paid', updated_at = now() WHERE id = %s AND status = 'charging' AND attempt_id = %s", (oid, attempt))
    return 'paid' if cur.rowcount == 1 else 'lost'
Enter fullscreen mode Exit fullscreen mode

In production, also pass attempt_id to the provider as its idempotency key; my fake took none.

Check: fire two checkouts 0 to 20 ms apart and count provider calls.

4. The Checkpoint Reached the Max and Still Skipped Events

A projector read WHERE global_seq > checkpoint on a BIGSERIAL column. The number is assigned at INSERT; the row becomes visible at COMMIT. If 101 commits before 100, the projector checkpoints 101 and never reads 100. With 8 concurrent writers the checkpoint reached max(global_seq) every run, yet 201 to 214 of 3,228 events were never projected. One writer missed 0.

Storing pg_current_xact_id() per event, reading only tx_id < pg_snapshot_xmin(pg_current_snapshot()) and checkpointing on (tx_id, global_seq) missed 0 in 8 runs. The price: any open write transaction stalls the projection.

Check: after the drain, events must equal projected rows.

5. bulk.close() Returned Before the Last Bulks Landed

An Elasticsearch reindex fed a BulkProcessor (5,000 actions, 2 concurrent requests), called close(), then swapped the alias. close() is awaitClose(0, NANOSECONDS), so two bulks, 10,000 documents, were still in flight. Counts through the alias right after the swap: 45,676, 68,830 and 70,116 of 100,000 (the 1 s refresh hid the rest). failedItems stayed 0. awaitClose(60, SECONDS) plus a refresh gave 100,000 in 3 of 3 runs.

Check: swap only after awaitClose returns true and the new count equals the source count.

6. A Webhook Got a 200 and Was Processed Zero Times

The handler claimed the delivery key in Redis with SET NX PX 30000, then processed. Processing threw, the handler returned 500, and the claim stayed. The retry at t=5 s hit the claim and got a 200 for "in progress"; most providers stop on any 2xx. At t=31 s the claim had expired with no done marker: processed 0 times. Releasing the claim in the catch (random token, Lua compare-and-delete) let the 5 s retry process it once. Answer 409 for in-progress claims.

Check: make the handler throw once, replay 5 s later, count successful runs.

7. Eight SQLite Workers Committed 2,000 Times and Kept 250

Eight Python processes each added 1 to one row 250 times: read, update, commit. All 2,000 commits succeeded; the counter ended at 250 in six of six runs. Default sqlite3 opens the transaction at the UPDATE, after the read, and the 5 s busy timeout turned contention into waiting, not errors. BEGIN IMMEDIATE before the read gave 2,000. Full write-up here.

Check: N workers add 1 M times each; assert the result is N × M.

What I Test Now

Error rates count calls that failed; all seven bugs lived in calls that succeeded. Before I trust a write path:

  • Force one failure, then count the source of truth.
  • Count external side effects per business id.
  • Test with concurrent writers: the checkpoint gap was 0 with one writer, about 200 with eight.
  • Count before switching reads: alias, checkpoint, new table.
  • Replay a delivery after a failure; claims and dedupe keys break on the second attempt.

Top comments (0)