bug(cash-out): a jammed dispense takes the customer's sats, tells the server nothing, over-counts the cassette, and leaves the machine advertising itself as available #122

Open
opened 2026-10-09 07:16:28 +00:00 by padreug · 3 comments
Owner

Sintra, 2026-10-09 01:02 CST. A customer paid a 40 EUR cash-out (54 440 sats) and got no cash. A 20 EUR note was found jammed just past the cassette exit. Three separate defects stacked up on one transaction; the money one is first.

Machine-side record is complete and correct:

txid        = tx_mv0madw6_wdhtea1v
type        = cash_out
fiat_cents  = 4000
sats        = 54440
status      = dispense_error
error       = Dispensing, code: 78 42
created_at  = 1791529353167

Timeline from the journal:

01:02:12  CONFIRM_AMOUNT → invoice 54440 sats (2 × 20 EUR @ 1361 sats/EUR)
01:02:21  Settlement watch armed in 3421 ms (hash 6f216df32c36…)
01:02:30  [ATM Service] Invoice paid (poll)!          ← customer's money is gone
01:02:30  [ATM] Dispensing via IPC: 20x2
01:02:32  response <Buffer f0 03 99 78 42 …>
01:02:32  found error code: 78 42
01:02:33  State: {"cashOut":"dispenseError"}
01:02:33  Recorded transaction: tx_mv0madw6_wdhtea1v cash_out (dispense_error)
01:02:33  Persisted inventory updated: 20x66 50x60     ← unchanged
01:02:45  CANCEL → "locked"
01:03:37  [Availability] {"cash_in":true,"cash_out":true,"cash_level":"full"}

1. The failure never leaves the machine (the money defect)

dispenseError is a terminal local state. The row above is written to state.db, the screen counts down 30s, and that is the end of it. Nothing publishes the outcome, nothing alerts, nothing refunds — grep -riE "refund|reversal|compensat|notify.*fail" across apps/ and packages/ returns nothing on the money path. So the operator's view is an LNbits payment marked processed with no hint of trouble, and the only record that a customer is owed 40 EUR lives on the ATM's own disk.

The hook for fixing this already exists: generateInvoice puts extra.txid on the invoice (apps/machine/src/services/lightning.ts:1004-1011), so the server can join a payment to a machine transaction. What's missing is the machine ever telling it the join came out bad. #78 noted in passing that "only spirekeeper-side reconciliation would ever notice" — this is that gap arriving in production, on a transaction that was watched correctly and recorded correctly.

A terminal dispense failure should publish the outcome for the txid the payment already carries, so the operator sees an owed-cash queue instead of a clean processed.

2. A mid-transport jam is recorded as dispensed: 0, so the ledger over-counts

The F56 reports per-bay dispensed/rejected alongside the error. Decoding the response bytes: error code at res[3..5] = 78 42; dispensed at 0x27 = 30 30 → 0; rejected at 0x2f = 30 30 → 0. A note that left the bay and stopped in the transport completes neither counter, so the driver faithfully reports nothing moved.

Consequences, all visible in the log above:

  • hal-service.ts:320 decrements each bay by result.value[i].dispensed — zero, so the bay stays at 66.
  • atm.ts:628-634 sees totalDispensed === 0, keeps status = dispense_error (not partial) and writes bills = [].
  • markCountsUncertain (atm.ts:645-657) is the safety net for exactly this — "bills may well have reached the customer, and nothing knows how many" — but it only fires when dispenseResult is absent. A structured report claiming dispensed: 0 is trusted outright, so countsUncertainSince was never set (meta has no such key).
  • publishCassettesState() then republished 20x66 as fact, three times since.

cassettes says 66 twenties. The cassette holds 65 and the transport holds one. A dispensed: 0 accompanied by an error is not evidence that nothing left the bay — it should route to the same uncertainty flag as a missing report.

3. The availability beacon has no notion of dispenser health

useAvailabilityBroadcast.computeSnapshot() derives cashOut from totalBills > 0 and nothing else. So 64 seconds after a jam that will block every subsequent dispense, sintra published {"cash_in":true,"cash_out":true,"cash_level":"full"}, and has kept republishing it every 5 minutes since.

This is what turns one bad transaction into many. dispenseCash re-inits the dispenser on the next attempt (hal-service.ts:255-259), but a note physically stuck in the transport path isn't cleared by re-initialising — so the next customer to tap, pay, and wait would have lost their money the same way. Nothing in the beacon, and nothing in the locked state the machine returned to, stops them.

#27 already classifies JAM as terminal ("bill stuck in transport path, will block all cassettes") and correctly says don't retry it. The missing half is that terminal means stop advertising cash-out until an operator clears it and confirms a recount.

Scope note

Distinct from #78 (payment with no machine row at all — unwatched window) and #27 (retry/fallback across cassettes on recoverable pickup errors). Here the watcher worked, the record is right, and the hardware error was correctly terminal; what failed is everything after the error.

Suggested split if these want to be separate: (1) is the release-blocker, (2) is a correctness fix in the dispenseResult interpretation, (3) is a beacon/health-gate feature. They're filed together because one transaction produced all three and (3) is what makes (1) recur.

Sintra, 2026-10-09 01:02 CST. A customer paid a 40 EUR cash-out (54 440 sats) and got no cash. A 20 EUR note was found jammed just past the cassette exit. Three separate defects stacked up on one transaction; the money one is first. Machine-side record is complete and correct: ``` txid = tx_mv0madw6_wdhtea1v type = cash_out fiat_cents = 4000 sats = 54440 status = dispense_error error = Dispensing, code: 78 42 created_at = 1791529353167 ``` Timeline from the journal: ``` 01:02:12 CONFIRM_AMOUNT → invoice 54440 sats (2 × 20 EUR @ 1361 sats/EUR) 01:02:21 Settlement watch armed in 3421 ms (hash 6f216df32c36…) 01:02:30 [ATM Service] Invoice paid (poll)! ← customer's money is gone 01:02:30 [ATM] Dispensing via IPC: 20x2 01:02:32 response <Buffer f0 03 99 78 42 …> 01:02:32 found error code: 78 42 01:02:33 State: {"cashOut":"dispenseError"} 01:02:33 Recorded transaction: tx_mv0madw6_wdhtea1v cash_out (dispense_error) 01:02:33 Persisted inventory updated: 20x66 50x60 ← unchanged 01:02:45 CANCEL → "locked" 01:03:37 [Availability] {"cash_in":true,"cash_out":true,"cash_level":"full"} ``` ## 1. The failure never leaves the machine (the money defect) `dispenseError` is a terminal local state. The row above is written to `state.db`, the screen counts down 30s, and that is the end of it. Nothing publishes the outcome, nothing alerts, nothing refunds — `grep -riE "refund|reversal|compensat|notify.*fail"` across `apps/` and `packages/` returns nothing on the money path. So the operator's view is an LNbits payment marked `processed` with no hint of trouble, and the only record that a customer is owed 40 EUR lives on the ATM's own disk. The hook for fixing this already exists: `generateInvoice` puts `extra.txid` on the invoice (`apps/machine/src/services/lightning.ts:1004-1011`), so the server can join a payment to a machine transaction. What's missing is the machine ever telling it the join came out bad. #78 noted in passing that "only spirekeeper-side reconciliation would ever notice" — this is that gap arriving in production, on a transaction that was watched correctly and recorded correctly. A terminal dispense failure should publish the outcome for the txid the payment already carries, so the operator sees an owed-cash queue instead of a clean `processed`. ## 2. A mid-transport jam is recorded as `dispensed: 0`, so the ledger over-counts The F56 reports per-bay dispensed/rejected alongside the error. Decoding the response bytes: error code at `res[3..5]` = `78 42`; dispensed at `0x27` = `30 30` → 0; rejected at `0x2f` = `30 30` → 0. A note that left the bay and stopped in the transport completes neither counter, so the driver faithfully reports nothing moved. Consequences, all visible in the log above: - `hal-service.ts:320` decrements each bay by `result.value[i].dispensed` — zero, so the bay stays at 66. - `atm.ts:628-634` sees `totalDispensed === 0`, keeps `status = dispense_error` (not `partial`) and writes `bills = []`. - `markCountsUncertain` (`atm.ts:645-657`) is the safety net for exactly this — "bills may well have reached the customer, and nothing knows how many" — but it only fires when `dispenseResult` is **absent**. A structured report claiming `dispensed: 0` is trusted outright, so `countsUncertainSince` was never set (`meta` has no such key). - `publishCassettesState()` then republished 20x66 as fact, three times since. `cassettes` says 66 twenties. The cassette holds 65 and the transport holds one. A `dispensed: 0` *accompanied by an error* is not evidence that nothing left the bay — it should route to the same uncertainty flag as a missing report. ## 3. The availability beacon has no notion of dispenser health `useAvailabilityBroadcast.computeSnapshot()` derives `cashOut` from `totalBills > 0` and nothing else. So 64 seconds after a jam that will block every subsequent dispense, sintra published `{"cash_in":true,"cash_out":true,"cash_level":"full"}`, and has kept republishing it every 5 minutes since. This is what turns one bad transaction into many. `dispenseCash` re-inits the dispenser on the next attempt (`hal-service.ts:255-259`), but a note physically stuck in the transport path isn't cleared by re-initialising — so the next customer to tap, pay, and wait would have lost their money the same way. Nothing in the beacon, and nothing in the `locked` state the machine returned to, stops them. #27 already classifies JAM as terminal ("bill stuck in transport path, will block all cassettes") and correctly says don't retry it. The missing half is that terminal means *stop advertising cash-out* until an operator clears it and confirms a recount. ## Scope note Distinct from #78 (payment with no machine row at all — unwatched window) and #27 (retry/fallback across cassettes on *recoverable* pickup errors). Here the watcher worked, the record is right, and the hardware error was correctly terminal; what failed is everything after the error. Suggested split if these want to be separate: (1) is the release-blocker, (2) is a correctness fix in the `dispenseResult` interpretation, (3) is a beacon/health-gate feature. They're filed together because one transaction produced all three and (3) is what makes (1) recur.
Author
Owner

A fourth gap, surfaced by actually responding to this incident: there is no way to record that a failed dispense was settled off-machine.

The operator cleared the jam and handed the customer 40 EUR by hand, pulling the notes from the cassette directly rather than through the machine. That is the obvious real-world response, and the ledger has no vocabulary for it:

  • remediateTransaction(txid, remediatedByTxid) requires a manual_dispense txid to point at. A hand-settled payout produces none, and running a real manual dispense just to mint one would push another 40 EUR out of the machine.
  • So tx_mv0madw6_wdhtea1v stays status = dispense_error indefinitely, and the machine's own ledger keeps asserting the customer is owed money that has in fact been paid.
  • The remediated_by column is TEXT, so the storage is already there — what's missing is a path that writes a non-txid provenance (an operator note / settlement reference) and flips the status.

This compounds defect 1 rather than being separate from it: once failures do reach the server, the operator needs a way to close one out, and "the only way to clear an owed-cash row is to dispense more cash from the machine that just jammed" is not it.

Worth considering as part of the same design: a settle operator op, carried the same way the cassette ops are (operator-authored, id-deduped, applied by the machine as sole writer), so an off-machine payout is as auditable as a refill.

Also for the record — how NOT to fix the count

The cassette row read 20x66 while the bay physically held fewer. The temptation is a UPDATE cassettes SET count = … against state.db, and that is wrong: applyOperatorCassetteOps is deliberately the single writer ("Nobody but this process writes a count any more, so there is no second writer to lose a race to"), and a hand-edit lands in neither cassette_ops nor the published cassette state, so the operator's view and the machine's diverge with no audit trail.

The supported repair is an operator-published recount op for the affected position — which is also the only op that clears countsUncertainSince, precisely because a recount is someone opening the bay and counting it. Any fix for defect 2 should make a jammed dispense set that flag so the next recount is the thing that resolves it.

A fourth gap, surfaced by actually responding to this incident: **there is no way to record that a failed dispense was settled off-machine.** The operator cleared the jam and handed the customer 40 EUR by hand, pulling the notes from the cassette directly rather than through the machine. That is the obvious real-world response, and the ledger has no vocabulary for it: - `remediateTransaction(txid, remediatedByTxid)` requires a `manual_dispense` txid to point at. A hand-settled payout produces none, and running a real manual dispense just to mint one would push another 40 EUR out of the machine. - So `tx_mv0madw6_wdhtea1v` stays `status = dispense_error` indefinitely, and the machine's own ledger keeps asserting the customer is owed money that has in fact been paid. - The `remediated_by` column is `TEXT`, so the storage is already there — what's missing is a path that writes a non-txid provenance (an operator note / settlement reference) and flips the status. This compounds defect 1 rather than being separate from it: once failures *do* reach the server, the operator needs a way to close one out, and "the only way to clear an owed-cash row is to dispense more cash from the machine that just jammed" is not it. Worth considering as part of the same design: a `settle` operator op, carried the same way the cassette ops are (operator-authored, id-deduped, applied by the machine as sole writer), so an off-machine payout is as auditable as a refill. ### Also for the record — how NOT to fix the count The cassette row read `20x66` while the bay physically held fewer. The temptation is a `UPDATE cassettes SET count = …` against `state.db`, and that is wrong: `applyOperatorCassetteOps` is deliberately the single writer ("Nobody but this process writes a count any more, so there is no second writer to lose a race to"), and a hand-edit lands in neither `cassette_ops` nor the published cassette state, so the operator's view and the machine's diverge with no audit trail. The supported repair is an operator-published **`recount`** op for the affected position — which is also the only op that clears `countsUncertainSince`, precisely because a recount is someone opening the bay and counting it. Any fix for defect 2 should make a jammed dispense *set* that flag so the next recount is the thing that resolves it.
Author
Owner

Spec'd as ADR-005 — docs/adr/005-cash-out-dispense-outcome.md (on dev, lands with the next push).

Tracing the whole cash-out path for it turned up a structural root underneath the four defects above, and it changes what "fix" means here:

Distribution runs before the dispense. _handle_payment spawns process_settlement the instant the payment lands — before the machine has even learned of the payment via watchInvoice, let alone commanded the dispenser. The legs are LNbits-internal transfers and complete sub-second. So when the F56 reported 78 42 at T+2 s, the settlement was already processed — which the dashboard reported accurately. processed means all legs paid; it has never had a dispense input.

That also means apply_partial_dispense_and_redistribute — the tool built for exactly this — is structurally unreachable: its hard guard refuses once any leg has completed, and under the current ordering a leg has always completed by the time a dispense can fail.

ADR-005's central decision is therefore authorize/capture: the payment is the authorization, the machine's dispense report is the capture, and distribution waits for it. Everything else (the report_dispense RPC with a durable outbox, the lamassu dispense_confirmed/error/error_code taxonomy, the per-bay action log the machine already records in cassette_bills, the fault-vs-out-of-cash customer screen, the terminal-fault latch cleared by recount, the off-machine settle path) hangs off that.

Three deliberate deviations from the lamassu baseline are called out in the doc, including the one that caused defect 2: their dispenseOccurred trusts a dispensed: 0 that arrives with an error, and their counts drift the same way sintra's did.

The ADR ends with ten review findings outside its scope — candidates, not filed.

Spec'd as **ADR-005** — `docs/adr/005-cash-out-dispense-outcome.md` (on `dev`, lands with the next push). Tracing the whole cash-out path for it turned up a structural root underneath the four defects above, and it changes what "fix" means here: **Distribution runs before the dispense.** `_handle_payment` spawns `process_settlement` the instant the payment lands — before the machine has even learned of the payment via `watchInvoice`, let alone commanded the dispenser. The legs are LNbits-internal transfers and complete sub-second. So when the F56 reported `78 42` at T+2 s, the settlement was already `processed` — which the dashboard reported accurately. `processed` means *all legs paid*; it has never had a dispense input. That also means `apply_partial_dispense_and_redistribute` — the tool built for exactly this — is structurally unreachable: its hard guard refuses once any leg has completed, and under the current ordering a leg has always completed by the time a dispense can fail. ADR-005's central decision is therefore **authorize/capture**: the payment is the authorization, the machine's dispense report is the capture, and distribution waits for it. Everything else (the `report_dispense` RPC with a durable outbox, the lamassu `dispense_confirmed`/`error`/`error_code` taxonomy, the per-bay action log the machine already records in `cassette_bills`, the fault-vs-out-of-cash customer screen, the terminal-fault latch cleared by recount, the off-machine settle path) hangs off that. Three deliberate deviations from the lamassu baseline are called out in the doc, including the one that caused defect 2: their `dispenseOccurred` trusts a `dispensed: 0` that arrives with an error, and their counts drift the same way sintra's did. The ADR ends with ten review findings outside its scope — candidates, not filed.
Author
Owner

Status 2026-10-10 — both halves of ADR-005's capture logic are merged.

  • bitspire #123 (merged to dev): value-confirmed dispense, dispenseFault vs outOfCash screens with evidence, terminal-fault cash-out latch, counts-uncertain on a zero-with-error report, and the dispense_reports outbox → report_dispense. Defects 1–4 above and the fourth gap (off-machine settle) all have their machine side in place.
  • spirekeeper #49 (merged to main, released as v0.1.7, in the catalog): cash_out settlements land as awaiting_dispense and are captured on the machine's report — confirmed → distributes; partial → partial_pending, held whole (ADR-005 Decision 1); nothing out → cash_owed, first on the worklist. Migration m016 verified on bohm's dev instance; report_dispense registered.

Deploy state: not yet on hardware. Sintra's nightly upgrade has been failing every night since Oct 6 on the same 60 s build timeout as batm3 (#116), so nothing merged this week has reached it; the fix is pushing the toplevel to the aiolabs cachix (deploy/push-cache.sh sintra), which in turn surfaced that nix/mkAtmApp.nix's pnpmDeps.hash was stale after today's lockfile changes — being corrected on dev now. ariege's LNbits needs the spirekeeper upgrade to 0.1.7 via the admin UI.

Still open for this issue (ADR-005 slice 2): Nostr operator notification on cash_owed, the off-machine settle_cash_owed path + settle_transaction op so a hand-paid customer closes both ledgers, the cash_out_enabled operator switch, the error glossary, operator docs. Keeping this open until the first real report has round-tripped from sintra and the slice-2 items are either landed or split out.

Status 2026-10-10 — both halves of ADR-005's capture logic are merged. - **bitspire #123** (merged to `dev`): value-confirmed dispense, `dispenseFault` vs `outOfCash` screens with evidence, terminal-fault cash-out latch, counts-uncertain on a zero-with-error report, and the `dispense_reports` outbox → `report_dispense`. Defects 1–4 above and the fourth gap (off-machine settle) all have their machine side in place. - **spirekeeper #49** (merged to `main`, released as **v0.1.7**, in the catalog): `cash_out` settlements land as `awaiting_dispense` and are captured on the machine's report — confirmed → distributes; partial → `partial_pending`, held whole (ADR-005 Decision 1); nothing out → `cash_owed`, first on the worklist. Migration m016 verified on bohm's dev instance; `report_dispense` registered. **Deploy state:** not yet on hardware. Sintra's nightly upgrade has been failing every night since Oct 6 on the same 60 s build timeout as batm3 (#116), so nothing merged this week has reached it; the fix is pushing the toplevel to the aiolabs cachix (`deploy/push-cache.sh sintra`), which in turn surfaced that `nix/mkAtmApp.nix`'s `pnpmDeps.hash` was stale after today's lockfile changes — being corrected on `dev` now. ariege's LNbits needs the spirekeeper upgrade to 0.1.7 via the admin UI. **Still open for this issue (ADR-005 slice 2):** Nostr operator notification on `cash_owed`, the off-machine `settle_cash_owed` path + `settle_transaction` op so a hand-paid customer closes both ledgers, the `cash_out_enabled` operator switch, the error glossary, operator docs. Keeping this open until the first real report has round-tripped from sintra and the slice-2 items are either landed or split out.
Sign in to join this conversation.
No labels
No milestone
No project
No assignees
1 participant
Notifications
Due date
The due date is invalid or out of range. Please use the format "yyyy-mm-dd".

No due date set.

Dependencies

No dependencies set.

Reference
aiolabs/bitspire#122
No description provided.