Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

refactor(examples): use tokio instead of async-std in relay-server #5600

Merged
merged 7 commits into from
Oct 4, 2024
Merged

refactor(examples): use tokio instead of async-std in relay-server #5600

merged 7 commits into from
Oct 4, 2024

Conversation

P1R
Copy link
Contributor

@P1R P1R commented Sep 17, 2024

Description

Following on issue #4449
refactor: use tokio instead of async-std in the relay-servert example and remove unnecessary dependencies

Notes & open questions

Fails on testing with the whole punch tutorial possibly because of my networking topology. connection established event registered.

I will publish the logs and testing information as a comment

Change checklist

  • Removed unnecessary dependencies on examples/relay-server/Cargo.toml
  • Updated tokio version to "1.37.0"
  • I have performed a self-review of my own code
  • I have made corresponding changes to the documentation
  • I have added tests that prove my fix is effective or that my feature works
  • A changelog entry has been made in the appropriate crates

@P1R
Copy link
Contributor Author

P1R commented Sep 17, 2024

Issue 4449 relay-server (examples)

#4449

Code review and tests

the current PR

  • Refactor: use tokio instead of async-std in the relay-server example
  • Remove the block_on from futures::executor
  • Setup relay-server with open tcp port on 4001 at
  • Test libp2p-lookup
  • Test whole punching

Whole punching

Status: Cannot stablish the whole punching
Error: Outgoing Connection Failed: Timeout has been reached

Network Topology

The network topology used in this setup involves three key nodes:

  • Relay Server (/ip4/66.29.128.144/tcp/4001/p2p/12D3KooWDpJ7As7BWAwRMfu1VU2WCqNjvq387JEYKDBj4kx6nXTN),
    running in an Incus container with port forwarding enabled.

  • Listening Client (/ip4/10.162.235.31/tcp/36521/p2p/12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X),
    also running in an Incus container behind NAT using the same server that hosts the relay server (on a private IP address).

  • Dialing Client (/ip4/192.168.1.150/tcp/42045/12D3KooWH3uVF6wv47WnArKHk5p6cvgCJEb74UTmxztmQDc298L3),
    running on a separate device behind a NAT.

Key Observations:

  • Relay server has public access and forwards connections on port 4001.
  • Listening client is behind NAT in an Incus container on the same LAN as the relay.
  • Dialing client attempts direct connectivity to the listening node using a relay but struggles due to timeouts.

Problem:

Hole punching isn't successfully establishing between the listening and dialing clients. Timeouts are being hit while trying to negotiate transport protocols over the relay.

Relay Server

Multiaddress: /ip4/66.29.128.144/tcp/4001/p2p/12D3KooWDpJ7As7BWAwRMfu1VU2WCqNjvq387JEYKDBj4kx6nXTN

Executed command

./relay-server-example --port 4001 --secret-key-seed 0

Notice: the relay server is running in an incus container where the iptables
of the main server with the public ip address redirect the 4001 tcp in bouth
directions (forwarding enable).

Logs

p1r0@libp2p:~/rust-libp2p-bare/relay-server-example/target/debug$ ./relay-server-example --port 4001 --secret-key-seed 0
Listening on "/ip4/127.0.0.1/tcp/4001"
Listening on "/ip4/10.162.235.39/tcp/4001"
Listening on "/ip4/127.0.0.1/udp/4001/quic-v1"
Listening on "/ip4/10.162.235.39/udp/4001/quic-v1"
BehaviourEvent: Sent { connection_id: ConnectionId(1), peer_id: PeerId("12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X") }
BehaviourEvent: Received { connection_id: ConnectionId(1), 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.45.1", listen_addrs: ["/ip4/127.0.0.1/udp/39912/quic-v1", "/ip4/10.162.235.31/tcp/36521", "/ip4/127.0.0.1/tcp/36521", "/ip4/10.162.235.31/udp/39912/quic-v1"], protocols: ["/libp2p/circuit/relay/0.2.0/stop", "/ipfs/id/push/1.0.0", "/ipfs/id/1.0.0", "/ipfs/ping/1.0.0"], observed_addr: "/ip4/10.162.235.39/tcp/4001" } }
BehaviourEvent: Event { peer: PeerId("12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X"), connection: ConnectionId(1), result: Ok(1.550565ms) }
BehaviourEvent: ReservationReqAccepted { src_peer_id: PeerId("12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X"), renewed: false }
BehaviourEvent: Event { peer: PeerId("12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X"), connection: ConnectionId(1), result: Ok(1.472772ms) }
BehaviourEvent: Event { peer: PeerId("12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X"), connection: ConnectionId(1), result: Ok(1.874097ms) }
BehaviourEvent: Event { peer: PeerId("12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X"), connection: ConnectionId(1), result: Ok(2.331323ms) }
BehaviourEvent: Sent { connection_id: ConnectionId(3), peer_id: PeerId("12D3KooWH3uVF6wv47WnArKHk5p6cvgCJEb74UTmxztmQDc298L3") }
BehaviourEvent: Received { connection_id: ConnectionId(3), 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.45.1", listen_addrs: ["/ip4/127.0.0.1/tcp/42045", "/ip4/192.168.122.1/tcp/42045", "/ip4/192.168.122.1/udp/56226/quic-v1", "/ip4/192.168.1.150/tcp/42045", "/ip4/192.168.1.150/udp/56226/quic-v1", "/ip4/127.0.0.1/udp/56226/quic-v1"], protocols: ["/ipfs/id/1.0.0", "/ipfs/id/push/1.0.0", "/ipfs/ping/1.0.0", "/libp2p/circuit/relay/0.2.0/stop"], observed_addr: "/ip4/66.29.128.144/tcp/4001" } }
BehaviourEvent: Event { peer: PeerId("12D3KooWH3uVF6wv47WnArKHk5p6cvgCJEb74UTmxztmQDc298L3"), connection: ConnectionId(3), result: Ok(300.63699ms) }
BehaviourEvent: CircuitReqAccepted { src_peer_id: PeerId("12D3KooWH3uVF6wv47WnArKHk5p6cvgCJEb74UTmxztmQDc298L3"), dst_peer_id: PeerId("12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X") }
BehaviourEvent: Event { peer: PeerId("12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X"), connection: ConnectionId(1), result: Ok(1.357739ms) }
BehaviourEvent: Event { peer: PeerId("12D3KooWH3uVF6wv47WnArKHk5p6cvgCJEb74UTmxztmQDc298L3"), connection: ConnectionId(3), result: Ok(599.426206ms) }
BehaviourEvent: Event { peer: PeerId("12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X"), connection: ConnectionId(1), result: Ok(1.850532ms) }
BehaviourEvent: Event { peer: PeerId("12D3KooWH3uVF6wv47WnArKHk5p6cvgCJEb74UTmxztmQDc298L3"), connection: ConnectionId(3), result: Ok(81.035919ms) }
BehaviourEvent: Event { peer: PeerId("12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X"), connection: ConnectionId(1), result: Ok(1.396456ms) }
BehaviourEvent: Event { peer: PeerId("12D3KooWH3uVF6wv47WnArKHk5p6cvgCJEb74UTmxztmQDc298L3"), connection: ConnectionId(3), result: Ok(144.138389ms) }
BehaviourEvent: Event { peer: PeerId("12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X"), connection: ConnectionId(1), result: Ok(1.365213ms) }
BehaviourEvent: Event { peer: PeerId("12D3KooWH3uVF6wv47WnArKHk5p6cvgCJEb74UTmxztmQDc298L3"), connection: ConnectionId(3), result: Ok(75.182587ms) }
BehaviourEvent: Event { peer: PeerId("12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X"), connection: ConnectionId(1), result: Ok(1.865604ms) }
BehaviourEvent: Event { peer: PeerId("12D3KooWH3uVF6wv47WnArKHk5p6cvgCJEb74UTmxztmQDc298L3"), connection: ConnectionId(3), result: Ok(147.051367ms) }
BehaviourEvent: CircuitClosed { src_peer_id: PeerId("12D3KooWH3uVF6wv47WnArKHk5p6cvgCJEb74UTmxztmQDc298L3"), dst_peer_id: PeerId("12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X"), error: None }
BehaviourEvent: Event { peer: PeerId("12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X"), connection: ConnectionId(1), result: Ok(949.996µs) }
BehaviourEvent: Event { peer: PeerId("12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X"), connection: ConnectionId(1), result: Ok(1.66916ms) }
BehaviourEvent: Event { peer: PeerId("12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X"), connection: ConnectionId(1), result: Ok(1.713821ms) }

Listening Client

Multiaddress: /ip4/10.162.235.31/tcp/33887/p2p/12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6Xe4

Notice: the listening client is behind a incus NAT in a incus container where the host server is the
public ip address.

Executed command

RUST_LOG=info ./dcutr-example --secret-key-seed 1 --mode listen --relay-address /ip4/10.162.235.39/tcp/4001/p2p/12D3KooWDpJ7As7BWAwRMfu1VU2WCqNjvq387JEYKDBj4kx6nXTN

Notice: this is my laptop running in my home network where there is a NAT and a basic firewall setup
in the gateway

Logs

p1r0@libp2pNode1:~/rust-libp2p-bare/relay-server-example/target/debug$ RUST_LOG=info ./dcutr-example --secret-key-seed 1 --mode listen --relay-address /ip4/10.162.235.39/tcp/4001/p2p/12D3KooWDpJ7As7BWAwRMfu1VU2WCqNjvq387JEYKDBj4kx6nXTN
2024-09-17T08:37:15.173682Z  INFO libp2p_swarm: local_peer_id=12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X
2024-09-17T08:37:15.174558Z  INFO dcutr_example: Listening on address address=/ip4/127.0.0.1/tcp/36521
2024-09-17T08:37:15.174644Z  INFO dcutr_example: Listening on address address=/ip4/10.162.235.31/tcp/36521
2024-09-17T08:37:15.174892Z  INFO dcutr_example: Listening on address address=/ip4/127.0.0.1/udp/39912/quic-v1
2024-09-17T08:37:15.174989Z  INFO dcutr_example: Listening on address address=/ip4/10.162.235.31/udp/39912/quic-v1
2024-09-17T08:37:16.265139Z  INFO dcutr_example: Told relay its public address
2024-09-17T08:37:16.267471Z  INFO dcutr_example: Relay told us our observed address address=/ip4/10.162.235.31/tcp/36521
2024-09-17T08:37:16.315280Z  INFO dcutr_example: Relay accepted our reservation request
2024-09-17T08:37:16.315695Z  INFO dcutr_example: Listening on address address=/ip4/10.162.235.39/tcp/4001/p2p/12D3KooWDpJ7As7BWAwRMfu1VU2WCqNjvq387JEYKDBj4kx6nXTN/p2p-circuit/p2p/12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X
2024-09-17T08:38:02.255853Z  INFO dcutr_example: event=InboundCircuitEstablished { src_peer_id: PeerId("12D3KooWH3uVF6wv47WnArKHk5p6cvgCJEb74UTmxztmQDc298L3"), limit: Some(Limit { duration: Some(120s), data_in_bytes: Some(131072) }) }
2024-09-17T08:38:02.488581Z  INFO dcutr_example: Established new connection peer=12D3KooWH3uVF6wv47WnArKHk5p6cvgCJEb74UTmxztmQDc298L3 endpoint=Listener { local_addr: "/ip4/10.162.235.39/tcp/4001/p2p/12D3KooWDpJ7As7BWAwRMfu1VU2WCqNjvq387JEYKDBj4kx6nXTN/p2p-circuit", send_back_addr: "/p2p/12D3KooWH3uVF6wv47WnArKHk5p6cvgCJEb74UTmxztmQDc298L3" }
2024-09-17T08:38:02.489372Z  INFO dcutr_example: event=Sent { connection_id: ConnectionId(2), peer_id: PeerId("12D3KooWH3uVF6wv47WnArKHk5p6cvgCJEb74UTmxztmQDc298L3") }
2024-09-17T08:38:02.772861Z  INFO dcutr_example: event=Received { connection_id: ConnectionId(2), 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.45.1", listen_addrs: ["/ip4/127.0.0.1/tcp/42045", "/ip4/192.168.1.150/tcp/42045", "/ip4/127.0.0.1/udp/56226/quic-v1", "/ip4/192.168.122.1/udp/56226/quic-v1", "/ip4/192.168.1.150/udp/56226/quic-v1", "/ip4/192.168.122.1/tcp/42045"], protocols: ["/ipfs/ping/1.0.0", "/ipfs/id/push/1.0.0", "/ipfs/id/1.0.0", "/libp2p/dcutr"], observed_addr: "/ip4/66.29.128.144/tcp/4001/p2p/12D3KooWDpJ7As7BWAwRMfu1VU2WCqNjvq387JEYKDBj4kx6nXTN/p2p-circuit" } }
2024-09-17T08:38:12.893833Z  INFO dcutr_example: Outgoing connection failed: Failed to negotiate transport protocol(s): [(/ip4/187.195.97.54/tcp/42045/p2p/12D3KooWH3uVF6wv47WnArKHk5p6cvgCJEb74UTmxztmQDc298L3: : Timeout has been reached)] peer=Some(PeerId("12D3KooWH3uVF6wv47WnArKHk5p6cvgCJEb74UTmxztmQDc298L3"))
2024-09-17T08:38:23.472986Z  INFO dcutr_example: Outgoing connection failed: Failed to negotiate transport protocol(s): [(/ip4/187.195.97.54/tcp/42045/p2p/12D3KooWH3uVF6wv47WnArKHk5p6cvgCJEb74UTmxztmQDc298L3: : Timeout has been reached)] peer=Some(PeerId("12D3KooWH3uVF6wv47WnArKHk5p6cvgCJEb74UTmxztmQDc298L3"))
2024-09-17T08:38:34.048308Z  INFO dcutr_example: Outgoing connection failed: Failed to negotiate transport protocol(s): [(/ip4/187.195.97.54/tcp/42045/p2p/12D3KooWH3uVF6wv47WnArKHk5p6cvgCJEb74UTmxztmQDc298L3: : Timeout has been reached)] peer=Some(PeerId("12D3KooWH3uVF6wv47WnArKHk5p6cvgCJEb74UTmxztmQDc298L3"))
2024-09-17T08:38:34.048736Z  INFO dcutr_example: event=Event { remote_peer_id: PeerId("12D3KooWH3uVF6wv47WnArKHk5p6cvgCJEb74UTmxztmQDc298L3"), result: Err(Error { inner: AttemptsExceeded(3) }) }
2024-09-17T08:42:16.225777Z  INFO dcutr_example: event=Sent { connection_id: ConnectionId(1), peer_id: PeerId("12D3KooWDpJ7As7BWAwRMfu1VU2WCqNjvq387JEYKDBj4kx6nXTN") }
2024-09-17T08:42:16.227835Z  INFO dcutr_example: event=Received { connection_id: ConnectionId(1), peer_id: PeerId("12D3KooWDpJ7As7BWAwRMfu1VU2WCqNjvq387JEYKDBj4kx6nXTN"), info: Info { public_key: PublicKey { publickey: Ed25519(PublicKey(compressed): 3b6a27bcceb6a42d62a3a8d02a6fd73653215771de243a63ac048a18b59da29) }, protocol_version: "/TODO/0.0.1", agent_version: "rust-libp2p/0.45.1", listen_addrs: ["/ip4/10.162.235.39/tcp/4001", "/ip4/127.0.0.1/udp/4001/quic-v1", "/ip4/66.29.128.144/tcp/4001", "/ip4/10.162.235.39/udp/4001/quic-v1", "/ip4/127.0.0.1/tcp/4001"], protocols: ["/ipfs/id/1.0.0", "/ipfs/ping/1.0.0", "/libp2p/circuit/relay/0.2.0/hop", "/ipfs/id/push/1.0.0"], observed_addr: "/ip4/10.162.235.31/tcp/36521" } }

Dialing Client

Multiaddress: /ip4/192.168.1.150/tcp/42045/12D3KooWH3uVF6wv47WnArKHk5p6cvgCJEb74UTmxztmQDc298L3

Executed command

RUST_LOG=info ./dcutr-example --secret-key-seed 2 --mode dial --relay-address /ip4/66.29.128.144/tcp/4001/p2p/12D3KooWDpJ7As7BWAwRMfu1VU2WCqNjvq387JEYKDBj4kx6nXTN --remote-peer-id 12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6Xe4

Logs

└─(02:32:31 on relay-server-example)──> RUST_LOG=info ./dcutr-example --secret-key-seed 2 --mode dial --relay-address /ip4/66.29.128.144/tcp/4001/p2p/12D3KooWDpJ7As7BWAwRMfu1VU2WCqNjvq387JEYKDBj4kx6nXTN --remote-peer-id 12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X
2024-09-17T08:32:43.043274Z  INFO libp2p_swarm: local_peer_id=12D3KooWH3uVF6wv47WnArKHk5p6cvgCJEb74UTmxztmQDc298L3
2024-09-17T08:32:43.044208Z  INFO dcutr_example: Listening on address address=/ip4/127.0.0.1/tcp/42045
2024-09-17T08:32:43.044291Z  INFO dcutr_example: Listening on address address=/ip4/192.168.1.150/tcp/42045
2024-09-17T08:32:43.044358Z  INFO dcutr_example: Listening on address address=/ip4/192.168.122.1/tcp/42045
2024-09-17T08:32:43.044516Z  INFO dcutr_example: Listening on address address=/ip4/127.0.0.1/udp/56226/quic-v1
2024-09-17T08:32:43.044581Z  INFO dcutr_example: Listening on address address=/ip4/192.168.1.150/udp/56226/quic-v1
2024-09-17T08:32:43.044644Z  INFO dcutr_example: Listening on address address=/ip4/192.168.122.1/udp/56226/quic-v1
2024-09-17T08:32:44.860437Z  INFO dcutr_example: Told relay its public address
2024-09-17T08:32:44.862479Z  INFO dcutr_example: Relay told us our observed address address=/ip4/187.195.97.54/tcp/42045
2024-09-17T08:32:45.292991Z  INFO dcutr_example: event=OutboundCircuitEstablished { relay_peer_id: PeerId("12D3KooWDpJ7As7BWAwRMfu1VU2WCqNjvq387JEYKDBj4kx6nXTN"), limit: Some(Limit { duration: Some(120s), data_in_bytes: Some(131072) }) }
2024-09-17T08:32:45.386709Z  INFO dcutr_example: Established new connection peer=12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X endpoint=Dialer { address: "/ip4/66.29.128.144/tcp/4001/p2p/12D3KooWDpJ7As7BWAwRMfu1VU2WCqNjvq387JEYKDBj4kx6nXTN/p2p-circuit/p2p/12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X", role_override: Dialer, port_use: Reuse }
2024-09-17T08:32:45.684082Z  INFO dcutr_example: event=Sent { connection_id: ConnectionId(2), peer_id: PeerId("12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X") }
2024-09-17T08:32:45.686354Z  INFO dcutr_example: event=Received { connection_id: ConnectionId(2), 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.45.1", listen_addrs: ["/ip4/10.162.235.31/udp/39912/quic-v1", "/ip4/10.162.235.31/tcp/36521", "/ip4/127.0.0.1/udp/39912/quic-v1", "/ip4/127.0.0.1/tcp/36521", "/ip4/10.162.235.39/tcp/4001/p2p/12D3KooWDpJ7As7BWAwRMfu1VU2WCqNjvq387JEYKDBj4kx6nXTN/p2p-circuit/p2p/12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X"], protocols: ["/ipfs/id/1.0.0", "/ipfs/ping/1.0.0", "/ipfs/id/push/1.0.0"], observed_addr: "/p2p/12D3KooWH3uVF6wv47WnArKHk5p6cvgCJEb74UTmxztmQDc298L3" } }
2024-09-17T08:32:56.045252Z  INFO dcutr_example: Outgoing connection failed: Failed to negotiate transport protocol(s): [(/ip4/10.162.235.31/tcp/36521/p2p/12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X: : Timeout has been reached)] peer=Some(PeerId("12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X"))
2024-09-17T08:33:06.395826Z  INFO dcutr_example: Outgoing connection failed: Failed to negotiate transport protocol(s): [(/ip4/10.162.235.31/tcp/36521/p2p/12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X: : Timeout has been reached)] peer=Some(PeerId("12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X"))
2024-09-17T08:33:16.971184Z  INFO dcutr_example: Outgoing connection failed: Failed to negotiate transport protocol(s): [(/ip4/10.162.235.31/tcp/36521/p2p/12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X: : Timeout has been reached)] peer=Some(PeerId("12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X"))

Issue Considerations

I am not getting the tutorial logs in the dialing or listening clients some issues I could think of:

  1. the incus container in the NAT might not resolve properly the public IP since it is also its gateway (yet DNS resolves it)
  2. iptables configs for tcp forward has extra restrictions, yet the libp2p-lookup works.
  3. My LAN resolves mostly on ipv6
  4. code or sync issue.

Posible solutions

In case is network topology related:

  1. check upd with quic-v1
  2. Someone else has an network topology or environment to test this.
  3. Someone can help me using their own NAT and LAN so that we can verify without the incus container and incus NAT

Others:

  • Code or sync issue?

References/Sources

  1. https://docs.rs/libp2p/0.54.1/libp2p/tutorials/hole_punching/index.html
  2. Prefer tokio runtime everywhere #4449
  3. https://github.com/mxinden/libp2p-lookup

@jxs jxs changed the title refactor(examples): use tokio instead of async-std in relay-server [Code Review] refactor(examples): use tokio instead of async-std in relay-server Sep 17, 2024
dariusc93
dariusc93 reviewed Sep 19, 2024
View reviewed changes
Copy link
Member

@dariusc93 dariusc93 left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Could you format the example?

@dariusc93 dariusc93 self-requested a review September 19, 2024 00:26
@P1R
Copy link
Contributor Author

P1R commented Sep 20, 2024 •
edited
Loading

UPDATE 1:

format added with cargo fmt.

UPDATE 2: testing with ../udp/4001/quic-v1/p2p..

Relay Server

Multiaddress: /ip4/66.29.128.144/udp/4001/quic-v1/p2p/12D3KooWDpJ7As7BWAwRMfu1VU2WCqNjvq387JEYKDBj4kx6nXTN

Executed command

./relay-server-example --port 4001 --secret-key-seed 0

Notice: the relay server is running in an incus container where the iptables
of the main server with the public ip address redirect the 4001 tcp in bouth
directions (forwarding enable).

Logs

p1r0@libp2p:~/rust-libp2p-bare/relay-server-example/target/debug$ ./relay-server-example --port 4001 --secret-key-seed 0
Listening on "/ip4/127.0.0.1/tcp/4001"
Listening on "/ip4/10.162.235.39/tcp/4001"
Listening on "/ip4/127.0.0.1/udp/4001/quic-v1"
Listening on "/ip4/10.162.235.39/udp/4001/quic-v1"
BehaviourEvent: Sent { connection_id: ConnectionId(12), peer_id: PeerId("12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X") }
BehaviourEvent: Error { connection_id: ConnectionId(12), peer_id: PeerId("12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X"), error: Timeout }
BehaviourEvent: Event { peer: PeerId("12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X"), connection: ConnectionId(12), result: Err(Other { error: Custom { kind: NotConnected, error: ConnectionLost(TimedOut) } }) }
BehaviourEvent: Sent { connection_id: ConnectionId(13), peer_id: PeerId("12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X") }
BehaviourEvent: Error { connection_id: ConnectionId(13), peer_id: PeerId("12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X"), error: Timeout }
BehaviourEvent: Event { peer: PeerId("12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X"), connection: ConnectionId(13), result: Err(Other { error: Custom { kind: NotConnected, error: ConnectionLost(TimedOut) } }) }
BehaviourEvent: Sent { connection_id: ConnectionId(15), peer_id: PeerId("12D3KooWH3uVF6wv47WnArKHk5p6cvgCJEb74UTmxztmQDc298L3") }
BehaviourEvent: Received { connection_id: ConnectionId(15), 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.45.1", listen_addrs: ["/ip4/192.168.1.24/tcp/43971", "/ip4/127.0.0.1/tcp/43971", "/ip4/192.168.1.24/udp/60821/quic-v1", "/ip4/127.0.0.1/udp/60821/quic-v1"], protocols: ["/ipfs/id/1.0.0", "/ipfs/ping/1.0.0", "/ipfs/id/push/1.0.0", "/libp2p/circuit/relay/0.2.0/stop"], observed_addr: "/ip4/66.29.128.144/udp/4001/quic-v1" } }

Listening Client

Multiaddress: /ip4/10.162.235.39/udp/4001/quic-v1/p2p/12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6Xe4

Notice: this time the client is running in a friend's LAN(NAT+Firewall )

Executed command

RUST_LOG=info ./dcutr-example --secret-key-seed 1 --mode listen --relay-address /ip4/66.29.128.144/udp/4001/quic-v1/p2p/12D3KooWDpJ7As7BWAwRMfu1VU2WCqNjvq387JEYKDBj4kx6nXTN

Logs

ahgala@rustbox ~/r/r/t/debug (relay-server-example) [101]> RUST_LOG=info ./dcutr-example --secret-key-seed 1 --mode listen --relay-address /ip4/66.29.128.144/udp/4001/quic-v1/p2p/12D3KooWDpJ7As7BWAwRMfu1VU2WCqNjvq387JEYKDBj4kx6nXTN
2024-09-20T05:51:48.136817Z  INFO libp2p_swarm: local_peer_id=12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X
2024-09-20T05:51:48.138042Z  INFO dcutr_example: Listening on address address=/ip4/127.0.0.1/tcp/34795
2024-09-20T05:51:48.138127Z  INFO dcutr_example: Listening on address address=/ip4/10.160.42.179/tcp/34795
2024-09-20T05:51:48.138359Z  INFO dcutr_example: Listening on address address=/ip4/127.0.0.1/udp/44072/quic-v1
2024-09-20T05:51:48.138442Z  INFO dcutr_example: Listening on address address=/ip4/10.160.42.179/udp/44072/quic-v1
2024-09-20T05:51:49.377339Z  INFO dcutr_example: Relay told us our observed address address=/ip4/201.102.167.194/udp/44072/quic-v1
thread 'main' panicked at examples/dcutr/src/main.rs:165:26:
NewExternalAddrOfPeer { peer_id: PeerId("12D3KooWDpJ7As7BWAwRMfu1VU2WCqNjvq387JEYKDBj4kx6nXTN"), address: "/ip4/10.162.235.39/udp/4001/quic-v1" }
note: run with RUST_BACKTRACE=1 environment variable to display a backtrace

Dialing Client

Multiaddress: /ip4/192.168.1.150/udp/4001/quic-v1/p2p/12D3KooWH3uVF6wv47WnArKHk5p6cvgCJEb74UTmxztmQDc298L3

Notice: this is my laptop running in my home network where there is a NAT and a basic firewall setup
in the gateway

Executed command

 RUST_LOG=info ./dcutr-example --secret-key-seed 2 --mode dial --relay-address /ip4/66.29.128.144/udp/4001/quic-v1/p2p/12D3KooWDpJ7As7BWAwRMfu1VU2WCqNjvq387JEYKDBj4kx6nXTN --remote-peer-id 12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X

Logs

┌─(...-libp2p-bare/relay-server-example/target/debug)───(p1r0@thoth:pts/4)─┐
└─(23:53:28 on relay-server-example)──> RUST_LOG=info ./dcutr-example --secret-key-seed 2 --mode dial --relay-address /ip4/66.29.128.144/udp/4001/quic-v1/p2p/12D3KooWDpJ7As7BWAwRMfu1VU2WCqNjvq387JEYKDBj4kx6nXTN --remote-peer-id 12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X

2024-09-20T05:53:44.435972Z  INFO libp2p_swarm: local_peer_id=12D3KooWH3uVF6wv47WnArKHk5p6cvgCJEb74UTmxztmQDc298L3
2024-09-20T05:53:44.436691Z  INFO dcutr_example: Listening on address address=/ip4/127.0.0.1/tcp/43971
2024-09-20T05:53:44.436723Z  INFO dcutr_example: Listening on address address=/ip4/192.168.1.24/tcp/43971
2024-09-20T05:53:44.436803Z  INFO dcutr_example: Listening on address address=/ip4/127.0.0.1/udp/60821/quic-v1
2024-09-20T05:53:44.436829Z  INFO dcutr_example: Listening on address address=/ip4/192.168.1.24/udp/60821/quic-v1
2024-09-20T05:53:45.677762Z  INFO dcutr_example: Relay told us our observed address address=/ip4/138.84.62.18/udp/2268/quic-v1
thread 'main' panicked at examples/dcutr/src/main.rs:165:26:
NewExternalAddrOfPeer { peer_id: PeerId("12D3KooWDpJ7As7BWAwRMfu1VU2WCqNjvq387JEYKDBj4kx6nXTN"), address: "/ip4/10.162.235.39/udp/4001/quic-v1" }
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace

Issue Considerations

Given the error on bouth peers:

 'main' panicked at examples/dcutr/src/main.rs:165:26:
NewExternalAddrOfPeer { peer_id: PeerId("12D3KooWDpJ7As7BWAwRMfu1VU2WCqNjvq387JEYKDBj4kx6nXTN"), address: "/ip4/10.162.235.39/udp/4001/quic-v1" }

it seems that the line 164 is inside an block_on(Async as in using the futures block_on crate:

   23     block_on(async {
   22         let mut learned_observed_addr = false;
   21         let mut told_relay_observed_addr = false;
   20
   19         loop {
   18             match swarm.next().await.unwrap() {
   17                 SwarmEvent::NewListenAddr { .. } => {}
   16                 SwarmEvent::Dialing { .. } => {}
   15                 SwarmEvent::ConnectionEstablished { .. } => {}
   14                 SwarmEvent::Behaviour(BehaviourEvent::Ping(_)) => {}
   13                 SwarmEvent::Behaviour(BehaviourEvent::Identify(identify::Event::Sent {
   12                     ..
   11                 })) => {
   10                     tracing::info!("Told relay its public address");
    9                     told_relay_observed_addr = true;
    8                 }
    7                 SwarmEvent::Behaviour(BehaviourEvent::Identify(identify::Event::Received {
    6                     info: identify::Info { observed_addr, .. },
    5                     ..
    4                 })) => {
    3                     tracing::info!(address=%observed_addr, "Relay told us our observed address");
    2                     learned_observed_addr = true;
    1                 }
  165                 event => panic!("{event:?}"),
    1             }
    2
    3             if learned_observed_addr && told_relay_observed_addr {
    4                 break;
    5             }
    6         }
    7     });

NOTICE: In a previous call it was requested to remove this block_on section from the relay-server example

Could the issue be related to the block_on future not managed in the releay-server?

Posible solutions:

  1. Remove the block_on from futures from the dcutr-example code as the clients and do the tests again.

@P1R
Copy link
Contributor Author

P1R commented Sep 24, 2024

UPDATE 3: Retesting the whole punch with some changes on dcutr-example

Notice: block_on from futures where removed from the dcutr... yet I am not sure if it does the whole process (I require to understand dcutr further and debug the loops inside the tokio async function, just testing and documenting)

Relay Server

Multiaddress: /ip4/66.29.128.144/tcp/4001/p2p/12D3KooWDpJ7As7BWAwRMfu1VU2WCqNjvq387JEYKDBj4kx6nXTN

Executed command

./relay-server-example --port 4001 --secret-key-seed 0

Notice: the relay server is running in an incus container where the iptables
of the main server with the public ip address redirect the 4001 tcp in bouth
directions (forwarding enable) .
it also redirects the 4001 udp for the quic-v1

Logs

p1r0@libp2p:~/rust-libp2p-bare/relay-server-example/target/debug$ ./relay-server-example --port 4001 --secret-key-seed 0
Listening on "/ip4/127.0.0.1/tcp/4001"
Listening on "/ip4/10.162.235.39/tcp/4001"
Listening on "/ip4/127.0.0.1/udp/4001/quic-v1"
Listening on "/ip4/10.162.235.39/udp/4001/quic-v1"
BehaviourEvent: Sent { connection_id: ConnectionId(1), peer_id: PeerId("12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X") }
BehaviourEvent: Received { connection_id: ConnectionId(1), 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.45.1", listen_addrs: ["/ip4/192.168.122.1/udp/51997/quic-v1", "/ip4/192.168.1.23/udp/51997/quic-v1", "/ip4/192.168.1.23/tcp/34015", "/ip4/192.168.122.1/tcp/34015", "/ip4/127.0.0.1/tcp/34015", "/ip4/127.0.0.1/udp/51997/quic-v1"], protocols: ["/ipfs/id/push/1.0.0", "/libp2p/circuit/relay/0.2.0/stop", "/ipfs/id/1.0.0", "/ipfs/ping/1.0.0"], observed_addr: "/ip4/66.29.128.144/tcp/4001" } }
BehaviourEvent: Event { peer: PeerId("12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X"), connection: ConnectionId(1), result: Ok(186.89332ms) }
BehaviourEvent: ReservationReqAccepted { src_peer_id: PeerId("12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X"), renewed: false }
BehaviourEvent: Sent { connection_id: ConnectionId(2), peer_id: PeerId("12D3KooWH3uVF6wv47WnArKHk5p6cvgCJEb74UTmxztmQDc298L3") }
BehaviourEvent: Received { connection_id: ConnectionId(2), 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.45.1", listen_addrs: ["/ip4/192.168.1.165/udp/57384/quic-v1", "/ip4/192.168.1.165/tcp/36199", "/ip4/127.0.0.1/udp/57384/quic-v1", "/ip4/127.0.0.1/tcp/36199"], protocols: ["/libp2p/circuit/relay/0.2.0/stop", "/ipfs/id/push/1.0.0", "/ipfs/id/1.0.0", "/ipfs/ping/1.0.0"], observed_addr: "/ip4/66.29.128.144/tcp/4001" } }
BehaviourEvent: Event { peer: PeerId("12D3KooWH3uVF6wv47WnArKHk5p6cvgCJEb74UTmxztmQDc298L3"), connection: ConnectionId(2), result: Ok(162.240753ms) }
BehaviourEvent: CircuitReqAccepted { src_peer_id: PeerId("12D3KooWH3uVF6wv47WnArKHk5p6cvgCJEb74UTmxztmQDc298L3"), dst_peer_id: PeerId("12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X") }
BehaviourEvent: Event { peer: PeerId("12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X"), connection: ConnectionId(1), result: Ok(155.51549ms) }
BehaviourEvent: Event { peer: PeerId("12D3KooWH3uVF6wv47WnArKHk5p6cvgCJEb74UTmxztmQDc298L3"), connection: ConnectionId(2), result: Ok(124.563906ms) }
BehaviourEvent: Event { peer: PeerId("12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X"), connection: ConnectionId(1), result: Ok(124.452108ms) }
BehaviourEvent: Event { peer: PeerId("12D3KooWH3uVF6wv47WnArKHk5p6cvgCJEb74UTmxztmQDc298L3"), connection: ConnectionId(2), result: Ok(128.176112ms) }
BehaviourEvent: Event { peer: PeerId("12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X"), connection: ConnectionId(1), result: Ok(108.157015ms) }
BehaviourEvent: Event { peer: PeerId("12D3KooWH3uVF6wv47WnArKHk5p6cvgCJEb74UTmxztmQDc298L3"), connection: ConnectionId(2), result: Ok(126.106238ms) }
BehaviourEvent: Event { peer: PeerId("12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X"), connection: ConnectionId(1), result: Ok(202.87967ms) }
BehaviourEvent: Event { peer: PeerId("12D3KooWH3uVF6wv47WnArKHk5p6cvgCJEb74UTmxztmQDc298L3"), connection: ConnectionId(2), result: Ok(122.195224ms) }
BehaviourEvent: Event { peer: PeerId("12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X"), connection: ConnectionId(1), result: Ok(109.240025ms) }
BehaviourEvent: Event { peer: PeerId("12D3KooWH3uVF6wv47WnArKHk5p6cvgCJEb74UTmxztmQDc298L3"), connection: ConnectionId(2), result: Ok(125.998096ms) }
BehaviourEvent: Event { peer: PeerId("12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X"), connection: ConnectionId(1), result: Ok(173.713696ms) }
BehaviourEvent: Event { peer: PeerId("12D3KooWH3uVF6wv47WnArKHk5p6cvgCJEb74UTmxztmQDc298L3"), connection: ConnectionId(2), result: Ok(124.848002ms) }
BehaviourEvent: Event { peer: PeerId("12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X"), connection: ConnectionId(1), result: Ok(120.624772ms) }
BehaviourEvent: Event { peer: PeerId("12D3KooWH3uVF6wv47WnArKHk5p6cvgCJEb74UTmxztmQDc298L3"), connection: ConnectionId(2), result: Ok(128.200104ms) }
BehaviourEvent: Event { peer: PeerId("12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X"), connection: ConnectionId(1), result: Ok(186.692759ms) }
BehaviourEvent: CircuitClosed { src_peer_id: PeerId("12D3KooWH3uVF6wv47WnArKHk5p6cvgCJEb74UTmxztmQDc298L3"), dst_peer_id: PeerId("12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X"), error: Some(Kind(TimedOut)) }
BehaviourEvent: Event { peer: PeerId("12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X"), connection: ConnectionId(1), result: Ok(139.108973ms) }
BehaviourEvent: Event { peer: PeerId("12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X"), connection: ConnectionId(1), result: Ok(112.638154ms) }
BehaviourEvent: Event { peer: PeerId("12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X"), connection: ConnectionId(1), result: Ok(182.846162ms) }
BehaviourEvent: Event { peer: PeerId("12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X"), connection: ConnectionId(1), result: Ok(105.296893ms) }
BehaviourEvent: Event { peer: PeerId("12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X"), connection: ConnectionId(1), result: Ok(178.216788ms) }

Listening Client

Multiaddress: /ip4/192.168.1.23/tcp/4001/p2p/12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6Xe4

Public IP of gateway is 138.84.62.21

Notice: this time the client is running in a Starlink network LAN (NAT+Firewall )

Executed command

RUST_LOG=info ./dcutr-example --secret-key-seed 1 --mode listen --relay-address /ip4/66.29.128.144/tcp/4001/p2p/12D3KooWDpJ7As7BWAwRMfu1VU2WCqNjvq387JEYKDBj4kx6nXTN

Logs

┌─(~/Dev/git/libp2p/issue4449/rust-libp2p-bare/dcutr-example/target/debug)───────────────────────────────────────────────────────────────(p1r0@mew:pts/0)─┐
└─(21:04:09 on dcutr-example)──> RUST_LOG=info ./dcutr-example --secret-key-seed 1 --mode listen --relay-address /ip4/66.29.128.144/tcp/4001/p2p/12D3KooWDpJ7As7BWAwRMfu1VU2WCqNjvq387JEYKDBj4kx6nXTN

2024-09-24T06:50:05.151826Z  INFO libp2p_swarm: local_peer_id=12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X
2024-09-24T06:50:05.152620Z  INFO dcutr_example: Listening on address address=/ip4/127.0.0.1/tcp/34015
2024-09-24T06:50:05.152691Z  INFO dcutr_example: Listening on address address=/ip4/192.168.1.23/tcp/34015
2024-09-24T06:50:05.152752Z  INFO dcutr_example: Listening on address address=/ip4/192.168.122.1/tcp/34015
2024-09-24T06:50:05.152929Z  INFO dcutr_example: Listening on address address=/ip4/127.0.0.1/udp/51997/quic-v1
2024-09-24T06:50:05.152992Z  INFO dcutr_example: Listening on address address=/ip4/192.168.1.23/udp/51997/quic-v1
2024-09-24T06:50:05.153052Z  INFO dcutr_example: Listening on address address=/ip4/192.168.122.1/udp/51997/quic-v1
2024-09-24T06:50:06.597423Z  INFO dcutr_example: Told relay its public address
2024-09-24T06:50:06.599805Z  INFO dcutr_example: Relay told us our observed address address=/ip4/138.84.62.21/tcp/53497
2024-09-24T06:50:06.885247Z  INFO dcutr_example: Relay accepted our reservation request
2024-09-24T06:50:06.885694Z  INFO dcutr_example: Listening on address address=/ip4/66.29.128.144/tcp/4001/p2p/12D3KooWDpJ7As7BWAwRMfu1VU2WCqNjvq387JEYKDBj4kx6nXTN/p2p-circuit/p2p/12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X
2024-09-24T06:50:10.975529Z  INFO dcutr_example: event=InboundCircuitEstablished { src_peer_id: PeerId("12D3KooWH3uVF6wv47WnArKHk5p6cvgCJEb74UTmxztmQDc298L3"), limit: Some(Limit { duration: Some(120s), data_in_bytes: Some(131072) }) }
2024-09-24T06:50:11.627476Z  INFO dcutr_example: Established new connection peer=12D3KooWH3uVF6wv47WnArKHk5p6cvgCJEb74UTmxztmQDc298L3 endpoint=Listener { local_addr: "/ip4/66.29.128.144/tcp/4001/p2p/12D3KooWDpJ7As7BWAwRMfu1VU2WCqNjvq387JEYKDBj4kx6nXTN/p2p-circuit", send_back_addr: "/p2p/12D3KooWH3uVF6wv47WnArKHk5p6cvgCJEb74UTmxztmQDc298L3" }
2024-09-24T06:50:11.627986Z  INFO dcutr_example: event=Sent { connection_id: ConnectionId(2), peer_id: PeerId("12D3KooWH3uVF6wv47WnArKHk5p6cvgCJEb74UTmxztmQDc298L3") }
2024-09-24T06:50:12.171458Z  INFO dcutr_example: event=Received { connection_id: ConnectionId(2), 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.45.1", listen_addrs: ["/ip4/192.168.1.165/tcp/36199", "/ip4/127.0.0.1/udp/57384/quic-v1", "/ip4/127.0.0.1/tcp/36199", "/ip4/192.168.1.165/udp/57384/quic-v1"], protocols: ["/ipfs/ping/1.0.0", "/ipfs/id/1.0.0", "/ipfs/id/push/1.0.0", "/libp2p/dcutr"], observed_addr: "/ip4/66.29.128.144/tcp/4001/p2p/12D3KooWDpJ7As7BWAwRMfu1VU2WCqNjvq387JEYKDBj4kx6nXTN/p2p-circuit" } }
2024-09-24T06:50:12.597641Z  INFO dcutr_example: Established new connection peer=12D3KooWH3uVF6wv47WnArKHk5p6cvgCJEb74UTmxztmQDc298L3 endpoint=Dialer { address: "/ip4/187.195.77.224/tcp/36199/p2p/12D3KooWH3uVF6wv47WnArKHk5p6cvgCJEb74UTmxztmQDc298L3", role_override: Listener, port_use: Reuse }
2024-09-24T06:50:12.597857Z  INFO dcutr_example: event=Event { remote_peer_id: PeerId("12D3KooWH3uVF6wv47WnArKHk5p6cvgCJEb74UTmxztmQDc298L3"), result: Ok(ConnectionId(3)) }
2024-09-24T06:50:12.598704Z  INFO dcutr_example: event=Sent { connection_id: ConnectionId(3), peer_id: PeerId("12D3KooWH3uVF6wv47WnArKHk5p6cvgCJEb74UTmxztmQDc298L3") }
2024-09-24T06:50:12.659021Z  INFO dcutr_example: event=Received { connection_id: ConnectionId(3), 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.45.1", listen_addrs: ["/ip4/127.0.0.1/udp/57384/quic-v1", "/ip4/192.168.1.165/udp/57384/quic-v1", "/ip4/127.0.0.1/tcp/36199", "/ip4/192.168.1.165/tcp/36199"], protocols: ["/ipfs/ping/1.0.0", "/ipfs/id/push/1.0.0", "/libp2p/circuit/relay/0.2.0/stop", "/ipfs/id/1.0.0"], observed_addr: "/ip4/138.84.62.21/tcp/53497" } }

Dialing Client

Multiaddress: /ip4/192.168.1.165/tcp/4001//p2p/12D3KooWH3uVF6wv47WnArKHk5p6cvgCJEb74UTmxztmQDc298L3

Public IP of gateway is 187.195.77.224

Notice: it is my ISP provider and my PC.

Executed command

RUST_LOG=info ./dcutr-example --secret-key-seed 2 --mode dial --relay-address /ip4/66.29.128.144/tcp/4001/p2p/12D3KooWDpJ7As7BWAwRMfu1VU2WCqNjvq387JEYKDBj4kx6nXTN --remote-peer-id 12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X

Logs

┌─(~/Dev/git/libp2p/issue4449/rust-libp2p-bare/dcutr-example/target/debug)─────────────────────────────────────────────────────────────(p1r0@thoth:pts/0)─┐
└─(00:45:28 on dcutr-example)──> RUST_LOG=info ./dcutr-example --secret-key-seed 2 --mode dial --relay-address /ip4/66.29.128.144/tcp/4001/p2p/12D3KooWDpJ7As7BWAwRMfu1VU2WCqNjvq387JEYKDBj4kx6nXTN --remote-peer-id 12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X
2024-09-24T06:49:53.431642Z  INFO libp2p_swarm: local_peer_id=12D3KooWH3uVF6wv47WnArKHk5p6cvgCJEb74UTmxztmQDc298L3
2024-09-24T06:49:53.432352Z  INFO dcutr_example: Listening on address address=/ip4/127.0.0.1/tcp/36199
2024-09-24T06:49:53.432385Z  INFO dcutr_example: Listening on address address=/ip4/192.168.1.165/tcp/36199
2024-09-24T06:49:53.432459Z  INFO dcutr_example: Listening on address address=/ip4/127.0.0.1/udp/57384/quic-v1
2024-09-24T06:49:53.432485Z  INFO dcutr_example: Listening on address address=/ip4/192.168.1.165/udp/57384/quic-v1
2024-09-24T06:49:54.826035Z  INFO dcutr_example: Told relay its public address
2024-09-24T06:49:54.826377Z  INFO dcutr_example: Relay told us our observed address address=/ip4/187.195.77.224/tcp/36199
2024-09-24T06:49:55.250296Z  INFO dcutr_example: event=OutboundCircuitEstablished { relay_peer_id: PeerId("12D3KooWDpJ7As7BWAwRMfu1VU2WCqNjvq387JEYKDBj4kx6nXTN"), limit: Some(Limit { duration: Some(120s), data_in_bytes: Some(131072) }) }
2024-09-24T06:49:55.673866Z  INFO dcutr_example: Established new connection peer=12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X endpoint=Dialer { address: "/ip4/66.29.128.144/tcp/4001/p2p/12D3KooWDpJ7As7BWAwRMfu1VU2WCqNjvq387JEYKDBj4kx6nXTN/p2p-circuit/p2p/12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X", role_override: Dialer, port_use: Reuse }
2024-09-24T06:49:56.070400Z  INFO dcutr_example: event=Sent { connection_id: ConnectionId(2), peer_id: PeerId("12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X") }
2024-09-24T06:49:56.070856Z  INFO dcutr_example: event=Received { connection_id: ConnectionId(2), 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.45.1", listen_addrs: ["/ip4/66.29.128.144/tcp/4001/p2p/12D3KooWDpJ7As7BWAwRMfu1VU2WCqNjvq387JEYKDBj4kx6nXTN/p2p-circuit/p2p/12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X", "/ip4/127.0.0.1/tcp/34015", "/ip4/192.168.122.1/udp/51997/quic-v1", "/ip4/192.168.122.1/tcp/34015", "/ip4/192.168.1.23/tcp/34015", "/ip4/127.0.0.1/udp/51997/quic-v1", "/ip4/192.168.1.23/udp/51997/quic-v1"], protocols: ["/ipfs/id/1.0.0", "/ipfs/ping/1.0.0", "/ipfs/id/push/1.0.0"], observed_addr: "/p2p/12D3KooWH3uVF6wv47WnArKHk5p6cvgCJEb74UTmxztmQDc298L3" } }
2024-09-24T06:49:56.745621Z  INFO dcutr_example: Established new connection peer=12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X endpoint=Dialer { address: "/ip4/138.84.62.21/tcp/53497/p2p/12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X", role_override: Dialer, port_use: Reuse }
2024-09-24T06:49:56.745690Z  INFO dcutr_example: event=Event { remote_peer_id: PeerId("12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X"), result: Ok(ConnectionId(3)) }
2024-09-24T06:49:56.843980Z  INFO dcutr_example: event=Sent { connection_id: ConnectionId(3), peer_id: PeerId("12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X") }
2024-09-24T06:49:56.844322Z  INFO dcutr_example: event=Received { connection_id: ConnectionId(3), 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.45.1", listen_addrs: ["/ip4/192.168.1.23/tcp/34015", "/ip4/192.168.122.1/tcp/34015", "/ip4/192.168.122.1/udp/51997/quic-v1", "/ip4/127.0.0.1/udp/51997/quic-v1", "/ip4/66.29.128.144/tcp/4001/p2p/12D3KooWDpJ7As7BWAwRMfu1VU2WCqNjvq387JEYKDBj4kx6nXTN/p2p-circuit/p2p/12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X", "/ip4/127.0.0.1/tcp/34015", "/ip4/192.168.1.23/udp/51997/quic-v1"], protocols: ["/ipfs/id/1.0.0", "/ipfs/id/push/1.0.0", "/ipfs/ping/1.0.0", "/libp2p/circuit/relay/0.2.0/stop"], observed_addr: "/ip4/187.195.77.224/tcp/36199" } }

Issue Considerations

  1. Not sure if the whole punch was performed correctly but at least there is the information exchange and a connection and exchanged data.
  2. Unknown if the dcutr-example loops works async jumps to other what used to be futures block_on (async...
  3. I saw a connection with the circuit-relay server happen (perhaps someone did the verification ?)

Conclusions

It seems I require to study deeper dcutr code and verify my changes to the futures block_on, this was just an experimental process but require to understand more the protocol and debug the code.

jxs
jxs approved these changes Oct 4, 2024
View reviewed changes
Copy link
Member

@jxs jxs left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

LGTM thanks David!

@jxs jxs added the send-it label Oct 4, 2024
@mergify mergify bot merged commit fcff3f8 into libp2p:master Oct 4, 2024
69 checks passed
sdbondi added a commit to sdbondi/rust-libp2p that referenced this pull request Nov 1, 2024
@sdbondi
Merge branch 'master' into add-sr25519-support
ed117ca 
* master: (36 commits)
  chore: refactor ping tests (libp2p#5655)
  feat: refactor distributed-key-value-store example (libp2p#5652)
  chore(ci): address clippy beta lints (libp2p#5649)
  feat(gossipsub): apply `max_transmit_size` to the published message (libp2p#5642)
  feat(kad): add `Behavior::find_closest_local_peers()` (libp2p#5645)
  fix(swarm-test): set proper version (libp2p#5648)
  deps(ci): update cargo-semver-checks (libp2p#5647)
  chore: fix typo in comment (libp2p#5643)
  feat: make runtime features optional in swarm-test (libp2p#5551)
  deps: bump Swatinem/rust-cache from 2.7.3 to 2.7.5 (libp2p#5633)
  chore: update igd-next to 0.15.1 (libp2p#5625)
  fix(server): removing dependency on libp2p-lookup (libp2p#5610)
  refactor(examples): use tokio instead of async-std in relay-server (libp2p#5600)
  deps: update metrics example dependencies (libp2p#5617)
  chore: update interop test run condition (libp2p#5611)
  chore(autonat-v2): fix dial_back_to_non_libp2p test (libp2p#5621)
  fix(swarm): don't report `NewExternalAddrCandidate` if already confirmed (libp2p#5582)
  chore(ci): address beta clippy lints (libp2p#5606)
  fix(ci): address cargo-deny advisories (libp2p#5596)
  chore(ci): only run interop tests on commits to master (libp2p#5604)
  ...
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Reviewers

@jxs jxs jxs approved these changes

@dariusc93 dariusc93 Awaiting requested review from dariusc93

Assignees
No one assigned
Labels
send-it
Projects
None yet
Milestone
No milestone
Development

Successfully merging this pull request may close these issues.
4 participants
@P1R @jxs @dariusc93 @guillaumemichel