You signed in with another tab or window. Reload to refresh your session.You signed out in another tab or window. Reload to refresh your session.You switched accounts on another tab or window. Reload to refresh your session.Dismiss alert
{{ message }}
Repository navigation
Spawned task is stuck during flushing in File.drop() #900
I built this example in the following configuration:
Debian sid as a host machine.
NetBSD 9.1 as a guest, installed in qemu (kvm)
Rust 1.47.0 installed on NetBSD via rustup.
When I execute cargo run, the program prints before drop and gets stuck. Apparently the problem is that despite what comment says, executor does not handle blocking operation in Drop correctly:
// We need to flush the file on drop. Unfortunately, that is not possible to do in a
After waiting a minute and terminating the program, the file foo.txt is created, but is empty.
When I uncomment the line file.flush().await.unwrap();, the program prints
before drop
after drop
and exits.
On my Linux machine this works correctly. It is not a QEMU bug, as the same problem is experienced on some Android phones, see original issue chatmail/core#2032
localhost$ gdb -p 1305
GNU gdb (GDB) 8.3
Copyright (C) 2019 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.
Type "show copying" and "show warranty" for details.
This GDB was configured as "x86_64--netbsd".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>.
Find the GDB manual and other documentation resources online at:
<http://www.gnu.org/software/gdb/documentation/>.
For help, type "help".
Type "apropos word" to search for commands related to "word".
Attaching to process 1305
Reading symbols from /home/user/filedrop/target/debug/./filedrop...
[New LWP 2 of process 1305]
[New LWP 1 of process 1305]
Reading symbols from /usr/lib/libpthread.so.1...
(No debugging symbols found in /usr/lib/libpthread.so.1)
Reading symbols from /usr/lib/libgcc_s.so.1...
(No debugging symbols found in /usr/lib/libgcc_s.so.1)
Reading symbols from /usr/lib/libc.so.12...
(No debugging symbols found in /usr/lib/libc.so.12)
Reading symbols from /usr/libexec/ld.elf_so...
(No debugging symbols found in /usr/libexec/ld.elf_so)
[Switching to LWP 3 of process 1305]
0x00006fc97cea1faa in ___lwp_park60 () from /usr/lib/libc.so.12
warning: Unsupported auto-load script at offset 0 in section .debug_gdb_scripts
of file /home/user/filedrop/target/debug/filedrop.
Use `info auto-load python-scripts [REGEXP]' to list them.
(gdb) info threads
Id Target Id Frame
* 1 LWP 3 of process 1305 "async-io" 0x00006fc97cea1faa in ___lwp_park60 () from /usr/lib/libc.so.12
2 LWP 2 of process 1305 "async-std/runti" 0x00006fc97cea1faa in ___lwp_park60 () from /usr/lib/libc.so.12
3 LWP 1 of process 1305 "" 0x00006fc97ce42b8a in _sys___kevent50 () from /usr/lib/libc.so.12
(gdb) bt
#0 0x00006fc97cea1faa in ___lwp_park60 () from /usr/lib/libc.so.12
#1 0x00006fc97d8095a6 in ?? () from /usr/lib/libpthread.so.1
#2 0x000000015c0a86ed in std::sys::unix::mutex::Mutex::lock (
self=0x6fc97db1b3c0)
at /rustc/18bf6b4f01a6feaf7259ba7cdae58031af1b7b39/library/std/src/sys/unix/mutex.rs:63
#3 0x000000015c0a7f1a in std::sys_common::mutex::Mutex::raw_lock (
self=0x6fc97db1b3c0)
at /rustc/18bf6b4f01a6feaf7259ba7cdae58031af1b7b39/library/std/src/sys_common/mutex.rs:42
#4 0x000000015c09dca6 in std::sync::mutex::Mutex<T>::lock (
self=0x15c37d1b0 <async_io::reactor::Reactor::get::REACTOR+128>)
at /rustc/18bf6b4f01a6feaf7259ba7cdae58031af1b7b39/library/std/src/sync/mutex.rs:269
#5 0x000000015c099c2b in async_io::reactor::Reactor::lock (
self=0x15c37d138 <async_io::reactor::Reactor::get::REACTOR+8>)
at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/async-io-1.1.10/src/reactor.rs:163
#6 0x000000015c0b26f3 in async_io::driver::main_loop (parker=...)
at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/async-io-1.1.10/src/driver.rs:54
#7 0x000000015c0b240a in async_io::driver::UNPARKER::{{closure}}::{{closure}}
()
at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/async-io-1.1.10/src/driver.rs:29
#8 0x000000015c0a85ee in std::sys_common::backtrace::__rust_begin_short_backtrace (f=...)
at /rustc/18bf6b4f01a6feaf7259ba7cdae58031af1b7b39/library/std/src/sys_common/backtrace.rs:137
#9 0x000000015c0aeb2b in std::thread::Builder::spawn_unchecked::{{closure}}::{{closure}} ()
at /rustc/18bf6b4f01a6feaf7259ba7cdae58031af1b7b39/library/std/src/thread/mod.rs:458
#10 0x000000015c0ae18f in <std::panic::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once (self=..., _args=())
at /rustc/18bf6b4f01a6feaf7259ba7cdae58031af1b7b39/library/std/src/panic.rs:308
#11 0x000000015c09c1cc in std::panicking::try::do_call (
data=0x6fc97c5efe30 <error reading variable>)
at /rustc/18bf6b4f01a6feaf7259ba7cdae58031af1b7b39/library/std/src/panicking.rs:373
#12 0x000000015c09d6ad in __rust_try ()
#13 0x000000015c09c137 in std::panicking::try (f=...)
at /rustc/18bf6b4f01a6feaf7259ba7cdae58031af1b7b39/library/std/src/panicking.rs:337
#14 0x000000015c0ae23f in std::panic::catch_unwind (f=...)
at /rustc/18bf6b4f01a6feaf7259ba7cdae58031af1b7b39/library/std/src/panic.rs:379
#15 0x000000015c0ae942 in std::thread::Builder::spawn_unchecked::{{closure}} ()
at /rustc/18bf6b4f01a6feaf7259ba7cdae58031af1b7b39/library/std/src/thread/mod.rs:457
#16 0x000000015c0a262f in core::ops::function::FnOnce::call_once{{vtable-shim}}
()
at /rustc/18bf6b4f01a6feaf7259ba7cdae58031af1b7b39/library/core/src/ops/function.rs:227
#17 0x000000015c10408a in <alloc::boxed::Box<F> as core::ops::function::FnOnce<A>>::call_once ()
at /rustc/18bf6b4f01a6feaf7259ba7cdae58031af1b7b39/library/alloc/src/boxed.rs:1042
#18 <alloc::boxed::Box<F> as core::ops::function::FnOnce<A>>::call_once ()
at /rustc/18bf6b4f01a6feaf7259ba7cdae58031af1b7b39/library/alloc/src/boxed.rs:1042
#19 std::sys::unix::thread::Thread::new::thread_start ()
at library/std/src/sys/unix/thread.rs:87
#20 0x00006fc97d80c072 in ?? () from /usr/lib/libpthread.so.1
#21 0x00006fc97ce87bb0 in ?? () from /usr/lib/libc.so.12
#22 0x0000000000000000 in ?? ()
(gdb) thread 2
[Switching to thread 2 (LWP 2 of process 1305)]
#0 0x00006fc97cea1faa in ___lwp_park60 () from /usr/lib/libc.so.12
(gdb) bt
#0 0x00006fc97cea1faa in ___lwp_park60 () from /usr/lib/libc.so.12
#1 0x00006fc97d80a71f in pthread_cond_timedwait ()
from /usr/lib/libpthread.so.1
#2 0x000000015c0e278d in std::sys::unix::condvar::Condvar::wait (
self=0x6fc97db1c5c0, mutex=0x6fc97db1c590)
at /rustc/18bf6b4f01a6feaf7259ba7cdae58031af1b7b39/library/std/src/sys/unix/condvar.rs:69
#3 0x000000015c0e0450 in std::sys_common::condvar::Condvar::wait (
self=0x6fc97db1c5c0, mutex=0x6fc97db1c590)
at /rustc/18bf6b4f01a6feaf7259ba7cdae58031af1b7b39/library/std/src/sys_common/condvar.rs:50
#4 0x000000015c0e1c54 in std::sync::condvar::Condvar::wait (
self=0x6fc97dac60e8, guard=...)
at /rustc/18bf6b4f01a6feaf7259ba7cdae58031af1b7b39/library/std/src/sync/condvar.rs:199
#5 0x000000015c0df1ca in parking::Inner::park (self=0x6fc97dac60d0,
timeout=...)
at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/parking-2.0.0/src/lib.rs:305
#6 0x000000015c0de9ea in parking::Parker::park (self=0x6fc97db1c570)
at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/parking-2.0.0/src/lib.rs:103
#7 0x000000015c047bd7 in futures_lite::future::block_on::{{closure}} (
cache=0x6fc97db1c568)
at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/futures-lite-1.11.2/src/future.rs:91
#8 0x000000015c04d234 in std::thread::local::LocalKey<T>::try_with (
self=0x15c3710f8, f=...)
at /rustc/18bf6b4f01a6feaf7259ba7cdae58031af1b7b39/library/std/src/thread/local.rs:265
#9 0x000000015c04cd09 in std::thread::local::LocalKey<T>::with (
self=0x15c3710f8, f=...)
at /rustc/18bf6b4f01a6feaf7259ba7cdae58031af1b7b39/library/std/src/thread/local.rs:241
#10 0x000000015c047a30 in futures_lite::future::block_on (future=...)
at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/futures-lite-1.11.2/src/future.rs:79
#11 0x000000015c056554 in <async_std::fs::file::File as core::ops::drop::Drop>::drop (self=0x6fc97dafa298)
at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/async-std-1.6.5/src/fs/file.rs:318
#12 0x000000015c04d7c6 in core::ptr::drop_in_place ()
at /rustc/18bf6b4f01a6feaf7259ba7cdae58031af1b7b39/library/core/src/ptr/mod.rs:184
#13 0x000000015c01dc4d in filedrop::create_file::{{closure}} ()
at src/main.rs:12
#14 0x000000015c021559 in <core::future::from_generator::GenFuture<T> as core::future::future::Future>::poll (self=..., cx=0x6fc97c7fe2d0)
at /rustc/18bf6b4f01a6feaf7259ba7cdae58031af1b7b39/library/core/src/future/mod.rs:79
#15 0x000000015c01dee8 in filedrop::test::{{closure}}::{{closure}} ()
at src/main.rs:16
#16 0x000000015c0214c9 in <core::future::from_generator::GenFuture<T> as core::future::future::Future>::poll (self=..., cx=0x6fc97c7fe2d0)
at /rustc/18bf6b4f01a6feaf7259ba7cdae58031af1b7b39/library/core/src/future/mod.rs:79
#17 0x000000015c0220c9 in <async_std::task::builder::SupportTaskLocals<F> as core::future::future::Future>::poll::{{closure}} ()
at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/async-std-1.6.5/src/task/builder.rs:199
#18 0x000000015c0208f3 in async_std::task::task_locals_wrapper::TaskLocalsWrapper::set_current::{{closure}} (current=0x6fc97db19d48)
at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/async-std-1.6.5/src/task/task_locals_wrapper.rs:60
#19 0x000000015c023fa1 in std::thread::local::LocalKey<T>::try_with (
self=0x15c370718, f=...)
at /rustc/18bf6b4f01a6feaf7259ba7cdae58031af1b7b39/library/std/src/thread/local.rs:265
#20 0x000000015c023dbd in std::thread::local::LocalKey<T>::with (
self=0x15c370718, f=...)
at /rustc/18bf6b4f01a6feaf7259ba7cdae58031af1b7b39/library/std/src/thread/local.rs:241
#21 0x000000015c020638 in async_std::task::task_locals_wrapper::TaskLocalsWrapper::set_current (task=0x6fc97dafa258, f=...)
at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/async-std-1.6.5/src/task/task_locals_wrapper.rs:55
#22 0x000000015c022028 in <async_std::task::builder::SupportTaskLocals<F> as core::future::future::Future>::poll (self=..., cx=0x6fc97c7fe2d0)
at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/async-std-1.6.5/src/task/builder.rs:197
#23 0x000000015c028f45 in async_executor::Executor::spawn::{{closure}} ()
at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/async-executor-1.3.0/src/lib.rs:116
#24 0x000000015c021949 in <core::future::from_generator::GenFuture<T> as core::future::future::Future>::poll (self=..., cx=0x6fc97c7fe2d0)
at /rustc/18bf6b4f01a6feaf7259ba7cdae58031af1b7b39/library/core/src/future/mod.rs:79
#25 0x000000015c033c8d in async_task::raw::RawTask<F,T,S>::run (
ptr=0x6fc97dafa180)
at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/async-task-4.0.3/src/raw.rs:489
#26 0x000000015c097ed6 in async_task::runnable::Runnable::run (self=...)
at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/async-task-4.0.3/src/runnable.rs:309
#27 0x000000015c0823c2 in async_executor::Executor::run::{{closure}}::{{closure}} ()
at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/async-executor-1.3.0/src/lib.rs:207
#28 0x000000015c0763ab in <core::future::from_generator::GenFuture<T> as core::future::future::Future>::poll (self=..., cx=0x6fc97c7fed10)
at /rustc/18bf6b4f01a6feaf7259ba7cdae58031af1b7b39/library/core/src/future/mod.rs:79
#29 0x000000015c07a37d in <futures_lite::future::Or<F1,F2> as core::future::future::Future>::poll (self=..., cx=0x6fc97c7fed10)
at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/futures-lite-1.11.2/src/future.rs:529
#30 0x000000015c081fa4 in async_executor::Executor::run::{{closure}} ()
at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/async-executor-1.3.0/src/lib.rs:214
#31 0x000000015c07656b in <core::future::from_generator::GenFuture<T> as core::future::future::Future>::poll (self=..., cx=0x6fc97c7fed10)
at /rustc/18bf6b4f01a6feaf7259ba7cdae58031af1b7b39/library/core/src/future/mod.rs:79
#32 0x000000015c07a2cd in <futures_lite::future::Or<F1,F2> as core::future::future::Future>::poll (self=..., cx=0x6fc97c7fed10)
at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/futures-lite-1.11.2/src/future.rs:529
#33 0x000000015c082a7c in async_io::driver::block_on (future=...)
at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/async-io-1.1.10/src/driver.rs:142
#34 0x000000015c07b7f6 in async_global_executor::reactor::block_on::{{closure}}
()
at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/async-global-executor-1.4.2/src/lib.rs:48
#35 0x000000015c07b7b0 in async_global_executor::reactor::block_on (future=...)
at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/async-global-executor-1.4.2/src/lib.rs:55
#36 0x000000015c076edc in async_global_executor::init_with_config::{{closure}}::{{closure}}::{{closure}} (executor=0x6fc97db1c2c8)
at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/async-global-executor-1.4.2/src/lib.rs:175
#37 0x000000015c075c1e in std::thread::local::LocalKey<T>::try_with (
self=0x15c371c18, f=...)
at /rustc/18bf6b4f01a6feaf7259ba7cdae58031af1b7b39/library/std/src/thread/local.rs:265
#38 0x000000015c07525f in std::thread::local::LocalKey<T>::with (
self=0x15c371c18, f=...)
at /rustc/18bf6b4f01a6feaf7259ba7cdae58031af1b7b39/library/std/src/thread/local.rs:241
#39 0x000000015c076f41 in async_global_executor::init_with_config::{{closure}}::{{closure}} ()
at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/async-global-executor-1.4.2/src/lib.rs:172
#40 0x000000015c077a9e in std::panicking::try::do_call (
data=0x6fc97c7ffc98 <error reading variable>)
at /rustc/18bf6b4f01a6feaf7259ba7cdae58031af1b7b39/library/std/src/panicking.rs:373
#41 0x000000015c077c4d in __rust_try ()
#42 0x000000015c077a14 in std::panicking::try (f=...)
at /rustc/18bf6b4f01a6feaf7259ba7cdae58031af1b7b39/library/std/src/panicking.rs:337
#43 0x000000015c07a98a in std::panic::catch_unwind (f=...)
at /rustc/18bf6b4f01a6feaf7259ba7cdae58031af1b7b39/library/std/src/panic.rs:379
#44 0x000000015c076f5d in async_global_executor::init_with_config::{{closure}}
()
at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/async-global-executor-1.4.2/src/lib.rs:171
#45 0x000000015c07f049 in std::sys_common::backtrace::__rust_begin_short_backtrace (f=...)
at /rustc/18bf6b4f01a6feaf7259ba7cdae58031af1b7b39/library/std/src/sys_common/backtrace.rs:137
#46 0x000000015c077907 in std::thread::Builder::spawn_unchecked::{{closure}}::{{closure}} ()
at /rustc/18bf6b4f01a6feaf7259ba7cdae58031af1b7b39/library/std/src/thread/mod.rs:458
#47 0x000000015c07a77a in <std::panic::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once (self=..., _args=())
at /rustc/18bf6b4f01a6feaf7259ba7cdae58031af1b7b39/library/std/src/panic.rs:308
#48 0x000000015c077acf in std::panicking::try::do_call (
data=0x6fc97c7ffe38 <error reading variable>)
at /rustc/18bf6b4f01a6feaf7259ba7cdae58031af1b7b39/library/std/src/panicking.rs:373
#49 0x000000015c077c4d in __rust_try ()
#50 0x000000015c077984 in std::panicking::try (f=...)
at /rustc/18bf6b4f01a6feaf7259ba7cdae58031af1b7b39/library/std/src/panicking.rs:337
#51 0x000000015c07a95a in std::panic::catch_unwind (f=...)
at /rustc/18bf6b4f01a6feaf7259ba7cdae58031af1b7b39/library/std/src/panic.rs:379
#52 0x000000015c07774c in std::thread::Builder::spawn_unchecked::{{closure}} ()
at /rustc/18bf6b4f01a6feaf7259ba7cdae58031af1b7b39/library/std/src/thread/mod.rs:457
#53 0x000000015c074469 in core::ops::function::FnOnce::call_once{{vtable-shim}}
()
at /rustc/18bf6b4f01a6feaf7259ba7cdae58031af1b7b39/library/core/src/ops/function.rs:227
#54 0x000000015c10408a in <alloc::boxed::Box<F> as core::ops::function::FnOnce<A>>::call_once ()
at /rustc/18bf6b4f01a6feaf7259ba7cdae58031af1b7b39/library/alloc/src/boxed.rs:1042
#55 <alloc::boxed::Box<F> as core::ops::function::FnOnce<A>>::call_once ()
at /rustc/18bf6b4f01a6feaf7259ba7cdae58031af1b7b39/library/alloc/src/boxed.rs:1042
#56 std::sys::unix::thread::Thread::new::thread_start ()
at library/std/src/sys/unix/thread.rs:87
#57 0x00006fc97d80c072 in ?? () from /usr/lib/libpthread.so.1
#58 0x00006fc97ce87bb0 in ?? () from /usr/lib/libc.so.12
#59 0x0000000000400000 in ?? ()
#60 0x00006fc97cc00000 in ?? ()
#61 0x0000001003a0efff in ?? ()
#62 0x00006fc97ca000c0 in ?? ()
#63 0x00000000001fff40 in ?? ()
#64 0x0000000000000000 in ?? ()
(gdb) thread 3
[Switching to thread 3 (LWP 1 of process 1305)]
#0 0x00006fc97ce42b8a in _sys___kevent50 () from /usr/lib/libc.so.12
(gdb) bt
#0 0x00006fc97ce42b8a in _sys___kevent50 () from /usr/lib/libc.so.12
#1 0x00006fc97d807879 in __kevent50 () from /usr/lib/libpthread.so.1
#2 0x000000015c0ca30c in polling::kqueue::Poller::wait (
self=0x15c37d160 <async_io::reactor::Reactor::get::REACTOR+48>,
events=0x15c37d148 <async_io::reactor::Reactor::get::REACTOR+24>,
timeout=...)
at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/polling-2.0.2/src/kqueue.rs:144
#3 0x000000015c0d08aa in polling::Poller::wait (
self=0x15c37d138 <async_io::reactor::Reactor::get::REACTOR+8>,
events=0x15c37d1c0 <async_io::reactor::Reactor::get::REACTOR+144>,
timeout=...)
at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/polling-2.0.2/src/lib.rs:385
#4 0x000000015c09ac80 in async_io::reactor::ReactorLock::react (
self=0x7f7fff8ba4a0, timeout=...)
at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/async-io-1.1.10/src/reactor.rs:261
#5 0x000000015c02a7e7 in async_io::driver::block_on (future=...)
at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/async-io-1.1.10/src/driver.rs:188
#6 0x000000015c02c603 in async_global_executor::reactor::block_on::{{closure}}
()
at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/async-global-executor-1.4.2/src/lib.rs:48
#7 0x000000015c02c5c0 in async_global_executor::reactor::block_on (future=...)
at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/async-global-executor-1.4.2/src/lib.rs:55
#8 0x000000015c0252ac in async_global_executor::block_on::{{closure}} (
executor=0x6fc97db1b0f8)
at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/async-global-executor-1.4.2/src/lib.rs:212
#9 0x000000015c024354 in std::thread::local::LocalKey<T>::try_with (
self=0x15c370878, f=...)
at /rustc/18bf6b4f01a6feaf7259ba7cdae58031af1b7b39/library/std/src/thread/local.rs:265
#10 0x000000015c023cd7 in std::thread::local::LocalKey<T>::with (
self=0x15c370878, f=...)
at /rustc/18bf6b4f01a6feaf7259ba7cdae58031af1b7b39/library/std/src/thread/local.rs:241
#11 0x000000015c025243 in async_global_executor::block_on (future=...)
at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/async-global-executor-1.4.2/src/lib.rs:212
#12 0x000000015c0237fe in async_std::task::builder::Builder::blocking::{{closure--Type <RET> for more, q to quit, c to continue without paging--
}}::{{closure}} ()
at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/async-std-1.6.5/src/task/builder.rs:171
#13 0x000000015c0207d9 in async_std::task::task_locals_wrapper::TaskLocalsWrapper::set_current::{{closure}} (current=0x6fc97db19048)
at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/async-std-1.6.5/src/task/task_locals_wrapper.rs:60
#14 0x000000015c024b00 in std::thread::local::LocalKey<T>::try_with (
self=0x15c370718, f=...)
at /rustc/18bf6b4f01a6feaf7259ba7cdae58031af1b7b39/library/std/src/thread/local.rs:265
#15 0x000000015c023a4d in std::thread::local::LocalKey<T>::with (
self=0x15c370718, f=...)
at /rustc/18bf6b4f01a6feaf7259ba7cdae58031af1b7b39/library/std/src/thread/local.rs:241
#16 0x000000015c0206ed in async_std::task::task_locals_wrapper::TaskLocalsWrapper::set_current (task=0x7f7fff8bb4f0, f=...)
at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/async-std-1.6.5/src/task/task_locals_wrapper.rs:55
#17 0x000000015c0236fd in async_std::task::builder::Builder::blocking::{{closure}} (num_nested_blocking=0x6fc97db19008)
at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/async-std-1.6.--Type <RET> for more, q to quit, c to continue without paging--
5/src/task/builder.rs:168
#18 0x000000015c02471c in std::thread::local::LocalKey<T>::try_with (
self=0x15c370808, f=...)
at /rustc/18bf6b4f01a6feaf7259ba7cdae58031af1b7b39/library/std/src/thread/local.rs:265
#19 0x000000015c023e37 in std::thread::local::LocalKey<T>::with (
self=0x15c370808, f=...)
at /rustc/18bf6b4f01a6feaf7259ba7cdae58031af1b7b39/library/std/src/thread/local.rs:241
#20 0x000000015c0235a9 in async_std::task::builder::Builder::blocking (
self=..., future=...)
at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/async-std-1.6.5/src/task/builder.rs:161
#21 0x000000015c037a26 in async_std::task::block_on::block_on (future=...)
at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/async-std-1.6.5/src/task/block_on.rs:33
#22 0x000000015c021cd8 in filedrop::main () at src/main.rs:23
(gdb) quit
A debugging session is active.
Inferior 1 [process 1305] will be detached.
Quit anyway? (y or n) y
Detaching from program: /home/user/filedrop/target/debug/filedrop, process 1305
[Inferior 1 (process 1305) detached]
Sidenote: there is a third alternative to dropping unwritten data and flushing it in a blocking way. It's possible to spawn a new task that will do the flushing sometime later. If user did not care to flush the file, it can be postponed.
Maybe this can be reproduced more reliably and converted into a test? Is it possible to cause File to become unflushed in deterministic way? This is probably caused by slow qemu device built on top of HDD and old android SD card.
We likely need to stop flushing automatically in the drop impl, and add to the docs that flushing is required to be manual. This is what tokio::fs::File does, and likely the only way to be sure it works, as long as AsyncDrop is not yet there.
It's possible to remove Drop, but isn't it a workaround? What is the reason for panic in the first thread? What if I implement a File wrapper that does flush in drop, why shouldn't it work?
Reproduced on Alpine linux under qemu, running on top of qcow2 disk backed by HDD. Dumped the core, copied to the host system and loaded it in gdb. On the host system same binary successfully writes the file by the way. So it is reproducible both with kqueue and epoll, on NetBSD and Alpine Linux running in KVM and on real Android.
Stacktraces with epoll, produced on Debian from binary and core file downloaded from Alpine
(gdb) info threads
Id Target Id Frame
* 1 LWP 2257 0x00007f2406a40fcd in sccp ()
2 LWP 2211 0x00007f2406a3cead in epoll_pwait ()
3 LWP 2256 0x00007f2406a40fcd in sccp ()
(gdb) bt
#0 0x00007f2406a40fcd in sccp ()
#1 0x00007f2406a43b93 in __timedwait_cp ()
#2 0x0000000000000000 in ?? ()
(gdb) thread 3
[Switching to thread 3 (LWP 2256)]
#0 0x00007f2406a40fcd in sccp ()
(gdb) bt
#0 0x00007f2406a40fcd in sccp ()
#1 0x00007f2406a43b93 in __timedwait_cp ()
#2 0x0000000000000000 in ?? ()
(gdb) thread 2
[Switching to thread 2 (LWP 2211)]
#0 0x00007f2406a3cead in epoll_pwait ()
(gdb) bt
#0 0x00007f2406a3cead in epoll_pwait ()
#1 0x0000000000000001 in ?? ()
#2 0x00007f24069e3021 in polling::epoll::Poller::wait (self=0x7f2406ab50d8 <async_io::reactor::Reactor::get::REACTOR+48>, events=0x7f2406ab50c0 <async_io::reactor::Reactor::get::REACTOR+24>, timeout=...)
at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/polling-2.0.2/src/epoll.rs:157
#3 0x00007f24069ea19a in polling::Poller::wait (self=0x7f2406ab50b0 <async_io::reactor::Reactor::get::REACTOR+8>, events=0x7f2406ab5140 <async_io::reactor::Reactor::get::REACTOR+152>, timeout=...)
at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/polling-2.0.2/src/lib.rs:385
#4 0x00007f24069b3550 in async_io::reactor::ReactorLock::react (self=0x7ffe348afac0, timeout=...) at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/async-io-1.1.10/src/reactor.rs:261
#5 0x00007f2406926f77 in async_io::driver::block_on (future=...) at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/async-io-1.1.10/src/driver.rs:188
#6 0x00007f2406934093 in async_global_executor::reactor::block_on::{{closure}} () at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/async-global-executor-1.4.2/src/lib.rs:48
#7 0x00007f2406934050 in async_global_executor::reactor::block_on (future=...) at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/async-global-executor-1.4.2/src/lib.rs:55
#8 0x00007f240692d69c in async_global_executor::block_on::{{closure}} (executor=0x7f2406907078) at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/async-global-executor-1.4.2/src/lib.rs:212
#9 0x00007f24069368c4 in std::thread::local::LocalKey<T>::try_with (self=0x7f2406aa7ed0, f=...) at /rustc/18bf6b4f01a6feaf7259ba7cdae58031af1b7b39/library/std/src/thread/local.rs:265
#10 0x00007f2406936037 in std::thread::local::LocalKey<T>::with (self=0x7f2406aa7ed0, f=...) at /rustc/18bf6b4f01a6feaf7259ba7cdae58031af1b7b39/library/std/src/thread/local.rs:241
#11 0x00007f240692d633 in async_global_executor::block_on (future=...) at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/async-global-executor-1.4.2/src/lib.rs:212
#12 0x00007f24069396ce in async_std::task::builder::Builder::blocking::{{closure}}::{{closure}} () at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/async-std-1.6.5/src/task/builder.rs:171
#13 0x00007f240693bb59 in async_std::task::task_locals_wrapper::TaskLocalsWrapper::set_current::{{closure}} (current=0x7f2406907060)
at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/async-std-1.6.5/src/task/task_locals_wrapper.rs:60
#14 0x00007f2406936da0 in std::thread::local::LocalKey<T>::try_with (self=0x7f2406aa8260, f=...) at /rustc/18bf6b4f01a6feaf7259ba7cdae58031af1b7b39/library/std/src/thread/local.rs:265
#15 0x00007f240693611d in std::thread::local::LocalKey<T>::with (self=0x7f2406aa8260, f=...) at /rustc/18bf6b4f01a6feaf7259ba7cdae58031af1b7b39/library/std/src/thread/local.rs:241
#16 0x00007f240693ba6d in async_std::task::task_locals_wrapper::TaskLocalsWrapper::set_current (task=0x7ffe348b0b10, f=...) at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/async-std-1.6.5/src/task/task_locals_wrapper.rs:55
#17 0x00007f24069395cd in async_std::task::builder::Builder::blocking::{{closure}} (num_nested_blocking=0x7f2406907048) at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/async-std-1.6.5/src/task/builder.rs:168
#18 0x00007f240693625c in std::thread::local::LocalKey<T>::try_with (self=0x7f2406aa81b8, f=...) at /rustc/18bf6b4f01a6feaf7259ba7cdae58031af1b7b39/library/std/src/thread/local.rs:265
#19 0x00007f2406935fb7 in std::thread::local::LocalKey<T>::with (self=0x7f2406aa81b8, f=...) at /rustc/18bf6b4f01a6feaf7259ba7cdae58031af1b7b39/library/std/src/thread/local.rs:241
#20 0x00007f2406939479 in async_std::task::builder::Builder::blocking (self=..., future=...) at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/async-std-1.6.5/src/task/builder.rs:161
#21 0x00007f2406933166 in async_std::task::block_on::block_on (future=...) at /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/async-std-1.6.5/src/task/block_on.rs:33
#22 0x00007f24069399c8 in filedrop::main () at src/main.rs:23
I had a case of this today. It occurred in a VM running under Virtualbox, running Rocky Linux 8.
The application I was testing is quite complex, the relevant bit has async tasks which are reading from TCP sockets, processing what they read, and writing the results to a file.
The VM was configured with two CPUs, so there were 2 async runtime threads. Each time I observed it, both runtime threads were stuck trying to drop async_std::fs::File instances. That seemed a little strange, although I can't be sure there were no cases where only one of the threads got stuck - obviously it was more obvious when they both get stuck because the whole application grinds to a halt.
Adding a flush() call just before dropping the file does seem to have fixed it. Interestingly, the test program above did not trigger a problem for me.
There definitely needs to be some documentation about this - I wasted a huge amount of time trying to debug this before stumbling across this ticket.
I think the problem is in Drop implementation calling async flush. poll_flush then tries to spawn another task and wait for its completion, calling poll_drain in turn and so on, and this is likely where we deadlock. Instead of calling async flush, flush() should be implemented using only blocking operations instead of calling this: https://github.com/async-rs/async-std/blob/11196c853dc42e86d608c4ed29af1a8f0c5c5084/src/fs/file.rs#L841-L861=
In other words, just self.file.write_all(self.cache) (add & and * where needed) directly and do nothing else.
You would need to have at least N+1 runtime threads in order to be able to drop N Files simultaneously - which explains why most cases of this have been seen in QEMU or VMs since they would be likely to have few CPUs.
One thing I do not understand though: when I configure my VM with 1 CPU, or instruct async_std to create one runtime thread via ASYNC_GLOBAL_EXECUTOR_THREADS, the reproduction program at the top of this ticket does not trigger a hanging for me.
Activity
link2xt commentedon Oct 22, 2020
Collected the backtraces of the stuck process:
Details
link2xt commentedon Oct 22, 2020
Sidenote: there is a third alternative to dropping unwritten data and flushing it in a blocking way. It's possible to spawn a new task that will do the flushing sometime later. If user did not care to flush the file, it can be postponed.
link2xt commentedon Oct 23, 2020
Maybe this can be reproduced more reliably and converted into a test? Is it possible to cause
Fileto become unflushed in deterministic way? This is probably caused by slow qemu device built on top of HDD and old android SD card.dignifiedquire commentedon Oct 23, 2020
We likely need to stop flushing automatically in the drop impl, and add to the docs that flushing is required to be manual. This is what
tokio::fs::Filedoes, and likely the only way to be sure it works, as long asAsyncDropis not yet there.link2xt commentedon Oct 23, 2020
It's possible to remove
Drop, but isn't it a workaround? What is the reason for panic in the first thread? What if I implement aFilewrapper that doesflushindrop, why shouldn't it work?link2xt commentedon Oct 23, 2020
Here is a way to create unflushed file:
async-std/src/fs/file.rs
Line 411 in 11196c8
I'll try to use it and see what happens.
link2xt commentedon Oct 23, 2020
This code does not fail on Linux:
But maybe because write operation never actually blocks.
link2xt commentedon Oct 26, 2020
Reproduced on Alpine linux under qemu, running on top of qcow2 disk backed by HDD. Dumped the core, copied to the host system and loaded it in gdb. On the host system same binary successfully writes the file by the way. So it is reproducible both with kqueue and epoll, on NetBSD and Alpine Linux running in KVM and on real Android.
Stacktraces with epoll, produced on Debian from binary and core file downloaded from Alpine
strace -fon Alpine Linux (program deadlocks)strace -fon host Debian GNU/Linux (program finishes)link2xt commentedon Oct 26, 2020
With
async_fs::OpenOptionsit works on Alpine (in qemu).link2xt commentedon Oct 26, 2020
strace -fon Alpine under qemu withasync_fs::OpenOptionslink2xt commentedon Oct 26, 2020
But
async_fs::OpenOptionsdoesn't implementDropat all, so it just doesn't trigger the bug. I'm not sure what this experiment shows.Also, with
async_fsthe file is empty, there is nowrite("foobarbaz")syscall instraceoutput, the file is simply never written.link2xt commentedon Oct 26, 2020
On Debian, the file is written even with
async_fs::OpenOptions.link2xt commentedon Aug 1, 2021
Probably related problem,
cargogets stuck compiling a package on a GitLab runner running under QEMU: https://gitlab.alpinelinux.org/alpine/aports/-/merge_requests/23790harmic commentedon Jun 27, 2022
I had a case of this today. It occurred in a VM running under Virtualbox, running Rocky Linux 8.
The application I was testing is quite complex, the relevant bit has async tasks which are reading from TCP sockets, processing what they read, and writing the results to a file.
The VM was configured with two CPUs, so there were 2 async runtime threads. Each time I observed it, both runtime threads were stuck trying to drop
async_std::fs::Fileinstances. That seemed a little strange, although I can't be sure there were no cases where only one of the threads got stuck - obviously it was more obvious when they both get stuck because the whole application grinds to a halt.Adding a
flush()call just before dropping the file does seem to have fixed it. Interestingly, the test program above did not trigger a problem for me.There definitely needs to be some documentation about this - I wasted a huge amount of time trying to debug this before stumbling across this ticket.
link2xt commentedon Jun 27, 2022
I think the problem is in
Dropimplementation calling async flush.poll_flushthen tries to spawn another task and wait for its completion, callingpoll_drainin turn and so on, and this is likely where we deadlock. Instead of calling async flush, flush() should be implemented using only blocking operations instead of calling this:https://github.com/async-rs/async-std/blob/11196c853dc42e86d608c4ed29af1a8f0c5c5084/src/fs/file.rs#L841-L861=
In other words, just
self.file.write_all(self.cache)(add&and*where needed) directly and do nothing else.harmic commentedon Jun 29, 2022
This makes perfect sense.
You would need to have at least N+1 runtime threads in order to be able to drop N
Files simultaneously - which explains why most cases of this have been seen in QEMU or VMs since they would be likely to have few CPUs.One thing I do not understand though: when I configure my VM with 1 CPU, or instruct async_std to create one runtime thread via ASYNC_GLOBAL_EXECUTOR_THREADS, the reproduction program at the top of this ticket does not trigger a hanging for me.
link2xt commentedon Jul 17, 2022
I made a fix #1033 but have not really tested it.