Closing fee negotiation fails between c-lightning and eclair

Question

Closing fee negotiation fails between c-lightning and eclair

Closed this issue 6 years ago · 2 comments

Just tried to do a collaborative close between my node and the starblocks node, and it failed to negotiate a common feerate:

2018-02-09T13:08:32.726Z lightningd(20203): peer 03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134: Peer permanent failure in CLOSINGD_SIGEXCHANGE: lightning_closingd: sent ERROR remote offer 350 not between 351 and 351

It seems that we received a fee offer for 350, but we bisected further and now only accepted a range of 351 - 351. Could this be related to the asynchronicity issue lightning/bolts#366?

The failure finally results in us not completing the closing negotiation, opting to drop on chain instead, with the really expensive fee.

Full shutdown logs:

2018-02-09T13:08:31.718Z lightningd(20203): peer 03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134: State changed from CHANNELD_NORMAL to CHANNELD_SHUTTING_DOWN 
2018-02-09T13:08:31.719Z lightningd(20203):jcon fd 14: Success 
2018-02-09T13:08:31.749Z lightningd(20203): lightning_channeld(03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134): Trying commit 
2018-02-09T13:08:31.749Z lightningd(20203): lightning_channeld(03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134): Can't send commit: nothing to send 
2018-02-09T13:08:31.750Z lightningd(20203): lightning_channeld(03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134): peer_out WIRE_CHANNEL_UPDATE 
2018-02-09T13:08:31.750Z lightningd(20203): lightning_channeld(03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134): peer_out WIRE_SHUTDOWN 
2018-02-09T13:08:31.750Z lightning_gossipd(20211): Received channel_update for channel 1280498:67:0(0) now DISABLED 
2018-02-09T13:08:31.758Z lightningd(20203): Connected json input 
2018-02-09T13:08:31.759Z lightningd(20203):jcon fd 14: Success 
2018-02-09T13:08:31.923Z lightningd(20203): lightning_channeld(03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134): peer_in WIRE_SHUTDOWN 
2018-02-09T13:08:31.924Z lightning_gossipd(20211): Received channel_update for channel 1280498:67:0(0) now DISABLED 
2018-02-09T13:08:31.924Z lightningd(20203): lightning_channeld(03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134): UPDATE WIRE_CHANNEL_GOT_SHUTDOWN 
2018-02-09T13:08:31.947Z lightningd(20203): lightning_channeld(03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134): UPDATE WIRE_CHANNEL_SHUTDOWN_COMPLETE 
2018-02-09T13:08:31.947Z lightningd(20203): lightning_channeld(03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134): UPDATE WIRE_CHANNEL_SHUTDOWN_COMPLETE 
2018-02-09T13:08:31.949Z lightningd(20203): lightning_closingd(03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134): pid 2898, msgfd 16 
2018-02-09T13:08:31.949Z lightningd(20203): peer 03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134: State changed from CHANNELD_SHUTTING_DOWN to CLOSINGD_SIGEXCHANGE 
2018-02-09T13:08:31.978Z lightningd(20203): lightning_closingd(03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134): satoshi_out = 9665336/334663 
2018-02-09T13:08:31.979Z lightningd(20203): lightning_closingd(03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134): dustlimit = 546 
2018-02-09T13:08:31.979Z lightningd(20203): lightning_closingd(03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134): fee = 360 
2018-02-09T13:08:31.979Z lightningd(20203): lightning_closingd(03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134): Making close tx at = 9665336/334663 fee 360 
2018-02-09T13:08:31.979Z lightningd(20203): lightning_closingd(03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134): sending fee offer 360 
2018-02-09T13:08:31.979Z lightningd(20203): lightning_closingd(03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134): peer_out WIRE_CLOSING_SIGNED 
2018-02-09T13:08:31.979Z lightningd(20203): lightning_closingd(03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134): peer_in WIRE_CLOSING_SIGNED 
2018-02-09T13:08:31.979Z lightningd(20203): lightning_closingd(03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134): Making close tx at = 9665336/334663 fee 336 
2018-02-09T13:08:31.979Z lightningd(20203): lightning_closingd(03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134): Received fee offer 336 
2018-02-09T13:08:31.979Z lightningd(20203): lightning_closingd(03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134): ...offer is reasonable 
2018-02-09T13:08:31.979Z lightningd(20203): lightning_closingd(03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134): UPDATE WIRE_CLOSING_RECEIVED_SIGNATURE 
2018-02-09T13:08:31.979Z lightningd(20203): peer 03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134: Their actual closing tx fee is 337 vs previous 9665337 
2018-02-09T13:08:31.979Z lightningd(20203): peer 03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134: ... That's closer to our ideal 300 
2018-02-09T13:08:32.002Z lightningd(20203): lightning_closingd(03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134): Feerange init 0-360, local higher 
2018-02-09T13:08:32.002Z lightningd(20203): lightning_closingd(03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134): Feerange remote update 336: now 337-360 
2018-02-09T13:08:32.002Z lightningd(20203): lightning_closingd(03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134): Feerange local update 360: now 337-359 
2018-02-09T13:08:32.231Z lightningd(20203): lightning_closingd(03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134): peer_in WIRE_CLOSING_SIGNED 
2018-02-09T13:08:32.231Z lightningd(20203): lightning_closingd(03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134): Making close tx at = 9665336/334663 fee 348 
2018-02-09T13:08:32.232Z lightningd(20203): lightning_closingd(03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134): Received fee offer 348 
2018-02-09T13:08:32.232Z lightningd(20203): lightning_closingd(03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134): ...offer is reasonable 
2018-02-09T13:08:32.232Z lightningd(20203): lightning_closingd(03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134): UPDATE WIRE_CLOSING_RECEIVED_SIGNATURE 
2018-02-09T13:08:32.232Z lightningd(20203): peer 03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134: Their actual closing tx fee is 349 vs previous 9665337 
2018-02-09T13:08:32.232Z lightningd(20203): peer 03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134: ... That's closer to our ideal 300 
2018-02-09T13:08:32.252Z lightningd(20203): lightning_closingd(03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134): Feerange remote update 348: now 349-359 
2018-02-09T13:08:32.252Z lightningd(20203): lightning_closingd(03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134): Making close tx at = 9665336/334663 fee 354 
2018-02-09T13:08:32.253Z lightningd(20203): lightning_closingd(03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134): sending fee offer 354
2018-02-09T13:08:32.253Z lightningd(20203): lightning_closingd(03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134): peer_out WIRE_CLOSING_SIGNED 
2018-02-09T13:08:32.253Z lightningd(20203): lightning_closingd(03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134): Feerange local update 354: now 349-353 
2018-02-09T13:08:32.393Z lightningd(20203): lightning_closingd(03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134): peer_in WIRE_CLOSING_SIGNED 
2018-02-09T13:08:32.393Z lightningd(20203): lightning_closingd(03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134): Making close tx at = 9665336/334663 fee 350 
2018-02-09T13:08:32.394Z lightningd(20203): lightning_closingd(03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134): Received fee offer 350 
2018-02-09T13:08:32.394Z lightningd(20203): lightning_closingd(03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134): ...offer is reasonable 
2018-02-09T13:08:32.394Z lightningd(20203): lightning_closingd(03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134): UPDATE WIRE_CLOSING_RECEIVED_SIGNATURE 
2018-02-09T13:08:32.394Z lightningd(20203): peer 03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134: Their actual closing tx fee is 351 vs previous 9665337 
2018-02-09T13:08:32.394Z lightningd(20203): peer 03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134: ... That's closer to our ideal 300 
2018-02-09T13:08:32.418Z lightningd(20203): lightning_closingd(03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134): Feerange remote update 350: now 351-353 
2018-02-09T13:08:32.418Z lightningd(20203): lightning_closingd(03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134): Making close tx at = 9665336/334663 fee 352 
2018-02-09T13:08:32.418Z lightningd(20203): lightning_closingd(03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134): sending fee offer 352 
2018-02-09T13:08:32.418Z lightningd(20203): lightning_closingd(03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134): peer_out WIRE_CLOSING_SIGNED 
2018-02-09T13:08:32.418Z lightningd(20203): lightning_closingd(03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134): Feerange local update 352: now 351-351 
2018-02-09T13:08:32.701Z lightningd(20203): lightning_closingd(03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134): peer_in WIRE_CLOSING_SIGNED 
2018-02-09T13:08:32.701Z lightningd(20203): lightning_closingd(03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134): Making close tx at = 9665336/334663 fee 350 
2018-02-09T13:08:32.702Z lightningd(20203): lightning_closingd(03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134): Received fee offer 350 
2018-02-09T13:08:32.702Z lightningd(20203): lightning_closingd(03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134): ...offer is reasonable 
2018-02-09T13:08:32.702Z lightningd(20203): peer 03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134: Their actual closing tx fee is 351 vs previous 9665337
2018-02-09T13:08:32.702Z lightningd(20203): peer 03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134: ... That's closer to our ideal 300 2018-02-09T13:08:32.726Z lightningd(20203): lightning_closingd(03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134): SENT ERROR:remote offer 350 not between 351 and 351
2018-02-09T13:08:32.726Z lightningd(20203): lightning_closingd(03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134): peer_out WIRE_ERROR
2018-02-09T13:08:32.726Z lightningd(20203): peer 03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134: Peer permanent failure in CLOSINGD_SIGEXCHANGE: lightning_closingd: sent ERROR remote offer 350 not between 351 and 351
2018-02-09T13:08:32.726Z lightningd(20203): (tx 897da30d7112da2b84215a51122a3e36c762eead64cefdf7c1c1a29539f31cbf)

Answer 1 · 2018-02-09T13:23:50.000Z

Ping @rustyrussell and @sstone

Answer 2 · 2018-02-13T14:16:47.000Z

Yes it's possible. We have not implemented this change yet and are working on improving how we handle the closing of channels.