payment stuck in flight for 10 days

[champo]

Background

On Feb 8 a user attempted to pay 2 invoices to the same node and both seem to have gotten stuck. Both payment exhibit the same behaviour.

In LND logs about the time the payment was originally executed we have the following log repeated over and over for several minutes:

Feb 08 18:43:00 ip-10-2-1-81 lnd[4074]: 2020-02-08 18:43:00.920 [ERR] CRTR: Channel update of ourselves received
Feb 08 18:43:00 ip-10-2-1-81 lnd[4074]: 2020-02-08 18:43:00.921 [WRN] CRTR: Routing failure for local channel 675143020513591296 occurred
Feb 08 18:43:00 ip-10-2-1-81 lnd[4074]: 2020-02-08 18:43:00.961 [WRN] HSWC: ChannelLink(614039:1612:0): unable to handle downstream add HTLC: commitment transaction dips peer below chan reserve
Feb 08 18:43:00 ip-10-2-1-81 lnd[4074]: 2020-02-08 18:43:00.972 [ERR] CRTR: Attempt to send payment 4165cdf619d75f944f0afe651730eb6296c75c8f6f29b5984301cf4b92925fa1 failed: TemporaryChannelFailure(update=(*lnwire.ChannelUpdate)(0xc0036e4370)({
Feb 08 18:43:00 ip-10-2-1-81 lnd[4074]:  Signature: (lnwire.Sig) (len=64 cap=64) {
Feb 08 18:43:00 ip-10-2-1-81 lnd[4074]:   00000000  57 6c 42 56 a6 a5 52 4d  34 53 dd ef c3 9a 54 89  |WlBV..RM4S....T.|
Feb 08 18:43:00 ip-10-2-1-81 lnd[4074]:   00000010  78 f5 15 f7 d0 7e 43 9b  1f ab 5f 7b 90 13 29 56  |x....~C..._{..)V|
Feb 08 18:43:00 ip-10-2-1-81 lnd[4074]:   00000020  3a d6 46 0a 52 82 ef bd  77 f1 2a 19 8d 55 fd 62  |:.F.R...w.*..U.b|
Feb 08 18:43:00 ip-10-2-1-81 lnd[4074]:   00000030  87 5c d7 47 78 7b f3 82  f8 99 2e e5 24 a5 01 4c  |.\.Gx{......$..L|
Feb 08 18:43:00 ip-10-2-1-81 lnd[4074]:  },
Feb 08 18:43:00 ip-10-2-1-81 lnd[4074]:  ChainHash: (chainhash.Hash) (len=32 cap=32) 000000000019d6689c085ae165831e934ff763ae46a2a6c172b3f1b60a8ce26f,
Feb 08 18:43:00 ip-10-2-1-81 lnd[4074]:  ShortChannelID: (lnwire.ShortChannelID) 614039:1612:0,
Feb 08 18:43:00 ip-10-2-1-81 lnd[4074]:  Timestamp: (uint32) 1581103023,
Feb 08 18:43:00 ip-10-2-1-81 lnd[4074]:  MessageFlags: (lnwire.ChanUpdateMsgFlags) 00000001,
Feb 08 18:43:00 ip-10-2-1-81 lnd[4074]:  ChannelFlags: (lnwire.ChanUpdateChanFlags) 00000000,
Feb 08 18:43:00 ip-10-2-1-81 lnd[4074]:  TimeLockDelta: (uint16) 40,
Feb 08 18:43:00 ip-10-2-1-81 lnd[4074]:  HtlcMinimumMsat: (lnwire.MilliSatoshi) 1000 mSAT,
Feb 08 18:43:00 ip-10-2-1-81 lnd[4074]:  BaseFee: (uint32) 1000,
Feb 08 18:43:00 ip-10-2-1-81 lnd[4074]:  FeeRate: (uint32) 1,
Feb 08 18:43:00 ip-10-2-1-81 lnd[4074]:  HtlcMaximumMsat: (lnwire.MilliSatoshi) 3300000000 mSAT,
Feb 08 18:43:00 ip-10-2-1-81 lnd[4074]:  ExtraOpaqueData: ([]uint8) <nil>
Feb 08 18:43:00 ip-10-2-1-81 lnd[4074]: })
Feb 08 18:43:00 ip-10-2-1-81 lnd[4074]: )

As far as I can tell, PaymentControl considers these payments to be in flight. I'm not sure whether there's a stuck HTLC somewhere or if LND gave up on the payment but failed to mark it as such.

Digging around the code for a bit, I think that the method interpretedResults.processPaymentOutcomeSelf is ignoring this error type and producing an empty interpretedResults structs. This then triggers a reattempt and MC/router produce exactly the same route again. What I can't figure out is why it seems to have stopped attempting the payment, I would expect it to retry forever given the current state.

Your environment

• version v0.9.0-beta
• Linux ip-10-2-1-81 4.15.0-1057-aws Update commitment transaction design to support blinded outsourcing #59-Ubuntu SMP Wed Dec 4 10:02:00 UTC 2019 x86_64 x86_64 x86_64 GNU/Linux
• bitcoind v0.18.1

[halseth]

Could you be running into #3787?

[champo]

Yes! Sorry for the dup.