Unexpected behavior of tarantool::cbus::unbounded::tests::unbounded_mpsc_test

Never seen this error before. Can you provide a configuration (rustc version, tarantool version, os, etc) and the way for reproduce (seems i don’t fully understand what “completely rebuild” means, you run cargo test without build?)

Sorry for long response, missed the notification

Just reproduced the error. Maybe thats something to do with my build

Rustc version is 1.72, I'm running tests on Fedora 37.

tarantool version is the one that is picodata repository is pointing to (32804216909233d48b0d2cd4ee08cab37e4dc64d)

The way to reproduce was:

build picodata using its cargo build (I'm on commit 4fa8a7f98a3ad4e05666a4fbf4a0d6729d90e876
export TARANTOOL_EXECUTABLE=<picodata repo dir>/target/debug/build/tarantool-sys/tarantool-prefix/bin/tarantool
cd tarantool (module dir in picodata repo)
cargo build -p tarantool-module-test-runner
cargo test -- that works fine
cargo build -p tarantool-module-test-runner --features=picodata
cargo test -- that fails. Now it fails each time deterministically with test tarantool::cbus::unbounded::tests::unbounded_mpsc_test ... malloc(): unaligned fastbin chunk detected

If I cargo clean it, build from scratch with picodata feature - it works.

Another experiment that failed for me. After performing the sequence above I run cargo clean, then build with picodata features from scratch, run tests - ok, then I add random println to the code, rebuild it without running cargo clean and it segfaulted for me.

Another time I do that the test is stuck. Tarantool process eats 100% of a cpu core and no progress seems to happen.

Attaching with gdb all threads except coio thread are in epoll_wait. Backtrace for coio thread is:

Thread 2 (Thread 0x7fa43d3ff6c0 (LWP 461171) "coio"):
#0  __futex_abstimed_wait_common64 (private=0, cancel=true, abstime=0x0, op=393, expected=0, futex_word=0x559f14b0cb04 <eio_pool+260>) at futex-internal.c:57
#1  __futex_abstimed_wait_common (futex_word=futex_word@entry=0x559f14b0cb04 <eio_pool+260>, expected=expected@entry=0, clockid=clockid@entry=0, abstime=abstime@entry=0x0, private=private@entry=0, cancel=cancel@entry=true) at futex-internal.c:87
#2  0x00007fa44b181def in __GI___futex_abstimed_wait_cancelable64 (futex_word=futex_word@entry=0x559f14b0cb04 <eio_pool+260>, expected=expected@entry=0, clockid=clockid@entry=0, abstime=abstime@entry=0x0, private=private@entry=0) at futex-internal.c:139
#3  0x00007fa44b184580 in __pthread_cond_wait_common (abstime=0x0, clockid=0, mutex=0x559f14b0cab0 <eio_pool+176>, cond=0x559f14b0cad8 <eio_pool+216>) at pthread_cond_wait.c:503
#4  ___pthread_cond_wait (cond=cond@entry=0x559f14b0cad8 <eio_pool+216>, mutex=mutex@entry=0x559f14b0cab0 <eio_pool+176>) at pthread_cond_wait.c:618
#5  0x0000559f11da5aa7 in etp_proc (thr_arg=<optimized out>) at /home/dr/wrk/picodata/master/tarantool-sys/third_party/libeio/etp.c:353
#6  0x00007fa44b18519d in start_thread (arg=<optimized out>) at pthread_create.c:442
#7  0x00007fa44b206c40 in clone3 () at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:81

Top part of perf report output: (to collect it I used perf record -p <tarantool pid> --call-graph dwarf

  Children      Self  Command    Shared Object                       Symbol
+   68.15%     0.00%  tarantool  tarantool                           [.] coro_init
+   68.15%     0.00%  tarantool  tarantool                           [.] fiber_loop
+   68.15%     0.00%  tarantool  libtarantool_module_test_runner.so  [.] _ZN9tarantool5fiber15unpack_callback10trampoline17h0547aabfbcce88e8E
+   68.15%     0.11%  tarantool  libtarantool_module_test_runner.so  [.] _ZN28tarantool_module_test_runner5fiber5yield28_$u7b$$u7b$closure$u7d$$u7d$17hf01a37ad58347141E
+   68.15%     0.00%  tarantool  tarantool                           [.] _ZL16fiber_cxx_invokePFiP13__va_list_tagES0_
+   62.28%     0.17%  tarantool  libtarantool_module_test_runner.so  [.] _ZN9tarantool5fiber5yield17h518014d5ae5339c2E
+   31.91%     0.33%  tarantool  tarantool                           [.] box_error_set
+   31.78%     0.00%  tarantool  tarantool                           [.] _start
+   31.78%     0.00%  tarantool  libc.so.6                           [.] __libc_start_main@@GLIBC_2.34
+   31.78%     0.00%  tarantool  libc.so.6                           [.] __libc_start_call_main
+   31.78%     0.00%  tarantool  tarantool                           [.] tarantool_main
+   31.78%     0.00%  tarantool  tarantool                           [.] tarantool_lua_run_script
+   31.78%    10.32%  tarantool  tarantool                           [.] ev_run

This is what I've gathered so far. Didnt dig into test code/cbus internals yet

Additionally in the past when I've first encountered this error full rebuild from scratch for both tarantool binary and module + its tests seemed to help

Unfortunately I couldn't repeat this crash. But, I know about the race condition in the mpsc test case (in unbounded_mpsc_test), and it also leads to an error inside the malloc (but a different one). I’m going to fix this in the near future and mention this issue in fix commit. It would be great if you repeated this crash after this, perhaps it will be fixed.

Sure!

mentioned in commit 16a43c7d

mentioned in merge request !407 (merged)

Got another instance: test fiber::immediate_with_cond ... malloc(): unaligned tcache chunk detected. It reproduced every time and full rebuild didnt help (maybe I've missed something I need to clean as well)

mentioned in issue picodata/tarantool#34

One more variant: test tarantool::cbus::unbounded::tests::unbounded_mpsc_test ... malloc(): unsorted double linked list corrupted

mentioned in commit f9672a19

mentioned in commit c7a46cff

please check now, i suppose that this must be fixed by !407 (merged)

I havent seen this for some time, thanks for the fix! I'll reopen if it happens again

closed

Unexpected behavior of tarantool::cbus::unbounded::tests::unbounded_mpsc_test

Designs

Child items ...

Activity