CoreLN not properly detecting force close UTXOs

[gkrizek]

Issue and Steps to Reproduce

I have a CoreLN node running 23.08. I was trying to track down a Force Close we had and where the funds had gone because I didn't notice them in my onchain wallet. I looked at the transactions in a block explorer and saw that they ended up in a particular address, but that address wasn't listed in my listfunds output. To ensure this address actually belonged to me I searched for the address in the dev-listaddrs command's output. The address showed up in that output so it seemed to me that my CoreLN node did own the address, however these funds were not showing up in the wallet. So I figured I needed to rescan the wallet to find the funds.

Before I did anything, I check all my UTXOs in the listfunds command and I had 15 UTXOs. They were a mix of confirmed and unconfirmed and a few were reserved. I first tried the dev-rescan-outputs command. This ran successfully but it decreased my UTXOs to 7. So I figured that didn't completely do what I wanted it to. Next I tried to do a rescan in the config and set it to a specific block height that was just before this force close transaction. After the rescan finished listfunds had 71 UTXOs which are all confirmed. Once I started looking into all these new UTXOs, I noticed they were all from force closes over time.

I can provide whatever technical details necessary for debugging, but it seems like CoreLN is not tracking these UTXOs properly. Thanks.

[niftynei]

iirc CLN delays adding UTXOs to the wallet/listfunds view until after the to_self_delay has expired, seems like there's something not working as intended here.

Were the missing UTXOs direct outputs from a force close tx?

[gkrizek]

@niftynei Yes, I believe so. Here's an example:
https://mempool.space/tx/3924b77729f675a8aebfd77ce38da2d5980e9399e1613ee9c9746e79c173f469

The address bc1qnk8l9azhds67yyyslgrau2ng0fdf0fc6nrz6fg was not in my output of listfunds previously and then after a rescan it was. And it was months since the transaction happened.

(The address was later used after the rescan on 12-08, but you can see it sat with a balance Oct - Dec as it was not in the utxo set for the node)

[niftynei]

Interesting. Are you running the bookkeeper? I'd be curious to know what the timestamp is on the wallet deposit event for that utxo (3924b77729f675a8aebfd77ce38da2d5980e9399e1613ee9c9746e79c173f469:0). You can grep the output of bkpr-listaccountevents wallet to find it, e.g.:

 lightning-cli bkpr-listaccountevents wallet | grep -C 8 "3924b77729f675a8aebfd77ce38da2d5980e9399e1613ee9c9746e79c173f469:0"

I'd anticipate it's the same as when it got added to the listfunds view, but maybe not?

[gkrizek]

@niftynei Sure, here's the output. The timestamp is indeed when the rescan happened and not when the actual close occured.

      {
         "account": "wallet",
         "type": "chain",
         "tag": "deposit",
         "credit_msat": 995730000,
         "debit_msat": 0,
         "currency": "bc",
         "outpoint": "3924b77729f675a8aebfd77ce38da2d5980e9399e1613ee9c9746e79c173f469:0",
         "timestamp": 1702005123,
         "blockheight": 812803
      },

It also shows up for when it was spent FWIW:

      {
         "account": "wallet",
         "type": "chain",
         "tag": "withdrawal",
         "credit_msat": 0,
         "debit_msat": 995730000,
         "currency": "bc",
         "outpoint": "3924b77729f675a8aebfd77ce38da2d5980e9399e1613ee9c9746e79c173f469:0",
         "txid": "38293400848c72059a7ca9d594dbfbdb8eb090531c187ebe90ae3a2fa0070f0c",
         "timestamp": 1702072152,
         "blockheight": 820315
      },

[niftynei]

ACK thanks. Pretty much lines up with what I'd have expected, thanks for that.

I'll try to replicate today, appears to be an issue with 'to us' force closes not being added to the internal wallet set correctly.

As-is we've got a bit of a visibility problem with pending to-us outputs, might be possible to knock those both out (no way to see outputs that we'll spend into our wallet when they hit deadline; confuses a bunch of people when force closes happen b/c the utxos "disappear" in the interim. Though in your case it seems like it stayed disappeared, oops).

[cdecker]

@niftynei how are things looking? I plan to call a feature freeze on the weekend of the 29th, and I am planning on what to include and what to defer. This issue was marked for the upcoming release, but if you need more time I'll remove that flag ^^

[niftynei]

@cdecker i haven't had time i hoped to look into this :(