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

Use of FuturesUnorderedmay prevent SwarmFuture from making progress. #190

Closed
twittner opened this issue May 16, 2018 · 0 comments
Closed
Assignees
Labels
priority:important The changes needed are critical for libp2p, or are blocking another project

Comments

@twittner
Copy link
Contributor

twittner commented May 16, 2018

PR #163 replaced various uses of vectors of futures with FuturesUnordereds and PR #169 wanted to revert those changes because the change resulted in problems, namely that SwarmFuture could stall. One example is starting the echo-server example, connecting to it and disconnecting again, without sending valid data:

TRACE 2018-05-09T15:46:10Z: mio::poll: registering with poller
TRACE 2018-05-09T15:46:10Z: tokio_threadpool::builder: build; num-workers=8
DEBUG 2018-05-09T15:46:10Z: tokio_reactor::background: starting background reactor
TRACE 2018-05-09T15:46:10Z: mio::poll: registering with poller
DEBUG 2018-05-09T15:46:10Z: libp2p_tcp_transport: Now listening on /ip4/0.0.0.0/tcp/10333
TRACE 2018-05-09T15:46:10Z: libp2p_swarm::swarm: Swarm listening on /ip4/0.0.0.0/tcp/10333
Now listening on "/ip4/0.0.0.0/tcp/10333"
DEBUG 2018-05-09T15:46:10Z: tokio_core::reactor: consuming notification queue
DEBUG 2018-05-09T15:46:10Z: tokio_core::reactor: loop poll - Duration { secs: 0, nanos: 46334 }
DEBUG 2018-05-09T15:46:10Z: tokio_core::reactor: loop time - Instant { tv_sec: 26326, tv_nsec: 680689193 }
DEBUG 2018-05-09T15:46:10Z: tokio_core::reactor: loop process, Duration { secs: 0, nanos: 69532 }
# first `echo "" | nc localhost 10333` from a separate console
TRACE 2018-05-09T15:46:31Z: tokio_reactor: event Readable Token(0)
DEBUG 2018-05-09T15:46:31Z: tokio_reactor: loop process - 1 events, 0.000s
DEBUG 2018-05-09T15:46:31Z: tokio_core::reactor: loop poll - Duration { secs: 20, nanos: 709840848 }
DEBUG 2018-05-09T15:46:31Z: tokio_core::reactor: loop time - Instant { tv_sec: 26347, tv_nsec: 390631598 }
DEBUG 2018-05-09T15:46:31Z: tokio_core::reactor: loop process, Duration { secs: 0, nanos: 92083 }
DEBUG 2018-05-09T15:46:31Z: libp2p_tcp_transport: Incoming connection from /ip4/127.0.0.1/tcp/54306
DEBUG 2018-05-09T15:46:31Z: libp2p_swarm::transport::upgrade: Starting protocol negotiation (listener)
TRACE 2018-05-09T15:46:31Z: mio::poll: registering with poller
TRACE 2018-05-09T15:46:31Z: tokio_reactor: event Readable | Writable Token(4194305)
DEBUG 2018-05-09T15:46:31Z: tokio_reactor: loop process - 1 events, 0.000s
DEBUG 2018-05-09T15:46:31Z: tokio_core::reactor: loop poll - Duration { secs: 0, nanos: 106871 }
DEBUG 2018-05-09T15:46:31Z: tokio_core::reactor: loop time - Instant { tv_sec: 26347, tv_nsec: 391297053 }
DEBUG 2018-05-09T15:46:31Z: tokio_core::reactor: loop process, Duration { secs: 0, nanos: 74241 }
# CTRL-C the connection
TRACE 2018-05-09T15:46:46Z: tokio_reactor: event Readable | Writable | Hup Token(4194305)
DEBUG 2018-05-09T15:46:46Z: tokio_reactor: loop process - 1 events, 0.000s
DEBUG 2018-05-09T15:46:46Z: tokio_core::reactor: loop poll - Duration { secs: 15, nanos: 152174476 }
DEBUG 2018-05-09T15:46:46Z: tokio_core::reactor: loop time - Instant { tv_sec: 26362, tv_nsec: 543692607 }
DEBUG 2018-05-09T15:46:46Z: tokio_core::reactor: loop process, Duration { secs: 0, nanos: 192847 }
TRACE 2018-05-09T15:46:46Z: mio::poll: deregistering handle with poller
DEBUG 2018-05-09T15:46:46Z: tokio_reactor: dropping I/O source: 1
DEBUG 2018-05-09T15:46:46Z: libp2p_swarm::transport::upgrade: Error while negotiated protocol upgrade: Custom { kind: Other, error: MultistreamSelectError(IoError(Custom { kind: BrokenPipe, error: StringError("unexpected eof") })) }
DEBUG 2018-05-09T15:46:46Z: libp2p_swarm::connection_reuse: error while upgrading listener connection: Custom { kind: Other, error: MultistreamSelectError(IoError(Custom { kind: BrokenPipe, error: StringError("unexpected eof") })) }
TRACE 2018-05-09T15:46:46Z: libp2p_swarm::swarm: Swarm received new connection on listener socket
 WARN 2018-05-09T15:46:46Z: libp2p_swarm::swarm: Error in listener upgrade: Custom { kind: Other, error: MultistreamSelectError(IoError(Custom { kind: BrokenPipe, error: StringError("unexpected eof") })) }
# second `echo "" | nc localhost 10333`from a separate console
TRACE 2018-05-09T15:47:11Z: tokio_reactor: event Readable Token(0)
DEBUG 2018-05-09T15:47:11Z: tokio_reactor: loop process - 1 events, 0.000s
# second CTRL-C
# third `echo "" | nc localhost 10333` from a separate console
TRACE 2018-05-09T15:47:35Z: tokio_reactor: event Readable Token(0)
DEBUG 2018-05-09T15:47:35Z: tokio_reactor: loop process - 1 events, 0.000s
# third CTRL-C
# and so on ...

AFAICT this is because notifications of tasks of Futures that have been added to FuturesUnordered will not be propagated until FuturesUnordered::poll is called. Presumably this problem does not always show up on the happy path because more notifications trigger SwarmFuture::poll which in turn polls FuturesUnordered.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
priority:important The changes needed are critical for libp2p, or are blocking another project
Projects
None yet
Development

No branches or pull requests

2 participants