search

lightninglabs / taproot-assets

A layer 1 daemon, for the Taproot Assets Protocol specification, written in Go (golang)
MIT License
457 stars 110 forks source link

[custom channels]: fix bandwidth reported by TLV traffic shaper #1060

Open MegalithicBTC opened 1 month ago

MegalithicBTC commented 1 month ago

Here is the situation.

A node opened an asset channel to my node, and used the keysend command to send my node assets.

Following the keysend, the channel looked like this:

user@aw60:/src$ lncli listchannels
{
    "channels": [
        {
            "active": true,
            "remote_pubkey": "022d71f557bdc06b37db1f2c8761e32c7345169719c49bb0f534bf9dc15fee141a",
            "channel_point": "c0e214e3dab15cde21d615ac110656f65d823ec852dbe78b5e83ceab8669da85:0",
            "chan_id": "940555231906103296",
            "capacity": "100000",
            "local_balance": "500",
            "remote_balance": "97914",
            "commit_fee": "926",
            "commit_weight": "958",
            "fee_per_kw": "957",
            "unsettled_balance": "0",
            "total_satoshis_sent": "0",
            "total_satoshis_received": "500",
            "num_updates": "2",
            "pending_htlcs": [],
            "csv_delay": 144,
            "private": true,
            "initiator": false,
            "chan_status_flags": "ChanStatusDefault",
            "local_chan_reserve_sat": "1062",
            "remote_chan_reserve_sat": "1000",
            "static_remote_key": false,
            "commitment_type": "SIMPLE_TAPROOT",
            "lifetime": "1160",
            "uptime": "1160",
            "close_address": "",
            "push_amount_sat": "0",
            "thaw_height": 0,
            "local_constraints": {
                "csv_delay": 144,
                "chan_reserve_sat": "1062",
                "dust_limit_sat": "354",
                "max_pending_amt_msat": "99000000",
                "min_htlc_msat": "1",
                "max_accepted_htlcs": 483
            },
            "remote_constraints": {
                "csv_delay": 144,
                "chan_reserve_sat": "1000",
                "dust_limit_sat": "354",
                "max_pending_amt_msat": "99000000",
                "min_htlc_msat": "1",
                "max_accepted_htlcs": 483
            },
            "alias_scids": [
                "17592186044416000000"
            ],
            "zero_conf": false,
            "zero_conf_confirmed_scid": "0",
            "peer_alias": "stablechannels",
            "peer_scid_alias": "17592186044416000000",
            "memo": "",
            "custom_channel_data": {
                "assets": [
                    {
                        "asset_utxo": {
                            "version": 1,
                            "asset_genesis": {
                                "genesis_point": "005f5e93263ff730fa0f2909e50ca9e5b8452a2f3a38621ada3356ac7662e5cd:0",
                                "name": "Umint.cash.test",
                                "meta_hash": "524d433446e98bece52809e65578efc6c625e226ba5f2debd7ae05b0611691d1",
                                "asset_id": "2ca93a1373e8a2ab2de8934f46fd86dac37cb7eca30accda6e24778f67020e5e"
                            },
                            "amount": 5000,
                            "script_key": "0250aaeb166f4234650d84a2d8a130987aeaf6950206e0905401ee74ff3f8d18e6"
                        },
                        "capacity": 5000,
                        "local_balance": 50,
                        "remote_balance": 4950
                    }
                ]
            }
        },

You can see the asset balances:

"capacity": 5000,
 "local_balance": 50,
 "remote_balance": 4950

Next: I attempted to keysend some assets back to this node. I used the command:

user@aw60:/src$ ./litcli-assetfunctions-mainnet.sh ln sendpayment --keysend --asset_id 2ca93a1373e8a2ab2de8934f46fd86dac37cb7eca30accda6e24778f67020e5e --amt 1 --dest 022d71f557bdc06b37db1f2c8761e32c7345169719c49bb0f534bf9dc15fee141a
+------------+--------------+--------------+--------------+-----+----------+----------+-------+
| HTLC_STATE | ATTEMPT_TIME | RESOLVE_TIME | RECEIVER_AMT | FEE | TIMELOCK | CHAN_OUT | ROUTE |
+------------+--------------+--------------+--------------+-----+----------+----------+-------+
+------------+--------------+--------------+--------------+-----+----------+----------+-------+
Amount + fee:   0 + 0 sat
Payment hash:   d927ad81e15ac37dc979c4a5409544014ab8366b57ec2bae9bd99139de6cf83c
Payment status: FAILED, reason: FAILURE_REASON_INSUFFICIENT_BALANCE
[litcli] FAILED
user@aw60:/src$

The keysend failed with FAILURE_REASON_INSUFFICIENT_BALANCE.

Following this, my partner node sent me 1000 satoshis, via standard bolt 11 invoice.

Following this, my local sats balance in the channel increased from 500 to 1500 satoshis

user@aw60:/src$ lncli listchannels
{
    "channels": [
        {
            "active": true,
            "remote_pubkey": "022d71f557bdc06b37db1f2c8761e32c7345169719c49bb0f534bf9dc15fee141a",
            "channel_point": "c0e214e3dab15cde21d615ac110656f65d823ec852dbe78b5e83ceab8669da85:0",
            "chan_id": "940555231906103296",
            "capacity": "100000",
            "local_balance": "1500",
            "remote_balance": "96914",

Following this, I again attempted the same keysend operation. I got a different output, but it was still not successful.

user@aw60:/src$ ./litcli-assetfunctions-mainnet.sh ln sendpayment --keysend --asset_id 2ca93a1373e8a2ab2de8934f46fd86dac37cb7eca30accda6e24778f67020e5e --amt 1 --dest 022d71f557bdc06b37db1f2c8761e32c7345169719c49bb0f534bf9dc15fee141a
+-------------------------------------+--------------+--------------+--------------+-----+----------+--------------------+----------------+
| HTLC_STATE                          | ATTEMPT_TIME | RESOLVE_TIME | RECEIVER_AMT | FEE | TIMELOCK | CHAN_OUT           | ROUTE          |
+-------------------------------------+--------------+--------------+--------------+-----+----------+--------------------+----------------+
| TEMPORARY_CHANNEL_FAILURE @ 0th hop |        0.042 |        0.059 | 500          | 0   |   855517 | 940555231906103296 | stablechannels |
| TEMPORARY_CHANNEL_FAILURE @ 0th hop |        0.106 |        0.123 | 500          | 0   |   855517 | 940555231906103296 | stablechannels |
| TEMPORARY_CHANNEL_FAILURE @ 0th hop |        0.174 |        0.185 | 500          | 0   |   855517 | 940555231906103296 | stablechannels |
| TEMPORARY_CHANNEL_FAILURE @ 0th hop |        0.233 |        0.250 | 500          | 0   |   855517 | 940555231906103296 | stablechannels |
| TEMPORARY_CHANNEL_FAILURE @ 0th hop |        0.300 |        0.317 | 500          | 0   |   855517 | 940555231906103296 | stablechannels |
| TEMPORARY_CHANNEL_FAILURE @ 0th hop |        0.367 |        0.384 | 500          | 0   |   855517 | 940555231906103296 | stablechannels |
| TEMPORARY_CHANNEL_FAILURE @ 0th hop |        0.434 |        0.451 | 500          | 0   |   855517 | 940555231906103296 | stablechannels |
| IN_FLIGHT                           |        0.497 |            - | 500          | 0   |   855517 | 940555231906103296 | stablechannels |

The console continued like this with thousands of 'TEMPORARY_CHANNEL_FAILURE @ 0th hop` outputs per second.

NOTE -- this is on Mainnet. Neither my node, nor my partner's node, has a price oracle set up.

MegalithicBTC commented 1 month ago

My VERY ROUGH guess is that the FAILURE_REASON_INSUFFICIENT_BALANCE response has something to do with channel reserves, and that the next error TEMPORARY_CHANNEL_FAILURE @ 0th hop might be related to not having a price oracle set up, or possible other issues with keysend.

guggero commented 1 month ago

Thanks for the detailed report.

The first part is a known issue: https://github.com/lightninglabs/taproot-assets/issues/888 You solved it "correctly" for now by sloshing around BTC balance.

The second time it failed with the temporary channel failure looks odd. Can you attach the logs of both the sending node and the first hop please?

guggero commented 1 month ago

Going to transfer the issue to the taproot-assets repository. You were correct in opening it here, since you're running litd. But anything directly related to Taproot Asset Channels is easier for us to track in the taproot-assets repo, as most changes will likely be implemented there.

MegalithicBTC commented 1 month ago

We were able to reproduce this issue. This time it's on testnet. I'm attempting to keysend an asset.

Let's start with the current state of the channel:

user@aw60:/src$ ./lncli-testnet.sh listchannels 
{
    "channels": [
        {
            "active": true,
            "remote_pubkey": "037631c146daa9894527447ef9d5edc99c8b3794b5234d825d11101c998064be86",
            "channel_point": "5ca999048d5054c05b999148e619ff126d47c1df9213a5c108c01290205b0b26:0",
            "chan_id": "3158101959713882112",
            "capacity": "100000",
            "local_balance": "1500",
            "remote_balance": "95420",
            "commit_fee": "2420",
            "commit_weight": "958",
            "fee_per_kw": "2500",
            "unsettled_balance": "0",
            "total_satoshis_sent": "0",
            "total_satoshis_received": "1500",
            "num_updates": "6",
            "pending_htlcs": [],
            "csv_delay": 144,
            "private": true,
            "initiator": false,
            "chan_status_flags": "ChanStatusDefault",
            "local_chan_reserve_sat": "1062",
            "remote_chan_reserve_sat": "1000",
            "static_remote_key": false,
            "commitment_type": "SIMPLE_TAPROOT",
            "lifetime": "55118",
            "uptime": "55118",
            "close_address": "",
            "push_amount_sat": "0",
            "thaw_height": 0,
            "local_constraints": {
                "csv_delay": 144,
                "chan_reserve_sat": "1062",
                "dust_limit_sat": "354",
                "max_pending_amt_msat": "99000000",
                "min_htlc_msat": "1",
                "max_accepted_htlcs": 483
            },
            "remote_constraints": {
                "csv_delay": 144,
                "chan_reserve_sat": "1000",
                "dust_limit_sat": "354",
                "max_pending_amt_msat": "99000000",
                "min_htlc_msat": "1",
                "max_accepted_htlcs": 483
            },
            "alias_scids": [
                "17592186044416000020"
            ],
            "zero_conf": false,
            "zero_conf_confirmed_scid": "0",
            "peer_alias": "stablechannels-testnet",
            "peer_scid_alias": "17592186044416000000",
            "memo": "",
            "custom_channel_data": {
                "assets": [
                    {
                        "asset_utxo": {
                            "version": 1,
                            "asset_genesis": {
                                "genesis_point": "eb278e14fb151f4d7b41673b0671093922012ebc3cfcaddd2156885943da61f7:1",
                                "name": "Umint.cash.test",
                                "meta_hash": "524d433446e98bece52809e65578efc6c625e226ba5f2debd7ae05b0611691d1",
                                "asset_id": "18ee41dbc92292d6fefcf066c7ea76e1fa711e9e347b768ad8760e177e451f67"
                            },
                            "amount": 5000,
                            "script_key": "0250aaeb166f4234650d84a2d8a130987aeaf6950206e0905401ee74ff3f8d18e6"
                        },
                        "capacity": 5000,
                        "local_balance": 150,
                        "remote_balance": 4850
                    }
                ]
            }
        }
    ]
}

You can see that I have 150 of this asset.

So here is my command, trying to keysend some to my channel counterparty:

./litcli-assetfunctions-testnet.sh ln sendpayment --keysend --asset_id 18ee41dbc92292d6fefcf066c7ea76e1fa711e9e347b768ad8760e177e451f67 --amt 1 --dest 037631c146daa9894527447ef9d5edc99c8b3794b5234d825d11101c998064be86

The LND logs immediately go beserk. I am attaching the logs here.

lnd.log lnd.log.4.gz lnd.log.5.gz lnd.log.6.gz

starbackr-dev commented 1 month ago

tap-channel-issue.txt

logs from the asset channel originator side.

guggero commented 1 month ago

Thanks a lot for the logs! I was able to pinpoint exactly what's going wrong.

Basically due to the channel reserve, the channel can only send a maximum of 438 sat in the current state (local_balance - local_chan_reserve_sat = 1500 - 1062 = 438), but the HTLC transporting the asset wants to send 500 sats.

Which can be seen by this message:

2024-08-06 13:22:29.592 [WRN] HSWC: ChannelLink(5ca999048d5054c05b999148e619ff126d47c1df9213a5c108c01290205b0b26:0): insufficient bandwidth to route htlc: 500000 mSAT is larger than 438000 mSAT

The issue is that the channel is still attempted, because the TLV traffic shaper reports more than enough bandwidth initially:

2024-08-06 13:22:29.568 [DBG] CRTR: ShortChannelID=2872277:310:0: external traffic shaper reported available bandwidth: 2100000000000000000 mSAT

The 2100000000000000000 mSAT is basically a dummy value telling lnd that there's enough bandwidth, since there are assets in that channel (for which at that point we can't calculate the real satoshi value because we don't have access to a quote with a price in that part of the code).

So there are two issues here that need fixing:

This will require changes in lnd, so I'll get to work on that.

dstadulis commented 3 weeks ago

Removing from Sprint 30 Available to be reassigned if others want to take it from @guggero

guggero commented 3 weeks ago

Probably also need to report 0 bandwidth for non-TAP channels.

Example for paying a 500 sat invoice with assets, but the pathfinding choosing arbitrary (non-TAP channel) first hops:

d5fac4f7358e:/# litcli --macaroonpath /root/.lnd/data/chain/bitcoin/mainnet/admin.macaroon ln payinvoice --pay_req lnbc5u1pnvgudppp52g3pn35s5ewzu2guahyv44mparkxg2y7r3egqpflumc6yt5xdd8sdqqcqzzsxqyz5vqsp5w64str3ac0s4z6h4fhzry5gcj483mvlz8n5l6uajcfsl2uvscvys9qxpqysgqwmw58axr96xln4srf4wgp69aqkrfgfl7cv79h83cs56s6zke07yhmr672xeyj8e6sz4k0w45dhcw559mtu5k3vwkv35dw6sk0qqlkugpjwcrpf --asset_id d75dae162be7cd0a2df76831ee1cce4eaeb74a32fabb0d46be7a0ad70fd6ad27
Payment hash: 522219c690a65c2e291cedc8cad761e8ec64289e1c7280053fe6f1a22e866b4f
Description:
Amount (in satoshis): 500
Fee limit (in satoshis): 500
Destination: 0324ba2392e25bff76abd0b1f7e4b53b5f82aa53fddc3419b051b6c801db9e2247
Confirm payment (yes/no): yes
Got quote for 29411 asset units at 17 msat/unit from peer 038dbb70e3484da0bed806156f5270d39b480a659c82fb4b56ba3dcbe0edd74d55 with SCID 15907459453197872513

image

dstadulis commented 1 week ago

Will dis-aggregate this issue into two sub issues. @guggero Recommendation 1) Start from itest 2) try to repro 3) look at logs 4) go into code

dstadulis commented 1 week ago

@GeorgeTsagk was able to reproduce the issue Will go forward implementing a fix via stop false positive reporting of asset bandwidth. Will fix this in the path pathfinding hook.