[bug]: `OpenChannel` randomly fails with `peer XXX is not online`

[ZZiigguurraatt]

I'm having a random issue when trying to use OpenChannel. The RPC call fails with

peer 03538435429936689cac551cc0b19d15992ddb4c8294090b4cb7f0f321ffe1aff5 is not online

I can increase the frequency of this issue by running stress-ng -q --cpu 0 in another tab, so it seems as though it is some kind of race condition related to system loading.

I'm currently running the LND version found in lightninglabs/lightning-terminal#1097 , but I've been having this issue for many months. I've failed to file an issue for this because it is random and I can't easily collect much data on the problem, but at this point I want to create some kind of issue in case anyone else out there is having a similar problem so that more perspective can be obtained.

I'm running a regtest network inside of docker. Erasing and restarting the network one or two times seems to avoid the issue.

This problem does not happen with many peers in the regtest network. When it does happen, it is not always between the same set of peers in the regtest network.

[guggero]

I think the PR you linked to is still based on the 0.19 lnd version which had the peer connection issue. Do you see in the log that the peers are being disconnected due to not responding to pings?

[ZZiigguurraatt]

I'm still getting this issue quite often. I'm now running https://github.com/lightninglabs/lightning-terminal/commits/tapd-main-branch/ . One thing I failed to mention is that immediately prior to running OpenChannel, I run ListPeers to see if we are already connected and if not I run ConnectPeer to make sure the nodes are connected first. So, I don't know why milliseconds later it would suddenly be disconnected. Possibly ConnectPeer is returning before the nodes are fully connected?

[ZZiigguurraatt]

I'm still getting this issue quite often. I'm now running https://github.com/lightninglabs/lightning-terminal/commits/tapd-main-branch/ . One thing I failed to mention is that immediately prior to running OpenChannel, I run ListPeers to see if we are already connected and if not I run ConnectPeer to make sure the nodes are connected first. So, I don't know why milliseconds later it would suddenly be disconnected. Possibly ConnectPeer is returning before the nodes are fully connected?

I've gone a few weeks with sleep(2) after ConnectPeer and I haven't had this issue. So, it seems that ConnectPeer must be returning too early.

[guggero]

I think the RPC returns once the initial TCP-level connection was successful but probably before the full Noise and p2p-level handshake has completed. That's why we always run AssertPeerConnected after a connection attempt:

lnd/lntest/harness_assertion.go

Line 86 in c4116e1

func (h *HarnessTest) AssertPeerConnected(a, b *node.HarnessNode) {

[ZZiigguurraatt]

I think the RPC returns once the initial TCP-level connection was successful but probably before the full Noise and p2p-level handshake has completed. That's why we always run AssertPeerConnected after a connection attempt:

lnd/lntest/harness_assertion.go

Line 86 in c4116e1
func (h *HarnessTest) AssertPeerConnected(a, b *node.HarnessNode) {

That makes sense that it is probably what it is doing, but should we change ConnectPeer to return after the the full Noise and p2p-level handshake has completed instead?