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

The chat-tokio example is broken since v0.45.0 #3100

Closed
Ma233 opened this issue Nov 9, 2022 · 4 comments
Closed

The chat-tokio example is broken since v0.45.0 #3100

Ma233 opened this issue Nov 9, 2022 · 4 comments

Comments

@Ma233
Copy link

Ma233 commented Nov 9, 2022

Summary

I tried chat-tokio example on v0.44.0, v0.45.0 and v0.49.0. Only worked on v0.44.0.
It seems to be something wrong on mdns as this issue #2676 mentioned.

FYI, this is my system info:

❯ uname -a
Darwin XXXXX 21.6.0 Darwin Kernel Version 21.6.0: Mon Aug 22 20:19:52 PDT 2022; root:xnu-8020.140.49~2/RELEASE_ARM64_T6000 arm64

Expected behaviour

First setup some chat nodes by cargo run --features="tcp-tokio mdns" --example chat-tokio.
Then when you input some words in a node, the other nodes should receive it and print it out.

Actual behaviour

The other nodes do not print anything after input.
And I logged the events, the connection event was not send after nodes setup.

Debug Output

Local peer id: PeerId("12D3KooWPwtV3juE79L1d3Y2Xc1UNFw8BTVsuwkXKv2qgwgeJtgd")
[2022-11-09T08:53:17Z DEBUG libp2p_tcp] listening on 0.0.0.0:0
[2022-11-09T08:53:17Z INFO  libp2p_mdns::behaviour::iface] creating instance on iface 10.206.53.188
[2022-11-09T08:53:17Z DEBUG libp2p_tcp] New listen address: /ip4/10.206.53.188/tcp/57067
[2022-11-09T08:53:17Z DEBUG libp2p_swarm] Listener ListenerId(1); New address: "/ip4/10.206.53.188/tcp/57067"
Listening on "/ip4/10.206.53.188/tcp/57067"
[2022-11-09T08:53:17Z DEBUG libp2p_tcp] New listen address: /ip4/127.0.0.1/tcp/57067
[2022-11-09T08:53:17Z DEBUG libp2p_swarm] Listener ListenerId(1); New address: "/ip4/127.0.0.1/tcp/57067"
Listening on "/ip4/127.0.0.1/tcp/57067"
[2022-11-09T08:53:17Z DEBUG libp2p_mdns::behaviour::iface::query] Parsing mdns packet failed: LabelIsNotAscii
[2022-11-09T08:53:17Z DEBUG libp2p_mdns::behaviour::iface::query] Parsing mdns packet failed: LabelIsNotAscii
[2022-11-09T08:53:17Z DEBUG libp2p_mdns::behaviour::iface::query] Parsing mdns packet failed: LabelIsNotAscii
[2022-11-09T08:53:17Z DEBUG libp2p_mdns::behaviour::iface::query] Parsing mdns packet failed: LabelIsNotAscii
...
[2022-11-09T08:53:18Z DEBUG libp2p_mdns::behaviour::iface::query] Parsing mdns packet failed: LabelIsNotAscii

Possible Solution

Check what's wrong on libp2p_mdns.

Version

v0.44.0, v0.45.0 and v0.49.0.

Would you like to work on fixing this bug?

Maybe.

@jxs
Copy link
Member

jxs commented Nov 14, 2022

@Ma233, did #3102 help with this?

@Ma233
Copy link
Author

Ma233 commented Nov 15, 2022

@jxs Yes, but still not work. I think it's now failed at:

[2022-11-15T03:36:22Z DEBUG libp2p_swarm] Connection closed with error KeepAliveTimeout: Connected { endpoint: Listener { local_addr: "/ip4/192.168.50.145/tcp/50634", send_back_addr: "/ip4/192.168.50.145/tcp/50678" }, peer_id: PeerId("12D3KooWBp3pXD9DcTgxYb2KnMEKDdJSmB9GwsJnycZQPmXAcPG2") }; Total (peer): 1.
[2022-11-15T03:36:22Z DEBUG libp2p_swarm] Connection closed with error KeepAliveTimeout: Connected { endpoint: Dialer { address: "/ip4/192.168.50.145/tcp/50650/p2p/12D3KooWBp3pXD9DcTgxYb2KnMEKDdJSmB9GwsJnycZQPmXAcPG2", role_override: Dialer }, peer_id: PeerId("12D3KooWBp3pXD9DcTgxYb2KnMEKDdJSmB9GwsJnycZQPmXAcPG2") }; Total (peer): 0.
Full Debug Output

❯ RUST_LOG=debug cargo run --features="full" --example chat-tokio
    Finished dev [unoptimized + debuginfo] target(s) in 0.19s
     Running `target/debug/examples/chat-tokio`
Local peer id: PeerId("12D3KooWFmViyWVzmdSybrjuxLTJWTcABAavsJ6UJ2o3SKJCR54b")
[2022-11-15T03:35:53Z DEBUG libp2p_tcp] listening on 0.0.0.0:0
[2022-11-15T03:35:53Z INFO  libp2p_mdns::behaviour::iface] creating instance on iface 192.168.50.145
[2022-11-15T03:35:53Z DEBUG libp2p_tcp] New listen address: /ip4/127.0.0.1/tcp/50634
[2022-11-15T03:35:53Z DEBUG libp2p_swarm] Listener ListenerId(9214877161746887602); New address: "/ip4/127.0.0.1/tcp/50634"
Listening on "/ip4/127.0.0.1/tcp/50634"
[2022-11-15T03:35:53Z DEBUG libp2p_tcp] New listen address: /ip4/192.168.50.145/tcp/50634
[2022-11-15T03:35:53Z DEBUG libp2p_swarm] Listener ListenerId(9214877161746887602); New address: "/ip4/192.168.50.145/tcp/50634"
Listening on "/ip4/192.168.50.145/tcp/50634"
[2022-11-15T03:36:02Z INFO  libp2p_mdns::behaviour] discovered: 12D3KooWBp3pXD9DcTgxYb2KnMEKDdJSmB9GwsJnycZQPmXAcPG2 /ip4/192.168.50.145/tcp/50650
[2022-11-15T03:36:02Z DEBUG libp2p_tcp] dialing 192.168.50.145:50650
[2022-11-15T03:36:02Z DEBUG libp2p_tcp] Incoming connection from /ip4/192.168.50.145/tcp/50651 at /ip4/192.168.50.145/tcp/50634
[2022-11-15T03:36:02Z DEBUG multistream_select::dialer_select] Dialer: Proposed protocol: /noise
[2022-11-15T03:36:02Z DEBUG multistream_select::listener_select] Listener: confirming protocol: /noise
[2022-11-15T03:36:02Z DEBUG multistream_select::listener_select] Listener: sent confirmed protocol: /noise
[2022-11-15T03:36:02Z DEBUG multistream_select::dialer_select] Dialer: Received confirmation for protocol: /noise
[2022-11-15T03:36:02Z DEBUG libp2p_core::upgrade::apply] Successfully applied negotiated protocol
[2022-11-15T03:36:02Z DEBUG multistream_select::dialer_select] Dialer: Proposed protocol: /mplex/6.7.0
[2022-11-15T03:36:02Z DEBUG libp2p_core::upgrade::apply] Successfully applied negotiated protocol
[2022-11-15T03:36:02Z DEBUG multistream_select::listener_select] Listener: confirming protocol: /mplex/6.7.0
[2022-11-15T03:36:02Z DEBUG multistream_select::listener_select] Listener: sent confirmed protocol: /mplex/6.7.0
[2022-11-15T03:36:02Z DEBUG libp2p_mplex::io] New multiplexed connection: 628aeca6d8ffd1f1
[2022-11-15T03:36:02Z DEBUG libp2p_core::upgrade::apply] Successfully applied negotiated protocol
[2022-11-15T03:36:02Z DEBUG multistream_select::dialer_select] Dialer: Received confirmation for protocol: /mplex/6.7.0
[2022-11-15T03:36:02Z DEBUG libp2p_mplex::io] New multiplexed connection: 3c811f47dacd5d96
[2022-11-15T03:36:02Z DEBUG libp2p_core::upgrade::apply] Successfully applied negotiated protocol
[2022-11-15T03:36:02Z DEBUG libp2p_swarm] Connection established: PeerId("12D3KooWBp3pXD9DcTgxYb2KnMEKDdJSmB9GwsJnycZQPmXAcPG2") Listener { local_addr: "/ip4/192.168.50.145/tcp/50634", send_back_addr: "/ip4/192.168.50.145/tcp/50651" }; Total (peer): 1. Total non-banned (peer): 1
[2022-11-15T03:36:02Z DEBUG libp2p_mplex::io] 628aeca6d8ffd1f1: New outbound substream: (0/initiator) (total 1)
[2022-11-15T03:36:02Z DEBUG multistream_select::dialer_select] Dialer: Proposed protocol: /floodsub/1.0.0
[2022-11-15T03:36:02Z DEBUG libp2p_swarm] Connection established: PeerId("12D3KooWBp3pXD9DcTgxYb2KnMEKDdJSmB9GwsJnycZQPmXAcPG2") Dialer { address: "/ip4/192.168.50.145/tcp/50650/p2p/12D3KooWBp3pXD9DcTgxYb2KnMEKDdJSmB9GwsJnycZQPmXAcPG2", role_override: Dialer }; Total (peer): 2. Total non-banned (peer): 2
[2022-11-15T03:36:02Z DEBUG libp2p_mplex::io] 3c811f47dacd5d96: New inbound substream: (0/receiver) (total 1)
[2022-11-15T03:36:02Z DEBUG multistream_select::listener_select] Listener: confirming protocol: /floodsub/1.0.0
[2022-11-15T03:36:02Z DEBUG multistream_select::listener_select] Listener: sent confirmed protocol: /floodsub/1.0.0
[2022-11-15T03:36:02Z DEBUG multistream_select::dialer_select] Dialer: Received confirmation for protocol: /floodsub/1.0.0
[2022-11-15T03:36:02Z DEBUG libp2p_mplex::io] 628aeca6d8ffd1f1: Closed substream (0/initiator) (half-close)
[2022-11-15T03:36:02Z DEBUG libp2p_core::upgrade::apply] Successfully applied negotiated protocol
[2022-11-15T03:36:02Z DEBUG libp2p_core::upgrade::apply] Successfully applied negotiated protocol
[2022-11-15T03:36:12Z DEBUG libp2p_swarm] Connection closed with error KeepAliveTimeout: Connected { endpoint: Listener { local_addr: "/ip4/192.168.50.145/tcp/50634", send_back_addr: "/ip4/192.168.50.145/tcp/50651" }, peer_id: PeerId("12D3KooWBp3pXD9DcTgxYb2KnMEKDdJSmB9GwsJnycZQPmXAcPG2") }; Total (peer): 1.
[2022-11-15T03:36:12Z DEBUG libp2p_swarm] Connection closed with error KeepAliveTimeout: Connected { endpoint: Dialer { address: "/ip4/192.168.50.145/tcp/50650/p2p/12D3KooWBp3pXD9DcTgxYb2KnMEKDdJSmB9GwsJnycZQPmXAcPG2", role_override: Dialer }, peer_id: PeerId("12D3KooWBp3pXD9DcTgxYb2KnMEKDdJSmB9GwsJnycZQPmXAcPG2") }; Total (peer): 0.
[2022-11-15T03:36:12Z DEBUG libp2p_tcp] dialing 192.168.50.145:50650
[2022-11-15T03:36:12Z INFO  libp2p_mdns::behaviour] expired: 12D3KooWBp3pXD9DcTgxYb2KnMEKDdJSmB9GwsJnycZQPmXAcPG2 /ip4/192.168.50.145/tcp/50650
[2022-11-15T03:36:12Z DEBUG multistream_select::dialer_select] Dialer: Proposed protocol: /noise
[2022-11-15T03:36:12Z DEBUG libp2p_tcp] Incoming connection from /ip4/192.168.50.145/tcp/50678 at /ip4/192.168.50.145/tcp/50634
[2022-11-15T03:36:12Z DEBUG multistream_select::listener_select] Listener: confirming protocol: /noise
[2022-11-15T03:36:12Z DEBUG multistream_select::listener_select] Listener: sent confirmed protocol: /noise
[2022-11-15T03:36:12Z DEBUG multistream_select::dialer_select] Dialer: Received confirmation for protocol: /noise
[2022-11-15T03:36:12Z DEBUG libp2p_core::upgrade::apply] Successfully applied negotiated protocol
[2022-11-15T03:36:12Z DEBUG multistream_select::dialer_select] Dialer: Proposed protocol: /mplex/6.7.0
[2022-11-15T03:36:12Z DEBUG libp2p_core::upgrade::apply] Successfully applied negotiated protocol
[2022-11-15T03:36:12Z DEBUG multistream_select::listener_select] Listener: confirming protocol: /mplex/6.7.0
[2022-11-15T03:36:12Z DEBUG multistream_select::listener_select] Listener: sent confirmed protocol: /mplex/6.7.0
[2022-11-15T03:36:12Z DEBUG libp2p_mplex::io] New multiplexed connection:  86c851513e7eda8
[2022-11-15T03:36:12Z DEBUG libp2p_core::upgrade::apply] Successfully applied negotiated protocol
[2022-11-15T03:36:12Z DEBUG multistream_select::dialer_select] Dialer: Received confirmation for protocol: /mplex/6.7.0
[2022-11-15T03:36:12Z DEBUG libp2p_mplex::io] New multiplexed connection: aa7e2256900883db
[2022-11-15T03:36:12Z DEBUG libp2p_core::upgrade::apply] Successfully applied negotiated protocol
[2022-11-15T03:36:12Z DEBUG libp2p_swarm] Connection established: PeerId("12D3KooWBp3pXD9DcTgxYb2KnMEKDdJSmB9GwsJnycZQPmXAcPG2") Listener { local_addr: "/ip4/192.168.50.145/tcp/50634", send_back_addr: "/ip4/192.168.50.145/tcp/50678" }; Total (peer): 1. Total non-banned (peer): 1
[2022-11-15T03:36:12Z DEBUG libp2p_swarm] Connection established: PeerId("12D3KooWBp3pXD9DcTgxYb2KnMEKDdJSmB9GwsJnycZQPmXAcPG2") Dialer { address: "/ip4/192.168.50.145/tcp/50650/p2p/12D3KooWBp3pXD9DcTgxYb2KnMEKDdJSmB9GwsJnycZQPmXAcPG2", role_override: Dialer }; Total (peer): 2. Total non-banned (peer): 2
[2022-11-15T03:36:22Z DEBUG libp2p_swarm] Connection closed with error KeepAliveTimeout: Connected { endpoint: Listener { local_addr: "/ip4/192.168.50.145/tcp/50634", send_back_addr: "/ip4/192.168.50.145/tcp/50678" }, peer_id: PeerId("12D3KooWBp3pXD9DcTgxYb2KnMEKDdJSmB9GwsJnycZQPmXAcPG2") }; Total (peer): 1.
[2022-11-15T03:36:22Z DEBUG libp2p_swarm] Connection closed with error KeepAliveTimeout: Connected { endpoint: Dialer { address: "/ip4/192.168.50.145/tcp/50650/p2p/12D3KooWBp3pXD9DcTgxYb2KnMEKDdJSmB9GwsJnycZQPmXAcPG2", role_override: Dialer }, peer_id: PeerId("12D3KooWBp3pXD9DcTgxYb2KnMEKDdJSmB9GwsJnycZQPmXAcPG2") }; Total (peer): 0.

@thomaseizinger
Copy link
Contributor

The connection is closed because it is idle. You need to either use the connection (send a message) or configure a permanent keep-alive (keep_alive::Behaviour).

@Ma233
Copy link
Author

Ma233 commented Jan 31, 2023

This issue was fixed by #3296

@Ma233 Ma233 closed this as completed Jan 31, 2023
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

No branches or pull requests

3 participants