Failed relay reservation shuts down the whole connection

[drHuangMHT]

my relay setup broke after using libp2p direct off this repo after an update to the SwarmBuilder.
the builder part looks like this:

            let mut swarm = libp2p::SwarmBuilder::with_existing_identity(ident.get_keypair())
                .with_tokio()
                .with_tcp(
                    Default::default(),
                     libp2p_noise::Config::new,
                    libp2p_yamux::Config::default,
                )
                .expect("transport upgrade to succeed")
                .with_quic()
                .with_relay_client(
                    libp2p_noise::Config::new,
                    libp2p_yamux::Config::default,
                )
                .expect("transport upgrade to succeed")
                .with_behaviour(|_key, relay| behaviour::Behaviour {
                    relay_server: libp2p::relay::Behaviour::new(
                        self.config.local_ident.get_peer_id(),
                        self.config.relay_server,
                    ),
                    relay_client:relay,
                    // other custom protocols
                })
                .expect("behaviour incorporation to succeed")
                .build();

more details can be found here
the builder configuration is a mix of example/relay-server and example/dcutr.
with logging enabled, these messages was observed on the server side after being listened on /p2p-circuit

2023-10-28T10:24:44.174780Z DEBUG multistream_select::listener_select: Listener: sent confirmed protocol: /yamux/1.0.0    
2023-10-28T10:24:44.174827Z DEBUG yamux::connection: new connection: db05e319 (Server)    
...
2023-10-28T10:24:44.184178Z DEBUG libp2p_relay::protocol::inbound_hop: Accepting relay reservation without providing external addresses of local node. Thus the remote node might not be able to advertise its relayed address.    
...
2023-10-28T10:24:44.184778Z DEBUG owlnest::net::p2p::protocols::relay_server: Reservation from 12D3KooWKBaaZcT4Q4pC8TGXnSMXCrQsWVDv4EHCSrGRm1mKF515 accepted, IsRenew:false
2023-10-28T10:24:44.184822Z TRACE yamux::frame::io: db05e319: write: (WriteState::Init)    
2023-10-28T10:24:44.184831Z TRACE yamux::frame::io: db05e319: write: (WriteState::Init)    
2023-10-28T10:24:44.184839Z TRACE yamux::frame::io: db05e319: read: (ReadState::Header (offset 0))    
2023-10-28T10:24:44.184849Z TRACE yamux::frame::io: db05e319: write: (WriteState::Init)    
2023-10-28T10:24:44.184855Z TRACE yamux::frame::io: db05e319: write: (WriteState::Init)    
2023-10-28T10:24:44.184860Z TRACE yamux::frame::io: db05e319: read: (ReadState::Header (offset 0))    
2023-10-28T10:24:44.185146Z TRACE yamux::frame::io: db05e319: write: (WriteState::Init)    
2023-10-28T10:24:44.185165Z TRACE yamux::frame::io: db05e319: write: (WriteState::Init)    
2023-10-28T10:24:44.185191Z TRACE yamux::frame::io: db05e319: read: (ReadState::Header (offset 0))    
2023-10-28T10:24:44.185227Z TRACE yamux::connection::stream: db05e319/3: update state: (from Open { acknowledged: true } to Closed -> Closed)    
2023-10-28T10:24:44.185237Z TRACE yamux::connection::stream: db05e319/4: update state: (from Open { acknowledged: true } to Closed -> Closed)    
2023-10-28T10:24:44.185245Z TRACE yamux::connection::stream: db05e319/6: update state: (from Open { acknowledged: true } to Closed -> Closed)    
2023-10-28T10:24:44.185252Z TRACE yamux::connection::stream: db05e319/7: update state: (from Open { acknowledged: true } to Closed -> Closed)    
2023-10-28T10:24:44.185258Z TRACE yamux::connection::stream: db05e319/8: update state: (from Open { acknowledged: true } to Closed -> Closed)    
2023-10-28T10:24:44.185264Z TRACE yamux::connection::stream: db05e319/9: update state: (from Open { acknowledged: true } to Closed -> Closed)    
2023-10-28T10:24:44.185269Z TRACE yamux::connection::stream: db05e319/10: update state: (from Open { acknowledged: true } to Closed -> Closed)    
2023-10-28T10:24:44.185275Z TRACE yamux::connection::stream: db05e319/11: update state: (from Open { acknowledged: true } to Closed -> Closed)    
2023-10-28T10:24:44.185463Z DEBUG libp2p_swarm: Connection closed with error IO(Custom { kind: Other, error: Error(Closed) }): Connected { endpoint: Listener { local_addr: "/ip4/127.0.0.1/tcp/10086", send_back_addr: "/ip4/127.0.0.1/tcp/12032" }, peer_id: PeerId("12D3KooWKBaaZcT4Q4pC8TGXnSMXCrQsWVDv4EHCSrGRm1mKF515") }; Total (peer): 0.    

at this point the connection to client side was completely shutdown and the relay was not considered connected by the client(swarm.is_connected() returned false)
the log on the client side:

2023-10-28T10:24:44.170364Z DEBUG yamux::connection: new connection: 573da22c (Client)    
2023-10-28T10:24:44.170399Z TRACE libp2p_core::upgrade::apply: Upgraded outbound stream to /yamux/1.0.0    
2023-10-28T10:24:44.170754Z DEBUG libp2p_kad::handler: Operating in client-mode on new outbound connection to 12D3KooWDHAf6dUgwkbYRRx88o6kLb1hxCb5aEe1HvtgXuNoypdv    
...
2023-10-28T10:24:44.184669Z TRACE yamux::connection::stream: 573da22c/5: update state: (from Open { acknowledged: true } to RecvClosed -> RecvClosed)    
2023-10-28T10:24:44.184676Z TRACE yamux::frame::io: 573da22c: write: (WriteState::Init)    
2023-10-28T10:24:44.184682Z TRACE yamux::frame::io: 573da22c: write: (WriteState::Init)    
2023-10-28T10:24:44.184688Z TRACE yamux::frame::io: 573da22c: read: (ReadState::Init)    
2023-10-28T10:24:44.184694Z TRACE yamux::frame::io: 573da22c: read: (ReadState::Header (offset 0))    
2023-10-28T10:24:44.184715Z TRACE yamux::frame::io: 573da22c: write: (WriteState::Init)    
2023-10-28T10:24:44.184723Z TRACE yamux::frame::io: 573da22c: write: (WriteState::Init)    
2023-10-28T10:24:44.184729Z TRACE yamux::frame::io: 573da22c: read: (ReadState::Header (offset 0))    
2023-10-28T10:24:44.184788Z TRACE yamux::connection::stream: 573da22c/5: read 21 bytes    
2023-10-28T10:24:44.184928Z TRACE yamux::connection::stream: 573da22c/3: update state: (from Open { acknowledged: true } to Closed -> Closed)    
2023-10-28T10:24:44.184940Z TRACE yamux::connection::stream: 573da22c/4: update state: (from Open { acknowledged: true } to Closed -> Closed)    
2023-10-28T10:24:44.184947Z TRACE yamux::connection::stream: 573da22c/5: update state: (from RecvClosed to Closed -> Closed)    
2023-10-28T10:24:44.184953Z TRACE yamux::connection::stream: 573da22c/6: update state: (from Open { acknowledged: true } to Closed -> Closed)    
2023-10-28T10:24:44.184959Z TRACE yamux::connection::stream: 573da22c/7: update state: (from Open { acknowledged: true } to Closed -> Closed)    
2023-10-28T10:24:44.184966Z TRACE yamux::connection::stream: 573da22c/8: update state: (from Open { acknowledged: true } to Closed -> Closed)    
2023-10-28T10:24:44.184972Z TRACE yamux::connection::stream: 573da22c/9: update state: (from Open { acknowledged: true } to Closed -> Closed)    
2023-10-28T10:24:44.184978Z TRACE yamux::connection::stream: 573da22c/10: update state: (from Open { acknowledged: true } to Closed -> Closed)    
2023-10-28T10:24:44.184984Z TRACE yamux::connection::stream: 573da22c/11: update state: (from Open { acknowledged: true } to Closed -> Closed)    
2023-10-28T10:24:44.185112Z DEBUG libp2p_swarm: Connection closed with error Handler(RelayClient(Left(Apply(Right(NoAddressesInReservation))))): Connected { endpoint: Dialer { address: "/ip4/127.0.0.1/tcp/10086/p2p/12D3KooWDHAf6dUgwkbYRRx88o6kLb1hxCb5aEe1HvtgXuNoypdv", role_override: Dialer }, peer_id: PeerId("12D3KooWDHAf6dUgwkbYRRx88o6kLb1hxCb5aEe1HvtgXuNoypdv") }; Total (peer): 0.    
2023-10-28T10:24:44.185292Z DEBUG libp2p_swarm: Listener ListenerId(1); Closed by Ok(()).    
2023-10-28T10:24:44.185320Z  INFO owlnest::net::p2p::swarm: Listener on address [] closed: Ok(())

you can establish a direct connection to the server node and other protocols work as expected, but once you attempt to listen on /p2p-circuit of the relay server, the whole connection will be shutdown.
things work before the update.

[drHuangMHT]

The behaviour is generated with a custom macro, not builtin NetworkBehaviour derive macro. I did some testing after changing to NetworkBehaviour derive macro but the problem persisted.

[dariusc93]

2023-10-28T10:24:44.184178Z DEBUG libp2p_relay::protocol::inbound_hop: Accepting relay reservation without providing external addresses of local node. Thus the remote node might not be able to advertise its relayed address.

Its because its checking to see if there are addresses. You would need to add an external address to your relay node using Swarm::add_external_address

rust-libp2p/protocols/relay/src/protocol/outbound_hop.rs

Lines 149 to 151 in 459c9d4

	if reservation.addrs.is_empty() {
	return Err(FatalUpgradeError::NoAddressesInReservation);
	}

What you could do is add the external address after SwarmEvent::NewListenAddr event was emitted from swarm. Not exactly ideal though since you dont want a local address to be treated as an external address to a remote node, which would require some checks on the address, but for testing and CI, it should help.

[dariusc93]

Though I do think that we should not accept the reservation if we dont have an external address for the relay node to use, which would prevent this confusion in the first place.

Thoughts @thomaseizinger ?

[drHuangMHT]

Have no idea what makes it behave differently. A couple of month ago, like in May, after 0.52 was released, I only need to listen on one address and clients can listen on that address for circuits. For example the server would only need to listen on /ip4/127.0.0.1/4242 and the client would simply listen on /ip4/127.0.0.1/4242/p2p/peer_id_of_relay_server/p2p-circuit without any problem. This functionality is critical and I've been extensively testing it(though manually), so I think there is more to the change. External address thing aside, is it a desired behaviour that the connection be completely shutdown in this case?

[thomaseizinger]

Yeah, conceptually I hope this makes sense. If the relay server doesn't have an external address, it is of no use to any client. Remember that relays are primarily used for circumventing NAT and other connectivity issues. If the client is in the same network as their other peers, having a relay server doesn't really make sense, right?

[drHuangMHT]

If the relay server doesn't have an external address, it is of no use to any client.

Agree. That makes sense. In that case, I think there's a commit that no longer lists local address(127.0.0.1) that is newly listened on as external address by default.

[thomaseizinger]

I think there's a commit that no longer lists local address(127.0.0.1) that is newly listened on as external address by default.

Yeah we reworked external addresses a while back, see #3954.

[thomaseizinger]

You'll be pleased to hear that I'vs literally been working on this as part of a bigger effort:

• feat(relay): don't close connections upon errors in relay server #4718
• feat(relay): propagate errors to Transport::{listen_on,dial}  #4745
• swarm: Remove ConnectionHandler::Error #3591

I fully agree with you that connections should not be shut done upon errors on streams.

I'll look into your issue in detail on Monday :)