[bug]: channel stuck in pending_force_closing_channels forever

[fivebyfive2]

Background

A channel has been stuck in pending_force_closing_channels for about 6 months, but the closing transaction confirmed a long time ago. The peer node has gone offline.

Your environment

lncli version 0.14.2-beta commit=v0.14.2-beta
Linux h440 6.5.0-14-generic #14~22.04.1-Ubuntu SMP PREEMPT_DYNAMIC Mon Nov 20 18:15:30 UTC 2 x86_64 x86_64 x86_64 GNU/Linux
Bitcoin Core 26.0.0
umbrelOS Version 0.5.4

Steps to reproduce

lncli pendingchannels
{
    "total_limbo_balance": "765",
    "pending_open_channels": [
    ],
    "pending_closing_channels": [
    ],
    "pending_force_closing_channels": [
        {
            "channel": {
                "remote_node_pub": "039b3cab2a452a0ec921c417009817a8ae871b2098454078dd439e5f328a1108e6",
                "channel_point": "1e00c6d1b0601d8cb6e2be3085dfabc2a95aef5959020fce42db9a5ed690e932:1",
                "capacity": "15000000",
                "local_balance": "158020",
                "remote_balance": "14837644",
                "local_chan_reserve_sat": "0",
                "remote_chan_reserve_sat": "0",
                "initiator": "INITIATOR_REMOTE",
                "commitment_type": "ANCHORS",
                "num_forwarding_packages": "0",
                "chan_status_flags": ""
            },
            "closing_txid": "1823bad5100cfda6194c587e641a5cbf518a809c9c90a50407a4c8b56f4ff91b",
            "limbo_balance": "765",
            "maturity_height": 0,
            "blocks_til_maturity": 0,
            "recovered_balance": "0",
            "pending_htlcs": [
                {
                    "incoming": false,
                    "amount": "435",
                    "outpoint": "128cfe64dca7c29a96e14c78bfed2b88cf86106f4a16103a9ac23d050c899f9b:0",
                    "maturity_height": 782626,
                    "blocks_til_maturity": -48538,
                    "stage": 1
                }
            ],
            "anchor": "LIMBO"
        }
    ],
    "waiting_close_channels": [
    ]
}

EDITED to add formatting to the json output.

[sputn1ck]

What version of LND are you running? Your lncli indicates 0.14.2 which is quite out of date. I would assume an upgrade to the latest LND could fix the problem.

[fivebyfive2]

Umbrel reports

LND 0.17.4-beta

[fivebyfive2]

The lncli client is provided by the 'Lightning Shell' Umbrel app so it is probably a dockerized client.

[hieblmi]

Hi, what's interesting is the "total_limbo_balance": "765". It is likely that around the time of the force closure, the limbo balance wasn't economical for lnd to be swept, the sweeping fees would've been higher than the actual output.
You can see that the second stage timeout transaction hasn't been swept yet: https://mempool.space/tx/ed69c574fc7027146229828c7e8b190a4a0378f9244ead9699a6eff2bf4e3edc

Could you do a favor and restart your node and provide the log file, or just relevant lines for the funding tx 1e00c6d1b0601d8cb6e2be3085dfabc2a95aef5959020fce42db9a5ed690e932:1?

[fivebyfive2]

xxx@h440:~/umbrel$ sudo docker logs f506a49f7720 > /tmp/lnd4.txt

xxx@h440:~/umbrel$ grep 1e00c6d1b0601d8cb6e2be3085dfabc2a95aef5959020fce42db9a5ed690e932 /tmp/lnd4.txt
2024-02-24 11:03:26.558 [INF] CNCT: ChannelArbitrator(1e00c6d1b0601d8cb6e2be3085dfabc2a95aef5959020fce42db9a5ed690e932:1): starting state=StateWaitingFullResolution, trigger=chainTrigger, triggerHeight=782627
2024-02-24 11:03:26.558 [INF] CNCT: ChannelArbitrator(1e00c6d1b0601d8cb6e2be3085dfabc2a95aef5959020fce42db9a5ed690e932:1): still awaiting contract resolution
2024-02-24 11:03:26.558 [INF] CNCT: ChannelArbitrator(1e00c6d1b0601d8cb6e2be3085dfabc2a95aef5959020fce42db9a5ed690e932:1): relaunching 1 contract resolvers

xxx@h440:~/umbrel$ grep ERR /tmp/lnd4.txt
2024-02-24 11:03:21.551 [ERR] RPCS: [/lnrpc.Lightning/GetInfo]: wallet locked, unlock it to enable full RPC access
2024-02-24 11:03:21.570 [ERR] RPCS: [/lnrpc.Lightning/GetInfo]: wallet locked, unlock it to enable full RPC access
2024-02-24 11:03:50.781 [ERR] PEER: Peer(03ecb39d80deaf6a934bac97ba514ef9709560e765c6408fef3ae8f9bc2c9f5854): resend failed: no chan sync message stored for channel 419950a922e6fb49dad0a4000e9bc7dddcd3adcd991091adebb820f1e1c26c07
2024-02-24 11:03:56.868 [ERR] BTCN: Broadcast attempt failed: double spend: -25: bad-txns-inputs-missingorspent
2024-02-24 11:03:56.895 [ERR] SWPR: Publish sweep tx e1e868d23dddc2f3e36b317db1235b4d11503ac6eca72977b4c7870e767dbb98 got error: transaction rejected: output already spent
2024-02-24 11:05:32.282 [ERR] SRVR: Unable to connect to 0212dfb5138fce06681efa58db32cfdb4f940b161f7385de55c236126752a7aaad@xl7les7algxqqlz473dq65f6eqbjnimof2h57xudcjcauuwqqyj5luad.onion:9735: dial proxy failed: socks connect tcp 10.21.21.11:9050->xl7les7algxqqlz473dq65f6eqbjnimof2h57xudcjcauuwqqyj5luad.onion:9735: unknown error TTL expired
2024-02-24 11:06:47.687 [ERR] BTCN: Broadcast attempt failed: double spend: -25: bad-txns-inputs-missingorspent
2024-02-24 11:06:47.693 [ERR] SWPR: Publish sweep tx b302db5b9eba03f1a7952db3500e4cb7c14f112c9dd89959e4e246758883c418 got error: transaction rejected: output already spent

[fivebyfive2]

Everything that happened in that second

grep 11:03:26 /tmp/lnd4.txt
2024-02-24 11:03:26.398 [INF] LTND: Chain backend is fully synced (end_height=831809)!
2024-02-24 11:03:26.398 [WRN] HLCK: check: disk space configured with 0 attempts, skipping it
2024-02-24 11:03:26.398 [WRN] HLCK: check: tls configured with 0 attempts, skipping it
2024-02-24 11:03:26.398 [WRN] HLCK: check: tor connection configured with 0 attempts, skipping it
2024-02-24 11:03:26.398 [INF] LNWL: SigPool starting
2024-02-24 11:03:26.491 [INF] CHNF: ChannelNotifier starting
2024-02-24 11:03:26.491 [INF] PRNF: PeerNotifier starting
2024-02-24 11:03:26.491 [INF] HSWC: HtlcNotifier starting
2024-02-24 11:03:26.491 [INF] SWPR: Sweeper starting
2024-02-24 11:03:26.491 [INF] NTFN: New block epoch subscription
2024-02-24 11:03:26.491 [INF] NTFN: New block epoch subscription
2024-02-24 11:03:26.491 [INF] BTCN: Broadcaster now active
2024-02-24 11:03:26.491 [INF] UTXN: UTXO nursery starting
2024-02-24 11:03:26.513 [INF] BRAR: Breach arbiter starting
2024-02-24 11:03:26.513 [INF] NTFN: New block epoch subscription
2024-02-24 11:03:26.522 [INF] FNDG: Funding manager starting
2024-02-24 11:03:26.522 [INF] BRAR: Starting contract observer, watching for breaches.
2024-02-24 11:03:26.522 [INF] HSWC: HTLC Switch starting
2024-02-24 11:03:26.538 [INF] NTFN: New block epoch subscription
2024-02-24 11:03:26.540 [INF] NTFN: New block epoch subscription
2024-02-24 11:03:26.540 [INF] CNCT: ChainArbitrator starting
2024-02-24 11:03:26.550 [INF] CNCT: Creating ChannelArbitrators for 1 closing channels
2024-02-24 11:03:26.558 [INF] CNCT: ChannelArbitrator(1e00c6d1b0601d8cb6e2be3085dfabc2a95aef5959020fce42db9a5ed690e932:1): starting state=StateWaitingFullResolution, trigger=chainTrigger, triggerHeight=782627
2024-02-24 11:03:26.558 [INF] CNCT: ChannelArbitrator(1e00c6d1b0601d8cb6e2be3085dfabc2a95aef5959020fce42db9a5ed690e932:1): still awaiting contract resolution
2024-02-24 11:03:26.558 [INF] CNCT: ChannelArbitrator(1e00c6d1b0601d8cb6e2be3085dfabc2a95aef5959020fce42db9a5ed690e932:1): relaunching 1 contract resolvers
2024-02-24 11:03:26.558 [INF] DISC: Authenticated Gossiper starting
2024-02-24 11:03:26.558 [INF] NTFN: New block epoch subscription
2024-02-24 11:03:26.558 [INF] CNCT: *contractcourt.htlcTimeoutResolver(128cfe64dca7c29a96e14c78bfed2b88cf86106f4a16103a9ac23d050c899f9b:0): waiting for spent of HTLC output 1823bad5100cfda6194c587e641a5cbf518a809c9c90a50407a4c8b56f4ff91b:2 to be found in mempool or block
2024-02-24 11:03:26.558 [INF] NTFN: New spend subscription: spend_id=1, outpoint=1823bad5100cfda6194c587e641a5cbf518a809c9c90a50407a4c8b56f4ff91b:2, script=0 c045dca5df19597a0f92bd1fb278ac2048e9a6a80d2cac748aeeb147bf82c214, height_hint=793613
2024-02-24 11:03:26.558 [INF] SWPR: Sweep request received: out_point=1823bad5100cfda6194c587e641a5cbf518a809c9c90a50407a4c8b56f4ff91b:1, witness_type=CommitmentAnchor, relative_time_lock=0, absolute_time_lock=0, amount=0.00000330 BTC, parent=(), params=(fee=253 sat/kw, force=false, exclusive_group=nil)
2024-02-24 11:03:26.558 [INF] NTFN: New block epoch subscription
2024-02-24 11:03:26.558 [INF] NTFN: Dispatching historical spend rescan for outpoint=1823bad5100cfda6194c587e641a5cbf518a809c9c90a50407a4c8b56f4ff91b:2, script=0 c045dca5df19597a0f92bd1fb278ac2048e9a6a80d2cac748aeeb147bf82c214, start=793613, end=831809
2024-02-24 11:03:26.558 [INF] NTFN: New spend subscription: spend_id=2, outpoint=1823bad5100cfda6194c587e641a5cbf518a809c9c90a50407a4c8b56f4ff91b:1, script=0 9f691b893c8c40c9bbb1a53b837a2ca128b8af85fead70b060a4e7ede80f7f4b, height_hint=782627
2024-02-24 11:03:26.559 [INF] NTFN: Dispatching historical spend rescan for outpoint=1823bad5100cfda6194c587e641a5cbf518a809c9c90a50407a4c8b56f4ff91b:1, script=0 9f691b893c8c40c9bbb1a53b837a2ca128b8af85fead70b060a4e7ede80f7f4b, start=782627, end=831809
2024-02-24 11:03:26.566 [INF] CRTR: Channel Router starting
2024-02-24 11:03:26.600 [INF] CRTR: FilteredChainView starting
2024-02-24 11:03:26.746 [INF] SWPR: Candidate sweep set of size=1 (+1 wallet inputs), has yield=0.00000159 BTC, weight=677
2024-02-24 11:03:26.746 [INF] SWPR: Sweep candidates at height=831809 with fee_rate=253 sat/kw, yield 1 distinct txns
2024-02-24 11:03:26.911 [INF] CRTR: Filtering chain using 7910 channels active

[fivebyfive2]

grep 1823bad5100cfda6194c587e641a5cbf518a809c9c90a50407a4c8b56f4ff91b /tmp/lnd4.txt
2024-02-24 11:03:26.558 [INF] CNCT: *contractcourt.htlcTimeoutResolver(128cfe64dca7c29a96e14c78bfed2b88cf86106f4a16103a9ac23d050c899f9b:0): waiting for spent of HTLC output 1823bad5100cfda6194c587e641a5cbf518a809c9c90a50407a4c8b56f4ff91b:2 to be found in mempool or block
2024-02-24 11:03:26.558 [INF] NTFN: New spend subscription: spend_id=1, outpoint=1823bad5100cfda6194c587e641a5cbf518a809c9c90a50407a4c8b56f4ff91b:2, script=0 c045dca5df19597a0f92bd1fb278ac2048e9a6a80d2cac748aeeb147bf82c214, height_hint=793613
2024-02-24 11:03:26.558 [INF] SWPR: Sweep request received: out_point=1823bad5100cfda6194c587e641a5cbf518a809c9c90a50407a4c8b56f4ff91b:1, witness_type=CommitmentAnchor, relative_time_lock=0, absolute_time_lock=0, amount=0.00000330 BTC, parent=(), params=(fee=253 sat/kw, force=false, exclusive_group=nil)
2024-02-24 11:03:26.558 [INF] NTFN: Dispatching historical spend rescan for outpoint=1823bad5100cfda6194c587e641a5cbf518a809c9c90a50407a4c8b56f4ff91b:2, script=0 c045dca5df19597a0f92bd1fb278ac2048e9a6a80d2cac748aeeb147bf82c214, start=793613, end=831809
2024-02-24 11:03:26.558 [INF] NTFN: New spend subscription: spend_id=2, outpoint=1823bad5100cfda6194c587e641a5cbf518a809c9c90a50407a4c8b56f4ff91b:1, script=0 9f691b893c8c40c9bbb1a53b837a2ca128b8af85fead70b060a4e7ede80f7f4b, height_hint=782627
2024-02-24 11:03:26.559 [INF] NTFN: Dispatching historical spend rescan for outpoint=1823bad5100cfda6194c587e641a5cbf518a809c9c90a50407a4c8b56f4ff91b:1, script=0 9f691b893c8c40c9bbb1a53b837a2ca128b8af85fead70b060a4e7ede80f7f4b, start=782627, end=831809
2024-02-24 11:03:56.754 [INF] SWPR: Creating sweep transaction e1e868d23dddc2f3e36b317db1235b4d11503ac6eca72977b4c7870e767dbb98 for 2 inputs (1823bad5100cfda6194c587e641a5cbf518a809c9c90a50407a4c8b56f4ff91b:1 (CommitmentAnchor), 673bdd8a72f61600b0e054fa1c278052a5d858cb1a48d98567ebfd85e16a1223:0 (TaprootPubKeySpend)) using 253 sat/kw, tx_weight=725, tx_fee=0.00000183 BTC, parents_count=0, parents_fee=0 BTC, parents_weight=0
2024-02-24 11:06:47.682 [INF] SWPR: Creating sweep transaction b302db5b9eba03f1a7952db3500e4cb7c14f112c9dd89959e4e246758883c418 for 2 inputs (1823bad5100cfda6194c587e641a5cbf518a809c9c90a50407a4c8b56f4ff91b:1 (CommitmentAnchor), 673bdd8a72f61600b0e054fa1c278052a5d858cb1a48d98567ebfd85e16a1223:0 (TaprootPubKeySpend)) using 253 sat/kw, tx_weight=725, tx_fee=0.00000183 BTC, parents_count=0, parents_fee=0 BTC, parents_weight=0

[fivebyfive2]

The full log 22kb

import.txt

[machadommm]

Hey guys,
I'm having the same problem with a channel being closed several months ago. See the log:

{
    "total_limbo_balance": "47639",
    "pending_open_channels": [],
    "pending_closing_channels": [],
    "pending_force_closing_channels": [
        {
            "channel": {
                "remote_node_pub": "024093f1b33c21e9219c162183df2d635db99184b6138f4b406931525bffe8f63a",
                "channel_point": "9aaf1ce5d49f97c7a895d54720863afb346b58ae8a521ec67cf282f07adca3c6:1",
                "capacity": "5000000",
                "local_balance": "4454320",
                "remote_balance": "62991",
                "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": "be2b5f5f904f18ca71ffd7e6ce5bd23a7c96c4b6a2ae5c148d238babb00b8dea",
            "limbo_balance": "47639",
            "maturity_height": 0,
            "blocks_til_maturity": 0,
            "recovered_balance": "0",
            "pending_htlcs": [
                {
                    "incoming": true,
                    "amount": "47639",
                    "outpoint": "be2b5f5f904f18ca71ffd7e6ce5bd23a7c96c4b6a2ae5c148d238babb00b8dea:4",
                    "maturity_height": 798917,
                    "blocks_til_maturity": -34356,
                    "stage": 1
                }
            ],
            "anchor": "LOST"
        }
    ],
    "waiting_close_channels": []
}

However, in my case it is reporting that the anchor was lost.

How do I solve this problem?

[amicwall]

same here, have a pending force closing channel with small balance, closing tx confirmed December 2023

"limbo_balance": "460",
"maturity_height": 0,
"blocks_til_maturity": 0,
"recovered_balance": "330",
"pending_htlcs": [
{
"incoming": false,
"amount": "460",
"outpoint": "381dd72ef45f59647d065546ab3cb4563b524490b8ff640213f87c441554e2ed:0",
"maturity_height": 823766,
"blocks_til_maturity": -9563,
"stage": 2
}
],
"anchor": "RECOVERED"

[guggero]

The amounts that are left to sweep are just too low, so with the current fee environment it's not economical to do so.

[hieblmi]

@machadommm,
I am still confirming, but it looks like that your pending balance of 47639 was already claimed back by you, here in this transaction: https://mempool.space/tx/6b5612b3fbd2bd24765121a17320b46401080c12d97b6cfcdd39d88f868e6c85, and then used to open a new channel here: https://mempool.space/address/bc1p4tpqdnz9ql85upag8s59m6rnmpkpuhwlcx579tvrnks2ylatavqqzxhatf.

As for 'anchor lost' that means that your 330 sats anchor output was collected by someone else, basically after 16 blocks anyone can claim it if it is not used for a fee bump. This is to reduce UTXO set clutter.

[machadommm]

@machadommm, I am still confirming, but it looks like that your pending balance of 47639 was already claimed back by you, here in this transaction: https://mempool.space/tx/6b5612b3fbd2bd24765121a17320b46401080c12d97b6cfcdd39d88f868e6c85, and then used to open a new channel here: https://mempool.space/address/bc1p4tpqdnz9ql85upag8s59m6rnmpkpuhwlcx579tvrnks2ylatavqqzxhatf.

As for 'anchor lost' that means that your 330 sats anchor output was collected by someone else, basically after 16 blocks anyone can claim it if it is not used for a fee bump. This is to reduce UTXO set clutter.

Hi, @hieblmi
Great so!
How then does the LND get this information trapped?
Is there any way to resolve it? Any commands?
It seems to me to be an application bug.
Could you provide a solution for this?
Thank you very much.