search

lightningnetwork / lnd

Lightning Network Daemon ⚡️
MIT License
7.68k stars 2.08k forks source link

[bug]: Unexpected insufficient balance error on SendPaymentV2 #9204

Open Jhoyola opened 1 week ago

Jhoyola commented 1 week ago

Background

On regtest when sending payment over grpc with SendPaymentV2 I get insufficient balance error eventough there is a direct channel with balance when checking with listchannels. The receiving node is CLN v24.05. Payments to the other direction on the channel work fine and the channel balance on listchannels is updated correctly.

Logs show this error for the channel: [ERR] NANN: Unable to retrieve chan status for Channel(ecd587ecb1df5098ce707143a4a7b4166cd1bea9a87a3f3c6f8a4a1abddb944a:0): edge not found

Your environment

Steps to reproduce

Not sure how to reproduce.

Expected behaviour

Payment should be successful

Actual behaviour

Get Payment_FAILED with FAILURE_REASON_INSUFFICIENT_BALANCE

GRPC request:

Dest = {[]uint8} nil
Amt = {int64} 0
PaymentHash = {[]uint8} nil
FinalCltvDelta = {int32} 0
**PaymentRequest = {string} "lnbcrt1u1pn3vxktsp5ygc6ckeny7wrrs5uykes42wnqnvr5scul4gtn5yzw2fqz0akwajspp5q9wtk5nnlnucwz4n2v2z9yxapkhx08tk8956gpd5006rs74slpcqdqqxqyrp4qcqp29qxpqysgq3r7akc3e0tvsepc6t6jzkv2pxp7lgpnps4xpzy9kl5ur3scqpyrhldv5sv9xhjd7yy4p85a395rk3d8v8aruj7n5kaugprfnp3f3lusplqkzhf"**
**TimeoutSeconds = {int32} 11**
FeeLimitSat = {int64} 0
OutgoingChanId = {uint64} 0
CltvLimit = {int32} 0
RouteHints = {[]*lnrpc.RouteHint} nil
DestCustomRecords = {map[uint64][]uint8} nil
AmtMsat = {int64} 0
FeeLimitMsat = {int64} 0
LastHopPubkey = {[]uint8} nil
AllowSelfPayment = {bool} false
DestFeatures = {[]lnrpc.FeatureBit} nil
MaxParts = {uint32} 0
NoInflightUpdates = {bool} false
OutgoingChanIds = {[]uint64} nil
PaymentAddr = {[]uint8} nil
MaxShardSizeMsat = {uint64} 0
Amp = {bool} false
TimePref = {float64} 0

GRPC response:

PaymentHash = {string} "015cbb5273fcf9870ab353142290dd0dae679d763969a405b47bf4387ab0f870"
Value = {int64} 100
CreationDate = {int64} 1729502075
Fee = {int64} 0
PaymentPreimage = {string} "0000000000000000000000000000000000000000000000000000000000000000"
ValueSat = {int64} 100
ValueMsat = {int64} 100000
PaymentRequest = {string} "lnbcrt1u1pn3vxktsp5ygc6ckeny7wrrs5uykes42wnqnvr5scul4gtn5yzw2fqz0akwajspp5q9wtk5nnlnucwz4n2v2z9yxapkhx08tk8956gpd5006rs74slpcqdqqxqyrp4qcqp29qxpqysgq3r7akc3e0tvsepc6t6jzkv2pxp7lgpnps4xpzy9kl5ur3scqpyrhldv5sv9xhjd7yy4p85a395rk3d8v8aruj7n5kaugprfnp3f3lusplqkzhf"
Status = {lnrpc.Payment_PaymentStatus} Payment_FAILED (3)
FeeSat = {int64} 0
FeeMsat = {int64} 0
CreationTimeNs = {int64} 1729502075950633068
Htlcs = {[]*lnrpc.HTLCAttempt} nil
PaymentIndex = {uint64} 17014
FailureReason = {lnrpc.PaymentFailureReason} PaymentFailureReason_FAILURE_REASON_INSUFFICIENT_BALANCE (5)

List channels response:

"channels":  [
    {
        "active":  true,
        "remote_pubkey":  "023872aec64e366654a07d1ad73f565d6c283237a9c0bb2c1c90a78c7c27a857db",
        "channel_point":  "ecd587ecb1df5098ce707143a4a7b4166cd1bea9a87a3f3c6f8a4a1abddb944a:0",
        "chan_id":  "222123339043373056",
        "capacity":  "500000",
        "local_balance":  "115882",
        "remote_balance":  "382047",
        "commit_fee":  "1411",
        "commit_weight":  "1116",
        "fee_per_kw":  "1255",
        "unsettled_balance":  "0",
        "total_satoshis_sent":  "0",
        "total_satoshis_received":  "15882",
        "num_updates":  "25",
        "pending_htlcs":  [],
        "csv_delay":  6,
        "private":  false,
        "initiator":  false,
        "chan_status_flags":  "ChanStatusDefault",
        "local_chan_reserve_sat":  "5000",
        "remote_chan_reserve_sat":  "5000",
        "static_remote_key":  false,
        "commitment_type":  "ANCHORS",
        "lifetime":  "2861",
        "uptime":  "2777",
        "close_address":  "",
        "push_amount_sat":  "100000",
        "thaw_height":  0,
        "local_constraints":  {
            "csv_delay":  6,
            "chan_reserve_sat":  "5000",
            "dust_limit_sat":  "354",
            "max_pending_amt_msat":  "18446744073709551615",
            "min_htlc_msat":  "0",
            "max_accepted_htlcs":  483
        },
        "remote_constraints":  {
            "csv_delay":  144,
            "chan_reserve_sat":  "5000",
            "dust_limit_sat":  "546",
            "max_pending_amt_msat":  "495000000",
            "min_htlc_msat":  "1",
            "max_accepted_htlcs":  483
        },
        "alias_scids":  [],
        "zero_conf":  false,
        "zero_conf_confirmed_scid":  "0",
        "peer_alias":  "carol",
        "peer_scid_alias":  "0",
        "memo":  ""
    }
]
Jhoyola commented 1 week ago

Might be related to https://github.com/lightningnetwork/lnd/issues/6987

ziggie1984 commented 1 week ago

Try settting the debuglevel for CRTR to debug/trace and check what its saying, it will give you a detailed reason why lnd thinks there is not enough balance to complete the payment.

Jhoyola commented 1 week ago

Trace level logs for attempted payment

2024-10-21 10:44:15.292 [TRC] CRTR: Dispatching SendPayment for lightning payment: (routing.LightningPayment) {
 Target: (route.Vertex) (len=33 cap=33) 023872aec64e366654a07d1ad73f565d6c283237a9c0bb2c1c90a78c7c27a857db,
 Amount: (lnwire.MilliSatoshi) 900000 mSAT,
 FeeLimit: (lnwire.MilliSatoshi) 900000 mSAT,
 CltvLimit: (uint32) 2016,
 paymentHash: (*lntypes.Hash)(0xc000b17300)((len=32 cap=32) d5e0b9371c6dc84f4fc7b519806f60f6eb4c8ffaf28629f1b515bbe64be62fca),
 amp: (*routing.AMPOptions)(<nil>),
 FinalCLTVDelta: (uint16) 10,
 PayAttemptTimeout: (time.Duration) 1m0s,
 RouteHints: ([][]zpay32.HopHint) <nil>,
 OutgoingChannelIDs: ([]uint64) <nil>,
 LastHop: (*route.Vertex)(<nil>),
 DestFeatures: (*lnwire.FeatureVector)(0xc000647d10)({
  RawFeatureVector: (*lnwire.RawFeatureVector)(0xc000b32aa8)({
   features: (map[lnwire.FeatureBit]struct {}) (len=4) {
    (lnwire.FeatureBit) 17: (struct {}) {
    },
    (lnwire.FeatureBit) 25: (struct {}) {
    },
    (lnwire.FeatureBit) 8: (struct {}) {
    },
    (lnwire.FeatureBit) 14: (struct {}) {
    }
   }
  }),
  featureNames: (map[lnwire.FeatureBit]string) (len=43) {
   (lnwire.FeatureBit) 13: (string) (len=17) "static-remote-key",
   (lnwire.FeatureBit) 14: (string) (len=12) "payment-addr",
   (lnwire.FeatureBit) 25: (string) (len=14) "route-blinding",
   (lnwire.FeatureBit) 27: (string) (len=19) "shutdown-any-segwit",
   (lnwire.FeatureBit) 181: (string) (len=22) "simple-taproot-chans-x",
   (lnwire.FeatureBit) 6: (string) (len=14) "gossip-queries",
   (lnwire.FeatureBit) 15: (string) (len=12) "payment-addr",
   (lnwire.FeatureBit) 22: (string) (len=24) "anchors-zero-fee-htlc-tx",
   (lnwire.FeatureBit) 50: (string) (len=9) "zero-conf",
   (lnwire.FeatureBit) 24: (string) (len=14) "route-blinding",
   (lnwire.FeatureBit) 80: (string) (len=20) "simple-taproot-chans",
   (lnwire.FeatureBit) 5: (string) (len=23) "upfront-shutdown-script",
   (lnwire.FeatureBit) 7: (string) (len=14) "gossip-queries",
   (lnwire.FeatureBit) 9: (string) (len=9) "tlv-onion",
   (lnwire.FeatureBit) 44: (string) (len=24) "explicit-commitment-type",
   (lnwire.FeatureBit) 54: (string) (len=7) "keysend",
   (lnwire.FeatureBit) 47: (string) (len=10) "scid-alias",
   (lnwire.FeatureBit) 46: (string) (len=10) "scid-alias",
   (lnwire.FeatureBit) 180: (string) (len=22) "simple-taproot-chans-x",
   (lnwire.FeatureBit) 12: (string) (len=17) "static-remote-key",
   (lnwire.FeatureBit) 19: (string) (len=14) "wumbo-channels",
   (lnwire.FeatureBit) 30: (string) (len=3) "amp",
   (lnwire.FeatureBit) 31: (string) (len=3) "amp",
   (lnwire.FeatureBit) 49: (string) (len=16) "payment-metadata",
   (lnwire.FeatureBit) 55: (string) (len=7) "keysend",
   (lnwire.FeatureBit) 0: (string) (len=17) "data-loss-protect",
   (lnwire.FeatureBit) 4: (string) (len=23) "upfront-shutdown-script",
   (lnwire.FeatureBit) 17: (string) (len=19) "multi-path-payments",
   (lnwire.FeatureBit) 20: (string) (len=18) "anchor-commitments",
   (lnwire.FeatureBit) 1: (string) (len=17) "data-loss-protect",
   (lnwire.FeatureBit) 51: (string) (len=9) "zero-conf",
   (lnwire.FeatureBit) 26: (string) (len=19) "shutdown-any-segwit",
   (lnwire.FeatureBit) 8: (string) (len=9) "tlv-onion",
   (lnwire.FeatureBit) 16: (string) (len=19) "multi-path-payments",
   (lnwire.FeatureBit) 21: (string) (len=18) "anchor-commitments",
   (lnwire.FeatureBit) 18: (string) (len=14) "wumbo-channels",
   (lnwire.FeatureBit) 45: (string) (len=24) "explicit-commitment-type",
   (lnwire.FeatureBit) 2022: (string) (len=21) "script-enforced-lease",
   (lnwire.FeatureBit) 3: (string) (len=20) "initial-routing-sync",
   (lnwire.FeatureBit) 23: (string) (len=24) "anchors-zero-fee-htlc-tx",
   (lnwire.FeatureBit) 48: (string) (len=16) "payment-metadata",
   (lnwire.FeatureBit) 2023: (string) (len=21) "script-enforced-lease",
   (lnwire.FeatureBit) 81: (string) (len=20) "simple-taproot-chans"
  }
 }),
 PaymentAddr: (*[32]uint8)(0xc000b17260)((len=32 cap=32) {
  00000000  9b 15 9e 31 b0 11 75 13  7d ee 12 98 d9 09 dd a2  |...1..u.}.......|
  00000010  7d 52 85 b8 00 84 06 97  e0 45 74 df 88 a6 77 d3  |}R.......Et...w.|
 }),
 PaymentRequest: ([]uint8) (len=259 cap=288) {
  00000000  6c 6e 62 63 72 74 39 75  31 70 6e 33 76 39 66 7a  |lnbcrt9u1pn3v9fz|
  00000010  73 70 35 6e 76 32 65 75  76 64 73 7a 39 36 33 78  |sp5nv2euvdsz963x|
  00000020  6c 30 77 7a 32 76 64 6a  7a 77 61 35 66 37 34 39  |l0wz2vdjzwa5f749|
  00000030  70 64 63 71 7a 7a 71 64  39 6c 71 67 34 36 64 6c  |pdcqzzqd9lqg46dl|
  00000040  7a 39 78 77 6c 66 73 70  70 35 36 68 73 74 6a 64  |z9xwlfspp56hstjd|
  00000050  63 75 64 68 79 79 37 6e  37 38 6b 35 76 63 71 6d  |cudhyy7n78k5vcqm|
  00000060  6d 71 37 6d 34 35 65 72  6c 36 37 32 72 7a 6e 75  |mq7m45erl672rznu|
  00000070  64 34 7a 6b 61 37 76 6a  6c 78 39 6c 39 71 64 71  |d4zka7vjlx9l9qdq|
  00000080  71 78 71 79 72 70 34 71  63 71 70 32 39 71 78 70  |qxqyrp4qcqp29qxp|
  00000090  71 79 73 67 71 76 66 71  65 77 6c 30 6a 64 36 79  |qysgqvfqewl0jd6y|
  000000a0  38 33 35 6b 6e 6e 33 6e  77 6e 35 64 6d 75 75 68  |835knn3nwn5dmuuh|
  000000b0  32 72 6b 34 38 61 66 68  63 68 78 6e 35 72 68 75  |2rk48afhchxn5rhu|
  000000c0  6a 63 7a 71 72 75 7a 70  68 68 78 79 36 76 35 77  |jczqruzphhxy6v5w|
  000000d0  77 34 6e 64 34 6a 66 67  36 72 71 37 34 70 79 70  |w4nd4jfg6rq74pyp|
  000000e0  66 33 61 71 6e 6d 35 76  6a 6c 74 6e 6d 7a 36 39  |f3aqnm5vjltnmz69|
  000000f0  74 65 32 71 6b 72 77 37  33 6d 64 67 71 38 61 33  |te2qkrw73mdgq8a3|
  00000100  36 79 61                                          |6ya|
 },
 DestCustomRecords: (record.CustomSet) <nil>,
 MaxParts: (uint32) 16,
 MaxShardAmt: (*lnwire.MilliSatoshi)(<nil>),
 TimePref: (float64) 0,
 Metadata: ([]uint8) <nil>
}
2024-10-21 10:44:15.295 [DBG] CRTR: Payment d5e0b9371c6dc84f4fc7b519806f60f6eb4c8ffaf28629f1b515bbe64be62fca: status=Initiated, active_shards=0, rem_value=900000 mSAT, fee_limit=900000 mSAT
2024-10-21 10:44:15.295 [DBG] CRTR: PaymentSession(d5e0b9371c6dc84f4fc7b519806f60f6eb4c8ffaf28629f1b515bbe64be62fca): pathfinding for amt=900000 mSAT
2024-10-21 10:44:15.295 [WRN] CRTR: Not enough outbound balance to send htlc of amount: 900000 mSAT, only have local balance: 0 mSAT
2024-10-21 10:44:15.295 [DBG] CRTR: Pathfinding perf metrics: nodes=0, edges=0, time=18.614µs
2024-10-21 10:44:15.295 [DBG] CRTR: PaymentSession(d5e0b9371c6dc84f4fc7b519806f60f6eb4c8ffaf28629f1b515bbe64be62fca): not splitting because local balance is insufficient
2024-10-21 10:44:15.295 [WRN] CRTR: Failed to find route for payment d5e0b9371c6dc84f4fc7b519806f60f6eb4c8ffaf28629f1b515bbe64be62fca: insufficient local balance
2024-10-21 10:44:15.295 [WRN] CRTR: Marking payment d5e0b9371c6dc84f4fc7b519806f60f6eb4c8ffaf28629f1b515bbe64be62fca permanently failed with no route: insufficient_balance
2024-10-21 10:44:15.311 [ERR] CRTR: No route found for payment d5e0b9371c6dc84f4fc7b519806f60f6eb4c8ffaf28629f1b515bbe64be62fca
2024-10-21 10:44:15.311 [DBG] CRTR: Payment d5e0b9371c6dc84f4fc7b519806f60f6eb4c8ffaf28629f1b515bbe64be62fca: status=Failed, active_shards=0, rem_value=900000 mSAT, fee_limit=900000 mSAT
2024-10-21 10:44:15.311 [WRN] CHDB: Payment(d5e0b9371c6dc84f4fc7b519806f60f6eb4c8ffaf28629f1b515bbe64be62fca): cannot register HTLC attempt: payment has already failed, current status: Failed
2024-10-21 10:44:15.311 [ERR] RRPC: TrackPayment got error for payment 64356530623933373163366463383466346663376235313938303666363066366562346338666661663238363239663162353135626265363462653632666361: <nil>
2024-10-21 10:44:15.313 [ERR] CRTR: Payment d5e0b9371c6dc84f4fc7b519806f60f6eb4c8ffaf28629f1b515bbe64be62fca failed: insufficient_balance
ziggie1984 commented 1 week ago

what does lncli getchaninfo 222123339043373056 say ?

ziggie1984 commented 1 week ago

My guess is that you have no outgoing policy set for this channel, that's why in the pathfinding logic we don't consider this this channel.

Jhoyola commented 1 week ago

what does lncli getchaninfo 222123339043373056 say ?

It gives edge not found (added -n regtest in the command of)

Also tried lncli -n regtest updatechanpolicy --base_fee_msat 1000 --fee_rate 0 --time_lock_delta 50 --chan_point ecd587ecb1df5098ce707143a4a7b4166cd1bea9a87a3f3c6f8a4a1abddb944a:0

That return:

"failed_updates": [ { "outpoint": "ecd587ecb1df5098ce707143a4a7b4166cd1bea9a87a3f3c6f8a4a1abddb944a:0", "reason": "UPDATE_FAILURE_UNKNOWN", "update_error": "could not update policies" } ]

ziggie1984 commented 1 week ago

can you reproduce this behavior with other CLN channels opened to you, seems like you did not get the ChanAnnouncement from you peer, can you verify if the CLN node can use this channel.

Jhoyola commented 1 week ago

My CLN can pay invoices on this channel, I just retested that. I also can open new channels in either direction and they work normally.

I suspect this is something to do me just shutting down LND and something unlucky happened.

ziggie1984 commented 1 week ago

your logs suggests that this channel was successfully used for some payments tho or ? Or did this channel ever send/forward some sats ?

Seems like this channel was never in its lifetime useable for sending : "total_satoshis_sent": "0",

ziggie1984 commented 1 week ago

I wonder if CLN ever resends the ChanAnnouncment (Signatures), do you still have the logs at channel confirmation time ? (CLN and LND logs)

EDIT: can you provide the channel.db of the regtest LND node.

Jhoyola commented 6 days ago

No logs anymore sadly. But here is the channel.db channel.zip