Debug assertion triggered in read_line_internal when using BufReader with TcpStream.

[artemii235]

Version

└── tokio v0.2.20

Platforms

Darwin 19.0.0 Darwin Kernel Version 19.0.0: Wed Sep 25 20:18:50 PDT 2019; root:xnu-6153.11.26~2/RELEASE_X86_64 x86_64

Linux 4.4.0-116-generic #140-Ubuntu SMP Mon Feb 12 21:23:04 UTC 2018 x86_64 x86_64 x86_64 GNU/Linux

Subcrates

io_util

Description

I've started using tokio recently for simple TCP floodsub server and noticed panics triggered by debug_assertion in read_line_internal, after some research I found out the quite strange conditions of the panic to occur:

1. Clients should connect quite often.
2. Clients should send the payload that has something after \n.
3. Clients should not read anything from server (while server sends them something).
4. And then clients should disconnect.

Here is the project that recreates the panic condition: https://github.com/artemii235/bufreader-debug-assert, the RUST_BACKTRACE=full cargo run should recreate the panic and print the following at least on platforms mentioned above:

Hello

thread 'main' panicked at 'assertion failed: `(left == right)`
  left: `1`,
 right: `0`', <::std::macros::panic macros>:5:6
stack backtrace:
   0:     0x559f2024a5c8 - backtrace::backtrace::libunwind::trace::ha50d6e1700b0eb2c
                               at /cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.40/src/backtrace/libunwind.rs:88
   1:     0x559f2024a5c8 - backtrace::backtrace::trace_unsynchronized::hed6300b0e8a8d34c
                               at /cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.40/src/backtrace/mod.rs:66
   2:     0x559f2024a5c8 - std::sys_common::backtrace::_print_fmt::h02d8d6e59c4a6ffd
                               at src/libstd/sys_common/backtrace.rs:77
   3:     0x559f2024a5c8 - <std::sys_common::backtrace::_print::DisplayBacktrace as core::fmt::Display>::fmt::h1f642adc5bdda227
                               at src/libstd/sys_common/backtrace.rs:59
   4:     0x559f20264f7c - core::fmt::write::h3f76f88b1fce4812
                               at src/libcore/fmt/mod.rs:1052
   5:     0x559f202449a7 - std::io::Write::write_fmt::hbb03ae82f9cef6e9
                               at src/libstd/io/mod.rs:1428
   6:     0x559f2024cc95 - std::sys_common::backtrace::_print::h21ddaa53463c7888
                               at src/libstd/sys_common/backtrace.rs:62
   7:     0x559f2024cc95 - std::sys_common::backtrace::print::h335952ea8eeb247c
                               at src/libstd/sys_common/backtrace.rs:49
   8:     0x559f2024cc95 - std::panicking::default_hook::{{closure}}::hf030245da7008606
                               at src/libstd/panicking.rs:204
   9:     0x559f2024c9d6 - std::panicking::default_hook::hf0ffbda78fb7d847
                               at src/libstd/panicking.rs:224
  10:     0x559f2024d2f2 - std::panicking::rust_panic_with_hook::hb1798496edc01b7d
                               at src/libstd/panicking.rs:472
  11:     0x559f2024cedb - rust_begin_unwind
                               at src/libstd/panicking.rs:380
  12:     0x559f2024ce4b - std::panicking::begin_panic_fmt::h812006ce7b41eb9a
                               at src/libstd/panicking.rs:334
  13:     0x559f20173cd6 - tokio::io::util::read_line::read_line_internal::h03a8ae069e75113b
                               at /root/bufreader-debug-assert/<::std::macros::panic macros>:5
  14:     0x559f20173f93 - <tokio::io::util::read_line::ReadLine<R> as core::future::future::Future>::poll::hc0d6099170a78e28
                               at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-0.2.20/src/io/util/read_line.rs:69
  15:     0x559f201627d4 - std::future::poll_with_tls_context::ha4004cd871cbd55f
                               at /rustc/cd1ef390e731ed77b90b11b1f77e2c5ca641b261/src/libstd/future.rs:98
  16:     0x559f20174132 - rust_test_project::server_loop::{{closure}}::{{closure}}::hace6319425ae031c
                               at src/main.rs:34
  17:     0x559f201633ca - <std::future::GenFuture<T> as core::future::future::Future>::poll::h3e4cc848533677cc
                               at /rustc/cd1ef390e731ed77b90b11b1f77e2c5ca641b261/src/libstd/future.rs:43
  18:     0x559f20178f41 - <core::pin::Pin<P> as core::future::future::Future>::poll::hd55dd94dc8792d1c
                               at /rustc/cd1ef390e731ed77b90b11b1f77e2c5ca641b261/src/libcore/future/future.rs:119
  19:     0x559f20178185 - futures_util::future::future::FutureExt::poll_unpin::hccf1112af0393497
                               at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/futures-util-0.3.5/src/future/future/mod.rs:554
  20:     0x559f201698cc - <futures_util::future::select::Select<A,B> as core::future::future::Future>::poll::h7c84e46ad952c0fb
                               at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/futures-util-0.3.5/src/future/select.rs:62
  21:     0x559f2017a2f7 - tokio::runtime::task::core::Core<T,S>::poll::{{closure}}::hcf9c9f7b11ed88de
                               at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-0.2.20/src/runtime/task/core.rs:173
  22:     0x559f2016fb54 - tokio::loom::std::unsafe_cell::UnsafeCell<T>::with_mut::hbda3695f6f7d0033
                               at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-0.2.20/src/loom/std/unsafe_cell.rs:14
  23:     0x559f20179eee - tokio::runtime::task::core::Core<T,S>::poll::h31959bfc796b57e3
                               at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-0.2.20/src/runtime/task/core.rs:158
  24:     0x559f2016dd1e - tokio::runtime::task::harness::Harness<T,S>::poll::{{closure}}::h44de740920e4edaa
                               at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-0.2.20/src/runtime/task/harness.rs:113
  25:     0x559f2015e440 - core::ops::function::FnOnce::call_once::h4e40672fb3e7318c
                               at /rustc/cd1ef390e731ed77b90b11b1f77e2c5ca641b261/src/libcore/ops/function.rs:232
  26:     0x559f2016fdc5 - <std::panic::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once::h0506429d53d5f1da
                               at /rustc/cd1ef390e731ed77b90b11b1f77e2c5ca641b261/src/libstd/panic.rs:318
  27:     0x559f20161578 - std::panicking::try::do_call::h0f6e471c385a8115
                               at /rustc/cd1ef390e731ed77b90b11b1f77e2c5ca641b261/src/libstd/panicking.rs:305
  28:     0x559f20250297 - __rust_maybe_catch_panic
                               at src/libpanic_unwind/lib.rs:86
  29:     0x559f20161127 - std::panicking::try::h285464372539e977
                               at /rustc/cd1ef390e731ed77b90b11b1f77e2c5ca641b261/src/libstd/panicking.rs:281
  30:     0x559f2016fec4 - std::panic::catch_unwind::hcf1f62cd06553345
                               at /rustc/cd1ef390e731ed77b90b11b1f77e2c5ca641b261/src/libstd/panic.rs:394
  31:     0x559f2016d09f - tokio::runtime::task::harness::Harness<T,S>::poll::h44f2a68a1418d506
                               at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-0.2.20/src/runtime/task/harness.rs:89
  32:     0x559f2015ce42 - tokio::runtime::task::raw::poll::hd9b5282e30eb1bcc
                               at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-0.2.20/src/runtime/task/raw.rs:104
  33:     0x559f201ab794 - tokio::runtime::task::raw::RawTask::poll::hc1bad240ef91afa8
                               at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-0.2.20/src/runtime/task/raw.rs:66
  34:     0x559f20172311 - tokio::runtime::task::Notified<S>::run::h2975eaefea4bad9d
                               at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-0.2.20/src/runtime/task/mod.rs:169
  35:     0x559f201687fe - tokio::runtime::basic_scheduler::BasicScheduler<P>::block_on::{{closure}}::{{closure}}::h7c143a1b25589e96
                               at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-0.2.20/src/runtime/basic_scheduler.rs:155
  36:     0x559f201601ae - tokio::coop::budget::{{closure}}::h99dffbef9f5db590
                               at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-0.2.20/src/coop.rs:97
  37:     0x559f20171836 - std::thread::local::LocalKey<T>::try_with::hac99e65da29d8ef3
                               at /rustc/cd1ef390e731ed77b90b11b1f77e2c5ca641b261/src/libstd/thread/local.rs:262
  38:     0x559f2017056d - std::thread::local::LocalKey<T>::with::h7772bb127bb470c9
                               at /rustc/cd1ef390e731ed77b90b11b1f77e2c5ca641b261/src/libstd/thread/local.rs:239
  39:     0x559f20168491 - tokio::coop::budget::hde63e99f6cd816d9
                               at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-0.2.20/src/coop.rs:79
  40:     0x559f20168491 - tokio::runtime::basic_scheduler::BasicScheduler<P>::block_on::{{closure}}::h73c67c03b2ccc021
                               at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-0.2.20/src/runtime/basic_scheduler.rs:155
  41:     0x559f20168c02 - tokio::runtime::basic_scheduler::enter::{{closure}}::h518d603306b65a8c
                               at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-0.2.20/src/runtime/basic_scheduler.rs:213
  42:     0x559f201618e1 - tokio::macros::scoped_tls::ScopedKey<T>::set::h02358c663b943ef3
                               at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-0.2.20/src/macros/scoped_tls.rs:64
  43:     0x559f20168add - tokio::runtime::basic_scheduler::enter::h26e3231e60ff9ffd
                               at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-0.2.20/src/runtime/basic_scheduler.rs:213
  44:     0x559f20167e5b - tokio::runtime::basic_scheduler::BasicScheduler<P>::block_on::h0081d634cf8062ba
                               at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-0.2.20/src/runtime/basic_scheduler.rs:123
  45:     0x559f2015e255 - tokio::runtime::Runtime::block_on::{{closure}}::h6d63211813ea419e
                               at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-0.2.20/src/runtime/mod.rs:444
  46:     0x559f20160d03 - tokio::runtime::context::enter::h70c49e56a987f8b7
                               at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-0.2.20/src/runtime/context.rs:72
  47:     0x559f2015dd02 - tokio::runtime::handle::Handle::enter::hc1261c3046192584
                               at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-0.2.20/src/runtime/handle.rs:71
  48:     0x559f2015e1b3 - tokio::runtime::Runtime::block_on::hfb8e59a02671c550
                               at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-0.2.20/src/runtime/mod.rs:441
  49:     0x559f2015e07a - rust_test_project::main::h516952b98299e52e
                               at src/main.rs:83
  50:     0x559f20161820 - std::rt::lang_start::{{closure}}::hc76260bd93b6fe0d
                               at /rustc/cd1ef390e731ed77b90b11b1f77e2c5ca641b261/src/libstd/rt.rs:67
  51:     0x559f2024cdb3 - std::rt::lang_start_internal::{{closure}}::hb1efcf7be50ae55e
                               at src/libstd/rt.rs:52
  52:     0x559f2024cdb3 - std::panicking::try::do_call::hef11fa8f14cd83c3
                               at src/libstd/panicking.rs:305
  53:     0x559f20250297 - __rust_maybe_catch_panic
                               at src/libpanic_unwind/lib.rs:86
  54:     0x559f2024d799 - std::panicking::try::ha3584cdf5598cf9a
                               at src/libstd/panicking.rs:281
  55:     0x559f2024d799 - std::panic::catch_unwind::hddd01adf3768858e
                               at src/libstd/panic.rs:394
  56:     0x559f2024d799 - std::rt::lang_start_internal::h757ff191005d952d
                               at src/libstd/rt.rs:51
  57:     0x559f201617f9 - std::rt::lang_start::hfda535fe79058002
                               at /rustc/cd1ef390e731ed77b90b11b1f77e2c5ca641b261/src/libstd/rt.rs:67
  58:     0x559f2015e15a - main
  59:     0x7f605af69830 - __libc_start_main
  60:     0x559f2015ca29 - _start
  61:                0x0 - <unknown>
Hello

[Darksonn]

I assume it hit this assert. To reach that line, it must have gone through this line, which requires read_until_internal to return Poll::Ready.

One place that can return Poll::Ready is this line

return Poll::Ready(Ok(mem::replace(read, 0)));

which leaves a zero in read, which means it should not trigger the assert.

The other possibility is the question mark on this line returning an error through this Try impl. This appears plausible. I guess it should handle failures halfway through better.