HTLC timeout transaction sweep is never run due to integer underflow

[cdecker]

Issue and Steps to Reproduce

We (Greenlight) got a number of reports of missing sweeps of HTLC timeout transactions, due to a potential integer underflow issue. The symptoms are as follows:

1. The node correctly recognizes an HTLC it has added to the channel as requiring a sweep

2024-04-08T21:13:56+02:00 {} stdout: DEBUG   0264a62a4307d701c04a46994ce5f5323b1ca28c80c66b73c631dbcb0990d6e835-onchaind-chan#1: Telling lightningd about OUR_HTLC_TIMEOUT_TX to resolve OUR_UNILATERAL/OUR_HTLC after block 835914 (-65 more blocks)
2024-04-08T21:13:57+02:00 {} stdout: DEBUG   0264a62a4307d701c04a46994ce5f5323b1ca28c80c66b73c631dbcb0990d6e835-onchaind-chan#1: Tracking output 463972904772472b38fa1cc907e5143a5af1a008cb373179c22f4d824d72e11f:4: OUR_UNILATERAL/DELAYED_OUTPUT_TO_US

2. The next time the HTLC timeout transaction is mentioned it is in this log here

2024-04-08T21:13:57+02:00 {} stdout: DEBUG   0264a62a4307d701c04a46994ce5f5323b1ca28c80c66b73c631dbcb0990d6e835-onchaind-chan#1: billboard: 6 outputs unresolved: in 4294967232 blocks will spend OUR_HTLC (463972904772472b38fa1cc907e5143a5af1a008cb373179c22f4d824d72e11f:2) using OUR_HTLC_TIMEOUT_TX

3. Notice that the timeout in blocks all of the sudden is (1 - 65) % UINT32_MAX, which is very suspicious.

My intuition is that this is an underflow in the u32 used to plan the execution of the transaction.

getinfo output

Server started with public key 02e5f238372e62540a421b9777f6efd9ea7ae78edb299a0dac74376ce27c5f6e49, alias STRANGEGOPHER-v23.08gl1

Yes, this has some small changes to the way UTXOs are tracked in the DB, but other than that it does not have any modification from the CLN in this repository.

[daywalker90]

I've seen this before on a vanilla 23.11 #6951 (comment)

[ksedgwic]

I've got one too on:

 ab4ea82638b1d49e206e6637ae2211010534bf32 lightning (v24.02.1-18-gab4ea8263)
 206a1f23c343b5f3e70f0091fad57f5bae998797 vls (v0.11.0-73-g206a1f23)

         "state_changes": [
           {
              "timestamp": "2024-04-04T06:42:00.804Z",
              "old_state": "CHANNELD_AWAITING_LOCKIN",
              "new_state": "CHANNELD_NORMAL",
              "cause": "user",
              "message": "Lockin complete"
           },
           {
              "timestamp": "2024-04-25T03:48:08.845Z",
              "old_state": "CHANNELD_NORMAL",
              "new_state": "AWAITING_UNILATERAL",
              "cause": "protocol",
              "message": "Offered HTLC 506 SENT_ADD_ACK_REVOCATION cltv 2673110 hit deadline"
           },
           {
              "timestamp": "2024-04-25T03:48:43.696Z",
              "old_state": "AWAITING_UNILATERAL",
              "new_state": "FUNDING_SPEND_SEEN",
              "cause": "onchain",
              "message": "Onchain funding spend"
           },
           {
              "timestamp": "2024-04-25T03:48:47.086Z",
              "old_state": "FUNDING_SPEND_SEEN",
              "new_state": "ONCHAIN",
              "cause": "onchain",
              "message": "Onchain init reply"
           },
           
... lots of last repeated ...

           {
              "timestamp": "2024-05-12T23:11:33.667Z",
              "old_state": "FUNDING_SPEND_SEEN",
              "new_state": "ONCHAIN",
              "cause": "onchain",
              "message": "Onchain init reply"
           }
        ],
        "status": [
           "ONCHAIN:Tracking our own unilateral close",
           "ONCHAIN:3 outputs unresolved: in 4294825093 blocks will spend OUR_HTLC (26ede09939e5528593b6f4d57ebf93a3ab86b763094f1a5fcf3df0862e62a080:2) using OUR_HTLC_TIMEOUT_TX"
        ],

Logs believed to be available, anything you want me to look for?

[rustyrussell]

This cosmetic only, and has been there for a long time. I keep meaning to fix it, but nobody complained before so I figured I'm the only one looking at the logs.