File sharing example not working

[snowmead]

Setup

OS: MacOS

I am running 2 nodes.

• 1 provider
• 1 retriever

Commands executed

Provider node 1:

RUST_LOG=debug cargo run -- --listen-address /ip4/*********/tcp/40837 --secret-key-seed 1 provide --path /Users/snowmead/opt/projects/rust-libp2p/README.md --name readme

    Finished dev [unoptimized + debuginfo] target(s) in 0.15s
     Running `/Users/snowmead/opt/projects/rust-libp2p/target/debug/file-sharing-example --listen-address /ip4/*********/tcp/40837 --secret-key-seed 1 provide --path /Users/snowmead/opt/projects/rust-libp2p/README.md --name readme`
2023-11-16T20:54:24.412614Z  INFO libp2p_swarm: local_peer_id=12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X
2023-11-16T20:54:24.413602Z DEBUG libp2p_tcp: listening on *********:40837
2023-11-16T20:54:24.414100Z DEBUG Swarm::poll: libp2p_swarm: New listener address listener=ListenerId(1) address=/ip4/*********/tcp/40837
Local node is listening on "/ip4/*********/tcp/40837/p2p/12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X"
2023-11-16T20:54:27.883216Z DEBUG Swarm::poll: libp2p_tcp: Incoming connection from remote at local remote_address=/ip4/*********/tcp/51417 local_address=/ip4/*********/tcp/40837
2023-11-16T20:54:27.883630Z DEBUG new_incoming_connection{remote_addr=/ip4/*********/tcp/51417 id=1}: multistream_select::listener_select: Listener: confirming protocol protocol=/noise
2023-11-16T20:54:27.883707Z DEBUG new_incoming_connection{remote_addr=/ip4/*********/tcp/51417 id=1}: multistream_select::listener_select: Listener: sent confirmed protocol protocol=/noise
2023-11-16T20:54:27.889043Z DEBUG Swarm::poll: libp2p_swarm: Incoming connection failed: Transport(Other(Custom { kind: Other, error: Other(Right(Select(Failed))) }))
2023-11-16T20:54:27.889310Z DEBUG Swarm::poll: libp2p_tcp: Incoming connection from remote at local remote_address=/ip4/*********/tcp/51418 local_address=/ip4/*********/tcp/40837
2023-11-16T20:54:27.890377Z DEBUG new_incoming_connection{remote_addr=/ip4/*********/tcp/51418 id=2}: multistream_select::listener_select: Listener: confirming protocol protocol=/noise
2023-11-16T20:54:27.890410Z DEBUG new_incoming_connection{remote_addr=/ip4/*********/tcp/51418 id=2}: multistream_select::listener_select: Listener: sent confirmed protocol protocol=/noise
2023-11-16T20:54:27.894797Z DEBUG new_incoming_connection{remote_addr=/ip4/*********/tcp/51418 id=2}: multistream_select::listener_select: Listener: confirming protocol protocol=/yamux/1.0.0
2023-11-16T20:54:27.894836Z DEBUG new_incoming_connection{remote_addr=/ip4/*********/tcp/51418 id=2}: multistream_select::listener_select: Listener: sent confirmed protocol protocol=/yamux/1.0.0
2023-11-16T20:54:27.894931Z DEBUG new_incoming_connection{remote_addr=/ip4/*********/tcp/51418 id=2}: yamux::connection: new connection: 6e84df5a (Server)
2023-11-16T20:54:27.895054Z DEBUG Swarm::poll: libp2p_kad::handler: New inbound connection peer=12D3KooWDb9Qf25wTM98LnnEgeNPv2tg63y8imn6QkzQ7EXzfGYs mode=server
2023-11-16T20:54:27.895226Z DEBUG Swarm::poll: libp2p_swarm: Connection established peer=12D3KooWDb9Qf25wTM98LnnEgeNPv2tg63y8imn6QkzQ7EXzfGYs endpoint=Listener { local_addr: "/ip4/*********/tcp/40837", send_back_addr: "/ip4/*********/tcp/51418" } total_peers=1
2023-11-16T20:54:27.895418Z DEBUG Swarm::poll: libp2p_swarm: Connection closed with error KeepAliveTimeout: Connected { endpoint: Listener { local_addr: "/ip4/*********/tcp/40837", send_back_addr: "/ip4/*********/tcp/51418" }, peer_id: PeerId("12D3KooWDb9Qf25wTM98LnnEgeNPv2tg63y8imn6QkzQ7EXzfGYs") } total_peers=0

Retriever node:

RUST_LOG=debug cargo run -- --peer /ip4/*********/tcp/40837/p2p/12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X get --name readme
    Finished dev [unoptimized + debuginfo] target(s) in 0.14s
     Running `/Users/snowmead/opt/projects/rust-libp2p/target/debug/file-sharing-example --peer /ip4/*********/tcp/40837/p2p/12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X get --name readme`
2023-11-16T20:55:44.477055Z  INFO libp2p_swarm: local_peer_id=12D3KooWG4Yr89Li3Ge1W48ffyA7ALBdxXYdpsMW3adTgn5dCzVi
2023-11-16T20:55:44.477682Z DEBUG libp2p_tcp: listening on *******:0
2023-11-16T20:55:44.478091Z DEBUG Swarm::poll: libp2p_tcp: New listen address address=/ip4/*********/tcp/51420
2023-11-16T20:55:44.478114Z DEBUG Swarm::poll: libp2p_swarm: New listener address listener=ListenerId(1) address=/ip4/*********/tcp/51420
Local node is listening on "/ip4/*********/tcp/51420/p2p/12D3KooWG4Yr89Li3Ge1W48ffyA7ALBdxXYdpsMW3adTgn5dCzVi"
2023-11-16T20:55:44.478240Z DEBUG Swarm::poll: libp2p_tcp: New listen address address=/ip4/************/tcp/51420
2023-11-16T20:55:44.478253Z DEBUG Swarm::poll: libp2p_swarm: New listener address listener=ListenerId(1) address=/ip4/************/tcp/51420
Local node is listening on "/ip4/************/tcp/51420/p2p/12D3KooWG4Yr89Li3Ge1W48ffyA7ALBdxXYdpsMW3adTgn5dCzVi"
2023-11-16T20:55:44.478423Z DEBUG libp2p_swarm: discarding addresses from `NetworkBehaviour` because `DialOpts::extend_addresses_through_behaviour is `false` for connection connection=1 discarded_addresses_count=1
2023-11-16T20:55:44.478459Z DEBUG libp2p_tcp: dialing address address=*********:40837
2023-11-16T20:55:44.479101Z DEBUG Transport::dial{address=/ip4/*********/tcp/40837/p2p/12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X/p2p/12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X}: multistream_select::dialer_select: Dialer: Proposed protocol protocol=/noise
2023-11-16T20:55:44.479127Z DEBUG Transport::dial{address=/ip4/*********/tcp/40837/p2p/12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X/p2p/12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X}: multistream_select::dialer_select: Dialer: Expecting proposed protocol protocol=/noise
2023-11-16T20:55:44.480036Z DEBUG Transport::dial{address=/ip4/*********/tcp/40837/p2p/12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X/p2p/12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X}: multistream_select::negotiated: Negotiated: Received confirmation for protocol protocol=/noise
2023-11-16T20:55:44.483880Z DEBUG Transport::dial{address=/ip4/*********/tcp/40837/p2p/12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X/p2p/12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X}: multistream_select::dialer_select: Dialer: Proposed protocol protocol=/yamux/1.0.0
2023-11-16T20:55:44.483904Z DEBUG Transport::dial{address=/ip4/*********/tcp/40837/p2p/12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X/p2p/12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X}: multistream_select::dialer_select: Dialer: Expecting proposed protocol protocol=/yamux/1.0.0
2023-11-16T20:55:44.483992Z DEBUG Transport::dial{address=/ip4/*********/tcp/40837/p2p/12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X/p2p/12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X}: yamux::connection: new connection: 93eec972 (Client)
2023-11-16T20:55:44.484146Z DEBUG Swarm::poll: libp2p_kad::handler: New outbound connection peer=12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X mode=server
2023-11-16T20:55:44.484325Z DEBUG Swarm::poll: libp2p_swarm: Connection established peer=12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X endpoint=Dialer { address: "/ip4/*********/tcp/40837/p2p/12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X/p2p/12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X", role_override: Dialer } total_peers=1
2023-11-16T20:55:44.484426Z DEBUG Swarm::poll: libp2p_swarm: Connection closed with error KeepAliveTimeout: Connected { endpoint: Dialer { address: "/ip4/*********/tcp/40837/p2p/12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X/p2p/12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X", role_override: Dialer }, peer_id: PeerId("12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X") } total_peers=0
2023-11-16T20:55:44.484879Z DEBUG Swarm::poll: libp2p_tcp: dialing address address=*********:40837
Dialing 12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X
2023-11-16T20:55:44.485215Z DEBUG Transport::dial{address=/ip4/*********/tcp/40837/p2p/12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X}: multistream_select::dialer_select: Dialer: Proposed protocol protocol=/noise
2023-11-16T20:55:44.485234Z DEBUG Transport::dial{address=/ip4/*********/tcp/40837/p2p/12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X}: multistream_select::dialer_select: Dialer: Expecting proposed protocol protocol=/noise
2023-11-16T20:55:44.486363Z DEBUG Transport::dial{address=/ip4/*********/tcp/40837/p2p/12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X}: multistream_select::negotiated: Negotiated: Received confirmation for protocol protocol=/noise
2023-11-16T20:55:44.489711Z DEBUG Transport::dial{address=/ip4/*********/tcp/40837/p2p/12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X}: multistream_select::dialer_select: Dialer: Proposed protocol protocol=/yamux/1.0.0
2023-11-16T20:55:44.489733Z DEBUG Transport::dial{address=/ip4/*********/tcp/40837/p2p/12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X}: multistream_select::dialer_select: Dialer: Expecting proposed protocol protocol=/yamux/1.0.0
2023-11-16T20:55:44.489786Z DEBUG Transport::dial{address=/ip4/*********/tcp/40837/p2p/12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X}: yamux::connection: new connection: 7861887e (Client)
2023-11-16T20:55:44.489902Z DEBUG Swarm::poll: libp2p_kad::handler: New outbound connection peer=12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X mode=server
2023-11-16T20:55:44.490036Z DEBUG Swarm::poll: libp2p_swarm: Connection established peer=12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X endpoint=Dialer { address: "/ip4/*********/tcp/40837/p2p/12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X", role_override: Dialer } total_peers=1
2023-11-16T20:55:44.490192Z DEBUG new_established_connection{remote_addr=/ip4/*********/tcp/40837/p2p/12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X id=2 peer=12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X}:Connection::poll: yamux::connection: 7861887e: new outbound (Stream 7861887e/1) of (Connection 7861887e Client (streams 0))
2023-11-16T20:55:44.490238Z DEBUG new_established_connection{remote_addr=/ip4/*********/tcp/40837/p2p/12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X id=2 peer=12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X}:Connection::poll: multistream_select::dialer_select: Dialer: Proposed protocol protocol=/ipfs/kad/1.0.0
2023-11-16T20:55:44.490350Z DEBUG new_established_connection{remote_addr=/ip4/*********/tcp/40837/p2p/12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X id=2 peer=12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X}:Connection::poll: multistream_select::negotiated: Negotiated: Received confirmation for protocol protocol=/yamux/1.0.0
2023-11-16T20:55:44.490854Z DEBUG Swarm::poll: libp2p_swarm: Connection closed with error IO(Custom { kind: Other, error: Error(Decode(Io(Os { code: 54, kind: ConnectionReset, message: "Connection reset by peer" }))) }): Connected { endpoint: Dialer { address: "/ip4/*********/tcp/40837/p2p/12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X", role_override: Dialer }, peer_id: PeerId("12D3KooWPjceQrSwdWXPyLLeABRXmuqt69Rg3sBYbU1Nft9HyQ6X") } total_peers=0

Problem

The connection closes right after establishing the connection. But the content of the file is not printed in stdout in the retriever logs.

2023-11-16T20:55:44.490682Z DEBUG Swarm::poll: libp2p_swarm: Connection closed with error KeepAliveTimeout: Connected { endpoint: Listener { local_addr: "/ip4/*********/tcp/40837", send_back_addr: "/ip4/*********/tcp/51422" }, peer_id: PeerId("12D3KooWG4Yr89Li3Ge1W48ffyA7ALBdxXYdpsMW3adTgn5dCzVi") } total_peers=0

I am running the master branch file-sharing example.

[thomaseizinger]

Ah yes, we forgot to set an idle_connection_timeout there. See

rust-libp2p/examples/chat/src/main.rs

Line 79 in caf9da4

.with_swarm_config(|c| c.with_idle_connection_timeout(Duration::from_secs(60)))

.

Mind submitting a PR and perhaps checking all the other examples as well? Thank you!

[snowmead]

Do you know why it was decided to have the idle connection timeout default 0?

[snowmead]

Opened #4887

[thomaseizinger]

Do you know why it was decided to have the idle connection timeout default 0?

Why would you want it to be anything other than 0? An idle connection takes up resources that could be used by another connection. For example, if you have connection limits set e.g. a max of 20 connections, having some of them idle would result in discarding other in- or outbound connections that could potentially do something useful.

Depending on what your application does, keeping idle connections alive for a bit may be useful. In general though, I think dropping them is the better default.

I've edited the PR description of #4887 to explain why we need it in the examples. Those often rely on user input and set up a very specific network configuration. In a real application, you should only make a connection to another peer if you actually need to talk to them (send a kademlia query, run a request-response protocol, etc). Executing these protocols will keep the connection alive automatically.

[snowmead]

Thank you for the explanation.

[thomaseizinger]

We are considering changing this default due to popular demand: #4967.