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.

Sign up for GitHub

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

Jump to bottom

"malloc_consolidate(): unaligned fastbin chunk detected" when attempting to block single-threaded runtime #6452

Closed
nazar-pc opened this issue Apr 2, 2024 · 9 comments
Closed

"malloc_consolidate(): unaligned fastbin chunk detected" when attempting to block single-threaded runtime #6452

nazar-pc opened this issue Apr 2, 2024 · 9 comments
Labels
A-tokio Area: The main tokio crate C-bug Category: This is a bug. M-runtime Module: tokio/runtime

Comments

@nazar-pc
Copy link

nazar-pc commented Apr 2, 2024

Version
List the versions of all tokio crates you are using. The easiest way to get
this information is using cargo tree subcommand:

│   └── tokio v1.35.1
│       └── tokio-macros v2.2.0 (proc-macro)
│   │   │   ├── tokio v1.35.1 (*)
│   │   │   │   ├── tokio v1.35.1 (*)
│   │   │   ├── tokio v1.35.1 (*)
│   │   │       │   │   └── tokio v1.35.1 (*)
│   │   │       │   └── tokio v1.35.1 (*)
│   │   │       └── tokio v1.35.1 (*)
│   │   ├── tokio v1.35.1 (*)
├── tokio v1.35.1 (*)

Platform

Ubuntu 22.04

Linux nazar-pc 6.8.2-x64v4-xanmod1 #0~20240326.g0e43e28 SMP PREEMPT_DYNAMIC Wed Mar 27 00:44:57 UTC x86_64 x86_64 x86_64 GNU/Linux

Description
I have a piece of broken code that results in the following unfortunate situation:

thread 'tests::basic' panicked at shared/subspace-cluster-networking/src/utils.rs:21:17:
can call blocking only when running on the multi-threaded runtime
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace
malloc_consolidate(): unaligned fastbin chunk detected

I tried this code:

Unfortunately I was not able to reduce the code yet, but here is the commit: nazar-pc/subspace@a761589

Specifically #[tokio::test] is problematic, when replaced with #[tokio::test(flavor = "multi_thread")] the problem goes away.

Here is backtrace in gdb:

running 2 tests
[New Thread 0x7ffff7a00640 (LWP 368334)]
[New Thread 0x7ffff7600640 (LWP 368335)]
[Thread 0x7ffff7a00640 (LWP 368334) exited]
test request_response::tests::test_codec ... ok
[New Thread 0x7ffff7a00640 (LWP 368336)]
malloc_consolidate(): unaligned fastbin chunk detected

Thread 3 "tests::basic" received signal SIGABRT, Aborted.
[Switching to Thread 0x7ffff7600640 (LWP 368335)]
__pthread_kill_implementation (no_tid=0, signo=6, threadid=140737343653440) at ./nptl/pthread_kill.c:44
44	./nptl/pthread_kill.c: Немає такого файла або каталогу.
(gdb) bt
#0  __pthread_kill_implementation (no_tid=0, signo=6, threadid=140737343653440) at ./nptl/pthread_kill.c:44
#1  __pthread_kill_internal (signo=6, threadid=140737343653440) at ./nptl/pthread_kill.c:78
#2  __GI___pthread_kill (threadid=140737343653440, signo=signo@entry=6) at ./nptl/pthread_kill.c:89
#3  0x00007ffff7c42476 in __GI_raise (sig=sig@entry=6) at ../sysdeps/posix/raise.c:26
#4  0x00007ffff7c287f3 in __GI_abort () at ./stdlib/abort.c:79
#5  0x00007ffff7c89676 in __libc_message (action=action@entry=do_abort, fmt=fmt@entry=0x7ffff7ddbb77 "%s\n") at ../sysdeps/posix/libc_fatal.c:155
#6  0x00007ffff7ca0cfc in malloc_printerr (str=str@entry=0x7ffff7dde5b8 "malloc_consolidate(): unaligned fastbin chunk detected") at ./malloc/malloc.c:5664
#7  0x00007ffff7ca198c in malloc_consolidate (av=av@entry=0x7ffff0000030) at ./malloc/malloc.c:4750
#8  0x00007ffff7ca2ea0 in _int_free (av=0x7ffff0000030, p=0x7ffff00558c0, have_lock=<optimized out>) at ./malloc/malloc.c:4674
#9  0x00007ffff7ca5453 in __GI___libc_free (mem=<optimized out>) at ./malloc/malloc.c:3391
#10 0x000055555560aa90 in alloc::alloc::dealloc () at /rustc/1684a753dbca5d23b2e03568e6fbbb48eb72d0e6/library/alloc/src/alloc.rs:119
#11 alloc::alloc::{impl#1}::deallocate (self=0x7ffff0055640, ptr=..., layout=...) at /rustc/1684a753dbca5d23b2e03568e6fbbb48eb72d0e6/library/alloc/src/alloc.rs:256
#12 0x0000555555794819 in alloc::boxed::{impl#8}::drop<subspace_cluster_networking::tests::basic::{async_block#0}::{async_block_env#8}, alloc::alloc::Global> (self=0x7ffff0055638) at /rustc/1684a753dbca5d23b2e03568e6fbbb48eb72d0e6/library/alloc/src/boxed.rs:1243
#13 0x0000555555779d9e in core::ptr::drop_in_place<alloc::boxed::Box<subspace_cluster_networking::tests::basic::{async_block#0}::{async_block_env#8}, alloc::alloc::Global>> () at /rustc/1684a753dbca5d23b2e03568e6fbbb48eb72d0e6/library/core/src/ptr/mod.rs:514
#14 0x000055555577b4aa in core::ptr::drop_in_place<core::pin::Pin<alloc::boxed::Box<subspace_cluster_networking::tests::basic::{async_block#0}::{async_block_env#8}, alloc::alloc::Global>>> () at /rustc/1684a753dbca5d23b2e03568e6fbbb48eb72d0e6/library/core/src/ptr/mod.rs:514
#15 0x000055555577de1f in core::ptr::drop_in_place<tokio::runtime::task::core::Stage<core::pin::Pin<alloc::boxed::Box<subspace_cluster_networking::tests::basic::{async_block#0}::{async_block_env#8}, alloc::alloc::Global>>>> () at /rustc/1684a753dbca5d23b2e03568e6fbbb48eb72d0e6/library/core/src/ptr/mod.rs:514
#16 0x00005555557bf43b in tokio::runtime::task::core::{impl#6}::set_stage::{closure#0}<core::pin::Pin<alloc::boxed::Box<subspace_cluster_networking::tests::basic::{async_block#0}::{async_block_env#8}, alloc::alloc::Global>>, alloc::sync::Arc<tokio::runtime::scheduler::current_thread::Handle, alloc::alloc::Global>> (ptr=0x7ffff0055630) at /home/nazar-pc/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.35.1/src/runtime/task/core.rs:382
#17 0x00005555557bc5f1 in tokio::loom::std::unsafe_cell::UnsafeCell<tokio::runtime::task::core::Stage<core::pin::Pin<alloc::boxed::Box<subspace_cluster_networking::tests::basic::{async_block#0}::{async_block_env#8}, alloc::alloc::Global>>>>::with_mut<tokio::runtime::task::core::Stage<core::pin::Pin<alloc::boxed::Box<subspace_cluster_networking::tests::basic::{async_block#0}::{async_block_env#8}, alloc::alloc::Global>>>, (), tokio::runtime::task::core::{impl#6}::set_stage::{closure_env#0}<core::pin::Pin<alloc::boxed::Box<subspace_cluster_networking::tests::basic::{async_block#0}::{async_block_env#8}, alloc::alloc::Global>>, alloc::sync::Arc<tokio::runtime::scheduler::current_thread::Handle, alloc::alloc::Global>>> (self=0x7ffff0055630, f=...) at /home/nazar-pc/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.35.1/src/loom/std/unsafe_cell.rs:16
#18 tokio::runtime::task::core::Core<core::pin::Pin<alloc::boxed::Box<subspace_cluster_networking::tests::basic::{async_block#0}::{async_block_env#8}, alloc::alloc::Global>>, alloc::sync::Arc<tokio::runtime::scheduler::current_thread::Handle, alloc::alloc::Global>>::set_stage<core::pin::Pin<alloc::boxed::Box<subspace_cluster_networking::tests::basic::{async_block#0}::{async_block_env#8}, alloc::alloc::Global>>, alloc::sync::Arc<tokio::runtime::scheduler::current_thread::Handle, alloc::alloc::Global>> (self=0x7ffff0055620, stage=...) at /home/nazar-pc/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.35.1/src/runtime/task/core.rs:382
#19 0x00005555557b4d59 in tokio::runtime::task::core::Core<core::pin::Pin<alloc::boxed::Box<subspace_cluster_networking::tests::basic::{async_block#0}::{async_block_env#8}, alloc::alloc::Global>>, alloc::sync::Arc<tokio::runtime::scheduler::current_thread::Handle, alloc::alloc::Global>>::drop_future_or_output<core::pin::Pin<alloc::boxed::Box<subspace_cluster_networking::tests::basic::{async_block#0}::{async_block_env#8}, alloc::alloc::Global>>, alloc::sync::Arc<tokio::runtime::scheduler::current_thread::Handle, alloc::alloc::Global>> (self=0x7ffff0055620) at /home/nazar-pc/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.35.1/src/runtime/task/core.rs:347
#20 0x00005555557703ad in tokio::runtime::task::harness::poll_future::{closure#0}::{impl#0}::drop<core::pin::Pin<alloc::boxed::Box<subspace_cluster_networking::tests::basic::{async_block#0}::{async_block_env#8}, alloc::alloc::Global>>, alloc::sync::Arc<tokio::runtime::scheduler::current_thread::Handle, alloc::alloc::Global>> (self=0x7ffff75fdde0)
    at /home/nazar-pc/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.35.1/src/runtime/task/harness.rs:481
#21 0x00005555557871ba in core::ptr::drop_in_place<tokio::runtime::task::harness::poll_future::{closure#0}::Guard<core::pin::Pin<alloc::boxed::Box<subspace_cluster_networking::tests::basic::{async_block#0}::{async_block_env#8}, alloc::alloc::Global>>, alloc::sync::Arc<tokio::runtime::scheduler::current_thread::Handle, alloc::alloc::Global>>> () at /rustc/1684a753dbca5d23b2e03568e6fbbb48eb72d0e6/library/core/src/ptr/mod.rs:514
#22 0x000055555583143e in tokio::runtime::task::harness::poll_future::{closure#0}<core::pin::Pin<alloc::boxed::Box<subspace_cluster_networking::tests::basic::{async_block#0}::{async_block_env#8}, alloc::alloc::Global>>, alloc::sync::Arc<tokio::runtime::scheduler::current_thread::Handle, alloc::alloc::Global>> () at /home/nazar-pc/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.35.1/src/runtime/task/harness.rs:488
#23 0x00005555555ffcd8 in core::panic::unwind_safe::{impl#23}::call_once<core::task::poll::Poll<()>, tokio::runtime::task::harness::poll_future::{closure_env#0}<core::pin::Pin<alloc::boxed::Box<subspace_cluster_networking::tests::basic::{async_block#0}::{async_block_env#8}, alloc::alloc::Global>>, alloc::sync::Arc<tokio::runtime::scheduler::current_thread::Handle, alloc::alloc::Global>>> (self=...)
    at /rustc/1684a753dbca5d23b2e03568e6fbbb48eb72d0e6/library/core/src/panic/unwind_safe.rs:272
#24 0x0000555555737651 in std::panicking::try::do_call<core::panic::unwind_safe::AssertUnwindSafe<tokio::runtime::task::harness::poll_future::{closure_env#0}<core::pin::Pin<alloc::boxed::Box<subspace_cluster_networking::tests::basic::{async_block#0}::{async_block_env#8}, alloc::alloc::Global>>, alloc::sync::Arc<tokio::runtime::scheduler::current_thread::Handle, alloc::alloc::Global>>>, core::task::poll::Poll<()>> (data=0x7ffff75fded8)
    at /rustc/1684a753dbca5d23b2e03568e6fbbb48eb72d0e6/library/std/src/panicking.rs:552
#25 0x000055555573d37b in __rust_try ()
#26 0x0000555555733d48 in std::panicking::try<core::task::poll::Poll<()>, core::panic::unwind_safe::AssertUnwindSafe<tokio::runtime::task::harness::poll_future::{closure_env#0}<core::pin::Pin<alloc::boxed::Box<subspace_cluster_networking::tests::basic::{async_block#0}::{async_block_env#8}, alloc::alloc::Global>>, alloc::sync::Arc<tokio::runtime::scheduler::current_thread::Handle, alloc::alloc::Global>>>> (f=...)
    at /rustc/1684a753dbca5d23b2e03568e6fbbb48eb72d0e6/library/std/src/panicking.rs:516
#27 0x0000555555650c8d in std::panic::catch_unwind<core::panic::unwind_safe::AssertUnwindSafe<tokio::runtime::task::harness::poll_future::{closure_env#0}<core::pin::Pin<alloc::boxed::Box<subspace_cluster_networking::tests::basic::{async_block#0}::{async_block_env#8}, alloc::alloc::Global>>, alloc::sync::Arc<tokio::runtime::scheduler::current_thread::Handle, alloc::alloc::Global>>>, core::task::poll::Poll<()>> (
    f=<error reading variable: Cannot access memory at address 0x59ecf>) at /rustc/1684a753dbca5d23b2e03568e6fbbb48eb72d0e6/library/std/src/panic.rs:149
#28 0x00005555558302b0 in tokio::runtime::task::harness::poll_future<core::pin::Pin<alloc::boxed::Box<subspace_cluster_networking::tests::basic::{async_block#0}::{async_block_env#8}, alloc::alloc::Global>>, alloc::sync::Arc<tokio::runtime::scheduler::current_thread::Handle, alloc::alloc::Global>> (core=0x7ffff0055620, cx=...) at /home/nazar-pc/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.35.1/src/runtime/task/harness.rs:473
#29 0x000055555583440b in tokio::runtime::task::harness::Harness<core::pin::Pin<alloc::boxed::Box<subspace_cluster_networking::tests::basic::{async_block#0}::{async_block_env#8}, alloc::alloc::Global>>, alloc::sync::Arc<tokio::runtime::scheduler::current_thread::Handle, alloc::alloc::Global>>::poll_inner<core::pin::Pin<alloc::boxed::Box<subspace_cluster_networking::tests::basic::{async_block#0}::{async_block_env#8}, alloc::alloc::Global>>, alloc::sync::Arc<tokio::runtime::scheduler::current_thread::Handle, alloc::alloc::Global>> (self=0x7ffff75fe100) at /home/nazar-pc/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.35.1/src/runtime/task/harness.rs:208
#30 0x0000555555839683 in tokio::runtime::task::harness::Harness<core::pin::Pin<alloc::boxed::Box<subspace_cluster_networking::tests::basic::{async_block#0}::{async_block_env#8}, alloc::alloc::Global>>, alloc::sync::Arc<tokio::runtime::scheduler::current_thread::Handle, alloc::alloc::Global>>::poll<core::pin::Pin<alloc::boxed::Box<subspace_cluster_networking::tests::basic::{async_block#0}::{async_block_env#8}, alloc::alloc::Global>>, alloc::sync::Arc<tokio::runtime::scheduler::current_thread::Handle, alloc::alloc::Global>> (self=...) at /home/nazar-pc/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.35.1/src/runtime/task/harness.rs:153
#31 0x00005555557cf07b in tokio::runtime::task::raw::poll<core::pin::Pin<alloc::boxed::Box<subspace_cluster_networking::tests::basic::{async_block#0}::{async_block_env#8}, alloc::alloc::Global>>, alloc::sync::Arc<tokio::runtime::scheduler::current_thread::Handle, alloc::alloc::Global>> (ptr=...) at /home/nazar-pc/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.35.1/src/runtime/task/raw.rs:271
#32 0x0000555555b99ee7 in tokio::runtime::task::raw::RawTask::poll (self=...) at /home/nazar-pc/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.35.1/src/runtime/task/raw.rs:201
#33 0x0000555555a11a72 in tokio::runtime::task::LocalNotified<alloc::sync::Arc<tokio::runtime::scheduler::current_thread::Handle, alloc::alloc::Global>>::run<alloc::sync::Arc<tokio::runtime::scheduler::current_thread::Handle, alloc::alloc::Global>> (self=...) at /home/nazar-pc/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.35.1/src/runtime/task/mod.rs:416
#34 0x00005555558507db in tokio::runtime::scheduler::current_thread::{impl#8}::block_on::{closure#0}::{closure#1}<core::pin::Pin<&mut core::pin::Pin<&mut dyn core::future::future::Future<Output=()>>>> () at /home/nazar-pc/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.35.1/src/runtime/scheduler/current_thread/mod.rs:706
#35 0x000055555584f973 in tokio::runtime::coop::with_budget<(), tokio::runtime::scheduler::current_thread::{impl#8}::block_on::{closure#0}::{closure_env#1}<core::pin::Pin<&mut core::pin::Pin<&mut dyn core::future::future::Future<Output=()>>>>> (budget=..., f=...) at /home/nazar-pc/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.35.1/src/runtime/coop.rs:107
#36 tokio::runtime::coop::budget<(), tokio::runtime::scheduler::current_thread::{impl#8}::block_on::{closure#0}::{closure_env#1}<core::pin::Pin<&mut core::pin::Pin<&mut dyn core::future::future::Future<Output=()>>>>> (f=...) at /home/nazar-pc/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.35.1/src/runtime/coop.rs:73
#37 tokio::runtime::scheduler::current_thread::{impl#3}::run_task::{closure#0}<(), tokio::runtime::scheduler::current_thread::{impl#8}::block_on::{closure#0}::{closure_env#1}<core::pin::Pin<&mut core::pin::Pin<&mut dyn core::future::future::Future<Output=()>>>>> () at /home/nazar-pc/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.35.1/src/runtime/scheduler/current_thread/mod.rs:343
#38 0x000055555584f606 in tokio::runtime::scheduler::current_thread::Context::enter<(), tokio::runtime::scheduler::current_thread::{impl#3}::run_task::{closure_env#0}<(), tokio::runtime::scheduler::current_thread::{impl#8}::block_on::{closure#0}::{closure_env#1}<core::pin::Pin<&mut core::pin::Pin<&mut dyn core::future::future::Future<Output=()>>>>>> (self=0x7ffff75fe938, core=0x7ffff0006550, f=...)
    at /home/nazar-pc/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.35.1/src/runtime/scheduler/current_thread/mod.rs:410
#39 0x000055555584f808 in tokio::runtime::scheduler::current_thread::Context::run_task<(), tokio::runtime::scheduler::current_thread::{impl#8}::block_on::{closure#0}::{closure_env#1}<core::pin::Pin<&mut core::pin::Pin<&mut dyn core::future::future::Future<Output=()>>>>> (self=0x7ffff75fe938, core=0x7ffff0006550, f=...) at /home/nazar-pc/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.35.1/src/runtime/scheduler/current_thread/mod.rs:343
#40 0x0000555555850746 in tokio::runtime::scheduler::current_thread::{impl#8}::block_on::{closure#0}<core::pin::Pin<&mut core::pin::Pin<&mut dyn core::future::future::Future<Output=()>>>> (core=0x7ffff0006550, context=0x7ffff75fe938) at /home/nazar-pc/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.35.1/src/runtime/scheduler/current_thread/mod.rs:705
#41 0x000055555584fe4b in tokio::runtime::scheduler::current_thread::{impl#8}::enter::{closure#0}<tokio::runtime::scheduler::current_thread::{impl#8}::block_on::{closure_env#0}<core::pin::Pin<&mut core::pin::Pin<&mut dyn core::future::future::Future<Output=()>>>>, core::option::Option<()>> () at /home/nazar-pc/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.35.1/src/runtime/scheduler/current_thread/mod.rs:743
#42 0x00005555556cd69d in tokio::runtime::context::scoped::Scoped<tokio::runtime::scheduler::Context>::set<tokio::runtime::scheduler::Context, tokio::runtime::scheduler::current_thread::{impl#8}::enter::{closure_env#0}<tokio::runtime::scheduler::current_thread::{impl#8}::block_on::{closure_env#0}<core::pin::Pin<&mut core::pin::Pin<&mut dyn core::future::future::Future<Output=()>>>>, core::option::Option<()>>, (alloc::boxed::Box<tokio::runtime::scheduler::current_thread::Core, alloc::alloc::Global>, core::option::Option<()>)> (self=0x7ffff76004b8, t=0x7ffff75fe930, f=...) at /home/nazar-pc/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.35.1/src/runtime/context/scoped.rs:40
#43 0x00005555557c05ab in tokio::runtime::context::set_scheduler::{closure#0}<(alloc::boxed::Box<tokio::runtime::scheduler::current_thread::Core, alloc::alloc::Global>, core::option::Option<()>), tokio::runtime::scheduler::current_thread::{impl#8}::enter::{closure_env#0}<tokio::runtime::scheduler::current_thread::{impl#8}::block_on::{closure_env#0}<core::pin::Pin<&mut core::pin::Pin<&mut dyn core::future::future::Future<Output=()>>>>, core::option::Option<()>>> (c=0x7ffff7600480) at /home/nazar-pc/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.35.1/src/runtime/context.rs:176
#44 0x000055555573d982 in std::thread::local::LocalKey<tokio::runtime::context::Context>::try_with<tokio::runtime::context::Context, tokio::runtime::context::set_scheduler::{closure_env#0}<(alloc::boxed::Box<tokio::runtime::scheduler::current_thread::Core, alloc::alloc::Global>, core::option::Option<()>), tokio::runtime::scheduler::current_thread::{impl#8}::enter::{closure_env#0}<tokio::runtime::scheduler::current_thread::{impl#8}::block_on::{closure_env#0}<core::pin::Pin<&mut core::pin::Pin<&mut dyn core::future::future::Future<Output=()>>>>, core::option::Option<()>>>, (alloc::boxed::Box<tokio::runtime::scheduler::current_thread::Core, alloc::alloc::Global>, core::option::Option<()>)> (self=0x555556007d28, f=...) at /rustc/1684a753dbca5d23b2e03568e6fbbb48eb72d0e6/library/std/src/thread/local.rs:284
#45 0x000055555573d3aa in std::thread::local::LocalKey<tokio::runtime::context::Context>::with<tokio::runtime::context::Context, tokio::runtime::context::set_scheduler::{closure_env#0}<(alloc::boxed::Box<tokio::runtime::scheduler::current_thread::Core, alloc::alloc::Global>, core::option::Option<()>), tokio::runtime::scheduler::current_thread::{impl#8}::enter::{closure_env#0}<tokio::runtime::scheduler::current_thread::{impl#8}::block_on::{closure_env#0}<core::pin::Pin<&mut core::pin::Pin<&mut dyn core::future::future::Future<Output=()>>>>, core::option::Option<()>>>, (alloc::boxed::Box<tokio::runtime::scheduler::current_thread::Core, alloc::alloc::Global>, core::option::Option<()>)> (self=0x555556007d28, f=<error reading variable: Cannot access memory at address 0x59ecf>) at /rustc/1684a753dbca5d23b2e03568e6fbbb48eb72d0e6/library/std/src/thread/local.rs:260
#46 0x00005555557c055f in tokio::runtime::context::set_scheduler<(alloc::boxed::Box<tokio::runtime::scheduler::current_thread::Core, alloc::alloc::Global>, core::option::Option<()>), tokio::runtime::scheduler::current_thread::{impl#8}::enter::{closure_env#0}<tokio::runtime::scheduler::current_thread::{impl#8}::block_on::{closure_env#0}<core::pin::Pin<&mut core::pin::Pin<&mut dyn core::future::future::Future<Output=()>>>>, core::option::Option<()>>> (
    v=0x7ffff75fe930, f=...) at /home/nazar-pc/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.35.1/src/runtime/context.rs:176
#47 0x000055555584fbe0 in tokio::runtime::scheduler::current_thread::CoreGuard::enter<tokio::runtime::scheduler::current_thread::{impl#8}::block_on::{closure_env#0}<core::pin::Pin<&mut core::pin::Pin<&mut dyn core::future::future::Future<Output=()>>>>, core::option::Option<()>> (self=..., f=...) at /home/nazar-pc/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.35.1/src/runtime/scheduler/current_thread/mod.rs:743
#48 0x000055555584fe6d in tokio::runtime::scheduler::current_thread::CoreGuard::block_on<core::pin::Pin<&mut core::pin::Pin<&mut dyn core::future::future::Future<Output=()>>>> (self=<error reading variable: Cannot access memory at address 0x59eca>, future=...) at /home/nazar-pc/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.35.1/src/runtime/scheduler/current_thread/mod.rs:652
#49 0x000055555584c9ba in tokio::runtime::scheduler::current_thread::{impl#0}::block_on::{closure#0}<core::pin::Pin<&mut dyn core::future::future::Future<Output=()>>> (blocking=0x7ffff75fead0) at /home/nazar-pc/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.35.1/src/runtime/scheduler/current_thread/mod.rs:175
#50 0x000055555564e0e7 in tokio::runtime::context::runtime::enter_runtime<tokio::runtime::scheduler::current_thread::{impl#0}::block_on::{closure_env#0}<core::pin::Pin<&mut dyn core::future::future::Future<Output=()>>>, ()> (handle=0x7ffff75ff340, allow_block_in_place=false, f=...) at /home/nazar-pc/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.35.1/src/runtime/context/runtime.rs:65
#51 0x000055555584c8de in tokio::runtime::scheduler::current_thread::CurrentThread::block_on<core::pin::Pin<&mut dyn core::future::future::Future<Output=()>>> (self=0x7ffff75ff318, handle=0x7ffff75ff340, future=...) at /home/nazar-pc/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.35.1/src/runtime/scheduler/current_thread/mod.rs:167
#52 0x0000555555657acd in tokio::runtime::runtime::Runtime::block_on<core::pin::Pin<&mut dyn core::future::future::Future<Output=()>>> (self=0x7ffff75ff310, future=...) at /home/nazar-pc/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.35.1/src/runtime/runtime.rs:348
#53 0x000055555575001c in subspace_cluster_networking::tests::basic () at shared/subspace-cluster-networking/src/tests.rs:155
#54 0x00005555556404a7 in subspace_cluster_networking::tests::basic::{closure#0} () at shared/subspace-cluster-networking/src/tests.rs:59
#55 0x0000555555772db6 in core::ops::function::FnOnce::call_once<subspace_cluster_networking::tests::basic::{closure_env#0}, ()> () at /rustc/1684a753dbca5d23b2e03568e6fbbb48eb72d0e6/library/core/src/ops/function.rs:250
#56 0x00005555558a79b2 in core::ops::function::FnOnce::call_once<fn() -> core::result::Result<(), alloc::string::String>, ()> () at library/core/src/ops/function.rs:250
#57 test::__rust_begin_short_backtrace<core::result::Result<(), alloc::string::String>, fn() -> core::result::Result<(), alloc::string::String>> () at library/test/src/lib.rs:621
#58 0x00005555558a7131 in test::run_test_in_process::{closure#0} () at library/test/src/lib.rs:644
#59 core::panic::unwind_safe::{impl#23}::call_once<core::result::Result<(), alloc::string::String>, test::run_test_in_process::{closure_env#0}> () at library/core/src/panic/unwind_safe.rs:272
#60 std::panicking::try::do_call<core::panic::unwind_safe::AssertUnwindSafe<test::run_test_in_process::{closure_env#0}>, core::result::Result<(), alloc::string::String>> () at library/std/src/panicking.rs:552
#61 std::panicking::try<core::result::Result<(), alloc::string::String>, core::panic::unwind_safe::AssertUnwindSafe<test::run_test_in_process::{closure_env#0}>> () at library/std/src/panicking.rs:516
#62 std::panic::catch_unwind<core::panic::unwind_safe::AssertUnwindSafe<test::run_test_in_process::{closure_env#0}>, core::result::Result<(), alloc::string::String>> () at library/std/src/panic.rs:149
#63 test::run_test_in_process () at library/test/src/lib.rs:644
#64 test::run_test::{closure#0} () at library/test/src/lib.rs:567
--Type <RET> for more, q to quit, c to continue without paging--c
#65 0x000055555586ef84 in test::run_test::{closure#1} () at library/test/src/lib.rs:595
#66 std::sys_common::backtrace::__rust_begin_short_backtrace<test::run_test::{closure_env#1}, ()> () at library/std/src/sys_common/backtrace.rs:155
#67 0x0000555555873a3b in std::thread::{impl#0}::spawn_unchecked_::{closure#1}::{closure#0}<test::run_test::{closure_env#1}, ()> () at library/std/src/thread/mod.rs:523
#68 core::panic::unwind_safe::{impl#23}::call_once<(), std::thread::{impl#0}::spawn_unchecked_::{closure#1}::{closure_env#0}<test::run_test::{closure_env#1}, ()>> () at library/core/src/panic/unwind_safe.rs:272
#69 std::panicking::try::do_call<core::panic::unwind_safe::AssertUnwindSafe<std::thread::{impl#0}::spawn_unchecked_::{closure#1}::{closure_env#0}<test::run_test::{closure_env#1}, ()>>, ()> () at library/std/src/panicking.rs:552
#70 std::panicking::try<(), core::panic::unwind_safe::AssertUnwindSafe<std::thread::{impl#0}::spawn_unchecked_::{closure#1}::{closure_env#0}<test::run_test::{closure_env#1}, ()>>> () at library/std/src/panicking.rs:516
#71 std::panic::catch_unwind<core::panic::unwind_safe::AssertUnwindSafe<std::thread::{impl#0}::spawn_unchecked_::{closure#1}::{closure_env#0}<test::run_test::{closure_env#1}, ()>>, ()> () at library/std/src/panic.rs:149
#72 std::thread::{impl#0}::spawn_unchecked_::{closure#1}<test::run_test::{closure_env#1}, ()> () at library/std/src/thread/mod.rs:522
#73 core::ops::function::FnOnce::call_once<std::thread::{impl#0}::spawn_unchecked_::{closure_env#1}<test::run_test::{closure_env#1}, ()>, ()> () at library/core/src/ops/function.rs:250
#74 0x0000555555da841b in alloc::boxed::{impl#48}::call_once<(), dyn core::ops::function::FnOnce<(), Output=()>, alloc::alloc::Global> () at library/alloc/src/boxed.rs:2018
#75 alloc::boxed::{impl#48}::call_once<(), alloc::boxed::Box<dyn core::ops::function::FnOnce<(), Output=()>, alloc::alloc::Global>, alloc::alloc::Global> () at library/alloc/src/boxed.rs:2018
#76 std::sys::pal::unix::thread::{impl#2}::new::thread_start () at library/std/src/sys/pal/unix/thread.rs:108
#77 0x00007ffff7c94ac3 in start_thread (arg=<optimized out>) at ./nptl/pthread_create.c:442
#78 0x00007ffff7d26850 in clone3 () at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:81

Specifically the code where it panics looks like this:

/// Joins async join handle on drop
pub(crate) struct AsyncJoinOnDrop<T>(Option<Fuse<task::JoinHandle<T>>>);

impl<T> Drop for AsyncJoinOnDrop<T> {
    fn drop(&mut self) {
        let handle = self.0.take().expect("Always called exactly once; qed");
        if !handle.is_terminated() {
            task::block_in_place(move || {
                let _ = Handle::current().block_on(handle);
            });
        }
    }
}

I expected to see this happen:

The panic is correct and fair, but it should not lead to memory issues.
@nazar-pc nazar-pc added A-tokio Area: The main tokio crate C-bug Category: This is a bug. labels Apr 2, 2024
@Darksonn Darksonn added the M-runtime Module: tokio/runtime label Apr 2, 2024
@Darksonn
Copy link
Contributor

Darksonn commented Apr 2, 2024

Have you tried running this under miri or valgrind?

@nazar-pc
Copy link
Author

nazar-pc commented Apr 2, 2024

Under valgrind it doesn't crash. It complains about a few things, but not sure if they are false positive or not:

==26497== Memcheck, a memory error detector
==26497== Copyright (C) 2002-2017, and GNU GPL'd, by Julian Seward et al.
==26497== Using Valgrind-3.18.1 and LibVEX; rerun with -h for copyright info
==26497== Command: /home/nazar-pc/.cache/cargo/target/debug/deps/subspace_cluster_networking-8c3f78d77dba1356
==26497== 

running 2 tests
test request_response::tests::test_codec ... ok
==26497== Thread 3 tests::basic:
==26497== Invalid read of size 8
==26497==    at 0x2644FB: core::sync::atomic::atomic_load (atomic.rs:3308)
==26497==    by 0x26664B: core::sync::atomic::AtomicPtr<T>::load (atomic.rs:1433)
==26497==    by 0x248C02: futures_util::stream::futures_unordered::ready_to_run_queue::ReadyToRunQueue<Fut>::dequeue (ready_to_run_queue.rs:60)
==26497==    by 0x1B9E37: <futures_util::stream::futures_unordered::ready_to_run_queue::ReadyToRunQueue<Fut> as core::ops::drop::Drop>::drop (ready_to_run_queue.rs:101)
==26497==    by 0x1CC5B2: core::ptr::drop_in_place<futures_util::stream::futures_unordered::ready_to_run_queue::ReadyToRunQueue<subspace_cluster_networking::utils::AsyncJoinOnDrop<(libp2p_identity::peer_id::PeerId,alloc::vec::Vec<multiaddr::Multiaddr>)>>> (mod.rs:515)
==26497==    by 0x2508FD: alloc::sync::Arc<T,A>::drop_slow (sync.rs:1804)
==26497==    by 0x1DCE40: <alloc::sync::Arc<T,A> as core::ops::drop::Drop>::drop (sync.rs:2459)
==26497==    by 0x1CE2F9: core::ptr::drop_in_place<alloc::sync::Arc<futures_util::stream::futures_unordered::ready_to_run_queue::ReadyToRunQueue<subspace_cluster_networking::utils::AsyncJoinOnDrop<(libp2p_identity::peer_id::PeerId,alloc::vec::Vec<multiaddr::Multiaddr>)>>>> (mod.rs:515)
==26497==    by 0x1CA92E: core::ptr::drop_in_place<futures_util::stream::futures_unordered::FuturesUnordered<subspace_cluster_networking::utils::AsyncJoinOnDrop<(libp2p_identity::peer_id::PeerId,alloc::vec::Vec<multiaddr::Multiaddr>)>>> (mod.rs:515)
==26497==    by 0x1C61F9: core::ptr::drop_in_place<subspace_cluster_networking::network_worker::NetworkWorker<subspace_cluster_networking::tests::Requests,subspace_cluster_networking::tests::Responses>> (mod.rs:515)
==26497==    by 0x41709E: subspace_cluster_networking::tests::basic::{{closure}}::{{closure}} (tests.rs:170)
==26497==    by 0x3CAE25: <core::pin::Pin<P> as core::future::future::Future>::poll (future.rs:124)
==26497==  Address 0x4c8de60 is 64 bytes inside a block of size 80 free'd
==26497==    at 0x484B27F: free (in /usr/libexec/valgrind/vgpreload_memcheck-amd64-linux.so)
==26497==    by 0x7A378F: <alloc::alloc::Global as core::alloc::Allocator>::deallocate (alloc.rs:117)
==26497==    by 0x7A04AF: <&A as core::alloc::Allocator>::deallocate (mod.rs:392)
==26497==    by 0x1E217F: <alloc::sync::Weak<T,A> as core::ops::drop::Drop>::drop (sync.rs:3050)
==26497==    by 0x1CE549: core::ptr::drop_in_place<alloc::sync::Weak<futures_util::stream::futures_unordered::task::Task<subspace_cluster_networking::utils::AsyncJoinOnDrop<(libp2p_identity::peer_id::PeerId,alloc::vec::Vec<multiaddr::Multiaddr>)>>,&alloc::alloc::Global>> (mod.rs:515)
==26497==    by 0x250A4C: drop<alloc::sync::Weak<futures_util::stream::futures_unordered::task::Task<subspace_cluster_networking::utils::AsyncJoinOnDrop<(libp2p_identity::peer_id::PeerId, alloc::vec::Vec<multiaddr::Multiaddr, alloc::alloc::Global>)>>, &alloc::alloc::Global>> (mod.rs:992)
==26497==    by 0x250A4C: alloc::sync::Arc<T,A>::drop_slow (sync.rs:1810)
==26497==    by 0x1DD9D0: <alloc::sync::Arc<T,A> as core::ops::drop::Drop>::drop (sync.rs:2459)
==26497==    by 0x1CC549: core::ptr::drop_in_place<alloc::sync::Arc<futures_util::stream::futures_unordered::task::Task<subspace_cluster_networking::utils::AsyncJoinOnDrop<(libp2p_identity::peer_id::PeerId,alloc::vec::Vec<multiaddr::Multiaddr>)>>>> (mod.rs:515)
==26497==    by 0x22269E: futures_util::stream::futures_unordered::FuturesUnordered<Fut>::release_task (mod.rs:283)
==26497==    by 0x1B9BC9: <futures_util::stream::futures_unordered::FuturesUnordered<Fut> as core::ops::drop::Drop>::drop (mod.rs:574)
==26497==    by 0x1CA922: core::ptr::drop_in_place<futures_util::stream::futures_unordered::FuturesUnordered<subspace_cluster_networking::utils::AsyncJoinOnDrop<(libp2p_identity::peer_id::PeerId,alloc::vec::Vec<multiaddr::Multiaddr>)>>> (mod.rs:515)
==26497==    by 0x1C61F9: core::ptr::drop_in_place<subspace_cluster_networking::network_worker::NetworkWorker<subspace_cluster_networking::tests::Requests,subspace_cluster_networking::tests::Responses>> (mod.rs:515)
==26497==  Block was alloc'd at
==26497==    at 0x4848899: malloc (in /usr/libexec/valgrind/vgpreload_memcheck-amd64-linux.so)
==26497==    by 0x29A64A: alloc::alloc::alloc (alloc.rs:98)
==26497==    by 0x29A80C: alloc::alloc::Global::alloc_impl (alloc.rs:181)
==26497==    by 0x29A57B: alloc::alloc::exchange_malloc (alloc.rs:241)
==26497==    by 0x24C7A7: new<alloc::sync::ArcInner<futures_util::stream::futures_unordered::task::Task<subspace_cluster_networking::utils::AsyncJoinOnDrop<(libp2p_identity::peer_id::PeerId, alloc::vec::Vec<multiaddr::Multiaddr, alloc::alloc::Global>)>>>> (boxed.rs:218)
==26497==    by 0x24C7A7: alloc::sync::Arc<T>::new (sync.rs:395)
==26497==    by 0x22AEF1: futures_util::stream::futures_unordered::FuturesUnordered<Fut>::push (mod.rs:167)
==26497==    by 0x2916A3: subspace_cluster_networking::network_worker::NetworkWorker<Requests,Responses>::handle_swarm_event::{{closure}} (network_worker.rs:277)
==26497==    by 0x28CDC9: subspace_cluster_networking::network_worker::NetworkWorker<Requests,Responses>::run::{{closure}} (network_worker.rs:128)
==26497==    by 0x41703A: subspace_cluster_networking::tests::basic::{{closure}}::{{closure}} (tests.rs:169)
==26497==    by 0x3CAE25: <core::pin::Pin<P> as core::future::future::Future>::poll (future.rs:124)
==26497==    by 0x38FA88: tokio::runtime::task::core::Core<T,S>::poll::{{closure}} (core.rs:328)
==26497==    by 0x38E0C5: with_mut<tokio::runtime::task::core::Stage<core::pin::Pin<alloc::boxed::Box<subspace_cluster_networking::tests::basic::{async_block#0}::{async_block_env#8}, alloc::alloc::Global>>>, core::task::poll::Poll<()>, tokio::runtime::task::core::{impl#6}::poll::{closure_env#0}<core::pin::Pin<alloc::boxed::Box<subspace_cluster_networking::tests::basic::{async_block#0}::{async_block_env#8}, alloc::alloc::Global>>, alloc::sync::Arc<tokio::runtime::scheduler::current_thread::Handle, alloc::alloc::Global>>> (unsafe_cell.rs:16)
==26497==    by 0x38E0C5: tokio::runtime::task::core::Core<T,S>::poll (core.rs:317)
==26497== 
==26497== Invalid write of size 8
==26497==    at 0x2651F4: core::sync::atomic::atomic_store (atomic.rs:3293)
==26497==    by 0x266F40: core::sync::atomic::AtomicPtr<T>::store (atomic.rs:1463)
==26497==    by 0x24A661: futures_util::stream::futures_unordered::ready_to_run_queue::ReadyToRunQueue<Fut>::enqueue (ready_to_run_queue.rs:41)
==26497==    by 0x248D21: futures_util::stream::futures_unordered::ready_to_run_queue::ReadyToRunQueue<Fut>::dequeue (ready_to_run_queue.rs:73)
==26497==    by 0x1B9E37: <futures_util::stream::futures_unordered::ready_to_run_queue::ReadyToRunQueue<Fut> as core::ops::drop::Drop>::drop (ready_to_run_queue.rs:101)
==26497==    by 0x1CC5B2: core::ptr::drop_in_place<futures_util::stream::futures_unordered::ready_to_run_queue::ReadyToRunQueue<subspace_cluster_networking::utils::AsyncJoinOnDrop<(libp2p_identity::peer_id::PeerId,alloc::vec::Vec<multiaddr::Multiaddr>)>>> (mod.rs:515)
==26497==    by 0x2508FD: alloc::sync::Arc<T,A>::drop_slow (sync.rs:1804)
==26497==    by 0x1DCE40: <alloc::sync::Arc<T,A> as core::ops::drop::Drop>::drop (sync.rs:2459)
==26497==    by 0x1CE2F9: core::ptr::drop_in_place<alloc::sync::Arc<futures_util::stream::futures_unordered::ready_to_run_queue::ReadyToRunQueue<subspace_cluster_networking::utils::AsyncJoinOnDrop<(libp2p_identity::peer_id::PeerId,alloc::vec::Vec<multiaddr::Multiaddr>)>>>> (mod.rs:515)
==26497==    by 0x1CA92E: core::ptr::drop_in_place<futures_util::stream::futures_unordered::FuturesUnordered<subspace_cluster_networking::utils::AsyncJoinOnDrop<(libp2p_identity::peer_id::PeerId,alloc::vec::Vec<multiaddr::Multiaddr>)>>> (mod.rs:515)
==26497==    by 0x1C61F9: core::ptr::drop_in_place<subspace_cluster_networking::network_worker::NetworkWorker<subspace_cluster_networking::tests::Requests,subspace_cluster_networking::tests::Responses>> (mod.rs:515)
==26497==    by 0x41709E: subspace_cluster_networking::tests::basic::{{closure}}::{{closure}} (tests.rs:170)
==26497==  Address 0x4c8de60 is 64 bytes inside a block of size 80 free'd
==26497==    at 0x484B27F: free (in /usr/libexec/valgrind/vgpreload_memcheck-amd64-linux.so)
==26497==    by 0x7A378F: <alloc::alloc::Global as core::alloc::Allocator>::deallocate (alloc.rs:117)
==26497==    by 0x7A04AF: <&A as core::alloc::Allocator>::deallocate (mod.rs:392)
==26497==    by 0x1E217F: <alloc::sync::Weak<T,A> as core::ops::drop::Drop>::drop (sync.rs:3050)
==26497==    by 0x1CE549: core::ptr::drop_in_place<alloc::sync::Weak<futures_util::stream::futures_unordered::task::Task<subspace_cluster_networking::utils::AsyncJoinOnDrop<(libp2p_identity::peer_id::PeerId,alloc::vec::Vec<multiaddr::Multiaddr>)>>,&alloc::alloc::Global>> (mod.rs:515)
==26497==    by 0x250A4C: drop<alloc::sync::Weak<futures_util::stream::futures_unordered::task::Task<subspace_cluster_networking::utils::AsyncJoinOnDrop<(libp2p_identity::peer_id::PeerId, alloc::vec::Vec<multiaddr::Multiaddr, alloc::alloc::Global>)>>, &alloc::alloc::Global>> (mod.rs:992)
==26497==    by 0x250A4C: alloc::sync::Arc<T,A>::drop_slow (sync.rs:1810)
==26497==    by 0x1DD9D0: <alloc::sync::Arc<T,A> as core::ops::drop::Drop>::drop (sync.rs:2459)
==26497==    by 0x1CC549: core::ptr::drop_in_place<alloc::sync::Arc<futures_util::stream::futures_unordered::task::Task<subspace_cluster_networking::utils::AsyncJoinOnDrop<(libp2p_identity::peer_id::PeerId,alloc::vec::Vec<multiaddr::Multiaddr>)>>>> (mod.rs:515)
==26497==    by 0x22269E: futures_util::stream::futures_unordered::FuturesUnordered<Fut>::release_task (mod.rs:283)
==26497==    by 0x1B9BC9: <futures_util::stream::futures_unordered::FuturesUnordered<Fut> as core::ops::drop::Drop>::drop (mod.rs:574)
==26497==    by 0x1CA922: core::ptr::drop_in_place<futures_util::stream::futures_unordered::FuturesUnordered<subspace_cluster_networking::utils::AsyncJoinOnDrop<(libp2p_identity::peer_id::PeerId,alloc::vec::Vec<multiaddr::Multiaddr>)>>> (mod.rs:515)
==26497==    by 0x1C61F9: core::ptr::drop_in_place<subspace_cluster_networking::network_worker::NetworkWorker<subspace_cluster_networking::tests::Requests,subspace_cluster_networking::tests::Responses>> (mod.rs:515)
==26497==  Block was alloc'd at
==26497==    at 0x4848899: malloc (in /usr/libexec/valgrind/vgpreload_memcheck-amd64-linux.so)
==26497==    by 0x29A64A: alloc::alloc::alloc (alloc.rs:98)
==26497==    by 0x29A80C: alloc::alloc::Global::alloc_impl (alloc.rs:181)
==26497==    by 0x29A57B: alloc::alloc::exchange_malloc (alloc.rs:241)
==26497==    by 0x24C7A7: new<alloc::sync::ArcInner<futures_util::stream::futures_unordered::task::Task<subspace_cluster_networking::utils::AsyncJoinOnDrop<(libp2p_identity::peer_id::PeerId, alloc::vec::Vec<multiaddr::Multiaddr, alloc::alloc::Global>)>>>> (boxed.rs:218)
==26497==    by 0x24C7A7: alloc::sync::Arc<T>::new (sync.rs:395)
==26497==    by 0x22AEF1: futures_util::stream::futures_unordered::FuturesUnordered<Fut>::push (mod.rs:167)
==26497==    by 0x2916A3: subspace_cluster_networking::network_worker::NetworkWorker<Requests,Responses>::handle_swarm_event::{{closure}} (network_worker.rs:277)
==26497==    by 0x28CDC9: subspace_cluster_networking::network_worker::NetworkWorker<Requests,Responses>::run::{{closure}} (network_worker.rs:128)
==26497==    by 0x41703A: subspace_cluster_networking::tests::basic::{{closure}}::{{closure}} (tests.rs:169)
==26497==    by 0x3CAE25: <core::pin::Pin<P> as core::future::future::Future>::poll (future.rs:124)
==26497==    by 0x38FA88: tokio::runtime::task::core::Core<T,S>::poll::{{closure}} (core.rs:328)
==26497==    by 0x38E0C5: with_mut<tokio::runtime::task::core::Stage<core::pin::Pin<alloc::boxed::Box<subspace_cluster_networking::tests::basic::{async_block#0}::{async_block_env#8}, alloc::alloc::Global>>>, core::task::poll::Poll<()>, tokio::runtime::task::core::{impl#6}::poll::{closure_env#0}<core::pin::Pin<alloc::boxed::Box<subspace_cluster_networking::tests::basic::{async_block#0}::{async_block_env#8}, alloc::alloc::Global>>, alloc::sync::Arc<tokio::runtime::scheduler::current_thread::Handle, alloc::alloc::Global>>> (unsafe_cell.rs:16)
==26497==    by 0x38E0C5: tokio::runtime::task::core::Core<T,S>::poll (core.rs:317)
==26497== 
==26497== Invalid read of size 8
==26497==    at 0x2644FB: core::sync::atomic::atomic_load (atomic.rs:3308)
==26497==    by 0x26664B: core::sync::atomic::AtomicPtr<T>::load (atomic.rs:1433)
==26497==    by 0x248D39: futures_util::stream::futures_unordered::ready_to_run_queue::ReadyToRunQueue<Fut>::dequeue (ready_to_run_queue.rs:75)
==26497==    by 0x1B9E37: <futures_util::stream::futures_unordered::ready_to_run_queue::ReadyToRunQueue<Fut> as core::ops::drop::Drop>::drop (ready_to_run_queue.rs:101)
==26497==    by 0x1CC5B2: core::ptr::drop_in_place<futures_util::stream::futures_unordered::ready_to_run_queue::ReadyToRunQueue<subspace_cluster_networking::utils::AsyncJoinOnDrop<(libp2p_identity::peer_id::PeerId,alloc::vec::Vec<multiaddr::Multiaddr>)>>> (mod.rs:515)
==26497==    by 0x2508FD: alloc::sync::Arc<T,A>::drop_slow (sync.rs:1804)
==26497==    by 0x1DCE40: <alloc::sync::Arc<T,A> as core::ops::drop::Drop>::drop (sync.rs:2459)
==26497==    by 0x1CE2F9: core::ptr::drop_in_place<alloc::sync::Arc<futures_util::stream::futures_unordered::ready_to_run_queue::ReadyToRunQueue<subspace_cluster_networking::utils::AsyncJoinOnDrop<(libp2p_identity::peer_id::PeerId,alloc::vec::Vec<multiaddr::Multiaddr>)>>>> (mod.rs:515)
==26497==    by 0x1CA92E: core::ptr::drop_in_place<futures_util::stream::futures_unordered::FuturesUnordered<subspace_cluster_networking::utils::AsyncJoinOnDrop<(libp2p_identity::peer_id::PeerId,alloc::vec::Vec<multiaddr::Multiaddr>)>>> (mod.rs:515)
==26497==    by 0x1C61F9: core::ptr::drop_in_place<subspace_cluster_networking::network_worker::NetworkWorker<subspace_cluster_networking::tests::Requests,subspace_cluster_networking::tests::Responses>> (mod.rs:515)
==26497==    by 0x41709E: subspace_cluster_networking::tests::basic::{{closure}}::{{closure}} (tests.rs:170)
==26497==    by 0x3CAE25: <core::pin::Pin<P> as core::future::future::Future>::poll (future.rs:124)
==26497==  Address 0x4c8de60 is 64 bytes inside a block of size 80 free'd
==26497==    at 0x484B27F: free (in /usr/libexec/valgrind/vgpreload_memcheck-amd64-linux.so)
==26497==    by 0x7A378F: <alloc::alloc::Global as core::alloc::Allocator>::deallocate (alloc.rs:117)
==26497==    by 0x7A04AF: <&A as core::alloc::Allocator>::deallocate (mod.rs:392)
==26497==    by 0x1E217F: <alloc::sync::Weak<T,A> as core::ops::drop::Drop>::drop (sync.rs:3050)
==26497==    by 0x1CE549: core::ptr::drop_in_place<alloc::sync::Weak<futures_util::stream::futures_unordered::task::Task<subspace_cluster_networking::utils::AsyncJoinOnDrop<(libp2p_identity::peer_id::PeerId,alloc::vec::Vec<multiaddr::Multiaddr>)>>,&alloc::alloc::Global>> (mod.rs:515)
==26497==    by 0x250A4C: drop<alloc::sync::Weak<futures_util::stream::futures_unordered::task::Task<subspace_cluster_networking::utils::AsyncJoinOnDrop<(libp2p_identity::peer_id::PeerId, alloc::vec::Vec<multiaddr::Multiaddr, alloc::alloc::Global>)>>, &alloc::alloc::Global>> (mod.rs:992)
==26497==    by 0x250A4C: alloc::sync::Arc<T,A>::drop_slow (sync.rs:1810)
==26497==    by 0x1DD9D0: <alloc::sync::Arc<T,A> as core::ops::drop::Drop>::drop (sync.rs:2459)
==26497==    by 0x1CC549: core::ptr::drop_in_place<alloc::sync::Arc<futures_util::stream::futures_unordered::task::Task<subspace_cluster_networking::utils::AsyncJoinOnDrop<(libp2p_identity::peer_id::PeerId,alloc::vec::Vec<multiaddr::Multiaddr>)>>>> (mod.rs:515)
==26497==    by 0x22269E: futures_util::stream::futures_unordered::FuturesUnordered<Fut>::release_task (mod.rs:283)
==26497==    by 0x1B9BC9: <futures_util::stream::futures_unordered::FuturesUnordered<Fut> as core::ops::drop::Drop>::drop (mod.rs:574)
==26497==    by 0x1CA922: core::ptr::drop_in_place<futures_util::stream::futures_unordered::FuturesUnordered<subspace_cluster_networking::utils::AsyncJoinOnDrop<(libp2p_identity::peer_id::PeerId,alloc::vec::Vec<multiaddr::Multiaddr>)>>> (mod.rs:515)
==26497==    by 0x1C61F9: core::ptr::drop_in_place<subspace_cluster_networking::network_worker::NetworkWorker<subspace_cluster_networking::tests::Requests,subspace_cluster_networking::tests::Responses>> (mod.rs:515)
==26497==  Block was alloc'd at
==26497==    at 0x4848899: malloc (in /usr/libexec/valgrind/vgpreload_memcheck-amd64-linux.so)
==26497==    by 0x29A64A: alloc::alloc::alloc (alloc.rs:98)
==26497==    by 0x29A80C: alloc::alloc::Global::alloc_impl (alloc.rs:181)
==26497==    by 0x29A57B: alloc::alloc::exchange_malloc (alloc.rs:241)
==26497==    by 0x24C7A7: new<alloc::sync::ArcInner<futures_util::stream::futures_unordered::task::Task<subspace_cluster_networking::utils::AsyncJoinOnDrop<(libp2p_identity::peer_id::PeerId, alloc::vec::Vec<multiaddr::Multiaddr, alloc::alloc::Global>)>>>> (boxed.rs:218)
==26497==    by 0x24C7A7: alloc::sync::Arc<T>::new (sync.rs:395)
==26497==    by 0x22AEF1: futures_util::stream::futures_unordered::FuturesUnordered<Fut>::push (mod.rs:167)
==26497==    by 0x2916A3: subspace_cluster_networking::network_worker::NetworkWorker<Requests,Responses>::handle_swarm_event::{{closure}} (network_worker.rs:277)
==26497==    by 0x28CDC9: subspace_cluster_networking::network_worker::NetworkWorker<Requests,Responses>::run::{{closure}} (network_worker.rs:128)
==26497==    by 0x41703A: subspace_cluster_networking::tests::basic::{{closure}}::{{closure}} (tests.rs:169)
==26497==    by 0x3CAE25: <core::pin::Pin<P> as core::future::future::Future>::poll (future.rs:124)
==26497==    by 0x38FA88: tokio::runtime::task::core::Core<T,S>::poll::{{closure}} (core.rs:328)
==26497==    by 0x38E0C5: with_mut<tokio::runtime::task::core::Stage<core::pin::Pin<alloc::boxed::Box<subspace_cluster_networking::tests::basic::{async_block#0}::{async_block_env#8}, alloc::alloc::Global>>>, core::task::poll::Poll<()>, tokio::runtime::task::core::{impl#6}::poll::{closure_env#0}<core::pin::Pin<alloc::boxed::Box<subspace_cluster_networking::tests::basic::{async_block#0}::{async_block_env#8}, alloc::alloc::Global>>, alloc::sync::Arc<tokio::runtime::scheduler::current_thread::Handle, alloc::alloc::Global>>> (unsafe_cell.rs:16)
==26497==    by 0x38E0C5: tokio::runtime::task::core::Core<T,S>::poll (core.rs:317)
==26497== 
==26497== Invalid read of size 8
==26497==    at 0x1DD9B6: <alloc::sync::Arc<T,A> as core::ops::drop::Drop>::drop (atomic.rs:3359)
==26497==    by 0x1CC549: core::ptr::drop_in_place<alloc::sync::Arc<futures_util::stream::futures_unordered::task::Task<subspace_cluster_networking::utils::AsyncJoinOnDrop<(libp2p_identity::peer_id::PeerId,alloc::vec::Vec<multiaddr::Multiaddr>)>>>> (mod.rs:515)
==26497==    by 0x40D75C: core::mem::drop (mod.rs:992)
==26497==    by 0x1B9E7A: <futures_util::stream::futures_unordered::ready_to_run_queue::ReadyToRunQueue<Fut> as core::ops::drop::Drop>::drop (ready_to_run_queue.rs:104)
==26497==    by 0x1CC5B2: core::ptr::drop_in_place<futures_util::stream::futures_unordered::ready_to_run_queue::ReadyToRunQueue<subspace_cluster_networking::utils::AsyncJoinOnDrop<(libp2p_identity::peer_id::PeerId,alloc::vec::Vec<multiaddr::Multiaddr>)>>> (mod.rs:515)
==26497==    by 0x2508FD: alloc::sync::Arc<T,A>::drop_slow (sync.rs:1804)
==26497==    by 0x1DCE40: <alloc::sync::Arc<T,A> as core::ops::drop::Drop>::drop (sync.rs:2459)
==26497==    by 0x1CE2F9: core::ptr::drop_in_place<alloc::sync::Arc<futures_util::stream::futures_unordered::ready_to_run_queue::ReadyToRunQueue<subspace_cluster_networking::utils::AsyncJoinOnDrop<(libp2p_identity::peer_id::PeerId,alloc::vec::Vec<multiaddr::Multiaddr>)>>>> (mod.rs:515)
==26497==    by 0x1CA92E: core::ptr::drop_in_place<futures_util::stream::futures_unordered::FuturesUnordered<subspace_cluster_networking::utils::AsyncJoinOnDrop<(libp2p_identity::peer_id::PeerId,alloc::vec::Vec<multiaddr::Multiaddr>)>>> (mod.rs:515)
==26497==    by 0x1C61F9: core::ptr::drop_in_place<subspace_cluster_networking::network_worker::NetworkWorker<subspace_cluster_networking::tests::Requests,subspace_cluster_networking::tests::Responses>> (mod.rs:515)
==26497==    by 0x41709E: subspace_cluster_networking::tests::basic::{{closure}}::{{closure}} (tests.rs:170)
==26497==    by 0x3CAE25: <core::pin::Pin<P> as core::future::future::Future>::poll (future.rs:124)
==26497==  Address 0x4c8de20 is 0 bytes inside a block of size 80 free'd
==26497==    at 0x484B27F: free (in /usr/libexec/valgrind/vgpreload_memcheck-amd64-linux.so)
==26497==    by 0x7A378F: <alloc::alloc::Global as core::alloc::Allocator>::deallocate (alloc.rs:117)
==26497==    by 0x7A04AF: <&A as core::alloc::Allocator>::deallocate (mod.rs:392)
==26497==    by 0x1E217F: <alloc::sync::Weak<T,A> as core::ops::drop::Drop>::drop (sync.rs:3050)
==26497==    by 0x1CE549: core::ptr::drop_in_place<alloc::sync::Weak<futures_util::stream::futures_unordered::task::Task<subspace_cluster_networking::utils::AsyncJoinOnDrop<(libp2p_identity::peer_id::PeerId,alloc::vec::Vec<multiaddr::Multiaddr>)>>,&alloc::alloc::Global>> (mod.rs:515)
==26497==    by 0x250A4C: drop<alloc::sync::Weak<futures_util::stream::futures_unordered::task::Task<subspace_cluster_networking::utils::AsyncJoinOnDrop<(libp2p_identity::peer_id::PeerId, alloc::vec::Vec<multiaddr::Multiaddr, alloc::alloc::Global>)>>, &alloc::alloc::Global>> (mod.rs:992)
==26497==    by 0x250A4C: alloc::sync::Arc<T,A>::drop_slow (sync.rs:1810)
==26497==    by 0x1DD9D0: <alloc::sync::Arc<T,A> as core::ops::drop::Drop>::drop (sync.rs:2459)
==26497==    by 0x1CC549: core::ptr::drop_in_place<alloc::sync::Arc<futures_util::stream::futures_unordered::task::Task<subspace_cluster_networking::utils::AsyncJoinOnDrop<(libp2p_identity::peer_id::PeerId,alloc::vec::Vec<multiaddr::Multiaddr>)>>>> (mod.rs:515)
==26497==    by 0x22269E: futures_util::stream::futures_unordered::FuturesUnordered<Fut>::release_task (mod.rs:283)
==26497==    by 0x1B9BC9: <futures_util::stream::futures_unordered::FuturesUnordered<Fut> as core::ops::drop::Drop>::drop (mod.rs:574)
==26497==    by 0x1CA922: core::ptr::drop_in_place<futures_util::stream::futures_unordered::FuturesUnordered<subspace_cluster_networking::utils::AsyncJoinOnDrop<(libp2p_identity::peer_id::PeerId,alloc::vec::Vec<multiaddr::Multiaddr>)>>> (mod.rs:515)
==26497==    by 0x1C61F9: core::ptr::drop_in_place<subspace_cluster_networking::network_worker::NetworkWorker<subspace_cluster_networking::tests::Requests,subspace_cluster_networking::tests::Responses>> (mod.rs:515)
==26497==  Block was alloc'd at
==26497==    at 0x4848899: malloc (in /usr/libexec/valgrind/vgpreload_memcheck-amd64-linux.so)
==26497==    by 0x29A64A: alloc::alloc::alloc (alloc.rs:98)
==26497==    by 0x29A80C: alloc::alloc::Global::alloc_impl (alloc.rs:181)
==26497==    by 0x29A57B: alloc::alloc::exchange_malloc (alloc.rs:241)
==26497==    by 0x24C7A7: new<alloc::sync::ArcInner<futures_util::stream::futures_unordered::task::Task<subspace_cluster_networking::utils::AsyncJoinOnDrop<(libp2p_identity::peer_id::PeerId, alloc::vec::Vec<multiaddr::Multiaddr, alloc::alloc::Global>)>>>> (boxed.rs:218)
==26497==    by 0x24C7A7: alloc::sync::Arc<T>::new (sync.rs:395)
==26497==    by 0x22AEF1: futures_util::stream::futures_unordered::FuturesUnordered<Fut>::push (mod.rs:167)
==26497==    by 0x2916A3: subspace_cluster_networking::network_worker::NetworkWorker<Requests,Responses>::handle_swarm_event::{{closure}} (network_worker.rs:277)
==26497==    by 0x28CDC9: subspace_cluster_networking::network_worker::NetworkWorker<Requests,Responses>::run::{{closure}} (network_worker.rs:128)
==26497==    by 0x41703A: subspace_cluster_networking::tests::basic::{{closure}}::{{closure}} (tests.rs:169)
==26497==    by 0x3CAE25: <core::pin::Pin<P> as core::future::future::Future>::poll (future.rs:124)
==26497==    by 0x38FA88: tokio::runtime::task::core::Core<T,S>::poll::{{closure}} (core.rs:328)
==26497==    by 0x38E0C5: with_mut<tokio::runtime::task::core::Stage<core::pin::Pin<alloc::boxed::Box<subspace_cluster_networking::tests::basic::{async_block#0}::{async_block_env#8}, alloc::alloc::Global>>>, core::task::poll::Poll<()>, tokio::runtime::task::core::{impl#6}::poll::{closure_env#0}<core::pin::Pin<alloc::boxed::Box<subspace_cluster_networking::tests::basic::{async_block#0}::{async_block_env#8}, alloc::alloc::Global>>, alloc::sync::Arc<tokio::runtime::scheduler::current_thread::Handle, alloc::alloc::Global>>> (unsafe_cell.rs:16)
==26497==    by 0x38E0C5: tokio::runtime::task::core::Core<T,S>::poll (core.rs:317)
==26497== 
test tests::basic ... ok

test result: ok. 2 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 4.30s

==26497== 
==26497== HEAP SUMMARY:
==26497==     in use at exit: 1,570 bytes in 18 blocks
==26497==   total heap usage: 5,499 allocs, 5,481 frees, 1,436,315 bytes allocated
==26497== 
==26497== LEAK SUMMARY:
==26497==    definitely lost: 0 bytes in 0 blocks
==26497==    indirectly lost: 0 bytes in 0 blocks
==26497==      possibly lost: 312 bytes in 2 blocks
==26497==    still reachable: 1,258 bytes in 16 blocks
==26497==         suppressed: 0 bytes in 0 blocks
==26497== Rerun with --leak-check=full to see details of leaked memory
==26497== 
==26497== For lists of detected and suppressed errors, rerun with: -s
==26497== ERROR SUMMARY: 6 errors from 4 contexts (suppressed: 0 from 0)

@Darksonn
Copy link
Contributor

Darksonn commented Apr 2, 2024

Yeah, that looks like memory corruption. They're not just false positives. You have a use-after-free or double-free somewhere. Most likely, the stack trace you reported here happens much later than the actual problem. That is, the allocator is corrupted at some earlier point, and the panic inside Tokio is just when the corruption is noticed later.

I think it's probably likely that the problem is in your own unsafe code.

@nazar-pc
Copy link
Author

nazar-pc commented Apr 2, 2024 •
edited
Loading

I think it's probably likely that the problem is in your own unsafe code.

That is a reasonable assumption, but I don't have unsafe in my code and list of dependencies is pretty respectable. Never used Miri before for anything, might try it now.

UPD: Can't use MIni for now:

851 |     syscall!(socket(family, ty, protocol))
    |     ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ can't call foreign function `socket` on OS `linux`

@nazar-pc
Copy link
Author

nazar-pc commented Apr 2, 2024

Do I read valgrind correctly that it indicates an issue in futures crate?

@Darksonn
Copy link
Contributor

Darksonn commented Apr 3, 2024

The valgrind output indicates that the use-after-free happened in the futures crate. But that doesn't necessarily mean that the bug is in the futures crate.

but I don't have unsafe in my code

If I search for "unsafe" in your repository, there are 32 results.

@nazar-pc
Copy link
Author

nazar-pc commented Apr 3, 2024

Ah, yes, all of that code was audited to be correct, but either way the crate I pointed to specifically is isolated and not relying on any of the code from other parts of the repository.

@Darksonn
Copy link
Contributor

Darksonn commented Apr 3, 2024

How about adding some printlns to the destructors of relevant objects (e.g. that NetworkWorker) to check whether any destructors run twice?

@Darksonn
Copy link
Contributor

Closing due to inactivity. I still don't think this is likely to be a bug in Tokio.

@Darksonn Darksonn closed this as not planned Won't fix, can't repro, duplicate, stale Apr 20, 2024
@nazar-pc nazar-pc mentioned this issue Jun 12, 2024
Closed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
A-tokio Area: The main tokio crate C-bug Category: This is a bug. M-runtime Module: tokio/runtime
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@Darksonn @nazar-pc