Lightning: Payment status changed from 'failed' to 'complete'

[fiatjaf]

Issue and Steps to Reproduce

I have a program that allows users to withdraw from their internal balances to the external lightning world. When they paste an invoice I issue a payment. If the payment doesn't fail or succeed in some seconds I mark it as pending in my database and keep polling lightning-cli listpayments <bolt11> until I get either complete or failed.

In this case I got failed and the transaction was canceled and the funds returned to the user internal balance, but later the payment was completed. I only noticed later when the user told me he got the funds in his remote wallet.

The following is taken from the logs of my program where the outgoing transaction is canceled and the funds returned to the user balance (I just log the JSON output from listpayments at the time):

{
  "id": 427,
  "payment_hash": "fddd29c59c582a44a3845b61398160a66105b01198b7d6522f9024db4db594d1",
  "destination": "02ceb7d27f68a060b38e466bdaf9842dd69d29213ece9a40253860ce558fc96bfe",
  "msatoshi": 99999000,
  "amount_msat": "99999000msat",
  "msatoshi_sent": 100010099,
  "amount_sent_msat": "100010099msat",
  "created_at": 1554141789,
  "status": "failed",
  "bolt11": "lnbc999990n1pw2y53upp5lhwjn3vutq4yfguytdsnnqtq5esstvq3nzmav530jqjdknd4jngsdqqxqr4rqrzjqw7apsu5zhgr9wcgz5n3ejs7wxnsxjv4k6nyw6xj6ueeqj7v0q9msz9snqqq0ucqqqqqqqlgqqqqqeqqjqrzjqwryaup9lh50kkranzgcdnn2fgvx390wgj5jd07rwr3vxeje0glc7z9sjsqqgqcqqqqqqqlgqqqqqeqqjq4h7xmtfkzkq72w0qjhp9e03q8pgllc4lekls7wcmuzr93uhy9sczda4hxa9nalp2hrl9032e24hkwvaktql7kk7uq5wdpz8y27zv4jgqwjzugj"
}

The following is the output of listpayments now:

~/lightning/cli/lightning-cli listpayments lnbc999990n1pw2y53upp5lhwjn3vutq4yfguytdsnnqtq5esstvq3nzmav530jqjdknd4jngsdqqxqr4rqrzjqw7apsu5zhgr9wcgz5n3ejs7wxnsxjv4k6nyw6xj6ueeqj7v0q9msz9snqqq0ucqqqqqqqlgqqqqqeqqjqrzjqwryaup9lh50kkranzgcdnn2fgvx390wgj5jd07rwr3vxeje0glc7z9sjsqqgqcqqqqqqqlgqqqqqeqqjq4h7xmtfkzkq72w0qjhp9e03q8pgllc4lekls7wcmuzr93uhy9sczda4hxa9nalp2hrl9032e24hkwvaktql7kk7uq5wdpz8y27zv4jgqwjzugj | jq .
{
  "payments": [
    {
      "id": 427,
      "payment_hash": "fddd29c59c582a44a3845b61398160a66105b01198b7d6522f9024db4db594d1",
      "destination": "02ceb7d27f68a060b38e466bdaf9842dd69d29213ece9a40253860ce558fc96bfe",
      "msatoshi": 99999000,
      "amount_msat": "99999000msat",
      "msatoshi_sent": 100010199,
      "amount_sent_msat": "100010199msat",
      "created_at": 1554141794,
      "status": "complete",
      "payment_preimage": "5377c43df546dd5884041b9875a0352c108c5fe0487bfeecf46d15b88474e611",
      "bolt11": "lnbc999990n1pw2y53upp5lhwjn3vutq4yfguytdsnnqtq5esstvq3nzmav530jqjdknd4jngsdqqxqr4rqrzjqw7apsu5zhgr9wcgz5n3ejs7wxnsxjv4k6nyw6xj6ueeqj7v0q9msz9snqqq0ucqqqqqqqlgqqqqqeqqjqrzjqwryaup9lh50kkranzgcdnn2fgvx390wgj5jd07rwr3vxeje0glc7z9sjsqqgqcqqqqqqqlgqqqqqeqqjq4h7xmtfkzkq72w0qjhp9e03q8pgllc4lekls7wcmuzr93uhy9sczda4hxa9nalp2hrl9032e24hkwvaktql7kk7uq5wdpz8y27zv4jgqwjzugj"
    }
  ]
}

getinfo output

{                                                                    
  "id": "02c16cca44562b590dd279c942200bdccfd4f990c3a69fad620c10ef2f8228eaff", 
  "alias": "telegram.me/lntxbot", 
  "color": "296683", 
  "num_peers": 47, 
  "num_pending_channels": 2, 
  "num_active_channels": 42, 
  "num_inactive_channels": 0, 
  "address": [
    {
      "type": "ipv4", 
      "address": "172.81.177.84", 
      "port": 9736
    }
  ], 
  "binding": [
    {
      "type": "ipv4", 
      "address": "0.0.0.0", 
      "port": 9736
    }, 
    {
      "type": "ipv6", 
      "address": "::", 
      "port": 9735
    }
  ], 
  "version": "v0.7.0-13-g0d35a71-modded", 
  "blockheight": 569785, 
  "network": "bitcoin", 
  "msatoshi_fees_collected": 7808, 
  "fees_collected_msat": "7808msat"
}

[cdecker]

That is an interesting situation. Would you happen to have the logs relating to this payment? The payment should probably not have been marked as failed as long as an attempt was still ongoing.

[fiatjaf]

What kind of logs? Where can I find them? I've searched the lightningd logs for something related to this transaction but didn't find anything.

[cdecker]

Doesn't grepping for 02ceb7d27f68a060b38e466bdaf9842dd69d29213ece9a40253860ce558fc96bfe or fddd29c59c582a44a3845b61398160a66105b01198b7d6522f9024db4db594d1 yield anything?

[fiatjaf]

See here: http://sprunge.us/FoxtRE

The first line where that node id appears, the last and everything in between. Removed bitcoin-cli lines.

[fiatjaf]

Just investigate and discovered that this has happened hundreds of times and caused me to lose hundreds of thousands of satoshis on https://t.me/lntxbot, because there seems to be a user abusing it. But yeah, I should have implemented a workaround as soon as I saw the bug first.

[cdecker]

Ok, I think I see what is going on here: pay attempts to pay the invoice, fails a few attempts (intermittently setting the state to failed), but continues to try. Eventually one of the attempts succeeds which results in the pay status being flipped from failed to success.

A more robust way of polling is to use the pay-plugin's paystatus command, that tracks a payment across all its attempts, not just the status of individual attempts.

[cdecker]

Maybe we should be migrating all the payment handling logic into the pay plugin? What do you think @rustyrussell? The alternative is to expose a setpaymentstatus command to the JSON-RPC which seems worse to me.

[fiatjaf]

I don't understand why listpayments has a pending status, then. Is that valid only for each individual payment attempt?

In the paystatus output, at which point a new attempt is added to the attempts array? I mean: if I call paystatus and there's just one attempt there that's a failure, can I be sure that the payment was indeed a failure and is not retrying in the background?

[fiatjaf]

Something like a waitanypayment command like waitanyinvoice would be a great solution here. This whole polling thing is a madness.

Or maybe I should bypass the pay plugin and write my own logic, but that wouldn't be cool.

EDIT: I'm going to write my own logic.

EDIT 2: I wrote my own logic in my c-lightning Go library then packaged it as plugin. If my reasoning is all wrong on this please please tell me now before I lose more money. Thank you!

[thorie7912]

LND has an event hook (subscription) for stuff like this in their newest release I believe. I think they wanted to get rid of that polling, to simplify wallets/clients work. Maybe c-lightning can have a more event-driven client API as well?

[cdecker]

Like @fiatjaf mentions we have some calls that allow you to wait for sendpay (single attempt) and invoices getting paid. It shouldn't be too hard to add another to the pay plugin that just waits for the multi-attempt pay to finish.

And event notifications and subscriptions should be coming to the JSON-RPC soon :-)

[ZmnSCPxj]

Is this still an issue? Current pay will only return if the payment definitely fails or definitely succeeds. We should use paystatus for now until we properly have listpayments return multi-attempt pay rather than single-attempt sendpay.

We probably need access to sqlite3 database inside the pay plugin to keep track of our multi-attempt pay commands.

[fiatjaf]

I don't know, this is not easy to reproduce and I'm not using it anymore.

But if you say we shouldn't rely on listpayments but on paystatus only it's probably necessary to write somewhere how people can trigger and monitor payments.

Part of the behavior is still unclear to me: what happens if the node stops and starts again?

[ZmnSCPxj]

Part of the behavior is still unclear to me: what happens if the node stops and starts again?

Only the last attempt is tracked in listpayments, no further attempts will be made, and the paystatus list is reset to containing nothing.

At some point we should switch to a listpays that overlays the status of pay on top of the sendpay attempts stored. That way we will have an ongoing status in listpays while a pay process is ongoing in paystatus, then fall back to the listpayments/listsendpays status for that payment if the pay process is not running in paystatus. That way we get some persistence (based on sendpay) but now avoid misleading clients (like your original software) with the flip-flopping failed/success.