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.

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

Rust server #3

Merged
merged 34 commits into from
Mar 29, 2023
Merged

Rust server #3

merged 34 commits into from
Mar 29, 2023

Conversation

2color
Copy link
Collaborator

@2color 2color commented Mar 21, 2023

Add Rust server that does the following:

  • Listen on the WebRTC transport
  • Support MeshSub (gossipsub) and join the universal-connectivity topic

TODO

  • bind to a specific UDP port so that binding the deployment port is easier

@vercel
Copy link

vercel bot commented Mar 21, 2023

The latest updates on your projects. Learn more about Vercel for Git ↗︎

Name Status Preview Comments Updated
universal-connectivity ✅ Ready (Inspect) Visit Preview 💬 Add your feedback Mar 29, 2023 at 3:20PM (UTC)

Copy link
Member

@mxinden mxinden left a comment

Choose a reason for hiding this comment

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

Great to see this happening. Thanks for the work!

In case you are still facing the connection issues, would you mind posting the log output with RUST_LOG=debug here?

(Run RUST_LOG=debug cargo run xxx instead of just cargo run xxx.)

// Set a custom gossipsub configuration
let gossipsub_config = gossipsub::ConfigBuilder::default()
.heartbeat_interval(Duration::from_secs(10)) // This is set to aid debugging by not cluttering the log space
.validation_mode(gossipsub::ValidationMode::Strict) // This sets the kind of message validation. The default is Strict (enforce message signing)
Copy link
Member

Choose a reason for hiding this comment

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

Consider not being strict. Just in case the JS implementation does not sign messages by default. If I am not mistaken, we are in a trusted setup here, right?

Copy link
Member

Choose a reason for hiding this comment

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

Good point, changed to permissive

rust-server/src/main.rs Outdated Show resolved Hide resolved
rust-server/Cargo.toml Outdated Show resolved Hide resolved
Co-authored-by: Max Inden <mail@max-inden.de>
@2color
Copy link
Collaborator Author

2color commented Mar 21, 2023

Seeing the following logs when connecting from the browser with the following multiaddr: /ip4/127.0.0.1/udp/51316/webrtc/certhash/uEiDZ636DR4yItj6h7Qgo7D-qJRszsU4k1P-F-vapWI70lg/p2p/QmNnooDu7bfjPFoTZYxMNLWUQJyrVwtbZg5gBMjTezGAJN

RUST_LOG=debug cargo run
Local peer id: 12D3KooWGKWQQRdyjvgGpgAQMT9nLtgd5erupxiKAi5ToTjRBbwL
New event: Behaviour(BehaviourEvent: RoutingUpdated { peer: PeerId("QmNnooDu7bfjPFoTZYxMNLWUQJyrVwtbZg5gBMjTezGAJN"), is_new_peer: true, addresses: ["/dnsaddr/bootstrap.libp2p.io"], bucket_range: (Distance(57896044618658097711785492504343953926634992332820282019728792003956564819968), Distance(115792089237316195423570985008687907853269984665640564039457584007913129639935)), old_peer: None })
New event: NewListenAddr { listener_id: ListenerId(5877970740032266740), address: "/ip4/127.0.0.1/udp/51316/webrtc/certhash/uEiDZ636DR4yItj6h7Qgo7D-qJRszsU4k1P-F-vapWI70lg" }

New event: IncomingConnection { local_addr: "/ip4/127.0.0.1/udp/51316/webrtc/certhash/uEiDZ636DR4yItj6h7Qgo7D-qJRszsU4k1P-F-vapWI70lg", send_back_addr: "/ip4/192.168.178.21/udp/65152/webrtc" }
New event: ConnectionEstablished { peer_id: PeerId("12D3KooWKrjTheKVr4Fquzo9555PbiiNW452DkMCHk4bQFJjoDY3"), endpoint: Listener { local_addr: "/ip4/127.0.0.1/udp/51316/webrtc/certhash/uEiDZ636DR4yItj6h7Qgo7D-qJRszsU4k1P-F-vapWI70lg", send_back_addr: "/ip4/192.168.178.21/udp/65152/webrtc" }, num_established: 1, concurrent_dial_errors: None, established_in: 157.648833ms }
New event: ConnectionClosed { peer_id: PeerId("12D3KooWKrjTheKVr4Fquzo9555PbiiNW452DkMCHk4bQFJjoDY3"), endpoint: Listener { local_addr: "/ip4/127.0.0.1/udp/51316/webrtc/certhash/uEiDZ636DR4yItj6h7Qgo7D-qJRszsU4k1P-F-vapWI70lg", send_back_addr: "/ip4/192.168.178.21/udp/65152/webrtc" }, num_established: 0, cause: Some(Handler(Left(NegotiationTimeout))) }


New event: IncomingConnection { local_addr: "/ip4/127.0.0.1/udp/51316/webrtc/certhash/uEiDZ636DR4yItj6h7Qgo7D-qJRszsU4k1P-F-vapWI70lg", send_back_addr: "/ip4/192.168.178.21/udp/60904/webrtc" }
New event: ConnectionEstablished { peer_id: PeerId("12D3KooWKrjTheKVr4Fquzo9555PbiiNW452DkMCHk4bQFJjoDY3"), endpoint: Listener { local_addr: "/ip4/127.0.0.1/udp/51316/webrtc/certhash/uEiDZ636DR4yItj6h7Qgo7D-qJRszsU4k1P-F-vapWI70lg", send_back_addr: "/ip4/192.168.178.21/udp/60904/webrtc" }, num_established: 1, concurrent_dial_errors: None, established_in: 182.188625ms }
New event: ConnectionClosed { peer_id: PeerId("12D3KooWKrjTheKVr4Fquzo9555PbiiNW452DkMCHk4bQFJjoDY3"), endpoint: Listener { local_addr: "/ip4/127.0.0.1/udp/51316/webrtc/certhash/uEiDZ636DR4yItj6h7Qgo7D-qJRszsU4k1P-F-vapWI70lg", send_back_addr: "/ip4/192.168.178.21/udp/60904/webrtc" }, num_established: 0, cause: Some(Handler(Left(NegotiationTimeout))) }

Copy link
Member

@mxinden mxinden left a comment

Choose a reason for hiding this comment

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

Sorry @2color I missed that env_logger wasn't in place yet. Mind running this again and posting the logs?

rust-server/Cargo.toml Show resolved Hide resolved
rust-server/src/main.rs Outdated Show resolved Hide resolved
Co-authored-by: Max Inden <mail@max-inden.de>
@2color
Copy link
Collaborator Author

2color commented Mar 22, 2023

Here are the logs when trying to connect the UI to the daemon:

New event: IncomingConnection { local_addr: "/ip4/127.0.0.1/udp/49815/webrtc/certhash/uEiCUs4FwNqjV35Txx4_bg2_o9HZC98v0_A2Rzsw-ispppA", send_back_addr: "/ip4/192.168.178.21/udp/62669/webrtc" }
[2023-03-22T14:00:02Z DEBUG libp2p_webrtc::tokio::upgrade] new inbound connection from 192.168.178.21:62669 (ufrag: libp2p+webrtc+v1/0RZBlEm2GPPfvhMAffZFMF3SlfpcZ+vM)
[2023-03-22T14:00:02Z DEBUG libp2p_webrtc::tokio::upgrade] calculated SDP offer for inbound connection: RTCSessionDescription { sdp_type: Offer, sdp: "v=0\no=- 0 0 IN IP4 192.168.178.21\ns=-\nc=IN IP4 192.168.178.21\nt=0 0\n\nm=application 62669 UDP/DTLS/SCTP webrtc-datachannel\na=mid:0\na=ice-options:ice2\na=ice-ufrag:libp2p+webrtc+v1/0RZBlEm2GPPfvhMAffZFMF3SlfpcZ+vM\na=ice-pwd:libp2p+webrtc+v1/0RZBlEm2GPPfvhMAffZFMF3SlfpcZ+vM\na=fingerprint:sha-256 FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF\na=setup:actpass\na=sctp-port:5000\na=max-message-size:16384\n", parsed: Some(SessionDescription { version: 0, origin: Origin { username: "-", session_id: 0, session_version: 0, network_type: "IN", address_type: "IP4", unicast_address: "192.168.178.21" }, session_name: "-", session_information: None, uri: None, email_address: None, phone_number: None, connection_information: Some(ConnectionInformation { network_type: "IN", address_type: "IP4", address: Some(Address { address: "192.168.178.21", ttl: None, range: None }) }), bandwidth: [], time_descriptions: [TimeDescription { timing: Timing { start_time: 0, stop_time: 0 }, repeat_times: [] }], time_zones: [], encryption_key: None, attributes: [], media_descriptions: [MediaDescription { media_name: MediaName { media: "application", port: RangedPort { value: 62669, range: None }, protos: ["UDP", "DTLS", "SCTP"], formats: ["webrtc-datachannel"] }, media_title: None, connection_information: None, bandwidth: [], encryption_key: None, attributes: [Attribute { key: "mid", value: Some("0") }, Attribute { key: "ice-options", value: Some("ice2") }, Attribute { key: "ice-ufrag", value: Some("libp2p+webrtc+v1/0RZBlEm2GPPfvhMAffZFMF3SlfpcZ+vM") }, Attribute { key: "ice-pwd", value: Some("libp2p+webrtc+v1/0RZBlEm2GPPfvhMAffZFMF3SlfpcZ+vM") }, Attribute { key: "fingerprint", value: Some("sha-256 FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF") }, Attribute { key: "setup", value: Some("actpass") }, Attribute { key: "sctp-port", value: Some("5000") }, Attribute { key: "max-message-size", value: Some("16384") }] }] }) }
[2023-03-22T14:00:02Z INFO  webrtc::peer_connection] signaling state changed to have-remote-offer
[2023-03-22T14:00:02Z INFO  webrtc_ice::mdns] mDNS is using 0.0.0.0:5353 as dest_addr
[2023-03-22T14:00:02Z INFO  webrtc_mdns::conn] Looping and listening Ok(0.0.0.0:5353)
[2023-03-22T14:00:02Z DEBUG webrtc_ice::agent::agent_internal] Started agent: isControlling? false, remoteUfrag: libp2p+webrtc+v1/0RZBlEm2GPPfvhMAffZFMF3SlfpcZ+vM, remotePwd: libp2p+webrtc+v1/0RZBlEm2GPPfvhMAffZFMF3SlfpcZ+vM
[2023-03-22T14:00:02Z INFO  webrtc_ice::agent::agent_internal] [controlled]: Setting new connection state: Checking
[2023-03-22T14:00:02Z INFO  webrtc::peer_connection] ICE connection state changed: checking
[2023-03-22T14:00:02Z DEBUG libp2p_webrtc::tokio::upgrade] created SDP answer for inbound connection: RTCSessionDescription { sdp_type: Answer, sdp: "v=0\r\no=- 8296556778790641950 505466000 IN IP4 0.0.0.0\r\ns=-\r\nt=0 0\r\na=fingerprint:sha-256 94:B3:81:70:36:A8:D5:DF:94:F1:C7:8F:DB:83:6F:E8:F4:76:42:F7:CB:F4:FC:0D:91:CE:CC:3E:8A:CA:69:A4\r\na=ice-lite:ice-lite\r\na=group:BUNDLE 0\r\nm=application 9 UDP/DTLS/SCTP webrtc-datachannel\r\nc=IN IP4 0.0.0.0\r\na=setup:passive\r\na=mid:0\r\na=sendrecv\r\na=sctp-port:5000\r\na=ice-ufrag:libp2p+webrtc+v1/0RZBlEm2GPPfvhMAffZFMF3SlfpcZ+vM\r\na=ice-pwd:libp2p+webrtc+v1/0RZBlEm2GPPfvhMAffZFMF3SlfpcZ+vM\r\n", parsed: Some(SessionDescription { version: 0, origin: Origin { username: "-", session_id: 8296556778790641950, session_version: 505466000, network_type: "IN", address_type: "IP4", unicast_address: "0.0.0.0" }, session_name: "-", session_information: None, uri: None, email_address: None, phone_number: None, connection_information: None, bandwidth: [], time_descriptions: [TimeDescription { timing: Timing { start_time: 0, stop_time: 0 }, repeat_times: [] }], time_zones: [], encryption_key: None, attributes: [Attribute { key: "fingerprint", value: Some("sha-256 94:B3:81:70:36:A8:D5:DF:94:F1:C7:8F:DB:83:6F:E8:F4:76:42:F7:CB:F4:FC:0D:91:CE:CC:3E:8A:CA:69:A4") }, Attribute { key: "ice-lite", value: Some("ice-lite") }, Attribute { key: "group", value: Some("BUNDLE 0") }], media_descriptions: [MediaDescription { media_name: MediaName { media: "application", port: RangedPort { value: 9, range: None }, protos: ["UDP", "DTLS", "SCTP"], formats: ["webrtc-datachannel"] }, media_title: None, connection_information: Some(ConnectionInformation { network_type: "IN", address_type: "IP4", address: Some(Address { address: "0.0.0.0", ttl: None, range: None }) }), bandwidth: [], encryption_key: None, attributes: [Attribute { key: "setup", value: Some("passive") }, Attribute { key: "mid", value: Some("0") }, Attribute { key: "sendrecv", value: None }, Attribute { key: "sctp-port:5000", value: None }, Attribute { key: "ice-ufrag", value: Some("libp2p+webrtc+v1/0RZBlEm2GPPfvhMAffZFMF3SlfpcZ+vM") }, Attribute { key: "ice-pwd", value: Some("libp2p+webrtc+v1/0RZBlEm2GPPfvhMAffZFMF3SlfpcZ+vM") }] }] }) }
[2023-03-22T14:00:02Z INFO  webrtc::peer_connection] signaling state changed to stable
[2023-03-22T14:00:02Z DEBUG webrtc_ice::agent::agent_internal] [controlled]: adding a new peer-reflexive candidate: 192.168.178.21:62669
[2023-03-22T14:00:02Z DEBUG libp2p_webrtc::tokio::udp_mux] Registered 192.168.178.21:62669 for libp2p+webrtc+v1/0RZBlEm2GPPfvhMAffZFMF3SlfpcZ+vM
[2023-03-22T14:00:02Z INFO  webrtc_ice::agent::agent_internal] [controlled]: Setting new connection state: Connected
[2023-03-22T14:00:02Z INFO  webrtc::peer_connection] ICE connection state changed: connected
[2023-03-22T14:00:02Z WARN  webrtc_dtls::handshake::handshake_message_client_hello] Unsupported Extension Type 0 35
[2023-03-22T14:00:02Z WARN  webrtc_dtls::handshake::handshake_message_client_hello] Unsupported Extension Type 0 35
[2023-03-22T14:00:02Z DEBUG webrtc_dtls::flight::flight0] [handshake:server] use cipher suite: TLS_ECDHE_ECDSA_WITH_AES_128_GCM_SHA256
[2023-03-22T14:00:02Z WARN  webrtc_dtls::handshake::handshake_message_client_hello] Unsupported Extension Type 0 35
[2023-03-22T14:00:02Z WARN  webrtc_dtls::handshake::handshake_message_client_hello] Unsupported Extension Type 0 35
[2023-03-22T14:00:02Z DEBUG webrtc_dtls::flight::flight0] [handshake:server] use cipher suite: TLS_ECDHE_ECDSA_WITH_AES_128_GCM_SHA256
[2023-03-22T14:00:02Z WARN  webrtc_dtls::handshake::handshake_message_client_hello] Unsupported Extension Type 0 35
[2023-03-22T14:00:02Z WARN  webrtc_dtls::handshake::handshake_message_client_hello] Unsupported Extension Type 0 35
[2023-03-22T14:00:02Z DEBUG webrtc_dtls::conn] server: CipherSuite not initialized, queuing packet
[2023-03-22T14:00:02Z DEBUG webrtc_dtls::conn] server: received packet of next epoch, queuing packet
[2023-03-22T14:00:02Z INFO  webrtc::peer_connection] peer connection state changed: connected
[2023-03-22T14:00:02Z DEBUG webrtc_sctp::association::association_internal] [] state change: 'Closed' => 'CookieWait'
[2023-03-22T14:00:02Z DEBUG webrtc_sctp::association::association_internal] [] sending INIT
[2023-03-22T14:00:02Z DEBUG webrtc_sctp::association] [] read_loop entered
[2023-03-22T14:00:02Z DEBUG webrtc_sctp::association] [] write_loop entered
[2023-03-22T14:00:02Z DEBUG webrtc_sctp::association] [] recving 44 bytes
[2023-03-22T14:00:02Z DEBUG webrtc_sctp::association] [] sending 40 bytes
[2023-03-22T14:00:02Z DEBUG webrtc_sctp::association::association_internal] [] chunkInit received in state 'CookieWait'
[2023-03-22T14:00:02Z DEBUG webrtc_sctp::association::association_internal] [] use ForwardTSN (on init)
[2023-03-22T14:00:02Z DEBUG webrtc_sctp::association] [] sending 76 bytes
[2023-03-22T14:00:02Z DEBUG webrtc_sctp::association] [] recving 84 bytes
[2023-03-22T14:00:02Z DEBUG webrtc_sctp::association::association_internal] [] chunkInitAck received in state 'CookieWait'
[2023-03-22T14:00:02Z DEBUG webrtc_sctp::association::association_internal] [] initial rwnd=5242880
[2023-03-22T14:00:02Z DEBUG webrtc_sctp::association::association_internal] [] use ForwardTSN (on initAck)
[2023-03-22T14:00:02Z DEBUG webrtc_sctp::association::association_internal] [] sending COOKIE-ECHO
[2023-03-22T14:00:02Z DEBUG webrtc_sctp::association::association_internal] [] state change: 'CookieWait' => 'CookieEchoed'
[2023-03-22T14:00:02Z DEBUG webrtc_sctp::association] [] recving 48 bytes
[2023-03-22T14:00:02Z DEBUG webrtc_sctp::association] [] sending 52 bytes
[2023-03-22T14:00:02Z DEBUG webrtc_sctp::association::association_internal] [] COOKIE-ECHO received in state 'CookieEchoed'
[2023-03-22T14:00:02Z DEBUG webrtc_sctp::association::association_internal] [] state change: 'CookieEchoed' => 'Established'
[2023-03-22T14:00:02Z DEBUG libp2p_webrtc::tokio::connection] Data channel 0 open
[2023-03-22T14:00:02Z DEBUG webrtc_sctp::association] [] sending 16 bytes
[2023-03-22T14:00:02Z DEBUG webrtc_sctp::association] [] recving 16 bytes
[2023-03-22T14:00:02Z DEBUG webrtc_sctp::association::association_internal] [] COOKIE-ACK received in state 'Established'
[2023-03-22T14:00:02Z DEBUG webrtc_sctp::association] [] sending 68 bytes
[2023-03-22T14:00:02Z DEBUG webrtc_sctp::association] [] recving 28 bytes
[2023-03-22T14:00:02Z DEBUG webrtc_sctp::association] [] recving 240 bytes
[2023-03-22T14:00:02Z DEBUG webrtc_sctp::stream] [0:] reassemblyQueue readable=true
[2023-03-22T14:00:02Z DEBUG webrtc_sctp::stream] [0:] readNotifier.signal()
[2023-03-22T14:00:02Z DEBUG webrtc_sctp::stream] [0:] readNotifier.signal() done
[2023-03-22T14:00:02Z DEBUG webrtc_sctp::association::association_internal] [] peer_last_tsn = 3877064515
[2023-03-22T14:00:02Z DEBUG webrtc_sctp::association::association_internal] [] peer_last_tsn = 3877064516
[2023-03-22T14:00:02Z DEBUG webrtc_sctp::association] [] sending 228 bytes
[2023-03-22T14:00:02Z DEBUG libp2p_swarm] Connection established: PeerId("12D3KooWDx73zPfANXZLB9AyXoDXfFnoZPrwZSeiy4yrE1E3EMwv") Listener { local_addr: "/ip4/127.0.0.1/udp/49815/webrtc/certhash/uEiCUs4FwNqjV35Txx4_bg2_o9HZC98v0_A2Rzsw-ispppA", send_back_addr: "/ip4/192.168.178.21/udp/62669/webrtc" }; Total (peer): 1.
[2023-03-22T14:00:02Z DEBUG libp2p_gossipsub::behaviour] New peer connected: 12D3KooWDx73zPfANXZLB9AyXoDXfFnoZPrwZSeiy4yrE1E3EMwv
New event: ConnectionEstablished { peer_id: PeerId("12D3KooWDx73zPfANXZLB9AyXoDXfFnoZPrwZSeiy4yrE1E3EMwv"), endpoint: Listener { local_addr: "/ip4/127.0.0.1/udp/49815/webrtc/certhash/uEiCUs4FwNqjV35Txx4_bg2_o9HZC98v0_A2Rzsw-ispppA", send_back_addr: "/ip4/192.168.178.21/udp/62669/webrtc" }, num_established: 1, concurrent_dial_errors: None, established_in: 163.257834ms }
[2023-03-22T14:00:02Z DEBUG libp2p_webrtc::tokio::connection] Data channel 1 open
[2023-03-22T14:00:02Z DEBUG multistream_select::dialer_select] Dialer: Proposed protocol: /ipfs/ping/1.0.0
[2023-03-22T14:00:02Z DEBUG webrtc_sctp::association] [] sending 40 bytes
[2023-03-22T14:00:02Z DEBUG webrtc_sctp::association] [] sending 72 bytes
[2023-03-22T14:00:02Z DEBUG webrtc_sctp::association] [] recving 28 bytes
[2023-03-22T14:00:02Z DEBUG webrtc_sctp::association] [] recving 32 bytes
[2023-03-22T14:00:02Z DEBUG webrtc_sctp::stream] [1:] reassemblyQueue readable=true
[2023-03-22T14:00:02Z DEBUG webrtc_sctp::stream] [1:] readNotifier.signal()
[2023-03-22T14:00:02Z DEBUG webrtc_sctp::stream] [1:] readNotifier.signal() done
[2023-03-22T14:00:02Z DEBUG webrtc_sctp::association::association_internal] [] peer_last_tsn = 3877064516
[2023-03-22T14:00:02Z DEBUG webrtc_sctp::association::association_internal] [] peer_last_tsn = 3877064517
[2023-03-22T14:00:02Z DEBUG webrtc_sctp::association::association_internal] [] sending SACK: SACK cumTsnAck=3877064517 arwnd=1048575 dupTsn=[]
[2023-03-22T14:00:02Z DEBUG webrtc_data::data_channel] Received DATA_CHANNEL_ACK
[2023-03-22T14:00:02Z DEBUG webrtc_sctp::stream] [1:] reliability params: ordered=true type=Reliable value=0
[2023-03-22T14:00:02Z DEBUG webrtc_sctp::association] [] sending 28 bytes
[2023-03-22T14:00:02Z DEBUG webrtc_sctp::association] [] recving 28 bytes
[2023-03-22T14:00:03Z WARN  webrtc_mdns::conn] Failed to parse mDNS packet parsing/packing of this type isn't available yet
[2023-03-22T14:00:04Z DEBUG libp2p_gossipsub::behaviour] Starting heartbeat
[2023-03-22T14:00:04Z DEBUG libp2p_gossipsub::behaviour] Completed Heartbeat
[2023-03-22T14:00:14Z DEBUG libp2p_gossipsub::behaviour] Starting heartbeat
[2023-03-22T14:00:14Z DEBUG libp2p_gossipsub::behaviour] Completed Heartbeat
[2023-03-22T14:00:22Z DEBUG libp2p_ping::handler] Ping failure: Timeout
[2023-03-22T14:00:22Z INFO  libp2p_webrtc::tokio::substream::drop_listener] Substream 1 dropped without graceful close, sending Reset
[2023-03-22T14:00:22Z DEBUG libp2p_webrtc::tokio::connection] Data channel 3 open
[2023-03-22T14:00:22Z DEBUG webrtc_sctp::association] [] sending 60 bytes
[2023-03-22T14:00:22Z DEBUG multistream_select::dialer_select] Dialer: Proposed protocol: /ipfs/ping/1.0.0
[2023-03-22T14:00:22Z DEBUG webrtc_sctp::association] [] sending 72 bytes
[2023-03-22T14:00:22Z DEBUG webrtc_sctp::association] [] recving 48 bytes
[2023-03-22T14:00:22Z DEBUG webrtc_sctp::stream] [3:] reassemblyQueue readable=true
[2023-03-22T14:00:22Z DEBUG webrtc_sctp::stream] [3:] readNotifier.signal()
[2023-03-22T14:00:22Z DEBUG webrtc_sctp::stream] [3:] readNotifier.signal() done
[2023-03-22T14:00:22Z DEBUG webrtc_sctp::association::association_internal] [] peer_last_tsn = 3877064517
[2023-03-22T14:00:22Z DEBUG webrtc_sctp::association::association_internal] [] peer_last_tsn = 3877064518
[2023-03-22T14:00:22Z DEBUG webrtc_data::data_channel] Received DATA_CHANNEL_ACK
[2023-03-22T14:00:22Z DEBUG webrtc_sctp::stream] [3:] reliability params: ordered=true type=Reliable value=0
[2023-03-22T14:00:22Z DEBUG webrtc_sctp::association::association_internal] [] sending SACK: SACK cumTsnAck=3877064518 arwnd=1048576 dupTsn=[]
[2023-03-22T14:00:22Z DEBUG webrtc_sctp::association] [] sending 28 bytes
[2023-03-22T14:00:22Z DEBUG webrtc_sctp::association] [] recving 28 bytes
[2023-03-22T14:00:24Z DEBUG libp2p_gossipsub::behaviour] Starting heartbeat
[2023-03-22T14:00:24Z DEBUG libp2p_gossipsub::behaviour] Completed Heartbeat
[2023-03-22T14:00:34Z DEBUG libp2p_gossipsub::behaviour] Starting heartbeat
[2023-03-22T14:00:34Z DEBUG libp2p_gossipsub::behaviour] Completed Heartbeat
[2023-03-22T14:00:42Z DEBUG libp2p_ping::handler] Ping failure: Timeout
[2023-03-22T14:00:42Z DEBUG libp2p_ping::handler] Too many failures (2). Closing connection.
[2023-03-22T14:00:42Z DEBUG libp2p_swarm] Connection closed with error Handler(Right(Timeout)): Connected { endpoint: Listener { local_addr: "/ip4/127.0.0.1/udp/49815/webrtc/certhash/uEiCUs4FwNqjV35Txx4_bg2_o9HZC98v0_A2Rzsw-ispppA", send_back_addr: "/ip4/192.168.178.21/udp/62669/webrtc" }, peer_id: PeerId("12D3KooWDx73zPfANXZLB9AyXoDXfFnoZPrwZSeiy4yrE1E3EMwv") }; Total (peer): 0.
[2023-03-22T14:00:42Z DEBUG libp2p_gossipsub::behaviour] Peer disconnected: 12D3KooWDx73zPfANXZLB9AyXoDXfFnoZPrwZSeiy4yrE1E3EMwv
New event: ConnectionClosed { peer_id: PeerId("12D3KooWDx73zPfANXZLB9AyXoDXfFnoZPrwZSeiy4yrE1E3EMwv"), endpoint: Listener { local_addr: "/ip4/127.0.0.1/udp/49815/webrtc/certhash/uEiCUs4FwNqjV35Txx4_bg2_o9HZC98v0_A2Rzsw-ispppA", send_back_addr: "/ip4/192.168.178.21/udp/62669/webrtc" }, num_established: 0, cause: Some(Handler(Right(Timeout))) }

@mxinden
Copy link
Member

mxinden commented Mar 22, 2023

The Rust server tries to send a ping to the remote:

[2023-03-22T14:00:02Z DEBUG multistream_select::dialer_select] Dialer: Proposed protocol: /ipfs/ping/1.0.0

But the remote seems to never reply:

[2023-03-22T14:00:22Z DEBUG libp2p_ping::handler] Ping failure: Timeout

Over time, libp2p-ping closes the connection:

[2023-03-22T14:00:42Z DEBUG libp2p_ping::handler] Too many failures (2). Closing connection.

What does the remote peer log? Does it actively ignore the incoming ping streams?

For testing purposes you can set max_failures to NonZeroU32::MAX:

https://github.com/libp2p/rust-libp2p/blob/0e468655a4ebe2554a11403062311160aeec59bb/protocols/ping/src/handler.rs#L52-L55

@p-shahi
Copy link
Member

p-shahi commented Mar 22, 2023

@mxinden I see the ping running ok

Local peer id: 12D3KooWFKQ9now1KsCSWNkWveAJNRmw4UtKkLbVSEFh1MPBGa1d
New event: Behaviour(BehaviourEvent: RoutingUpdated { peer: PeerId("QmNnooDu7bfjPFoTZYxMNLWUQJyrVwtbZg5gBMjTezGAJN"), is_new_peer: true, addresses: ["/dnsaddr/bootstrap.libp2p.io"], bucket_range: (Distance(28948022309329048855892746252171976963317496166410141009864396001978282409984), Distance(57896044618658097711785492504343953926634992332820282019728792003956564819967)), old_peer: None })
[2023-03-22T14:17:40Z DEBUG libp2p_swarm] Listener ListenerId(6643527489441789571); New address: "/ip4/127.0.0.1/udp/53783/webrtc/certhash/uEiA6jE4GG4WYbtsu75dKEcRYXpXzEhD6Kq-hOBy0Vm8EpQ"
New event: NewListenAddr { listener_id: ListenerId(6643527489441789571), address: "/ip4/127.0.0.1/udp/53783/webrtc/certhash/uEiA6jE4GG4WYbtsu75dKEcRYXpXzEhD6Kq-hOBy0Vm8EpQ" }
[2023-03-22T14:17:45Z DEBUG libp2p_gossipsub::behaviour] Starting heartbeat
[2023-03-22T14:17:45Z DEBUG libp2p_gossipsub::behaviour] Completed Heartbeat



[2023-03-22T14:17:55Z DEBUG libp2p_gossipsub::behaviour] Starting heartbeat
[2023-03-22T14:17:55Z DEBUG libp2p_gossipsub::behaviour] Completed Heartbeat




[2023-03-22T14:18:05Z DEBUG libp2p_gossipsub::behaviour] Starting heartbeat
[2023-03-22T14:18:05Z DEBUG libp2p_gossipsub::behaviour] Completed Heartbeat
New event: IncomingConnection { local_addr: "/ip4/127.0.0.1/udp/53783/webrtc/certhash/uEiA6jE4GG4WYbtsu75dKEcRYXpXzEhD6Kq-hOBy0Vm8EpQ", send_back_addr: "/ip4/127.0.0.1/udp/58692/webrtc" }
[2023-03-22T14:18:13Z DEBUG libp2p_webrtc::tokio::upgrade] new inbound connection from 127.0.0.1:58692 (ufrag: libp2p+webrtc+v1/ujtgHar3CtmvkAq6DJ+HWKYkqnIY//ge)
[2023-03-22T14:18:13Z DEBUG libp2p_webrtc::tokio::upgrade] calculated SDP offer for inbound connection: RTCSessionDescription { sdp_type: Offer, sdp: "v=0\no=- 0 0 IN IP4 127.0.0.1\ns=-\nc=IN IP4 127.0.0.1\nt=0 0\n\nm=application 58692 UDP/DTLS/SCTP webrtc-datachannel\na=mid:0\na=ice-options:ice2\na=ice-ufrag:libp2p+webrtc+v1/ujtgHar3CtmvkAq6DJ+HWKYkqnIY//ge\na=ice-pwd:libp2p+webrtc+v1/ujtgHar3CtmvkAq6DJ+HWKYkqnIY//ge\na=fingerprint:sha-256 FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF\na=setup:actpass\na=sctp-port:5000\na=max-message-size:16384\n", parsed: Some(SessionDescription { version: 0, origin: Origin { username: "-", session_id: 0, session_version: 0, network_type: "IN", address_type: "IP4", unicast_address: "127.0.0.1" }, session_name: "-", session_information: None, uri: None, email_address: None, phone_number: None, connection_information: Some(ConnectionInformation { network_type: "IN", address_type: "IP4", address: Some(Address { address: "127.0.0.1", ttl: None, range: None }) }), bandwidth: [], time_descriptions: [TimeDescription { timing: Timing { start_time: 0, stop_time: 0 }, repeat_times: [] }], time_zones: [], encryption_key: None, attributes: [], media_descriptions: [MediaDescription { media_name: MediaName { media: "application", port: RangedPort { value: 58692, range: None }, protos: ["UDP", "DTLS", "SCTP"], formats: ["webrtc-datachannel"] }, media_title: None, connection_information: None, bandwidth: [], encryption_key: None, attributes: [Attribute { key: "mid", value: Some("0") }, Attribute { key: "ice-options", value: Some("ice2") }, Attribute { key: "ice-ufrag", value: Some("libp2p+webrtc+v1/ujtgHar3CtmvkAq6DJ+HWKYkqnIY//ge") }, Attribute { key: "ice-pwd", value: Some("libp2p+webrtc+v1/ujtgHar3CtmvkAq6DJ+HWKYkqnIY//ge") }, Attribute { key: "fingerprint", value: Some("sha-256 FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF:FF") }, Attribute { key: "setup", value: Some("actpass") }, Attribute { key: "sctp-port", value: Some("5000") }, Attribute { key: "max-message-size", value: Some("16384") }] }] }) }
[2023-03-22T14:18:13Z INFO  webrtc::peer_connection] signaling state changed to have-remote-offer
[2023-03-22T14:18:13Z INFO  webrtc_ice::mdns] mDNS is using 0.0.0.0:5353 as dest_addr
[2023-03-22T14:18:13Z INFO  webrtc_mdns::conn] Looping and listening Ok(0.0.0.0:5353)
[2023-03-22T14:18:13Z DEBUG webrtc_ice::agent::agent_internal] Started agent: isControlling? false, remoteUfrag: libp2p+webrtc+v1/ujtgHar3CtmvkAq6DJ+HWKYkqnIY//ge, remotePwd: libp2p+webrtc+v1/ujtgHar3CtmvkAq6DJ+HWKYkqnIY//ge
[2023-03-22T14:18:13Z INFO  webrtc_ice::agent::agent_internal] [controlled]: Setting new connection state: Checking
[2023-03-22T14:18:13Z INFO  webrtc::peer_connection] ICE connection state changed: checking
[2023-03-22T14:18:13Z DEBUG libp2p_webrtc::tokio::upgrade] created SDP answer for inbound connection: RTCSessionDescription { sdp_type: Answer, sdp: "v=0\r\no=- 156725031936052232 920017000 IN IP4 0.0.0.0\r\ns=-\r\nt=0 0\r\na=fingerprint:sha-256 3A:8C:4E:06:1B:85:98:6E:DB:2E:EF:97:4A:11:C4:58:5E:95:F3:12:10:FA:2A:AF:A1:38:1C:B4:56:6F:04:A5\r\na=ice-lite:ice-lite\r\na=group:BUNDLE 0\r\nm=application 9 UDP/DTLS/SCTP webrtc-datachannel\r\nc=IN IP4 0.0.0.0\r\na=setup:passive\r\na=mid:0\r\na=sendrecv\r\na=sctp-port:5000\r\na=ice-ufrag:libp2p+webrtc+v1/ujtgHar3CtmvkAq6DJ+HWKYkqnIY//ge\r\na=ice-pwd:libp2p+webrtc+v1/ujtgHar3CtmvkAq6DJ+HWKYkqnIY//ge\r\n", parsed: Some(SessionDescription { version: 0, origin: Origin { username: "-", session_id: 156725031936052232, session_version: 920017000, network_type: "IN", address_type: "IP4", unicast_address: "0.0.0.0" }, session_name: "-", session_information: None, uri: None, email_address: None, phone_number: None, connection_information: None, bandwidth: [], time_descriptions: [TimeDescription { timing: Timing { start_time: 0, stop_time: 0 }, repeat_times: [] }], time_zones: [], encryption_key: None, attributes: [Attribute { key: "fingerprint", value: Some("sha-256 3A:8C:4E:06:1B:85:98:6E:DB:2E:EF:97:4A:11:C4:58:5E:95:F3:12:10:FA:2A:AF:A1:38:1C:B4:56:6F:04:A5") }, Attribute { key: "ice-lite", value: Some("ice-lite") }, Attribute { key: "group", value: Some("BUNDLE 0") }], media_descriptions: [MediaDescription { media_name: MediaName { media: "application", port: RangedPort { value: 9, range: None }, protos: ["UDP", "DTLS", "SCTP"], formats: ["webrtc-datachannel"] }, media_title: None, connection_information: Some(ConnectionInformation { network_type: "IN", address_type: "IP4", address: Some(Address { address: "0.0.0.0", ttl: None, range: None }) }), bandwidth: [], encryption_key: None, attributes: [Attribute { key: "setup", value: Some("passive") }, Attribute { key: "mid", value: Some("0") }, Attribute { key: "sendrecv", value: None }, Attribute { key: "sctp-port:5000", value: None }, Attribute { key: "ice-ufrag", value: Some("libp2p+webrtc+v1/ujtgHar3CtmvkAq6DJ+HWKYkqnIY//ge") }, Attribute { key: "ice-pwd", value: Some("libp2p+webrtc+v1/ujtgHar3CtmvkAq6DJ+HWKYkqnIY//ge") }] }] }) }
[2023-03-22T14:18:13Z INFO  webrtc::peer_connection] signaling state changed to stable
[2023-03-22T14:18:13Z DEBUG webrtc_ice::agent::agent_internal] [controlled]: adding a new peer-reflexive candidate: 127.0.0.1:58692
[2023-03-22T14:18:13Z DEBUG libp2p_webrtc::tokio::udp_mux] Registered 127.0.0.1:58692 for libp2p+webrtc+v1/ujtgHar3CtmvkAq6DJ+HWKYkqnIY//ge
[2023-03-22T14:18:14Z INFO  webrtc_ice::agent::agent_internal] [controlled]: Setting new connection state: Connected
[2023-03-22T14:18:14Z INFO  webrtc::peer_connection] ICE connection state changed: connected
[2023-03-22T14:18:14Z WARN  webrtc_dtls::handshake::handshake_message_client_hello] Unsupported Extension Type 0 35
[2023-03-22T14:18:14Z WARN  webrtc_dtls::handshake::handshake_message_client_hello] Unsupported Extension Type 0 35
[2023-03-22T14:18:14Z DEBUG webrtc_dtls::flight::flight0] [handshake:server] use cipher suite: TLS_ECDHE_ECDSA_WITH_AES_128_GCM_SHA256
[2023-03-22T14:18:14Z WARN  webrtc_dtls::handshake::handshake_message_client_hello] Unsupported Extension Type 0 35
[2023-03-22T14:18:14Z WARN  webrtc_dtls::handshake::handshake_message_client_hello] Unsupported Extension Type 0 35
[2023-03-22T14:18:14Z DEBUG webrtc_dtls::flight::flight0] [handshake:server] use cipher suite: TLS_ECDHE_ECDSA_WITH_AES_128_GCM_SHA256
[2023-03-22T14:18:14Z WARN  webrtc_dtls::handshake::handshake_message_client_hello] Unsupported Extension Type 0 35
[2023-03-22T14:18:14Z WARN  webrtc_dtls::handshake::handshake_message_client_hello] Unsupported Extension Type 0 35
[2023-03-22T14:18:14Z DEBUG webrtc_dtls::conn] server: CipherSuite not initialized, queuing packet
[2023-03-22T14:18:14Z DEBUG webrtc_dtls::conn] server: received packet of next epoch, queuing packet
[2023-03-22T14:18:14Z INFO  webrtc::peer_connection] peer connection state changed: connected
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association::association_internal] [] state change: 'Closed' => 'CookieWait'
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association] [] read_loop entered
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association::association_internal] [] sending INIT
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association] [] write_loop entered
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association] [] sending 40 bytes
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association] [] recving 44 bytes
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association::association_internal] [] chunkInit received in state 'CookieWait'
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association::association_internal] [] use ForwardTSN (on init)
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association] [] recving 84 bytes
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association] [] sending 76 bytes
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association::association_internal] [] chunkInitAck received in state 'CookieWait'
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association::association_internal] [] initial rwnd=5242880
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association::association_internal] [] use ForwardTSN (on initAck)
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association::association_internal] [] sending COOKIE-ECHO
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association::association_internal] [] state change: 'CookieWait' => 'CookieEchoed'
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association] [] recving 48 bytes
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association::association_internal] [] COOKIE-ECHO received in state 'CookieEchoed'
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association::association_internal] [] state change: 'CookieEchoed' => 'Established'
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association] [] sending 52 bytes
[2023-03-22T14:18:14Z DEBUG libp2p_webrtc::tokio::connection] Data channel 0 open
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association] [] sending 16 bytes
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association] [] sending 68 bytes
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association] [] recving 16 bytes
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association::association_internal] [] COOKIE-ACK received in state 'Established'
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association] [] recving 28 bytes
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association] [] recving 240 bytes
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::stream] [0:] reassemblyQueue readable=true
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::stream] [0:] readNotifier.signal()
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::stream] [0:] readNotifier.signal() done
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association::association_internal] [] peer_last_tsn = 3749657544
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association::association_internal] [] peer_last_tsn = 3749657545
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association] [] sending 228 bytes
[2023-03-22T14:18:14Z DEBUG libp2p_swarm] Connection established: PeerId("12D3KooWMs8X6PFr6wcHTFho37vN91k3phCaCDsoKXRqf8hcjYqU") Listener { local_addr: "/ip4/127.0.0.1/udp/53783/webrtc/certhash/uEiA6jE4GG4WYbtsu75dKEcRYXpXzEhD6Kq-hOBy0Vm8EpQ", send_back_addr: "/ip4/127.0.0.1/udp/58692/webrtc" }; Total (peer): 1.
[2023-03-22T14:18:14Z DEBUG libp2p_gossipsub::behaviour] New peer connected: 12D3KooWMs8X6PFr6wcHTFho37vN91k3phCaCDsoKXRqf8hcjYqU
New event: ConnectionEstablished { peer_id: PeerId("12D3KooWMs8X6PFr6wcHTFho37vN91k3phCaCDsoKXRqf8hcjYqU"), endpoint: Listener { local_addr: "/ip4/127.0.0.1/udp/53783/webrtc/certhash/uEiA6jE4GG4WYbtsu75dKEcRYXpXzEhD6Kq-hOBy0Vm8EpQ", send_back_addr: "/ip4/127.0.0.1/udp/58692/webrtc" }, num_established: 1, concurrent_dial_errors: None, established_in: 215.274333ms }
[2023-03-22T14:18:14Z DEBUG libp2p_webrtc::tokio::connection] Data channel 1 open
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association] [] sending 40 bytes
[2023-03-22T14:18:14Z DEBUG multistream_select::dialer_select] Dialer: Proposed protocol: /ipfs/ping/1.0.0
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association] [] sending 72 bytes
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association] [] recving 28 bytes
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association] [] recving 32 bytes
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::stream] [1:] reassemblyQueue readable=true
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::stream] [1:] readNotifier.signal()
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::stream] [1:] readNotifier.signal() done
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association::association_internal] [] peer_last_tsn = 3749657545
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association::association_internal] [] peer_last_tsn = 3749657546
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association::association_internal] [] sending SACK: SACK cumTsnAck=3749657546 arwnd=1048575 dupTsn=[]
[2023-03-22T14:18:14Z DEBUG webrtc_data::data_channel] Received DATA_CHANNEL_ACK
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::stream] [1:] reliability params: ordered=true type=Reliable value=0
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association] [] sending 28 bytes
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association] [] recving 28 bytes
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association] [] recving 40 bytes
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association::association_internal] [] accepted a new stream (streamIdentifier: 2)
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::stream] [2:] reassemblyQueue readable=true
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::stream] [2:] readNotifier.signal()
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::stream] [2:] readNotifier.signal() done
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association::association_internal] [] peer_last_tsn = 3749657546
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association::association_internal] [] peer_last_tsn = 3749657547
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::stream] [2:] reliability params: ordered=true type=Reliable value=0
[2023-03-22T14:18:14Z DEBUG libp2p_webrtc::tokio::connection] Incoming data channel 0
[2023-03-22T14:18:14Z DEBUG libp2p_webrtc::tokio::connection] Data channel 0 open
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association] [] sending 32 bytes
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association] [] recving 84 bytes
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::stream] [2:] reassemblyQueue readable=true
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::stream] [2:] readNotifier.signal()
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::stream] [2:] readNotifier.signal() done
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association::association_internal] [] peer_last_tsn = 3749657547
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association::association_internal] [] peer_last_tsn = 3749657548
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association::association_internal] [] sending SACK: SACK cumTsnAck=3749657548 arwnd=1048537 dupTsn=[]
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association] [] sending 28 bytes
[2023-03-22T14:18:14Z DEBUG multistream_select::listener_select] Listener: confirming protocol: /meshsub/1.1.0
[2023-03-22T14:18:14Z DEBUG multistream_select::listener_select] Listener: sent confirmed protocol: /meshsub/1.1.0
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association] [] recving 52 bytes
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::stream] [1:] reassemblyQueue readable=true
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::stream] [1:] readNotifier.signal()
[2023-03-22T14:18:14Z DEBUG libp2p_gossipsub::behaviour] New peer type found: Gossipsub v1.1 for peer: 12D3KooWMs8X6PFr6wcHTFho37vN91k3phCaCDsoKXRqf8hcjYqU
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::stream] [1:] readNotifier.signal() done
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association::association_internal] [] peer_last_tsn = 3749657548
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association::association_internal] [] peer_last_tsn = 3749657549
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association] [] recving 52 bytes
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association] [] sending 88 bytes
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::stream] [1:] reassemblyQueue readable=true
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::stream] [1:] readNotifier.signal()
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::stream] [1:] readNotifier.signal() done
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association::association_internal] [] peer_last_tsn = 3749657549
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association::association_internal] [] peer_last_tsn = 3749657550
[2023-03-22T14:18:14Z DEBUG multistream_select::dialer_select] Dialer: Received confirmation for protocol: /ipfs/ping/1.0.0
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association::association_internal] [] sending SACK: SACK cumTsnAck=3749657550 arwnd=1048576 dupTsn=[]
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association] [] sending 64 bytes
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association] [] sending 28 bytes
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association] [] recving 28 bytes
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association] [] recving 64 bytes
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::stream] [1:] reassemblyQueue readable=true
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::stream] [1:] readNotifier.signal()
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::stream] [1:] readNotifier.signal() done
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association::association_internal] [] peer_last_tsn = 3749657550
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association::association_internal] [] peer_last_tsn = 3749657551
[2023-03-22T14:18:14Z DEBUG libp2p_ping] Ping sent to PeerId("12D3KooWMs8X6PFr6wcHTFho37vN91k3phCaCDsoKXRqf8hcjYqU")
New event: Behaviour(BehaviourEvent: Event { peer: PeerId("12D3KooWMs8X6PFr6wcHTFho37vN91k3phCaCDsoKXRqf8hcjYqU"), result: Ok(Ping { rtt: 982µs }) })
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association] [] recving 40 bytes
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association::association_internal] [] accepted a new stream (streamIdentifier: 4)
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::stream] [4:] reassemblyQueue readable=true
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::stream] [4:] readNotifier.signal()
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::stream] [4:] readNotifier.signal() done
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association::association_internal] [] peer_last_tsn = 3749657551
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association::association_internal] [] peer_last_tsn = 3749657552
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association::association_internal] [] sending SACK: SACK cumTsnAck=3749657552 arwnd=1048564 dupTsn=[]
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association] [] sending 28 bytes
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::stream] [4:] reliability params: ordered=true type=Reliable value=0
[2023-03-22T14:18:14Z DEBUG libp2p_webrtc::tokio::connection] Incoming data channel 0
[2023-03-22T14:18:14Z DEBUG libp2p_webrtc::tokio::connection] Data channel 0 open
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association] [] recving 68 bytes
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::stream] [4:] reassemblyQueue readable=true
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::stream] [4:] readNotifier.signal()
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::stream] [4:] readNotifier.signal() done
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association::association_internal] [] peer_last_tsn = 3749657552
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association::association_internal] [] peer_last_tsn = 3749657553
[2023-03-22T14:18:14Z DEBUG multistream_select::listener_select] Listener: rejecting protocol: /ipfs/id/1.0.0
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association] [] sending 96 bytes
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association] [] recving 36 bytes
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association::association_internal] [] resetStream(): senderLastTSN=3749657553 <= peer_last_tsn=3749657553
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association] [] sending 28 bytes
[2023-03-22T14:18:14Z INFO  libp2p_webrtc::tokio::substream::drop_listener] Substream 4 dropped without graceful close, sending Reset
[2023-03-22T14:18:14Z DEBUG libp2p_webrtc::tokio::connection] a DropListener failed: Stream closed
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association] [] recving 28 bytes
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association] [] recving 40 bytes
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association::association_internal] [] accepted a new stream (streamIdentifier: 6)
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::stream] [6:] reassemblyQueue readable=true
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::stream] [6:] readNotifier.signal()
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::stream] [6:] readNotifier.signal() done
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association::association_internal] [] peer_last_tsn = 3749657553
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association::association_internal] [] peer_last_tsn = 3749657554
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association] [] recving 68 bytes
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::stream] [6:] reassemblyQueue readable=true
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::stream] [6:] readNotifier.signal()
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::stream] [6:] readNotifier.signal() done
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::stream] [6:] reliability params: ordered=true type=Reliable value=0
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association::association_internal] [] peer_last_tsn = 3749657554
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association::association_internal] [] peer_last_tsn = 3749657555
[2023-03-22T14:18:14Z DEBUG libp2p_webrtc::tokio::connection] Incoming data channel 0
[2023-03-22T14:18:14Z DEBUG libp2p_webrtc::tokio::connection] Data channel 0 open
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association::association_internal] [] sending SACK: SACK cumTsnAck=3749657555 arwnd=1048537 dupTsn=[]
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association] [] sending 32 bytes
[2023-03-22T14:18:14Z DEBUG multistream_select::listener_select] Listener: confirming protocol: /meshsub/1.1.0
[2023-03-22T14:18:14Z DEBUG multistream_select::listener_select] Listener: sent confirmed protocol: /meshsub/1.1.0
[2023-03-22T14:18:14Z INFO  libp2p_webrtc::tokio::substream::drop_listener] Substream 2 dropped without graceful close, sending Reset
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association] [] sending 28 bytes
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association] [] sending 108 bytes
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association] [] recving 28 bytes
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association] [] recving 48 bytes
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::stream] [6:] reassemblyQueue readable=true
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::stream] [6:] readNotifier.signal()
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::stream] [6:] readNotifier.signal() done
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association::association_internal] [] peer_last_tsn = 3749657555
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association::association_internal] [] peer_last_tsn = 3749657556
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association] [] recving 60 bytes
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::stream] [6:] reassemblyQueue readable=true
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::stream] [6:] readNotifier.signal()
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::stream] [6:] readNotifier.signal() done
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association::association_internal] [] peer_last_tsn = 3749657556
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association::association_internal] [] peer_last_tsn = 3749657557
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association::association_internal] [] sending SACK: SACK cumTsnAck=3749657557 arwnd=1048576 dupTsn=[]
[2023-03-22T14:18:14Z DEBUG webrtc_sctp::association] [] sending 28 bytes
[2023-03-22T14:18:14Z DEBUG libp2p_gossipsub::behaviour] Handling subscriptions: [Subscription { action: Subscribe, topic_hash: TopicHash { hash: "universal-connectivity" } }], from source: 12D3KooWMs8X6PFr6wcHTFho37vN91k3phCaCDsoKXRqf8hcjYqU
[2023-03-22T14:18:14Z DEBUG libp2p_gossipsub::behaviour] SUBSCRIPTION: Adding gossip peer: 12D3KooWMs8X6PFr6wcHTFho37vN91k3phCaCDsoKXRqf8hcjYqU to topic: TopicHash { hash: "universal-connectivity" }
New event: Behaviour(BehaviourEvent: Subscribed { peer_id: PeerId("12D3KooWMs8X6PFr6wcHTFho37vN91k3phCaCDsoKXRqf8hcjYqU"), topic: TopicHash { hash: "universal-connectivity" } })
[2023-03-22T14:18:15Z DEBUG libp2p_gossipsub::behaviour] Starting heartbeat
[2023-03-22T14:18:15Z DEBUG libp2p_gossipsub::behaviour] Completed Heartbeat




[2023-03-22T14:18:25Z DEBUG libp2p_gossipsub::behaviour] Starting heartbeat
[2023-03-22T14:18:25Z DEBUG libp2p_gossipsub::behaviour] Completed Heartbeat




[2023-03-22T14:18:29Z DEBUG webrtc_sctp::association] [] sending 64 bytes
[2023-03-22T14:18:29Z DEBUG webrtc_sctp::association] [] recving 80 bytes
[2023-03-22T14:18:29Z DEBUG webrtc_sctp::stream] [1:] reassemblyQueue readable=true
[2023-03-22T14:18:29Z DEBUG webrtc_sctp::stream] [1:] readNotifier.signal()
[2023-03-22T14:18:29Z DEBUG webrtc_sctp::stream] [1:] readNotifier.signal() done
[2023-03-22T14:18:29Z DEBUG webrtc_sctp::association::association_internal] [] peer_last_tsn = 3749657557
[2023-03-22T14:18:29Z DEBUG webrtc_sctp::association::association_internal] [] peer_last_tsn = 3749657558
[2023-03-22T14:18:29Z DEBUG libp2p_ping] Ping sent to PeerId("12D3KooWMs8X6PFr6wcHTFho37vN91k3phCaCDsoKXRqf8hcjYqU")
New event: Behaviour(BehaviourEvent: Event { peer: PeerId("12D3KooWMs8X6PFr6wcHTFho37vN91k3phCaCDsoKXRqf8hcjYqU"), result: Ok(Ping { rtt: 5.497416ms }) })
[2023-03-22T14:18:29Z DEBUG webrtc_sctp::association::association_internal] [] sending SACK: SACK cumTsnAck=3749657558 arwnd=1048576 dupTsn=[]
[2023-03-22T14:18:29Z DEBUG webrtc_sctp::association] [] sending 28 bytes
[2023-03-22T14:18:35Z DEBUG libp2p_gossipsub::behaviour] Starting heartbeat
[2023-03-22T14:18:35Z DEBUG libp2p_gossipsub::behaviour] Completed Heartbeat
[2023-03-22T14:18:44Z DEBUG webrtc_sctp::association] [] sending 64 bytes
[2023-03-22T14:18:44Z DEBUG webrtc_sctp::association] [] recving 80 bytes
[2023-03-22T14:18:44Z DEBUG webrtc_sctp::stream] [1:] reassemblyQueue readable=true
[2023-03-22T14:18:44Z DEBUG webrtc_sctp::stream] [1:] readNotifier.signal()
[2023-03-22T14:18:44Z DEBUG webrtc_sctp::stream] [1:] readNotifier.signal() done
[2023-03-22T14:18:44Z DEBUG webrtc_sctp::association::association_internal] [] peer_last_tsn = 3749657558
[2023-03-22T14:18:44Z DEBUG webrtc_sctp::association::association_internal] [] peer_last_tsn = 3749657559
[2023-03-22T14:18:44Z DEBUG libp2p_ping] Ping sent to PeerId("12D3KooWMs8X6PFr6wcHTFho37vN91k3phCaCDsoKXRqf8hcjYqU")
New event: Behaviour(BehaviourEvent: Event { peer: PeerId("12D3KooWMs8X6PFr6wcHTFho37vN91k3phCaCDsoKXRqf8hcjYqU"), result: Ok(Ping { rtt: 10.455166ms }) })
[2023-03-22T14:18:44Z DEBUG webrtc_sctp::association] [] recving 64 bytes
[2023-03-22T14:18:44Z DEBUG webrtc_sctp::association::association_internal] [] peer_last_tsn = 3749657559
[2023-03-22T14:18:44Z DEBUG webrtc_sctp::association::association_internal] [] sending SACK: SACK cumTsnAck=3749657559 arwnd=1048576 dupTsn=[]
[2023-03-22T14:18:44Z DEBUG webrtc_sctp::association] [] sending 28 bytes
[2023-03-22T14:18:45Z DEBUG libp2p_gossipsub::behaviour] Starting heartbeat
[2023-03-22T14:18:45Z DEBUG libp2p_gossipsub::behaviour] Completed Heartbeat
[2023-03-22T14:18:55Z DEBUG libp2p_gossipsub::behaviour] Starting heartbeat
[2023-03-22T14:18:55Z DEBUG libp2p_gossipsub::behaviour] Completed Heartbeat
[2023-03-22T14:18:59Z DEBUG webrtc_sctp::association] [] sending 64 bytes
[2023-03-22T14:18:59Z DEBUG webrtc_sctp::association] [] recving 80 bytes
[2023-03-22T14:18:59Z DEBUG webrtc_sctp::stream] [1:] reassemblyQueue readable=true
[2023-03-22T14:18:59Z DEBUG webrtc_sctp::stream] [1:] readNotifier.signal()
[2023-03-22T14:18:59Z DEBUG webrtc_sctp::stream] [1:] readNotifier.signal() done
[2023-03-22T14:18:59Z DEBUG webrtc_sctp::association::association_internal] [] peer_last_tsn = 3749657559
[2023-03-22T14:18:59Z DEBUG webrtc_sctp::association::association_internal] [] peer_last_tsn = 3749657560
[2023-03-22T14:18:59Z DEBUG libp2p_ping] Ping sent to PeerId("12D3KooWMs8X6PFr6wcHTFho37vN91k3phCaCDsoKXRqf8hcjYqU")
New event: Behaviour(BehaviourEvent: Event { peer: PeerId("12D3KooWMs8X6PFr6wcHTFho37vN91k3phCaCDsoKXRqf8hcjYqU"), result: Ok(Ping { rtt: 8.8345ms }) })
[2023-03-22T14:18:59Z DEBUG webrtc_sctp::association::association_internal] [] sending SACK: SACK cumTsnAck=3749657560 arwnd=1048576 dupTsn=[]
[2023-03-22T14:18:59Z DEBUG webrtc_sctp::association] [] sending 28 bytes
[2023-03-22T14:19:05Z DEBUG libp2p_gossipsub::behaviour] Starting heartbeat
[2023-03-22T14:19:05Z DEBUG libp2p_gossipsub::behaviour] Completed Heartbeat
[2023-03-22T14:19:14Z DEBUG webrtc_sctp::association] [] sending 64 bytes
[2023-03-22T14:19:14Z DEBUG webrtc_sctp::association] [] recving 80 bytes
[2023-03-22T14:19:14Z DEBUG webrtc_sctp::stream] [1:] reassemblyQueue readable=true
[2023-03-22T14:19:14Z DEBUG webrtc_sctp::stream] [1:] readNotifier.signal()
[2023-03-22T14:19:14Z DEBUG webrtc_sctp::stream] [1:] readNotifier.signal() done
[2023-03-22T14:19:14Z DEBUG webrtc_sctp::association::association_internal] [] peer_last_tsn = 3749657560
[2023-03-22T14:19:14Z DEBUG webrtc_sctp::association::association_internal] [] peer_last_tsn = 3749657561
[2023-03-22T14:19:14Z DEBUG libp2p_ping] Ping sent to PeerId("12D3KooWMs8X6PFr6wcHTFho37vN91k3phCaCDsoKXRqf8hcjYqU")
New event: Behaviour(BehaviourEvent: Event { peer: PeerId("12D3KooWMs8X6PFr6wcHTFho37vN91k3phCaCDsoKXRqf8hcjYqU"), result: Ok(Ping { rtt: 7.371625ms }) })
[2023-03-22T14:19:14Z DEBUG webrtc_sctp::association] [] recving 64 bytes
[2023-03-22T14:19:14Z DEBUG webrtc_sctp::association::association_internal] [] peer_last_tsn = 3749657561
[2023-03-22T14:19:14Z DEBUG webrtc_sctp::association::association_internal] [] sending SACK: SACK cumTsnAck=3749657561 arwnd=1048576 dupTsn=[]
[2023-03-22T14:19:14Z DEBUG webrtc_sctp::association] [] sending 28 bytes
[2023-03-22T14:19:15Z DEBUG libp2p_gossipsub::behaviour] Starting heartbeat
[2023-03-22T14:19:15Z DEBUG libp2p_gossipsub::behaviour] Completed Heartbeat
[2023-03-22T14:19:25Z DEBUG libp2p_gossipsub::behaviour] Starting heartbeat
[2023-03-22T14:19:25Z DEBUG libp2p_gossipsub::behaviour] Completed Heartbeat

@p-shahi
Copy link
Member

p-shahi commented Mar 22, 2023

The real issue is this.

When I enable the following topic subscription

    // Create a Gossipsub topic
    let topic = gossipsub::IdentTopic::new("universal-connectivity");

    // subscribes to our topic
    gossipsub.subscribe(&topic)?;

I get the following and a closed connection. It looks like the mesh is low, and needs at least 5. I'll try to update the setting

[2023-03-22T14:27:35Z DEBUG libp2p_gossipsub::behaviour] Handling subscriptions: [Subscription { action: Subscribe, topic_hash: TopicHash { hash: "universal-connectivity" } }], from source: 12D3KooWMs8X6PFr6wcHTFho37vN91k3phCaCDsoKXRqf8hcjYqU
[2023-03-22T14:27:35Z DEBUG libp2p_gossipsub::behaviour] SUBSCRIPTION: Adding gossip peer: 12D3KooWMs8X6PFr6wcHTFho37vN91k3phCaCDsoKXRqf8hcjYqU to topic: TopicHash { hash: "universal-connectivity" }
[2023-03-22T14:27:35Z DEBUG libp2p_gossipsub::behaviour] SUBSCRIPTION: Adding peer 12D3KooWMs8X6PFr6wcHTFho37vN91k3phCaCDsoKXRqf8hcjYqU to the mesh for topic TopicHash { hash: "universal-connectivity" }
[2023-03-22T14:27:35Z DEBUG libp2p_gossipsub::behaviour] Sending GRAFT to peer 12D3KooWMs8X6PFr6wcHTFho37vN91k3phCaCDsoKXRqf8hcjYqU for topic TopicHash { hash: "universal-connectivity" }
New event: Behaviour(BehaviourEvent: Subscribed { peer_id: PeerId("12D3KooWMs8X6PFr6wcHTFho37vN91k3phCaCDsoKXRqf8hcjYqU"), topic: TopicHash { hash: "universal-connectivity" } })
[2023-03-22T14:27:36Z DEBUG webrtc_sctp::association::association_internal] [] sending SACK: SACK cumTsnAck=2082090746 arwnd=1048576 dupTsn=[]
[2023-03-22T14:27:36Z DEBUG webrtc_sctp::association] [] sending 28 bytes
[2023-03-22T14:27:38Z DEBUG libp2p_gossipsub::behaviour] Starting heartbeat
[2023-03-22T14:27:38Z DEBUG libp2p_gossipsub::behaviour] HEARTBEAT: Mesh low. Topic: universal-connectivity Contains: 1 needs: 5
[2023-03-22T14:27:38Z DEBUG libp2p_gossipsub::behaviour] RANDOM PEERS: Got 0 peers
[2023-03-22T14:27:38Z DEBUG libp2p_gossipsub::behaviour] Updating mesh, new mesh: {}
[2023-03-22T14:27:38Z DEBUG libp2p_gossipsub::behaviour] Completed Heartbeat
[2023-03-22T14:27:45Z WARN  libp2p_gossipsub::handler] Dial upgrade error Timeout
[2023-03-22T14:27:45Z DEBUG libp2p_swarm] Connection closed with error Handler(Left(Left(Left(NegotiationTimeout)))): Connected { endpoint: Listener { local_addr: "/ip4/127.0.0.1/udp/60288/webrtc/certhash/uEiCU_0YHz_KXjK73lugucGCfJ8D1D0q23xCnArVzyWVcvA", send_back_addr: "/ip4/127.0.0.1/udp/53206/webrtc" }, peer_id: PeerId("12D3KooWMs8X6PFr6wcHTFho37vN91k3phCaCDsoKXRqf8hcjYqU") }; Total (peer): 0.
[2023-03-22T14:27:45Z DEBUG libp2p_gossipsub::behaviour] Peer disconnected: 12D3KooWMs8X6PFr6wcHTFho37vN91k3phCaCDsoKXRqf8hcjYqU
New event: ConnectionClosed { peer_id: PeerId("12D3KooWMs8X6PFr6wcHTFho37vN91k3phCaCDsoKXRqf8hcjYqU"), endpoint: Listener { local_addr: "/ip4/127.0.0.1/udp/60288/webrtc/certhash/uEiCU_0YHz_KXjK73lugucGCfJ8D1D0q23xCnArVzyWVcvA", send_back_addr: "/ip4/127.0.0.1/udp/53206/webrtc" }, num_established: 0, cause: Some(Handler(Left(Left(Left(NegotiationTimeout))))) }
[2023-03-22T14:27:48Z DEBUG libp2p_gossipsub::behaviour] Starting heartbeat
[2023-03-22T14:27:48Z DEBUG libp2p_gossipsub::behaviour] HEARTBEAT: Mesh low. Topic: universal-connectivity Contains: 0 needs: 5
[2023-03-22T14:27:48Z DEBUG libp2p_gossipsub::behaviour] RANDOM PEERS: Got 0 peers
[2023-03-22T14:27:48Z DEBUG libp2p_gossipsub::behaviour] Updating mesh, new mesh: {}

@mxinden
Copy link
Member

mxinden commented Mar 27, 2023

I found the issue for the missing subscribe from the rust-libp2p server to the js-libp2p (or any other) client. Sparsely documented in libp2p/rust-libp2p#3690 for now. Will follow up with more details and push a patch here.

Great job everyone surfacing this issue!

Depend on latest commits on libp2p/rust-libp2p#3625 more
specifically
libp2p/rust-libp2p@b572895
resolving the missing SUBSCRIBE message previously not send by a rust-libp2p server.

Additional refactorings:

- Use clap to parse command line arguments. Among other things gives us nice
help text and better error messages.
- Depend on `libp2p-webrtc` directly as we will remove the re-export from
`libp2p`.
- Use `futures-timer` to send `Hello World` on a 2 second interval instead of on
each `SwarmEvent`.
- Redo logging on various levels (warn, info, debug).
@mxinden
Copy link
Member

mxinden commented Mar 29, 2023

Fix for the missing SUBSCRIBE will be added with #6.

Fix missing SUBSCRIBE and refactor
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

5 participants