"Adding HTLC timed out: killed channel", "Timed out while waiting", and blinking connections

[artlav]

I've been running c-lightning, 0.7.0 at the moment, for about a year on the same database and it's been accumulating weird issues over time.

The latest and fatal issue is that attempting to pay anything would end up with

      { "code" : 200, "message" : "Timed out while waiting" }

message, and channels would randomly get and lose an "Adding HTLC timed out: killed channel" status:

      "status": [
        "CHANNELD_NORMAL:Reconnected, and reestablished.", 
        "CHANNELD_NORMAL:Adding HTLC timed out: killed channel"
      ], 

The log is full of "Peer connection lost" and "Adding HTLC too slow: killing channel" messages.

Eventually the payment would go into failed state.

I've tried restarting everything, to no effect.

I've retried the payment many times, and in the end one of the channels went into unilateral close ( "Peer permanent failure in CHANNELD_NORMAL: Offered HTLC 8 SENT_ADD_COMMIT cltv 575751 hit deadline" ) with 1200 blocks of waiting, at which point i've stopped trying.

Currently contemplating closing everything, salvaging the funds and starting from blank. Is there any useful data i can provide here?

Other weird things started around the beginning of the year.

First i noticed that the channels kept blinking - showing as connected, then as disconnected, then connected again. Every hour i check, there is a random list of connected and disconnected channels. Before then they would all typically be connected all the time. Nothing changed on the network level, and internet connection remains stable.

That was also around the last time my node routed any payments (or at least listforwards stopped showing any new ones, even when they should have been logged).

Then, about a month ago, channels started to drop out into unilateral closes on bitcoind updates and restarts, if the node was out for more than a few hours. However, payments still worked.

Finally, this happened today.

[whitslack]

I've been seeing similar problems with some payments, only in my case the error message is

Peer permanent failure in CHANNELD_NORMAL: Offered HTLC 40 SENT_ADD_ACK_REVOCATION cltv 591225 hit deadline

at which point my node unilaterally closes the outgoing channel, costing me anywhere between 50¢ and $2.00. I find it a bit ridiculous that using Lightning ends up soaking me with absurdly high fees over which I have no control, when my whole reason for using Lightning in the first place is to pay less in fees.

The error messages aren't very informative, but I'm thinking/guessing they mean that a node in a multi-hop payment failed/neglected/refused to add or remove an HTLC from a channel, and the only recourse my node had at that point was to unilaterally close the channel.

This actually seems like a devastating attack vector on the Lightning Network. If a motivated party wanted to see the Lightning Network fail, they'd set up nodes, open a bunch of channels, and then start randomly refusing to add/remove HTLCs, forcing other nodes to unilaterally close their channels and pay exorbitant fees to do so. It would be enough to discourage many people from using Lightning Network at all. Imagine if LNBIG were to start doing this.

Assuming no malicious intent in the general case, is there any way to make adding/removing HTLCs more robust against intermittent failure? The actual unilateral close of the channel seems to be initiated about a day after the stuck payment that precipitated it. I find it hard to believe that retrying the add/remove would continue to fail for an entire day, so I'm led to believe that retries are not happening.

[ZmnSCPxj]

If a motivated party wanted to see the Lightning Network fail, they'd set up nodes, open a bunch of channels, and then start randomly refusing to add/remove HTLCs, forcing other nodes to unilaterally close their channels and pay exorbitant fees to do so.

This is not possible now, due to principle "Initiator Pays".

This means: the one which initiates the channel open, pays all onchain fees involved, including the tx fees on funding, both unilateral closes, and mutual close.

Thus if anyone performs this (non-)attack, because they opened the channels, they will pay the onchain fees if they timeout the HTLCs and force their (non-)victims to unilateral close, because of "Initiator Pays" principle.

The attack can only be done passively, where a node advertises itself and then does this attack on those who open channels to them, but that is a lot less stressful on LN than the active version, which is blocked by "Initiator Pays".

[whitslack]

@ZmnSCPxj: I understand the "Initiator Pays" principle, but I don't think it applies in this case. I am on the paying end of a multi-hop (routed) payment, and the non-responsive node ("the attacker") is somewhere in the route beyond the first hop. Because the attacker refuses to acknowledge my HTLC revocation command, I am forced to close my channel with the first node in my route, which is an innocent bystander. Thus far, I have been forced to unilaterally close channels with several well-behaved routing nodes, such as LNBIG, SilentBob, and Bitstamp. They are not the nodes that refused to respond to my HTLC revocation commands. Rather, the misbehaving nodes were somewhere further along the route. Moreover, I was the initiator of those first-hop channels that had to be sacrificed to the HTLC gods, so I paid the unilateral closing fees.

The attack can only be done passively, where a node advertises itself and then does this attack on those who open channels to them, but that is a lot less stressful on LN than the active version

I disagree. An attacker who wants to see LN fail wouldn't be targeting any particular individual or organization. Rather, they'd be attacking indiscriminately, hoping to infuriate a large number of random users.

[ZmnSCPxj]

I am on the paying end of a multi-hop (routed) payment, and the non-responsive node ("the attacker") is somewhere in the route beyond the first hop.

This is not correct.

The error you pointed at is:

 Peer permanent failure in CHANNELD_NORMAL: Offered HTLC 40 SENT_ADD_ACK_REVOCATION cltv 591225 hit deadline

Which is printed here:

lightning/lightningd/peer_htlcs.c

Lines 1906 to 1911 in 4929034

	channel_fail_permanent(hout->key.channel,
	"Offered HTLC %"PRIu64
	" %s cltv %u hit deadline",
	hout->key.id,
	htlc_state_name(hout->hstate),
	hout->cltv_expiry);

What this message means is visible in this BOLT snippet we have embedded in our code:

lightning/lightningd/peer_htlcs.c

Lines 1878 to 1883 in 4929034

	/* BOLT #2:
	*
	* - if an HTLC which it offered is in either node's current
	* commitment transaction, AND is past this timeout deadline:
	* - MUST fail the channel.
	*/

Basically: every HTLC has a timeout. The timeout cannot be enforced offchain, it can only be enforced onchain. In order to enforce the timeout when your peer is not responding, you have to drop the transaction onchain. Thus, we need to fail the channel.

Now, suppose you have a payment path like this:

you -> peer -> attacker -> payee

Each of the HTLCs offered at each step has a lower timeout. The highest timeout is what you offer, the lowest timeout is the payee:

you -> 591255 -> peer -> 591241 -> attacker -> 591227 -> payee

Now, if the "attacker" is the one that is attempting to make you fail, then the blockheight 591241 should have occurred before the blockheight 591255.

This means that your peer should, if it were BOLT-compliant, have closed its channel to the attacker first, at blockheight 591241, 14 blocks before blockheight 591255.

Then, after closing its channel at blockheight 519241, your direct peer should have returned an onion-wrapped error to you (permanent channel failure, i.e. "sorry the channel is closed now"), long before blockheight 519255 came and you were forced to close your channel with the peer.

If it did not, then the peer is either buggy, or it is the attacker.

Since, according to your quoted log, your direct peer did not, then:

• Either the peer is buggy, or,
• You are the victim of the passive form of this attack.

If the latter, we can maintain a simple banlist of such nodes and that closes even the passive form of this attack.

We do not do this yet because the balance of probability is that the peer is buggy, because our software is still largely beta level (and a lot of existing nodes still run old alpha-quality releases, for that matter). For reference, it is only C-Lightning release 0.7.2.1 which removed the scary "this is not ready for mainnet yet" warning.

The attack you describe can only be done on direct peers, and can only be done passively. Both restrictions greatly mitigate its effect. Eventually we will implement a banlist once we are confident that buggy unreliable nodes are no longer common on the network. We do not yet, because your peer might just be lazy in updating his or her node software to something that is not buggy and you might someday want to reconnect to them once they have non-buggy reliable software.

The close is triggered by direct channel peer failure (they know they have a pending timeout and have not responded to it yet, so be paranoid and just reclaim the HTLC onchain), not remote forwarding node failure.

[artlav]

Following up on the original post, since then i have recreated the node and other than bug 2820 i had no timeout, connection or channel closing issues. (New node does not show up in explorers, however, and no payments get routed, but sending and receiving works fine).

I still suspect that either old to new database transitions over the year or just the long run times of the node could have broken something, rather than this being an attack of some sort.

[whitslack]

@ZmnSCPxj: Thank you so much for taking the time to write out that explanation. I sincerely appreciate being educated on how this all works under the hood.

So let me see if I understand correctly by way of an example scenario. I'm attempting to complete a 5-hop payment. The first hop (the node to which I am directly connected) is Bitstamp's node. My node initiates a payment attempt, but the attempt neither completes nor fails within my waitsendpay timeout (several minutes). My node continues to show the payment attempt in listsendpays with "status": "pending". What you are saying is that Bitstamp's node should remember that I have an ongoing HTLC through it, and at some point it should send my node a permanent channel failure message, which would allow my node to forget the HTLC without needing to close its channel with Bitstamp's node. That this does not happen indicates that Bitstamp's node is either malicious or buggy. Is that correct? If so, then I'm finding that a lot of big players are either malicious or buggy.

Question: If my node's TCP connection with Bitstamp's node were to be dropped at some point in time after I initiated my payment attempt but before Bitstamp's HTLC with the second hop should have timed out, then should I still expect that Bitstamp's node will send my node a permanent channel failure message if: (A) my node reestablishes a connection with Bitstamp's node prior to when Bitstamp's node should send my node the failure message? (B) my node remains disconnected from Bitstamp's node at the time when Bitstamp's node should send my node the failure message but reestablishes before my own HTLC would time out? In case B, I could guess that Bitstamp's node would have wanted to send my node a permanent channel failure message but would have been unable to send it due to the intermittent disconnection, and maybe it would no longer remember that it needs to send that error to my node upon its reestablishing a connection with my node. I know you have no hand in LND's implementation, but can you at least confirm that C-Lightning will remember that it needs to send a permanent channel failure message to a peer that is disconnected at the time that the failure is raised but later becomes reconnected?

[whitslack]

Here's my latest example:

2019-08-22T20:53:08.111Z INFO plugin-rebalance.py Sending 2500012352msat over 7 hops to rebalance 2500000000msat
2019-08-22T20:53:08.111Z INFO plugin-rebalance.py     - 0327049d8d63f0c40193cdf3afc61817c8647808a4e482de0716fcef74e6d92ebf   ######x####x#  2500012352msat
2019-08-22T20:53:08.111Z INFO plugin-rebalance.py     - 03f443605e76840a654b19247240d98ac56d1b80ec069dc608bf98e3bb172b68ee   562330x2114x1  2500008852msat
2019-08-22T20:53:08.111Z INFO plugin-rebalance.py     - 03da1c27ca77872ac5b3e568af30673e599a47a5e4497f85c7b5da42048807b3ed   550795x2495x0  2500005351msat
2019-08-22T20:53:08.111Z INFO plugin-rebalance.py     - 02c91d6aa51aa940608b497b6beebcb1aec05be3c47704b682b3889424679ca490   575180x1303x0  2500005351msat
2019-08-22T20:53:08.111Z INFO plugin-rebalance.py     - 03de7f5fa97bc87f048e977533fdc0484bf4e0a5b5ca6e55f7baf32b533cbac3f7   573948x2137x1  2500005351msat
2019-08-22T20:53:08.111Z INFO plugin-rebalance.py     - 02e9046555a9665145b0dbd7f135744598418df7d61d3660659641886ef1274844    575311x521x1  2500002500msat
2019-08-22T20:53:08.111Z INFO plugin-rebalance.py     - ##################################################################   ######x####x#  2500000000msat
2019-08-22T20:53:08.119Z INFO lightningd(11323): Sending 2500012352msat over 7 hops to deliver 2500000000msat
2019-08-22T20:54:08.168Z INFO lightningd(11323): lightning_channeld-036e8a8efeb26f3cffce99f462839ef6ea3b1691d569d59c402be0d3d6cef9b79c chan #25717: Peer connection lost
2019-08-22T20:54:08.168Z INFO lightningd(11323): 036e8a8efeb26f3cffce99f462839ef6ea3b1691d569d59c402be0d3d6cef9b79c chan #25717: Peer transient failure in CHANNELD_NORMAL: lightning_channeld: Owning subdaemon lightning_channeld died (62208)
2019-08-22T20:54:10.007Z INFO lightningd(11323): 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f chan #102: Peer transient failure in CHANNELD_NORMAL: Reconnected
2019-08-22T20:54:13.892Z UNUSUAL lightningd(11323): bitcoin-cli: finished bitcoin-cli -datadir=/var/lib/bitcoind getblock 00000000000000000002ca99dfad43e98a86cdd1fd7a9b1b1b3b10f78ad2aae9 false (24511 ms)
2019-08-22T20:54:21.571Z INFO lightningd(11323): 02065e25c272203440b66ea0ba66601d1248564554d0a68472b82511af54288120 chan #26252: Peer transient failure in CHANNELD_NORMAL: Reconnected
2019-08-22T20:54:44.260Z UNUSUAL lightningd(11323): bitcoin-cli: finished bitcoin-cli -datadir=/var/lib/bitcoind getblock 00000000000000000003d9f61495f8874426d823e9c7ba8e11a6716fb262cccd false (22697 ms)
2019-08-22T20:54:45.603Z INFO lightningd(11323): lightning_channeld-0254ff808f53b2f8c45e74b70430f336c6c76ba2f4af289f48d6086ae6e60462d3 chan #15385: Peer connection lost
2019-08-22T20:54:45.603Z INFO lightningd(11323): 0254ff808f53b2f8c45e74b70430f336c6c76ba2f4af289f48d6086ae6e60462d3 chan #15385: Peer transient failure in CHANNELD_NORMAL: lightning_channeld: Owning subdaemon lightning_channeld died (62208)
2019-08-22T20:55:22.704Z INFO lightningd(11323): 02065e25c272203440b66ea0ba66601d1248564554d0a68472b82511af54288120 chan #26252: Peer transient failure in CHANNELD_NORMAL: Reconnected
2019-08-22T20:55:34.100Z INFO lightningd(11323): 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f chan #102: Peer transient failure in CHANNELD_NORMAL: Reconnected
2019-08-22T20:55:58.102Z INFO lightningd(11323): lightning_openingd-03e1a884b7abd5ae840ffe0ccfcabc8af4a0037a942829c50d1161b9f221e5a7b4 chan #28377: Peer connection lost
2019-08-22T20:55:58.102Z INFO lightningd(11323): 03e1a884b7abd5ae840ffe0ccfcabc8af4a0037a942829c50d1161b9f221e5a7b4 chan #28377: Owning subdaemon lightning_openingd died (62208)
2019-08-22T20:57:47.418Z INFO plugin-rebalance.py RpcError: RPC call failed: method: waitsendpay, payload: {'payment_hash': '################################################################', 'timeout': 279}, error: {'code': 200, 'message': 'Timed out while waiting'}

I was attempting to rebalance a channel. This payment attempt got stuck. It is still showing (more than 20 hours later) as pending in my listsendpays:

{
  "id": 1586,
  "payment_hash": "################################################################",
  "destination": "################################################################",
  "msatoshi": 2500000000,
  "amount_msat": "2500000000msat",
  "msatoshi_sent": 2500012352,
  "amount_sent_msat": "2500012352msat",
  "created_at": 1566507188,
  "status": "pending"
}

The first hop in the route is 0327049d8d63f0c40193cdf3afc61817c8647808a4e482de0716fcef74e6d92ebf, a node going by the alias https://diddyinc.com/, which has 196 public channels with about 316 Msat of capacity — clearly a big player.

I can see four possible ways for my payment attempt to be resolved:

1. My node never hears anything back from Diddyinc and is forced to unilaterally close its channel with Diddyinc to recover my 2.5 Msat that are held up in an HTLC.
2. Diddyinc never hears anything back from the second hop in the route (03f4436…) and is forced to unilaterally close its channel with that node. Diddyinc should then send my node a permanent channel failure message to report that it closed its channel (562330x2114x1) with the second hop. I would presume that Diddyinc should also then update its channel with my node to remove my HTLC, to save my node from being forced to close its channel with Diddyinc.
3. Diddyinc receives a permanent channel failure message from the second hop in the route (03f4436…), reporting that the second hop was forced to unilaterally close its channel (550795x2495x0) with the third hop (03da1c2…). In this case, Diddyinc should update its channel with my node to remove my HTLC, thereby saving my node from needing to unilaterally close its channel with Diddyinc.
4. Diddyinc eventually gets its channel (550795x2495x0) with the third hop (03da1c2…) updated to remove its HTLC. In this case, Diddyinc should act toward my node in the same way as in case 3.

Is my understanding correct?

[ZmnSCPxj]

All 4 points in your latest post are correct. In your experienced case it is the point 1 that occurred. This could happen for anything from a bug in the implementation to some unreliability in your connection with Diddyinc.

I apologize but I am busy on non-Bitcoin-related tasks for now and cannot answer the previous post in detail.

It has been a long time since I had a good look into the HTLC-forwarding code (early 2017). A quick look on the recent version of the HTLC-forwarding code suggests it has changed massively since then. In any case, C-Lightning goal is to follow BOLT spec as closely as possible, and any mismatch of the code vs the spec-mandated behavior I described would be a bug.

[whitslack]

Argh! It happened again, this time involving my channel to CoinGate. Yesterday, three of my attempted outgoing payments through CoinGate (i.e., where CoinGate was the first hop) got stuck. Today, my node force-closed its channel to CoinGate because the first of those three HTLCs hit its deadline.

Is the assertion here really that CoinGate's Lightning node is so buggy that it didn't send my node a permanent routing failure prior to the first of my three stuck HTLCs' deadlines? I suspect there is some other issue at play here.

Log excerpt follows:

{
   "type": "DEBUG",
   "time": "1296497.275162228",
   "source": "lightning_channeld-0242a4ae0c5bef18048fbecf995094b74bfb0f7391418d71ed394784373f41e4f3 chan #476:",
   "log": "peer_in WIRE_REVOKE_AND_ACK"
},
{
   "type": "DEBUG",
   "time": "1296502.264845154",
   "source": "lightning_channeld-0242a4ae0c5bef18048fbecf995094b74bfb0f7391418d71ed394784373f41e4f3 chan #476:",
   "log": "Received revoke_and_ack"
},
{
   "type": "DEBUG",
   "time": "1296513.625356336",
   "source": "lightning_channeld-0242a4ae0c5bef18048fbecf995094b74bfb0f7391418d71ed394784373f41e4f3 chan #476:",
   "log": "Applying feerate 4565 to LOCAL"
},
{
   "type": "DEBUG",
   "time": "1296533.246604863",
   "source": "lightning_channeld-0242a4ae0c5bef18048fbecf995094b74bfb0f7391418d71ed394784373f41e4f3 chan #476:",
   "log": "Commits outstanding after recv revoke_and_ack"
},
{
   "type": "DEBUG",
   "time": "1296533.887231878",
   "source": "lightning_channeld-0242a4ae0c5bef18048fbecf995094b74bfb0f7391418d71ed394784373f41e4f3 chan #476:",
   "log": "Sending master 1022"
},
{
   "type": "DEBUG",
   "time": "1296534.320173264",
   "source": "0242a4ae0c5bef18048fbecf995094b74bfb0f7391418d71ed394784373f41e4f3 chan #476:",
   "log": "got revoke 13170: 0 changed"
},
{
   "type": "DEBUG",
   "time": "1296534.845535562",
   "source": "lightning_channeld-0242a4ae0c5bef18048fbecf995094b74bfb0f7391418d71ed394784373f41e4f3 chan #476:",
   "log": "... , awaiting 1122"
},
{
   "type": "DEBUG",
   "time": "1296535.967775691",
   "source": "lightning_channeld-0242a4ae0c5bef18048fbecf995094b74bfb0f7391418d71ed394784373f41e4f3 chan #476:",
   "log": "Got it!"
},
{
   "type": "DEBUG",
   "time": "1296536.949455397",
   "source": "lightning_channeld-0242a4ae0c5bef18048fbecf995094b74bfb0f7391418d71ed394784373f41e4f3 chan #476:",
   "log": "revoke_and_ack LOCAL: remote_per_commit = 03c444f438e2e868bdc5b902002d4dcc83a7978d6a6c0c3817ad2141772df22f9e, old_remote_per_commit = 03e5ba3389a33ca30ea476e588eb51c29af6afe18132047512227b9d14218aa35b"
},
{
   "type": "DEBUG",
   "time": "1296537.565749170",
   "source": "lightning_channeld-0242a4ae0c5bef18048fbecf995094b74bfb0f7391418d71ed394784373f41e4f3 chan #476:",
   "log": "peer_in WIRE_COMMITMENT_SIGNED"
},
{
   "type": "DEBUG",
   "time": "1296544.215932447",
   "source": "lightning_channeld-0242a4ae0c5bef18048fbecf995094b74bfb0f7391418d71ed394784373f41e4f3 chan #476:",
   "log": "Received commit"
},
{
   "type": "DEBUG",
   "time": "1296555.006354481",
   "source": "lightning_channeld-0242a4ae0c5bef18048fbecf995094b74bfb0f7391418d71ed394784373f41e4f3 chan #476:",
   "log": "Derived key 0378face5a93e09077129cdf0d697ad967587fede485fe104c795568f490d7ef20 from basepoint 02e3730b521c5fcdb12d8f9605b869cffd0a872e43cd197def4050bcf98d6e1079, point 03c79e8225cd30f82fc3849e387e28ecee6778b8f9a6a65448e2ecb8606c73d28d"
},
{
   "type": "DEBUG",
   "time": "1296569.947867023",
   "source": "lightning_channeld-0242a4ae0c5bef18048fbecf995094b74bfb0f7391418d71ed394784373f41e4f3 chan #476:",
   "log": "Received commit_sig with 3 htlc sigs"
},
{
   "type": "DEBUG",
   "time": "1296570.848311714",
   "source": "lightning_channeld-0242a4ae0c5bef18048fbecf995094b74bfb0f7391418d71ed394784373f41e4f3 chan #476:",
   "log": "Sending master 1021"
},
{
   "type": "DEBUG",
   "time": "1296571.251009400",
   "source": "0242a4ae0c5bef18048fbecf995094b74bfb0f7391418d71ed394784373f41e4f3 chan #476:",
   "log": "got commitsig 13161: feerate 4565, 0 added, 0 fulfilled, 0 failed, 0 changed"
},
{
   "type": "DEBUG",
   "time": "1296571.666477911",
   "source": "lightning_channeld-0242a4ae0c5bef18048fbecf995094b74bfb0f7391418d71ed394784373f41e4f3 chan #476:",
   "log": "... , awaiting 1121"
},
{
   "type": "DEBUG",
   "time": "1296572.858526595",
   "source": "lightning_channeld-0242a4ae0c5bef18048fbecf995094b74bfb0f7391418d71ed394784373f41e4f3 chan #476:",
   "log": "Got it!"
},
{
   "type": "DEBUG",
   "time": "1296573.557387894",
   "source": "lightning_channeld-0242a4ae0c5bef18048fbecf995094b74bfb0f7391418d71ed394784373f41e4f3 chan #476:",
   "log": "Sending revoke_and_ack"
},
{
   "type": "DEBUG",
   "time": "1296574.096841002",
   "source": "lightning_channeld-0242a4ae0c5bef18048fbecf995094b74bfb0f7391418d71ed394784373f41e4f3 chan #476:",
   "log": "peer_out WIRE_REVOKE_AND_ACK"
},
{
   "type": "DEBUG",
   "time": "1296576.547076690",
   "source": "lightning_channeld-0242a4ae0c5bef18048fbecf995094b74bfb0f7391418d71ed394784373f41e4f3 chan #476:",
   "log": "Trying commit"
},
{
   "type": "DEBUG",
   "time": "1296576.659197068",
   "source": "lightning_channeld-0242a4ae0c5bef18048fbecf995094b74bfb0f7391418d71ed394784373f41e4f3 chan #476:",
   "log": "Can't send commit: nothing to send"
},
{
   "type": "DEBUG",
   "time": "1297267.756580369",
   "source": "lightning_channeld-0242a4ae0c5bef18048fbecf995094b74bfb0f7391418d71ed394784373f41e4f3 chan #476:",
   "log": "Trying commit"
},
{
   "type": "DEBUG",
   "time": "1297267.756756611",
   "source": "lightning_channeld-0242a4ae0c5bef18048fbecf995094b74bfb0f7391418d71ed394784373f41e4f3 chan #476:",
   "log": "Can't send commit: nothing to send"
},
{
   "type": "DEBUG",
   "time": "1298176.366493312",
   "source": "lightning_channeld-0242a4ae0c5bef18048fbecf995094b74bfb0f7391418d71ed394784373f41e4f3 chan #476:",
   "log": "Trying commit"
},
{
   "type": "DEBUG",
   "time": "1298176.366670870",
   "source": "lightning_channeld-0242a4ae0c5bef18048fbecf995094b74bfb0f7391418d71ed394784373f41e4f3 chan #476:",
   "log": "Can't send commit: nothing to send"
},
{
   "type": "UNUSUAL",
   "time": "1298189.174188731",
   "source": "0242a4ae0c5bef18048fbecf995094b74bfb0f7391418d71ed394784373f41e4f3 chan #476:",
   "log": "Peer permanent failure in CHANNELD_NORMAL: Offered HTLC 3085 SENT_ADD_ACK_REVOCATION cltv 599527 hit deadline"
},
{
   "type": "DEBUG",
   "time": "1298189.174302728",
   "source": "lightning_channeld-0242a4ae0c5bef18048fbecf995094b74bfb0f7391418d71ed394784373f41e4f3 chan #476:",
   "log": "Status closed, but not exited. Killing"
},
{
   "type": "INFO",
   "time": "1298189.274248219",
   "source": "0242a4ae0c5bef18048fbecf995094b74bfb0f7391418d71ed394784373f41e4f3 chan #476:",
   "log": "State changed from CHANNELD_NORMAL to AWAITING_UNILATERAL"
},
{
   "type": "DEBUG",
   "time": "1298191.079820472",
   "source": "0242a4ae0c5bef18048fbecf995094b74bfb0f7391418d71ed394784373f41e4f3 chan #476:",
   "log": "Peer has reconnected, state AWAITING_UNILATERAL"
},
{
   "type": "DEBUG",
   "time": "1298191.112437461",
   "source": "lightning_openingd-0242a4ae0c5bef18048fbecf995094b74bfb0f7391418d71ed394784373f41e4f3 chan #53531:",
   "log": "pid 18578, msgfd 56"
},
{
   "type": "DEBUG",
   "time": "1298191.169607072",
   "source": "lightning_openingd-0242a4ae0c5bef18048fbecf995094b74bfb0f7391418d71ed394784373f41e4f3 chan #53531:",
   "log": "peer_out WIRE_ERROR"
},
{
   "type": "DEBUG",
   "time": "1298191.171911594",
   "source": "lightning_openingd-0242a4ae0c5bef18048fbecf995094b74bfb0f7391418d71ed394784373f41e4f3 chan #53531:",
   "log": "Handed peer, entering loop"
},
{
   "type": "DEBUG",
   "time": "1298191.172227494",
   "source": "lightning_openingd-0242a4ae0c5bef18048fbecf995094b74bfb0f7391418d71ed394784373f41e4f3 chan #53531:",
   "log": "peer_in WIRE_CHANNEL_REESTABLISH"
},
{
   "type": "DEBUG",
   "time": "1298191.172534416",
   "source": "lightning_openingd-0242a4ae0c5bef18048fbecf995094b74bfb0f7391418d71ed394784373f41e4f3 chan #53531:",
   "log": "Rejecting WIRE_CHANNEL_REESTABLISH for unknown channel_id 247878f74ba61576bf8b6130bd9f583f28bb52dc2975d08898240bfe1a49f62b"
},
{
   "type": "DEBUG",
   "time": "1298191.172843558",
   "source": "lightning_openingd-0242a4ae0c5bef18048fbecf995094b74bfb0f7391418d71ed394784373f41e4f3 chan #53531:",
   "log": "peer_out WIRE_ERROR"
},
{
   "type": "DEBUG",
   "time": "1298191.173146655",
   "source": "lightning_openingd-0242a4ae0c5bef18048fbecf995094b74bfb0f7391418d71ed394784373f41e4f3 chan #53531:",
   "log": "peer_out WIRE_GOSSIP_TIMESTAMP_FILTER"
},
{
   "type": "DEBUG",
   "time": "1298191.384443194",
   "source": "lightning_openingd-0242a4ae0c5bef18048fbecf995094b74bfb0f7391418d71ed394784373f41e4f3 chan #53531:",
   "log": "peer_in WIRE_ERROR"
},
{
   "type": "DEBUG",
   "time": "1298401.217105731",
   "source": "0242a4ae0c5bef18048fbecf995094b74bfb0f7391418d71ed394784373f41e4f3 chan #476:",
   "log": "Got UTXO spend for 2bf6491afe0b249888d07529dc52bb283f589fbd30618bbf7615a64bf7787824:0: 19306e451a349d1d999f456fd700e569e77c28fc1fdeea2316ef53a019f2c6b1"
},
{
   "type": "UNUSUAL",
   "time": "1298401.217197334",
   "source": "0242a4ae0c5bef18048fbecf995094b74bfb0f7391418d71ed394784373f41e4f3 chan #476:",
   "log": "Peer permanent failure in AWAITING_UNILATERAL: Funding transaction spent"
},
{
   "type": "INFO",
   "time": "1298401.273356539",
   "source": "0242a4ae0c5bef18048fbecf995094b74bfb0f7391418d71ed394784373f41e4f3 chan #476:",
   "log": "State changed from AWAITING_UNILATERAL to AWAITING_UNILATERAL"
},
{
   "type": "INFO",
   "time": "1298401.273942629",
   "source": "0242a4ae0c5bef18048fbecf995094b74bfb0f7391418d71ed394784373f41e4f3 chan #476:",
   "log": "State changed from AWAITING_UNILATERAL to FUNDING_SPEND_SEEN"
},
{
   "type": "DEBUG",
   "time": "1298401.303342770",
   "source": "lightning_onchaind-0242a4ae0c5bef18048fbecf995094b74bfb0f7391418d71ed394784373f41e4f3 chan #476:",
   "log": "pid 19896, msgfd 48"
},
{
   "type": "DEBUG",
   "time": "1298403.299105776",
   "source": "0242a4ae0c5bef18048fbecf995094b74bfb0f7391418d71ed394784373f41e4f3 chan #476:",
   "log": "We want to know if htlc 3085 is missing (immediate)"
},
{
   "type": "DEBUG",
   "time": "1298403.299482135",
   "source": "0242a4ae0c5bef18048fbecf995094b74bfb0f7391418d71ed394784373f41e4f3 chan #476:",
   "log": "We want to know if htlc 3126 is missing (immediate)"
},
{
   "type": "DEBUG",
   "time": "1298403.299522570",
   "source": "0242a4ae0c5bef18048fbecf995094b74bfb0f7391418d71ed394784373f41e4f3 chan #476:",
   "log": "We want to know if htlc 3130 is missing (immediate)"
},
{
   "type": "DEBUG",
   "time": "1298404.201577423",
   "source": "0242a4ae0c5bef18048fbecf995094b74bfb0f7391418d71ed394784373f41e4f3 chan #476:",
   "log": "Got depth change 0->1 for 19306e451a349d1d999f456fd700e569e77c28fc1fdeea2316ef53a019f2c6b1"
},
{
   "type": "DEBUG",
   "time": "1298404.395317824",
   "source": "lightning_onchaind-0242a4ae0c5bef18048fbecf995094b74bfb0f7391418d71ed394784373f41e4f3 chan #476:",
   "log": "feerate_per_kw = 4138"
},
{
   "type": "DEBUG",
   "time": "1298405.417337196",
   "source": "lightning_onchaind-0242a4ae0c5bef18048fbecf995094b74bfb0f7391418d71ed394784373f41e4f3 chan #476:",
   "log": "Tracking output 0 of 2bf6491afe0b249888d07529dc52bb283f589fbd30618bbf7615a64bf7787824: FUNDING_TRANSACTION/FUNDING_OUTPUT"
},
{
   "type": "DEBUG",
   "time": "1298405.417682712",
   "source": "lightning_onchaind-0242a4ae0c5bef18048fbecf995094b74bfb0f7391418d71ed394784373f41e4f3 chan #476:",
   "log": "Remote per-commit point: 03c444f438e2e868bdc5b902002d4dcc83a7978d6a6c0c3817ad2141772df22f9e"
},
{
   "type": "DEBUG",
   "time": "1298405.417989251",
   "source": "lightning_onchaind-0242a4ae0c5bef18048fbecf995094b74bfb0f7391418d71ed394784373f41e4f3 chan #476:",
   "log": "Old remote per-commit point: 03e5ba3389a33ca30ea476e588eb51c29af6afe18132047512227b9d14218aa35b"
},
{
   "type": "DEBUG",
   "time": "1298405.418145367",
   "source": "lightning_onchaind-0242a4ae0c5bef18048fbecf995094b74bfb0f7391418d71ed394784373f41e4f3 chan #476:",
   "log": "commitnum = 13161, revocations_received = 13171"
},
{
   "type": "INFO",
   "time": "1298405.418429231",
   "source": "0242a4ae0c5bef18048fbecf995094b74bfb0f7391418d71ed394784373f41e4f3 chan #476:",
   "log": "State changed from FUNDING_SPEND_SEEN to ONCHAIN"
},

[whitslack]

Happened again, this time with Sagittarius A, and this time it wasn't my own payment that did it but rather one my node was forwarding.

"Peer permanent failure in CHANNELD_NORMAL: Offered HTLC 2629 SENT_ADD_ACK_REVOCATION cltv 599640 hit deadline"

This is becoming expensive.

[whitslack]

Another one, this one with LightningTo.Me, and this is another one where the HTLC in question wasn't mine.

"Peer permanent failure in CHANNELD_NORMAL: Offered HTLC 61 SENT_ADD_COMMIT cltv 599803 hit deadline"

Notable is that this one wasn't a SENT_ADD_ACK_REVOCATION like the others but was instead a SENT_ADD_COMMIT.

There is something seriously wrong here.

[whitslack]

The latest fly to drop in this saga is OpenChannel. This one had 30 pending HTLCs at the time my node force-closed it, all for 2000 msat, none of them originated by me.

"Peer permanent failure in CHANNELD_NORMAL: Offered HTLC 572 SENT_ADD_ACK_REVOCATION cltv 600201 hit deadline"

[ZmnSCPxj]

Hi @whitslack, sorry for not tracking this.

I have been thinking about this more deeply recently in the past week. Sorry, but the below has many substantive footnotes, please read them as well in full.

Can you corroborate my basic assumption below?

• This kind of event ("HTLC does not fail before time out while peer is "connected": true") tends to happen during high-onchain-fee periods, often with the mempool getting even more congested afterwards.

My current working hypothesis is that this is triggered by a node that, by complete accident, goes offline after receiving an HTLC from a multi-hop routing, then is still offline when the HTLC times out, and then this event occurs during high-onchain-fee period.

First, let me explicate the model of my working hypothesis:

• The path is from A -> B -> C -> D -> ...
• D dies (due to incompetence rather than malice) after receiving the C->D HTLC of this payment.
• This occurs during a high-onchain-fee period that subsequently gets exacerbated by even sharper rise of fees.

Let us now take on the identity of C.

• Time advances even after D dies.
• The HTLC C->D is now about to time out. Since D is offline, it cannot do anything, so we are forced to drop the channel onchain.
• D went offline some time ago, so the unilateral close feerate of the C-D channel is currently laughably out-of-date: just updating this feerate requires both C and D to be online [FOOTNOTE 1].
• The recent high fees mean that the unilateral close of the C-D channel is not sufficient to beat other transactions, so the unilateral close remains on the mempool.
• Even if the HTLC timelock is valid, we cannot rely on that fact --- the hashlock branch remains valid, which if confirmed would pay out the HTLC amount to D.
  • D could only pretend to be dead --- our code cannot differentiate between incompetence and malice, and is thus coded to assume malice.
  • If D is only pretending to be dead, it can wait for the C-D unilateral close to come on the mempool, and then get the hashlock branch confirmed.
• The previous point is exacerbated by the fact that we broadcasted our unilateral close!
  • Any HTLC we offered to D has the hashlock encumbered only by the hashlock, but the timelock has a greater encumberance --- it pays out only to a pre-signed transaction (HTLC-timeout of BOLT3) whose output has a CSV requirement [FOOTNOTE 2].
  • The timelock we hold means we cannot CPFP the commitment transaction faster!
  • At the same time, the hashlock is not so encumbered and if D is pretending to be dead, it can CPFP the commitment tx, but with the HTLC resolved with the hashlock branch (paying out to D).
• Since the C-D HTLC can still be claimed by D in the hashlock branch until the C timelock branch is confirmed, we cannot safely fail the incoming B->C HTLC!

Let us suppose that the balance of probability is that D is incompetent rather than malicious.

• In that case, the C-D channel commitment transaction remains in the mempool unconfirmed with its old, low feerate.
• This remains true even as the incoming B->C HTLC timeout approaches.
• Time passes with the mempool growing in size.
• The B->C HTLC times out, forcing B to drop the B-C channel unilaterally onchain (i.e. an instance of this event you are reporting).
• B and C were online at the time of unilateral close, so presumably we and B were able to update the feerate. Unfortunately, due to various policies, the B-C unilateral close feerate is actually laggy and out-of-date due to smoothing, which is imposed for historical reasons [FOOTNOTE 3].
• The B-C unilateral close also floats in the mempool with an out-of-date, laughably low feerate,

At this point, we can take on the identity of node B on the route.

We should now observe that:

• B now sees C in the same light as C sees D.
• Thus, B will also do what C did: it will refuse to fail the incoming A->B HTLC.
• This further causes the A-B channel to later be forced onchain, further exacerbating the mempool congestion that got us into this mess in the first place.

The end effect is that:

• Due to the incompetence of D, the C-D, B-C, and A-B channels get closed.

The above analysis assumes this tends to occur in high-fee periods.

What can be done to fix this? Anchor commitments fixes this, but that requires:

• A spec change.
• Coordination among multiple implementations.
• Existing channels are not negotiated with anchor commitments (because anchor commitments did not exist at the time they were created), so we need a mechanism to upgrade a non-anchor-commitment channel to an anchor-commitment channel, which further requires:
  • Its own spec change.
  • Coordination among multiple implementations.

For now, what can C-Lightning do by itself? Well, C can "take one for the team" and, even if the C->D HTLC is still ambiguous (it is still floating in the mempool and can still be confirmed in either the hashlock or the timelock branch), if the incoming B->C HTLC is about to time out in two blocks [FOOTNOTE 4], it should just fail B->C HTLC. This lets the A->B HTLC fail and only the C-D channel is closed, which is fine since D is (pretending to be) offline anyway.

That solution works if D is incompetent, but what if D is malicious and is actually in cahoots with B?

• D can deliberately lowball the C-D feerate if it is the one that created C-D in the first place. C might accept a slightly low feerate rather than drop channels onchain since onchain activity is so expensive.
  • Modern C-Lightning nodes have very loose bounds on what it will accept as "reasonable" for unilateral close tx.
  • D can do this while onchain fees are low, .e.g. weekend.
• B and D wait for a sudden fee spike (or manufacture one, e.g. by self-paying pointless transactions with high feerates).
• B quickly routes from B->C->D and waits for D to receive it.
• Before C starts wondering about the low fees of the C-D channel, D goes offline with the C->D HTLC still in the channel.
• At some point (either when the C->D HTLC is about to expire, or onchain fees are now unreasonably high compared to the unilateral close feerate on the C-D channel) C drops the C-D channel with the C->D HTLC onchain.
• When the B->C HTLC is about to expire, C fails it (this is the solution we are proposing) even if the C->D HTLC is still ambiguous (it is not confirmed either way yet).
• B gets refunded and signals D.
• D suddenly comes online and claims the C->D HTLC with the hashlock branch, which we should note (since C dropped the C-D channel onchain) is not encumbered and can be CPFPed.
• C just paid to D without getting an incoming payment from B, and cries in frustration with much wailing and gnashing of teeth. It was being civic minded and preventing this issue, and got punished for it! Why o why is the world so unfair?????

On the other hand --- we should note that the solution only invites attack for high-value HTLCs. Perhaps there is some sufficiently low HTLC size which C can still safely fail even if the outgoing HTLC is still ambiguous?

• We can observe that the HTLC on the C-D commitment transaction can be spent by either the HTLC-timeout transaction by C, or by any hashlock-spending transaction by D.
• Rational miners will still prefer to confirm the HTLC-timeout transaction if it has a higher feerate than the hashlock-spending transaction by D.
• Thus, in order for D to steal the HTLC, it has to pay at least the feerate of the HTLC-timeout transaction, which it should be noted, is the feerate both C and D agreed on the last time they updated commitment feerates.
• Logically, D will only do this if the HTLC amount is greater than the fee that needs to be paid to defeat the HTLC-timeout transaction.
• Thus, C can safely fail the B->C HTLC if and only if the outgoing C->D HTLC is less than or equal to the fee needed by the hashlock branch to defeat the HTLC-timeout transaction.

Note that the above is logic about feerates, but the HTLC amount must be less than some fee. So what weight should we multiply with the latest feerate of the C-D channel in order to see the actual fee, where a C->D HTLC below that fee means it is safe to fail B->C?

• B and D can instead make lots of tiny HTLCs, each below the limit, but in total summing up to a substantial sum. Or in simpler terms, B and D can send thousands of HTLCs along B->C->D, and at the D end, claim all thousand HTLCs using a single transaction.
• Thus, it should only be the weight of an input, (32 byte txid, 4 byte outnum) plus the witness needed to satisfy the hashlock branch (1 sipa preimage size, 32 sipa preimage, 1 sipa signature size, 72 sipa signature (signatures can be ground to this weight I think, though most signatures are 73 sipa)).
• If C will only fail the B->C HTLC if the C->D HTLC is below the above, then D must pay more than an HTLC amount to claim a single C->D HTLC, so this is sufficient to disincentivize the attack.

Thus, as long as the HTLC is below the C-D unilateral feerate-per-kilosipa times 250 divided by 1000, then it should be safe for C to fail the B->C HTLC, since this attack will cost D more than what it earns.

This limit is fairly low. However, we note that:

• This event tends to happen during high-onchain-fee periods (note this is the assumption I make in the analysis), so the unilateral feerate-per-kilosipa should be fairly high, if the cause is incompetence rather than active malice.
• If D is truly incompetent and not malicious, even if the C->D HTLC fails this check, the B-C channel feerate is updating to higher fees (even though at a slower rate than actual mempool growth, it still goes up slightly over time) so even if B-C channel is forced onchain by the B->C HTLC, the B->C HTLC might now be smaller than the "only slightly out-of-date" B-C unilateral close feerate and B can safely fail the A->B HTLC instead of continuing the failures out to the payer.

@rustyrussell @niftynei @cdecker @darosior what do you all think? Can/should we implement this as a stopgap until anchor commitments are fully deployed?

---

[FOOTNOTE 1] Anchor commitments fixes this, so that unilateral close fees can be updated by either side independently of the other. It seems likely that anchor commitments is the complete solution here, though I admit that is little help to current node operators, thus in the above main text I propose a stopgap solution.

[FOOTNOTE 2] This is a consequence of the Poon-Dryja mechanism. Each side keeps its own latest commitment transaction. As part of Poon-Dryja, the owner of a commitment transaction must be encumbered on every contract branch that leads unambiguously to that owner, and the encumberance must be a revocable output. In simpler terms: if I have offered an HTLC to you, you own the hashlock branch of the HTLC and I own the timelock branch. On my version of the commitment tx, the timelock branch is encumbered and requires a second-stage transaction, the HTLC-timeout transaction that is signed by both you and me, but the hashlock branch is unencumbered except for the hash requirement and your signature. On your version of the commitment tx, the timelock branch I own is unencumbered oither than my signature and the needed time, but the hashlock branch is encumbered by a second-stage HTLC-success transaction. The HTLC-timeout / HTLC-success tx has the same fixed feerate as the commitment transaction, which leads to the troubles above.

[FOOTNOTE 3] The historical reason is that in 2017 or thereabouts, there were mass closures of Lightning Network channels due to sudden onchain fee spikes. This is because both sides of the channel need to agree on the feerate of unilateral close transactions (commitment txes). Even if, say, one side pays for all channel fees, the other side is still interested in the feerate. This is because in case the fee-paying side goes offline, the non-fee-paying side still needs to get any high-value HTLCs on the channel to be confirmed in timely manner, since HTLCs have a time limit. So the non-fee-paying side needs to agree to the feerate still. If the fee-paying side gives a too-low feerate, it is better for the non-fee-paying side to drop the channel onchain now while the latest commitment tx feerate is still mostly acceptable for current conditions, than to wait later when the fee-paying side has gone offline and conditions might be even worse. Now, during onchain fee spikes, two Lightning nodes might disagree on what a "reasonable" fee is. This is because two peers on the Lightning layer might not be peers on the Bitcoin layer, so one peer might see a sudden increase in high-fee mempool txes on the Bitcoin layer while the other has not received those yet, leading to feerate disagreement and channels dropping onchain (and further exacerbating the mempool congestion!).

To mitigate this, C-Lightning (and probably other implementations as well) smooth out the fees sampled from the Bitcoin layer, so that in case the peer is not yet up-to-date on the higher fees, we do not trigger the disagreement with them. But this implies that the current onchain fees we are using are not up-to-date on the higher fees that the actual mempool congestion level requires, leading to the above troubles.

[FOOTNOTE 4] Common node policies (C-Lightning does this, and there is good reason to believe lnd and Eclair and LDK and Ptarmigan and Electrum do this too) mean nodes will drop channels onchain if any HTLC in it will expire in one block, so we need to fail incoming HTLCs that will expire in two blocks.