diff options
| author | Adam Soltys <[email protected]> | 2026-05-20 08:53:09 -0700 |
|---|---|---|
| committer | Adam Soltys <[email protected]> | 2026-05-20 08:53:09 -0700 |
| commit | 51107ed4b4079238ed1f657ec7231943f3c08696 (patch) | |
| tree | 5f92ce79894c13cafa0c2cc3ab61cc3d92ad29d9 | |
| parent | 9142b4dbcce407e331a2c1c9b56bb1ead3d3df76 (diff) | |
| download | coinos-server-51107ed4b4079238ed1f657ec7231943f3c08696.tar.gz coinos-server-51107ed4b4079238ed1f657ec7231943f3c08696.zip | |
sendLightning/sendKeysend: instrument exit paths to surface stuck-debit cases
Diagnosing the stuck "optimistic" state seen on payment 30976bc9 (joho33,
2026-05-19): confirmed=true with no preimage, not in the pending set, so
check() couldn't reconcile. Most likely path: ln.xpay returned without
throwing but with failed_parts > 0; the previous `if (!r.failed_parts)`
guard skipped finalize, no catch ran, and the debit was left stranded.
Adds:
- Log the full xpay/keysend response shape (status, failed_parts, parts,
amount_sent_msat, has_preimage) so we can see what CLN actually returned.
- Handle the failed_parts branch explicitly — verify with listpays and
finalize, reverse, or leave pending based on actual outcome.
- Track an `outcome` string through every branch and log it before
returning or throwing.
- "LEAKED DEBIT" err line at the function-end if we return without a clean
finalize — that's the exact stuck state we want zero of. grep `LEAKED
DEBIT` in app logs to catch any future occurrences immediately.
Same instrumentation pattern applied to sendKeysend.
Co-Authored-By: Claude Opus 4.7 (1M context) <[email protected]>
| -rw-r--r-- | lib/payments.ts | 103 |
1 files changed, 91 insertions, 12 deletions
diff --git a/lib/payments.ts b/lib/payments.ts index 01492975..af45ebc3 100644 --- a/lib/payments.ts +++ b/lib/payments.ts @@ -595,25 +595,46 @@ export const sendKeysend = async ({ type: PaymentType.lightning, }); + let outcome = "unknown"; try { - return await ln.keysend({ + const r = await ln.keysend({ destination: pubkey, amount_msat: amount * 1000, maxfee: fee * 1000, retry_for: 10, extratlvs, }); - } catch (e) { + warn("keysend returned", p.id, JSON.stringify({ + status: r?.status, + has_preimage: !!(r?.payment_preimage ?? r?.preimage), + amount_sent_msat: r?.amount_sent_msat, + })); + outcome = "keysend-returned"; // success path — caller handles preimage polling + l("sendKeysend outcome", p.id, "=", outcome); + return r; + } catch (e: any) { + err("failed keysend", hash?.slice(0,16), "error:", e?.message); try { const { pays } = await ln.listpays({ payment_hash: hash }); - const failed = !pays.length || pays.every((p) => p.status === "failed"); - if (failed) await reverse(p); + warn("listpays after keysend-threw", p.id, JSON.stringify(pays?.map((x) => ({ status: x.status, amount_sent_msat: x.amount_sent_msat })) ?? [])); + const completed = pays.find((x) => x.status === "complete"); + const failed = !pays.length || pays.every((x) => x.status === "failed"); + if (completed) { + outcome = "keysend-completed-despite-throw"; + } else if (failed) { + await reverse(p); + outcome = "reversed-after-keysend-throw"; + } else { + outcome = "pending-after-keysend-throw"; + } // else: pending or completed — leave the debit; check() loop will // reconcile. Reversing on pending would refund while CLN may still // settle the keysend. } catch (verifyErr: any) { warnThrottled("listpays verification failed (keysend)", verifyErr?.message ?? String(verifyErr)); + outcome = "verify-failed-after-keysend-throw"; } + warn("sendKeysend outcome", p.id, "=", outcome); throw e; } }; @@ -670,6 +691,12 @@ export const sendLightning = async ({ l("paying lightning invoice", pr.substr(-8), amount, fee); + // Instrumentation: track which exit path the payment took so we can + // diagnose any future stuck "optimistic" cases (confirmed=true with no + // ref, no pending-set membership). Logged just before the function + // returns; if "outcome=unsettled" appears in the logs we have a leak. + let outcome = "unknown"; + try { const r = await ln.xpay({ invstring: pr.replace(/\s/g, "").toLowerCase(), @@ -680,22 +707,62 @@ export const sendLightning = async ({ layers: ["prefer-kappa"], }); - try { - if (!r.failed_parts) p = await finalize(r, p); - } catch (e) { - warn("failed to process payment", p.id); + // Dump the full xpay response shape so we can see what CLN actually + // returned — especially failed_parts, missing preimage, partial sends. + warn("xpay returned", p.id, JSON.stringify({ + status: r?.status, + failed_parts: r?.failed_parts, + parts: r?.parts, + has_preimage: !!(r?.payment_preimage ?? r?.preimage), + amount_sent_msat: r?.amount_sent_msat, + amount_msat: r?.amount_msat, + })); + + if (r.failed_parts) { + // xpay didn't throw but reported failed parts. The old code path + // skipped finalize and left the debit stranded. Verify with listpays + // and act accordingly. + warn("xpay returned failed_parts without throwing", p.id, r.failed_parts); + try { + const { pays } = await ln.listpays(pr); + const completed = pays.find((x) => x.status === "complete"); + const failed = !pays.length || pays.every((x) => x.status === "failed"); + if (completed) { + warn("xpay failed_parts but listpays complete — finalizing", p.id); + try { await finalize(completed, p); outcome = "finalized-via-listpays-after-failed_parts"; } catch (e: any) { warn("finalize threw in failed_parts branch", p.id, e?.message); outcome = "finalize-threw-failed_parts"; } + } else if (failed) { + warn("xpay failed_parts and listpays failed — reversing", p.id); + await reverse(p); outcome = "reversed-via-failed_parts"; + } else { + outcome = "pending-after-failed_parts"; // leave for check() loop + } + } catch (verifyErr: any) { + warnThrottled("listpays verification failed (failed_parts branch)", verifyErr?.message ?? String(verifyErr)); + outcome = "verify-failed-after-failed_parts"; + } + } else { + try { + p = await finalize(r, p); + outcome = "finalized"; + } catch (e: any) { + warn("finalize threw despite no failed_parts", p.id, e?.message); + outcome = "finalize-threw"; + } } - } catch (e) { - err("failed to pay", pr.substr(-8)); + } catch (e: any) { + err("failed to pay", pr.substr(-8), "xpay error:", e?.message); try { const { pays } = await ln.listpays(pr); + warn("listpays after xpay-threw", p.id, JSON.stringify(pays?.map((x) => ({ status: x.status, amount_sent_msat: x.amount_sent_msat })) ?? [])); const completed = pays.find((p) => p.status === "complete"); const failed = !pays.length || pays.every((p) => p.status === "failed"); if (completed) { warn("payment completed despite error, finalizing", p.id); - try { await finalize(completed, p); } catch (_) {} + try { await finalize(completed, p); outcome = "finalized-after-xpay-throw"; } catch (_) { outcome = "finalize-threw-after-xpay-throw"; } } else if (failed) { - await reverse(p); + await reverse(p); outcome = "reversed-after-xpay-throw"; + } else { + outcome = "pending-after-xpay-throw"; } // else: pending — leave the debit in place; check() loop will reconcile // once CLN confirms outcome. Reversing while still in flight would @@ -706,10 +773,22 @@ export const sendLightning = async ({ // set, so check() will retry once CLN is back. Surface the failure so // a real outage doesn't go unnoticed. warnThrottled("listpays verification failed", verifyErr?.message ?? String(verifyErr)); + outcome = "verify-failed-after-xpay-throw"; } + warn("sendLightning outcome", p.id, "=", outcome); throw e; } + // Leak guard: if we got here without a clean finalize, the payment is + // confirmed=true (from debit's default) but has no ref/preimage — the + // exact stuck state we want to avoid. Log loudly so the next occurrence + // shows up in app logs immediately. + if (outcome !== "finalized") { + err("LEAKED DEBIT in sendLightning", p.id, "outcome=", outcome, "user=", user?.username, "amount=", amount, "fee=", fee); + } else { + l("sendLightning outcome", p.id, "=", outcome); + } + return p; }; |
