lightning icon indicating copy to clipboard operation
lightning copied to clipboard

Channels get arbitrarily marked as inactive

Open zerofeerouting opened this issue 1 year ago • 4 comments

Issue and Steps to Reproduce

My CLN node 038fe1bd966b5cb0545963490c631eaa1924e2c4c0ea4e7dcb5d4582a1e7f2f1a5 seems to arbitrarily mark some channels as inactive "active": false.

In listpeers the channel looks up and running albeit the channel is marked as inactive on listchannels.

If I execute a setchannel command, the channel will be marked as active again (see Workaround to fix).

The peer in this example is a clearnet peer, so TOR can be ruled out as the culprit 0317983322379d859c0d43a90c8dcd3e7239b8e0671b00a657ce3924d4498f3754@198.58.118.99:9735.
https://amboss.space/node/0317983322379d859c0d43a90c8dcd3e7239b8e0671b00a657ce3924d4498f3754

As far as I can tell, they're running CLN as well, so it does not seem to be an interoperability issue.

Excerpt from listchannels

      {
         "source": "0317983322379d859c0d43a90c8dcd3e7239b8e0671b00a657ce3924d4498f3754",
         "destination": "038fe1bd966b5cb0545963490c631eaa1924e2c4c0ea4e7dcb5d4582a1e7f2f1a5",
         "short_channel_id": "745944x1893x1",
         "public": true,
         "satoshis": 100000000,
         "amount_msat": "100000000000msat",
         "message_flags": 1,
         "channel_flags": 0,
         "active": true,
         "last_update": 1660621498,
         "base_fee_millisatoshi": 0,
         "fee_per_millionth": 144,
         "delay": 34,
         "htlc_minimum_msat": "0msat",
         "htlc_maximum_msat": "99000000000msat",
         "features": ""
      },
      {
         "source": "038fe1bd966b5cb0545963490c631eaa1924e2c4c0ea4e7dcb5d4582a1e7f2f1a5",
         "destination": "0317983322379d859c0d43a90c8dcd3e7239b8e0671b00a657ce3924d4498f3754",
         "short_channel_id": "745944x1893x1",
         "public": true,
         "satoshis": 100000000,
         "amount_msat": "100000000000msat",
         "message_flags": 1,
         "channel_flags": 3,
         "active": false,
         "last_update": 1660147710,
         "base_fee_millisatoshi": 0,
         "fee_per_millionth": 0,
         "delay": 34,
         "htlc_minimum_msat": "1msat",
         "htlc_maximum_msat": "99000000000msat",
         "features": ""
      }

Excerpt from listpeers

{
         "id": "0317983322379d859c0d43a90c8dcd3e7239b8e0671b00a657ce3924d4498f3754",
         "connected": true,
         "netaddr": [
            "198.58.118.99:48952"
         ],
         "features": "080a69a2",
         "channels": [
            {
               "state": "CHANNELD_NORMAL",
               "scratch_txid": "8dda2c8adc132b3da1114a54171835f20795371a2cab3239cf81d9b1fdfca329",
               "last_tx_fee": "947000msat",
               "last_tx_fee_msat": "947000msat",
               "feerate": {
                  "perkw": 1055,
                  "perkb": 4220
               },
               "owner": "channeld",
               "short_channel_id": "745944x1893x1",
               "direction": 1,
               "channel_id": "2368d24ebc1b6377e97290b01334dd45f8f581116ec8c856de54bc8e8474e48b",
               "funding_txid": "8ae474848ebc54de56c8c86e1181f5f845dd3413b09072e977631bbc4ed26823",
               "funding_outnum": 1,
               "close_to_addr": "bc1q963224zqy6c5za309vpanmr49l2q7gs7l0xumj",
               "close_to": "00142ea2a5544026b141762f2b03d9ec752fd40f221e",
               "private": false,
               "opener": "local",
               "closer": null,
               "features": [
                  "option_static_remotekey"
               ],
               "funding_allocation_msat": {
                  "0317983322379d859c0d43a90c8dcd3e7239b8e0671b00a657ce3924d4498f3754": 0,
                  "038fe1bd966b5cb0545963490c631eaa1924e2c4c0ea4e7dcb5d4582a1e7f2f1a5": 100000000000
               },
               "funding_msat": {
                  "0317983322379d859c0d43a90c8dcd3e7239b8e0671b00a657ce3924d4498f3754": "0msat",
                  "038fe1bd966b5cb0545963490c631eaa1924e2c4c0ea4e7dcb5d4582a1e7f2f1a5": "100000000000msat"
               },
               "funding": {
                  "local_msat": "100000000000msat",
                  "remote_msat": "0msat",
                  "pushed_msat": "0msat"
               },
               "msatoshi_to_us": 53739930532,
               "to_us_msat": "53739930532msat",
               "msatoshi_to_us_min": 1003751887,
               "min_to_us_msat": "1003751887msat",
               "msatoshi_to_us_max": 100000000000,
               "max_to_us_msat": "100000000000msat",
               "msatoshi_total": 100000000000,
               "total_msat": "100000000000msat",
               "fee_base_msat": "0msat",
               "fee_proportional_millionths": 0,
               "dust_limit_satoshis": 546,
               "dust_limit_msat": "546000msat",
               "max_htlc_value_in_flight_msat": 18446744073709551615,
               "max_total_htlc_in_msat": "18446744073709551615msat",
               "their_channel_reserve_satoshis": 1000000,
               "their_reserve_msat": "1000000000msat",
               "our_channel_reserve_satoshis": 1000000,
               "our_reserve_msat": "1000000000msat",
               "spendable_msatoshi": 4294967295,
               "spendable_msat": "4294967295msat",
               "receivable_msatoshi": 4294967295,
               "receivable_msat": "4294967295msat",
               "htlc_minimum_msat": 0,
               "minimum_htlc_in_msat": "0msat",
               "minimum_htlc_out_msat": "1msat",
               "maximum_htlc_out_msat": "99000000000msat",
               "their_to_self_delay": 144,
               "our_to_self_delay": 144,
               "max_accepted_htlcs": 30,
               "state_changes": [
                  {
                     "timestamp": "2022-07-21T23:14:39.680Z",
                     "old_state": "CHANNELD_AWAITING_LOCKIN",
                     "new_state": "CHANNELD_NORMAL",
                     "cause": "user",
                     "message": "Lockin complete"
                  }
               ],
               "status": [
                  "CHANNELD_NORMAL:Reconnected, and reestablished.",
                  "CHANNELD_NORMAL:Funding transaction locked. Channel announced."
               ],
               "in_payments_offered": 20671,
               "in_msatoshi_offered": 44548076049348,
               "in_offered_msat": "44548076049348msat",
               "in_payments_fulfilled": 883,
               "in_msatoshi_fulfilled": 478258261132,
               "in_fulfilled_msat": "478258261132msat",
               "out_payments_offered": 85584,
               "out_msatoshi_offered": 16347241303830,
               "out_offered_msat": "16347241303830msat",
               "out_payments_fulfilled": 2892,
               "out_msatoshi_fulfilled": 524518330600,
               "out_fulfilled_msat": "524518330600msat",
               "htlcs": [
                  {
                     "direction": "out",
                     "id": 85536,
                     "msatoshi": 996270856,
                     "amount_msat": "996270856msat",
                     "expiry": 749984,
                     "payment_hash": "0ce269e50c6141b2aa25eb6436e1f1f5958c8ac594667f45bca67cb9a86dae2b",
                     "state": "SENT_ADD_ACK_REVOCATION"
                  }
               ]
            }

Logs

I don't really have logs prior to changing the feerate. After changing the logs start with:

2022-08-16T06:30:38.508Z DEBUG   0317983322379d859c0d43a90c8dcd3e7239b8e0671b00a657ce3924d4498f3754-channeld-chan#26102: peer_in WIRE_UPDATE_FAIL_HTLC
2022-08-16T06:30:38.508Z DEBUG   0317983322379d859c0d43a90c8dcd3e7239b8e0671b00a657ce3924d4498f3754-channeld-chan#26102: FAIL:: HTLC LOCAL 85584 = RCVD_REMOVE_HTLC/SENT_REMOVE_HTLC 
2022-08-16T06:30:38.519Z DEBUG   0317983322379d859c0d43a90c8dcd3e7239b8e0671b00a657ce3924d4498f3754-channeld-chan#26102: Trying commit
2022-08-16T06:30:38.519Z DEBUG   0317983322379d859c0d43a90c8dcd3e7239b8e0671b00a657ce3924d4498f3754-channeld-chan#26102: Can't send commit: nothing to send, feechange not wanted ({ SENT_ADD_ACK_REVOCATION:1055 }) blockheight not wanted ({ SENT_ADD_ACK_REVOCATION:0 })
2022-08-16T06:30:38.967Z DEBUG   0317983322379d859c0d43a90c8dcd3e7239b8e0671b00a657ce3924d4498f3754-channeld-chan#26102: peer_in WIRE_COMMITMENT_SIGNED
2022-08-16T06:30:38.967Z DEBUG   0317983322379d859c0d43a90c8dcd3e7239b8e0671b00a657ce3924d4498f3754-channeld-chan#26102: Received commit
2022-08-16T06:30:38.968Z DEBUG   0317983322379d859c0d43a90c8dcd3e7239b8e0671b00a657ce3924d4498f3754-channeld-chan#26102: htlc 85584: RCVD_REMOVE_HTLC->RCVD_REMOVE_COMMIT
2022-08-16T06:30:38.968Z DEBUG   0317983322379d859c0d43a90c8dcd3e7239b8e0671b00a657ce3924d4498f3754-channeld-chan#26102: htlc added LOCAL: local 53689922568 remote 46260069468
2022-08-16T06:30:38.968Z DEBUG   0317983322379d859c0d43a90c8dcd3e7239b8e0671b00a657ce3924d4498f3754-channeld-chan#26102: -> local 53739930532 remote 46260069468
2022-08-16T06:30:38.968Z DEBUG   0317983322379d859c0d43a90c8dcd3e7239b8e0671b00a657ce3924d4498f3754-channeld-chan#26102: rcvd_commit: HTLC LOCAL 85584 = RCVD_REMOVE_COMMIT/SENT_REMOVE_COMMIT FAILED

Workaround to fix

UPDATE 2022-08-18: A better workaround (without gossip spam) is to just disconnect and reconnect the peer.

If I update the fee of the channel (probably any gossip data) lightning-cli setchannel -k id=745944x1893x1 feeppm=2000, the channel gets marked as active again in listchannels:

{
         "source": "038fe1bd966b5cb0545963490c631eaa1924e2c4c0ea4e7dcb5d4582a1e7f2f1a5",
         "destination": "0317983322379d859c0d43a90c8dcd3e7239b8e0671b00a657ce3924d4498f3754",
         "short_channel_id": "745944x1893x1",
         "public": true,
         "satoshis": 100000000,
         "amount_msat": "100000000000msat",
         "message_flags": 1,
         "channel_flags": 1,
         "active": true,
         "last_update": 1660631224,
         "base_fee_millisatoshi": 0,
         "fee_per_millionth": 2000,
         "delay": 34,
         "htlc_minimum_msat": "1msat",
         "htlc_maximum_msat": "99000000000msat",
         "features": ""
      }

I need to actively change a setting. If I set feeppm to 0 (as it was when the channel was inactive), the channel will not get set to active.

getinfo output

v0.11.2

zerofeerouting avatar Aug 16 '22 06:08 zerofeerouting

Thank you @rustyrussell!

zerofeerouting avatar Aug 16 '22 09:08 zerofeerouting

Out of my 110+ channels i have (at the moment) 4 channels where my node says connected = true in listpeers and in listchannels one of the sides (not both) says active = false. With 3 out of those 4 channels my node partners are the ones who have active = false and with one channel its my node who has active = false listed and guess which node that is Mr. zerofeerouting?

Edit: Workaround only seems to work if it's your own node that is wrongly "reporting" active = false. So i could only fix the one channel not the other 3. Edit2: also on v0.11.2

Spoiler! It's you :)

daywalker90 avatar Aug 16 '22 14:08 daywalker90

Just a quick update on the workaround.

As suggested by @wtogami - it also works to force-disconnect and reconnect the peer. So this should actually be the preferred method to avoid gossip spamming the network.

Better workaround

lightning-cli disconnect [peer-id] true
lightning-cli connect [peer-id]

zerofeerouting avatar Aug 18 '22 14:08 zerofeerouting

I may have had this problem yesterday. My node was connected to most of its peers (as many as it ever does), but it had not forwarded any payments for several hours. (Usually it forwards at least one every few minutes.) I was able to connect my mobile wallet (Breez/LND) to my node, but that wallet showed my channel as inactive. Only after I restarted my CLN node did my mobile wallet show my channel as active. Also worthy of noting: Terminal Score Debugger was saying my node had over a 50% channel disable ratio. Today it's down to 20%, which is still higher than I'd like but honestly fairly realistic since I am only ever connected to around 80-85% of my channel peers at any given time.

whitslack avatar Oct 08 '22 16:10 whitslack