search

lightningnetwork / lnd

Lightning Network Daemon ⚡️
MIT License
7.65k stars 2.07k forks source link

[bug]: channel inactive but online #7756

Closed mariodian closed 6 months ago

mariodian commented 1 year ago

Background

One of the channels I opened long time ago has been showing as inactive for a few weeks now. I can't find the node in lncli peers but it seems to be alive and well (it's blockstream store). I get disconnected from it every time I try connecting either automatically or manually.

Your environment

Steps to reproduce

$ lncli connect 02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f@giexynrrloc2fewstcybenljdksidtglfydecbellzkl63din6w73eid.onion:9735 |  tail -f ~/.lnd/logs/bitcoin/mainnet/lnd.log

Finalizing connection to 02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f@127.0.0.1:49756, inbound=true
2023-06-11 14:16:10.233 [INF] PEER: Peer(02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f): loading ChannelPoint(3e37348c79282a149f48eae6c51548b01e0064f5e7d8903fe7f4ca911855c278:1)
2023-06-11 14:16:10.233 [INF] HSWC: ChannelLink(3e37348c79282a149f48eae6c51548b01e0064f5e7d8903fe7f4ca911855c278:1): starting
2023-06-11 14:16:10.233 [INF] HSWC: Trimming open circuits for chan_id=689862:1669:1, start_htlc_id=224
2023-06-11 14:16:10.233 [INF] HSWC: Adding live link chan_id=78c2551891caf4e73f90d8e7f564001eb04815c5e6ea489f142a28798c34373f, short_chan_id=689862:1669:1
2023-06-11 14:16:10.234 [INF] NTFN: New block epoch subscription
2023-06-11 14:16:10.233 [INF] HSWC: ChannelLink(3e37348c79282a149f48eae6c51548b01e0064f5e7d8903fe7f4ca911855c278:1): HTLC manager started, bandwidth=7819940195 mSAT
2023-06-11 14:16:10.234 [INF] HSWC: ChannelLink(3e37348c79282a149f48eae6c51548b01e0064f5e7d8903fe7f4ca911855c278:1): attempting to re-synchronize
2023-06-11 14:16:10.234 [INF] PEER: Peer(02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f): Negotiated chan series queries
2023-06-11 14:16:10.233 [INF] CNCT: Attempting to update ContractSignals for ChannelPoint(3e37348c79282a149f48eae6c51548b01e0064f5e7d8903fe7f4ca911855c278:1)
2023-06-11 14:16:11.351 [INF] HSWC: ChannelLink(3e37348c79282a149f48eae6c51548b01e0064f5e7d8903fe7f4ca911855c278:1): received re-establishment message from remote side
2023-06-11 14:16:11.359 [INF] HSWC: ChannelLink(3e37348c79282a149f48eae6c51548b01e0064f5e7d8903fe7f4ca911855c278:1): sending 2 updates to synchronize the state
2023-06-11 14:16:12.213 [INF] PEER: Peer(02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f): unable to read message from peer: EOF
2023-06-11 14:16:12.213 [INF] PEER: Peer(02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f): disconnecting 02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f@127.0.0.1:49756, reason: read handler closed
2023-06-11 14:16:12.214 [INF] NTFN: Cancelling epoch notification, epoch_id=1099
2023-06-11 14:16:12.414 [INF] HSWC: ChannelLink(3e37348c79282a149f48eae6c51548b01e0064f5e7d8903fe7f4ca911855c278:1): stopping
2023-06-11 14:16:12.414 [INF] HSWC: ChannelLink(3e37348c79282a149f48eae6c51548b01e0064f5e7d8903fe7f4ca911855c278:1): exited
2023-06-11 14:16:12.414 [INF] HSWC: Removing channel link with ChannelID(78c2551891caf4e73f90d8e7f564001eb04815c5e6ea489f142a28798c34373f)
$ lncli listchannels --inactive_only

{
    "channels": [
        {
            "active": false,
            "remote_pubkey": "02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f",
            "channel_point": "3e37348c79282a149f48eae6c51548b01e0064f5e7d8903fe7f4ca911855c278:1",
            "chan_id": "758511290670186497",
            "capacity": "8000000",
            "local_balance": "7890518",
            "remote_balance": "99833",
            "commit_fee": "9649",
            "commit_weight": "724",
            "fee_per_kw": "13326",
            "unsettled_balance": "0",
            "total_satoshis_sent": "1909115",
            "total_satoshis_received": "1809281",
            "num_updates": "6390",
            "pending_htlcs": [
            ],
            "csv_delay": 144,
            "private": false,
            "initiator": true,
            "chan_status_flags": "ChanStatusDefault",
            "local_chan_reserve_sat": "80000",
            "remote_chan_reserve_sat": "80000",
            "static_remote_key": true,
            "commitment_type": "STATIC_REMOTE_KEY",
            "lifetime": "325301",
            "uptime": "0",
            "close_address": "",
            "push_amount_sat": "0",
            "thaw_height": 0,
            "local_constraints": {
                "csv_delay": 144,
                "chan_reserve_sat": "80000",
                "dust_limit_sat": "573",
                "max_pending_amt_msat": "18446744073709551615",
                "min_htlc_msat": "0",
                "max_accepted_htlcs": 30
            },
            "remote_constraints": {
                "csv_delay": 961,
                "chan_reserve_sat": "80000",
                "dust_limit_sat": "546",
                "max_pending_amt_msat": "7920000000",
                "min_htlc_msat": "1",
                "max_accepted_htlcs": 483
            },
            "alias_scids": [
            ],
            "zero_conf": false,
            "zero_conf_confirmed_scid": "0"
        }
    ]
}
bitromortac commented 1 year ago

Thank you, I think the interesting line is

2023-06-11 14:16:11.359 [INF] HSWC: ChannelLink(3e37348c79282a149f48eae6c51548b01e0064f5e7d8903fe7f4ca911855c278:1): sending 2 updates to synchronize the state

Could you enable debug logs (lncli debuglevel --level debug), repeat the connection process and report those logs as well?

mariodian commented 1 year ago

Thank you, I think the interesting line is

2023-06-11 14:16:11.359 [INF] HSWC: ChannelLink(3e37348c79282a149f48eae6c51548b01e0064f5e7d8903fe7f4ca911855c278:1): sending 2 updates to synchronize the state

Indeed, although I have no idea what a zombie index means:

2023-06-13 15:11:14.429 [INF] HSWC: ChannelLink(3e37348c79282a149f48eae6c51548b01e0064f5e7d8903fe7f4ca911855c278:1): sending 2 updates to synchronize the state
2023-06-13 15:11:14.432 [DBG] HSWC: ChannelLink(3e37348c79282a149f48eae6c51548b01e0064f5e7d8903fe7f4ca911855c278:1): loaded 0 fwd pks
2023-06-13 15:11:14.432 [DBG] PEER: Peer(02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f): Sending UpdateFee(chan_id=78c2551891caf4e73f90d8e7f564001eb04815c5e6ea489f142a28798c34373f, fee_update_sat=253) to 02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f@giexynrrloc2fewstcybenljdksidtglfydecbellzkl63din6w73eid.onion:9735
2023-06-13 15:11:14.433 [DBG] PEER: Peer(02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f): Sending CommitSig(chan_id=78c2551891caf4e73f90d8e7f564001eb04815c5e6ea489f142a28798c34373f, num_htlcs=0) to 02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f@giexynrrloc2fewstcybenljdksidtglfydecbellzkl63din6w73eid.onion:9735
2023-06-13 15:11:14.433 [DBG] DISC: Removed edge with chan_id=769110:588:1 from zombie index
2023-06-13 15:11:14.434 [DBG] DISC: Got ChannelUpdate for edge not found in graph(shortChanID=845645388077334529), saving for reprocessing later
2023-06-13 15:11:14.442 [DBG] PEER: Peer(02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f): Received ChannelAnnouncement(chain_hash=000000000019d6689c085ae165831e934ff763ae46a2a6c172b3f1b60a8ce26f, short_chan_id=832311610619068416) from 02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f@giexynrrloc2fewstcybenljdksidtglfydecbellzkl63din6w73eid.onion:9735
2023-06-13 15:11:14.443 [DBG] PEER: Peer(02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f): Received ChannelUpdate(chain_hash=000000000019d6689c085ae165831e934ff763ae46a2a6c172b3f1b60a8ce26f, short_chan_id=832311610619068416, mflags=00000001, cflags=00000001, update_time=2023-05-31 19:33:47 +0800 CST) from 02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f@giexynrrloc2fewstcybenljdksidtglfydecbellzkl63din6w73eid.onion:9735
2023-06-13 15:11:14.443 [DBG] PEER: Peer(02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f): Received ChannelAnnouncement(chain_hash=000000000019d6689c085ae165831e934ff763ae46a2a6c172b3f1b60a8ce26f, short_chan_id=762972009373696001) from 02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f@giexynrrloc2fewstcybenljdksidtglfydecbellzkl63din6w73eid.onion:9735
2023-06-13 15:11:14.443 [DBG] DISC: Processing ChannelAnnouncement: peer=02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f@giexynrrloc2fewstcybenljdksidtglfydecbellzkl63din6w73eid.onion:9735, short_chan_id=832311610619068416
2023-06-13 15:11:14.443 [DBG] CRTR: Waiting for dependent on job=lnwire.ChannelUpdate, scid=832311610619068416
2023-06-13 15:11:14.445 [DBG] DISC: Processing ChannelUpdate: peer=02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f@giexynrrloc2fewstcybenljdksidtglfydecbellzkl63din6w73eid.onion:9735, short_chan_id=832311610619068416, 
2023-06-13 15:11:14.444 [DBG] PEER: Peer(02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f): Received ChannelUpdate(chain_hash=000000000019d6689c085ae165831e934ff763ae46a2a6c172b3f1b60a8ce26f, short_chan_id=762972009373696001, mflags=00000001, cflags=00000001, update_time=2023-05-31 19:22:01 +0800 CST) from 02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f@giexynrrloc2fewstcybenljdksidtglfydecbellzkl63din6w73eid.onion:9735
2023-06-13 15:11:14.445 [DBG] PEER: Peer(02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f): Received ChannelUpdate(chain_hash=000000000019d6689c085ae165831e934ff763ae46a2a6c172b3f1b60a8ce26f, short_chan_id=645626630834814977, mflags=00000001, cflags=00000000, update_time=2023-06-01 01:55:29 +0800 CST) from 02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f@giexynrrloc2fewstcybenljdksidtglfydecbellzkl63din6w73eid.onion:9735
2023-06-13 15:11:14.446 [DBG] PEER: Peer(02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f): Received ChannelUpdate(chain_hash=000000000019d6689c085ae165831e934ff763ae46a2a6c172b3f1b60a8ce26f, short_chan_id=850594290052235264, mflags=00000001, cflags=00000001, update_time=2023-06-01 11:44:57 +0800 CST) from 02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f@giexynrrloc2fewstcybenljdksidtglfydecbellzkl63din6w73eid.onion:9735
2023-06-13 15:11:14.444 [DBG] DISC: Processing ChannelAnnouncement: peer=02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f@giexynrrloc2fewstcybenljdksidtglfydecbellzkl63din6w73eid.onion:9735, short_chan_id=762972009373696001
2023-06-13 15:11:14.446 [DBG] DISC: Processing ChannelUpdate: peer=02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f@giexynrrloc2fewstcybenljdksidtglfydecbellzkl63din6w73eid.onion:9735, short_chan_id=645626630834814977, 
2023-06-13 15:11:14.446 [DBG] CRTR: Waiting for dependent on job=lnwire.ChannelUpdate, scid=762972009373696001
2023-06-13 15:11:14.446 [DBG] DISC: Processing ChannelUpdate: peer=02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f@giexynrrloc2fewstcybenljdksidtglfydecbellzkl63din6w73eid.onion:9735, short_chan_id=850594290052235264, 
2023-06-13 15:11:14.446 [DBG] PEER: Peer(02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f): Received ChannelUpdate(chain_hash=000000000019d6689c085ae165831e934ff763ae46a2a6c172b3f1b60a8ce26f, short_chan_id=848805384547860481, mflags=00000001, cflags=00000000, update_time=2023-06-01 21:50:29 +0800 CST) from 02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f@giexynrrloc2fewstcybenljdksidtglfydecbellzkl63din6w73eid.onion:9735
2023-06-13 15:11:14.447 [DBG] DISC: Removed edge with chan_id=756983:1378:0 from zombie index
2023-06-13 15:11:14.447 [DBG] DISC: Got ChannelUpdate for edge not found in graph(shortChanID=832311610619068416), saving for reprocessing later
2023-06-13 15:11:14.447 [DBG] DISC: Processing ChannelUpdate: peer=02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f@giexynrrloc2fewstcybenljdksidtglfydecbellzkl63din6w73eid.onion:9735, short_chan_id=848805384547860481, 
2023-06-13 15:11:14.447 [DBG] DISC: Processing ChannelUpdate: peer=02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f@giexynrrloc2fewstcybenljdksidtglfydecbellzkl63din6w73eid.onion:9735, short_chan_id=762972009373696001, 
2023-06-13 15:11:14.449 [DBG] DISC: Removed edge with chan_id=587194:1137:1 from zombie index
2023-06-13 15:11:14.449 [DBG] DISC: Ignored stale edge policy for short_chan_id(848805384547860481): peer=02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f@giexynrrloc2fewstcybenljdksidtglfydecbellzkl63din6w73eid.onion:9735, msg=ChannelUpdate, is_remote=true
2023-06-13 15:11:14.449 [DBG] DISC: Got ChannelUpdate for edge not found in graph(shortChanID=645626630834814977), saving for reprocessing later
2023-06-13 15:11:14.450 [DBG] DISC: Removed edge with chan_id=773611:2698:0 from zombie index
2023-06-13 15:11:14.450 [DBG] DISC: Got ChannelUpdate for edge not found in graph(shortChanID=850594290052235264), saving for reprocessing later
2023-06-13 15:11:14.451 [DBG] DISC: Removed edge with chan_id=693919:2121:1 from zombie index
2023-06-13 15:11:14.452 [DBG] DISC: Got ChannelUpdate for edge not found in graph(shortChanID=762972009373696001), saving for reprocessing later
2023-06-13 15:11:14.458 [DBG] HSWC: Sent 1909115 satoshis and received 1809281 satoshis in the last 10 seconds (639.000000 tx/sec)
2023-06-13 15:11:14.486 [DBG] PEER: Peer(02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f): Received ChannelUpdate(chain_hash=000000000019d6689c085ae165831e934ff763ae46a2a6c172b3f1b60a8ce26f, short_chan_id=823661752678547457, mflags=00000001, cflags=00000001, update_time=2023-06-02 09:10:35 +0800 CST) from 02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f@giexynrrloc2fewstcybenljdksidtglfydecbellzkl63din6w73eid.onion:9735
2023-06-13 15:11:14.486 [DBG] PEER: Peer(02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f): Received ChannelUpdate(chain_hash=000000000019d6689c085ae165831e934ff763ae46a2a6c172b3f1b60a8ce26f, short_chan_id=801991477978726402, mflags=00000001, cflags=00000001, update_time=2023-06-02 20:50:54 +0800 CST) from 02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f@giexynrrloc2fewstcybenljdksidtglfydecbellzkl63din6w73eid.onion:9735
2023-06-13 15:11:14.487 [DBG] PEER: Peer(02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f): Received ChannelUpdate(chain_hash=000000000019d6689c085ae165831e934ff763ae46a2a6c172b3f1b60a8ce26f, short_chan_id=755117098304667649, mflags=00000001, cflags=00000001, update_time=2023-06-02 22:28:36 +0800 CST) from 02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f@giexynrrloc2fewstcybenljdksidtglfydecbellzkl63din6w73eid.onion:9735
2023-06-13 15:11:14.487 [DBG] PEER: Peer(02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f): Received ChannelUpdate(chain_hash=000000000019d6689c085ae165831e934ff763ae46a2a6c172b3f1b60a8ce26f, short_chan_id=823864062870814720, mflags=00000001, cflags=00000001, update_time=2023-06-03 06:51:03 +0800 CST) from 02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f@giexynrrloc2fewstcybenljdksidtglfydecbellzkl63din6w73eid.onion:9735
2023-06-13 15:11:14.488 [DBG] PEER: Peer(02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f): Received ChannelUpdate(chain_hash=000000000019d6689c085ae165831e934ff763ae46a2a6c172b3f1b60a8ce26f, short_chan_id=745207199950766080, mflags=00000001, cflags=00000001, update_time=2023-06-04 03:52:20 +0800 CST) from 02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f@giexynrrloc2fewstcybenljdksidtglfydecbellzkl63din6w73eid.onion:9735
2023-06-13 15:11:14.487 [DBG] DISC: Processing ChannelUpdate: peer=02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f@giexynrrloc2fewstcybenljdksidtglfydecbellzkl63din6w73eid.onion:9735, short_chan_id=823661752678547457, 
2023-06-13 15:11:14.487 [DBG] DISC: Processing ChannelUpdate: peer=02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f@giexynrrloc2fewstcybenljdksidtglfydecbellzkl63din6w73eid.onion:9735, short_chan_id=801991477978726402, 
2023-06-13 15:11:14.487 [DBG] DISC: Processing ChannelUpdate: peer=02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f@giexynrrloc2fewstcybenljdksidtglfydecbellzkl63din6w73eid.onion:9735, short_chan_id=755117098304667649, 
2023-06-13 15:11:14.489 [DBG] DISC: Ignored stale edge policy for short_chan_id(755117098304667649): peer=02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f@giexynrrloc2fewstcybenljdksidtglfydecbellzkl63din6w73eid.onion:9735, msg=ChannelUpdate, is_remote=true
2023-06-13 15:11:14.488 [DBG] DISC: Processing ChannelUpdate: peer=02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f@giexynrrloc2fewstcybenljdksidtglfydecbellzkl63din6w73eid.onion:9735, short_chan_id=823864062870814720, 
2023-06-13 15:11:14.488 [DBG] PEER: Peer(02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f): Received ChannelUpdate(chain_hash=000000000019d6689c085ae165831e934ff763ae46a2a6c172b3f1b60a8ce26f, short_chan_id=809695755924406272, mflags=00000001, cflags=00000001, update_time=2023-06-04 07:32:18 +0800 CST) from 02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f@giexynrrloc2fewstcybenljdksidtglfydecbellzkl63din6w73eid.onion:9735
2023-06-13 15:11:14.490 [DBG] DISC: Processing ChannelUpdate: peer=02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f@giexynrrloc2fewstcybenljdksidtglfydecbellzkl63din6w73eid.onion:9735, short_chan_id=809695755924406272, 
2023-06-13 15:11:14.488 [DBG] DISC: Processing ChannelUpdate: peer=02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f@giexynrrloc2fewstcybenljdksidtglfydecbellzkl63din6w73eid.onion:9735, short_chan_id=745207199950766080, 
2023-06-13 15:11:14.488 [DBG] DISC: Ignored stale edge policy for short_chan_id(823661752678547457): peer=02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f@giexynrrloc2fewstcybenljdksidtglfydecbellzkl63din6w73eid.onion:9735, msg=ChannelUpdate, is_remote=true
2023-06-13 15:11:14.488 [DBG] DISC: Ignored stale edge policy for short_chan_id(801991477978726402): peer=02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f@giexynrrloc2fewstcybenljdksidtglfydecbellzkl63din6w73eid.onion:9735, msg=ChannelUpdate, is_remote=true
2023-06-13 15:11:14.491 [DBG] PEER: Peer(02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f): Received ChannelUpdate(chain_hash=000000000019d6689c085ae165831e934ff763ae46a2a6c172b3f1b60a8ce26f, short_chan_id=865073758518837249, mflags=00000001, cflags=00000001, update_time=2023-06-04 07:32:18 +0800 CST) from 02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f@giexynrrloc2fewstcybenljdksidtglfydecbellzkl63din6w73eid.onion:9735
2023-06-13 15:11:14.491 [DBG] DISC: Processing ChannelUpdate: peer=02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f@giexynrrloc2fewstcybenljdksidtglfydecbellzkl63din6w73eid.onion:9735, short_chan_id=865073758518837249, 
2023-06-13 15:11:14.491 [DBG] PEER: Peer(02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f): Received ChannelUpdate(chain_hash=000000000019d6689c085ae165831e934ff763ae46a2a6c172b3f1b60a8ce26f, short_chan_id=822031176893267970, mflags=00000001, cflags=00000000, update_time=2023-06-04 07:32:18 +0800 CST) from 02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f@giexynrrloc2fewstcybenljdksidtglfydecbellzkl63din6w73eid.onion:9735
2023-06-13 15:11:14.492 [DBG] DISC: Processing ChannelUpdate: peer=02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f@giexynrrloc2fewstcybenljdksidtglfydecbellzkl63din6w73eid.onion:9735, short_chan_id=822031176893267970, 
2023-06-13 15:11:14.492 [DBG] PEER: Peer(02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f): Received ChannelUpdate(chain_hash=000000000019d6689c085ae165831e934ff763ae46a2a6c172b3f1b60a8ce26f, short_chan_id=838683280479420417, mflags=00000001, cflags=00000001, update_time=2023-06-04 07:32:18 +0800 CST) from 02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f@giexynrrloc2fewstcybenljdksidtglfydecbellzkl63din6w73eid.onion:9735
2023-06-13 15:11:14.492 [DBG] PEER: Peer(02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f): Received ChannelUpdate(chain_hash=000000000019d6689c085ae165831e934ff763ae46a2a6c172b3f1b60a8ce26f, short_chan_id=861741138826100736, mflags=00000001, cflags=00000000, update_time=2023-06-04 07:32:19 +0800 CST) from 02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f@giexynrrloc2fewstcybenljdksidtglfydecbellzkl63din6w73eid.onion:9735
2023-06-13 15:11:14.493 [DBG] DISC: Processing ChannelUpdate: peer=02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f@giexynrrloc2fewstcybenljdksidtglfydecbellzkl63din6w73eid.onion:9735, short_chan_id=861741138826100736, 
2023-06-13 15:11:14.492 [DBG] DISC: Processing ChannelUpdate: peer=02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f@giexynrrloc2fewstcybenljdksidtglfydecbellzkl63din6w73eid.onion:9735, short_chan_id=838683280479420417, 
2023-06-13 15:11:14.492 [DBG] PEER: Peer(02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f): Received ChannelUpdate(chain_hash=000000000019d6689c085ae165831e934ff763ae46a2a6c172b3f1b60a8ce26f, short_chan_id=758988478675550209, mflags=00000001, cflags=00000000, update_time=2023-06-04 07:32:18 +0800 CST) from 02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f@giexynrrloc2fewstcybenljdksidtglfydecbellzkl63din6w73eid.onion:9735
2023-06-13 15:11:14.493 [DBG] DISC: Processing ChannelUpdate: peer=02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f@giexynrrloc2fewstcybenljdksidtglfydecbellzkl63din6w73eid.onion:9735, short_chan_id=758988478675550209, 
2023-06-13 15:11:14.493 [DBG] PEER: Peer(02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f): Received ChannelUpdate(chain_hash=000000000019d6689c085ae165831e934ff763ae46a2a6c172b3f1b60a8ce26f, short_chan_id=789811088221274112, mflags=00000001, cflags=00000000, update_time=2023-06-04 07:32:18 +0800 CST) from 02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f@giexynrrloc2fewstcybenljdksidtglfydecbellzkl63din6w73eid.onion:9735
2023-06-13 15:11:14.494 [DBG] DISC: Processing ChannelUpdate: peer=02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f@giexynrrloc2fewstcybenljdksidtglfydecbellzkl63din6w73eid.onion:9735, short_chan_id=789811088221274112, 
2023-06-13 15:11:14.494 [DBG] PEER: Peer(02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f): Received ChannelUpdate(chain_hash=000000000019d6689c085ae165831e934ff763ae46a2a6c172b3f1b60a8ce26f, short_chan_id=842818543729246209, mflags=00000001, cflags=00000000, update_time=2023-06-04 07:32:19 +0800 CST) from 02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f@giexynrrloc2fewstcybenljdksidtglfydecbellzkl63din6w73eid.onion:9735
2023-06-13 15:11:14.494 [DBG] DISC: Processing ChannelUpdate: peer=02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f@giexynrrloc2fewstcybenljdksidtglfydecbellzkl63din6w73eid.onion:9735, short_chan_id=842818543729246209, 
2023-06-13 15:11:14.495 [DBG] PEER: Peer(02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f): Received ChannelUpdate(chain_hash=000000000019d6689c085ae165831e934ff763ae46a2a6c172b3f1b60a8ce26f, short_chan_id=812083895183409153, mflags=00000001, cflags=00000001, update_time=2023-06-04 07:32:18 +0800 CST) from 02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f@giexynrrloc2fewstcybenljdksidtglfydecbellzkl63din6w73eid.onion:9735
2023-06-13 15:11:14.495 [DBG] DISC: Processing ChannelUpdate: peer=02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f@giexynrrloc2fewstcybenljdksidtglfydecbellzkl63din6w73eid.onion:9735, short_chan_id=812083895183409153, 
2023-06-13 15:11:14.495 [DBG] PEER: Peer(02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f): Received ChannelUpdate(chain_hash=000000000019d6689c085ae165831e934ff763ae46a2a6c172b3f1b60a8ce26f, short_chan_id=723467656115781632, mflags=00000001, cflags=00000000, update_time=2023-06-04 07:32:19 +0800 CST) from 02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f@giexynrrloc2fewstcybenljdksidtglfydecbellzkl63din6w73eid.onion:9735
2023-06-13 15:11:14.495 [DBG] PEER: Peer(02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f): Received ChannelUpdate(chain_hash=000000000019d6689c085ae165831e934ff763ae46a2a6c172b3f1b60a8ce26f, short_chan_id=734188993981841408, mflags=00000001, cflags=00000001, update_time=2023-06-04 07:32:18 +0800 CST) from 02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f@giexynrrloc2fewstcybenljdksidtglfydecbellzkl63din6w73eid.onion:9735
2023-06-13 15:11:14.495 [DBG] DISC: Processing ChannelUpdate: peer=02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f@giexynrrloc2fewstcybenljdksidtglfydecbellzkl63din6w73eid.onion:9735, short_chan_id=723467656115781632, 
2023-06-13 15:11:14.496 [DBG] DISC: Processing ChannelUpdate: peer=02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f@giexynrrloc2fewstcybenljdksidtglfydecbellzkl63din6w73eid.onion:9735, short_chan_id=734188993981841408, 
2023-06-13 15:11:14.497 [DBG] DISC: Removed edge with chan_id=749300:2720:0 from zombie index
2023-06-13 15:11:14.498 [DBG] DISC: Got ChannelUpdate for edge not found in graph(shortChanID=823864062870814720), saving for reprocessing later
2023-06-13 15:11:14.497 [DBG] DISC: Ignored stale edge policy for short_chan_id(838683280479420417): peer=02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f@giexynrrloc2fewstcybenljdksidtglfydecbellzkl63din6w73eid.onion:9735, msg=ChannelUpdate, is_remote=true
2023-06-13 15:11:14.497 [DBG] DISC: Ignored stale edge policy for short_chan_id(745207199950766080): peer=02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f@giexynrrloc2fewstcybenljdksidtglfydecbellzkl63din6w73eid.onion:9735, msg=ChannelUpdate, is_remote=true
2023-06-13 15:11:14.497 [DBG] DISC: Ignored stale edge policy for short_chan_id(865073758518837249): peer=02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f@giexynrrloc2fewstcybenljdksidtglfydecbellzkl63din6w73eid.onion:9735, msg=ChannelUpdate, is_remote=true
2023-06-13 15:11:14.497 [DBG] DISC: Ignored stale edge policy for short_chan_id(822031176893267970): peer=02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f@giexynrrloc2fewstcybenljdksidtglfydecbellzkl63din6w73eid.onion:9735, msg=ChannelUpdate, is_remote=true
2023-06-13 15:11:14.497 [DBG] DISC: Ignored stale edge policy for short_chan_id(861741138826100736): peer=02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f@giexynrrloc2fewstcybenljdksidtglfydecbellzkl63din6w73eid.onion:9735, msg=ChannelUpdate, is_remote=true
2023-06-13 15:11:14.497 [DBG] DISC: Ignored stale edge policy for short_chan_id(842818543729246209): peer=02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f@giexynrrloc2fewstcybenljdksidtglfydecbellzkl63din6w73eid.onion:9735, msg=ChannelUpdate, is_remote=true
2023-06-13 15:11:14.497 [DBG] DISC: Ignored stale edge policy for short_chan_id(758988478675550209): peer=02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f@giexynrrloc2fewstcybenljdksidtglfydecbellzkl63din6w73eid.onion:9735, msg=ChannelUpdate, is_remote=true
2023-06-13 15:11:14.497 [DBG] DISC: Ignored stale edge policy for short_chan_id(789811088221274112): peer=02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f@giexynrrloc2fewstcybenljdksidtglfydecbellzkl63din6w73eid.onion:9735, msg=ChannelUpdate, is_remote=true
2023-06-13 15:11:14.498 [DBG] DISC: Ignored stale edge policy for short_chan_id(812083895183409153): peer=02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f@giexynrrloc2fewstcybenljdksidtglfydecbellzkl63din6w73eid.onion:9735, msg=ChannelUpdate, is_remote=true
2023-06-13 15:11:14.498 [DBG] DISC: Ignored stale edge policy for short_chan_id(734188993981841408): peer=02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f@giexynrrloc2fewstcybenljdksidtglfydecbellzkl63din6w73eid.onion:9735, msg=ChannelUpdate, is_remote=true
2023-06-13 15:11:14.499 [DBG] DISC: Removed edge with chan_id=736414:1028:0 from zombie index
2023-06-13 15:11:14.499 [DBG] DISC: Got ChannelUpdate for edge not found in graph(shortChanID=809695755924406272), saving for reprocessing later
2023-06-13 15:11:14.500 [DBG] DISC: Removed edge with chan_id=657990:2372:0 from zombie index
2023-06-13 15:11:14.500 [DBG] DISC: Got ChannelUpdate for edge not found in graph(shortChanID=723467656115781632), saving for reprocessing later

More in the attached file:

lnd_log.txt

// edit: updated the log file going from peer connect all the way to the exit. there may be some unrelated stuff

bitromortac commented 1 year ago

Great, I think you can ignore the zombie index logs. It seems like your peer doesn't like the fee update for the channel which is sent here:

2023-06-13 15:11:14.432 [DBG] PEER: Peer(02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f): Sending UpdateFee(chan_id=78c2551891caf4e73f90d8e7f564001eb04815c5e6ea489f142a28798c34373f, fee_update_sat=253) to 02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f@giexynrrloc2fewstcybenljdksidtglfydecbellzkl63din6w73eid.onion:9735

and rejected here with a warning:

2023-06-13 15:27:54.004 [DBG] PEER: Peer(02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f): Received Warning(chan_id=78c2551891caf4e73f90d8e7f564001eb04815c5e6ea489f142a28798c34373f, err=update_fee 253 outside range 1766-67478 (currently 13326)) from 02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f@giexynrrloc2fewstcybenljdksidtglfydecbellzkl63din6w73eid.onion:9735
2023-06-13 15:27:54.004 [INF] PEER: Peer(02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f): unable to read message from peer: EOF
2023-06-13 15:27:54.005 [INF] PEER: Peer(02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f): disconnecting

Do you use any custom fee estimation, or could you look up any fee related settings in your lnd.conf?

mariodian commented 1 year ago

I use charge-lnd to change fees once an hour based on various scenarios. However, that should be unrelated no? (meanwhile I set correct fees from the range above just to be safe)

And no, I don't use any custom fee estimation as far as I'm aware.

Fee related settings in ~/.lnd/lnd.conf:

bitcoin.basefee=0
bitcoin.feerate=100
bitcoin.minhtlc=1000

Fee report for the node:

$ lncli feereport

lncli feereport
{
    "channel_fees": [
        {
            "chan_id": "758511290670186497",
            "channel_point": "3e37348c79282a149f48eae6c51548b01e0064f5e7d8903fe7f4ca911855c278:1",
            "base_fee_msat": "0",
            "fee_per_mil": "2587",
            "fee_rate": 0.002587
        }
...

I don't know where it's getting the number 253 from.

BTW, after setting the fees from the correct range I'm getting this message:

[DBG] SRVR: Scheduling connection re-establishment to persistent peer 02df5ffe895c778e10f7742a6c5b8a0cefbe9465df58b92fadeb883752c8107c8f in 1h3m0s

So I guess I have to wait for now?

mariodian commented 1 year ago

I see the number 253 mentioned in logs for another node but I have no idea where it's set or where it's coming from or even how to change it:

cat ~/.lnd/logs/bitcoin/mainnet/lnd.log | grep 253

2023-06-13 15:27:50.092 [DBG] DISC: Ignored stale edge policy for short_chan_id(862383253637169153): peer=03cde60a6323f7122d5178255766e38114b4722ede08f7c9e0c5df9b912cc201d6@34.65.85.39:9745, msg=ChannelUpdate, is_remote=true
 feePerKw: (chainfee.SatPerKWeight) 253 sat/kw,
bitromortac commented 1 year ago

I think this is about your node sending an automatic UpdateFee (this is a protocol message https://github.com/lightning/bolts/blob/master/02-peer-protocol.md#updating-fees-update_fee one can't send manually or via other tools). There may be an issue with fee estimation of your backend. Perhaps reporting bitcoin-cli getmempoolinfo and bitcoin-cli estimatesmartfee 1 gives more info.

mariodian commented 1 year ago

This are the outputs for the commands:

$ bitcoin-cli getmempoolinfo
{
  "loaded": true,
  "size": 112634,
  "bytes": 54353252,
  "usage": 295491120,
  "total_fee": 4.60670316,
  "maxmempool": 300000000,
  "mempoolminfee": 0.00005765,
  "minrelaytxfee": 0.00001000,
  "incrementalrelayfee": 0.00001000,
  "unbroadcastcount": 0,
  "fullrbf": true
}

$ bitcoin-cli estimatesmartfee 1
{
  "feerate": 0.00029702,
  "blocks": 2
}

I don't have any fee related settings in ~/.bitcoin/bitcoin.conf though. I do have mempoolfullrbf=1 but that shouldn't have any effect on the fee estimate, no?

Not sure if it helps, I do run these services but I don't think any of those provide fee estimate for lnd by default: electrs, lnbits, btcpayserver, thunderhub

adamteale commented 1 year ago

@mariodian I seem to be in the same situation as yourself, with possibly 2-3 channels marked as inactive. Have you had any luck sorting this out? I'm on the latest version of Umbrel OS with LND 0.16.3-beta

mariodian commented 1 year ago

@adamteale no idea, how to solve this.

adamteale commented 1 year ago

@mariodian @bitromortac in case it is of any use to you:

bitcoin-cli estimatesmartfee 1

{
  "feerate": 0.00037909,
  "blocks": 2
}

bitcoin-cli getmempoolinfo

{
  "loaded": true,
  "size": 116314,
  "bytes": 41678984,
  "usage": 249162752,
  "total_fee": 4.35632783,
  "maxmempool": 300000000,
  "mempoolminfee": 0.00005154,
  "minrelaytxfee": 0.00001000,
  "incrementalrelayfee": 0.00001000,
  "unbroadcastcount": 0,
  "fullrbf": true
}

A snippet from the lnd logs (i've purposely altered any channel/node hash to try to hide it here):

2023-06-20 15:05:45.693 [INF] PEER: Peer(02e1dad4d396696cb207a524bdf595f1a2e6792d7b990f18cef1ebd1b567bb110f): Loading ChannelPoint(600a54e257612992513b8bbb629379b7c2b441189ee7fd7e5805a53cbb1396d4:0), isPending=false
2023-06-20 15:05:45.695 [INF] HSWC: ChannelLink(600a54e257612992513b8bbb629379b7c2b441189ee7fd7e5805a53cbb1396d4:0): starting
2023-06-20 15:05:45.695 [INF] HSWC: Trimming open circuits for chan_id=785297:1440:0, start_htlc_id=4572
2023-06-20 15:05:45.695 [INF] HSWC: Adding live link chan_id=d49616bb2ca505587efde79e1841b4c2b7799362bb8b3b5192296157e2540a60, short_chan_id=785297:1440:0
2023-06-20 15:05:45.695 [INF] NTFN: New block epoch subscription
2023-06-20 15:05:45.695 [INF] CNCT: Attempting to update ContractSignals for ChannelPoint(600a54e257612992513b8bbb629379b7c2b441189ee7fd7e5805a53cbb1396d4:0)
2023-06-20 15:05:45.695 [INF] HSWC: ChannelLink(600a54e257612992513b8bbb629379b7c2b441189ee7fd7e5805a53cbb1396d4:0): HTLC manager started, bandwidth=1218607184 mSAT
2023-06-20 15:05:45.695 [INF] HSWC: ChannelLink(600a54e257612992513b8bbb629379b7c2b441189ee7fd7e5805a53cbb1396d4:0): attempting to re-synchronize
2023-06-20 15:05:45.696 [INF] PEER: Peer(02e1dad4d396696cb207a524bdf595f1a2e6792d7b990f18cef1ebd1b567bb110f): Negotiated chan series queries
2023-06-20 15:05:45.696 [INF] DISC: Creating new GossipSyncer for peer=02e1dad4d396696cb207a524bdf595f1a2e6792d7b990f18cef1ebd1b567bb110f
2023-06-20 15:05:45.723 [WRN] DISC: ignoring remote ChannelAnnouncement for own channel
2023-06-20 15:05:45.839 [ERR] DISC: unable to validate channel update announcement for short_chan_id=(lnwire.ShortChannelID) 795179:3754:0
: invalid max htlc for channel update (*lnwire.ChannelUpdate)(0x4013d8e2c0)({
 Signature: (lnwire.Sig) (len=64 cap=64) {
  00000000  3f 55 96 45 2e 88 96 ef  9a a7 7b 53 f8 7d 70 f3  |?U.E......zS.}p.|
  00000010  54 da 06 3d 1b db 5e 27  53 ea e3 4f 0d 36 57 f9  |T..=..^'S..O.6W.|
  00000020  41 8a 8b ec df cd 40 9c  d3 8f c5 08 b5 66 5f e5  |A.....@......f_.|
  00000030  23 b6 c1 c6 c1 b6 43 d0  5a 90 9e 88 a8 36 a0 aa  |#.....C.Z....6..|
 },
 ChainHash: (chainhash.Hash) (len=32 cap=32) 000000000019d6689c085ae155831e934ff763ae46a2a6c172b3f1c60a8ce26f,
 ShortChannelID: (lnwire.ShortChannelID) 795179:3754:0,
 Timestamp: (uint32) 1687263262,
 MessageFlags: (lnwire.ChanUpdateMsgFlags) 00000001,
 ChannelFlags: (lnwire.ChanUpdateChanFlags) 00000000,
 TimeLockDelta: (uint16) 34,
 HtlcMinimumMsat: (lnwire.MilliSatoshi) 1 mSAT,
 BaseFee: (uint32) 3042,
 FeeRate: (uint32) 1156,
 HtlcMaximumMsat: (lnwire.MilliSatoshi) 0 mSAT,
 ExtraOpaqueData: (lnwire.ExtraOpaqueData) {
 }
})

2023-06-20 15:05:46.144 [INF] HSWC: ChannelLink(600a54e257612992513b8bbb629379b7c2b441189ee7fd7e5805a53cbb1396d4:0): received re-establishment message from remote side
2023-06-20 15:05:46.148 [INF] HSWC: ChannelLink(600a54e257612992513b8bbb629379b7c2b441189ee7fd7e5805a53cbb1396d4:0): sending 3 updates to synchronize the state
2023-06-20 15:05:46.149 [INF] DISC: GossipSyncer(02e1dad4d396696cb207a524bdf595f1a2e6792d7b990f18cef1ebd1b567bb110f): applying new update horizon: start=2106-02-07 06:28:15 +0000 UTC, end=2242-03-16 12:56:30 +0000 UTC, backlog_size=0
2023-06-20 15:05:46.766 [INF] DISC: Received new remote announcement signature for 785297:1440:0
2023-06-20 15:05:47.150 [INF] PEER: Peer(02e1dad4d396696cb207a524bdf595f1a2e6792d7b990f18cef1ebd1b567bb110f): unable to read message from peer: EOF
2023-06-20 15:05:47.150 [WRN] HSWC: ChannelLink(600a54e257612992513b8bbb629379b7c2b441189ee7fd7e5805a53cbb1396d4:0): received warning message from peer: chan_id=d49616bb2ca505587efde79e1841b4c2b7799362bb8b3b5192296157e2540a60, err=update_fee 253 outside range 1330-55280 (currently 5272)
2023-06-20 15:05:47.150 [INF] PEER: Peer(02e1dad4d396696cb207a524bdf595f1a2e6792d7b990f18cef1ebd1b567bb110f): disconnecting 02e1dad4d396696cb207a524bdf595f1a2e6792d7b990f18cef1ebd1b567bb110f@fmspampdsqre7aiyag6le6nyi7g3xigaf26lx56bnjser2b5cs2ys6id.onion:9735, reason: read handler closed
2023-06-20 15:05:47.151 [INF] NTFN: Cancelling epoch notification, epoch_id=241
2023-06-20 15:05:47.353 [INF] DISC: Removing GossipSyncer for peer=02e1dad4d396696cb207a524bdf595f1a2e6792d7b990f18cef1ebd1b567bb110f
2023-06-20 15:05:47.353 [INF] HSWC: ChannelLink(600a54e257612992513b8bbb629379b7c2b441189ee7fd7e5805a53cbb1396d4:0): stopping
2023-06-20 15:05:47.354 [INF] HSWC: ChannelLink(600a54e257612992513b8bbb629379b7c2b441189ee7fd7e5805a53cbb1396d4:0): exited
2023-06-20 15:05:47.354 [INF] HSWC: Removing channel link with ChannelID(d49616bb2ca505587efde79e1841b4c2b7799362bb8b3b5192296157e2540a60)
2023-06-20 15:05:52.166 [WRN] HSWC: ChannelLink(d7a3ce6a137b9d8920d8301cd6082e1c7d89ae48247dec4ce5a8aaaa58e2b7d6:0): insufficient bandwidth to route htlc: 234548176 mSAT is larger than 1452913 mSAT
2023-06-20 15:05:52.166 [ERR] HSWC: insufficient bandwidth to route htlc
2023-06-20 15:05:52.167 [ERR] HSWC: Unhandled error while reforwarding htlc settle/fail over htlcswitch: insufficient bandwidth to route htlc
2023-06-20 15:05:55.041 [INF] CRTR: Processed channels=0 updates=83 nodes=6 in last 1m0.000036275s
2023-06-20 15:06:03.643 [ERR] RPCS: [/lnrpc.Lightning/GetChanInfo]: edge not found
2023-06-20 15:06:08.736 [WRN] HSWC: ChannelLink(7a6f6e2bfe03ce18fbf098a58bff8da4b093bf768c6547a2b1bb094aeaaf0ed0:1): insufficient bandwidth to route htlc: 45827135 mSAT is larger than 1355386 mSAT
2023-06-20 15:06:08.737 [ERR] HSWC: insufficient bandwidth to route htlc
2023-06-20 15:06:08.737 [ERR] HSWC: Unhandled error while reforwarding htlc settle/fail over htlcswitch: insufficient bandwidth to route htlc
2023-06-20 15:06:23.156 [ERR] RPCS: [/lnrpc.Lightning/GetChanInfo]: edge not found
2023-06-20 15:06:27.337 [ERR] NANN: Unable to retrieve chan status for Channel(a0f154923c7ffda443b24121f236231f9d2b93fe1cadb0d80f6c731378b24043:1): edge not found
2023-06-20 15:06:42.415 [ERR] RPCS: [/lnrpc.Lightning/GetChanInfo]: edge not found
2023-06-20 15:06:55.041 [INF] CRTR: Processed channels=0 updates=120 nodes=2 in last 59.999774416s
2023-06-20 15:07:01.421 [ERR] RPCS: [/lnrpc.Lightning/GetChanInfo]: edge not found
2023-06-20 15:07:21.185 [ERR] RPCS: [/lnrpc.Lightning/GetChanInfo]: edge not found
2023-06-20 15:07:27.338 [ERR] NANN: Unable to retrieve chan status for Channel(a0f154923c7ffda443b24121f236231f9d2b93fe1cadb0d80f6c731378b24043:1): edge not found
2023-06-20 15:07:41.233 [ERR] RPCS: [/lnrpc.Lightning/GetChanInfo]: edge not found
2023-06-20 15:07:55.041 [INF] CRTR: Processed channels=0 updates=171 nodes=8 in last 59.999459079s
2023-06-20 15:08:00.206 [ERR] RPCS: [/lnrpc.Lightning/GetChanInfo]: edge not found
2023-06-20 15:08:19.621 [ERR] RPCS: [/lnrpc.Lightning/GetChanInfo]: edge not found
2023-06-20 15:08:23.160 [WRN] HSWC: ChannelLink(d7a3ce6a137b9d8920d8301cd6082e1c7d89ae48247dec4ce5a8aaaa58e2b7d6:0): insufficient bandwidth to route htlc: 50008500 mSAT is larger than 1452913 mSAT
2023-06-20 15:08:23.161 [ERR] HSWC: insufficient bandwidth to route htlc
2023-06-20 15:08:23.161 [ERR] HSWC: Unhandled error while reforwarding htlc settle/fail over htlcswitch: insufficient bandwidth to route htlc
2023-06-20 15:08:27.358 [ERR] NANN: Unable to retrieve chan status for Channel(a0f154923c7ffda443b24121f236231f9d2b93fe1cadb0d80f6c731378b24043:1): edge not found
2023-06-20 15:08:38.174 [WRN] HSWC: ChannelLink(d7a3ce6a137b9d8920d8301cd6082e1c7d89ae48247dec4ce5a8aaaa58e2b7d6:0): insufficient bandwidth to route htlc: 58622897 mSAT is larger than 1452913 mSAT
2023-06-20 15:08:38.175 [ERR] HSWC: insufficient bandwidth to route htlc
2023-06-20 15:08:38.175 [ERR] HSWC: Unhandled error while reforwarding htlc settle/fail over htlcswitch: insufficient bandwidth to route htlc
2023-06-20 15:08:38.372 [ERR] RPCS: [/lnrpc.Lightning/GetChanInfo]: edge not found
2023-06-20 15:08:55.042 [INF] CRTR: Processed channels=0 updates=166 nodes=9 in last 1m0.00033709s
2023-06-20 15:08:58.553 [ERR] RPCS: [/lnrpc.Lightning/GetChanInfo]: edge not found
2023-06-20 15:08:59.147 [WRN] SRVR: Already have 1 persistent connection requests for 02e1dad4d396696cb207a524bdf595f1a2e6792d7b990f18cef1ebd1b567bb110f@10.21.21.11:51132, connecting anyway.
aplnx commented 1 year ago

Hello. This is also happening to me. It is exactly the same behavior. 

PEER: Peer(xxx): unable to read message from peer: EOF
PEER: Peer(xxx): disconnecting 0334346507fbd9c36742122414e3fb9b5b4db4e432e137633bb225b1926327b51c@127.0.0.1:40126, reason: read handler closed
HSWC: ChannelLink(xxx): received warning message from peer: chan_id=xxx, err=update_fee 253 outside range 1319-64263 (currently 8149)
NTFN: Cancelling epoch notification, epoch_id=687

It is locked in a loop and this log message keeps hammering the other node every 5 seconds. I think this behavior is not good for the network if we think in scale!

UPDATE: After some research I thought it could be related to bitcoind fee estimation. So, I tried to "feeurl" config on lnd.conf. But unfortunately, it keeps the same error message.

wtogami commented 1 year ago

LND has a confirmed working fee estimator available to it but in this case it appears to not be using it?

saubyk commented 1 year ago

cc: @ziggie1984

Dark345 commented 1 year ago

experiencing exact the same behaviour. Do you have any workaround in the meantime?

aplnx commented 1 year ago

experiencing exact the same behaviour. Do you have any workaround in the meantime?

Well, there is no easy way around. I just forced close my channel since it was not useful anymore.

Please, if you are going to FC the channel, ensure that fees are very low. Check it out on mempool.space. Forcing Close costs you at least two transactions submitted. Have this in mind.

I suggest closing this issue since the real problem was revealed on issue #7666.

SunnySarahNode commented 1 year ago

similar behavior across several channels. example : 

2023-07-17 13:36:19.437 [INF] SRVR: New inbound connection from 49.228.105.0:60320
2023-07-17 13:36:19.438 [INF] SRVR: Finalizing connection to 020d1617e27ac022395352f2b3774969593d3d6ddff6fb117d820a9dda8da45217@49.228.105.0:60320, inbound=true
2023-07-17 13:36:19.703 [INF] PEER: Peer(020d1617e27ac022395352f2b3774969593d3d6ddff6fb117d820a9dda8da45217): Loading ChannelPoint(cb5377202d85fb8a03c8070b25b3cd347b319e78951b67d4767e94a04c20db1a:1), isPending=false
2023-07-17 13:36:19.703 [INF] HSWC: ChannelLink(cb5377202d85fb8a03c8070b25b3cd347b319e78951b67d4767e94a04c20db1a:1): starting
2023-07-17 13:36:19.703 [INF] HSWC: Trimming open circuits for chan_id=742685:2053:1, start_htlc_id=147113
2023-07-17 13:36:19.703 [INF] HSWC: Adding live link chan_id=1adb204ca0947e76d4671b95789e317b34cdb3250b07c8038afb852d207753ca, short_chan_id=742685:2053:1
2023-07-17 13:36:19.703 [INF] NTFN: New block epoch subscription
2023-07-17 13:36:19.703 [INF] PEER: Peer(020d1617e27ac022395352f2b3774969593d3d6ddff6fb117d820a9dda8da45217): Negotiated chan series queries
2023-07-17 13:36:19.703 [INF] DISC: Creating new GossipSyncer for peer=020d1617e27ac022395352f2b3774969593d3d6ddff6fb117d820a9dda8da45217
2023-07-17 13:36:19.703 [INF] CNCT: Attempting to update ContractSignals for ChannelPoint(cb5377202d85fb8a03c8070b25b3cd347b319e78951b67d4767e94a04c20db1a:1)
2023-07-17 13:36:19.703 [INF] HSWC: ChannelLink(cb5377202d85fb8a03c8070b25b3cd347b319e78951b67d4767e94a04c20db1a:1): HTLC manager started, bandwidth=717605537 mSAT
2023-07-17 13:36:19.703 [INF] HSWC: ChannelLink(cb5377202d85fb8a03c8070b25b3cd347b319e78951b67d4767e94a04c20db1a:1): attempting to re-synchronize
2023-07-17 13:36:20.473 [WRN] DISC: ignoring remote ChannelAnnouncement for own channel
2023-07-17 13:36:20.746 [INF] DISC: Received new remote announcement signature for 742685:2053:1
2023-07-17 13:36:20.746 [INF] HSWC: ChannelLink(cb5377202d85fb8a03c8070b25b3cd347b319e78951b67d4767e94a04c20db1a:1): received re-establishment message from remote side
2023-07-17 13:36:20.757 [INF] HSWC: ChannelLink(cb5377202d85fb8a03c8070b25b3cd347b319e78951b67d4767e94a04c20db1a:1): sending 3 updates to synchronize the state
2023-07-17 13:36:21.018 [WRN] HSWC: ChannelLink(cb5377202d85fb8a03c8070b25b3cd347b319e78951b67d4767e94a04c20db1a:1): received warning message from peer: chan_id=1adb204ca0947e76d4671b95789e317b34cdb3250b07c8038afb852d207753ca, err=update_fee 253 outside range 833-4294967295 (currently 13357)
2023-07-17 13:36:21.019 [INF] PEER: Peer(020d1617e27ac022395352f2b3774969593d3d6ddff6fb117d820a9dda8da45217): unable to read message from peer: EOF
2023-07-17 13:36:21.019 [INF] PEER: Peer(020d1617e27ac022395352f2b3774969593d3d6ddff6fb117d820a9dda8da45217): disconnecting 020d1617e27ac022395352f2b3774969593d3d6ddff6fb117d820a9dda8da45217@49.228.105.0:60320, reason: read handler closed
2023-07-17 13:36:21.019 [INF] NTFN: Cancelling epoch notification, epoch_id=814
2023-07-17 13:36:21.220 [INF] DISC: Removing GossipSyncer for peer=020d1617e27ac022395352f2b3774969593d3d6ddff6fb117d820a9dda8da45217
2023-07-17 13:36:21.220 [INF] HSWC: ChannelLink(cb5377202d85fb8a03c8070b25b3cd347b319e78951b67d4767e94a04c20db1a:1): stopping
2023-07-17 13:36:21.220 [INF] HSWC: ChannelLink(cb5377202d85fb8a03c8070b25b3cd347b319e78951b67d4767e94a04c20db1a:1): exited
2023-07-17 13:36:21.220 [INF] HSWC: Removing channel link with ChannelID(1adb204ca0947e76d4671b95789e317b34cdb3250b07c8038afb852d207753ca)

the most interesting : 

2023-07-17 13:36:21.018 [WRN] HSWC: ChannelLink(cb5377202d85fb8a03c8070b25b3cd347b319e78951b67d4767e94a04c20db1a:1): received warning message from peer: chan_id=1adb204ca0947e76d4671b95789e317b34cdb3250b07c8038afb852d207753ca, err=update_fee 253 outside range 833-4294967295 (currently 13357)
aplnx commented 1 year ago

020d1617e27ac022395352f2b3774969593d3d6ddff6fb117d820a9dda8da45217

Are you able to contact the node's owner? It would be interesting to know if he is using CLN implementation of the lightning network. This error is related to some incompatibility among them.

Please, check the issue 7666. Ziggie on our plebnet group is working on something that might solve this.

I had the same issue, but I waited for Mempool to clear and I forced close the channel since it was unusable and there wasn't any workaround.

ziggie1984 commented 1 year ago

@SunnySarahNode what's interesting to find out, why your backend reports such a low feerate for the feeupdate. In your case it used 1 sats/vbyte that should not happen considering current mempool conditions did you wipe your mempool? Or could you investigate in your logs since when you are seeing these low feeupdates ? Lnd will use a blocktraget of 3 blocks for the fee-estimation. What is your fee-estimation currently:

bitcoin-cli estimatesmartfee 3

whats your bitcoin backend ?

SunnySarahNode commented 1 year ago

@ziggie1984 I have bitcoind RPC (Bitcoin Core version v23.0.0) backend. Full, indexed.

{
  "feerate": 0.00031121,
  "blocks": 3
}

I have maxmempool=3000 in my bitcoin settings in order to prevent 7156 issue ( https://github.com/lightningnetwork/lnd/issues/7156#issuecomment-1572144164 ).

I can't reach my peers with this problem (unfortunately none of them), but I assume they have CLN. I'll let you know the details as soon as I know them.

ziggie1984 commented 1 year ago

ok could you grep for some logs, I am especially interested when this feeupdate with those low fees emerged:

can you grep for: grep -B 1 -i "updating commit fee"

you should see something like this:

lnd.log.54088.gz-2023-07-14 07:31:49.195 [DBG] HSWC: ChannelLink(xxx:x) sampled fee rate for 3 block conf: 4781 sat/kw
lnd.log.54088.gz:2023-07-14 07:31:49.195 [INF] HSWC: ChannelLink(xxx:x): updating commit fee to 4781 sat/kw

can you look through your logs and see how the fee values behaved especially when your node proposed the 253.

Seems like you did not have any mempool issues so I am wondering where those corrupt fee-estimates come from.

ziggie1984 commented 1 year ago

Ok I think I know what the problem might be, could you confirm that the channel which is affected by this was almost drained ?

My general impression was that this behaviour is most likely caused by some bad backend fee-estimation. I concluded this because the example I investigated in #7666 was caused by a mempool wipe-out.

But looking at the code again it seems to me, that we can also end up in this situation when our channel is drained. Could you also take a look at this @ellemouton.

Looking in particular at this code part: https://github.com/lightningnetwork/lnd/blob/bd3f570107244688583f450653e906943f69a2f4/lnwallet/channel.go#L7339-L7355

It seems to me, that because we have a default FeeAllocation of 0.5 in combination we a drained channel (low local cap) that we end up going all the way down to the min_relay_floor (253 sat/kw). And because most of the nodes running big mempools nowdays the min_relay fee is 1 sat/vbyte.

So I think we need to be careful with the FeeAllocation, because the old fee will basically decrease over time especially when the channel is drained locally.

aplnx commented 1 year ago

Ok I think I know what the problem might be, could you confirm that the channel which is affected by this was almost drained ?

My general impression was that this behaviour is most likely caused by some bad backend fee-estimation. I concluded this because the example I investigated in #7666 was caused by a mempool wipe-out.

But looking at the code again it seems to me, that we can also end up in this situation when our channel is drained. Could you also take a look at this @ellemouton.

Looking in particular at this code part:

https://github.com/lightningnetwork/lnd/blob/bd3f570107244688583f450653e906943f69a2f4/lnwallet/channel.go#L7339-L7355

It seems to me, that because we have a default FeeAllocation of 0.5 in combination we a drained channel (low local cap) that we end up going all the way down to the min_relay_floor (253 sat/kw). And because most of the nodes running big mempools nowdays the min_relay fee is 1 sat/vbyte.

So I think we need to be careful with the FeeAllocation, because the old fee will basically decrease over time especially when the channel is drained locally.

I can confirm that by the moment I had to force close my problematic channel, I clearly remember that it was drained. Also, the node was coinos which is CLN.

mariodian commented 1 year ago

Not sure what happened but this issue has been resolved for me. Perhaps Blockstream Store did something on their end.

ziggie1984 commented 1 year ago

Not sure what happened but this issue has been resolved for me. Perhaps Blockstream Store did something on their end.

This can happen, if mempool fees for the CLN side go so low again, that they accept your feeupdate of 1 sat_per_vbyte, tho this can either happen if you have luck, or never when the mempool remains at high fee level.

ziggie1984 commented 1 year ago

Ok, I could reproduce on regtest, it is indeed a problem, working on a fix.

To prevent this from happening again, please set max-channel-fee-allocation=1 for now, this should prevent you from scaling down your fees too much from a prior state.

wtogami commented 1 year ago

Not sure what happened but this issue has been resolved for me. Perhaps Blockstream Store did something on their end.

Blockstream Store applied a one time update_fee exception to allow the remote peer's erroneous state to be accepted just once. If their mempool is subsequently fixed then the channel will continue to work.

We found all but one of the stuck channels recovered after this one time exception. The one broken peer actually has a broken mempool right now. All of the stuck peers appear to be LND nodes.

btweenthebars commented 1 year ago

Not sure what happened but this issue has been resolved for me. Perhaps Blockstream Store did something on their end.

Blockstream Store applied a one time update_fee exception to allow the remote peer's erroneous state to be accepted just once. If their mempool is subsequently fixed then the channel will continue to work.

We found all but one of the stuck channels recovered after this one time exception. The one broken peer actually has a broken mempool right now. All of the stuck peers appear to be LND nodes.

one time exception, how ? by ignore-fee-limits=true ?

aplnx commented 1 year ago

Ok, I could reproduce on regtest, it is indeed a problem, working on a fix.

To prevent this from happening again, please set max-channel-fee-allocation=1 for now, this should prevent you from scaling down your fees too much from a prior state.

Is this a configuration on lnd.conf?

mariodian commented 1 year ago

Is this a configuration on lnd.conf?

Yes, have a look at the example config.

wtogami commented 1 year ago

Blockstream Store applied a one time update_fee exception to allow the remote peer's erroneous state to be accepted just once. If their mempool is subsequently fixed then the channel will continue to work. We found all but one of the stuck channels recovered after this one time exception. The one broken peer actually has a broken mempool right now. All of the stuck peers appear to be LND nodes.

one time exception, how ? by ignore-fee-limits=true ?

https://fedorapeople.org/~wtogami/a/2023/0001-DO-NOT-COMMIT-Temporary-workaround-for-LND-update_fe.patch CLN v23.05.2 users can temporarily run with this patch.

btweenthebars commented 1 year ago

right, I used to rely on the ignore-fee-limit=true in my CLN. Now it's broken with this bug on the 23.05 release https://github.com/ElementsProject/lightning/issues/6362 . I lost a bunch of channels before seeing this ticket.

I have to wonder, since between LND-LND nobody complains about update_fee mismatch, does it mean LND does not care about it at all ?

rkfg commented 1 year ago

I've set max-channel-fee-allocation=1 and it still happens. A few caveats that might affect this (but unlikely): I run the ordisrespecter patch that probably reduces the mempool load and my mempool is limited by 100 Mb because on RPi it makes sense, with default 300 Mb it grows too much.

But I don't think it matters. First of all, it happens to people with much bigger mempools here in the comments. And second, my fee estimation works fine:

> bitcoin-cli estimatesmartfee 1 economical
{
  "feerate": 0.00008346,
  "blocks": 2
}

which roughly corresponds to mempool.space's fees. And yet lnd proposes the same 253 sat/kw (HSWC: ChannelLink(2dc978c8d6b2b7a61e9d7ab3131593d0c963bc305010a9c1927753c71fba0f3a:1): received warning message from peer: chan_id=3a0fba1fc7537792c1a9105030bc63c9d0931513b37a9d1ea6b7b2d6c878c92c, err=update_fee 253 outside range 803-45398 (currently 5296)). It happens to 2 of my channels, one is almost drained, one is almost full but still there's at least 140k sats on one side so it should be more than enough. I run v0.16.4-beta on Raspbian arm64.

ziggie1984 commented 1 year ago

I've set max-channel-fee-allocation=1 and it still happens. A few caveats that might affect this (but unlikely): I run the ordisrespecter patch that probably reduces the mempool load and my mempool is limited by 100 Mb because on RPi it makes sense, with default 300 Mb it grows too much.

It can also happen that lnd proposes the min-relay-feerate when the mempool is still not ready estimating data. Unfortunately you can either wait now for the CLN peer to relax its rules or hope that the feerate range of the CLN Peer sometime in the near feature hits 1 sat/vbyte again (unlikely).

This will be fixed with #7805

rkfg commented 1 year ago

Any ideas how to resolve this after the patch is accepted? If I understand it right from the discussion, we signed the new commitment with this 235 sat fee and sent it to the remote, it doesn't accept it and doesn't let us propose another fee (because we're disconnected immediately) and revoke this low fee commitment. We're stuck in a loop now. Should the spec be improved in this regard then? If we can't advance the commitment chain because of just one mistake I see it as a serious flaw. And even then this mistake might not be a technical error (not the case in this issue but in a broad sense it can be) because different implementations can have different opinions about the reasonable fee range, and nodes can have very different mempools.

wtogami commented 1 year ago

Any ideas how to resolve this after the patch is accepted?

Your choices.

  1. The CLN admin notices and manually overrides to unstuck the channel.
  2. Force Close
SunnySarahNode commented 1 year ago

I have an interesting case possibly related to this issue.

Me: LND 0.16.4-beta My peer: LND 0.16.4-beta (Umbrel)

Both nodes are online and ok. the connection is established without any problems.

My log:

[ERR] HSWC: ChannelLink(xxx:1): failing link: ChannelPoint(xxx:1): received error from peer: chan_id=xxx, err=internal error with error: remote error
[ERR] HSWC: ChannelLink(xxx:1): link failed, exiting htlcManager

My peer log:

[ERR] HSWC: ChannelLink(xxx:1): failing link: unable to update commitment: commitment transaction dips peer below chan reserve: our balance below chan reserve with error: internal error
[ERR] HSWC: ChannelLink(xxx:1): link failed, exiting htlcManager

All of the liquidity in the channel is on my side, remote balance = 60,218 sats.

I'm ready to provide any necessary information.

Can anyone of us do something to resolve this problem? Should my peer use max-channel-fee-allocation=1 for temporary resolving it?

ziggie1984 commented 1 year ago

Any ideas how to resolve this after the patch is accepted? If I understand it right from the discussion, we signed the new commitment with this 235 sat fee and sent it to the remote, it doesn't accept it and doesn't let us propose another fee (because we're disconnected immediately) and revoke this low fee commitment. We're stuck in a loop now. Should the spec be improved in this regard then? If we can't advance the commitment chain because of just one mistake I see it as a serious flaw. And even then this mistake might not be a technical error (not the case in this issue but in a broad sense it can be) because different implementations can have different opinions about the reasonable fee range, and nodes can have very different mempools.

I think there might be room in the spec to integrate a kind of agreement between two parties before commitments are signed. So currently lnd proposes the feeupdate and also immediately signs the new commitment tx with this new feeupdate (sending a commitment signed msg). As soon as signatures are exchanged the peer needs to collaborate to invalidate the state. The spec says the following which reads promising:

if the update_fee is too low for timely processing, OR is unreasonably large:
MUST send a warning and close the connection, or send an error and fail the channel.

So maybe we could just sent out the feeupdate, see whether the fee response with a warning and then maybe discards this update as a whole. But it looks like the spec did not foresee such back and forth. Maybe some more experienced dev can jump in and add his thoughts ?

ziggie1984 commented 1 year ago

@SunnySarahNode could you comment in this issue, because these two are not related (only the outcome looks the same because the channel is unusable) #7657

SunnySarahNode commented 1 year ago

@ziggie1984 but it's about the Eclair client and interop... But ok : ) Done.

rkfg commented 1 year ago

Funny thing: I now have an incoming HTLC in a bugged channel, it keeps connecting and disconnecting as before. How is this possible without revoking the erroneous state? And if it's revoked why does it keep sending warnings and disconnecting me?

ziggie1984 commented 1 year ago

Funny thing: I now have an incoming HTLC in a bugged channel, it keeps connecting and disconnecting as before. How is this possible without revoking the erroneous state? And if it's revoked why does it keep sending warnings and disconnecting me?

@wtogami I think CLN still tried to add a new Outgoing HTLC (on their remote commitment tx) although they block the ChannelState machine from continuing (don't accept the feeupdate), I guess CLN has an edge case here where they should definitely mark the channel as not usable instead of trying to add another HTLC to it as long as a remote update (feeupdate here) is not accepted?

wtogami commented 1 year ago

@wtogami I think CLN still tried to add a new Outgoing HTLC (on their remote commitment tx) although they block the ChannelState machine from continuing (don't accept the feeupdate), I guess CLN has an edge case here where they should definitely mark the channel as not usable instead of trying to add another HTLC to it as long as a remote update (feeupdate here) is not accepted?

I asked CLN devs. Response was roughly, "Sure we could do that but it doesn't help much."

Even if they did it doesn't prevent these LND channels from becoming and staying stuck. That only reduces the chance of the stuck channel from becoming a force close. I've otherwise seen these stuck channels go months without a force close because there were no pending HTLCs to become expired.

CLN v23.08 has a new way for CLN admins to temporarily accept the bad update_fee so the channel can get unstuck. I've used this a dozen times in past weeks.

2023-09-05T02:41:11.761Z INFO    0360a41eb8c3fe09782ef6c984acbb003b0e1ebc4fe10ae01bab0e80d76618c8f4-chan#7040: Peer transient failure in CHANNELD_NORMAL: channeld WARNING: update_fee 1011 outside range 1736-32700 (currently 1564)
# lightning-cli setchannel -k id=0360a41eb8c3fe09782ef6c984acbb003b0e1ebc4fe10ae01bab0e80d76618c8f4 ignorefeelimits=true
# lightning-cli connect 0360a41eb8c3fe09782ef6c984acbb003b0e1ebc4fe10ae01bab0e80d76618c8f4
2023-09-05T02:46:23.476Z UNUSUAL 0360a41eb8c3fe09782ef6c984acbb003b0e1ebc4fe10ae01bab0e80d76618c8f4-chan#7040: Ignoring fee limits!
# lightning-cli setchannel -k id=0360a41eb8c3fe09782ef6c984acbb003b0e1ebc4fe10ae01bab0e80d76618c8f4 ignorefeelimits=false
rkfg commented 1 year ago

A little update, since the fees have dropped to 1 sat/vB and I didn't force close any channels that were disabled due to this bug, they came back to life during the last few days. Hopefully #7805 is finalized and merged soon.

tsjk commented 11 months ago

@ziggie1984 I have bitcoind RPC (Bitcoin Core version v23.0.0) backend. Full, indexed.

{
  "feerate": 0.00031121,
  "blocks": 3
}

I have maxmempool=3000 in my bitcoin settings in order to prevent 7156 issue ( #7156 (comment) ).

I can't reach my peers with this problem (unfortunately none of them), but I assume they have CLN. I'll let you know the details as soon as I know them.

Doesn't changing the mempool size influence fee estimation? I mean, the bigger you local mempool is, the better is your estimate is, but it's also likely lower than with a smaller one - because the ones unconfirmed have lower fees. I also don't know what confirmation target the force close fee aims for, but if it doesn't aim for urgency a larger pool possibly leads to lower estimates. I'm not a dev, so don't know the details, and am just guessing here. But, unless estimation just uses some subset of the mempool or the force close fee uses a very low conf target there might be a problem with differing mempool sizes. E.g. If we have a 1GB pool with lots of 1 sat/vB txs that are unconfirmed while the fees for priority txs are 50+ sat/vB (like today), fee estimations using a 3GB pool and a default 300MB one will have difficulties reaching consensus.

tsjk commented 11 months ago

@wtogami I think CLN still tried to add a new Outgoing HTLC (on their remote commitment tx) although they block the ChannelState machine from continuing (don't accept the feeupdate), I guess CLN has an edge case here where they should definitely mark the channel as not usable instead of trying to add another HTLC to it as long as a remote update (feeupdate here) is not accepted?

I asked CLN devs. Response was roughly, "Sure we could do that but it doesn't help much."

Even if they did it doesn't prevent these LND channels from becoming and staying stuck. That only reduces the chance of the stuck channel from becoming a force close. I've otherwise seen these stuck channels go months without a force close because there were no pending HTLCs to become expired.

CLN v23.08 has a new way for CLN admins to temporarily accept the bad update_fee so the channel can get unstuck. I've used this a dozen times in past weeks.

2023-09-05T02:41:11.761Z INFO    0360a41eb8c3fe09782ef6c984acbb003b0e1ebc4fe10ae01bab0e80d76618c8f4-chan#7040: Peer transient failure in CHANNELD_NORMAL: channeld WARNING: update_fee 1011 outside range 1736-32700 (currently 1564)
# lightning-cli setchannel -k id=0360a41eb8c3fe09782ef6c984acbb003b0e1ebc4fe10ae01bab0e80d76618c8f4 ignorefeelimits=true
# lightning-cli connect 0360a41eb8c3fe09782ef6c984acbb003b0e1ebc4fe10ae01bab0e80d76618c8f4
2023-09-05T02:46:23.476Z UNUSUAL 0360a41eb8c3fe09782ef6c984acbb003b0e1ebc4fe10ae01bab0e80d76618c8f4-chan#7040: Ignoring fee limits!
# lightning-cli setchannel -k id=0360a41eb8c3fe09782ef6c984acbb003b0e1ebc4fe10ae01bab0e80d76618c8f4 ignorefeelimits=false

Yes, that's very nice of them. But I for one will never ever use this, and will opt for ditching my lnd (or otherwise broken) peer and not risking a force close tx with that peer to get stuck. The only use case this has for me, is to allow the channel to come online and then immediately negotiate a cooperative close with the faulty peer. But even that is risky, since if something happens along that path one is a bit screwed.

babikpatient6 commented 10 months ago

Yes, that's very nice of them. But I for one will never ever use this, and will opt for ditching my lnd (or otherwise broken) peer and not risking a force close tx with that peer to get stuck. The only use case this has for me, is to allow the channel to come online and then immediately negotiate a cooperative close with the faulty peer. But even that is risky, since if something happens along that path one is a bit screwed.

There are mostly legit reasons why could peer temporarily lose mempool rather then being somehow "broken". For example any kind of hw migration, ibd or up until recently (https://github.com/bitcoin/bitcoin/issues/27722) potentially every bitcoin core reboot could lead to loss of mempool data, causing this issue. Within few hours after boot w/o mempool data bitcoin node will develop reasonably accurate tip of mempool nomatter of set mempool limit (accuracy of the tip is much more important then size for fee estimation). So unless your peer is shortly after such boot, you can unstuck the channel with cln, give it few minutes and then change setchannel back and done.

mrfelton commented 8 months ago

We just lost a couple of channels to this issue and have had to force close them in order to reclaim the locked funds in them. I believe it happened when we restarted our bitcoind node with an updated mempool config, causing it to drop and resync. This in turn caused our bitcoin fee estimates to be getting returned as 1 sat/byte for a period, resulting in channel state updates that caused this eternal disconnect loop from the remote peer.

Roasbeef commented 7 months ago

This in turn caused our bitcoin fee estimates to be getting returned as 1 sat/byte for a period, resulting in channel state updates that caused this eternal disconnect loop from the remote peer.

This PR will help to resolve this (avoid sharp changes in fee rate): https://github.com/lightningnetwork/lnd/pull/7805