[bug]: `no_route` error when paying dispite direct/opened channel with the peer

phr34k commented 1 year ago

Background

I run a testnet version of a btcpayserver and configured it with lnd. The node is connected to +/- 14 peers, and plenty of liquidity. I've been running some tests with phoenix wallet, and always get a no_route when I try to do a payment from my lnd to my phoenix wallet. I can use the phoenix wallet, to pay for the btcpay invoices w/o problem however.

At first, I assumed it was related there no channel available so I've used https://lndecode.com/ to decode one of the payment request, and took the public key 03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134 - looked up the node and opened a direct channel of about ~399000 sats.

According to 1ml.com that node (endurance) is owned by acinq so I believe this implies that I should have been able to directly transfer money back and forth between phoenix and my lnd node, but instead I always get a no_route error upon using lnd to pay for the payment request.

I think this could be related to:

Your environment

lncli version 0.15.4-beta commit=basedon-v0.15.4-beta-1-fresh-btcpay

Steps to reproduce

I don't know the exact reproduction steps that lead up to the issue. In general what, I did was:

on phoenix (testnet-) wallet, generate a receive invoice- use the edit button to set the amounts
perform a payinvoice with the payment request

docker restart btcpayserver_lnd_bitcoin
./bitcoin-lncli.sh resetmc

 ./bitcoin-lncli.sh payinvoice -f lntb20u1p3hcrlkpp5pufrjwh7m4jjn5029zk76vx7jpk43pzja5f0qp940f7wyrrfr80qdqqxqyjw5q9qtzqqqqqq9qsqsp52vckzug0vcunwm8llauyq300l9wtg33y4jcfj8f9wj20prw3rq3qrzjqwfn3p9278ttzzpe0e00uhyxhned3j5d9acqak5emwfpflp8z2cnflew55fxxm6n65qqqqlgqqqqqeqqjqm4zp9t8drlmgmgcuxcl53cvxnl6htmzl8lrjxz9kw5a7x0w9gm94rgsmudy29wzsmxxh73gcc9xr5sf99jlngkq0fta3snt26f2anvspkwmsky

Expected behaviour

I expected that either the direct channel or one of the other channels would have been used to transfer money back to phoenix wallet.

Actual behaviour

+------------+--------------+--------------+--------------+-----+----------+----------+-------+
| HTLC_STATE | ATTEMPT_TIME | RESOLVE_TIME | RECEIVER_AMT | FEE | TIMELOCK | CHAN_OUT | ROUTE |
+------------+--------------+--------------+--------------+-----+----------+----------+-------+
+------------+--------------+--------------+--------------+-----+----------+----------+-------+
Amount + fee:   0 + 0 sat
Payment hash:   0f12393afedd6529d1ea28aded30de906d588452ed12f004b57a7ce20c6919de
Payment status: FAILED, reason: FAILURE_REASON_NO_ROUTE
[lncli] FAILED

ellemouton commented 1 year ago

Hi @phr34k - just checking: are you sure that the channel was in fact opened & if so, is it active?

phr34k commented 1 year ago

@ellemouton I believe so yes, I mean I'm rather new so I'm not that savvy with the command line to assert but from what I understand the channel is open and active. Here you can see a couple of screens:

I think there's plenty of liquidity and the channel to endurance is opened, green, and also you can see I can receive a (recent-) payment on btcpay, but the payment sending to phoenix always hits a no_route error. You can also see when I query for routes it does actually select endurance node, so I'm puzzled what's actually causing this.

rbndg commented 1 year ago

this happens to me sometimes and it resolves itself eventually.

yyforyongyu commented 1 year ago

Do you have debug logs?

phr34k commented 1 year ago

I recreated some payments in order to capture the logs, I believe this is relevant portion: "missing feature dependency 47". Just my two cents, might be usefull to aggregate warnings/errors that lead up no_route and return them as contextual reasons, so they can be displayed in user-facing ui's such as rtl and some wallets.

2022-11-25 11:22:40.292 [ERR] RPCS: [/routerrpc.Router/TrackPaymentV2]: rpc error: code = NotFound desc = payment isn't initiated
2022-11-25 11:22:40.295 [ERR] RPCS: [/routerrpc.Router/TrackPaymentV2]: rpc error: code = NotFound desc = payment isn't initiated
2022-11-25 11:22:43.858 [ERR] RPCS: [/lnrpc.Lightning/SendPaymentSync]: invalid character in string: '
'
2022-11-25 11:22:45.305 [ERR] RPCS: [/routerrpc.Router/TrackPaymentV2]: rpc error: code = NotFound desc = payment isn't initiated
2022-11-25 11:22:50.319 [ERR] RPCS: [/routerrpc.Router/TrackPaymentV2]: rpc error: code = NotFound desc = payment isn't initiated
2022-11-25 11:22:51.245 [WRN] CRTR: Pathfinding destination node features: missing feature dependency: 47
2022-11-25 11:22:51.245 [WRN] CRTR: Failed to find route for payment c04b876ae0e41e926089ff634ee701b362dfd8c946edb5fc78a382fe9fe5ecfb: missing dependent feature
2022-11-25 11:22:51.261 [WRN] RPCS: Unable to send payment: no_route
2022-11-25 11:22:55.327 [ERR] RPCS: [/routerrpc.Router/TrackPaymentV2]: rpc error: code = NotFound desc = payment isn't initiated
2022-11-25 11:22:55.328 [ERR] RPCS: [/routerrpc.Router/TrackPaymentV2]: rpc error: code = NotFound desc = payment isn't initiated

guggero commented 1 year ago

Feature bit 47 is ScidAliasOptional. Sounds like this might be some issue with the endurance node itself since that's Acinq's implementation (Eclair). Or an interoperability problem. Can you run lncli getnodeinfo 03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134 and paste the result here please?

phr34k commented 1 year ago

@guggero here's the output

{
    "node": {
        "last_update": 1669209210,
        "pub_key": "03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134",
        "alias": "endurance",
        "addresses": [
            {
                "network": "tcp",
                "addr": "13.248.222.197:9735"
            },
            {
                "network": "tcp",
                "addr": "76.223.71.211:9735"
            },
            {
                "network": "tcp",
                "addr": "h7vdzsdiwmtv7ypli7e5ynjpgnnnmtj2wfbxz4dudwpzthfimcqcbkid.onion:9735"
            }
        ],
        "color": "#ffff00",
        "features": {
            "1": {
                "name": "data-loss-protect",
                "is_required": false,
                "is_known": true
            },
            "5": {
                "name": "upfront-shutdown-script",
                "is_required": false,
                "is_known": true
            },
            "7": {
                "name": "gossip-queries",
                "is_required": false,
                "is_known": true
            },
            "8": {
                "name": "tlv-onion",
                "is_required": true,
                "is_known": true
            },
            "11": {
                "name": "unknown",
                "is_required": false,
                "is_known": false
            },
            "13": {
                "name": "static-remote-key",
                "is_required": false,
                "is_known": true
            },
            "14": {
                "name": "payment-addr",
                "is_required": true,
                "is_known": true
            },
            "17": {
                "name": "multi-path-payments",
                "is_required": false,
                "is_known": true
            },
            "19": {
                "name": "wumbo-channels",
                "is_required": false,
                "is_known": true
            },
            "23": {
                "name": "anchors-zero-fee-htlc-tx",
                "is_required": false,
                "is_known": true
            },
            "27": {
                "name": "shutdown-any-segwit",
                "is_required": false,
                "is_known": true
            },
            "29": {
                "name": "unknown",
                "is_required": false,
                "is_known": false
            },
            "39": {
                "name": "unknown",
                "is_required": false,
                "is_known": false
            },
            "45": {
                "name": "explicit-commitment-type",
                "is_required": false,
                "is_known": true
            },
            "47": {
                "name": "scid-alias",
                "is_required": false,
                "is_known": true
            }
        }
    },
    "num_channels": 200,
    "total_capacity": "651304925",
    "channels": [
    ]
}

phr34k commented 1 year ago

I checked my own node and feature 47 isn't listed, when I query the public node id. I think this is due to btcpay not enabling the configuration by default. So I added the a custom fragment to turn it on, like this.

version: "3"
services:
  lnd_bitcoin:
    environment:
      LND_EXTRA_ARGS: |
        protocol.option-scid-alias=true

Now when I run docker exec -it btcpayserver_lnd_bitcoin /bin/cat ~/.lnd/lnd.conf I can clearly see the option listed, and when I run ./bitcoin-lncli.sh getnodeinfo 03d5b2724e7624b436b61599c337fbc91eb7a09e82d2f0bfcfb05567aca9555fc4 the following output is generated.

{
    "node": {
        "last_update": 1669436505,
        "pub_key": "03d5b2724e7624b436b61599c337fbc91eb7a09e82d2f0bfcfb05567aca9555fc4",
        "alias": "03d5b2724e7624b436b6",
        "addresses": [
            {
                "network": "tcp",
                "addr": "82.168.121.213:9735"
            },
            {
                "network": "tcp",
                "addr": "f6fn672s6dco3bfog3ulwuisexotyktnjhruvswpfkxc7ywrjzbejjyd.onion:9735"
            }
        ],
        "color": "#3399ff",
        "features": {
            "0": {
                "name": "data-loss-protect",
                "is_required": true,
                "is_known": true
            },
            "5": {
                "name": "upfront-shutdown-script",
                "is_required": false,
                "is_known": true
            },
            "7": {
                "name": "gossip-queries",
                "is_required": false,
                "is_known": true
            },
            "9": {
                "name": "tlv-onion",
                "is_required": false,
                "is_known": true
            },
            "12": {
                "name": "static-remote-key",
                "is_required": true,
                "is_known": true
            },
            "14": {
                "name": "payment-addr",
                "is_required": true,
                "is_known": true
            },
            "17": {
                "name": "multi-path-payments",
                "is_required": false,
                "is_known": true
            },
            "19": {
                "name": "wumbo-channels",
                "is_required": false,
                "is_known": true
            },
            "23": {
                "name": "anchors-zero-fee-htlc-tx",
                "is_required": false,
                "is_known": true
            },
            "27": {
                "name": "shutdown-any-segwit",
                "is_required": false,
                "is_known": true
            },
            "31": {
                "name": "amp",
                "is_required": false,
                "is_known": true
            },
            "45": {
                "name": "explicit-commitment-type",
                "is_required": false,
                "is_known": true
            },
            "47": {
                "name": "scid-alias",
                "is_required": false,
                "is_known": true
            },
            "2023": {
                "name": "script-enforced-lease",
                "is_required": false,
                "is_known": true
            }
        }
    },
    "num_channels": 14,
    "total_capacity": "88373916",
    "channels": [
    ]
}

It still generates a no_route through:

2022-11-26 04:34:52.081 [WRN] CRTR: Pathfinding destination node features: missing feature dependency: 47
2022-11-26 04:34:52.081 [WRN] CRTR: Failed to find route for payment e066d3cfc6b9cdc82e7256907264f4aef744ea04acdbd4337902d7e789eeafb3: missing dependent feature
2022-11-26 04:34:52.094 [WRN] RPCS: Unable to send payment: no_route
2022-11-26 04:34:53.225 [ERR] RPCS: [/routerrpc.Router/TrackPaymentV2]: rpc error: code = NotFound desc = payment isn't initiated

phr34k commented 1 year ago

Looks like this might be a known issue with older version of the phoenix wallet (https://github.com/ACINQ/phoenix/issues/317#issuecomment-1328030106).

bitromortac commented 1 year ago

I recently tried a payment from lnd to phoenix (mainnet), which worked. Since this looks like it's already fixed, would you consider to close the issue?

Roasbeef commented 1 year ago

Closing based on the above comment from the OP.

lightningnetwork / lnd