rust-libp2p: Panic in `libp2p-websocket` at 'SinkImpl::poll_ready called after error.'

Mar 24 02:52:40 ip-172-31-13-88 nimiq-client[36147]:    0: log_panics::init::{{closure}}
Mar 24 02:52:40 ip-172-31-13-88 nimiq-client[36147]:    1: std::panicking::rust_panic_with_hook
Mar 24 02:52:40 ip-172-31-13-88 nimiq-client[36147]:              at /rustc/3c17c84a386e7badf6b2c6018d172496b3a28a04/library/std/src/panicking.rs:702:17
Mar 24 02:52:40 ip-172-31-13-88 nimiq-client[36147]:    2: std::panicking::begin_panic::{{closure}}
Mar 24 02:52:40 ip-172-31-13-88 nimiq-client[36147]:    3: std::sys_common::backtrace::__rust_end_short_backtrace
Mar 24 02:52:40 ip-172-31-13-88 nimiq-client[36147]:    4: std::panicking::begin_panic
Mar 24 02:52:40 ip-172-31-13-88 nimiq-client[36147]:    5: <quicksink::SinkImpl<S,F,T,A,E> as futures_sink::Sink<A>>::poll_ready
Mar 24 02:52:40 ip-172-31-13-88 nimiq-client[36147]:    6: <rw_stream_sink::RwStreamSink<S> as futures_io::if_std::AsyncWrite>::poll_write
Mar 24 02:52:40 ip-172-31-13-88 nimiq-client[36147]:    7: <multistream_select::negotiated::Negotiated<TInner> as futures_io::if_std::AsyncWrite>::poll_write
Mar 24 02:52:40 ip-172-31-13-88 nimiq-client[36147]:    8: <libp2p_noise::io::framed::NoiseFramed<T,S> as futures_sink::Sink<&alloc::vec::Vec<u8>>>::poll_ready
Mar 24 02:52:40 ip-172-31-13-88 nimiq-client[36147]:    9: <libp2p_noise::io::framed::NoiseFramed<T,S> as futures_sink::Sink<&alloc::vec::Vec<u8>>>::poll_flush
Mar 24 02:52:40 ip-172-31-13-88 nimiq-client[36147]:   10: <libp2p_noise::io::NoiseOutput<T> as futures_io::if_std::AsyncWrite>::poll_flush
Mar 24 02:52:40 ip-172-31-13-88 nimiq-client[36147]:   11: multistream_select::negotiated::Negotiated<TInner>::poll
Mar 24 02:52:40 ip-172-31-13-88 nimiq-client[36147]:   12: <multistream_select::negotiated::Negotiated<TInner> as futures_io::if_std::AsyncWrite>::poll_close
Mar 24 02:52:40 ip-172-31-13-88 nimiq-client[36147]:   13: <core::future::from_generator::GenFuture<T> as core::future::future::Future>::poll
Mar 24 02:52:40 ip-172-31-13-88 nimiq-client[36147]:   14: <S as futures_core::stream::TryStream>::try_poll_next
Mar 24 02:52:40 ip-172-31-13-88 nimiq-client[36147]:   15: <futures_util::stream::try_stream::ErrInto<St,E> as futures_core::stream::Stream>::poll_next
Mar 24 02:52:40 ip-172-31-13-88 nimiq-client[36147]:   16: <libp2p_yamux::Yamux<S> as libp2p_core::muxing::StreamMuxer>::close
Mar 24 02:52:40 ip-172-31-13-88 nimiq-client[36147]:   17: <libp2p_core::muxing::Wrap<T> as libp2p_core::muxing::StreamMuxer>::close
Mar 24 02:52:40 ip-172-31-13-88 nimiq-client[36147]:   18: <core::future::from_generator::GenFuture<T> as core::future::future::Future>::poll
Mar 24 02:52:40 ip-172-31-13-88 nimiq-client[36147]:   19: tokio::runtime::task::harness::poll_future
Mar 24 02:52:40 ip-172-31-13-88 nimiq-client[36147]:   20: tokio::runtime::task::harness::Harness<T,S>::poll
Mar 24 02:52:40 ip-172-31-13-88 nimiq-client[36147]:   21: std::thread::local::LocalKey<T>::with
Mar 24 02:52:40 ip-172-31-13-88 nimiq-client[36147]:   22: tokio::runtime::thread_pool::worker::Context::run_task
Mar 24 02:52:40 ip-172-31-13-88 nimiq-client[36147]:   23: tokio::runtime::thread_pool::worker::Context::run
Mar 24 02:52:40 ip-172-31-13-88 nimiq-client[36147]:   24: tokio::macros::scoped_tls::ScopedKey<T>::set
Mar 24 02:52:40 ip-172-31-13-88 nimiq-client[36147]:   25: tokio::runtime::thread_pool::worker::run
Mar 24 02:52:40 ip-172-31-13-88 nimiq-client[36147]:   26: tokio::runtime::task::harness::Harness<T,S>::poll
Mar 24 02:52:40 ip-172-31-13-88 nimiq-client[36147]:   27: tokio::runtime::blocking::pool::Inner::run
Mar 24 02:52:40 ip-172-31-13-88 nimiq-client[36147]:   28: std::sys_common::backtrace::__rust_begin_short_backtrace
Mar 24 02:52:40 ip-172-31-13-88 nimiq-client[36147]:   29: core::ops::function::FnOnce::call_once{{vtable.shim}}
Mar 24 02:52:40 ip-172-31-13-88 nimiq-client[36147]:   30: <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once
Mar 24 02:52:40 ip-172-31-13-88 nimiq-client[36147]:              at /rustc/3c17c84a386e7badf6b2c6018d172496b3a28a04/library/alloc/src/boxed.rs:1853:9
Mar 24 02:52:40 ip-172-31-13-88 nimiq-client[36147]:       <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once
Mar 24 02:52:40 ip-172-31-13-88 nimiq-client[36147]:              at /rustc/3c17c84a386e7badf6b2c6018d172496b3a28a04/library/alloc/src/boxed.rs:1853:9
Mar 24 02:52:40 ip-172-31-13-88 nimiq-client[36147]:       std::sys::unix::thread::Thread::new::thread_start
Mar 24 02:52:40 ip-172-31-13-88 nimiq-client[36147]:              at /rustc/3c17c84a386e7badf6b2c6018d172496b3a28a04/library/std/src/sys/unix/thread.rs:108:17
Mar 24 02:52:40 ip-172-31-13-88 nimiq-client[36147]:   31: start_thread
Mar 24 02:52:40 ip-172-31-13-88 nimiq-client[36147]:   32: clone

I don’t know how to reproduce the bug, but it seemed likely to be fixable without reproduction.

CC https://github.com/nimiq/core-rs-albatross/issues/732

About this issue

Original URL
State: closed
Created 2 years ago
Comments: 24 (20 by maintainers)

Commits related to this issue

Don't panic in libp2p-websocket Return an error instead. `quicksink` panics if you call a method after it returned an error once. Fixes #2598. — committed to hrxi/rust-libp2p by hrxi 2 years ago
src/connection: Return error from next_frame Future early > The `frame` future might be _ready_ with an `Error` from the underlying socket (i.e. here `libp2p-websocket`). Though given that the result... — committed to mxinden/rust-yamux by mxinden 2 years ago
src/connection: Process command or socket result immediately > The `frame` future might be _ready_ with an `Error` from the underlying socket (i.e. here `libp2p-websocket`). Though given that the res... — committed to mxinden/rust-yamux by mxinden 2 years ago
src/connection: Process command or socket result immediately (#138) > The `frame` future might be _ready_ with an `Error` from the underlying socket (i.e. here `libp2p-websocket`). Though given that... — committed to libp2p/rust-yamux by mxinden 2 years ago
Upgrade yamux for https://github.com/libp2p/rust-libp2p/issues/2598 — committed to Phala-Network/khala-parachain by jasl 2 years ago
src/connection: Process command or socket result immediately (#138) > The `frame` future might be _ready_ with an `Error` from the underlying socket (i.e. here `libp2p-websocket`). Though given that... — committed to RubyOnWorld/rust-yamux by ben07ab 2 years ago
Update the `yamux` dependency Update the `yamux` dependency from version 0.10.1 to version 0.10.2 to pull a fix for a call to `SinkImpl::poll_ready` after error as described in [this rust-libp2p issu... — committed to nimiq/core-rs-albatross by jsdanielh a year ago
Update the `yamux` dependency (#1368) Update the `yamux` dependency from version 0.10.1 to version 0.10.2 to pull a fix for a call to `SinkImpl::poll_ready` after error as described in [this rust-l... — committed to nimiq/core-rs-albatross by jsdanielh a year ago

Most upvoted comments

Will try to prepare a proper patch for yamux tomorrow. This can be released as patch release, i.e. yamux v0.10.2 and thus only needs an update in the Polkadot Cargo.lock.

mxinden on Aug 3, 2022

@mxinden Thanks for helping, here are the logs with 10 seconds before: https://we.tl/t-6TuATzVqV4

NZT48 on Jul 27, 2022

Running nearly a day with patched binaries, haven’t crash yet

jasl on Aug 2, 2022

@NZT48 @hrxi @jasl @doutv

It would be very helpful to get more logs right before (~10 seconds) a crash like the one above. Any chance one of you can provide a log output on debug level RUST_LOG=debug with the logs 10 seconds before up until the crash?

mxinden on Jul 27, 2022

there is no need to update libp2p

Still the yamux dep in libp2p needs to be increased in order to force people to download the new version upon upgrade.

I would expect downstream users to use tools like @dependabot and thus keeping their dependencies up to date. That said, I am happy to merge a pull request updating the yamux version in the libp2p-yamux crate.

mxinden on Aug 8, 2022

libp2p/rust-yamux#138 is reviewed and approved thanks to @elenaf9 and @thomaseizinger. @jasl once I get the green light from you, I will cut a release.

Great! I can’t wait

Just to make sure, do I understand correctly that you ran https://github.com/libp2p/rust-yamux/pull/138 and that you are not seeing any panics @jasl?

BTW, could you help to backport the upgrade to polkadot-v0.9.27 ?

I can not, as I am no longer directly involved in the project. Maybe @kpp or @bkchr can help with the backport.

No need to backport this. Parachains can just run cargo update -p yamux to get the latest version of the crate. As this is nothing critical and doesn’t happen that often there is no need for a full polkadot release. It can wait and go into the next polkadot release.

bkchr on Aug 5, 2022

libp2p/rust-yamux#138 is reviewed and approved thanks to @elenaf9 and @thomaseizinger. @jasl once I get the green light from you, I will cut a release.

Great! I can’t wait

Just to make sure, do I understand correctly that you ran libp2p/rust-yamux#138 and that you are not seeing any panics @jasl?

BTW, could you help to backport the upgrade to polkadot-v0.9.27 ?

I can not, as I am no longer directly involved in the project. Maybe @kpp or @bkchr can help with the backport.

For a night I don’t see panic

jasl on Aug 5, 2022

@NZT48 @jasl those are wonderful news. Would you mind keeping those deployments running for a bit longer, just to make sure?

mxinden on Aug 2, 2022

@NZT48 @hrxi @jasl @doutv @kpp

Would very much appreciate help testing https://github.com/libp2p/rust-yamux/pull/137. Instructions are in the pull request description.

mxinden on Aug 1, 2022