Unilateral close never concludes

[tsjk]

I have two channels that were unilaterally closed by me. These now refuse to be forgotten, even though the associated transactions were confirmed long ago. This also means that cln spams RBF transactions that are senseless. While the status remains at

  "status": [
    "ONCHAIN:Tracking our own unilateral close",
    "ONCHAIN:1 outputs unresolved: waiting confirmation that we spent DELAYED_OUTPUT_TO_US (<txid>:<vout>) using OUR_DELAYED_RETURN_TO_WALLET"
  ],

where <txid>:<vout> is long settled, on every restart of cln, I get two new state updates like

    {
      "timestamp": "2024-06-06T17:29:06.993Z",
      "old_state": "ONCHAIN",
      "new_state": "FUNDING_SPEND_SEEN",
      "cause": "remote",
      "message": "Onchain funding spend"
    },
    {
      "timestamp": "2024-06-06T17:29:07.304Z",
      "old_state": "FUNDING_SPEND_SEEN",
      "new_state": "ONCHAIN",
      "cause": "remote",
      "message": "Onchain init reply"
    }

When cln starts, I see log entries like

2024-06-06T17:29:06.789Z INFO    lightningd: Restarting onchaind for channel 186
2024-06-06T17:29:06.796Z UNUSUAL <node_id>-chan#186: Peer permanent failure in ONCHAIN: Funding transaction spent
2024-06-06T17:29:06.856Z INFO    <node_id>-chan#186: State changed from ONCHAIN to FUNDING_SPEND_SEEN
2024-06-06T17:29:07.145Z INFO    <node_id>-chan#186: State changed from FUNDING_SPEND_SEEN to ONCHAIN

getinfo output

{
   "id": "-",
   "alias": "-",
   "color": "000000",
   "num_peers": <int>,
   "num_pending_channels": 0,
   "num_active_channels": <int>,
   "num_inactive_channels": <int>,
   "address": [
      {
         "type": "ipv4",
         "address": "<ip>",
         "port": <port>
      },
      {
         "type": "torv3",
         "address": "*d.onion",
         "port": 9735
      }
   ],
   "binding": [
      {
         "type": "ipv4",
         "address": "0.0.0.0",
         "port": 9735
      },
      {
         "type": "ipv4",
         "address": "0.0.0.0",
         "port": <port>
      }
   ],
   "version": "v23.11.2-modded",
   "blockheight": 846864,
   "network": "bitcoin",
   "fees_collected_msat": <int>,
   "lightning-dir": "/home/lightning/.lightning/bitcoin",
   "our_features": {
      "init": "08a0800a0a69a2",
      "node": "88a0800a0a69a2",
      "channel": "",
      "invoice": "02000002024100"
   }
}

[Lagrang3]

You closed the channel unilaterally, therefore the output sending funds to you has a timelock. You can get the value of this timelock with the command

lightning-cli listpeerchannels <your peer id> | jq '.["channels"][0]["our_to_self_delay"]'

While you're waiting for this timelock to expire you will see the following status of the channel for example:

lightning-cli listpeerchannels <your peer id> | jq '.["channels"][0]["status"]'
[
  "ONCHAIN:Tracking our own unilateral close",
  "ONCHAIN:5 outputs unresolved: waiting confirmation that we spent DELAYED_OUTPUT_TO_US (<txid>:<output num>) using OUR_DELAYED_RETURN_TO_WALLET"
]

After enough confirmations have passed lightningd will broadcast a transaction that spends that output to your wallet and the status will transition to:

lightning-cli listpeerchannels <your peer id> | jq '.["channels"][0]["status"]'
[
  "ONCHAIN:Tracking our own unilateral close",
  "ONCHAIN:All outputs resolved: waiting 99 more blocks before forgetting channel"
]

Eventually after 100 blocks from this point you will not see the channel again in listfunds.

You said the closing transaction has long been confirmed. The timelock value is negotiated when the channels are created and they can vary. I have for example one channel with 1200 blocks timelock, that means I need a bit more than 8 days after a force closure before I can spend my funds.

[tsjk]

Yes, you misunderstood. The timelock has long passed and I've received my funds. The close was initiated more than a month ago. The only thing left is for cln to understand that, which I think it never will.

[Lagrang3]

If the timelock has expired already you could check in a block explorer if your corresponding output has been spent or not.

Just making hypothesis here: but what if your output is not enough to pay for the transaction fees to claim these funds?

[tsjk]

As stated in the original post: "where <txid>:<vout> is long settled". I also just typed that I have received my funds. This means that the referred to output belongs to a confirmed transaction, and thus waiting confirmation that we spent DELAYED_OUTPUT_TO_US (<txid>:<output num>) using OUR_DELAYED_RETURN_TO_WALLET makes no sense. To be clear, not only is <txid> confirmed, but the following payout tx is also confirmed. This is another way of saying that I have received my funds. I do understand that you want to help. I'm not sure I need help. I think this is a bug, where cln has failed to change state where it should have.

[Lagrang3]

If you don't need help that's ok. I do need your help to understand where the problem is.

Can you filter out all messages from the logs that match <node_id>-chan and <node id>-onchaind-chan? You might have to add log-level=debug in your config file.

[tsjk]

I'm happy to help. Just want to make sure our ambitions are aligned. :) So, the log entries I have is:

2024-06-06T17:29:06.796Z UNUSUAL <node_id>-chan#186: Peer permanent failure in ONCHAIN: Funding transaction spent
2024-06-06T17:29:06.856Z INFO    <node_id>-chan#186: State changed from ONCHAIN to FUNDING_SPEND_SEEN
2024-06-06T17:29:07.145Z INFO    <node_id>-chan#186: State changed from FUNDING_SPEND_SEEN to ONCHAIN

and then a bunch of

<node_id>-chan#186: RBF onchain txid ...

Nothing from onchaind. Can I enable debug logging for only that component? And can I do it without rebooting cln? :)

(afk for a few hours)

[Lagrang3]

Nothing from onchaind. Can I enable debug logging for only that component? And can I do it without rebooting cln? :)

I can't change the log-level without rebooting, it is not one of the dynamic config options. I don't think you can enable debug logs only for that component, but you can use grep to filter the logs. For example

grep /tmp/l1/log -e 02f06884d035e010ec45ee7796df134e2af4b25b1010420e0304e370d7a5f20936 | sed 's/02f06884d035e010ec45ee7796df134e2af4b25b1010420e0304e370d7a5f20936/<node id>/g'

and then a bunch of -chan#186: RBF onchain txid ...

That's interesting.

[tsjk]

Ok, there are a lot of logs, with txids, transactions and and keys. I'm hesitant to post these to a public forum.

On another note, it seems to be possible to do log-level=debug:onchaind-chan#<channel_number> to limit the debug logging to onchaind.