ElementsProject / lightning

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

listpays vs paystatus #4780

Closed Kexkey closed 2 years ago

Kexkey commented 3 years ago

Description and details

Sometimes bolt11 payments show up with paystatus and not with listpays, and other times it's the other way around. I would expect both to return payment data whatever the status is.

Below is an example of an empty listpays array and a valid paystatus response. But I got other cases where listpays was returning payment info and paystatus was returning an empty array.

On instance1:

kexkey@AlcodaZ-2 lnurl_cypherapp % docker exec -it d511 lightning-cli --lightning-dir=/.lightning invoice 12345 l09 d09
{
   "payment_hash": "05469b4408363320c5fc00fb6ef19d7c72a39872312a7c06fd3cd18c92da504c",
   "expires_at": 1631824938,
   "bolt11": "lnbcrt123450p1psn5ud2pp5q4rfk3qgxcejp30uqrakauva03e28xrjxy48cpha8ngceyk62pxqdq9vscrjxqyjw5qcqp2sp5cen5rxu72vcktz7mu3uaq84gqulcc0a5yvekmdfady8v5dr5xkjq9qyyssqs7ff458qr6atp2k8lj0t5l8n722mtv3qnetrclzep33mdp48smgrl4phqz89wq07wmhlug5ezztr2yxh8uzwpda5pzfsdtvz3d5qdvgpt56wqt",
   "payment_secret": "c667419b9e5331658bdbe479d01ea8073f8c3fb423336db53d690eca347435a4",
   "warning_deadends": "Insufficient incoming capacity, once dead-end peers were excluded"
}

On instance2:

kexkey@AlcodaZ-2 lnurl_cypherapp % docker exec -it 664 lightning-cli --lightning-dir=/.lightning pay lnbcrt123450p1psn5ud2pp5q4rfk3qgxcejp30uqrakauva03e28xrjxy48cpha8ngceyk62pxqdq9vscrjxqyjw5qcqp2sp5cen5rxu72vcktz7mu3uaq84gqulcc0a5yvekmdfady8v5dr5xkjq9qyyssqs7ff458qr6atp2k8lj0t5l8n722mtv3qnetrclzep33mdp48smgrl4phqz89wq07wmhlug5ezztr2yxh8uzwpda5pzfsdtvz3d5qdvgpt56wqt
{
   "code": 210,
   "message": "Destination 029b26c73b2c19ec9bdddeeec97c313670c96b6414ceacae0fb1b3502e490a6cbb is not reachable directly and all routehints were unusable.",
   "attempts": [
      {
         "status": "failed",
         "failreason": "Destination 029b26c73b2c19ec9bdddeeec97c313670c96b6414ceacae0fb1b3502e490a6cbb is not reachable directly and all routehints were unusable.",
         "partid": 0,
         "amount": "12345msat"
      }
   ]
}

I want to know the status of the payment:

kexkey@AlcodaZ-2 lnurl_cypherapp % docker exec -it 664 lightning-cli --lightning-dir=/.lightning listpays lnbcrt123450p1psn5ud2pp5q4rfk3qgxcejp30uqrakauva03e28xrjxy48cpha8ngceyk62pxqdq9vscrjxqyjw5qcqp2sp5cen5rxu72vcktz7mu3uaq84gqulcc0a5yvekmdfady8v5dr5xkjq9qyyssqs7ff458qr6atp2k8lj0t5l8n722mtv3qnetrclzep33mdp48smgrl4phqz89wq07wmhlug5ezztr2yxh8uzwpda5pzfsdtvz3d5qdvgpt56wqt
{
   "pays": []
}

Not sure why I don't have anything here, let's try with paystatus...

kexkey@AlcodaZ-2 lnurl_cypherapp % docker exec -it 664 lightning-cli --lightning-dir=/.lightning paystatus lnbcrt123450p1psn5ud2pp5q4rfk3qgxcejp30uqrakauva03e28xrjxy48cpha8ngceyk62pxqdq9vscrjxqyjw5qcqp2sp5cen5rxu72vcktz7mu3uaq84gqulcc0a5yvekmdfady8v5dr5xkjq9qyyssqs7ff458qr6atp2k8lj0t5l8n722mtv3qnetrclzep33mdp48smgrl4phqz89wq07wmhlug5ezztr2yxh8uzwpda5pzfsdtvz3d5qdvgpt56wqt
{
   "pay": [
      {
         "bolt11": "lnbcrt123450p1psn5ud2pp5q4rfk3qgxcejp30uqrakauva03e28xrjxy48cpha8ngceyk62pxqdq9vscrjxqyjw5qcqp2sp5cen5rxu72vcktz7mu3uaq84gqulcc0a5yvekmdfady8v5dr5xkjq9qyyssqs7ff458qr6atp2k8lj0t5l8n722mtv3qnetrclzep33mdp48smgrl4phqz89wq07wmhlug5ezztr2yxh8uzwpda5pzfsdtvz3d5qdvgpt56wqt",
         "amount_msat": "12345msat",
         "amount_msat": "12345msat",
         "destination": "029b26c73b2c19ec9bdddeeec97c313670c96b6414ceacae0fb1b3502e490a6cbb",
         "attempts": [
            {
               "strategy": "Initial attempt",
               "start_time": "2021-09-09T20:42:54.779Z",
               "age_in_seconds": 22,
               "end_time": "2021-09-09T20:42:54.826Z",
               "state": "completed",
               "failure": {
                  "code": 205,
                  "message": "Call to getroute: Could not find a route"
               }
            }
         ]
      }
   ]
}

Of course, when I reconnect the two instances, payment goes through. Then, listpays and paystatus both return data.

kexkey@AlcodaZ-2 tests % ./ln_reconnect.sh 
{
   "id": "0321a6b9fbf438bfb8994c7eb9c66fd5759cbf255edc2b065cd04c5dd7380dcdbd",
   "features": "08026aa2",
   "direction": "out",
   "address": {
      "type": "ipv4",
      "address": "10.0.1.122",
      "port": 9735
   }
}
{
   "id": "029b26c73b2c19ec9bdddeeec97c313670c96b6414ceacae0fb1b3502e490a6cbb",
   "features": "08026aa2",
   "direction": "in",
   "address": {
      "type": "ipv4",
      "address": "10.0.1.14",
      "port": 42872
   }
}
kexkey@AlcodaZ-2 lnurl_cypherapp % docker exec -it 664 lightning-cli --lightning-dir=/.lightning pay lnbcrt123450p1psn5ud2pp5q4rfk3qgxcejp30uqrakauva03e28xrjxy48cpha8ngceyk62pxqdq9vscrjxqyjw5qcqp2sp5cen5rxu72vcktz7mu3uaq84gqulcc0a5yvekmdfady8v5dr5xkjq9qyyssqs7ff458qr6atp2k8lj0t5l8n722mtv3qnetrclzep33mdp48smgrl4phqz89wq07wmhlug5ezztr2yxh8uzwpda5pzfsdtvz3d5qdvgpt56wqt     
{
   "destination": "029b26c73b2c19ec9bdddeeec97c313670c96b6414ceacae0fb1b3502e490a6cbb",
   "payment_hash": "05469b4408363320c5fc00fb6ef19d7c72a39872312a7c06fd3cd18c92da504c",
   "created_at": 1631220817.384,
   "parts": 1,
   "msatoshi": 12345,
   "amount_msat": "12345msat",
   "msatoshi_sent": 12345,
   "amount_sent_msat": "12345msat",
   "payment_preimage": "0fe69b61ee05fa966b612a9398057730f69459a8a7cf5a1f518203be92ce962e",
   "status": "complete"
}
kexkey@AlcodaZ-2 lnurl_cypherapp % docker exec -it 664 lightning-cli --lightning-dir=/.lightning listpays lnbcrt123450p1psn5ud2pp5q4rfk3qgxcejp30uqrakauva03e28xrjxy48cpha8ngceyk62pxqdq9vscrjxqyjw5qcqp2sp5cen5rxu72vcktz7mu3uaq84gqulcc0a5yvekmdfady8v5dr5xkjq9qyyssqs7ff458qr6atp2k8lj0t5l8n722mtv3qnetrclzep33mdp48smgrl4phqz89wq07wmhlug5ezztr2yxh8uzwpda5pzfsdtvz3d5qdvgpt56wqt
{
   "pays": [
      {
         "bolt11": "lnbcrt123450p1psn5ud2pp5q4rfk3qgxcejp30uqrakauva03e28xrjxy48cpha8ngceyk62pxqdq9vscrjxqyjw5qcqp2sp5cen5rxu72vcktz7mu3uaq84gqulcc0a5yvekmdfady8v5dr5xkjq9qyyssqs7ff458qr6atp2k8lj0t5l8n722mtv3qnetrclzep33mdp48smgrl4phqz89wq07wmhlug5ezztr2yxh8uzwpda5pzfsdtvz3d5qdvgpt56wqt",
         "destination": "029b26c73b2c19ec9bdddeeec97c313670c96b6414ceacae0fb1b3502e490a6cbb",
         "payment_hash": "05469b4408363320c5fc00fb6ef19d7c72a39872312a7c06fd3cd18c92da504c",
         "status": "complete",
         "created_at": 1631220817,
         "preimage": "0fe69b61ee05fa966b612a9398057730f69459a8a7cf5a1f518203be92ce962e",
         "amount_msat": "12345msat",
         "amount_sent_msat": "12345msat"
      }
   ]
}
kexkey@AlcodaZ-2 lnurl_cypherapp % docker exec -it 664 lightning-cli --lightning-dir=/.lightning paystatus lnbcrt123450p1psn5ud2pp5q4rfk3qgxcejp30uqrakauva03e28xrjxy48cpha8ngceyk62pxqdq9vscrjxqyjw5qcqp2sp5cen5rxu72vcktz7mu3uaq84gqulcc0a5yvekmdfady8v5dr5xkjq9qyyssqs7ff458qr6atp2k8lj0t5l8n722mtv3qnetrclzep33mdp48smgrl4phqz89wq07wmhlug5ezztr2yxh8uzwpda5pzfsdtvz3d5qdvgpt56wqt
{
   "pay": [
      {
         "bolt11": "lnbcrt123450p1psn5ud2pp5q4rfk3qgxcejp30uqrakauva03e28xrjxy48cpha8ngceyk62pxqdq9vscrjxqyjw5qcqp2sp5cen5rxu72vcktz7mu3uaq84gqulcc0a5yvekmdfady8v5dr5xkjq9qyyssqs7ff458qr6atp2k8lj0t5l8n722mtv3qnetrclzep33mdp48smgrl4phqz89wq07wmhlug5ezztr2yxh8uzwpda5pzfsdtvz3d5qdvgpt56wqt",
         "amount_msat": "12345msat",
         "amount_msat": "12345msat",
         "destination": "029b26c73b2c19ec9bdddeeec97c313670c96b6414ceacae0fb1b3502e490a6cbb",
         "attempts": [
            {
               "strategy": "Initial attempt",
               "start_time": "2021-09-09T20:42:54.779Z",
               "age_in_seconds": 652,
               "end_time": "2021-09-09T20:42:54.826Z",
               "state": "completed",
               "failure": {
                  "code": 205,
                  "message": "Call to getroute: Could not find a route"
               }
            }
         ]
      },
      {
         "bolt11": "lnbcrt123450p1psn5ud2pp5q4rfk3qgxcejp30uqrakauva03e28xrjxy48cpha8ngceyk62pxqdq9vscrjxqyjw5qcqp2sp5cen5rxu72vcktz7mu3uaq84gqulcc0a5yvekmdfady8v5dr5xkjq9qyyssqs7ff458qr6atp2k8lj0t5l8n722mtv3qnetrclzep33mdp48smgrl4phqz89wq07wmhlug5ezztr2yxh8uzwpda5pzfsdtvz3d5qdvgpt56wqt",
         "amount_msat": "12345msat",
         "amount_msat": "12345msat",
         "destination": "029b26c73b2c19ec9bdddeeec97c313670c96b6414ceacae0fb1b3502e490a6cbb",
         "attempts": [
            {
               "strategy": "Initial attempt",
               "start_time": "2021-09-09T20:53:37.384Z",
               "age_in_seconds": 9,
               "end_time": "2021-09-09T20:53:37.719Z",
               "state": "completed",
               "success": {
                  "id": 225,
                  "payment_preimage": "0fe69b61ee05fa966b612a9398057730f69459a8a7cf5a1f518203be92ce962e"
               }
            }
         ]
      }
   ]
}

getinfo for both instances

kexkey@AlcodaZ-2 lnurl_cypherapp % docker exec -it d511 lightning-cli --lightning-dir=/.lightning getinfo              
{
   "id": "029b26c73b2c19ec9bdddeeec97c313670c96b6414ceacae0fb1b3502e490a6cbb",
   "alias": "🚀 Unblemished Uguisu 🚀",
   "color": "40bfbf",
   "num_peers": 1,
   "num_pending_channels": 0,
   "num_active_channels": 1,
   "num_inactive_channels": 0,
   "address": [],
   "binding": [
      {
         "type": "ipv4",
         "address": "0.0.0.0",
         "port": 9735
      }
   ],
   "version": "v0.10.1",
   "blockheight": 536,
   "network": "regtest",
   "msatoshi_fees_collected": 0,
   "fees_collected_msat": "0msat",
   "lightning-dir": "/.lightning/regtest"
}
kexkey@AlcodaZ-2 lnurl_cypherapp % docker exec -it 664 lightning-cli --lightning-dir=/.lightning getinfo   
{
   "id": "0321a6b9fbf438bfb8994c7eb9c66fd5759cbf255edc2b065cd04c5dd7380dcdbd",
   "alias": "🚀 Unblemished Uguisu 🚀",
   "color": "40bfbf",
   "num_peers": 1,
   "num_pending_channels": 0,
   "num_active_channels": 1,
   "num_inactive_channels": 0,
   "address": [],
   "binding": [
      {
         "type": "ipv4",
         "address": "0.0.0.0",
         "port": 9735
      }
   ],
   "version": "v0.10.1",
   "blockheight": 536,
   "network": "regtest",
   "msatoshi_fees_collected": 0,
   "fees_collected_msat": "0msat",
   "lightning-dir": "/.lightning/regtest"
}
Kexkey commented 3 years ago

I found an example of the other way around in my terminal scrollback. Unfortunately that was on v0.10.0... if I can reproduce this case on v0.10.1, I'll add to this issue. (EDIT: see next comment)

kexkey@AlcodaZ-2 lnurl_cypherapp % docker exec -it 44b lightning-cli --lightning-dir=/.lightning paystatus lnbcrt5185530p1psjjjc2pp5vlecv5amfwul9f8vwrmjc8ycaqwyvld5t2672qweynkkrgpngvmsdq0v3jhxce38q6n2vcxqyjw5qcqp2sp56kaynnrmvtnqqts4yxjnv87rqya95xllweqm45dmew5pmcumgp5q9qy9qsqflhsnezxjph23xk8tq85uh50nwx4wr94ft8mpq5kv43zrxj8wqdskl7veqvnze42u85m6km6aq9zsg3sucut58r7zzxjtykuasmqmvcqgkxv9e
{
   "pay": []
}
kexkey@AlcodaZ-2 lnurl_cypherapp % docker exec -it 44b lightning-cli --lightning-dir=/.lightning listpays lnbcrt5185530p1psjjjc2pp5vlecv5amfwul9f8vwrmjc8ycaqwyvld5t2672qweynkkrgpngvmsdq0v3jhxce38q6n2vcxqyjw5qcqp2sp56kaynnrmvtnqqts4yxjnv87rqya95xllweqm45dmew5pmcumgp5q9qy9qsqflhsnezxjph23xk8tq85uh50nwx4wr94ft8mpq5kv43zrxj8wqdskl7veqvnze42u85m6km6aq9zsg3sucut58r7zzxjtykuasmqmvcqgkxv9e
{
   "pays": [
      {
         "bolt11": "lnbcrt5185530p1psjjjc2pp5vlecv5amfwul9f8vwrmjc8ycaqwyvld5t2672qweynkkrgpngvmsdq0v3jhxce38q6n2vcxqyjw5qcqp2sp56kaynnrmvtnqqts4yxjnv87rqya95xllweqm45dmew5pmcumgp5q9qy9qsqflhsnezxjph23xk8tq85uh50nwx4wr94ft8mpq5kv43zrxj8wqdskl7veqvnze42u85m6km6aq9zsg3sucut58r7zzxjtykuasmqmvcqgkxv9e",
         "destination": "029b26c73b2c19ec9bdddeeec97c313670c96b6414ceacae0fb1b3502e490a6cbb",
         "payment_hash": "67f38653bb4bb9f2a4ec70f72c1c98e81c467db45ab5e501d924ed61a0334337",
         "status": "failed",
         "created_at": 1630096140,
         "amount_sent_msat": "0msat"
      }
   ]
}
Kexkey commented 3 years ago

Here is a case on our production server running v0.10.1. I obfuscated some data because real date on mainnet.

prod:~$ dexec lightning lightning-cli --lightning-dir=/.lightning listpays lnbc8341[...]uck50y
{
   "pays": [
      {
         "bolt11": "lnbc8341[...]uck50y",
         "destination": "034[...]6fe",
         "payment_hash": "cb4[...]268",
         "status": "failed",
         "created_at": 1631149603,
         "amount_sent_msat": "0msat"
      }
   ]
}
prod:~$ dexec lightning lightning-cli --lightning-dir=/.lightning paystatus lnbc8341[...]uck50y
{
   "pay": []
}
prod:~$ dexec lightning lightning-cli --lightning-dir=/.lightning getinfo
{
   "id": "020a1df50b701331a29782093210460b10eee0ac5ef6a01b9c51dff9b8fddf5fb0",
   "alias": "bullbitcoin.com",
   "color": "5140bf",
   "num_peers": 118,
   "num_pending_channels": 1,
   "num_active_channels": 113,
   "num_inactive_channels": 1,
   "address": [
      {
         "type": "ipv4",
         "address": "170.75.170.23",
         "port": 9735
      },
      {
         "type": "torv3",
         "address": "bodtfyvzc5dkcoxmpd2gogg6eufm44vrdwow2vfsonc3mavjhsmb3hid.onion",
         "port": 9735
      }
   ],
   "binding": [
      {
         "type": "ipv4",
         "address": "0.0.0.0",
         "port": 9735
      }
   ],
   "version": "v0.10.1",
   "blockheight": 699813,
   "network": "bitcoin",
   "msatoshi_fees_collected": 34014091,
   "fees_collected_msat": "34014091msat",
   "lightning-dir": "/.lightning/bitcoin"
}
cdecker commented 2 years ago

I think #4567 might fix this issue. The problem is that we were implicitly assuming that the parts are returned in order, and therefore were annotating only the first part with the metadata (annotating all parts with identical metadata can bloat the DB quite a bit). We would then extract the metadata from the first part, and accumulate the other parts.

Some change in the ordering, especially with postgres backends, could end up with this assumption being broken. We now order the listsendpays result by id, and we process them in the correct order in the listpays call, so this should be fixed again.

Sorry for the inconvenience.