search

scylladb / scylla-rust-driver

Async CQL driver for Rust, optimized for ScyllaDB!
Apache License 2.0
562 stars 98 forks source link

`if_lwt_optimisation_mark_offered_then_negotiatied_and_lwt_routed_optimally` may be flaky with Cassandra #813

Open piodul opened 12 months ago

piodul commented 12 months ago

It failed twice in an unrelated pull request (https://github.com/scylladb/scylla-rust-driver/pull/808).

Link to logs (attempt 2 and 3 failed): https://github.com/scylladb/scylla-rust-driver/actions/runs/6164271508/job/16967689748

Example:

---- lwt_optimisation::if_lwt_optimisation_mark_offered_then_negotiatied_and_lwt_routed_optimally stdout ----
Unique name: test_rust_1694796250_3
thread 'lwt_optimisation::if_lwt_optimisation_mark_offered_then_negotiatied_and_lwt_routed_optimally' panicked at 'timeout: the function call took 20000 ms. Max time 20000 ms', scylla/tests/integration/lwt_optimisation.rs:16:1
stack backtrace:
   0:     0x558539fceb41 - std::backtrace_rs::backtrace::libunwind::trace::he648b5c8dd376705
                               at /rustc/5680fa18feaa87f3ff04063800aec256c3d4b4be/library/std/src/../../backtrace/src/backtrace/libunwind.rs:93:5
   1:     0x558539fceb41 - std::backtrace_rs::backtrace::trace_unsynchronized::h5da3e203eef39e9f
                               at /rustc/5680fa18feaa87f3ff04063800aec256c3d4b4be/library/std/src/../../backtrace/src/backtrace/mod.rs:66:5
   2:     0x558539fceb41 - std::sys_common::backtrace::_print_fmt::h8d28d3f20588ae4c
                               at /rustc/5680fa18feaa87f3ff04063800aec256c3d4b4be/library/std/src/sys_common/backtrace.rs:65:5
   3:     0x558539fceb41 - <std::sys_common::backtrace::_print::DisplayBacktrace as core::fmt::Display>::fmt::hd9a5b0c9c6b058c0
                               at /rustc/5680fa18feaa87f3ff04063800aec256c3d4b4be/library/std/src/sys_common/backtrace.rs:44:22
   4:     0x558539fff11f - core::fmt::rt::Argument::fmt::h0afc04119f252b53
                               at /rustc/5680fa18feaa87f3ff04063800aec256c3d4b4be/library/core/src/fmt/rt.rs:138:9
   5:     0x558539fff11f - core::fmt::write::h50b1b3e73851a6fe
                               at /rustc/5680fa18feaa87f3ff04063800aec256c3d4b4be/library/core/src/fmt/mod.rs:1094:21
   6:     0x558539fcaf37 - std::io::Write::write_fmt::hbe8ec71df0521cbb
                               at /rustc/5680fa18feaa87f3ff04063800aec256c3d4b4be/library/std/src/io/mod.rs:1714:15
   7:     0x558539fce955 - std::sys_common::backtrace::_print::hf58c3a5a25090e71
                               at /rustc/5680fa18feaa87f3ff04063800aec256c3d4b4be/library/std/src/sys_common/backtrace.rs:47:5
   8:     0x558539fce955 - std::sys_common::backtrace::print::hb9cf0a7c7f077819
                               at /rustc/5680fa18feaa87f3ff04063800aec256c3d4b4be/library/std/src/sys_common/backtrace.rs:34:9
   9:     0x558539fd05e3 - std::panicking::default_hook::{{closure}}::h066adb2e3f3e2c07
                               at /rustc/5680fa18feaa87f3ff04063800aec256c3d4b4be/library/std/src/panicking.rs:269:22
  10:     0x558539fd0300 - std::panicking::default_hook::h277fa2776900ff14
                               at /rustc/5680fa18feaa87f3ff04063800aec256c3d4b4be/library/std/src/panicking.rs:285:9
  11:     0x558539ba4e52 - <alloc::boxed::Box<F,A> as core::ops::function::Fn<Args>>::call::hebadf745f5e9a923
                               at /rustc/5680fa18feaa87f3ff04063800aec256c3d4b4be/library/alloc/src/boxed.rs:2007:9
  12:     0x558539ba4e52 - test::test_main::{{closure}}::hd0fa290055e6f5e1
                               at /rustc/5680fa18feaa87f3ff04063800aec256c3d4b4be/library/test/src/lib.rs:135:21
  13:     0x558539fd0cde - <alloc::boxed::Box<F,A> as core::ops::function::Fn<Args>>::call::h09cad52ea08435f2
                               at /rustc/5680fa18feaa87f3ff04063800aec256c3d4b4be/library/alloc/src/boxed.rs:2007:9
  14:     0x558539fd0cde - std::panicking::rust_panic_with_hook::hceaf38da6d9db792
                               at /rustc/5680fa18feaa87f3ff04063800aec256c3d4b4be/library/std/src/panicking.rs:709:13
  15:     0x558539fd0a67 - std::panicking::begin_panic_handler::{{closure}}::h2bce3ed2516af7df
                               at /rustc/5680fa18feaa87f3ff04063800aec256c3d4b4be/library/std/src/panicking.rs:597:13
  16:     0x558539fcefa6 - std::sys_common::backtrace::__rust_end_short_backtrace::h090f3faf8f98a395
                               at /rustc/5680fa18feaa87f3ff04063800aec256c3d4b4be/library/std/src/sys_common/backtrace.rs:151:18
  17:     0x558539fd07b2 - rust_begin_unwind
                               at /rustc/5680fa18feaa87f3ff04063800aec256c3d4b4be/library/std/src/panicking.rs:593:5
  18:     0x558539495c43 - core::panicking::panic_fmt::h4ec8274704d163a3
                               at /rustc/5680fa18feaa87f3ff04063800aec256c3d4b4be/library/core/src/panicking.rs:67:14
  19:     0x55853962e4d7 - integration::lwt_optimisation::if_lwt_optimisation_mark_offered_then_negotiatied_and_lwt_routed_optimally::h7ce9b1aebbaa6be5
                               at /home/runner/work/scylla-rust-driver/scylla-rust-driver/scylla/tests/integration/lwt_optimisation.rs:16:1
  20:     0x5585394afaf7 - integration::lwt_optimisation::if_lwt_optimisation_mark_offered_then_negotiatied_and_lwt_routed_optimally::{{closure}}::h0e293c4ec1074455
                               at /home/runner/work/scylla-rust-driver/scylla-rust-driver/scylla/tests/integration/lwt_optimisation.rs:18:87
  21:     0x558539792945 - core::ops::function::FnOnce::call_once::h854579c0097f24d1
                               at /rustc/5680fa18feaa87f3ff04063800aec256c3d4b4be/library/core/src/ops/function.rs:250:5
  22:     0x558539baa06f - core::ops::function::FnOnce::call_once::h48e05de01475cffa
                               at /rustc/5680fa18feaa87f3ff04063800aec256c3d4b4be/library/core/src/ops/function.rs:250:5
  23:     0x558539baa06f - test::__rust_begin_short_backtrace::h6f768fb9c89e0ae1
                               at /rustc/5680fa18feaa87f3ff04063800aec256c3d4b4be/library/test/src/lib.rs:626:18
  24:     0x558539ba9097 - test::run_test_in_process::{{closure}}::h626f15ef40d33b22
                               at /rustc/5680fa18feaa87f3ff04063800aec256c3d4b4be/library/test/src/lib.rs:649:60
  25:     0x558539ba9097 - <core::panic::unwind_safe::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once::hc7c1f9553db7812d
                               at /rustc/5680fa18feaa87f3ff04063800aec256c3d4b4be/library/core/src/panic/unwind_safe.rs:271:9
  26:     0x558539ba9097 - std::panicking::try::do_call::hf33f8ddbb41f511f
                               at /rustc/5680fa18feaa87f3ff04063800aec256c3d4b4be/library/std/src/panicking.rs:500:40
  27:     0x558539ba9097 - std::panicking::try::h2e44572c16e4d548
                               at /rustc/5680fa18feaa87f3ff04063800aec256c3d4b4be/library/std/src/panicking.rs:464:19
  28:     0x558539ba9097 - std::panic::catch_unwind::h6094e97c72a2b294
                               at /rustc/5680fa18feaa87f3ff04063800aec256c3d4b4be/library/std/src/panic.rs:142:14
  29:     0x558539ba9097 - test::run_test_in_process::h4690d697fe09c97c
                               at /rustc/5680fa18feaa87f3ff04063800aec256c3d4b4be/library/test/src/lib.rs:649:27
  30:     0x558539ba9097 - test::run_test::{{closure}}::hb7ea0d3d94d9d223
                               at /rustc/5680fa18feaa87f3ff04063800aec256c3d4b4be/library/test/src/lib.rs:572:43
  31:     0x558539b6ff5f - test::run_test::{{closure}}::h05235221b85ccf60
                               at /rustc/5680fa18feaa87f3ff04063800aec256c3d4b4be/library/test/src/lib.rs:600:41
  32:     0x558539b6ff5f - std::sys_common::backtrace::__rust_begin_short_backtrace::h31b2f9bcfe4d7d74
                               at /rustc/5680fa18feaa87f3ff04063800aec256c3d4b4be/library/std/src/sys_common/backtrace.rs:135:18
  33:     0x558539b75acf - std::thread::Builder::spawn_unchecked_::{{closure}}::{{closure}}::h38bd627c42e6932c
                               at /rustc/5680fa18feaa87f3ff04063800aec256c3d4b4be/library/std/src/thread/mod.rs:529:17
  34:     0x558539b75acf - <core::panic::unwind_safe::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once::h7a939712f8af1464
                               at /rustc/5680fa18feaa87f3ff04063800aec256c3d4b4be/library/core/src/panic/unwind_safe.rs:271:9
  35:     0x558539b75acf - std::panicking::try::do_call::h6ef55747c96d66d9
                               at /rustc/5680fa18feaa87f3ff04063800aec256c3d4b4be/library/std/src/panicking.rs:500:40
  36:     0x558539b75acf - std::panicking::try::hac89413dd547f4ca
                               at /rustc/5680fa18feaa87f3ff04063800aec256c3d4b4be/library/std/src/panicking.rs:464:19
  37:     0x558539b75acf - std::panic::catch_unwind::h26bd382c5a7e8184
                               at /rustc/5680fa18feaa87f3ff04063800aec256c3d4b4be/library/std/src/panic.rs:142:14
  38:     0x558539b75acf - std::thread::Builder::spawn_unchecked_::{{closure}}::h9f1648b0596869e2
                               at /rustc/5680fa18feaa87f3ff04063800aec256c3d4b4be/library/std/src/thread/mod.rs:528:30
  39:     0x558539b75acf - core::ops::function::FnOnce::call_once{{vtable.shim}}::h1e338cfcfd8dc720
                               at /rustc/5680fa18feaa87f3ff04063800aec256c3d4b4be/library/core/src/ops/function.rs:250:5
  40:     0x558539fd5305 - <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once::hc0b1022758ecac73
                               at /rustc/5680fa18feaa87f3ff04063800aec256c3d4b4be/library/alloc/src/boxed.rs:1993:9
  41:     0x558539fd5305 - <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once::h0c9654ebe7ad657e
                               at /rustc/5680fa18feaa87f3ff04063800aec256c3d4b4be/library/alloc/src/boxed.rs:1993:9
  42:     0x558539fd5305 - std::sys::unix::thread::Thread::new::thread_start::h04c8e9c7d83d3bd5
                               at /rustc/5680fa18feaa87f3ff04063800aec256c3d4b4be/library/std/src/sys/unix/thread.rs:108:17
  43:     0x7ffb46a94b43 - <unknown>
  44:     0x7ffb46b26a00 - <unknown>
  45:                0x0 - <unknown>

failures:
    lwt_optimisation::if_lwt_optimisation_mark_offered_then_negotiatied_and_lwt_routed_optimally

The test has a timeout set, so maybe it's not enough - but it's not that small (20s) and didn't seem to fail before the mentioned PR.

mykaul commented 9 months ago

Failed again @ https://github.com/scylladb/scylla-rust-driver/actions/runs/7151594195/job/19476066249?pr=876

Lorak-mmk commented 6 months ago

Failes for Scylla once after unrelated change: https://github.com/scylladb/scylla-rust-driver/actions/runs/8251660910/job/22569250953