ElementsProject / lightning

Core Lightning — Lightning Network implementation focusing on spec compliance and performance
Other
2.81k stars 887 forks source link

status "pending" from "sendpay_failure" #7561

Open darioAnongba opened 1 month ago

darioAnongba commented 1 month ago

Issue and Steps to Reproduce

I'm not entirely sure if this is a bug or a normal behaviour from the node but it seems odd. When sending a payment from our node:, we get the following logs from the node:

2024-08-12T14:44:59.816Z DEBUG   plugin-cln-renepay: sendpay_failure notification: {\"sendpay_failure\":{\"code\":204,\"message\":\"failed: WIRE_TEMPORARY_CHANNEL_FAILURE (reply from remote)\",\"data\":{\"created_index\":7,\"id\":7,\"payment_hash\":\"5bcdef9cea15a684216f49720470628aa698479bf2646e5f1b4764f5258f391a\",\"groupid\":1,\"partid\":3,\"destination\":\"035e4ff418fc8b5554c5d9eea66396c227bd429a3251c8cbc711002ba215bfc226\",\"amount_msat\":15000,\"amount_sent_msat\":15009,\"created_at\":1723473803,\"status\":\"pending\",\"label\":\"a213a41c-64ca-474c-9575-aa89a965aadc\",\"erring_index\":7,\"failcode\":4103,\"failcodename\":\"WIRE_TEMPORARY_CHANNEL_FAILURE\",\"raw_message\":\"1007000001021798afa4a87e6036732e3eff069584b94f18abbce65016cf62d8db83cb157e88292693da648490dfb2ac9a750f4c880ce9c5fd564388da42e18c32ae05905b6f6fe28c0ab6f1b372c1a6a246ae63f74f931e8365e15a089c68d61900000000000c84b8000e24000066b18b570101002200000000000000010000000000000000000000024e160300\"}}}
2024-08-12T14:44:59.817Z DEBUG   plugin-clnrest: Notification: {'sendpay_failure': {'code': 204, 'message': 'failed: WIRE_TEMPORARY_CHANNEL_FAILURE (reply from remote)', 'data': {'created_index': 7, 'id': 7, 'payment_hash': '5bcdef9cea15a684216f49720470628aa698479bf2646e5f1b4764f5258f391a', 'groupid': 1, 'partid': 3, 'destination': '035e4ff418fc8b5554c5d9eea66396c227bd429a3251c8cbc711002ba215bfc226', 'amount_msat': 15000, 'amount_sent_msat': 15009, 'created_at': 1723473803, 'status': 'pending', 'label': 'a213a41c-64ca-474c-9575-aa89a965aadc', 'erring_index': 7, 'failcode': 4103, 'failcodename': 'WIRE_TEMPORARY_CHANNEL_FAILURE', 'raw_message': '1007000001021798afa4a87e6036732e3eff069584b94f18abbce65016cf62d8db83cb157e88292693da648490dfb2ac9a750f4c880ce9c5fd564388da42e18c32ae05905b6f6fe28c0ab6f1b372c1a6a246ae63f74f931e8365e15a089c68d61900000000000c84b8000e24000066b18b570101002200000000000000010000000000000000000000024e160300'}}}
2024-08-12T14:44:59.821Z DEBUG   plugin-pay: cmd 34 partid 3: Intermediate node 037621d90b5f3673834287d2f87d4c5a014ccad50a973d3b8c6aa5b94c30a537e7 reported 1007 (WIRE_TEMPORARY_CHANNEL_FAILURE) at 820408x3620x0 on route 843479x1348x0 -> 855917x1467x1 -> 802369x965x0 -> 824797x1871x7 -> 849304x777x2 -> 810489x1163x0 -> 783276x1383x0 -> 820408x3620x0
2024-08-12T14:44:59.823Z DEBUG   plugin-pay: cmd 34 partid 0: Added a channel hint for 820408x3620x0/1: enabled true, estimated capacity 14999msat
2024-08-12T14:44:59.824Z INFO    plugin-pay: cmd 34 partid 3: failed: WIRE_TEMPORARY_CHANNEL_FAILURE (reply from remote)
2024-08-12T14:44:59.828Z INFO    plugin-pay: cmd 34 partid 3: Payment deadline expired, not retrying (partial-)payment 5bcdef9cea15a684216f49720470628aa698479bf2646e5f1b4764f5258f391a/3
2024-08-12T14:44:59.834Z DEBUG   plugin-clnrest: Notification: {'origin': 'pay', 'payload': {'payment_hash': '5bcdef9cea15a684216f49720470628aa698479bf2646e5f1b4764f5258f391a', 'bolt11': 'lnbc150n1pnt58mdpp5t0x7l882zkngggt0f9eqgurz32nfs3um7fjxuhcmgaj02fv08ydqhp50pqvmyzmyk5wu8n8d07hcn5tf7r094gl8sm2fpy8k7tfatztcz0qcqzzsxqyz5vqsp5xkv5nzzn44fr2u9f5j9vv56y4cc8s8stzdwc9c928ue8d3484d9s9qxpqysgqlrxumlengtn7lm6njarnr0lgwlx0um5pgurft2e7y4hcxsy2q9m3vpjare9d55kfqk6vs9cpdqsu83nt77k62tlefvm3k7ysn3syw8spenehv0', 'error': {'message': 'Ran out of routes to try after 4 attempts: see `paystatus`'}}}
2024-08-12T14:44:59.840Z INFO    plugin-clnrest: RPC Error: {'code': 210, 'message': 'Ran out of routes to try after 4 attempts: see `paystatus`', 'attempts': [{'status': 'failed', 'failreason': 'failed: WIRE_TEMPORARY_CHANNEL_FAILURE (reply from remote)', 'partid': 0, 'amount_msat': 15000}, {'status': 'failed', 'failreason': 'failed: WIRE_TEMPORARY_CHANNEL_FAILURE (reply from remote)', 'partid': 1, 'amount_msat': 15000, 'parent_partid': 0}, {'status': 'failed', 'failreason': 'failed: WIRE_TEMPORARY_CHANNEL_FAILURE (reply from remote)', 'partid': 2, 'amount_msat': 15000, 'parent_partid': 1}, {'status': 'failed', 'failreason': 'failed: WIRE_TEMPORARY_CHANNEL_FAILURE (reply from remote)', 'partid': 3, 'amount_msat': 15000, 'parent_partid': 2}]}

The error itself is not the issue. The problem is that we receive multiple sendpay_failure notifications on the websocket listener with the status pending. On our implementation, we expect the status to be failed.

Expected

Receive a notification with status failed for the payment, given that it was initiated with the pay RPC command, that returns on success or failure.

It would also be acceptable to receive multiple notifications for each failed attempt but we need an actual final notification for the payment failure.

Current behaviour

Receive multiple sendpay_failure notifications with pending status and no notification with failed status. The consequence is that we receive 4 sendpay_failure notifications for the same payment_hash. None of them stating for sure that the payment failed.

getinfo output:

{
   "id": "02fc22cb2dd9c71b39ad246ae206259376e0127cce2192d4061abd0172b53f391b",
   "alias": "NumeraireSwissKnife",
   "color": "55c692",
   "num_peers": 2,
   "num_pending_channels": 0,
   "num_active_channels": 4,
   "num_inactive_channels": 0,
   "address": [],
   "binding": [
      {
         "type": "ipv6",
         "address": "::",
         "port": 9735
      },
      {
         "type": "ipv4",
         "address": "0.0.0.0",
         "port": 9735
      }
   ],
   "version": "v24.05-modded",
   "blockheight": 856477,
   "network": "bitcoin",
   "fees_collected_msat": 2533300,
   "lightning-dir": "REDACTED",
   "our_features": {
      "init": "08a0000a8a59a1",
      "node": "0200000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000088a0000a8a59a1",
      "channel": "",
      "invoice": "02000002024100"
   }
}
rustyrussell commented 1 month ago

Good catch. pay calls sendpay multiple times, so the failures of each sendpay is not 1:1. And we do update the database to set the status, but we don't set it in the local one.

darioAnongba commented 1 month ago

Hi Rusty,

Any short term recommendations to fix this? The main problem being that we cannot know for sure that the payment has failed since we do not receive any event for such. Currently we fail the payment on "timeout" (and can reconcile the status by fetching from the node).

rustyrussell commented 1 month ago

The "sendpay_failure" notification itself is sufficient, you can ignore the status for now?

darioAnongba commented 1 month ago

Okay, so just to clarify, getting a "sendpay_failure" is sufficient regardless of receiving multiple and regardless of status "pending" ? Meaning we can get the first event, assume the payment has failed and discard subsequent events?