feat(hal/ebds): escrow watchdog — log every escrow's wall-clock duration

Time each bill's stay in the `billsRead` (escrow) status. Anything that
exits escrow within ESCROW_WATCHDOG_WARN_MS=500ms gets logged at info
level; anything longer gets a warning naming the elapsed milliseconds.

500ms is 5× our 100ms poll cadence and well below MEI's ~5s grace
window. A warning means we're drifting toward the autonomous-return
failure mode that tears bills on the BATM3 — useful field signal for
verifying the poll-interval fix is sufficient under real load.

Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>
This commit is contained in:
Padreug 2026-05-19 22:36:27 +02:00
commit 7126bd05d3

View file

@ -13,8 +13,14 @@
import { EventEmitter } from 'node:events' import { EventEmitter } from 'node:events'
import type { ParseResult } from './ebds-rs232.js' import type { ParseResult } from './ebds-rs232.js'
// MEI's internal escrow grace expires around 5s. We want any escrow that
// sits open for >500ms (5× our 100ms poll cadence) to surface in field
// logs so we can spot drift toward the autonomous-return failure mode.
const ESCROW_WATCHDOG_WARN_MS = 500
export class EbdsFsm extends EventEmitter { export class EbdsFsm extends EventEmitter {
private currentStatus: string | null = null private currentStatus: string | null = null
private escrowOpenedAt: number | null = null
constructor() { constructor() {
super() super()
@ -38,6 +44,26 @@ export class EbdsFsm extends EventEmitter {
this.currentStatus = status this.currentStatus = status
console.log('[EBDS] %d status: %s → %s', Date.now(), prev ?? '(init)', status) console.log('[EBDS] %d status: %s → %s', Date.now(), prev ?? '(init)', status)
// Escrow watchdog: time the bill's stay in `billsRead`. Anything past
// ESCROW_WATCHDOG_WARN_MS means the host took too long to decide
// stack/reject relative to the validator's grace window — exactly
// the timing that produces torn bills on MEI hardware.
if (prev === 'billsRead' && this.escrowOpenedAt !== null) {
const elapsed = Date.now() - this.escrowOpenedAt
this.escrowOpenedAt = null
if (elapsed > ESCROW_WATCHDOG_WARN_MS) {
console.warn(
'[EBDS] escrow held %dms before transition to %s (threshold %dms) — ' +
'host decision latency creeping toward MEI grace window',
elapsed,
status,
ESCROW_WATCHDOG_WARN_MS
)
} else {
console.log('[EBDS] escrow → %s in %dms', status, elapsed)
}
}
switch (status) { switch (status) {
case 'accepting': case 'accepting':
// Transient: bill is being read by the validator head. Diagnostic // Transient: bill is being read by the validator head. Diagnostic
@ -53,6 +79,7 @@ export class EbdsFsm extends EventEmitter {
this.emit('reject') this.emit('reject')
return return
} }
this.escrowOpenedAt = Date.now()
this.emit('billsAccepted') this.emit('billsAccepted')
// Emit billsRead on next tick (matches lamassu-machine behavior) // Emit billsRead on next tick (matches lamassu-machine behavior)
process.nextTick(() => this.emit('billsRead', bill)) process.nextTick(() => this.emit('billsRead', bill))
@ -107,5 +134,6 @@ export class EbdsFsm extends EventEmitter {
/** Reset status tracking (e.g., after reload) */ /** Reset status tracking (e.g., after reload) */
reset(): void { reset(): void {
this.currentStatus = null this.currentStatus = null
this.escrowOpenedAt = null
} }
} }