diff --git a/payout/README.md b/payout/README.md index 865ee7e..05132e5 100644 --- a/payout/README.md +++ b/payout/README.md @@ -93,9 +93,41 @@ had already been paid. Thunder advances only when a mainchain block commits to it, and nothing schedules that — so without help a broadcast payout waits for a human to press -a button, and the whole queue waits behind it. When a batch is outstanding and -unconfirmed, the loop calls Thunder's `mine`, at most once per -`PAYOUT_NUDGE_INTERVAL_MS`. +a button, and the whole queue waits behind it. The loop calls Thunder's `mine` +in exactly two places, and **when** it fires matters as much as that it does. + +### Once per broadcast, not once per tick + +`mine` builds a block body from the mempool *before* it takes the miner lock, +then parks that snapshot as its BMM request the moment the lock frees: + +```rust +let body = types::Body::new(Vec::new(), coinbase); // mempool snapshot HERE +let mut miner_write = miner.write().await; // then block on the lock +miner_write.attempt_bmm(bribe.to_sat(), 0, header, body) +``` + +So a nudge issued *while waiting* captures a mempool that predates the next +batch, queues behind the in-flight `mine`, and becomes the parked request the +instant the current batch confirms. The next batch — broadcast seconds later — +cannot be in the block that request produces, so it waits for the one after. +Every payout then costs two sidechain blocks instead of one. + +Measured on drynet3 before this was fixed: Thunder parked its request 14–93s +*ahead* of the broadcast it was meant to carry in 7 of 7 cycles, and 42 Thunder +blocks produced only 25 settlements. + +The loop therefore nudges: + +- **right after a broadcast**, so the snapshot contains the batch just sent. + Never rate-limited — it is already bounded by the settlement cadence. +- **to break a stall**, once a batch has sat unconfirmed for + `PAYOUT_NUDGE_STALL_SEC` (default 300s), which means its request was not + carried and nothing will re-park. Rate-limited by + `PAYOUT_NUDGE_INTERVAL_MS`. + +Do not lower `PAYOUT_NUDGE_STALL_SEC` towards the tick interval — that +reintroduces the stale-snapshot problem the split exists to avoid. It fires only while something is genuinely waiting to settle, so an idle pool spends no BMM bids on empty blocks. A failed nudge never fails the tick. diff --git a/payout/lib/config.js b/payout/lib/config.js index 1c581ce..1f7248e 100644 --- a/payout/lib/config.js +++ b/payout/lib/config.js @@ -21,10 +21,18 @@ * actually waiting, so an idle pool spends no BMM * bids on empty blocks. * PAYOUT_NUDGE_INTERVAL_MS - * floor between mine attempts (default 120s). Each - * nudge costs a mainchain BMM bid; the tick is far - * faster than Thunder can produce blocks, so without - * this every tick would pay for one. + * floor between stall-recovery mine attempts + * (default 120s). Each nudge costs a mainchain BMM + * bid. Does NOT apply to the nudge issued right after + * a broadcast, which must always fire. + * PAYOUT_NUDGE_STALL_SEC how long a broadcast batch may sit unconfirmed + * before we assume its BMM request was not carried + * and nudge again (default 300s, ~2 mainchain + * blocks on drynet3). Do NOT lower this to the tick + * interval: nudging on every tick makes Thunder park + * a mempool snapshot that predates the next batch, + * costing one extra sidechain block per payout. See + * settlePending() for the mechanism. * THUNDER_RPC_USER optional basic-auth user * THUNDER_RPC_PASS optional basic-auth pass * THUNDER_FROM_ADDRESS pool reserve address to send from (must match @@ -54,6 +62,7 @@ export function loadConfig() { dryRun: process.env.PAYOUT_DRY_RUN === '1', nudgeMine: process.env.PAYOUT_NUDGE_MINE !== '0', nudgeIntervalMs: parseInt(process.env.PAYOUT_NUDGE_INTERVAL_MS || '120000', 10), + nudgeStallSec: parseInt(process.env.PAYOUT_NUDGE_STALL_SEC || '300', 10), /* Admin HTTP surface — used by the dashboard's "Trigger payout now" * button. Loopback-bound by default; set port=0 to disable. */ adminHttpBind: process.env.PAYOUT_ADMIN_BIND || '127.0.0.1', diff --git a/payout/lib/payout.js b/payout/lib/payout.js index 3298331..e4f5e6d 100644 --- a/payout/lib/payout.js +++ b/payout/lib/payout.js @@ -147,14 +147,39 @@ async function settlePending(ctx, log) { return { blocked: true, txid: pending.txid, reason: 'undetermined' }; } - await nudgeMine(ctx, log); + /* Deliberately NOT nudging on every tick while we wait — that cost an + * entire extra sidechain block per payout. + * + * Thunder's `mine` snapshots the mempool into a block body BEFORE it takes + * the miner lock, then parks that snapshot as its BMM request the instant + * the lock frees. A nudge issued while waiting therefore captures a + * mempool that predates the NEXT batch, queues behind the in-flight + * mine(), and becomes the parked request the moment this batch confirms — + * so the next batch, broadcast seconds later, cannot be in the block that + * request produces. It waits for the one after. + * + * Measured on drynet3: 7 of 7 cycles had Thunder park 14-93s before the + * broadcast it was supposed to carry, and 42 Thunder blocks yielded only + * 25 settlements. One nudge per broadcast (see runOnce) keeps the parked + * body and the batch in step. + * + * The exception is a genuine stall: if our post-broadcast request was not + * carried (a BMM miss) nothing is parked and nothing will re-park, so + * after stallSec we nudge to recover. That nudge is safe in the sense that + * matters — this batch is in the mempool, so the body it builds contains + * it — and rare enough not to reintroduce the every-tick problem. */ + const waited = Math.floor(Date.now() / 1000) - pending.started_at; + if (waited >= ctx.cfg.nudgeStallSec) { + await nudgeMine(ctx, log, { reason: `no block in ${waited}s` }); + } + log.info(`payout: waiting on ${short(pending.txid)} (unconfirmed, ` + - `${pending.rows.length} worker(s)); skipping tick. ` + + `${pending.rows.length} worker(s), ${waited}s); skipping tick. ` + 'Thunder must mine a block before this settles.'); return { blocked: true, txid: pending.txid, reason: 'unconfirmed' }; } -/* Ask Thunder to attempt BMM, at most once per `nudgeIntervalMs`. +/* Ask Thunder to attempt BMM. * * Thunder advances only when a mainchain block commits to it and nothing * schedules that, so a broadcast payout otherwise waits for a human to press @@ -163,17 +188,28 @@ async function settlePending(ctx, log) { * exactly when something is waiting to settle: no pending batch, no BMM bid * spent on an empty block. * + * Called in exactly two places, and the distinction is the whole point: + * - immediately after a broadcast, so the body Thunder snapshots contains + * the batch we just sent. This one must never be skipped, so it is not + * rate-limited — it is already bounded by the settlement cadence. + * - to break a stall, when a batch has waited long enough that its request + * was evidently not carried. Rate-limited, because repeated nudges are + * what put a stale body in the parked slot to begin with (see + * settlePending). + * * Best-effort by construction. A failed nudge must not fail the tick — the - * batch is already broadcast and safe, and the next tick will try again. */ -async function nudgeMine(ctx, log) { + * batch is already broadcast and safe, and a later tick will try again. */ +async function nudgeMine(ctx, log, { force = false, reason = '' } = {}) { const { thunder, cfg } = ctx; if (!cfg.nudgeMine) return false; const now = Date.now(); - if (ctx._lastNudgeMs && now - ctx._lastNudgeMs < cfg.nudgeIntervalMs) return false; + if (!force && ctx._lastNudgeMs && now - ctx._lastNudgeMs < cfg.nudgeIntervalMs) { + return false; + } ctx._lastNudgeMs = now; try { const r = await thunder.mine(); - log.info('payout: nudged Thunder to mine (a payout is waiting to confirm)' + + log.info(`payout: nudged Thunder to mine${reason ? ` (${reason})` : ''}` + (r.completed ? '' : ' — BMM request parked, awaiting a mainchain block')); return true; } catch (e) { @@ -287,7 +323,11 @@ export async function runOnce(ctx, log) { log.info(`payout: broadcast ${batch.length} worker(s), ${totalOwed} sats, ` + `txid=${res.txid} — awaiting confirmation`); for (const b of batch) log.info(` ${b.worker_name} -> ${b.address} ${b.sats} sats`); - await nudgeMine(ctx, log); + /* Forced: this is the nudge whose mempool snapshot has to contain the + * batch above. Letting the rate limiter skip it hands the parked BMM + * slot to a body that predates the broadcast, which costs a whole + * sidechain block. */ + await nudgeMine(ctx, log, { force: true, reason: 'batch just broadcast' }); return { attempted: due.length, paid: 0, broadcast: batch.length, failed: 0, settled, txid: res.txid }; } catch (e) { diff --git a/payout/test/pending.test.js b/payout/test/pending.test.js index 5aad836..edc0b2e 100644 --- a/payout/test/pending.test.js +++ b/payout/test/pending.test.js @@ -104,7 +104,8 @@ function thunderStub({ txState = {}, utxoTxids = [], balance = 10n ** 12n, const quietLog = { info() {}, warn() {}, error() {}, debug() {} }; const baseCfg = { minSats: 10000n, maxPerTick: 50, dryRun: false, intervalMs: 1000, - nudgeMine: true, nudgeIntervalMs: 120000 }; + nudgeMine: true, nudgeIntervalMs: 120000, nudgeStallSec: 300 }; +const nowSec = () => Math.floor(Date.now() / 1000); const cfg = baseCfg; const credited = db => db.prepare('SELECT COUNT(*) n FROM pps_credits WHERE paid_sats > 0').get().n; @@ -263,9 +264,32 @@ test('listStuck reports unbroadcast rows only, not ones awaiting confirmation', /* ---------- nudging Thunder ---------------------------------------------- */ -test('a waiting payout nudges Thunder to mine', async () => { +/* The core of the fix. Thunder's `mine` snapshots the mempool into a block + * body BEFORE taking the miner lock, then parks that snapshot the instant the + * lock frees. A nudge issued while waiting therefore captures a mempool that + * predates the NEXT batch and becomes the parked request the moment this one + * confirms — so the next batch cannot be in the block it produces, and every + * payout costs two sidechain blocks instead of one. */ +test('a batch still within its settling window does not nudge again', async () => { const db = makeDb({ - inFlight: [{ txid: 'abc123', worker_id: 1, sats: 5_000_000 }], + inFlight: [{ txid: 'abc123', worker_id: 1, sats: 5_000_000, + started_at: nowSec() }], + owed: { rig1: 5_000_000 }, + }); + const thunder = thunderStub({ txState: { abc123: { known: true, confirmed: false } } }); + + await runOnce({ db, thunder, cfg }, quietLog); + assert.equal(thunder.calls.mines, 0, + 'its request is already parked with this batch in the body; ' + + 'nudging now parks a stale body for the next one'); +}); + +test('a stalled batch nudges to recover', async () => { + /* If our post-broadcast request was not carried, nothing is parked and + * nothing will re-park. After stallSec, nudge. */ + const db = makeDb({ + inFlight: [{ txid: 'abc123', worker_id: 1, sats: 5_000_000, + started_at: nowSec() - 600 }], owed: { rig1: 5_000_000 }, }); const thunder = thunderStub({ txState: { abc123: { known: true, confirmed: false } } }); @@ -274,11 +298,12 @@ test('a waiting payout nudges Thunder to mine', async () => { assert.equal(thunder.calls.mines, 1, 'nothing else will make Thunder advance'); }); -test('the nudge is rate-limited across ticks', async () => { +test('the stall nudge is rate-limited across ticks', async () => { /* Each nudge costs a mainchain BMM bid, and the tick is far faster than * Thunder can produce blocks. */ const db = makeDb({ - inFlight: [{ txid: 'abc123', worker_id: 1, sats: 5_000_000 }], + inFlight: [{ txid: 'abc123', worker_id: 1, sats: 5_000_000, + started_at: nowSec() - 600 }], owed: { rig1: 5_000_000 }, }); const thunder = thunderStub({ txState: { abc123: { known: true, confirmed: false } } }); @@ -290,9 +315,28 @@ test('the nudge is rate-limited across ticks', async () => { assert.equal(thunder.calls.mines, 1, 'once per nudgeIntervalMs, not once per tick'); }); +/* The rate limiter must never suppress this one: it is the nudge whose body + * snapshot has to contain the batch just sent. */ +test('a broadcast nudges even inside the rate-limit window', async () => { + const db = makeDb({ + inFlight: [{ txid: 'abc123', worker_id: 1, sats: 5_000_000, + started_at: nowSec() - 600 }], + owed: { rig1: 5_000_000, rig2: 6_000_000 }, + }); + const thunder = thunderStub({ txState: { abc123: { known: true, confirmed: true } } }); + const ctx = { db, thunder, cfg, _lastNudgeMs: Date.now() }; + + const r = await runOnce(ctx, quietLog); + assert.equal(r.settled, 1, 'the old batch cleared'); + assert.ok(r.broadcast > 0, 'and a new one went out'); + assert.equal(thunder.calls.mines, 1, + 'forced despite _lastNudgeMs being moments ago'); +}); + test('the nudge can be turned off', async () => { const db = makeDb({ - inFlight: [{ txid: 'abc123', worker_id: 1, sats: 5_000_000 }], + inFlight: [{ txid: 'abc123', worker_id: 1, sats: 5_000_000, + started_at: nowSec() - 600 }], owed: { rig1: 5_000_000 }, }); const thunder = thunderStub({ txState: { abc123: { known: true, confirmed: false } } }); @@ -310,7 +354,8 @@ test('an idle pool spends no BMM bids', async () => { test('a failing mine nudge does not fail the tick', async () => { const db = makeDb({ - inFlight: [{ txid: 'abc123', worker_id: 1, sats: 5_000_000 }], + inFlight: [{ txid: 'abc123', worker_id: 1, sats: 5_000_000, + started_at: nowSec() - 600 }], owed: { rig1: 5_000_000 }, }); const thunder = thunderStub({ txState: { abc123: { known: true, confirmed: false } } });