dialing client raised `Connection closed with error NoAddresses`, relay server log is `no protocol could be agreed upon for inbound stream`
Nobody has claimed this yet.
- Dominant language
- Rust
- Stars
- 5.6k
- Forks
- 1.3k
- Avg merge
- 8h 47m
- Merged PRs (30d)
- 19
Description
Summary
I started by the docs in libp2p/src/tutorials/hole_punching.rs.
The relay and listening client can connect successful, but the dialing client couldn't.
When dailing client try to dial, the relay server always has a debug level log is no protocol could be agreed upon for inbound stream, and return a bytes [8, 100] to dailing client, which means CONNECT (refer rust-libp2p/protocols/dcutr/src/generated/holepunch/pb.rs) for dailing client.
Dialing client error libp2p_swarm] Connection closed with error Handler(Left(Right(Left(Apply(Left(NoAddresses)))))) .
Expected behaviour
The listening client initiating a direct connection upgrade for the new relayed connection.
Actual behaviour
Dailing client raised an error Connection closed with error Handler(Left(Right(Left(Apply(Left(NoAddresses)))))), and the connection between Dailing client and relay server broken.
Relay Debug Output
$ sudo RUST_LOG=debug ./relay --secret-key-seed 0 --port 4001
opt: Opt { use_ipv6: None, secret_key_seed: 0, port: 4001 }
Local peer id: PeerId("12D3KooWDpJ7As7BWAwRMfu1VU2WCqNjvq387JEYKDBj4kx6nXTN")
[2023-05-30T06:30:38Z DEBUG libp2p_tcp] listening on 0.0.0.0:4001
[2023-05-30T06:30:38Z DEBUG netlink_proto::handle] handle: forwarding new request to connection
[2023-05-30T06:30:38Z DEBUG netlink_proto::connection] reading incoming messages
[2023-05-30T06:30:38Z DEBUG netlink_proto::codecs] NetlinkCodec: decoding next message
[2023-05-30T06:30:38Z DEBUG netlink_proto::connection] forwarding unsolicited messages to the connection handle
[2023-05-30T06:30:38Z DEBUG netlink_proto::connection] forwaring responses to previous requests to the connection handle
[2023-05-30T06:30:38Z DEBUG netlink_proto::connection] handling requests
[2023-05-30T06:30:38Z DEBUG netlink_proto::connection] sending messages
[2023-05-30T06:30:38Z DEBUG netlink_proto::connection] reading incoming messages
[2023-05-30T06:30:38Z DEBUG netlink_proto::codecs] NetlinkCodec: decoding next message
[2023-05-30T06:30:38Z DEBUG netlink_proto::codecs] NetlinkCodec: decoding next message
[2023-05-30T06:30:38Z DEBUG netlink_proto::protocol::protocol] handling messages (request id = RequestId { sequence_number: 1, port: 0 })
[2023-05-30T06:30:38Z DEBUG netlink_proto::protocol::protocol] handling response to request RequestId { sequence_number: 1, port: 0 }
[2023-05-30T06:30:38Z DEBUG netlink_proto::protocol::protocol] done handling response to request RequestId { sequence_number: 1, port: 0 }
[2023-05-30T06:30:38Z DEBUG netlink_proto::codecs] NetlinkCodec: decoding next message
[2023-05-30T06:30:38Z DEBUG netlink_proto::protocol::protocol] handling messages (request id = RequestId { sequence_number: 1, port: 0 })
[2023-05-30T06:30:38Z DEBUG netlink_proto::protocol::protocol] handling response to request RequestId { sequence_number: 1, port: 0 }
[2023-05-30T06:30:38Z DEBUG netlink_proto::protocol::protocol] done handling response to request RequestId { sequence_number: 1, port: 0 }
[2023-05-30T06:30:38Z DEBUG netlink_proto::codecs] NetlinkCodec: decoding next message
[2023-05-30T06:30:38Z DEBUG netlink_proto::codecs] NetlinkCodec: decoding next message
[2023-05-30T06:30:38Z DEBUG netlink_proto::protocol::protocol] handling messages (request id = RequestId { sequence_number: 1, port: 0 })
[2023-05-30T06:30:38Z DEBUG netlink_proto::protocol::protocol] handling response to request RequestId { sequence_number: 1, port: 0 }
[2023-05-30T06:30:38Z DEBUG netlink_proto::protocol::protocol] done handling response to request RequestId { sequence_number: 1, port: 0 }
[2023-05-30T06:30:38Z DEBUG netlink_proto::codecs] NetlinkCodec: decoding next message
[2023-05-30T06:30:38Z DEBUG netlink_proto::protocol::protocol] handling messages (request id = RequestId { sequence_number: 1, port: 0 })
[2023-05-30T06:30:38Z DEBUG netlink_proto::protocol::protocol] handling response to request RequestId { sequence_number: 1, port: 0 }
[2023-05-30T06:30:38Z DEBUG netlink_proto::protocol::protocol] done handling response to request RequestId { sequence_number: 1, port: 0 }
[2023-05-30T06:30:38Z DEBUG netlink_proto::codecs] NetlinkCodec: decoding next message
[2023-05-30T06:30:38Z DEBUG netlink_proto::codecs] NetlinkCodec: decoding next message
[2023-05-30T06:30:38Z DEBUG netlink_proto::protocol::protocol] handling messages (request id = RequestId { sequence_number: 1, port: 0 })
[2023-05-30T06:30:38Z DEBUG netlink_proto::protocol::protocol] handling response to request RequestId { sequence_number: 1, port: 0 }
[2023-05-30T06:30:38Z DEBUG netlink_proto::protocol::protocol] done handling response to request RequestId { sequence_number: 1, port: 0 }
[2023-05-30T06:30:38Z DEBUG netlink_proto::codecs] NetlinkCodec: decoding next message
[2023-05-30T06:30:38Z DEBUG netlink_proto::connection] forwarding unsolicited messages to the connection handle
[2023-05-30T06:30:38Z DEBUG netlink_proto::connection] forwaring responses to previous requests to the connection handle
[2023-05-30T06:30:38Z DEBUG netlink_proto::connection] handling requests
[2023-05-30T06:30:38Z DEBUG netlink_proto::connection] sending messages
[2023-05-30T06:30:38Z DEBUG libp2p_tcp] New listen address: /ip4/127.0.0.1/tcp/4001
[2023-05-30T06:30:38Z DEBUG libp2p_swarm] Listener ListenerId(1); New address: "/ip4/127.0.0.1/tcp/4001"
Listening on "/ip4/127.0.0.1/tcp/4001"
[2023-05-30T06:30:38Z DEBUG netlink_proto::connection] reading incoming messages
[2023-05-30T06:30:38Z DEBUG netlink_proto::codecs] NetlinkCodec: decoding next message
[2023-05-30T06:30:38Z DEBUG netlink_proto::connection] forwarding unsolicited messages to the connection handle
[2023-05-30T06:30:38Z DEBUG netlink_proto::connection] forwaring responses to previous requests to the connection handle
[2023-05-30T06:30:38Z DEBUG netlink_proto::connection] handling requests
[2023-05-30T06:30:38Z DEBUG netlink_proto::connection] sending messages
[2023-05-30T06:30:38Z DEBUG libp2p_tcp] New listen address: /ip4/10.0.8.14/tcp/4001
[2023-05-30T06:30:38Z DEBUG libp2p_swarm] Listener ListenerId(1); New address: "/ip4/10.0.8.14/tcp/4001"
Listening on "/ip4/10.0.8.14/tcp/4001"
[2023-05-30T06:30:38Z DEBUG netlink_proto::connection] reading incoming messages
[2023-05-30T06:30:38Z DEBUG netlink_proto::codecs] NetlinkCodec: decoding next message
[2023-05-30T06:30:38Z DEBUG netlink_proto::connection] forwarding unsolicited messages to the connection handle
[2023-05-30T06:30:38Z DEBUG netlink_proto::connection] forwaring responses to previous requests to the connection handle
[2023-05-30T06:30:38Z DEBUG netlink_proto::connection] handling requests
[2023-05-30T06:30:38Z DEBUG netlink_proto::connection] sending messages
[2023-05-30T06:30:38Z DEBUG netlink_proto::connection] reading incoming messages
[2023-05-30T06:30:38Z DEBUG netlink_proto::codecs] NetlinkCodec: decoding next message
[2023-05-30T06:30:38Z DEBUG netlink_proto::connection] forwarding unsolicited messages to the connection handle
[2023-05-30T06:30:38Z DEBUG netlink_proto::connection] forwaring responses to previous requests to the connection handle
........
[2023-05-30T06:30:45Z DEBUG libp2p_tcp] Incoming connection from /ip4/115.216.2.224/tcp/27594 at /ip4/10.0.8.14/tcp/4001
[2023-05-30T06:30:45Z DEBUG multistream_select::listener_select] Listener: confirming protocol: /noise
[2023-05-30T06:30:45Z DEBUG multistream_select::listener_select] Listener: sent confirmed protocol: /noise
[2023-05-30T06:30:45Z DEBUG netlink_proto::connection] reading incoming messages
[2023-05-30T06:30:45Z DEBUG netlink_proto::codecs] NetlinkCodec: decoding next message
[2023-05-30T06:30:45Z DEBUG netlink_proto::connection] forwarding unsolicited messages to the connection handle
[2023-05-30T06:30:45Z DEBUG netlink_proto::connection] forwaring responses to previous requests to the connection handle
[2023-05-30T06:30:45Z DEBUG netlink_proto::connection] handling requests
[2023-05-30T06:30:45Z DEBUG netlink_proto::connection] sending messages
[2023-05-30T06:30:46Z DEBUG multistream_select::listener_select] Listener: confirming protocol: /yamux/1.0.0
[2023-05-30T06:30:46Z DEBUG multistream_select::listener_select] Listener: sent confirmed protocol: /yamux/1.0.0
[2023-05-30T06:30:46Z DEBUG yamux::connection] new connection: 0753d206 (Server)
[2023-05-30T06:30:46Z DEBUG libp2p_swarm] Connection established: PeerId("12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X") Listener { local_addr: "/ip4/10.0.8.14/tcp/4001", send_back_addr: "/ip4/115.216.2.224/tcp/27594" }; Total (peer): 1.
[2023-05-30T06:30:46Z DEBUG multistream_select::listener_select] Listener: confirming protocol: /ipfs/id/1.0.0
[2023-05-30T06:30:46Z DEBUG multistream_select::listener_select] Listener: sent confirmed protocol: /ipfs/id/1.0.0
[2023-05-30T06:30:46Z DEBUG yamux::connection] 0753d206: new outbound (Stream 0753d206/2) of (Connection 0753d206 Server (streams 0))
[2023-05-30T06:30:46Z DEBUG multistream_select::dialer_select] Dialer: Proposed protocol: /ipfs/id/1.0.0
[2023-05-30T06:30:46Z DEBUG multistream_select::listener_select] Listener: confirming protocol: /ipfs/ping/1.0.0
[2023-05-30T06:30:46Z DEBUG multistream_select::listener_select] Listener: sent confirmed protocol: /ipfs/ping/1.0.0
[2023-05-30T06:30:46Z DEBUG yamux::connection] 0753d206: new outbound (Stream 0753d206/4) of (Connection 0753d206 Server (streams 3))
[2023-05-30T06:30:46Z DEBUG multistream_select::dialer_select] Dialer: Proposed protocol: /ipfs/ping/1.0.0
[2023-05-30T06:30:46Z DEBUG multistream_select::listener_select] Listener: rejecting protocol: /meshsub/1.1.0
BehaviourEvent: Sent { peer_id: PeerId("12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X") }
[2023-05-30T06:30:46Z DEBUG multistream_select::dialer_select] Dialer: Received confirmation for protocol: /ipfs/id/1.0.0
[2023-05-30T06:30:46Z DEBUG multistream_select::dialer_select] Dialer: Received confirmation for protocol: /ipfs/ping/1.0.0
[2023-05-30T06:30:46Z DEBUG multistream_select::listener_select] Listener: rejecting protocol: /meshsub/1.0.0
[2023-05-30T06:30:46Z DEBUG multistream_select::listener_select] Listener: confirming protocol: /libp2p/circuit/relay/0.2.0/hop
[2023-05-30T06:30:46Z DEBUG multistream_select::listener_select] Listener: sent confirmed protocol: /libp2p/circuit/relay/0.2.0/hop
BehaviourEvent: Received { peer_id: PeerId("12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X"), info: Info { public_key: PublicKey { publickey: Ed25519(PublicKey(compressed): cecc157dc1ddd7295951c29888f095adb944d1b73d696e6df65d683bd4fc) }, protocol_version: "/TODO/0.0.1", agent_version: "rust-libp2p/0.43.0", listen_addrs: ["/ip4/172.21.0.1/tcp/44415", "/ip4/192.168.160.1/tcp/44415", "/ip4/192.168.192.1/tcp/44415", "/ip4/172.17.0.1/tcp/44415", "/ip4/10.30.6.101/tcp/44415", "/ip4/127.0.0.1/tcp/44415", "/ip4/192.168.176.1/tcp/44415", "/ip4/172.22.0.1/tcp/44415", "/ip4/192.168.144.1/tcp/44415"], protocols: [StreamProtocol { inner: Right("/ipfs/id/push/1.0.0") }, StreamProtocol { inner: Right("/meshsub/1.0.0") }, StreamProtocol { inner: Right("/ipfs/ping/1.0.0") }, StreamProtocol { inner: Right("/libp2p/circuit/relay/0.2.0/stop") }, StreamProtocol { inner: Right("/ipfs/id/1.0.0") }, StreamProtocol { inner: Right("/meshsub/1.1.0") }], observed_addr: "/ip4/114.132.71.142/tcp/4001/p2p/12D3KooWDpJ7As7BWAwRMfu1VU2WCqNjvq387JEYKDBj4kx6nXTN" } }
[2023-05-30T06:30:46Z DEBUG libp2p_ping::handler] latency to 12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X is 179ms
[2023-05-30T06:30:46Z DEBUG yamux::connection::stream] 0753d206/5: eof
[2023-05-30T06:30:46Z DEBUG libp2p_swarm::connection] no protocol could be agreed upon for inbound stream
[2023-05-30T06:30:46Z DEBUG multistream_select::listener_select] Listener: confirming protocol: /ipfs/id/push/1.0.0
[2023-05-30T06:30:46Z DEBUG multistream_select::listener_select] Listener: sent confirmed protocol: /ipfs/id/push/1.0.0
BehaviourEvent: Event { peer: PeerId("12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X"), connection: ConnectionId(1), result: Ok(179.687047ms) }
BehaviourEvent: ReservationReqAccepted { src_peer_id: PeerId("12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X"), renewed: false }
BehaviourEvent: Received { peer_id: PeerId("12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X"), info: Info { public_key: PublicKey { publickey: Ed25519(PublicKey(compressed): cecc157dc1ddd7295951c29888f095adb944d1b73d696e6df65d683bd4fc) }, protocol_version: "/TODO/0.0.1", agent_version: "rust-libp2p/0.43.0", listen_addrs: ["/ip4/172.21.0.1/tcp/44415", "/ip4/192.168.160.1/tcp/44415", "/ip4/192.168.192.1/tcp/44415", "/ip4/172.17.0.1/tcp/44415", "/ip4/10.30.6.101/tcp/44415", "/ip4/127.0.0.1/tcp/44415", "/ip4/192.168.176.1/tcp/44415", "/ip4/172.22.0.1/tcp/44415", "/ip4/192.168.144.1/tcp/44415"], protocols: [StreamProtocol { inner: Right("/ipfs/id/push/1.0.0") }, StreamProtocol { inner: Right("/ipfs/ping/1.0.0") }, StreamProtocol { inner: Right("/libp2p/circuit/relay/0.2.0/stop") }, StreamProtocol { inner: Right("/ipfs/id/1.0.0") }], observed_addr: "/ip4/114.132.71.142/tcp/4001/p2p/12D3KooWDpJ7As7BWAwRMfu1VU2WCqNjvq387JEYKDBj4kx6nXTN" } }
[2023-05-30T06:31:01Z DEBUG libp2p_ping::handler] latency to 12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X is 143ms
BehaviourEvent: Event { peer: PeerId("12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X"), connection: ConnectionId(1), result: Ok(143.976607ms) }
[2023-05-30T06:31:15Z DEBUG netlink_proto::connection] reading incoming messages
[2023-05-30T06:31:15Z DEBUG netlink_proto::codecs] NetlinkCodec: decoding next message
[2023-05-30T06:31:15Z DEBUG netlink_proto::connection] forwarding unsolicited messages to the connection handle
[2023-05-30T06:31:15Z DEBUG netlink_proto::connection] forwaring responses to previous requests to the connection handle
[2023-05-30T06:31:15Z DEBUG netlink_proto::connection] handling requests
[2023-05-30T06:31:15Z DEBUG netlink_proto::connection] sending messages
[2023-05-30T06:31:15Z DEBUG libp2p_tcp] Incoming connection from /ip4/115.216.2.224/tcp/33323 at /ip4/10.0.8.14/tcp/4001
[2023-05-30T06:31:15Z DEBUG multistream_select::listener_select] Listener: confirming protocol: /noise
[2023-05-30T06:31:15Z DEBUG multistream_select::listener_select] Listener: sent confirmed protocol: /noise
[2023-05-30T06:31:15Z DEBUG netlink_proto::connection] reading incoming messages
[2023-05-30T06:31:15Z DEBUG netlink_proto::codecs] NetlinkCodec: decoding next message
[2023-05-30T06:31:15Z DEBUG netlink_proto::connection] forwarding unsolicited messages to the connection handle
[2023-05-30T06:31:15Z DEBUG netlink_proto::connection] forwaring responses to previous requests to the connection handle
[2023-05-30T06:31:15Z DEBUG netlink_proto::connection] handling requests
[2023-05-30T06:31:15Z DEBUG netlink_proto::connection] sending messages
[2023-05-30T06:31:15Z DEBUG multistream_select::listener_select] Listener: confirming protocol: /yamux/1.0.0
[2023-05-30T06:31:15Z DEBUG multistream_select::listener_select] Listener: sent confirmed protocol: /yamux/1.0.0
[2023-05-30T06:31:15Z DEBUG yamux::connection] new connection: 73634848 (Server)
[2023-05-30T06:31:15Z DEBUG libp2p_swarm] Connection established: PeerId("12D3KooWH3uVF6wv47WnArKHk5p6cvgCJEb74UTmxztmQDc298L3") Listener { local_addr: "/ip4/10.0.8.14/tcp/4001", send_back_addr: "/ip4/115.216.2.224/tcp/33323" }; Total (peer): 1.
[2023-05-30T06:31:15Z DEBUG multistream_select::listener_select] Listener: rejecting protocol: /meshsub/1.1.0
[2023-05-30T06:31:15Z DEBUG yamux::connection] 73634848: new outbound (Stream 73634848/2) of (Connection 73634848 Server (streams 1))
[2023-05-30T06:31:15Z DEBUG multistream_select::dialer_select] Dialer: Proposed protocol: /ipfs/ping/1.0.0
[2023-05-30T06:31:15Z DEBUG multistream_select::listener_select] Listener: confirming protocol: /ipfs/id/1.0.0
[2023-05-30T06:31:15Z DEBUG multistream_select::listener_select] Listener: sent confirmed protocol: /ipfs/id/1.0.0
[2023-05-30T06:31:15Z DEBUG multistream_select::listener_select] Listener: confirming protocol: /ipfs/ping/1.0.0
[2023-05-30T06:31:15Z DEBUG multistream_select::listener_select] Listener: sent confirmed protocol: /ipfs/ping/1.0.0
[2023-05-30T06:31:15Z DEBUG yamux::connection] 73634848: new outbound (Stream 73634848/4) of (Connection 73634848 Server (streams 3))
[2023-05-30T06:31:15Z DEBUG multistream_select::dialer_select] Dialer: Proposed protocol: /ipfs/id/1.0.0
BehaviourEvent: Sent { peer_id: PeerId("12D3KooWH3uVF6wv47WnArKHk5p6cvgCJEb74UTmxztmQDc298L3") }
[2023-05-30T06:31:15Z DEBUG multistream_select::dialer_select] Dialer: Received confirmation for protocol: /ipfs/ping/1.0.0
[2023-05-30T06:31:15Z DEBUG multistream_select::dialer_select] Dialer: Received confirmation for protocol: /ipfs/id/1.0.0
[2023-05-30T06:31:15Z DEBUG multistream_select::listener_select] Listener: rejecting protocol: /meshsub/1.0.0
[2023-05-30T06:31:15Z DEBUG multistream_select::listener_select] Listener: confirming protocol: /libp2p/circuit/relay/0.2.0/hop
[2023-05-30T06:31:15Z DEBUG multistream_select::listener_select] Listener: sent confirmed protocol: /libp2p/circuit/relay/0.2.0/hop
BehaviourEvent: Received { peer_id: PeerId("12D3KooWH3uVF6wv47WnArKHk5p6cvgCJEb74UTmxztmQDc298L3"), info: Info { public_key: PublicKey { publickey: Ed25519(PublicKey(compressed): 6b79c57e6a95239282c4818e96112f3f3a401ba97a564c23852a3f1ea5fc) }, protocol_version: "/TODO/0.0.1", agent_version: "rust-libp2p/0.43.0", listen_addrs: ["/ip4/172.17.0.1/tcp/35759", "/ip4/172.18.0.1/tcp/35759", "/ip4/10.30.6.152/tcp/35759", "/ip4/127.0.0.1/tcp/35759"], protocols: [StreamProtocol { inner: Right("/ipfs/id/1.0.0") }, StreamProtocol { inner: Right("/meshsub/1.1.0") }, StreamProtocol { inner: Right("/libp2p/circuit/relay/0.2.0/stop") }, StreamProtocol { inner: Right("/ipfs/ping/1.0.0") }, StreamProtocol { inner: Right("/ipfs/id/push/1.0.0") }, StreamProtocol { inner: Right("/meshsub/1.0.0") }], observed_addr: "/ip4/114.132.71.142/tcp/4001/p2p/12D3KooWDpJ7As7BWAwRMfu1VU2WCqNjvq387JEYKDBj4kx6nXTN" } }
[2023-05-30T06:31:15Z DEBUG libp2p_ping::handler] latency to 12D3KooWH3uVF6wv47WnArKHk5p6cvgCJEb74UTmxztmQDc298L3 is 175ms
[2023-05-30T06:31:15Z DEBUG yamux::connection::stream] 73634848/1: eof
[2023-05-30T06:31:15Z DEBUG libp2p_swarm::connection] no protocol could be agreed upon for inbound stream
[2023-05-30T06:31:15Z DEBUG multistream_select::listener_select] Listener: confirming protocol: /ipfs/id/push/1.0.0
[2023-05-30T06:31:15Z DEBUG multistream_select::listener_select] Listener: sent confirmed protocol: /ipfs/id/push/1.0.0
BehaviourEvent: Event { peer: PeerId("12D3KooWH3uVF6wv47WnArKHk5p6cvgCJEb74UTmxztmQDc298L3"), connection: ConnectionId(2), result: Ok(175.785608ms) }
[2023-05-30T06:31:15Z DEBUG yamux::connection] 0753d206: new outbound (Stream 0753d206/6) of (Connection 0753d206 Server (streams 2))
[2023-05-30T06:31:15Z DEBUG multistream_select::dialer_select] Dialer: Proposed protocol: /libp2p/circuit/relay/0.2.0/stop
[2023-05-30T06:31:15Z DEBUG multistream_select::dialer_select] Dialer: Received confirmation for protocol: /libp2p/circuit/relay/0.2.0/stop
BehaviourEvent: Received { peer_id: PeerId("12D3KooWH3uVF6wv47WnArKHk5p6cvgCJEb74UTmxztmQDc298L3"), info: Info { public_key: PublicKey { publickey: Ed25519(PublicKey(compressed): 6b79c57e6a95239282c4818e96112f3f3a401ba97a564c23852a3f1ea5fc) }, protocol_version: "/TODO/0.0.1", agent_version: "rust-libp2p/0.43.0", listen_addrs: ["/ip4/172.17.0.1/tcp/35759", "/ip4/172.18.0.1/tcp/35759", "/ip4/10.30.6.152/tcp/35759", "/ip4/127.0.0.1/tcp/35759"], protocols: [StreamProtocol { inner: Right("/ipfs/id/1.0.0") }, StreamProtocol { inner: Right("/libp2p/circuit/relay/0.2.0/stop") }, StreamProtocol { inner: Right("/ipfs/ping/1.0.0") }, StreamProtocol { inner: Right("/ipfs/id/push/1.0.0") }], observed_addr: "/ip4/114.132.71.142/tcp/4001/p2p/12D3KooWDpJ7As7BWAwRMfu1VU2WCqNjvq387JEYKDBj4kx6nXTN" } }
BehaviourEvent: CircuitReqAccepted { src_peer_id: PeerId("12D3KooWH3uVF6wv47WnArKHk5p6cvgCJEb74UTmxztmQDc298L3"), dst_peer_id: PeerId("12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X") }
[2023-05-30T06:31:16Z DEBUG libp2p_ping::handler] latency to 12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X is 136ms
BehaviourEvent: Event { peer: PeerId("12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X"), connection: ConnectionId(1), result: Ok(136.707858ms) }
[2023-05-30T06:31:26Z DEBUG yamux::connection] 73634848: socket eof
[2023-05-30T06:31:26Z DEBUG libp2p_swarm] Connection closed with error IO(Custom { kind: Other, error: Error(Closed) }): Connected { endpoint: Listener { local_addr: "/ip4/10.0.8.14/tcp/4001", send_back_addr: "/ip4/115.216.2.224/tcp/33323" }, peer_id: PeerId("12D3KooWH3uVF6wv47WnArKHk5p6cvgCJEb74UTmxztmQDc298L3") }; Total (peer): 0.
BehaviourEvent: CircuitClosed { src_peer_id: PeerId("12D3KooWH3uVF6wv47WnArKHk5p6cvgCJEb74UTmxztmQDc298L3"), dst_peer_id: PeerId("12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X"), error: Some(Kind(ConnectionAborted)) }
[2023-05-30T06:31:31Z DEBUG libp2p_ping::handler] latency to 12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X is 114ms
BehaviourEvent: Event { peer: PeerId("12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X"), connection: ConnectionId(1), result: Ok(114.897524ms) }
[2023-05-30T06:31:46Z DEBUG libp2p_ping::handler] latency to 12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X is 135ms
BehaviourEvent: Event { peer: PeerId("12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X"), connection: ConnectionId(1), result: Ok(135.231272ms) }
Listening Client Debug Output
$ RUST_LOG=debug ./client --secret-key-seed 1 --mode listen --relay-address /ip4/114.132.71.142/tcp/4001/p2p/12D3KooWDpJ7As7BWAwRMfu1VU2WCqNjvq387JEYKDBj4kx6nXTN
[2023-05-30T06:31:02Z INFO client] Local peer id: PeerId("12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X")
[2023-05-30T06:31:02Z DEBUG libp2p_gossipsub::behaviour] Subscribing to topic: test-net
[2023-05-30T06:31:02Z DEBUG libp2p_gossipsub::behaviour] Running JOIN for topic: TopicHash { hash: "test-net" }
[2023-05-30T06:31:02Z DEBUG libp2p_gossipsub::behaviour] RANDOM PEERS: Got 0 peers
[2023-05-30T06:31:02Z DEBUG libp2p_gossipsub::behaviour] JOIN: Inserting 0 random peers into the mesh
[2023-05-30T06:31:02Z DEBUG libp2p_gossipsub::behaviour] Completed JOIN for topic: TopicHash { hash: "test-net" }
[2023-05-30T06:31:02Z DEBUG libp2p_gossipsub::behaviour] Subscribed to topic: test-net
[2023-05-30T06:31:02Z DEBUG libp2p_tcp] listening on 0.0.0.0:0
[2023-05-30T06:31:02Z DEBUG netlink_proto::handle] handle: forwarding new request to connection
[2023-05-30T06:31:02Z DEBUG netlink_proto::connection] reading incoming messages
[2023-05-30T06:31:02Z DEBUG netlink_proto::codecs] NetlinkCodec: decoding next message
[2023-05-30T06:31:02Z DEBUG netlink_proto::connection] forwarding unsolicited messages to the connection handle
.........
[2023-05-30T06:31:02Z DEBUG netlink_proto::codecs] NetlinkCodec: decoding next message
[2023-05-30T06:31:02Z DEBUG netlink_proto::connection] forwarding unsolicited messages to the connection handle
[2023-05-30T06:31:02Z DEBUG netlink_proto::connection] forwaring responses to previous requests to the connection handle
[2023-05-30T06:31:02Z DEBUG netlink_proto::connection] handling requests
[2023-05-30T06:31:02Z DEBUG netlink_proto::connection] sending messages
[2023-05-30T06:31:02Z DEBUG libp2p_tcp] New listen address: /ip4/127.0.0.1/tcp/44415
[2023-05-30T06:31:02Z DEBUG libp2p_swarm] Listener ListenerId(1); New address: "/ip4/127.0.0.1/tcp/44415"
[2023-05-30T06:31:02Z INFO client] Listening on "/ip4/127.0.0.1/tcp/44415"
[2023-05-30T06:31:02Z DEBUG netlink_proto::connection] reading incoming messages
[2023-05-30T06:31:02Z DEBUG netlink_proto::codecs] NetlinkCodec: decoding next message
[2023-05-30T06:31:02Z DEBUG netlink_proto::connection] forwarding unsolicited messages to the connection handle
[2023-05-30T06:31:02Z DEBUG netlink_proto::connection] forwaring responses to previous requests to the connection handle
[2023-05-30T06:31:02Z DEBUG netlink_proto::connection] handling requests
[2023-05-30T06:31:02Z DEBUG netlink_proto::connection] sending messages
[2023-05-30T06:31:02Z DEBUG libp2p_tcp] New listen address: /ip4/10.30.6.101/tcp/44415
[2023-05-30T06:31:02Z DEBUG libp2p_swarm] Listener ListenerId(1); New address: "/ip4/10.30.6.101/tcp/44415"
[2023-05-30T06:31:02Z INFO client] Listening on "/ip4/10.30.6.101/tcp/44415"
[2023-05-30T06:31:02Z DEBUG netlink_proto::connection] reading incoming messages
[2023-05-30T06:31:02Z DEBUG netlink_proto::codecs] NetlinkCodec: decoding next message
[2023-05-30T06:31:02Z DEBUG netlink_proto::connection] forwarding unsolicited messages to the connection handle
[2023-05-30T06:31:02Z DEBUG netlink_proto::connection] forwaring responses to previous requests to the connection handle
[2023-05-30T06:31:02Z DEBUG netlink_proto::connection] handling requests
[2023-05-30T06:31:02Z DEBUG netlink_proto::connection] sending messages
[2023-05-30T06:31:02Z DEBUG libp2p_tcp] New listen address: /ip4/10.30.6.101/tcp/44415
[2023-05-30T06:31:02Z DEBUG libp2p_swarm] Listener ListenerId(1); New address: "/ip4/10.30.6.101/tcp/44415"
[2023-05-30T06:31:02Z INFO client] Listening on "/ip4/10.30.6.101/tcp/44415"
[2023-05-30T06:31:02Z DEBUG netlink_proto::connection] reading incoming messages
[2023-05-30T06:31:02Z DEBUG netlink_proto::codecs] NetlinkCodec: decoding next message
[2023-05-30T06:31:02Z DEBUG netlink_proto::connection] forwarding unsolicited messages to the connection handle
[2023-05-30T06:31:02Z DEBUG netlink_proto::connection] forwaring responses to previous requests to the connection handle
[2023-05-30T06:31:02Z DEBUG netlink_proto::connection] handling requests
[2023-05-30T06:31:02Z DEBUG netlink_proto::connection] sending messages
[2023-05-30T06:31:02Z DEBUG libp2p_tcp] New listen address: /ip4/172.22.0.1/tcp/44415
[2023-05-30T06:31:02Z DEBUG libp2p_swarm] Listener ListenerId(1); New address: "/ip4/172.22.0.1/tcp/44415"
[2023-05-30T06:31:02Z INFO client] Listening on "/ip4/172.22.0.1/tcp/44415"
[2023-05-30T06:31:02Z DEBUG netlink_proto::connection] reading incoming messages
[2023-05-30T06:31:02Z DEBUG netlink_proto::codecs] NetlinkCodec: decoding next message
[2023-05-30T06:31:02Z DEBUG netlink_proto::connection] forwarding unsolicited messages to the connection handle
[2023-05-30T06:31:02Z DEBUG netlink_proto::connection] forwaring responses to previous requests to the connection handle
[2023-05-30T06:31:02Z DEBUG netlink_proto::connection] handling requests
[2023-05-30T06:31:02Z DEBUG netlink_proto::connection] sending messages
[2023-05-30T06:31:02Z DEBUG libp2p_tcp] New listen address: /ip4/172.17.0.1/tcp/44415
[2023-05-30T06:31:02Z DEBUG libp2p_swarm] Listener ListenerId(1); New address: "/ip4/172.17.0.1/tcp/44415"
[2023-05-30T06:31:02Z INFO client] Listening on "/ip4/172.17.0.1/tcp/44415"
[2023-05-30T06:31:02Z DEBUG netlink_proto::connection] reading incoming messages
[2023-05-30T06:31:02Z DEBUG netlink_proto::codecs] NetlinkCodec: decoding next message
[2023-05-30T06:31:02Z DEBUG netlink_proto::connection] forwarding unsolicited messages to the connection handle
[2023-05-30T06:31:02Z DEBUG netlink_proto::connection] forwaring responses to previous requests to the connection handle
[2023-05-30T06:31:02Z DEBUG netlink_proto::connection] handling requests
[2023-05-30T06:31:02Z DEBUG netlink_proto::connection] sending messages
[2023-05-30T06:31:02Z DEBUG libp2p_tcp] New listen address: /ip4/172.21.0.1/tcp/44415
[2023-05-30T06:31:02Z DEBUG libp2p_swarm] Listener ListenerId(1); New address: "/ip4/172.21.0.1/tcp/44415"
[2023-05-30T06:31:02Z INFO client] Listening on "/ip4/172.21.0.1/tcp/44415"
[2023-05-30T06:31:02Z DEBUG netlink_proto::connection] reading incoming messages
[2023-05-30T06:31:02Z DEBUG netlink_proto::codecs] NetlinkCodec: decoding next message
[2023-05-30T06:31:02Z DEBUG netlink_proto::connection] forwarding unsolicited messages to the connection handle
[2023-05-30T06:31:02Z DEBUG netlink_proto::connection] forwaring responses to previous requests to the connection handle
[2023-05-30T06:31:02Z DEBUG netlink_proto::connection] handling requests
[2023-05-30T06:31:02Z DEBUG netlink_proto::connection] sending messages
[2023-05-30T06:31:02Z DEBUG libp2p_tcp] New listen address: /ip4/192.168.144.1/tcp/44415
[2023-05-30T06:31:02Z DEBUG libp2p_swarm] Listener ListenerId(1); New address: "/ip4/192.168.144.1/tcp/44415"
[2023-05-30T06:31:02Z INFO client] Listening on "/ip4/192.168.144.1/tcp/44415"
[2023-05-30T06:31:02Z DEBUG netlink_proto::connection] reading incoming messages
[2023-05-30T06:31:02Z DEBUG netlink_proto::codecs] NetlinkCodec: decoding next message
[2023-05-30T06:31:02Z DEBUG netlink_proto::connection] forwarding unsolicited messages to the connection handle
[2023-05-30T06:31:02Z DEBUG netlink_proto::connection] forwaring responses to previous requests to the connection handle
[2023-05-30T06:31:02Z DEBUG netlink_proto::connection] handling requests
[2023-05-30T06:31:02Z DEBUG netlink_proto::connection] sending messages
[2023-05-30T06:31:02Z DEBUG libp2p_tcp] New listen address: /ip4/192.168.160.1/tcp/44415
[2023-05-30T06:31:02Z DEBUG libp2p_swarm] Listener ListenerId(1); New address: "/ip4/192.168.160.1/tcp/44415"
[2023-05-30T06:31:02Z INFO client] Listening on "/ip4/192.168.160.1/tcp/44415"
[2023-05-30T06:31:02Z DEBUG netlink_proto::connection] reading incoming messages
[2023-05-30T06:31:02Z DEBUG netlink_proto::codecs] NetlinkCodec: decoding next message
[2023-05-30T06:31:02Z DEBUG netlink_proto::connection] forwarding unsolicited messages to the connection handle
[2023-05-30T06:31:02Z DEBUG netlink_proto::connection] forwaring responses to previous requests to the connection handle
[2023-05-30T06:31:02Z DEBUG netlink_proto::connection] handling requests
[2023-05-30T06:31:02Z DEBUG netlink_proto::connection] sending messages
[2023-05-30T06:31:02Z DEBUG libp2p_tcp] New listen address: /ip4/192.168.176.1/tcp/44415
[2023-05-30T06:31:02Z DEBUG libp2p_swarm] Listener ListenerId(1); New address: "/ip4/192.168.176.1/tcp/44415"
[2023-05-30T06:31:02Z INFO client] Listening on "/ip4/192.168.176.1/tcp/44415"
[2023-05-30T06:31:02Z DEBUG netlink_proto::connection] reading incoming messages
[2023-05-30T06:31:02Z DEBUG netlink_proto::codecs] NetlinkCodec: decoding next message
[2023-05-30T06:31:02Z DEBUG netlink_proto::connection] forwarding unsolicited messages to the connection handle
[2023-05-30T06:31:02Z DEBUG netlink_proto::connection] forwaring responses to previous requests to the connection handle
[2023-05-30T06:31:02Z DEBUG netlink_proto::connection] handling requests
[2023-05-30T06:31:02Z DEBUG netlink_proto::connection] sending messages
[2023-05-30T06:31:02Z DEBUG libp2p_tcp] New listen address: /ip4/192.168.192.1/tcp/44415
[2023-05-30T06:31:02Z DEBUG libp2p_swarm] Listener ListenerId(1); New address: "/ip4/192.168.192.1/tcp/44415"
[2023-05-30T06:31:02Z INFO client] Listening on "/ip4/192.168.192.1/tcp/44415"
........
[2023-05-30T06:31:03Z DEBUG libp2p_dns] Dialing /ip4/114.132.71.142/tcp/4001/p2p/12D3KooWDpJ7As7BWAwRMfu1VU2WCqNjvq387JEYKDBj4kx6nXTN
[2023-05-30T06:31:03Z DEBUG libp2p_tcp] dialing 114.132.71.142:4001
[2023-05-30T06:31:03Z DEBUG multistream_select::dialer_select] Dialer: Proposed protocol: /noise
[2023-05-30T06:31:03Z DEBUG multistream_select::dialer_select] Dialer: Expecting proposed protocol: /noise
[2023-05-30T06:31:03Z DEBUG multistream_select::negotiated] Negotiated: Received confirmation for protocol: /noise
[2023-05-30T06:31:03Z DEBUG multistream_select::dialer_select] Dialer: Proposed protocol: /yamux/1.0.0
[2023-05-30T06:31:03Z DEBUG multistream_select::dialer_select] Dialer: Expecting proposed protocol: /yamux/1.0.0
[2023-05-30T06:31:03Z DEBUG yamux::connection] new connection: f1a6b756 (Client)
[2023-05-30T06:31:03Z DEBUG yamux::connection] f1a6b756: new outbound (Stream f1a6b756/1) of (Connection f1a6b756 Client (streams 0))
[2023-05-30T06:31:03Z DEBUG multistream_select::dialer_select] Dialer: Proposed protocol: /ipfs/id/1.0.0
[2023-05-30T06:31:03Z DEBUG yamux::connection] f1a6b756: new outbound (Stream f1a6b756/3) of (Connection f1a6b756 Client (streams 1))
[2023-05-30T06:31:03Z DEBUG multistream_select::dialer_select] Dialer: Proposed protocol: /ipfs/ping/1.0.0
[2023-05-30T06:31:03Z DEBUG libp2p_swarm] Connection established: PeerId("12D3KooWDpJ7As7BWAwRMfu1VU2WCqNjvq387JEYKDBj4kx6nXTN") Dialer { address: "/ip4/114.132.71.142/tcp/4001/p2p/12D3KooWDpJ7As7BWAwRMfu1VU2WCqNjvq387JEYKDBj4kx6nXTN", role_override: Dialer }; Total (peer): 1.
[2023-05-30T06:31:03Z DEBUG libp2p_gossipsub::behaviour] New peer connected: 12D3KooWDpJ7As7BWAwRMfu1VU2WCqNjvq387JEYKDBj4kx6nXTN
[2023-05-30T06:31:03Z DEBUG yamux::connection] f1a6b756: new outbound (Stream f1a6b756/5) of (Connection f1a6b756 Client (streams 2))
[2023-05-30T06:31:03Z DEBUG multistream_select::dialer_select] Dialer: Proposed protocol: /meshsub/1.1.0
[2023-05-30T06:31:03Z DEBUG multistream_select::negotiated] Negotiated: Received confirmation for protocol: /yamux/1.0.0
[2023-05-30T06:31:03Z DEBUG multistream_select::dialer_select] Dialer: Received confirmation for protocol: /ipfs/id/1.0.0
[2023-05-30T06:31:03Z DEBUG multistream_select::listener_select] Listener: confirming protocol: /ipfs/id/1.0.0
[2023-05-30T06:31:03Z DEBUG multistream_select::listener_select] Listener: sent confirmed protocol: /ipfs/id/1.0.0
[2023-05-30T06:31:03Z INFO client] Relay told us our public address: "/ip4/115.216.2.224/tcp/27594"
[2023-05-30T06:31:03Z INFO client] Told relay its public address.
[2023-05-30T06:31:03Z DEBUG multistream_select::dialer_select] Dialer: Received confirmation for protocol: /ipfs/ping/1.0.0
[2023-05-30T06:31:03Z DEBUG multistream_select::listener_select] Listener: confirming protocol: /ipfs/ping/1.0.0
[2023-05-30T06:31:03Z DEBUG multistream_select::listener_select] Listener: sent confirmed protocol: /ipfs/ping/1.0.0
[2023-05-30T06:31:03Z DEBUG multistream_select::dialer_select] Dialer: Received rejection of protocol: /meshsub/1.1.0
[2023-05-30T06:31:03Z DEBUG multistream_select::dialer_select] Dialer: Proposed protocol: /meshsub/1.0.0
[2023-05-30T06:31:03Z DEBUG yamux::connection] f1a6b756: new outbound (Stream f1a6b756/7) of (Connection f1a6b756 Client (streams 3))
[2023-05-30T06:31:03Z DEBUG multistream_select::dialer_select] Dialer: Proposed protocol: /libp2p/circuit/relay/0.2.0/hop
[2023-05-30T06:31:03Z DEBUG libp2p_ping::handler] latency to 12D3KooWDpJ7As7BWAwRMfu1VU2WCqNjvq387JEYKDBj4kx6nXTN is 179ms
[2023-05-30T06:31:03Z DEBUG multistream_select::dialer_select] Dialer: Received rejection of protocol: /meshsub/1.0.0
[2023-05-30T06:31:03Z DEBUG libp2p_gossipsub::handler] The remote peer does not support gossipsub on this connection
[2023-05-30T06:31:03Z DEBUG multistream_select::dialer_select] Dialer: Received confirmation for protocol: /libp2p/circuit/relay/0.2.0/hop
[2023-05-30T06:31:03Z DEBUG libp2p_identify::handler] Supported listen protocols changed from [/ipfs/id/push/1.0.0, /meshsub/1.0.0, /ipfs/ping/1.0.0, /libp2p/circuit/relay/0.2.0/stop, /ipfs/id/1.0.0, /meshsub/1.1.0] to [/ipfs/id/push/1.0.0, /ipfs/ping/1.0.0, /libp2p/circuit/relay/0.2.0/stop, /ipfs/id/1.0.0], pushing to 12D3KooWDpJ7As7BWAwRMfu1VU2WCqNjvq387JEYKDBj4kx6nXTN
[2023-05-30T06:31:03Z DEBUG yamux::connection] f1a6b756: new outbound (Stream f1a6b756/9) of (Connection f1a6b756 Client (streams 3))
[2023-05-30T06:31:03Z DEBUG multistream_select::dialer_select] Dialer: Proposed protocol: /ipfs/id/push/1.0.0
[2023-05-30T06:31:03Z DEBUG libp2p_gossipsub::behaviour] Peer does not support gossipsub protocols. 12D3KooWDpJ7As7BWAwRMfu1VU2WCqNjvq387JEYKDBj4kx6nXTN
[2023-05-30T06:31:03Z DEBUG multistream_select::dialer_select] Dialer: Received confirmation for protocol: /ipfs/id/push/1.0.0
[2023-05-30T06:31:03Z INFO client] Pushed { peer_id: PeerId("12D3KooWDpJ7As7BWAwRMfu1VU2WCqNjvq387JEYKDBj4kx6nXTN") }
[2023-05-30T06:31:03Z INFO client] Relay accepted our reservation request.
[2023-05-30T06:31:03Z DEBUG libp2p_swarm] Listener ListenerId(2); New address: "/ip4/114.132.71.142/tcp/4001/p2p/12D3KooWDpJ7As7BWAwRMfu1VU2WCqNjvq387JEYKDBj4kx6nXTN/p2p-circuit/p2p/12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X"
[2023-05-30T06:31:03Z INFO client] Listening on "/ip4/114.132.71.142/tcp/4001/p2p/12D3KooWDpJ7As7BWAwRMfu1VU2WCqNjvq387JEYKDBj4kx6nXTN/p2p-circuit/p2p/12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X"
[2023-05-30T06:31:07Z DEBUG libp2p_gossipsub::behaviour] Starting heartbeat
[2023-05-30T06:31:07Z DEBUG libp2p_gossipsub::behaviour] HEARTBEAT: Mesh low. Topic: test-net Contains: 0 needs: 5
[2023-05-30T06:31:07Z DEBUG libp2p_gossipsub::behaviour] RANDOM PEERS: Got 0 peers
[2023-05-30T06:31:07Z DEBUG libp2p_gossipsub::behaviour] Updating mesh, new mesh: {}
[2023-05-30T06:31:07Z DEBUG libp2p_gossipsub::behaviour] Completed Heartbeat
[2023-05-30T06:31:17Z DEBUG libp2p_gossipsub::behaviour] Starting heartbeat
[2023-05-30T06:31:17Z DEBUG libp2p_gossipsub::behaviour] HEARTBEAT: Mesh low. Topic: test-net Contains: 0 needs: 5
[2023-05-30T06:31:17Z DEBUG libp2p_gossipsub::behaviour] RANDOM PEERS: Got 0 peers
[2023-05-30T06:31:17Z DEBUG libp2p_gossipsub::behaviour] Updating mesh, new mesh: {}
[2023-05-30T06:31:17Z DEBUG libp2p_gossipsub::behaviour] Completed Heartbeat
[2023-05-30T06:31:18Z DEBUG libp2p_ping::handler] latency to 12D3KooWDpJ7As7BWAwRMfu1VU2WCqNjvq387JEYKDBj4kx6nXTN is 135ms
[2023-05-30T06:31:27Z DEBUG libp2p_gossipsub::behaviour] Starting heartbeat
[2023-05-30T06:31:27Z DEBUG libp2p_gossipsub::behaviour] HEARTBEAT: Mesh low. Topic: test-net Contains: 0 needs: 5
[2023-05-30T06:31:27Z DEBUG libp2p_gossipsub::behaviour] RANDOM PEERS: Got 0 peers
[2023-05-30T06:31:27Z DEBUG libp2p_gossipsub::behaviour] Updating mesh, new mesh: {}
[2023-05-30T06:31:27Z DEBUG libp2p_gossipsub::behaviour] Completed Heartbeat
[2023-05-30T06:31:33Z DEBUG multistream_select::listener_select] Listener: confirming protocol: /libp2p/circuit/relay/0.2.0/stop
[2023-05-30T06:31:33Z DEBUG multistream_select::listener_select] Listener: sent confirmed protocol: /libp2p/circuit/relay/0.2.0/stop
[2023-05-30T06:31:33Z INFO client] InboundCircuitEstablished { src_peer_id: PeerId("12D3KooWH3uVF6wv47WnArKHk5p6cvgCJEb74UTmxztmQDc298L3"), limit: Some(Limit { duration: Some(120s), data_in_bytes: Some(131072) }) }
[2023-05-30T06:31:33Z DEBUG multistream_select::listener_select] Listener: confirming protocol: /noise
[2023-05-30T06:31:33Z DEBUG multistream_select::listener_select] Listener: sent confirmed protocol: /noise
[2023-05-30T06:31:33Z DEBUG multistream_select::listener_select] Listener: confirming protocol: /yamux/1.0.0
[2023-05-30T06:31:33Z DEBUG multistream_select::listener_select] Listener: sent confirmed protocol: /yamux/1.0.0
[2023-05-30T06:31:33Z DEBUG yamux::connection] new connection: f7c16b4d (Server)
[2023-05-30T06:31:33Z DEBUG libp2p_swarm] Connection established: PeerId("12D3KooWH3uVF6wv47WnArKHk5p6cvgCJEb74UTmxztmQDc298L3") Listener { local_addr: "/ip4/114.132.71.142/tcp/4001/p2p/12D3KooWDpJ7As7BWAwRMfu1VU2WCqNjvq387JEYKDBj4kx6nXTN/p2p-circuit", send_back_addr: "/p2p/12D3KooWH3uVF6wv47WnArKHk5p6cvgCJEb74UTmxztmQDc298L3" }; Total (peer): 1.
[2023-05-30T06:31:33Z DEBUG libp2p_gossipsub::behaviour] New peer connected: 12D3KooWH3uVF6wv47WnArKHk5p6cvgCJEb74UTmxztmQDc298L3
[2023-05-30T06:31:33Z INFO client] Established connection to PeerId("12D3KooWH3uVF6wv47WnArKHk5p6cvgCJEb74UTmxztmQDc298L3") via Listener { local_addr: "/ip4/114.132.71.142/tcp/4001/p2p/12D3KooWDpJ7As7BWAwRMfu1VU2WCqNjvq387JEYKDBj4kx6nXTN/p2p-circuit", send_back_addr: "/p2p/12D3KooWH3uVF6wv47WnArKHk5p6cvgCJEb74UTmxztmQDc298L3" }
[2023-05-30T06:31:33Z DEBUG multistream_select::listener_select] Listener: confirming protocol: /meshsub/1.1.0
[2023-05-30T06:31:33Z INFO client] dcutr: InitiatedDirectConnectionUpgrade { remote_peer_id: PeerId("12D3KooWH3uVF6wv47WnArKHk5p6cvgCJEb74UTmxztmQDc298L3"), local_relayed_addr: "/ip4/114.132.71.142/tcp/4001/p2p/12D3KooWDpJ7As7BWAwRMfu1VU2WCqNjvq387JEYKDBj4kx6nXTN/p2p-circuit" }
[2023-05-30T06:31:33Z DEBUG multistream_select::listener_select] Listener: sent confirmed protocol: /meshsub/1.1.0
[2023-05-30T06:31:33Z DEBUG yamux::connection] f7c16b4d: new outbound (Stream f7c16b4d/2) of (Connection f7c16b4d Server (streams 1))
[2023-05-30T06:31:33Z DEBUG multistream_select::dialer_select] Dialer: Proposed protocol: /meshsub/1.1.0
[2023-05-30T06:31:33Z DEBUG multistream_select::listener_select] Listener: confirming protocol: /ipfs/id/1.0.0
[2023-05-30T06:31:33Z DEBUG libp2p_gossipsub::behaviour] New peer type found: Gossipsub v1.1 for peer: 12D3KooWH3uVF6wv47WnArKHk5p6cvgCJEb74UTmxztmQDc298L3
[2023-05-30T06:31:33Z DEBUG multistream_select::listener_select] Listener: sent confirmed protocol: /ipfs/id/1.0.0
[2023-05-30T06:31:33Z DEBUG yamux::connection] f7c16b4d: new outbound (Stream f7c16b4d/4) of (Connection f7c16b4d Server (streams 3))
[2023-05-30T06:31:33Z DEBUG multistream_select::dialer_select] Dialer: Proposed protocol: /libp2p/dcutr
[2023-05-30T06:31:33Z INFO client] Sent { peer_id: PeerId("12D3KooWH3uVF6wv47WnArKHk5p6cvgCJEb74UTmxztmQDc298L3") }
[2023-05-30T06:31:33Z DEBUG multistream_select::listener_select] Listener: confirming protocol: /ipfs/ping/1.0.0
[2023-05-30T06:31:33Z DEBUG multistream_select::listener_select] Listener: sent confirmed protocol: /ipfs/ping/1.0.0
[2023-05-30T06:31:33Z DEBUG yamux::connection] f7c16b4d: new outbound (Stream f7c16b4d/6) of (Connection f7c16b4d Server (streams 4))
[2023-05-30T06:31:33Z DEBUG multistream_select::dialer_select] Dialer: Proposed protocol: /ipfs/id/1.0.0
[2023-05-30T06:31:33Z DEBUG yamux::connection] f7c16b4d: new outbound (Stream f7c16b4d/8) of (Connection f7c16b4d Server (streams 5))
[2023-05-30T06:31:33Z DEBUG multistream_select::dialer_select] Dialer: Proposed protocol: /ipfs/ping/1.0.0
[2023-05-30T06:31:33Z DEBUG libp2p_ping::handler] latency to 12D3KooWDpJ7As7BWAwRMfu1VU2WCqNjvq387JEYKDBj4kx6nXTN is 93ms
[2023-05-30T06:31:34Z DEBUG multistream_select::dialer_select] Dialer: Received confirmation for protocol: /meshsub/1.1.0
[2023-05-30T06:31:34Z DEBUG multistream_select::dialer_select] Dialer: Received confirmation for protocol: /libp2p/dcutr
[2023-05-30T06:31:34Z DEBUG libp2p_gossipsub::behaviour] Handling subscriptions: [Subscription { action: Subscribe, topic_hash: TopicHash { hash: "test-net" } }], from source: 12D3KooWH3uVF6wv47WnArKHk5p6cvgCJEb74UTmxztmQDc298L3
[2023-05-30T06:31:34Z DEBUG multistream_select::dialer_select] Dialer: Received confirmation for protocol: /ipfs/id/1.0.0
[2023-05-30T06:31:34Z DEBUG libp2p_gossipsub::behaviour] SUBSCRIPTION: Adding gossip peer: 12D3KooWH3uVF6wv47WnArKHk5p6cvgCJEb74UTmxztmQDc298L3 to topic: TopicHash { hash: "test-net" }
[2023-05-30T06:31:34Z DEBUG libp2p_gossipsub::behaviour] SUBSCRIPTION: Adding peer 12D3KooWH3uVF6wv47WnArKHk5p6cvgCJEb74UTmxztmQDc298L3 to the mesh for topic TopicHash { hash: "test-net" }
[2023-05-30T06:31:34Z DEBUG libp2p_gossipsub::behaviour] Sending GRAFT to peer 12D3KooWH3uVF6wv47WnArKHk5p6cvgCJEb74UTmxztmQDc298L3 for topic TopicHash { hash: "test-net" }
[2023-05-30T06:31:34Z DEBUG multistream_select::dialer_select] Dialer: Received confirmation for protocol: /ipfs/ping/1.0.0
[2023-05-30T06:31:34Z INFO client] Received { peer_id: PeerId("12D3KooWH3uVF6wv47WnArKHk5p6cvgCJEb74UTmxztmQDc298L3"), info: Info { public_key: PublicKey { publickey: Ed25519(PublicKey(compressed): 6b79c57e6a95239282c4818e96112f3f3a401ba97a564c23852a3f1ea5fc) }, protocol_version: "/TODO/0.0.1", agent_version: "rust-libp2p/0.43.0", listen_addrs: ["/ip4/10.30.6.152/tcp/35759", "/ip4/172.17.0.1/tcp/35759", "/ip4/172.18.0.1/tcp/35759", "/ip4/127.0.0.1/tcp/35759"], protocols: [StreamProtocol { inner: Right("/libp2p/dcutr") }, StreamProtocol { inner: Right("/meshsub/1.0.0") }, StreamProtocol { inner: Right("/ipfs/id/push/1.0.0") }, StreamProtocol { inner: Right("/ipfs/id/1.0.0") }, StreamProtocol { inner: Right("/ipfs/ping/1.0.0") }, StreamProtocol { inner: Right("/meshsub/1.1.0") }], observed_addr: "/ip4/114.132.71.142/tcp/4001/p2p/12D3KooWDpJ7As7BWAwRMfu1VU2WCqNjvq387JEYKDBj4kx6nXTN/p2p-circuit/p2p/12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X" } }
[2023-05-30T06:31:37Z DEBUG libp2p_gossipsub::behaviour] Starting heartbeat
[2023-05-30T06:31:37Z DEBUG libp2p_gossipsub::behaviour] HEARTBEAT: Mesh low. Topic: test-net Contains: 1 needs: 5
[2023-05-30T06:31:37Z DEBUG libp2p_gossipsub::behaviour] RANDOM PEERS: Got 0 peers
[2023-05-30T06:31:37Z DEBUG libp2p_gossipsub::behaviour] Updating mesh, new mesh: {}
[2023-05-30T06:31:37Z DEBUG libp2p_gossipsub::behaviour] Completed Heartbeat
[2023-05-30T06:31:43Z INFO client] dcutr: DirectConnectionUpgradeFailed { remote_peer_id: PeerId("12D3KooWH3uVF6wv47WnArKHk5p6cvgCJEb74UTmxztmQDc298L3"), error: Handler(Timeout) }
[2023-05-30T06:31:47Z DEBUG libp2p_gossipsub::behaviour] Starting heartbeat
[2023-05-30T06:31:47Z DEBUG libp2p_gossipsub::behaviour] HEARTBEAT: Mesh low. Topic: test-net Contains: 1 needs: 5
[2023-05-30T06:31:47Z DEBUG libp2p_gossipsub::behaviour] RANDOM PEERS: Got 0 peers
[2023-05-30T06:31:47Z DEBUG libp2p_gossipsub::behaviour] Updating mesh, new mesh: {}
[2023-05-30T06:31:47Z DEBUG libp2p_gossipsub::behaviour] Completed Heartbeat
[2023-05-30T06:31:49Z DEBUG yamux::connection::stream] f1a6b756/6: eof
[2023-05-30T06:31:49Z DEBUG libp2p_ping::handler] latency to 12D3KooWDpJ7As7BWAwRMfu1VU2WCqNjvq387JEYKDBj4kx6nXTN is 133ms
[2023-05-30T06:31:49Z DEBUG yamux::connection] f7c16b4d: socket eof
[2023-05-30T06:31:49Z DEBUG libp2p_swarm] Connection closed with error IO(Custom { kind: Other, error: Error(Closed) }): Connected { endpoint: Listener { local_addr: "/ip4/114.132.71.142/tcp/4001/p2p/12D3KooWDpJ7As7BWAwRMfu1VU2WCqNjvq387JEYKDBj4kx6nXTN/p2p-circuit", send_back_addr: "/p2p/12D3KooWH3uVF6wv47WnArKHk5p6cvgCJEb74UTmxztmQDc298L3" }, peer_id: PeerId("12D3KooWH3uVF6wv47WnArKHk5p6cvgCJEb74UTmxztmQDc298L3") }; Total (peer): 0.
[2023-05-30T06:31:49Z DEBUG libp2p_gossipsub::behaviour] Peer disconnected: 12D3KooWH3uVF6wv47WnArKHk5p6cvgCJEb74UTmxztmQDc298L3
[2023-05-30T06:31:57Z DEBUG libp2p_gossipsub::behaviour] Starting heartbeat
[2023-05-30T06:31:57Z DEBUG libp2p_gossipsub::behaviour] HEARTBEAT: Mesh low. Topic: test-net Contains: 0 needs: 5
[2023-05-30T06:31:57Z DEBUG libp2p_gossipsub::behaviour] RANDOM PEERS: Got 0 peers
[2023-05-30T06:31:57Z DEBUG libp2p_gossipsub::behaviour] Updating mesh, new mesh: {}
[2023-05-30T06:31:57Z DEBUG libp2p_gossipsub::behaviour] Completed Heartbeat
[2023-05-30T06:32:04Z DEBUG libp2p_ping::handler] latency to 12D3KooWDpJ7As7BWAwRMfu1VU2WCqNjvq387JEYKDBj4kx6nXTN is 135ms
Dailing Debug Output
$ RUST_LOG=debug ./client --secret-key-seed 2 --mode dial --relay-address /ip4/114.132.71.142/tcp/4001/p2p/12D3KooWDpJ7As7BWAwRMfu1VU2WCqNjvq387JEYKDBj4kx6nXTN --remote-peer-id 12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X
[2023-05-30T06:31:14Z INFO client] Local peer id: PeerId("12D3KooWH3uVF6wv47WnArKHk5p6cvgCJEb74UTmxztmQDc298L3")
[2023-05-30T06:31:14Z DEBUG libp2p_gossipsub::behaviour] Subscribing to topic: test-net
[2023-05-30T06:31:14Z DEBUG libp2p_gossipsub::behaviour] Running JOIN for topic: TopicHash { hash: "test-net" }
[2023-05-30T06:31:14Z DEBUG libp2p_gossipsub::behaviour] RANDOM PEERS: Got 0 peers
[2023-05-30T06:31:14Z DEBUG libp2p_gossipsub::behaviour] JOIN: Inserting 0 random peers into the mesh
[2023-05-30T06:31:14Z DEBUG libp2p_gossipsub::behaviour] Completed JOIN for topic: TopicHash { hash: "test-net" }
[2023-05-30T06:31:14Z DEBUG libp2p_gossipsub::behaviour] Subscribed to topic: test-net
[2023-05-30T06:31:14Z DEBUG libp2p_tcp] listening on 0.0.0.0:0
[2023-05-30T06:31:14Z DEBUG netlink_proto::handle] handle: forwarding new request to connection
[2023-05-30T06:31:14Z DEBUG netlink_proto::connection] reading incoming messages
[2023-05-30T06:31:14Z DEBUG netlink_proto::codecs] NetlinkCodec: decoding next message
[2023-05-30T06:31:14Z DEBUG netlink_proto::connection] forwarding unsolicited messages to the connection handle
[2023-05-30T06:31:14Z DEBUG netlink_proto::connection] forwaring responses to previous requests to the connection handle
......
[2023-05-30T06:31:15Z DEBUG libp2p_dns] Dialing /ip4/114.132.71.142/tcp/4001/p2p/12D3KooWDpJ7As7BWAwRMfu1VU2WCqNjvq387JEYKDBj4kx6nXTN
[2023-05-30T06:31:15Z DEBUG libp2p_tcp] dialing 114.132.71.142:4001
[2023-05-30T06:31:15Z DEBUG multistream_select::dialer_select] Dialer: Proposed protocol: /noise
[2023-05-30T06:31:15Z DEBUG multistream_select::dialer_select] Dialer: Expecting proposed protocol: /noise
[2023-05-30T06:31:15Z DEBUG multistream_select::negotiated] Negotiated: Received confirmation for protocol: /noise
[2023-05-30T06:31:15Z DEBUG multistream_select::dialer_select] Dialer: Proposed protocol: /yamux/1.0.0
[2023-05-30T06:31:15Z DEBUG multistream_select::dialer_select] Dialer: Expecting proposed protocol: /yamux/1.0.0
[2023-05-30T06:31:15Z DEBUG yamux::connection] new connection: 95a3c808 (Client)
[2023-05-30T06:31:15Z DEBUG libp2p_swarm] Connection established: PeerId("12D3KooWDpJ7As7BWAwRMfu1VU2WCqNjvq387JEYKDBj4kx6nXTN") Dialer { address: "/ip4/114.132.71.142/tcp/4001/p2p/12D3KooWDpJ7As7BWAwRMfu1VU2WCqNjvq387JEYKDBj4kx6nXTN", role_override: Dialer }; Total (peer): 1.
[2023-05-30T06:31:15Z DEBUG libp2p_gossipsub::behaviour] New peer connected: 12D3KooWDpJ7As7BWAwRMfu1VU2WCqNjvq387JEYKDBj4kx6nXTN
[2023-05-30T06:31:15Z DEBUG yamux::connection] 95a3c808: new outbound (Stream 95a3c808/1) of (Connection 95a3c808 Client (streams 0))
[2023-05-30T06:31:15Z DEBUG multistream_select::dialer_select] Dialer: Proposed protocol: /meshsub/1.1.0
[2023-05-30T06:31:15Z DEBUG yamux::connection] 95a3c808: new outbound (Stream 95a3c808/3) of (Connection 95a3c808 Client (streams 1))
[2023-05-30T06:31:15Z DEBUG multistream_select::dialer_select] Dialer: Proposed protocol: /ipfs/id/1.0.0
[2023-05-30T06:31:15Z DEBUG yamux::connection] 95a3c808: new outbound (Stream 95a3c808/5) of (Connection 95a3c808 Client (streams 2))
[2023-05-30T06:31:15Z DEBUG multistream_select::dialer_select] Dialer: Proposed protocol: /ipfs/ping/1.0.0
[2023-05-30T06:31:15Z DEBUG multistream_select::negotiated] Negotiated: Received confirmation for protocol: /yamux/1.0.0
[2023-05-30T06:31:15Z DEBUG multistream_select::dialer_select] Dialer: Received rejection of protocol: /meshsub/1.1.0
[2023-05-30T06:31:15Z DEBUG multistream_select::dialer_select] Dialer: Proposed protocol: /meshsub/1.0.0
[2023-05-30T06:31:15Z DEBUG multistream_select::listener_select] Listener: confirming protocol: /ipfs/ping/1.0.0
[2023-05-30T06:31:15Z DEBUG multistream_select::listener_select] Listener: sent confirmed protocol: /ipfs/ping/1.0.0
[2023-05-30T06:31:15Z DEBUG multistream_select::dialer_select] Dialer: Received confirmation for protocol: /ipfs/id/1.0.0
[2023-05-30T06:31:15Z DEBUG multistream_select::dialer_select] Dialer: Received confirmation for protocol: /ipfs/ping/1.0.0
[2023-05-30T06:31:15Z DEBUG multistream_select::listener_select] Listener: confirming protocol: /ipfs/id/1.0.0
[2023-05-30T06:31:15Z DEBUG multistream_select::listener_select] Listener: sent confirmed protocol: /ipfs/id/1.0.0
[2023-05-30T06:31:15Z INFO client] Relay told us our public address: "/ip4/115.216.2.224/tcp/33323"
[2023-05-30T06:31:15Z INFO client] Told relay its public address.
[2023-05-30T06:31:15Z DEBUG yamux::connection] 95a3c808: new outbound (Stream 95a3c808/7) of (Connection 95a3c808 Client (streams 3))
[2023-05-30T06:31:15Z DEBUG multistream_select::dialer_select] Dialer: Proposed protocol: /libp2p/circuit/relay/0.2.0/hop
[2023-05-30T06:31:15Z DEBUG libp2p_ping::handler] latency to 12D3KooWDpJ7As7BWAwRMfu1VU2WCqNjvq387JEYKDBj4kx6nXTN is 175ms
[2023-05-30T06:31:15Z DEBUG multistream_select::dialer_select] Dialer: Received rejection of protocol: /meshsub/1.0.0
[2023-05-30T06:31:15Z DEBUG libp2p_gossipsub::handler] The remote peer does not support gossipsub on this connection
[2023-05-30T06:31:15Z DEBUG multistream_select::dialer_select] Dialer: Received confirmation for protocol: /libp2p/circuit/relay/0.2.0/hop
[2023-05-30T06:31:15Z DEBUG libp2p_identify::handler] Supported listen protocols changed from [/ipfs/id/1.0.0, /meshsub/1.1.0, /libp2p/circuit/relay/0.2.0/stop, /ipfs/ping/1.0.0, /ipfs/id/push/1.0.0, /meshsub/1.0.0] to [/ipfs/id/1.0.0, /libp2p/circuit/relay/0.2.0/stop, /ipfs/ping/1.0.0, /ipfs/id/push/1.0.0], pushing to 12D3KooWDpJ7As7BWAwRMfu1VU2WCqNjvq387JEYKDBj4kx6nXTN
[2023-05-30T06:31:15Z DEBUG yamux::connection] 95a3c808: new outbound (Stream 95a3c808/9) of (Connection 95a3c808 Client (streams 3))
[2023-05-30T06:31:15Z DEBUG multistream_select::dialer_select] Dialer: Proposed protocol: /ipfs/id/push/1.0.0
[2023-05-30T06:31:15Z DEBUG libp2p_gossipsub::behaviour] Peer does not support gossipsub protocols. 12D3KooWDpJ7As7BWAwRMfu1VU2WCqNjvq387JEYKDBj4kx6nXTN
[2023-05-30T06:31:15Z DEBUG multistream_select::dialer_select] Dialer: Received confirmation for protocol: /ipfs/id/push/1.0.0
[2023-05-30T06:31:15Z INFO client] Pushed { peer_id: PeerId("12D3KooWDpJ7As7BWAwRMfu1VU2WCqNjvq387JEYKDBj4kx6nXTN") }
[2023-05-30T06:31:16Z DEBUG multistream_select::dialer_select] Dialer: Proposed protocol: /noise
[2023-05-30T06:31:16Z DEBUG multistream_select::dialer_select] Dialer: Expecting proposed protocol: /noise
[2023-05-30T06:31:16Z INFO client] OutboundCircuitEstablished { relay_peer_id: PeerId("12D3KooWDpJ7As7BWAwRMfu1VU2WCqNjvq387JEYKDBj4kx6nXTN"), limit: None }
[2023-05-30T06:31:16Z DEBUG multistream_select::negotiated] Negotiated: Received confirmation for protocol: /noise
[2023-05-30T06:31:16Z DEBUG multistream_select::dialer_select] Dialer: Proposed protocol: /yamux/1.0.0
[2023-05-30T06:31:16Z DEBUG multistream_select::dialer_select] Dialer: Expecting proposed protocol: /yamux/1.0.0
[2023-05-30T06:31:16Z DEBUG yamux::connection] new connection: 62f1cf94 (Client)
[2023-05-30T06:31:16Z DEBUG libp2p_swarm] Connection established: PeerId("12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X") Dialer { address: "/ip4/114.132.71.142/tcp/4001/p2p/12D3KooWDpJ7As7BWAwRMfu1VU2WCqNjvq387JEYKDBj4kx6nXTN/p2p-circuit/p2p/12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X", role_override: Dialer }; Total (peer): 1.
[2023-05-30T06:31:16Z DEBUG libp2p_gossipsub::behaviour] New peer connected: 12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X
[2023-05-30T06:31:16Z INFO client] Established connection to PeerId("12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X") via Dialer { address: "/ip4/114.132.71.142/tcp/4001/p2p/12D3KooWDpJ7As7BWAwRMfu1VU2WCqNjvq387JEYKDBj4kx6nXTN/p2p-circuit/p2p/12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X", role_override: Dialer }
[2023-05-30T06:31:16Z DEBUG yamux::connection] 62f1cf94: new outbound (Stream 62f1cf94/1) of (Connection 62f1cf94 Client (streams 0))
[2023-05-30T06:31:16Z DEBUG multistream_select::dialer_select] Dialer: Proposed protocol: /meshsub/1.1.0
[2023-05-30T06:31:16Z DEBUG yamux::connection] 62f1cf94: new outbound (Stream 62f1cf94/3) of (Connection 62f1cf94 Client (streams 1))
[2023-05-30T06:31:16Z DEBUG multistream_select::dialer_select] Dialer: Proposed protocol: /ipfs/id/1.0.0
[2023-05-30T06:31:16Z DEBUG yamux::connection] 62f1cf94: new outbound (Stream 62f1cf94/5) of (Connection 62f1cf94 Client (streams 2))
[2023-05-30T06:31:16Z DEBUG multistream_select::dialer_select] Dialer: Proposed protocol: /ipfs/ping/1.0.0
[2023-05-30T06:31:16Z DEBUG multistream_select::negotiated] Negotiated: Received confirmation for protocol: /yamux/1.0.0
[2023-05-30T06:31:16Z DEBUG multistream_select::dialer_select] Dialer: Received confirmation for protocol: /meshsub/1.1.0
[2023-05-30T06:31:16Z DEBUG multistream_select::listener_select] Listener: confirming protocol: /meshsub/1.1.0
[2023-05-30T06:31:16Z DEBUG multistream_select::listener_select] Listener: sent confirmed protocol: /meshsub/1.1.0
[2023-05-30T06:31:16Z DEBUG multistream_select::dialer_select] Dialer: Received confirmation for protocol: /ipfs/id/1.0.0
[2023-05-30T06:31:16Z DEBUG multistream_select::listener_select] Listener: confirming protocol: /libp2p/dcutr
[2023-05-30T06:31:16Z DEBUG multistream_select::listener_select] Listener: sent confirmed protocol: /libp2p/dcutr
[2023-05-30T06:31:16Z DEBUG multistream_select::dialer_select] Dialer: Received confirmation for protocol: /ipfs/ping/1.0.0
[2023-05-30T06:31:16Z DEBUG multistream_select::listener_select] Listener: confirming protocol: /ipfs/id/1.0.0
[2023-05-30T06:31:16Z DEBUG multistream_select::listener_select] Listener: sent confirmed protocol: /ipfs/id/1.0.0
[2023-05-30T06:31:16Z DEBUG multistream_select::listener_select] Listener: confirming protocol: /ipfs/ping/1.0.0
[2023-05-30T06:31:16Z DEBUG multistream_select::listener_select] Listener: sent confirmed protocol: /ipfs/ping/1.0.0
[2023-05-30T06:31:16Z DEBUG libp2p_gossipsub::behaviour] New peer type found: Gossipsub v1.1 for peer: 12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X
[2023-05-30T06:31:16Z INFO client] Received { peer_id: PeerId("12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X"), info: Info { public_key: PublicKey { publickey: Ed25519(PublicKey(compressed): cecc157dc1ddd7295951c29888f095adb944d1b73d696e6df65d683bd4fc) }, protocol_version: "/TODO/0.0.1", agent_version: "rust-libp2p/0.43.0", listen_addrs: ["/ip4/10.30.6.101/tcp/44415", "/ip4/192.168.160.1/tcp/44415", "/ip4/192.168.192.1/tcp/44415", "/ip4/172.21.0.1/tcp/44415", "/ip4/114.132.71.142/tcp/4001/p2p/12D3KooWDpJ7As7BWAwRMfu1VU2WCqNjvq387JEYKDBj4kx6nXTN/p2p-circuit/p2p/12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X", "/ip4/192.168.176.1/tcp/44415", "/ip4/127.0.0.1/tcp/44415", "/ip4/172.22.0.1/tcp/44415", "/ip4/192.168.144.1/tcp/44415", "/ip4/172.17.0.1/tcp/44415"], protocols: [StreamProtocol { inner: Right("/meshsub/1.0.0") }, StreamProtocol { inner: Right("/meshsub/1.1.0") }, StreamProtocol { inner: Right("/ipfs/id/1.0.0") }, StreamProtocol { inner: Right("/ipfs/ping/1.0.0") }, StreamProtocol { inner: Right("/ipfs/id/push/1.0.0") }], observed_addr: "/p2p/12D3KooWH3uVF6wv47WnArKHk5p6cvgCJEb74UTmxztmQDc298L3" } }
[2023-05-30T06:31:16Z INFO client] Sent { peer_id: PeerId("12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X") }
[2023-05-30T06:31:16Z DEBUG libp2p_ping::handler] latency to 12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X is 272ms
[2023-05-30T06:31:16Z DEBUG libp2p_gossipsub::behaviour] Handling subscriptions: [Subscription { action: Subscribe, topic_hash: TopicHash { hash: "test-net" } }], from source: 12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X
[2023-05-30T06:31:16Z DEBUG libp2p_gossipsub::behaviour] SUBSCRIPTION: Adding gossip peer: 12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X to topic: TopicHash { hash: "test-net" }
[2023-05-30T06:31:16Z DEBUG libp2p_gossipsub::behaviour] SUBSCRIPTION: Adding peer 12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X to the mesh for topic TopicHash { hash: "test-net" }
[2023-05-30T06:31:16Z DEBUG libp2p_gossipsub::behaviour] Sending GRAFT to peer 12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X for topic TopicHash { hash: "test-net" }
[2023-05-30T06:31:16Z DEBUG libp2p_gossipsub::behaviour] Handling GRAFT message for peer: 12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X
[2023-05-30T06:31:16Z DEBUG libp2p_gossipsub::behaviour] GRAFT: Received graft for peer PeerId("12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X") that is already in topic TopicHash { hash: "test-net" }
[2023-05-30T06:31:16Z DEBUG libp2p_gossipsub::behaviour] Completed GRAFT handling for peer: 12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X
[2023-05-30T06:31:16Z DEBUG libp2p_swarm] Connection closed with error Handler(Left(Right(Left(Apply(Left(NoAddresses)))))): Connected { endpoint: Dialer { address: "/ip4/114.132.71.142/tcp/4001/p2p/12D3KooWDpJ7As7BWAwRMfu1VU2WCqNjvq387JEYKDBj4kx6nXTN/p2p-circuit/p2p/12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X", role_override: Dialer }, peer_id: PeerId("12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X") }; Total (peer): 0.
[2023-05-30T06:31:16Z DEBUG libp2p_gossipsub::behaviour] Peer disconnected: 12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X
[2023-05-30T06:31:19Z DEBUG libp2p_gossipsub::behaviour] Starting heartbeat
[2023-05-30T06:31:19Z DEBUG libp2p_gossipsub::behaviour] HEARTBEAT: Mesh low. Topic: test-net Contains: 0 needs: 5
[2023-05-30T06:31:19Z DEBUG libp2p_gossipsub::behaviour] RANDOM PEERS: Got 0 peers
[2023-05-30T06:31:19Z DEBUG libp2p_gossipsub::behaviour] Updating mesh, new mesh: {}
[2023-05-30T06:31:19Z DEBUG libp2p_gossipsub::behaviour] Completed Heartbeat
[2023-05-30T06:31:26Z DEBUG libp2p_swarm] Connection closed with error KeepAliveTimeout: Connected { endpoint: Dialer { address: "/ip4/114.132.71.142/tcp/4001/p2p/12D3KooWDpJ7As7BWAwRMfu1VU2WCqNjvq387JEYKDBj4kx6nXTN", role_override: Dialer }, peer_id: PeerId("12D3KooWDpJ7As7BWAwRMfu1VU2WCqNjvq387JEYKDBj4kx6nXTN") }; Total (peer): 0.
[2023-05-30T06:31:26Z DEBUG libp2p_gossipsub::behaviour] Peer disconnected: 12D3KooWDpJ7As7BWAwRMfu1VU2WCqNjvq387JEYKDBj4kx6nXTN
[2023-05-30T06:31:29Z DEBUG libp2p_gossipsub::behaviour] Starting heartbeat
[2023-05-30T06:31:29Z DEBUG libp2p_gossipsub::behaviour] HEARTBEAT: Mesh low. Topic: test-net Contains: 0 needs: 5
[2023-05-30T06:31:29Z DEBUG libp2p_gossipsub::behaviour] RANDOM PEERS: Got 0 peers
[2023-05-30T06:31:29Z DEBUG libp2p_gossipsub::behaviour] Updating mesh, new mesh: {}
[2023-05-30T06:31:29Z DEBUG libp2p_gossipsub::behaviour] Completed Heartbeat
[2023-05-30T06:31:39Z DEBUG libp2p_gossipsub::behaviour] Starting heartbeat
[2023-05-30T06:31:39Z DEBUG libp2p_gossipsub::behaviour] HEARTBEAT: Mesh low. Topic: test-net Contains: 0 needs: 5
[2023-05-30T06:31:39Z DEBUG libp2p_gossipsub::behaviour] RANDOM PEERS: Got 0 peers
[2023-05-30T06:31:39Z DEBUG libp2p_gossipsub::behaviour] Updating mesh, new mesh: {}
[2023-05-30T06:31:39Z DEBUG libp2p_gossipsub::behaviour] Completed Heartbeat
[2023-05-30T06:31:49Z DEBUG libp2p_gossipsub::behaviour] Starting heartbeat
[2023-05-30T06:31:49Z DEBUG libp2p_gossipsub::behaviour] HEARTBEAT: Mesh low. Topic: test-net Contains: 0 needs: 5
[2023-05-30T06:31:49Z DEBUG libp2p_gossipsub::behaviour] RANDOM PEERS: Got 0 peers
[2023-05-30T06:31:49Z DEBUG libp2p_gossipsub::behaviour] Updating mesh, new mesh: {}
[2023-05-30T06:31:49Z DEBUG libp2p_gossipsub::behaviour] Completed Heartbeat
[2023-05-30T06:31:59Z DEBUG libp2p_gossipsub::behaviour] Starting heartbeat
[2023-05-30T06:31:59Z DEBUG libp2p_gossipsub::behaviour] HEARTBEAT: Mesh low. Topic: test-net Contains: 0 needs: 5
[2023-05-30T06:31:59Z DEBUG libp2p_gossipsub::behaviour] RANDOM PEERS: Got 0 peers
[2023-05-30T06:31:59Z DEBUG libp2p_gossipsub::behaviour] Updating mesh, new mesh: {}
[2023-05-30T06:31:59Z DEBUG libp2p_gossipsub::behaviour] Completed Heartbeat
[2023-05-30T06:32:09Z DEBUG libp2p_gossipsub::behaviour] Starting heartbeat
[2023-05-30T06:32:09Z DEBUG libp2p_gossipsub::behaviour] HEARTBEAT: Mesh low. Topic: test-net Contains: 0 needs: 5
[2023-05-30T06:32:09Z DEBUG libp2p_gossipsub::behaviour] RANDOM PEERS: Got 0 peers
[2023-05-30T06:32:09Z DEBUG libp2p_gossipsub::behaviour] Updating mesh, new mesh: {}
[2023-05-30T06:32:09Z DEBUG libp2p_gossipsub::behaviour] Completed Heartbeat
[2023-05-30T06:32:19Z DEBUG libp2p_gossipsub::behaviour] Starting heartbeat
[2023-05-30T06:32:19Z DEBUG libp2p_gossipsub::behaviour] HEARTBEAT: Mesh low. Topic: test-net Contains: 0 needs: 5
[2023-05-30T06:32:19Z DEBUG libp2p_gossipsub::behaviour] RANDOM PEERS: Got 0 peers
[2023-05-30T06:32:19Z DEBUG libp2p_gossipsub::behaviour] Updating mesh, new mesh: {}
[2023-05-30T06:32:19Z DEBUG libp2p_gossipsub::behaviour] Completed Heartbeat
[2023-05-30T06:32:29Z DEBUG libp2p_gossipsub::behaviour] Starting heartbeat
[2023-05-30T06:32:29Z DEBUG libp2p_gossipsub::behaviour] HEARTBEAT: Mesh low. Topic: test-net Contains: 0 needs: 5
Possible Solution
Version
- rust-libp2p master@34e178049826789956dcab6aefe491e4b156a024 (Tue May 30 02:06:57 2023), and later master
- I also tried the tag
libp2p-v0.51.3, still failed.
Would you like to work on fixing this bug?
Contributor guide
First steps
- Read the whole issue, then the project's contributing guide.
- Comment on the issue to say you are picking it up — it saves two people doing the same work.
- Fork the repository and make your change on a branch.
- Open a pull request that references the issue number.
Research direction
Start with libp2p/src/tutorials/hole_punching.rs and compare the relay and dialing-client flow described in the report. Inspect the generated dcutr message definitions in rust-libp2p/protocols/dcutr/src/generated/holepunch/pb.rs alongside the relay log showing that no inbound protocol was agreed upon. Done means the dialing client can complete the direct connection upgrade without the reported NoAddresses error.
Written by the indexing model from the issue text.
Assessment
- Tech stack
- rust
- Domain
- networking
- Issue type
- Bug
- Difficulty
- 4/5
- Estimated time
- 3-5 days
- Activity status
- Stale
- Clarity
- Needs clarification
- Newbie friendliness
- 30/100