Can't hold peers for longer than 2 minutes - connectd: peer_out WIRE_WARNING | connectd: drain_peer

[jmoasth]

I've been struggling to figure out what's going on for the past week, and I hope this is the right place to put this. It seems like it's a problem with gossip.

Issue and Steps to Reproduce

I'm running a Linux VM Ubuntu 22.04.1 LTS with Bitcoin Core v24, Core Lightning v22.11.rc3.

I attached a lightning.log with DEBUG level info from the lightning log dir. Hopefully it has the information needed
lightning.log

getinfo output

{
   "id": "031d41bd502c8971c27189fcc94f1283d6feb9cd9bc19c2f66aa8dede501bf366a",
   "alias": "bhd",
   "color": "000000",
   "num_peers": 1,
   "num_pending_channels": 0,
   "num_active_channels": 0,
   "num_inactive_channels": 1,
   "address": [
      {
         "type": "torv3",
         "address": "2movtx6aqudlysujkmuow5xybq37dwdfp4if33jmfao6hjkzlmkstwad.onion",
         "port": 9736
      }
   ],
   "binding": [
      {
         "type": "ipv4",
         "address": "0.0.0.0",
         "port": 9736
      }
   ],
   "version": "v22.11rc3",
   "blockheight": 767103,
   "network": "bitcoin",
   "msatoshi_fees_collected": 0,
   "fees_collected_msat": "0msat",
   "lightning-dir": "/data/lightning/.lightning/bitcoin",
   "our_features": {
      "init": "08a088082a69a2",
      "node": "88a088082a69a2",
      "channel": "",
      "invoice": "02000000024100"
   }
}

[jmoasth]

These are the logs for trying to connect to my personal node running Umbrel LND.

2022-12-12T18:57:43.027Z DEBUG   connectd: Now try LN connect out for host 4ea55p5546gip22ydcoepmx5usp2otml3so22vyndh47ebexvm7jluqd.onion
2022-12-12T18:57:43.027Z DEBUG   028da8c4989b4d31faf1a8bb285f59c87bc164e3e8b9ba4ac036cf4df55d54a338-connectd: Connected out, starting crypto
2022-12-12T18:57:45.453Z DEBUG   031d41bd502c8971c27189fcc94f1283d6feb9cd9bc19c2f66aa8dede501bf366a-hsmd: Got WIRE_HSMD_ECDH_REQ
2022-12-12T18:57:45.453Z DEBUG   hsmd: Client: Received message 1 from client
2022-12-12T18:57:45.453Z DEBUG   028da8c4989b4d31faf1a8bb285f59c87bc164e3e8b9ba4ac036cf4df55d54a338-connectd: Connect OUT
2022-12-12T18:57:45.453Z DEBUG   028da8c4989b4d31faf1a8bb285f59c87bc164e3e8b9ba4ac036cf4df55d54a338-connectd: peer_out WIRE_INIT
2022-12-12T18:57:47.832Z DEBUG   028da8c4989b4d31faf1a8bb285f59c87bc164e3e8b9ba4ac036cf4df55d54a338-connectd: peer_in WIRE_INIT
2022-12-12T18:57:47.833Z DEBUG   028da8c4989b4d31faf1a8bb285f59c87bc164e3e8b9ba4ac036cf4df55d54a338-gossipd: seeker: chosen as startup peer
2022-12-12T18:57:47.833Z DEBUG   028da8c4989b4d31faf1a8bb285f59c87bc164e3e8b9ba4ac036cf4df55d54a338-connectd: Handed peer, entering loop
2022-12-12T18:57:47.833Z DEBUG   028da8c4989b4d31faf1a8bb285f59c87bc164e3e8b9ba4ac036cf4df55d54a338-gossipd: seeker: starting gossip
2022-12-12T18:57:47.833Z DEBUG   028da8c4989b4d31faf1a8bb285f59c87bc164e3e8b9ba4ac036cf4df55d54a338-connectd: peer_out WIRE_GOSSIP_TIMESTAMP_FILTER
2022-12-12T18:57:54.157Z DEBUG   028da8c4989b4d31faf1a8bb285f59c87bc164e3e8b9ba4ac036cf4df55d54a338-connectd: peer_out WIRE_WARNING
2022-12-12T18:57:54.157Z DEBUG   connectd: drain_peer
2022-12-12T18:57:54.158Z DEBUG   028da8c4989b4d31faf1a8bb285f59c87bc164e3e8b9ba4ac036cf4df55d54a338-lightningd: peer_disconnect_done
2022-12-12T18:57:54.158Z DEBUG   028da8c4989b4d31faf1a8bb285f59c87bc164e3e8b9ba4ac036cf4df55d54a338-lightningd: Not reconnecting: no active channel
2022-12-12T18:57:54.158Z DEBUG   connectd: maybe_free_peer freeing peer!
2022-12-12T18:57:54.158Z DEBUG   plugin-funder: Cleaning up inflights for peer id 028da8c4989b4d31faf1a8bb285f59c87bc164e3e8b9ba4ac036cf4df55d54a338
2022-12-12T18:57:54.159Z DEBUG   028da8c4989b4d31faf1a8bb285f59c87bc164e3e8b9ba4ac036cf4df55d54a338-gossipd: Received channel_announcement for channel 581615x281x1
2022-12-12T18:57:54.159Z DEBUG   028da8c4989b4d31faf1a8bb285f59c87bc164e3e8b9ba4ac036cf4df55d54a338-gossipd: Updated pending announce with update 581615x281x1/0
2022-12-12T18:57:54.160Z DEBUG   028da8c4989b4d31faf1a8bb285f59c87bc164e3e8b9ba4ac036cf4df55d54a338-gossipd: Updated pending announce with update 581615x281x1/1
2022-12-12T18:57:54.160Z DEBUG   028da8c4989b4d31faf1a8bb285f59c87bc164e3e8b9ba4ac036cf4df55d54a338-gossipd: Received channel_announcement for channel 581615x282x0
2022-12-12T18:57:54.161Z DEBUG   028da8c4989b4d31faf1a8bb285f59c87bc164e3e8b9ba4ac036cf4df55d54a338-gossipd: Received channel_update for channel 581615x281x1/1 now DISABLED
2022-12-12T18:57:54.161Z DEBUG   028da8c4989b4d31faf1a8bb285f59c87bc164e3e8b9ba4ac036cf4df55d54a338-gossipd: Updated pending announce with update 581615x282x0/0
2022-12-12T18:57:54.161Z DEBUG   028da8c4989b4d31faf1a8bb285f59c87bc164e3e8b9ba4ac036cf4df55d54a338-gossipd: Updated pending announce with update 581615x282x0/1
2022-12-12T18:57:54.161Z DEBUG   gossipd: Received channel_update for channel 581615x282x0/1 now DISABLED

[Coinomatron]

Have a 2nd node on tor that has the same behavior. In my case, I think it may be because I connect via an address generated by tor-browser (easiest tor connect settings at the time). For now, fixed it with a script that connects to nodes every few hundred seconds.

Edit: doesn't seem to work anymore.
Edit 2: killed the node, latest CLN build+latest tor still gave the same issue. Wild guess is port interference with the clearnet node behind the same router on a different machine.