ElementsProject / lightning

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

Unable to make a payment on directly connected cln node #7751

Closed NicolasDorier closed 1 week ago

NicolasDorier commented 1 week ago

So, I have connected two nodes on regtest, customer and merchant.

  1. customer established the channel to merchant and successfully pushed a payment to merchant.
  2. merchant is unable to send back (the situation unlock itself later on, though I haven't identified what fix it)

Customer getinfo:

{
   "id": "02a3f887e6654e5ce3a6b451a72fa4b6c27d4e852831410f0d75edbd218d54e96d",
   "alias": "HAPPYNET-c910f0f-modded",
   "color": "02a3f8",
   "num_peers": 2,
   "num_pending_channels": 0,
   "num_active_channels": 2,
   "num_inactive_channels": 0,
   "address": [
      {
         "type": "ipv4",
         "address": "172.30.0.7",
         "port": 9735
      }
   ],
   "binding": [
      {
         "type": "ipv4",
         "address": "0.0.0.0",
         "port": 9735
      }
   ],
   "version": "c910f0f-modded",
   "blockheight": 113,
   "network": "regtest",
   "fees_collected_msat": 0,
   "lightning-dir": "/root/.lightning/regtest",
   "our_features": {
      "init": "08a0000a8a59a1",
      "node": "88a0000a8a59a1",
      "channel": "",
      "invoice": "02000002024100"
   }
}

Merchant getinfo:

{
   "id": "03951fb687ccb0798cb4230ba40ab489f0783ba76f31e62ee36634ff06152c6d8e",
   "alias": "LOUDROUTE-c910f0f-modded",
   "color": "03951f",
   "num_peers": 1,
   "num_pending_channels": 0,
   "num_active_channels": 1,
   "num_inactive_channels": 0,
   "address": [
      {
         "type": "ipv4",
         "address": "172.30.0.6",
         "port": 9735
      }
   ],
   "binding": [
      {
         "type": "ipv4",
         "address": "0.0.0.0",
         "port": 9735
      }
   ],
   "version": "c910f0f-modded",
   "blockheight": 113,
   "network": "regtest",
   "fees_collected_msat": 0,
   "lightning-dir": "/root/.lightning/regtest",
   "our_features": {
      "init": "08a0000a8a59a1",
      "node": "88a0000a8a59a1",
      "channel": "",
      "invoice": "02000002024100"
   }
}

Merchant listpeerchannels:

{
   "channels": [
      {
         "peer_id": "02a3f887e6654e5ce3a6b451a72fa4b6c27d4e852831410f0d75edbd218d54e96d",
         "peer_connected": true,
         "reestablished": true,
         "channel_type": {
            "bits": [
               12,
               22
            ],
            "names": [
               "static_remotekey/even",
               "anchors_zero_fee_htlc_tx/even"
            ]
         },
         "ignore_fee_limits": true,
         "updates": {
            "local": {
               "htlc_minimum_msat": 0,
               "htlc_maximum_msat": 16609443000,
               "cltv_expiry_delta": 6,
               "fee_base_msat": 1,
               "fee_proportional_millionths": 10
            },
            "remote": {
               "htlc_minimum_msat": 0,
               "htlc_maximum_msat": 16609443000,
               "cltv_expiry_delta": 6,
               "fee_base_msat": 1,
               "fee_proportional_millionths": 10
            }
         },
         "last_stable_connection": 1729231631,
         "state": "CHANNELD_NORMAL",
         "scratch_txid": "8e81a834b063c7f846697f91942e4fee4b2179f67ec6410ad8fcc7e14e06389d",
         "last_tx_fee_msat": 1411000,
         "lost_state": false,
         "feerate": {
            "perkw": 1255,
            "perkb": 5020
         },
         "owner": "channeld",
         "short_channel_id": "112x1x0",
         "direction": 1,
         "channel_id": "0d90c978fa10ff95ee609d7eaf13413260d59f9844d06fb9bb80362deabc7a92",
         "funding_txid": "927abcea2d3680bbb96fd044989fd560324113af7e9d60ee95ff10fa78c9900d",
         "funding_outnum": 0,
         "close_to_addr": "bcrt1plta9g6y5u3gmll9kfssm6vkx0gl7k0ec97mu74s9y5drmkannhgq0vw2nr",
         "close_to": "5120fafa546894e451bffcb64c21bd32c67a3feb3f382fb7cf5605251a3ddbb39dd0",
         "private": false,
         "opener": "remote",
         "alias": {
            "local": "11156498x7898321x63406",
            "remote": "12384582x3716140x61128"
         },
         "features": [
            "option_static_remotekey",
            "option_anchors_zero_fee_htlc_tx"
         ],
         "funding": {
            "local_funds_msat": 0,
            "remote_funds_msat": 16777215000,
            "pushed_msat": 0
         },
         "to_us_msat": 123456789,
         "min_to_us_msat": 0,
         "max_to_us_msat": 123456789,
         "total_msat": 16777215000,
         "fee_base_msat": 1,
         "fee_proportional_millionths": 10,
         "dust_limit_msat": 546000,
         "max_total_htlc_in_msat": 18446744073709551615,
         "their_reserve_msat": 167772000,
         "our_reserve_msat": 167772000,
         "spendable_msat": 0,
         "receivable_msat": 16481680211,
         "minimum_htlc_in_msat": 0,
         "minimum_htlc_out_msat": 0,
         "maximum_htlc_out_msat": 16609443000,
         "their_to_self_delay": 6,
         "our_to_self_delay": 6,
         "max_accepted_htlcs": 483,
         "state_changes": [
            {
               "timestamp": "2024-10-18T06:06:12.506Z",
               "old_state": "CHANNELD_AWAITING_LOCKIN",
               "new_state": "CHANNELD_NORMAL",
               "cause": "remote",
               "message": "Lockin complete"
            }
         ],
         "status": [
            "CHANNELD_NORMAL:Channel ready for use."
         ],
         "in_payments_offered": 1,
         "in_offered_msat": 123456789,
         "in_payments_fulfilled": 1,
         "in_fulfilled_msat": 123456789,
         "out_payments_offered": 0,
         "out_offered_msat": 0,
         "out_payments_fulfilled": 0,
         "out_fulfilled_msat": 0,
         "htlcs": []
      }
   ]
}

As you can see, the channel is local and seems in a good state.

Now, merchant tries to pay the invoice issued by customer lnbcrt1u1pn3r7cssp5xmy48dxg5pwrdrj7pyctlcezcxm53z6qsxgdz58m7md84smyc6espp585rmft0kypuc0d4vj3hvqj6xd9cwlete5du2squ6p4qmr84lz0cqdp6vcurjwryxdjrxttz8qukvtf5xccxztfc8psngtf4xfskxepcv4jk2enrvyxq9rf0qqcqp29qxpqysgqw32nlmcr0y5t5ekdnzy5e57d6vw7tjz58y6s25pkl8es0krs9l88j7lnp8hypm5nr2pgepqvt7ke4gtm2v2fx07wlvcth4tqed9549cqtdn897.

The following decode:

{
   "type": "bolt11 invoice",
   "currency": "bcrt",
   "created_at": 1729231632,
   "expiry": 3456000,
   "payee": "02a3f887e6654e5ce3a6b451a72fa4b6c27d4e852831410f0d75edbd218d54e96d",
   "amount_msat": 100000,
   "description": "f898d3d3-b89f-460a-88a4-52acd8eeefca",
   "min_final_cltv_expiry": 10,
   "payment_secret": "36c953b4c8a05c368e5e0930bfe322c1b7488b408190d150fbf6da7ac364c6b3",
   "features": "02024100",
   "payment_hash": "3d07b4adf6207987b6ac946ec04b466970efe579a378a8039a0d41b19ebf13f0",
   "signature": "3044022074553fef037928ba66cd98894cd3cdd31de5c8543935055036f9f307d8702fce0220797bf309ee40ee931a828c840c5fad9aa17b5314933fcefb30bbd560cb4b4a97",
   "valid": true
}

When the merchant pay, it fails:

{
   "code": 210,
   "message": "Destination 02a3f887e6654e5ce3a6b451a72fa4b6c27d4e852831410f0d75edbd218d54e96d is not reachable directly and all routehints were unusable.",
   "attempts": [
      {
         "status": "failed",
         "failreason": "Destination 02a3f887e6654e5ce3a6b451a72fa4b6c27d4e852831410f0d75edbd218d54e96d is not reachable directly and all routehints were unusable.",
         "partid": 0,
         "amount_msat": 100000
      }
   ]
}

Here are the logs of the merchant:

2024-10-18T06:28:26.190Z DEBUG   hsmd: Client: Received message 51 from client
2024-10-18T06:28:26.190Z DEBUG   hsmd: preapprove_invoice: check_only=0
2024-10-18T06:28:26.192Z DEBUG   plugin-pay: cmd 34 partid 0: Received getchaininfo blockcount=113, headercount=113
2024-10-18T06:28:26.192Z DEBUG   plugin-pay: cmd 34 partid 0: waitblockheight reports syncheight=113
2024-10-18T06:28:26.192Z DEBUG   plugin-pay: cmd 34 partid 0: Added a channel hint for 112x1x0/1: enabled true, estimated capacity 0msat
2024-10-18T06:28:26.192Z DEBUG   plugin-pay: cmd 34 partid 0: Added a channel hint for 11156498x7898321x63406/1: enabled false, estimated capacity 0msat
2024-10-18T06:28:26.192Z INFO    plugin-pay: cmd 34 partid 0: Payment fee constraint 500msat is below exemption threshold, allowing a maximum fee of 5000msat
2024-10-18T06:28:26.193Z DEBUG   plugin-topology: Note: disallowing deprecated listchannels.include_private for \"pay:listchannels#35/cln:listchannels#2905\"
2024-10-18T06:28:26.193Z DEBUG   plugin-pay: cmd 34 partid 0: After filtering routehints we're left with 0 usable hints
2024-10-18T06:28:26.193Z INFO    plugin-pay: cmd 34 partid 0: Destination 02a3f887e6654e5ce3a6b451a72fa4b6c27d4e852831410f0d75edbd218d54e96d is not reachable directly and all routehints were unusable.

It seems the estimated capacity is incorrectly set for routing purpose. How can I fix this?

The merchant settings are:

        developer
        bitcoin-datadir=/etc/bitcoin
        bitcoin-rpcconnect=bitcoind
        announce-addr=merchant_lightningd:9735
        funding-confirms=1
        log-level=debug
        dev-fast-gossip
        dev-bitcoind-poll=1

Version: btcpayserver/lightning:v24.05

NicolasDorier commented 1 week ago

I tried on 24.08.2 as well, same result... May not be a problem from CLN, as I switched the merchant side from CLN to LND and got same behavior... (keeping the customer as CLN)

Something I don't understand about lightning I guess...

cdecker commented 1 week ago

This works as expected. The cause for your inability to send from the fundee is rather simple: you are not meeting the reserve yet.

The reserve is a minimum amount of satoshis that (once you exceed it) you can no longer dip below it. It is usually set to 1% of the funding amount, and is there so that both parties have a stake in the future of the channel, and is enforced by the peer. If we were to let a peer drain its channels completely, then they could cheat without risking any funds, since they don't have any more in the channel. By forcing the peer to keep 1% in their channel this cannot happen. As fundee you start out with no funds on your side, so any amount received goes to fill the reserve, and only then will the funds become available to send.

In your RPC results you can clearly see pieces of information:

...
         "funding": {
            "local_funds_msat": 0,
            "remote_funds_msat": 16777215000,
            "pushed_msat": 0
         },
         "to_us_msat": 123456789,
         "min_to_us_msat": 0,
         "max_to_us_msat": 123456789,
...
         "their_reserve_msat": 167772000,
         "our_reserve_msat": 167772000,
         "spendable_msat": 0,
         "receivable_msat": 16481680211,

This is all from the merchant side, and we can deduce that:

NicolasDorier commented 1 week ago

That make sense, thanks a lot! That explain why things start working when I ran the test twice!