Automatic fee update results in unilateral close

[azhmur]

Background

Your environment

• lnd 0.4.1 commit=b7875fce4cb82db11c86cec41218f3e49e8c15b0
• 4.9.0-6-amd64 Fix name typo in README #1 SMP Debian 4.9.82-1+deb9u3 (2018-03-02) x86_64 GNU/Linux
• bitcoind 16.0

Steps to reproduce

Happens without any user interaction. Autopilot was on.

Expected behaviour

Unilateral channel close in this case seems to be misunderstanding between lighting nodes. Not sure if my node is guilty,

Actual behaviour

2018-04-09 02:31:19.203 [INF] CRTR: Pruning channel graph using block 0000000000000000001f1cd44618fb8d3ed8571051726fd786bff128e9c361e2 (height=517299)
2018-04-09 02:31:19.256 [INF] NTFN: New block: height=517299, sha=0000000000000000001f1cd44618fb8d3ed8571051726fd786bff128e9c361e2
2018-04-09 02:31:19.256 [INF] UTXN: Attempting to graduate height=517299: num_kids=0, num_babies=0
2018-04-09 02:31:19.259 [INF] HSWC: ChannelPoint(a2fa9466d51fd2e19c35b9a67a92a375bf519f78965e3da24af78c71988685cf:0): updating commit fee to 250 sat/kw
2018-04-09 02:31:19.262 [INF] HSWC: ChannelPoint(5d988d34adb5ed8e50404a305660f0606600bedff60f7a5809bb8eff61b23357:0): updating commit fee to 250 sat/kw
2018-04-09 02:31:19.266 [INF] HSWC: ChannelPoint(3a2d25bbab1e57f55f158cddc7d681bf7784e1e223faa4a174a14353f13cb39f:0): updating commit fee to 250 sat/kw
2018-04-09 02:31:19.269 [INF] HSWC: ChannelPoint(6a3aef987032829e31087b220c2d3c6d488c932089fc0e1e72bac4ce291928f0:0): updating commit fee to 250 sat/kw
2018-04-09 02:31:19.272 [INF] HSWC: ChannelPoint(6e532fd0c082caa205d2cb07898935374ace21224b6f37063e821894a0a40ee6:0): updating commit fee to 250 sat/kw
2018-04-09 02:31:19.277 [INF] HSWC: ChannelPoint(2b3fb2cdf4a93126e180bd3ddc87525d4af7cfd3249c4a0fe9dfa8e3eb1ff93b:0): updating commit fee to 250 sat/kw
2018-04-09 02:31:19.280 [INF] HSWC: ChannelPoint(19c2a69e947dcd21ca5049555ff7d9c87c487222887cc28cb1758895f50aa3ee:0): updating commit fee to 250 sat/kw
2018-04-09 02:31:19.283 [INF] HSWC: ChannelPoint(ce6a432f59f3152be725dfd696fac31b2a0456e868f0f232137c0812b4e27b02:0): updating commit fee to 250 sat/kw
2018-04-09 02:31:20.449 [INF] CRTR: Block 0000000000000000001f1cd44618fb8d3ed8571051726fd786bff128e9c361e2 (height=517299) closed 0 channels
2018-04-09 02:31:21.938 [ERR] HSWC: ChannelPoint(5d988d34adb5ed8e50404a305660f0606600bedff60f7a5809bb8eff61b23357:0): recieved error from peer: update_fee 250 outside range 253-6785
2018-04-09 02:31:21.938 [INF] PEER: unable to read message from 136.59.98.27:9735: read tcp 192.168.1.19:45510->136.59.98.27:9735: use of closed network connection
2018-04-09 02:31:21.939 [INF] HSWC: Removing channel link with ChannelID(5733b261ff8ebb09587a0ff6dfbe006660f06056304a40508eedb5ad348d985d)
2018-04-09 02:31:21.939 [INF] HSWC: ChannelLink(5d988d34adb5ed8e50404a305660f0606600bedff60f7a5809bb8eff61b23357:0) is stopping
2018-04-09 02:31:21.939 [INF] NTFN: Cancelling epoch notification, epoch_id=21
2018-04-09 02:31:21.939 [INF] HSWC: ChannelLink(5d988d34adb5ed8e50404a305660f0606600bedff60f7a5809bb8eff61b23357:0) has exited
2018-04-09 02:31:22.038 [ERR] HSWC: ChannelPoint(6a3aef987032829e31087b220c2d3c6d488c932089fc0e1e72bac4ce291928f0:0): recieved error from peer: update_fee 250 outside range 253-6785
2018-04-09 02:31:22.038 [INF] PEER: unable to read message from 47.184.129.94:9735: read tcp 192.168.1.19:49216->47.184.129.94:9735: use of closed network connection
2018-04-09 02:31:22.039 [INF] HSWC: Removing channel link with ChannelID(f0281929cec4ba721e0efc8920938c486d3c2d0c227b08319e82327098ef3a6a)
2018-04-09 02:31:22.039 [INF] HSWC: ChannelLink(6a3aef987032829e31087b220c2d3c6d488c932089fc0e1e72bac4ce291928f0:0) is stopping
2018-04-09 02:31:22.039 [INF] NTFN: Cancelling epoch notification, epoch_id=18
2018-04-09 02:31:22.039 [INF] HSWC: ChannelLink(6a3aef987032829e31087b220c2d3c6d488c932089fc0e1e72bac4ce291928f0:0) has exited
2018-04-09 02:31:22.094 [ERR] HSWC: ChannelPoint(6e532fd0c082caa205d2cb07898935374ace21224b6f37063e821894a0a40ee6:0): recieved error from peer: update_fee 250 outside range 253-6785
2018-04-09 02:31:22.094 [INF] PEER: unable to read message from 34.236.113.58:9735: read tcp 192.168.1.19:58784->34.236.113.58:9735: use of closed network connection
2018-04-09 02:31:22.094 [INF] HSWC: Removing channel link with ChannelID(e60ea4a09418823e06376f4b2221ce4a3735898907cbd205a2ca82c0d02f536e)
2018-04-09 02:31:22.094 [INF] HSWC: ChannelLink(6e532fd0c082caa205d2cb07898935374ace21224b6f37063e821894a0a40ee6:0) is stopping
2018-04-09 02:31:22.094 [INF] NTFN: Cancelling epoch notification, epoch_id=17
2018-04-09 02:31:22.094 [INF] HSWC: ChannelLink(6e532fd0c082caa205d2cb07898935374ace21224b6f37063e821894a0a40ee6:0) has exited
2018-04-09 02:31:22.216 [ERR] HSWC: ChannelPoint(19c2a69e947dcd21ca5049555ff7d9c87c487222887cc28cb1758895f50aa3ee:0): recieved error from peer: update_fee 250 outside range 253-6785
2018-04-09 02:31:22.216 [INF] PEER: unable to read message from 104.198.32.198:9735: read tcp 192.168.1.19:51282->104.198.32.198:9735: use of closed network connection
2018-04-09 02:31:22.216 [INF] HSWC: Removing channel link with ChannelID(eea30af5958875b18cc27c882272487cc8d9f75f554950ca21cd7d949ea6c219)
2018-04-09 02:31:22.216 [INF] HSWC: ChannelLink(19c2a69e947dcd21ca5049555ff7d9c87c487222887cc28cb1758895f50aa3ee:0) is stopping
2018-04-09 02:31:22.216 [INF] NTFN: Cancelling epoch notification, epoch_id=20
2018-04-09 02:31:22.216 [INF] HSWC: ChannelLink(19c2a69e947dcd21ca5049555ff7d9c87c487222887cc28cb1758895f50aa3ee:0) has exited
2018-04-09 02:31:22.586 [INF] NTFN: Dispatching spend notification for outpoint=6a3aef987032829e31087b220c2d3c6d488c932089fc0e1e72bac4ce291928f0:0
2018-04-09 02:31:22.586 [INF] NTFN: Dispatching spend notification for outpoint=6e532fd0c082caa205d2cb07898935374ace21224b6f37063e821894a0a40ee6:0
2018-04-09 02:31:22.589 [INF] NTFN: Dispatching spend notification for outpoint=5d988d34adb5ed8e50404a305660f0606600bedff60f7a5809bb8eff61b23357:0
2018-04-09 02:31:22.590 [INF] NTFN: Dispatching spend notification for outpoint=19c2a69e947dcd21ca5049555ff7d9c87c487222887cc28cb1758895f50aa3ee:0
2018-04-09 02:31:22.656 [WRN] CNCT: Unprompted commitment broadcast for ChannelPoint(19c2a69e947dcd21ca5049555ff7d9c87c487222887cc28cb1758895f50aa3ee:0)
2018-04-09 02:31:22.656 [INF] CNCT: Unilateral close of ChannelPoint(19c2a69e947dcd21ca5049555ff7d9c87c487222887cc28cb1758895f50aa3ee:0) detected
2018-04-09 02:31:22.656 [WRN] CNCT: Unprompted commitment broadcast for ChannelPoint(6a3aef987032829e31087b220c2d3c6d488c932089fc0e1e72bac4ce291928f0:0)
2018-04-09 02:31:22.656 [INF] CNCT: Unilateral close of ChannelPoint(6a3aef987032829e31087b220c2d3c6d488c932089fc0e1e72bac4ce291928f0:0) detected
2018-04-09 02:31:22.656 [WRN] CNCT: Unprompted commitment broadcast for ChannelPoint(6e532fd0c082caa205d2cb07898935374ace21224b6f37063e821894a0a40ee6:0)
2018-04-09 02:31:22.656 [INF] CNCT: Unilateral close of ChannelPoint(6e532fd0c082caa205d2cb07898935374ace21224b6f37063e821894a0a40ee6:0) detected
2018-04-09 02:31:22.659 [WRN] CNCT: Unprompted commitment broadcast for ChannelPoint(5d988d34adb5ed8e50404a305660f0606600bedff60f7a5809bb8eff61b23357:0)
2018-04-09 02:31:22.659 [INF] CNCT: Unilateral close of ChannelPoint(5d988d34adb5ed8e50404a305660f0606600bedff60f7a5809bb8eff61b23357:0) detected
2018-04-09 02:31:23.294 [INF] CNCT: ChannelArbitrator(6e532fd0c082caa205d2cb07898935374ace21224b6f37063e821894a0a40ee6:0): remote party has closed channel out on-chain
2018-04-09 02:31:23.383 [INF] CNCT: ChannelArbitrator(19c2a69e947dcd21ca5049555ff7d9c87c487222887cc28cb1758895f50aa3ee:0): remote party has closed channel out on-chain
2018-04-09 02:31:23.439 [INF] CNCT: ChannelArbitrator(5d988d34adb5ed8e50404a305660f0606600bedff60f7a5809bb8eff61b23357:0): remote party has closed channel out on-chain
2018-04-09 02:31:23.494 [INF] CNCT: ChannelArbitrator(6a3aef987032829e31087b220c2d3c6d488c932089fc0e1e72bac4ce291928f0:0): remote party has closed channel out on-chain
2018-04-09 02:31:24.337 [INF] SRVR: Established connection to: 136.59.98.27:9735
2018-04-09 02:31:24.484 [INF] SRVR: Established connection to: 34.236.113.58:9735
2018-04-09 02:31:24.570 [INF] SRVR: Established connection to: 47.184.129.94:9735
2018-04-09 02:31:24.639 [INF] SRVR: Established connection to: 104.198.32.198:9735
2018-04-09 02:31:24.681 [ERR] PEER: recv'd update for unknown channel 5733b261ff8ebb09587a0ff6dfbe006660f06056304a40508eedb5ad348d985d from 136.59.98.27:9735
2018-04-09 02:31:24.740 [ERR] PEER: recv'd update for unknown channel e60ea4a09418823e06376f4b2221ce4a3735898907cbd205a2ca82c0d02f536e from 34.236.113.58:9735
2018-04-09 02:31:24.874 [ERR] PEER: recv'd update for unknown channel f0281929cec4ba721e0efc8920938c486d3c2d0c227b08319e82327098ef3a6a from 47.184.129.94:9735
2018-04-09 02:31:24.980 [ERR] PEER: recv'd update for unknown channel eea30af5958875b18cc27c882272487cc8d9f75f554950ca21cd7d949ea6c219 from 104.198.32.198:9735
2018-04-09 02:31:25.531 [INF] DISC: Syncing channel graph state with 02f6725f9c1c40333b67faea92fd211c183050f28df32cac3f9d69685fe9665432, sending 9479 vertexes and 4750 edges
2018-04-09 02:31:25.532 [INF] SRVR: Attempting to send msgs 23713 to: 02f6725f9c1c40333b67faea92fd211c183050f28df32cac3f9d69685fe9665432
2018-04-09 02:31:25.532 [INF] DISC: Syncing channel graph state with 024b82d69859d63f9fce375041a34e61f4bfd445494b41d873ae7505322323d384, sending 9479 vertexes and 4750 edges
2018-04-09 02:31:25.532 [INF] SRVR: Attempting to send msgs 23713 to: 024b82d69859d63f9fce375041a34e61f4bfd445494b41d873ae7505322323d384
2018-04-09 02:31:25.535 [INF] DISC: Syncing channel graph state with 021f2cbffc4045ca2d70678ecf8ed75e488290874c9da38074f6d378248337062b, sending 9479 vertexes and 4750 edges
2018-04-09 02:31:25.535 [INF] SRVR: Attempting to send msgs 23713 to: 021f2cbffc4045ca2d70678ecf8ed75e488290874c9da38074f6d378248337062b
2018-04-09 02:31:25.531 [INF] DISC: Syncing channel graph state with 0235447c7485ff2b945bac5fbc366d54a87389bab8cacf1b64b26ec01e96bd165a, sending 9479 vertexes and 4750 edges
2018-04-09 02:31:25.558 [INF] SRVR: Attempting to send msgs 23713 to: 0235447c7485ff2b945bac5fbc366d54a87389bab8cacf1b64b26ec01e96bd165a
2018-04-09 02:31:27.895 [INF] NTFN: New confirmations subscription: txid=99c96b3fbf0a0ae32620f27bc3fc1d4c0fdef3c0ee62ae74ec18e9da986cb91a, numconfs=1
2018-04-09 02:31:28.750 [INF] NTFN: New confirmations subscription: txid=ba10c343c0e966eac30e2be972160ffcfae61d7992bbeac7d96c6f7436fc9918, numconfs=1
2018-04-09 02:31:28.805 [INF] NTFN: New confirmations subscription: txid=75ac22603829c18d9db6728c6120d497323beba11d42e66ff097e6eee3b4261a, numconfs=1
2018-04-09 02:31:28.861 [INF] NTFN: New confirmations subscription: txid=030092bcefa2b48b6777823559d9a900f1a7291af1b4659ddac3e0d4ddc756e8, numconfs=1
2018-04-09 02:31:28.916 [INF] CNCT: ChannelArbitrator(6e532fd0c082caa205d2cb07898935374ace21224b6f37063e821894a0a40ee6:0): still awaiting contract resolution
2018-04-09 02:31:28.972 [INF] CNCT: ChannelArbitrator(19c2a69e947dcd21ca5049555ff7d9c87c487222887cc28cb1758895f50aa3ee:0): still awaiting contract resolution
2018-04-09 02:31:29.016 [INF] CNCT: ChannelArbitrator(5d988d34adb5ed8e50404a305660f0606600bedff60f7a5809bb8eff61b23357:0): still awaiting contract resolution
2018-04-09 02:31:29.072 [INF] CNCT: ChannelArbitrator(6a3aef987032829e31087b220c2d3c6d488c932089fc0e1e72bac4ce291928f0:0): still awaiting contract resolution

[Roasbeef]

This isn't an issue with lnd. It's that other implementations don't like if we create a fee update that's three satoshis outside their desired range. They then force close in this state. This is probably the worst thing one can do as it's the initiator that actually pays all the transaction fees in the channel. As a result of them force closing, they now need to wait N blocks in order to get their funds back, while we get our funds back immediately.

What they should do instead is: accept the fee update, but then immediately do a cooperative channel closure. This guarantees that they fee ceiling will the the newly proposed fee.

[azhmur]

Thanks for explanation. Can i disable this automatic fee updates from lnd? In this actual example my node was decreasing fees (500 -> 250), i prefer it didn't touch it as a workaround for other misbeahaving nodes.
As far as i understand updatechanpolicy doesn't affect this value.

[Roasbeef]

Can i disable this automatic fee updates from lnd? In this actual example my node was decreasing fees (500 -> 250)

At this point, no. Since we're the initiator of the channel it's our duty to ensure that we don't overpay or underpay with active commitments.

[azhmur]

I found the other side.

https://github.com/ElementsProject/lightning/blob/86290b54d49d183e49f905be6a18bfc65612580e/channeld/channel.c#L680

https://github.com/ElementsProject/lightning/blob/8a9fef21273b6535a3b4e2fdc3b7d52cf3613f22/lightningd/peer_control.c#L152

But i can't guess how this miscommunication can be fixed. lnd and clighting use different algorthims for fee estimation. In some situations fee set by lnd goes out of boundaries for clighting. channel closes. If i manually reopen it it will be closed again within days.

[Roasbeef]

Yes, we're aware of the fee disagreements. IMO it's that clightning should be more liberal with accepting these fees are they aren't the ones paying for the fees on the commitment transaction. For now, if you want to ensure this doesn't happen, ever, then take care not to open any channels with clightning /shruggie