libp2p-0.49 with severe problems due to this crate (pulled in via mdns)

[rkuhn]

This is what happens:

line: 2022-10-28T20:11:16.141162Z TRACE netlink_sys::smol: poll_recv_from: Ok((360, SocketAddr(nl_family=16, nl_pid=0, nl_groups=0)))    
line: 2022-10-28T20:11:16.141324Z TRACE netlink_sys::smol: poll_recv_from: Ok((20, SocketAddr(nl_family=16, nl_pid=0, nl_groups=0)))    
line: 2022-10-28T20:11:16.141376Z TRACE netlink_sys::smol: poll_recv_from: Err(Os { code: 11, kind: WouldBlock, message: "Resource temporarily unavailable" })    
line: 2022-10-28T20:11:16.141411Z TRACE polling::epoll: modify: epoll_fd=27, fd=31, ev=Event { key: 1, readable: true, writable: false }    
line: 2022-10-28T20:11:16.141524Z TRACE netlink_sys::smol: poll_recv_from: Err(Os { code: 11, kind: WouldBlock, message: "Resource temporarily unavailable" })    
line: 2022-10-28T20:11:16.141597Z TRACE netlink_sys::smol: poll_recv_from: Err(Os { code: 11, kind: WouldBlock, message: "Resource temporarily unavailable" })    
line: 2022-10-28T20:11:16.141666Z TRACE netlink_sys::smol: poll_recv_from: Err(Os { code: 11, kind: WouldBlock, message: "Resource temporarily unavailable" })    
line: 2022-10-28T20:11:16.141742Z TRACE netlink_sys::smol: poll_recv_from: Err(Os { code: 11, kind: WouldBlock, message: "Resource temporarily unavailable" })    

Thereafter the poll_recv_from logs that same line about 10'000 times per second, starving everything else.
It is this loop:

https://github.com/little-dude/netlink/blob/8fc3843dcc5ddc4ece815e3f3df124e196d17dcf/netlink-sys/src/smol.rs#L56-L63

It matches my earlier investigations this year: poll says “I’m ready” while reading says “there’s nothing here!”. Perhaps switching to Tokio solves this — my trust in async-io has sunken below zero.

[rkuhn]

Using #27 I tried it with Tokio, but alas, the behaviour is unchanged:

line: 2022-10-29T09:23:12.402792Z TRACE mio::poll: registering event source with poller: token=Token(0), interests=READABLE    
line: 2022-10-29T09:23:12.402796Z TRACE mio::poll: registering event source with poller: token=Token(0), interests=READABLE    
line: 2022-10-29T09:23:12.404589Z TRACE trust_dns_resolver::async_resolver: handle passed back
line: 2022-10-29T09:23:12.406227Z DEBUG node::node_api: Admin API trying to bind to /ip4/0.0.0.0/tcp/0
line: 2022-10-29T09:23:12.406305Z DEBUG libp2p_tcp: listening on 0.0.0.0:0    
line: 2022-10-29T09:23:12.406390Z TRACE mio::poll: registering event source with poller: token=Token(1), interests=READABLE | WRITABLE    
line: 2022-10-29T09:23:12.406484Z TRACE mio::poll: registering event source with poller: token=Token(2), interests=READABLE | WRITABLE    
line: 2022-10-29T09:23:12.406538Z DEBUG node::node_api: Admin API trying to bind to /ip6/::/tcp/0
line: 2022-10-29T09:23:12.406592Z DEBUG libp2p_tcp: listening on [::]:0    
line: 2022-10-29T09:23:12.406646Z TRACE mio::poll: registering event source with poller: token=Token(3), interests=READABLE | WRITABLE    
line: 2022-10-29T09:23:12.406712Z TRACE mio::poll: registering event source with poller: token=Token(4), interests=READABLE | WRITABLE    
line: 2022-10-29T09:23:12.407023Z TRACE netlink_sys::tokio: poll_recv_from called    
line: 2022-10-29T09:23:12.407221Z TRACE netlink_sys::tokio: poll_recv_from called    
line: 2022-10-29T09:23:12.407364Z TRACE netlink_sys::tokio: poll_recv_from called    
line: 2022-10-29T09:23:12.407394Z TRACE netlink_sys::tokio: poll_recv_from socket is ready for reading    
line: 2022-10-29T09:23:12.407437Z TRACE netlink_sys::tokio: poll_recv_from Ok((348, SocketAddr(nl_family=16, nl_pid=0, nl_groups=0))) bytes read    
line: 2022-10-29T09:23:12.407656Z TRACE netlink_sys::tokio: poll_recv_from called    
line: 2022-10-29T09:23:12.407687Z TRACE netlink_sys::tokio: poll_recv_from socket is ready for reading    
line: 2022-10-29T09:23:12.407721Z TRACE netlink_sys::tokio: poll_recv_from Ok((360, SocketAddr(nl_family=16, nl_pid=0, nl_groups=0))) bytes read    
line: 2022-10-29T09:23:12.407884Z TRACE netlink_sys::tokio: poll_recv_from called    
line: 2022-10-29T09:23:12.407912Z TRACE netlink_sys::tokio: poll_recv_from socket is ready for reading    
line: 2022-10-29T09:23:12.407937Z TRACE netlink_sys::tokio: poll_recv_from Ok((20, SocketAddr(nl_family=16, nl_pid=0, nl_groups=0))) bytes read    
line: 2022-10-29T09:23:12.407992Z TRACE netlink_sys::tokio: poll_recv_from called    
line: 2022-10-29T09:23:12.408017Z TRACE netlink_sys::tokio: poll_recv_from socket is ready for reading    
line: 2022-10-29T09:23:12.408046Z TRACE netlink_sys::tokio: poll_recv_from socket would block    
line: 2022-10-29T09:23:12.408068Z TRACE netlink_sys::tokio: poll_recv_from called    
line: 2022-10-29T09:23:12.408212Z TRACE netlink_sys::tokio: poll_recv_from called    
line: 2022-10-29T09:23:12.408280Z TRACE netlink_sys::tokio: poll_recv_from called    
line: 2022-10-29T09:23:12.408344Z TRACE netlink_sys::tokio: poll_recv_from called    
line: 2022-10-29T09:23:12.408416Z TRACE netlink_sys::tokio: poll_recv_from called    
[ad nauseam]

[rkuhn]

Sorry guys, nothing to see here: I had a poll_fn bug in my own code, leading to immediate wakeup.

The good thing about this wasted day is that I can confirm that the Tokio variant does seem to work nicely.