Concurrency issue with update_fee (round 2)

[pm47]

Background

This seems to be the exact opposite of #2348: lnd sends an update_fee, signs it, and eclair ackowledges the new signature. On reconnect, eclair (lawfully) applies the new fee, but lnd rejects it.

I don't know the version of lnd, but I see this a lot so there is a good chance it is in the latest released version.

  eclair              lnd
    |                  |
    |<-----fee-1-------|
    |<-----sig-23------|
    |------rev-22----->|
    |------sig-23----->|
    |<-----rev-22------|
    |                  | <- idle, no pending changes, fee=fee-1
    |                  |
    |<------fee-2------|
    |<-----sig-24------|
    |------rev-23----->|
    |------sig-24--> ? | <- lnd is unresponsive, eclair disconnects
    |                  |
    |                  |
    |---reestablish--->|
    |<--reestablish----| <- `next_local_commitment_number`=24 and `next_remote_revocation_number`=24 so lnd has received rev-23 but not sig-24
    |<-----sig-24------| <- eclair resends sig-24
    |<------err--------| <- lnd rejects, looking at the tx embedded in the error message it was (wrongly) expecting fee-1
    |                  |

Interestingly I filed the same bug a few days ago in c-lightning (ElementsProject/lightning#2661), but I double and triple checked and pretty sure eclair is doing the right thing here.

Relevant logs:

2019-05-25 13:44:45,064 INFO  f.a.eclair.Diagnostics - IN msg=UpdateFee(c6890266e62d811463f113772b1322742790896ea2f104d559db2d739c5be118,30782)
2019-05-25 13:44:45,100 INFO  f.a.eclair.Diagnostics - IN msg=CommitSig(c6890266e62d811463f113772b1322742790896ea2f104d559db2d739c5be118,cc06b4a935d869845e9c27262a82360e1311c0cdf67ecb3e2df691f8cd4e6baf389c5062a8794fecc268923df9ac5836c4453b527de4e94cb0de584e5d2c74ca,List())
2019-05-25 13:44:45,103 INFO  f.a.e.channel.Channel - built local commit number=22 htlc_in= htlc_out= feeratePerKw=30782 txid=b3099c8c80bea173b2b3bb16452a81a8003826ba3f8f00fb370abfa6d4365f6c tx=0200000001c6890266e62d811463f113772b1322742790896ea2f104d559db2d739c5be1190100000000c11ee18001922f0100000000001600145cbaae00c6bffe7f27b0b79f4f052dc739acaa4d1704e320
2019-05-25 13:44:45,109 INFO  f.a.eclair.Diagnostics - OUT msg=RevokeAndAck(c6890266e62d811463f113772b1322742790896ea2f104d559db2d739c5be118,06b6e486f13f9c62293114e74ee8a0043b57c39c739b6ec89ada313bebeb11da,028d7a424fc3c34dee776b4441654eca1fcdf4355988212b7b114c92f69f79d999)
2019-05-25 13:44:45,110 INFO  f.a.e.channel.Channel - built remote commit number=22 htlc_in= htlc_out= feeratePerKw=30782 txid=9b1eb21240f0bd890524efcd46269e2b115d9d8af6353b9de87ba28518ebe390 tx=0200000001c6890266e62d811463f113772b1322742790896ea2f104d559db2d739c5be1190100000000c11ee18001922f0100000000002200206170efdfdab87a67117631ea695f54a8554114a249b2f8c6a9bce1eae9e857f31704e320
2019-05-25 13:44:45,196 INFO  f.a.eclair.Diagnostics - OUT msg=CommitSig(c6890266e62d811463f113772b1322742790896ea2f104d559db2d739c5be118,549e6f9532fc3654b8083a3999a7d7b5bf71a831d8e2bd248de8a02b383a218f4ffdf16ebe3cbfbd936aa4ca42a6376951ef99f12620a52725c20029637c5fb7,List())
2019-05-25 13:44:45,342 INFO  f.a.eclair.Diagnostics - IN msg=RevokeAndAck(c6890266e62d811463f113772b1322742790896ea2f104d559db2d739c5be118,f504f16d86fce4e5fc36a2bdd4707557f118daa5785aa684aff86b987eb78535,02477341fc1d3bd539c56074b412e25301e1ca93058af2a5e7aca7a05bde82faae)
2019-05-25 14:56:19,225 INFO  f.a.eclair.Diagnostics - IN msg=UpdateFee(c6890266e62d811463f113772b1322742790896ea2f104d559db2d739c5be118,37322)
2019-05-25 14:56:19,315 INFO  f.a.eclair.Diagnostics - IN msg=CommitSig(c6890266e62d811463f113772b1322742790896ea2f104d559db2d739c5be118,05c734980a5a23482d1d12e80642b27e06c0a7e02ac2b7a3c0f81a23821fc1497a893e0b1b46b38dd5512edef5bf21bdaa3f0412ccb1ffef4601b27a65e298b4,List())
2019-05-25 14:56:19,316 INFO  f.a.e.channel.Channel - built local commit number=23 htlc_in= htlc_out= feeratePerKw=37322 txid=847e7c1a7c592885c6d37dfa79f3ac93dddc5c4a3c1b8aa54bc239cb4fca1480 tx=0200000001c6890266e62d811463f113772b1322742790896ea2f104d559db2d739c5be1190100000000c11ee18001131d010000000000160014dfa3b8380d1ae474d1c5a7b2e9f11086e4a7f15c1604e320
2019-05-25 14:56:19,322 INFO  f.a.eclair.Diagnostics - OUT msg=RevokeAndAck(c6890266e62d811463f113772b1322742790896ea2f104d559db2d739c5be118,920f2895d69c631e1433ddb9adfc037de35d9a86b3f71f0899c5c063e07c255d,034eaf50761003da9e53e968aa9ab34d8675861200b7c2e79a3e0ce51bf6fe04c3)
2019-05-25 14:56:19,323 INFO  f.a.e.channel.Channel - built remote commit number=23 htlc_in= htlc_out= feeratePerKw=37322 txid=0de8679b3172c03759723939fbb1cae0900e9182b56f1968e82334961339cb13 tx=0200000001c6890266e62d811463f113772b1322742790896ea2f104d559db2d739c5be1190100000000c11ee18001131d010000000000220020f0d2c99d6ac4383ada27f6285b5ff46139221ea9ebad15ae1336e35b5a6845af1604e320
2019-05-25 14:56:19,429 INFO  f.a.eclair.Diagnostics - OUT msg=CommitSig(c6890266e62d811463f113772b1322742790896ea2f104d559db2d739c5be118,7adcacad046cbe8615161efce2192238e9a439baece5c1078eb89529fd618c1c2fb145de17b15a66ff195c64c0b42ca5710b5a40a49150a96a36bd19d23ebb6c,List())
2019-05-25 14:56:20,843 INFO  f.a.eclair.Diagnostics - IN msg=RevokeAndAck(c6890266e62d811463f113772b1322742790896ea2f104d559db2d739c5be118,0ad360364b20e2739f1de74a0c2bfda37a79ccaa234cfe420825097132b6a54d,0316aaa44aa352159a49ef53bb269a60c40df3ce4f3212b8c023829db1dea211ea)
2019-05-27 08:40:02,988 INFO  f.a.eclair.Diagnostics - IN msg=UpdateFee(c6890266e62d811463f113772b1322742790896ea2f104d559db2d739c5be118,32146)
2019-05-27 08:47:45,187 INFO  f.a.eclair.Diagnostics - IN msg=CommitSig(c6890266e62d811463f113772b1322742790896ea2f104d559db2d739c5be118,5c08259180c9220778d88d5d3e756927d03cccf1b64b275aa53f51c6f707c5e118ee5fb01188f96943f101f7159985d242cdc39e9f80954aa22cc8be1c82b84d,List())
2019-05-27 08:47:45,190 INFO  f.a.e.channel.Channel - built local commit number=24 htlc_in= htlc_out= feeratePerKw=32146 txid=cea38699db293c62341680b44ff04dd35d02f42ac649f24217f99e9a6cca18a3 tx=0200000001c6890266e62d811463f113772b1322742790896ea2f104d559db2d739c5be1190100000000c11ee18001b72b010000000000160014f538e39af5fe191be234651d4443f62db34c83871904e320
2019-05-27 08:47:45,198 INFO  f.a.eclair.Diagnostics - OUT msg=RevokeAndAck(c6890266e62d811463f113772b1322742790896ea2f104d559db2d739c5be118,afd2197e1c64af22ad21a888794550c2fd8cf2fba35202068dc1b93b0454ac2c,0243658b3022b91f368c19214e9d87878b06d5b6875b693f35233c32c3f618e526)
2019-05-27 08:47:45,199 INFO  f.a.e.channel.Channel - built remote commit number=24 htlc_in= htlc_out= feeratePerKw=32146 txid=a68c971f997ff655d5ae1c286e9a06a63f72f610a255ba3a6efeee84cec15328 tx=0200000001c6890266e62d811463f113772b1322742790896ea2f104d559db2d739c5be1190100000000c11ee18001b72b0100000000002200206077168d3084111eda2ac103d9c30acc5bd550e8cdfe36c794e11a11bf6f5ada1904e320
2019-05-27 08:47:45,313 INFO  f.a.eclair.Diagnostics - OUT msg=CommitSig(c6890266e62d811463f113772b1322742790896ea2f104d559db2d739c5be118,b722ad364b41d97e265ce5e67d5047b7d7b8e29381b33c9e67d939efa91b35e4649a623fbb279ef9af096b6501cf8a2e0305a11c43c2af2f374fd7465f50283e,List())
2019-05-27 08:48:05,218 WARN  f.a.e.channel.Channel - waited for too long for a revocation to remoteCommitNumber=23, disconnecting
2019-05-27 08:50:57,832 INFO  f.a.eclair.Diagnostics - OUT msg=ChannelReestablish(c6890266e62d811463f113772b1322742790896ea2f104d559db2d739c5be118,25,23,Some(0ad360364b20e2739f1de74a0c2bfda37a79ccaa234cfe420825097132b6a54d),Some(034eaf50761003da9e53e968aa9ab34d8675861200b7c2e79a3e0ce51bf6fe04c3))
2019-05-27 08:51:23,544 INFO  f.a.eclair.Diagnostics - IN msg=ChannelReestablish(c6890266e62d811463f113772b1322742790896ea2f104d559db2d739c5be118,24,24,Some(afd2197e1c64af22ad21a888794550c2fd8cf2fba35202068dc1b93b0454ac2c),Some(02477341fc1d3bd539c56074b412e25301e1ca93058af2a5e7aca7a05bde82faae))
2019-05-27 08:51:23,544 INFO  f.a.eclair.Diagnostics - OUT msg=CommitSig(c6890266e62d811463f113772b1322742790896ea2f104d559db2d739c5be118,b722ad364b41d97e265ce5e67d5047b7d7b8e29381b33c9e67d939efa91b35e4649a623fbb279ef9af096b6501cf8a2e0305a11c43c2af2f374fd7465f50283e,List())
2019-05-27 08:51:33,559 INFO  f.a.e.channel.Channel - not sending a new identical channel_update, current one was created 7 days ago
2019-05-27 08:51:43,559 WARN  f.a.e.channel.Channel - waited for too long for a revocation to remoteCommitNumber=23, disconnecting
2019-05-27 08:52:12,047 INFO  f.a.eclair.Diagnostics - OUT msg=ChannelReestablish(c6890266e62d811463f113772b1322742790896ea2f104d559db2d739c5be118,25,23,Some(0ad360364b20e2739f1de74a0c2bfda37a79ccaa234cfe420825097132b6a54d),Some(034eaf50761003da9e53e968aa9ab34d8675861200b7c2e79a3e0ce51bf6fe04c3))
2019-05-27 08:52:13,764 INFO  f.a.eclair.Diagnostics - IN msg=ChannelReestablish(c6890266e62d811463f113772b1322742790896ea2f104d559db2d739c5be118,24,24,Some(afd2197e1c64af22ad21a888794550c2fd8cf2fba35202068dc1b93b0454ac2c),Some(02477341fc1d3bd539c56074b412e25301e1ca93058af2a5e7aca7a05bde82faae))
2019-05-27 08:52:13,764 INFO  f.a.eclair.Diagnostics - OUT msg=CommitSig(c6890266e62d811463f113772b1322742790896ea2f104d559db2d739c5be118,b722ad364b41d97e265ce5e67d5047b7d7b8e29381b33c9e67d939efa91b35e4649a623fbb279ef9af096b6501cf8a2e0305a11c43c2af2f374fd7465f50283e,List())
2019-05-27 08:52:23,779 INFO  f.a.e.channel.Channel - not sending a new identical channel_update, current one was created 7 days ago
2019-05-27 08:52:33,270 INFO  f.a.eclair.Diagnostics - IN msg=Error(c6890266e62d811463f113772b1322742790896ea2f104d559db2d739c5be118,ByteVector(475 bytes, 0x72656a656374656420636f6d6d69746d656e743a20636f6d6d69745f6865696768743d32342c20696e76616c69645f636f6d6d69745f7369673d333034353032323130306237323261643336346234316439376532363563653565363764353034376237643762386532393338316233336339653637643933396566613931623335653430323230363439613632336662623237396566396166303936623635303163663861326530333035613131633433633261663266333734666437343635663530323833652c20636f6d6d69745f74783d30323030303030303031633638393032363665363264383131343633663131333737326231333232373432373930383936656132663130346435353964623264373339633562653131393031303030303030303063313165653138303031313331643031303030303030303030303232303032303630373731363864333038343131316564613261633130336439633330616363356264353530653863646665333663373934653131613131626636663561646131393034653332302c207369675f686173683d66373366336461393931323762643064356635616431653033386530373232383236393737373762363536383164313866393539636238346333306662643331))
2019-05-27 08:52:33,270 ERROR f.a.e.channel.Channel - peer sent error: ascii='rejected commitment: commit_height=24, invalid_commit_sig=3045022100b722ad364b41d97e265ce5e67d5047b7d7b8e29381b33c9e67d939efa91b35e40220649a623fbb279ef9af096b6501cf8a2e0305a11c43c2af2f374fd7465f50283e, commit_tx=0200000001c6890266e62d811463f113772b1322742790896ea2f104d559db2d739c5be1190100000000c11ee18001131d0100000000002200206077168d3084111eda2ac103d9c30acc5bd550e8cdfe36c794e11a11bf6f5ada1904e320, sig_hash=f73f3da99127bd0d5f5ad1e038e072282697777b65681d18f959cb84c30fbd31' bin=72656a656374656420636f6d6d69746d656e743a20636f6d6d69745f6865696768743d32342c20696e76616c69645f636f6d6d69745f7369673d333034353032323130306237323261643336346234316439376532363563653565363764353034376237643762386532393338316233336339653637643933396566613931623335653430323230363439613632336662623237396566396166303936623635303163663861326530333035613131633433633261663266333734666437343635663530323833652c20636f6d6d69745f74783d30323030303030303031633638393032363665363264383131343633663131333737326231333232373432373930383936656132663130346435353964623264373339633562653131393031303030303030303063313165653138303031313331643031303030303030303030303232303032303630373731363864333038343131316564613261633130336439633330616363356264353530653863646665333663373934653131613131626636663561646131393034653332302c207369675f686173683d66373366336461393931323762643064356635616431653033386530373232383236393737373762363536383164313866393539636238346333306662643331

[Roasbeef]

|<-----sig-24------| <- eclair resends sig-24

Shouldn't eclair re-send the fee-update 2 before sending this signature? Or was this just omitted from the sequence?

Yeah it seems we should be expecting the signature with the latest fee there.

[halseth]

Sounds wrong indeed. @pm47 if you run into this with a known version of lnd that would help a lot 🙏