Excessive fees for automatically forced closed channel

[ericpp]

While I was busy celebrating New Years Weekend, my node decided to waste 206,967 sats to force close a 500k sat channel.

Looking at the logs, it seems that there was some connectivity issues between my node and the remote node:

lnd_1        | 2023-12-29 22:23:21.232 [INF] DISC: GossipSyncer(028eb5be336f7fdf2a4e40c57ff55d3d5d71277bb4197ea14957f756bff249e623): applying gossipFilter(start=2023-12-29 22:23:21.232926063 +0000 UTC m=+700403.774882883, end=2160-02-05 04:51:36.232926063 +0000 UTC)
lnd_1        | 2023-12-29 22:23:21.237 [INF] HSWC: ChannelLink(4569e357c3bf31822248076d99027213f3108924973b109c7d1ff7b4ea85b945:1): exited
lnd_1        | 2023-12-29 22:23:21.238 [INF] HSWC: Removing channel link with ChannelID(45b985eab4f71f7d9c103b97248910f3137202996d0748228231bfc357e36944)
lnd_1        | 2023-12-29 22:23:37.211 [INF] SRVR: Established connection to: 02453e4e93322d60219808c00c2e6d1f1c673420e95b5511a33c40cfb4df5e9148@w2jsq47qcysiwqaxjsrofsrglnx2mcmypvukbmnisy6wufi22uaw2dqd.onion:9735
lnd_1        | 2023-12-29 22:23:37.216 [INF] SRVR: Finalizing connection to 02453e4e93322d60219808c00c2e6d1f1c673420e95b5511a33c40cfb4df5e9148@w2jsq47qcysiwqaxjsrofsrglnx2mcmypvukbmnisy6wufi22uaw2dqd.onion:9735, inbound=false
lnd_1        | 2023-12-29 22:23:38.112 [INF] PEER: Peer(02453e4e93322d60219808c00c2e6d1f1c673420e95b5511a33c40cfb4df5e9148): disconnecting 02453e4e93322d60219808c00c2e6d1f1c673420e95b5511a33c40cfb4df5e9148@w2jsq47qcysiwqaxjsrofsrglnx2mcmypvukbmnisy6wufi22uaw2dqd.onion:9735, reason: unable to start peer: unable to read init msg: read next header: EOF
lnd_1        | 2023-12-29 22:23:42.445 [INF] SRVR: New inbound connection from 10.21.21.11:37304
lnd_1        | 2023-12-29 22:23:42.445 [INF] SRVR: Finalizing connection to 02453e4e93322d60219808c00c2e6d1f1c673420e95b5511a33c40cfb4df5e9148@10.21.21.11:37304, inbound=true
lnd_1        | 2023-12-29 22:23:42.675 [INF] PEER: Peer(02453e4e93322d60219808c00c2e6d1f1c673420e95b5511a33c40cfb4df5e9148): Loading ChannelPoint(4569e357c3bf31822248076d99027213f3108924973b109c7d1ff7b4ea85b945:1), isPending=false
lnd_1        | 2023-12-29 22:23:42.678 [INF] HSWC: ChannelLink(4569e357c3bf31822248076d99027213f3108924973b109c7d1ff7b4ea85b945:1): starting
lnd_1        | 2023-12-29 22:23:42.678 [INF] HSWC: Trimming open circuits for chan_id=811425:1252:1, start_htlc_id=31945
lnd_1        | 2023-12-29 22:23:42.682 [INF] CNCT: Attempting to update ContractSignals for ChannelPoint(4569e357c3bf31822248076d99027213f3108924973b109c7d1ff7b4ea85b945:1)
lnd_1        | 2023-12-29 22:23:42.682 [INF] HSWC: ChannelLink(4569e357c3bf31822248076d99027213f3108924973b109c7d1ff7b4ea85b945:1): HTLC manager started, bandwidth=201278139 mSAT
lnd_1        | 2023-12-29 22:23:42.682 [INF] HSWC: Adding live link chan_id=45b985eab4f71f7d9c103b97248910f3137202996d0748228231bfc357e36944, short_chan_id=811425:1252:1
lnd_1        | 2023-12-29 22:23:42.685 [INF] NTFN: New block epoch subscription
lnd_1        | 2023-12-29 22:23:42.683 [INF] PEER: Peer(02453e4e93322d60219808c00c2e6d1f1c673420e95b5511a33c40cfb4df5e9148): Negotiated chan series queries
lnd_1        | 2023-12-29 22:23:42.688 [INF] DISC: Creating new GossipSyncer for peer=02453e4e93322d60219808c00c2e6d1f1c673420e95b5511a33c40cfb4df5e9148
lnd_1        | 2023-12-29 22:23:42.683 [INF] HSWC: ChannelLink(4569e357c3bf31822248076d99027213f3108924973b109c7d1ff7b4ea85b945:1): Attempting to re-synchronize channel: SCID=811425:1252:1, status=ChanStatusDefault, initiator=true, pending=false, local commitment has height=83794, local_htlc_index=31945, local_log_index=42352, remote_htlc_index=10065, remote_log_index=42009, remote commitment has height=83991, local_htlc_index=31945, local_log_index=42352, remote_htlc_index=10065, remote_log_index=42009
lnd_1        | 2023-12-29 22:23:43.326 [INF] HSWC: ChannelLink(4569e357c3bf31822248076d99027213f3108924973b109c7d1ff7b4ea85b945:1): received re-establishment message from remote side

Eventually an htlc hit a timeout and attempted to force close the channel with a 29,615 sat fee:

lnd_1        | 2023-12-30 12:00:03.366 [INF] NTFN: New block: height=823549, sha=000000000000000000030dd366e1b989588c5f083f7a5dcbb768c1856723d9ab
lnd_1        | 2023-12-30 12:00:03.367 [INF] UTXN: Attempting to graduate height=823549: num_kids=0, num_babies=0
lnd_1        | 2023-12-30 12:00:03.368 [INF] CNCT: ChannelArbitrator(4569e357c3bf31822248076d99027213f3108924973b109c7d1ff7b4ea85b945:1): go to chain for outgoing htlc 1ada492ac922ba12c540c4954774aaff626e984a58ad44b475a56db2fa73fff3: timeout=823549, blocks_until_expiry=0, broadcast_delta=0
lnd_1        | 2023-12-30 12:00:03.373 [INF] SWPR: Sweep candidates at height=823549 with fee_rate=40917 sat/kw, yield 0 distinct txns
lnd_1        | 2023-12-30 12:00:03.381 [INF] HSWC: Garbage collected 8 shared secret hashes at height=823549
lnd_1        | 2023-12-30 12:00:03.382 [INF] CNCT: ChannelArbitrator(4569e357c3bf31822248076d99027213f3108924973b109c7d1ff7b4ea85b945:1): force closing chan
lnd_1        | 2023-12-30 12:00:03.387 [INF] HSWC: ChannelLink(4569e357c3bf31822248076d99027213f3108924973b109c7d1ff7b4ea85b945:1): stopping
lnd_1        | 2023-12-30 12:00:03.392 [INF] HSWC: ChannelLink(4569e357c3bf31822248076d99027213f3108924973b109c7d1ff7b4ea85b945:1): exited
lnd_1        | 2023-12-30 12:00:03.392 [INF] HSWC: Removing channel link with ChannelID(45b985eab4f71f7d9c103b97248910f3137202996d0748228231bfc357e36944)
lnd_1        | 2023-12-30 12:00:03.450 [INF] CNCT: Broadcasting force close transaction 58092aa251fac750f1a8cd023df49aac6e9c6b182ea7dc4027c615befb84e42e, ChannelPoint(4569e357c3bf31822248076d99027213f3108924973b109c7d1ff7b4ea85b945:1): (*wire.MsgTx)(0x4003925a80)({
lnd_1        |  Version: (int32) 2,
lnd_1        |  TxIn: ([]*wire.TxIn) (len=1 cap=1) {
lnd_1        |   (*wire.TxIn)(0x40069744e0)({
lnd_1        |    PreviousOutPoint: (wire.OutPoint) 4569e357c3bf31822248076d99027213f3108924973b109c7d1ff7b4ea85b945:1,
lnd_1        |    SignatureScript: ([]uint8) <nil>,
lnd_1        |    Witness: (wire.TxWitness) (len=4 cap=4) {
lnd_1        |     ([]uint8) <nil>,
lnd_1        |     ([]uint8) (len=71 cap=144) {
lnd_1        |      00000000  30 44 02 20 0d f8 f2 9a  e9 a5 be 27 8d 4b e4 06  |0D. .......'.K..|
lnd_1        |      00000010  27 3a f6 d2 13 0b 75 65  f9 75 04 38 c4 eb c5 9c  |':....ue.u.8....|
lnd_1        |      00000020  e7 36 a7 b0 02 20 61 19  43 74 a1 e3 8f 94 2b 90  |.6... a.Ct....+.|
lnd_1        |      00000030  a2 c9 b6 a9 70 49 3b d2  db 9c 0e 3a 6c c0 69 d2  |....pI;....:l.i.|
lnd_1        |      00000040  5e 3f 48 3e 70 49 01                              |^?H>pI.|
lnd_1        |     },
lnd_1        |     ([]uint8) (len=71 cap=144) {
lnd_1        |      00000000  30 44 02 20 54 35 6e 6a  3d 6b db 75 76 86 e8 3f  |0D. T5nj=k.uv..?|
lnd_1        |      00000010  1c fb 86 d9 2c ce ac c6  95 3e 8e e3 f4 8e 6c 0d  |....,....>....l.|
lnd_1        |      00000020  cd 84 b3 5b 02 20 43 08  9c 96 bb 03 0e 80 79 a9  |...[. C.......y.|
lnd_1        |      00000030  23 76 d1 ef fb 3b fe 83  14 aa 59 01 ca 07 27 ac  |#v...;....Y...'.|
lnd_1        |      00000040  c1 f2 49 e8 2b bd 01                              |..I.+..|
lnd_1        |     },
lnd_1        |     ([]uint8) (len=71 cap=71) {
lnd_1        |      00000000  52 21 02 49 90 56 8a a7  a8 5e 74 77 64 fc ab 69  |R!.I.V...^twd..i|
lnd_1        |      00000010  f5 1e 97 f6 39 5a 5b b6  4e cd b3 3e ee c4 b8 3f  |....9Z[.N..>...?|
lnd_1        |      00000020  71 80 0a 21 03 99 25 e9  eb 6f 2c 17 82 0e 9b 20  |q..!..%..o,.... |
lnd_1        |      00000030  3f e1 0c 5e 3c 95 d1 f8  f1 90 44 5a 21 de df 8a  |?..^<.....DZ!...|
lnd_1        |      00000040  a2 a9 e4 e0 c0 52 ae                              |.....R.|
lnd_1        |     }
lnd_1        |    },
lnd_1        |    Sequence: (uint32) 2159611673
lnd_1        |   })
lnd_1        |  },
lnd_1        |  TxOut: ([]*wire.TxOut) (len=5 cap=5) {
lnd_1        |   (*wire.TxOut)(0x4003b67000)({
lnd_1        |    Value: (int64) 330,
lnd_1        |    PkScript: ([]uint8) (len=34 cap=34) {
lnd_1        |     00000000  00 20 bb e0 8d b0 2f 97  17 93 e9 01 02 86 82 25  |. ..../........%|
lnd_1        |     00000010  4d bb 04 60 ba ed 1d c7  99 ec a1 7a ba 65 e4 15  |M..`.......z.e..|
lnd_1        |     00000020  61 e6                                             |a.|
lnd_1        |    }
lnd_1        |   }),
lnd_1        |   (*wire.TxOut)(0x4003b67040)({
lnd_1        |    Value: (int64) 330,
lnd_1        |    PkScript: ([]uint8) (len=34 cap=34) {
lnd_1        |     00000000  00 20 d7 a8 c8 51 b1 8a  62 93 7e 29 66 07 f4 06  |. ...Q..b.~)f...|
lnd_1        |     00000010  bb f6 61 48 d6 84 d3 d6  19 09 a7 28 f6 c5 9d e3  |..aH.......(....|
lnd_1        |     00000020  7c 71                                             ||q|
lnd_1        |    }
lnd_1        |   }),
lnd_1        |   (*wire.TxOut)(0x4003b670c0)({
lnd_1        |    Value: (int64) 8549,
lnd_1        |    PkScript: ([]uint8) (len=34 cap=34) {
lnd_1        |     00000000  00 20 93 c5 88 93 e4 3b  6f 2c 88 59 d6 8d 4d 9b  |. .....;o,.Y..M.|
lnd_1        |     00000010  ec 78 1b d2 43 f7 d9 40  46 6b c2 94 ad 49 86 24  |[email protected].$|
lnd_1        |     00000020  67 0a                                             |g.|
lnd_1        |    }
lnd_1        |   }),
lnd_1        |   (*wire.TxOut)(0x4003b67100)({
lnd_1        |    Value: (int64) 210193,
lnd_1        |    PkScript: ([]uint8) (len=34 cap=34) {
lnd_1        |     00000000  00 20 50 06 0e c4 f0 9f  0e f7 9a 66 7c a0 00 d1  |. P........f|...|
lnd_1        |     00000010  c4 67 f0 5c fa d6 a2 46  14 e5 30 0c aa ce 3b e8  |.g.\...F..0...;.|
lnd_1        |     00000020  73 8c                                             |s.|
lnd_1        |    }
lnd_1        |   }),
lnd_1        |   (*wire.TxOut)(0x4003b67120)({
lnd_1        |    Value: (int64) 250983,
lnd_1        |    PkScript: ([]uint8) (len=34 cap=34) {
lnd_1        |     00000000  00 20 c5 bd 62 f0 9e 31  9c 00 a9 46 bd d2 40 b4  |. ..b..1...F..@.|
lnd_1        |     00000010  02 f2 b8 7a b9 39 55 ea  05 c0 26 96 92 19 5f 92  |...z.9U...&..._.|
lnd_1        |     00000020  95 a5                                             |..|
lnd_1        |    }
lnd_1        |   })
lnd_1        |  },
lnd_1        |  LockTime: (uint32) 539711087
lnd_1        | })
lnd_1        |
lnd_1        | 2023-12-30 12:00:03.590 [INF] LNWL: Inserting unconfirmed transaction 58092aa251fac750f1a8cd023df49aac6e9c6b182ea7dc4027c615befb84e42e
lnd_1        | 2023-12-30 12:00:03.615 [INF] NTFN: New confirmation subscription: conf_id=2, txid=58092aa251fac750f1a8cd023df49aac6e9c6b182ea7dc4027c615befb84e42e, num_confs=6 height_hint=823549
lnd_1        | 2023-12-30 12:00:03.646 [WRN] CNCT: ChannelArbitrator(4569e357c3bf31822248076d99027213f3108924973b109c7d1ff7b4ea85b945:1): deadline is passed with deadlineMinHeight=823549, heightHint=823549
lnd_1        | 2023-12-30 12:00:03.653 [INF] SWPR: Sweep request received: out_point=f2ab6d558420314c90ea8d8afb88ce7ba33b47ffee5425af61d5640ab1477dc7:1, witness_type=CommitmentAnchor, relative_time_lock=0, absolute_time_lock=0, amount=0.00000330 BTC, parent=(fee=0.00029615 BTC, weight=1288), params=(fee=1 blocks, force=true, exclusive_group=892171222650191873)
lnd_1        | 2023-12-30 12:00:03.656 [WRN] CNCT: ChannelArbitrator(4569e357c3bf31822248076d99027213f3108924973b109c7d1ff7b4ea85b945:1): deadline is passed with deadlineMinHeight=823549, heightHint=823549
lnd_1        | 2023-12-30 12:00:03.656 [INF] NTFN: New spend subscription: spend_id=8, outpoint=f2ab6d558420314c90ea8d8afb88ce7ba33b47ffee5425af61d5640ab1477dc7:1, script=0 d7a8c851b18a62937e296607f406bbf66148d684d3d61909a728f6c59de37c71, height_hint=823549
lnd_1        | 2023-12-30 12:00:03.659 [INF] NTFN: Dispatching historical spend rescan for outpoint=f2ab6d558420314c90ea8d8afb88ce7ba33b47ffee5425af61d5640ab1477dc7:1, script=0 d7a8c851b18a62937e296607f406bbf66148d684d3d61909a728f6c59de37c71, start=823549, end=823549
lnd_1        | 2023-12-30 12:00:03.662 [INF] SWPR: Sweep request received: out_point=58092aa251fac750f1a8cd023df49aac6e9c6b182ea7dc4027c615befb84e42e:1, witness_type=CommitmentAnchor, relative_time_lock=0, absolute_time_lock=0, amount=0.00000330 BTC, parent=(fee=0.00029615 BTC, weight=1288), params=(fee=1 blocks, force=true, exclusive_group=892171222650191873)
lnd_1        | 2023-12-30 12:00:03.750 [INF] NTFN: Historical spend dispatch finished for request outpoint=f2ab6d558420314c90ea8d8afb88ce7ba33b47ffee5425af61d5640ab1477dc7:1, script=0 d7a8c851b18a62937e296607f406bbf66148d684d3d61909a728f6c59de37c71 (start=823549 end=823549) with details: <nil>
lnd_1        | 2023-12-30 12:00:03.762 [INF] SWPR: Candidate sweep set of size=1 (+3 wallet inputs), has yield=-0.00202126 BTC, weight=1181
lnd_1        | 2023-12-30 12:00:03.762 [INF] SWPR: Sweep candidates at height=823549 with fee_rate=93994 sat/kw, yield 1 distinct txns
lnd_1        | 2023-12-30 12:00:03.762 [INF] CNCT: ChannelArbitrator(4569e357c3bf31822248076d99027213f3108924973b109c7d1ff7b4ea85b945:1): trigger chainTrigger moving from state StateCommitmentBroadcasted to StateCommitmentBroadcasted
lnd_1        | 2023-12-30 12:00:03.764 [INF] NTFN: New spend subscription: spend_id=9, outpoint=58092aa251fac750f1a8cd023df49aac6e9c6b182ea7dc4027c615befb84e42e:1, script=0 d7a8c851b18a62937e296607f406bbf66148d684d3d61909a728f6c59de37c71, height_hint=823549
lnd_1        | 2023-12-30 12:00:03.764 [INF] NTFN: Dispatching historical spend rescan for outpoint=58092aa251fac750f1a8cd023df49aac6e9c6b182ea7dc4027c615befb84e42e:1, script=0 d7a8c851b18a62937e296607f406bbf66148d684d3d61909a728f6c59de37c71, start=823549, end=823549

Then ONLY 30 seconds later, it creates a sweep transaction that uses CPFP to bump the fee to 206,967 sats:

lnd_1        | 2023-12-30 12:00:33.777 [INF] SWPR: Candidate sweep set of size=1 (+3 wallet inputs), has yield=-0.00202126 BTC, weight=1181
lnd_1        | 2023-12-30 12:00:33.808 [INF] SWPR: Creating sweep transaction 44a4eed7c97c8ef44c637cd0833f3fa91e0b738bace8793212968670a210ebaa for 4 inputs (58092aa251fac750f1a8cd023df49aac6e9c6b182ea7dc4027c615befb84e42e:1 (CommitmentAnchor), fe7ce5611d5baff2022fe68de51d05563a77474bcc3b31b8dc54d185286dd020:0 (TaprootPubKeySpend), 6d5b9a42a8849b46b3dcf87bd21778b513cca89a156b85ae68bf701ed33ee73a:0 (TaprootPubKeySpend), 16eaa02fe401af112c98c22fcbe4485f1bdaff511dc83649f5b471964a69bce3:147 (WitnessKeyHash)) using 93994 sat/kw, tx_weight=1229, tx_fee=0.00206967 BTC, parents_count=1, parents_fee=0.00029615 BTC, parents_weight=1288
lnd_1        | 2023-12-30 12:00:33.828 [INF] LNWL: Inserting unconfirmed transaction 44a4eed7c97c8ef44c637cd0833f3fa91e0b738bace8793212968670a210ebaa
lnd_1        | 2023-12-30 12:00:33.852 [INF] SWPR: Candidate sweep set of size=1 (+1 wallet inputs), has yield=-0.00158700 BTC, weight=719
lnd_1        | 2023-12-30 12:00:33.856 [INF] NTFN: New confirmation subscription: conf_id=3, txid=44a4eed7c97c8ef44c637cd0833f3fa91e0b738bace8793212968670a210ebaa, num_confs=6 height_hint=823549

It also tries to waste 163,542 more sats on another transaction that seems to fail:

lnd_1        | 2023-12-30 12:00:33.873 [INF] SWPR: Creating sweep transaction 0906c0dd7c51e42c06250f986febdda3ff5f8e4a55655745c6fda9612878c5b0 for 2 inputs (f2ab6d558420314c90ea8d8afb88ce7ba33b47ffee5425af61d5640ab1477dc7:1 (CommitmentAnchor), 0e14a569d9d255a722f33096773d88ed46c61c50bfc528a851f2f8708feed7c0:18 (WitnessKeyHash)) using 93994 sat/kw, tx_weight=767, tx_fee=0.00163542 BTC, parents_count=1, parents_fee=0.00029615 BTC, parents_weight=1288
lnd_1        | 2023-12-30 12:00:33.892 [ERR] BTCN: Broadcast attempt failed: double spend: -25: bad-txns-inputs-missingorspent
lnd_1        | 2023-12-30 12:00:33.893 [INF] LNWL: Inserting unconfirmed transaction 0906c0dd7c51e42c06250f986febdda3ff5f8e4a55655745c6fda9612878c5b0
lnd_1        | 2023-12-30 12:00:33.899 [INF] LNWL: 0906c0dd7c51e42c06250f986febdda3ff5f8e4a55655745c6fda9612878c5b0: broadcast failed because of: double spend: -25: bad-txns-inputs-missingorspent
lnd_1        | 2023-12-30 12:00:33.901 [INF] LNWL: Removed invalid transaction: (*wire.MsgTx)(0x40039c1100)({
lnd_1        |  Version: (int32) 2,
lnd_1        |  TxIn: ([]*wire.TxIn) (len=2 cap=15) {
lnd_1        |   (*wire.TxIn)(0x4009c48900)({
lnd_1        |    PreviousOutPoint: (wire.OutPoint) f2ab6d558420314c90ea8d8afb88ce7ba33b47ffee5425af61d5640ab1477dc7:1,
lnd_1        |    SignatureScript: ([]uint8) <nil>,
lnd_1        |    Witness: (wire.TxWitness) (len=2 cap=2) {
lnd_1        |     ([]uint8) (len=71 cap=144) {
lnd_1        |      00000000  30 44 02 20 71 0d 0e 53  08 e2 23 8a 31 79 a5 a8  |0D. q..S..#.1y..|
lnd_1        |      00000010  1c 6c f5 13 61 5e 26 51  74 48 54 0a 24 b1 dc e3  |.l..a^&QtHT.$...|
lnd_1        |      00000020  9e c3 f5 84 02 20 72 35  8a 90 4c 93 cd c2 1a 58  |..... r5..L....X|
lnd_1        |      00000030  8a c1 de 67 09 91 d4 9a  85 67 43 c5 af 34 15 4a  |...g.....gC..4.J|
lnd_1        |      00000040  95 4c 34 4b b8 ea 01                              |.L4K...|
lnd_1        |     },
lnd_1        |     ([]uint8) (len=40 cap=40) {
lnd_1        |      00000000  21 02 49 90 56 8a a7 a8  5e 74 77 64 fc ab 69 f5  |!.I.V...^twd..i.|
lnd_1        |      00000010  1e 97 f6 39 5a 5b b6 4e  cd b3 3e ee c4 b8 3f 71  |...9Z[.N..>...?q|
lnd_1        |      00000020  80 0a ac 73 64 60 b2 68                           |...sd`.h|
lnd_1        |     }
lnd_1        |    },
lnd_1        |    Sequence: (uint32) 0
lnd_1        |   }),
lnd_1        |   (*wire.TxIn)(0x4009c48960)({
lnd_1        |    PreviousOutPoint: (wire.OutPoint) 0e14a569d9d255a722f33096773d88ed46c61c50bfc528a851f2f8708feed7c0:18,
lnd_1        |    SignatureScript: ([]uint8) <nil>,
lnd_1        |    Witness: (wire.TxWitness) (len=2 cap=2) {
lnd_1        |     ([]uint8) (len=72 cap=144) {
lnd_1        |      00000000  30 45 02 21 00 ea 9e 16  92 74 c5 62 81 a4 d4 2f  |0E.!.....t.b.../|
lnd_1        |      00000010  4e 2e 91 1b 52 b6 22 98  02 7a 88 67 9d 31 23 f3  |N...R."..z.g.1#.|
lnd_1        |      00000020  63 36 2e 8a 47 02 20 0f  eb c3 83 0f be 38 af 61  |c6..G. ......8.a|
lnd_1        |      00000030  db 51 4e 56 07 62 ab e8  49 08 dd fe 64 74 e8 c1  |.QNV.b..I...dt..|
lnd_1        |      00000040  67 6b 81 68 94 46 c3 01                           |gk.h.F..|
lnd_1        |     },
lnd_1        |     ([]uint8) (len=33 cap=33) {
lnd_1        |      00000000  02 d2 4a e9 10 78 05 c6  6a fe aa 9b e8 4d 47 8d  |..J..x..j....MG.|
lnd_1        |      00000010  3e 15 76 69 db 1c 62 bb  44 21 39 76 66 12 50 b2  |>.vi..b.D!9vf.P.|
lnd_1        |      00000020  fb                                                |.|
lnd_1        |     }
lnd_1        |    },
lnd_1        |    Sequence: (uint32) 0
lnd_1        |   })
lnd_1        |  },
lnd_1        |  TxOut: ([]*wire.TxOut) (len=1 cap=15) {
lnd_1        |   (*wire.TxOut)(0x400f531060)({
lnd_1        |    Value: (int64) 56729,
lnd_1        |    PkScript: ([]uint8) (len=34 cap=500) {
lnd_1        |     00000000  51 20 6d 90 4f 2b bf 23  86 c3 a0 9c 89 1d b8 ed  |Q m.O+.#........|
lnd_1        |     00000010  ad 92 28 1b 19 14 60 04  fd fd a2 fb e9 02 6c 30  |..(...`.......l0|
lnd_1        |     00000020  40 23                                             |@#|
lnd_1        |    }
lnd_1        |   })
lnd_1        |  },
lnd_1        |  LockTime: (uint32) 823549
lnd_1        | })
lnd_1        |
lnd_1        | 2023-12-30 12:00:33.901 [INF] LNWL: Removed invalid transaction: 02000000000102c77d47b10a64d561af2554eeff473ba37bce88fb8a8dea904c312084556dabf2010000000000000000c0d7ee8f70f8f251a828c5bf501cc646ed883d779630f322a755d2d969a5140e1200000000000000000199dd0000000000002251206d904f2bbf2386c3a09c891db8edad92281b19146004fdfda2fbe9026c304023024730440220710d0e5308e2238a3179a5a81c6cf513615e26517448540a24b1dce39ec3f584022072358a904c93cdc21a588ac1de670991d49a856743c5af34154a954c344bb8ea012821024990568aa7a85e747764fcab69f51e97f6395a5bb64ecdb33eeec4b83f71800aac736460b26802483045022100ea9e169274c56281a4d42f4e2e911b52b62298027a88679d3123f363362e8a4702200febc3830fbe38af61db514e560762abe84908ddfe6474e8c1676b81689446c3012102d24ae9107805c66afeaa9be84d478d3e157669db1c62bb44213976661250b2fbfd900c00
lnd_1        | 2023-12-30 12:00:33.903 [ERR] SWPR: Publish sweep tx 0906c0dd7c51e42c06250f986febdda3ff5f8e4a55655745c6fda9612878c5b0 got error: transaction rejected: output already spent

The transaction was accepted on the blockchain, but my node still refuses to acknowledge it. It also refuses to acknowledge the force close that it did during Thanksgiving that I had to manually bump (2351706de72637b19f80c6c5eefe764e84c39f560fbace7d08a96c7f53cf26a5).

lncli pendingchannels
{
    "total_limbo_balance":  "15601",
    "pending_open_channels":  [],
    "pending_closing_channels":  [],
    "pending_force_closing_channels":  [
        {
            "channel":  {
                "remote_node_pub":  "02453e4e93322d60219808c00c2e6d1f1c673420e95b5511a33c40cfb4df5e9148",
                "channel_point":  "4569e357c3bf31822248076d99027213f3108924973b109c7d1ff7b4ea85b945:1",
                "capacity":  "500000",
                "local_balance":  "210193",
                "remote_balance":  "250983",
                "local_chan_reserve_sat":  "0",
                "remote_chan_reserve_sat":  "0",
                "initiator":  "INITIATOR_LOCAL",
                "commitment_type":  "ANCHORS",
                "num_forwarding_packages":  "0",
                "chan_status_flags":  "",
                "private":  false,
                "memo":  ""
            },
            "closing_txid":  "58092aa251fac750f1a8cd023df49aac6e9c6b182ea7dc4027c615befb84e42e",
            "limbo_balance":  "8549",
            "maturity_height":  0,
            "blocks_til_maturity":  0,
            "recovered_balance":  "330",
            "pending_htlcs":  [
                {
                    "incoming":  false,
                    "amount":  "8549",
                    "outpoint":  "e8f801f816355a260ca0d06fd5de3e41e3ebb980e9b28b2b217507e25c8f5f0c:0",
                    "maturity_height":  823729,
                    "blocks_til_maturity":  -240,
                    "stage":  2
                }
            ],
            "anchor":  "RECOVERED"
        },
        {
            "channel":  {
                "remote_node_pub":  "0237ea4cc4842e73d048bff2520159f9cb3d6d602859aa07e908594dc4b3939af1",
                "channel_point":  "cfceb173e485e950afede71fcaaf62b0ac5a5971005b32fbb21e900cd17a329f:1",
                "capacity":  "700000",
                "local_balance":  "7052",
                "remote_balance":  "691623",
                "local_chan_reserve_sat":  "0",
                "remote_chan_reserve_sat":  "0",
                "initiator":  "INITIATOR_LOCAL",
                "commitment_type":  "ANCHORS",
                "num_forwarding_packages":  "0",
                "chan_status_flags":  "",
                "private":  false,
                "memo":  ""
            },
            "closing_txid":  "2351706de72637b19f80c6c5eefe764e84c39f560fbace7d08a96c7f53cf26a5",
            "limbo_balance":  "7052",
            "maturity_height":  821533,
            "blocks_til_maturity":  -2436,
            "recovered_balance":  "330",
            "pending_htlcs":  [],
            "anchor":  "RECOVERED"
        }
    ],
    "waiting_close_channels":  []
}

During the Thanksgiving auto force close, it tried to create a transaction with a small fee that wasn't being accepted and I had to manually bump it to 100 sats/vB. After that happened, I adjusted max-commit-fee-rate-anchors from 10 to 100 as advised by https://www.lightningnode.info/technicals/highonchainfees . Would that have caused the high fee estimate that happened this time? If so, why was the final fee set to 676 sats/vB which is much larger than that 100 sats/vB setting?

How do I make it use a reasonable fee when force closing a channel? How do I get it to acknowledge these force closed channels? I tried to use --reset-wallet-transactions multiple times to clear the Thanksgiving one to no avail. I plan to try it again with this one, but I'm not hopeful.

[yyforyongyu]

Looking at the logs, it seems that there was some connectivity issues between my node and the remote node

Since this is the root cause, do you know why it happened?

Then ONLY 30 seconds later, it creates a sweep transaction that uses CPFP to bump the fee to 206,967 sats:

It had to because the outgoing htlc had expired. However it's bad that it doesn't take economical actions, which should be fixed once #1226 is properly handled.

It also tries to waste 163,542 more sats on another transaction that seems to fail:

This is an anchor sweeping transaction created using the remote commitment. This is required in case your peer is also force closing.

The transaction was accepted on the blockchain, but my node still refuses to acknowledge it.

After the FC transaction being confirmed, you still need to wait a few more blocks to unlock your to_local balance, which is locked inside a CSV. It won't be considered as finalized unless all outputs are swept back to your wallet.

I adjusted max-commit-fee-rate-anchors from 10 to 100

This config is used to set the FC fee rate. After that, based on the timelocks in HTLCs, there will be a CPFP attempt if the timelock has expired.

How do I make it use a reasonable fee when force closing a channel?

Aside from #1226, there's --sweeper.maxfeerate which you can use to cap the fee rate being used when sweeping the outputs from a FC.

[ericpp]

Thanks for helping me out with this. Much appreciated!

Since this is the root cause, do you know why it happened?

Both nodes are tor-only nodes and it's possible that something happened with the tor connection. However, I didn't see any issues in the tor logs on my end.

Do you know how to make it sweep the outputs of my FC transactions? The one from Thanksgiving was confirmed on Dec 15th but is still listed in pending_force_closing_channels. Blocks until maturity was reached awhile ago for that one ( blocks_til_maturity=-2436)

The other FC seems stuck at 0 for blocks_til_maturity and a negative number for the expired htlc.

[yyforyongyu]

Based on this link, it looks like one of the anchor output has already been swept by someone else and is still pending. That might be the reason? There are a few commands you can use under lncli wallet to interact with the sweeper, maybe you could do a lncli wallet pendingsweeps and see if there are any transactions pending?

[ericpp]

Here's my pendingsweeps:

$ lncli wallet pendingsweeps
{
        "pending_sweeps": [
                {
                        "outpoint": "ccaab0cd4d6670a902cab150833e3a091d99e91789150df957fccff640ec154b:0",
                        "witness_type": "HTLC_OFFERED_TIMEOUT_SECOND_LEVEL",
                        "amount_sat": 8549,
                        "sat_per_vbyte": 242,
                        "broadcast_attempts": 0,
                        "next_broadcast_height": 823933,
                        "requested_sat_per_vbyte": 0,
                        "requested_conf_target": 6,
                        "force": false
                },
                {
                        "outpoint": "2351706de72637b19f80c6c5eefe764e84c39f560fbace7d08a96c7f53cf26a5:2",
                        "witness_type": "COMMITMENT_TIME_LOCK",
                        "amount_sat": 7052,
                        "sat_per_vbyte": 242,
                        "broadcast_attempts": 0,
                        "next_broadcast_height": 823933,
                        "requested_sat_per_vbyte": 0,
                        "requested_conf_target": 6,
                        "force": false
                }
        ]
}

The 2351706de transaction was confirmed after I manually bumped it with lncli wallet bumpclosefee:

https://mempool.space/tx/2351706de72637b19f80c6c5eefe764e84c39f560fbace7d08a96c7f53cf26a5
https://blockchair.com/bitcoin/transaction/2351706de72637b19f80c6c5eefe764e84c39f560fbace7d08a96c7f53cf26a5
https://blockstream.info/tx/2351706de72637b19f80c6c5eefe764e84c39f560fbace7d08a96c7f53cf26a5

Interestingly, mempool only shows :2 as unswept while blockchair shows both :0 and :2 as unswept.

[yyforyongyu]

yeah I guess it's just a small difference in the UI - blockchair seems to be more strict as it only considers it being swept if the sweeping transaction is confirmed. The closing tx 2351706de72637b19f80c6c5eefe764e84c39f560fbace7d08a96c7f53cf26a5 did confirm a while back, but the output 2351706de72637b19f80c6c5eefe764e84c39f560fbace7d08a96c7f53cf26a5:2 is not swept yet, think it's due to the current high fee environment.