Browse Source
I just had a channel force-closed over a fee-estimate-disagreement :(
Scenario:
1. started electrum, opened wallet
2. waited around 10 seconds, opened the lightning channels overview, saw that channels are open/ready
3. after around 10 more seconds, scanned bolt11 invoice and tried to pay
4. channel got force-closed
Before this commit, we only call maybe_update_fee via lnwatcher callbacks.
These callbacks trigger on events such as "adb_set_up_to_date", "blockchain_updated", "network_updated", "fee".
In my case there was a race that all these events triggered *before* the channel got reestablished
(in fact before the peer handshake finished). And also, by chance there were none of these events after
the reestablish but before I sent the HTLC.
When I sent the HTLC, the channel counterparty (eclair) sent back an "error" msg that the feerates are
too different, which led us to do a local-force-close.
I have other channels in this wallet (with other peers), which reestablished faster and got lucky with
timing: the lnwatcher callbacks came just in time to trigger update_fee for them.
```
20241017T222847.598163Z | INFO | lnpeer.Peer.[LNWallet, 03ecef675b-98960573] | handshake done for 03ecef675be448b615e6176424070673ef8284e0fd19d8be062a6cb5b130a0a0d1@lightning.electrum.org:9740
20241017T222847.602594Z | DEBUG | lnpeer.Peer.[LNWallet, 03ecef675b-98960573] | Sending INIT
20241017T222847.641383Z | DEBUG | lnpeer.Peer.[LNWallet, 03ecef675b-98960573] | Received INIT
20241017T222847.655041Z | DEBUG | lnpeer.Peer.[LNWallet, 03ecef675b-98960573] | Sending CHANNEL_REESTABLISH
20241017T222847.658355Z | INFO | lnpeer.Peer.[LNWallet, 03ecef675b-98960573] | channel_reestablish (<redacted_shortchanid>): sent channel_reestablish with (next_local_ctn=157, oldest_unrevoked_remote_ctn=156)
20241017T222847.659524Z | INFO | lnpeer.Peer.[LNWallet, 03ecef675b-98960573] | reestablish_channel was called but channel <redacted_shortchanid> already in peer_state <PeerState.REESTABLISHING: 1>
20241017T222847.660491Z | INFO | lnpeer.Peer.[LNWallet, 03ecef675b-98960573] | reestablish_channel was called but channel <redacted_shortchanid> already in peer_state <PeerState.REESTABLISHING: 1>
20241017T222847.661442Z | INFO | lnpeer.Peer.[LNWallet, 03ecef675b-98960573] | reestablish_channel was called but channel <redacted_shortchanid> already in peer_state <PeerState.REESTABLISHING: 1>
20241017T222847.662768Z | INFO | lnpeer.Peer.[LNWallet, 03ecef675b-98960573] | reestablish_channel was called but channel <redacted_shortchanid> already in peer_state <PeerState.REESTABLISHING: 1>
20241017T222847.669875Z | DEBUG | lnpeer.Peer.[LNWallet, 03ecef675b-98960573] | Received QUERY_CHANNEL_RANGE
20241017T222847.690318Z | DEBUG | lnpeer.Peer.[LNWallet, 03ecef675b-98960573] | Received GOSSIP_TIMESTAMP_FILTER
20241017T222847.705782Z | DEBUG | lnpeer.Peer.[LNWallet, 03ecef675b-98960573] | Received CHANNEL_REESTABLISH
20241017T222847.707932Z | INFO | lnpeer.Peer.[LNWallet, 03ecef675b-98960573] | channel_reestablish (<redacted_shortchanid>): received channel_reestablish with (their_next_local_ctn=157, their_oldest_unrevoked_remote_ctn=156)
20241017T222847.712504Z | INFO | lnpeer.Peer.[LNWallet, 03ecef675b-98960573] | channel_reestablish (<redacted_shortchanid>): replayed 0 unacked messages. []
20241017T222847.716096Z | DEBUG | lnpeer.Peer.[LNWallet, 03ecef675b-98960573] | Sending CHANNEL_READY
20241017T222847.738709Z | INFO | lnpeer.Peer.[LNWallet, 03ecef675b-98960573] | saved remote channel_update gossip msg for chan <redacted_shortchanid>
20241017T222907.627447Z | INFO | lnpeer.Peer.[LNWallet, 03ecef675b-98960573] | lnpeer.pay len(route)=1
20241017T222907.628927Z | INFO | lnpeer.Peer.[LNWallet, 03ecef675b-98960573] | 0: edge=<redacted_shortchanid> hop_data=<OnionHopsDataSingle. payload={<redacted>}. hmac=None>
20241017T222907.629184Z | INFO | lnpeer.Peer.[LNWallet, 03ecef675b-98960573] | adding trampoline onion to final payload
20241017T222907.629405Z | INFO | lnpeer.Peer.[LNWallet, 03ecef675b-98960573] | lnpeer.pay len(t_route)=2
20241017T222907.629653Z | INFO | lnpeer.Peer.[LNWallet, 03ecef675b-98960573] | 0: t_node=03ecef675be448b615e6176424070673ef8284e0fd19d8be062a6cb5b130a0a0d1 hop_data=<OnionHopsDataSingle. payload={<redacted>}. hmac=<redacted>>
20241017T222907.629894Z | INFO | lnpeer.Peer.[LNWallet, 03ecef675b-98960573] | 1: t_node=<redacted> hop_data=<OnionHopsDataSingle. payload={<redacted>}. hmac=b'\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00'>
20241017T222907.631495Z | INFO | lnpeer.Peer.[LNWallet, 03ecef675b-98960573] | starting payment. len(route)=1.
20241017T222907.633075Z | INFO | lnpeer.Peer.[LNWallet, 03ecef675b-98960573] | starting payment. htlc: UpdateAddHtlc(amount_msat=<redacted>, payment_hash=<redacted>, cltv_abs=<redacted>, timestamp=1729204147, htlc_id=66)
20241017T222907.633385Z | DEBUG | lnpeer.Peer.[LNWallet, 03ecef675b-98960573] | Sending UPDATE_ADD_HTLC
20241017T222907.635118Z | INFO | lnpeer.Peer.[LNWallet, 03ecef675b-98960573] | send_commitment. chan <redacted_shortchanid>. ctn: 157.
20241017T222907.643229Z | DEBUG | lnpeer.Peer.[LNWallet, 03ecef675b-98960573] | Sending COMMITMENT_SIGNED
20241017T222907.721929Z | DEBUG | lnpeer.Peer.[LNWallet, 03ecef675b-98960573] | Received ERROR
20241017T222907.722621Z | INFO | lnpeer.Peer.[LNWallet, 03ecef675b-98960573] | remote peer sent error [DO NOT TRUST THIS MESSAGE]: 'local/remote feerates are too different: remoteFeeratePerKw=<redacted_low_val> localFeeratePerKw=50125'. chan_id=<redacted>. is_known_chan_id=True
20241017T222907.734272Z | DEBUG | lnchannel.Channel.[<redacted_shortchanid>] | Setting channel state: OPEN -> FORCE_CLOSING
20241017T222907.825540Z | INFO | lnpeer.Peer.[LNWallet, 03ecef675b-98960573] | Disconnecting: GracefulDisconnect()
```
master
1 changed files with 3 additions and 0 deletions
Loading…
Reference in new issue