Idling connection keep-alive interval does not seem to be respected.

[vnermolaev]

Hi there,

I'm experiencing a strange situation and I'm unsure whether it's a bug or something I'm doing incorrectly. I hope this discussion will help clarify the issue.

Here's the setup:
I have a network of 10 nodes that need to connect to each other, forming a fully connected network. To establish these connections, each node, N, initiates connections with nodes 1 through N-1, creating a fully connected network with a single connection between each pair of nodes. Each node attempts to re-dial its peers every 5 seconds. For example, node 5 follows this logic (pseudo-code):

for callee in 1..4 {
    let dial_opts = DialOpts::peer_id(callee.id)
        .condition(PeerCondition::DisconnectedAndNotDialing)
        .addresses(vec![callee.multiaddr.clone()])
        .build();

    match self.swarm.dial(dial_opts) {
        Ok(_) => debug!("Swarm will dial {}", callee.id),
        Err(DialError::DialPeerConditionFalse(_)) => {
            trace!("Swarm skips dialing {}", callee.id)
        }
        Err(error) => warn!("Dialing failed: {error:?}"),
    }
}

In this scenario, node 5 tries to reconnect with nodes 1 through 4 if they are disconnected and not currently being dialled.

Communication between the nodes is structured as follows: nodes 1 through 7 frequently send messages to nodes 8 through 10, while nodes 8 through 10 send messages to all other nodes except themselves.

After approximately 24 hours, I restarted node 3. It successfully dials nodes 1 and 2 and is dialed by nodes 8 through 10. However, nodes 4 through 7 never attempt to reconnect to node 3, as if they don't recognize that the connection has dropped.

The key observation here is that node 3 and nodes 8 through 10 engage in heavy message exchanges, while node 3 and nodes 4 through 7 do not exchange any messages. I'd like to emphasize that I've configured the swarm to essentially never drop idle connections:
SwarmBuilder::with_swarm_config(|cfg| cfg.with_idle_connection_timeout(Duration::from_secs(u64::MAX))).

What could be causing this behaviour? Any suggestions or advice would be greatly appreciated.

PS:

libp2p = { version = "0.53.2", features = [
    "noise",
    "tcp",
    "tokio",
    "yamux",
    "macros",
    "request-response",
] }

[dariusc93]

The with_idle_connection_timeout only have it so the connection would drop after the duration if it is idle, in other words no activity (assuming the connection handler isnt marked to be kept alive).

Could you confirm the transport that youre using (ie, tcp, quic, etc)? The behaviour you describe sounds like it might be related to the quic transport since depending on the configuration it may not drop the connection right away but wait a specific duration to determine if the connection is alive and during that period, the node could have disconnected and reconnected without reporting the event unless the duration has elapsed. If this is the case, you could change your quic configuration to lower those values down further.

[vnermolaev]

It's tcp. For completeness, below is the snippet building the swarm:

pub(crate) fn build_swarm(
    keypair: identity::Keypair,
) -> Result<Swarm<MyNetworkBehaviour>, NetworkBuilderError> {
    Ok(libp2p::SwarmBuilder::with_existing_identity(keypair)
        .with_tokio()
        .with_tcp(
            tcp::Config::default().nodelay(true),
            noise::Config::new,
            yamux::Config::default,
        )?
        .with_behaviour(|_keypair| MyNetworkBehaviour::new())?
        .with_swarm_config(|cfg| cfg.with_idle_connection_timeout(Duration::from_secs(u64::MAX)))
        .build())
}

[dariusc93]

Thanks. Looks like youre only using tcp then. Could you provide any logs from the nodes?

[vnermolaev]

Can you please be more specific about what logs you're interested in? There are quite a few for 24 hours.

[dariusc93]

Mostly for nodes 4-7 when they attempt to dial node 3 after the restart.

[vnermolaev]

That's the point: they never retry.

Currently, I only collected logs from the application level, not on the libp2p level. Here is the re-dial procedure completely

pub(crate) fn dial(&mut self) {
        debug!("Dialing callees");

        for callee in &self.callees {
            let dial_opts = DialOpts::peer_id(callee.id)
                .condition(PeerCondition::DisconnectedAndNotDialing)
                .addresses(vec![callee.multiaddr.clone()])
                .build();

            match self.swarm.dial(dial_opts) {
                Ok(_) => debug!("Swarm will dial {}", callee.id),
                Err(DialError::DialPeerConditionFalse(_)) => {
                    trace!("Swarm skips dialing {}", callee.id)
                }
                Err(error) => warn!("Dialing failed: {error:?}"),
            }
        }
    }

So after node 3 has been restarted, on nodes 4-7, I get

[2024-08-06T06:55:51Z DEBUG network] Dialing callees

while on nodes 8-10, I get

[2024-08-07T07:57:55Z DEBUG network] Dialing callees
[2024-08-07T07:57:55Z DEBUG network] Swarm will dial 12D3KooWJhfyVVAmH8WGZiEx45CrPjirksooZQwhiB5JyTxFTrws

12D3KooWJhfyVVAmH8WGZiEx45CrPjirksooZQwhiB5JyTxFTrws is node 3.

The issue is challenging to reproduce as it only pops up when the nodes run for a significant amount of time; that is why I'd like to know what exactly you'd like to see; it'll take another 24 hrs (in my experience) before the issue manifests.