Deadlock in mobilecoind

[eranrund]

Hello,

We've run into a deadlock in mobilecoind twice now and wondering if you also happened to run into it.
The way we have observed this is that mobilecoind stops responding to GRPC calls.
The two times we encountered it we attached gdb and were able to learn that the GRPC worker thread (of which there is only one appears to be blocked on locking an rwlock.

Here's the list of threads at the time this happened:

(gdb) info thread
  Id   Target Id                                         Frame 
* 1    Thread 0x7f2c917fac80 (LWP 33) "mobilecoind"      0x00007f2c918dc23f in __GI___clock_nanosleep (clock_id=clock_id@entry=0, flags=flags@entry=0, req=0x7fff2dd0d190, rem=0x7fff2dd0d190) at ../sysdeps/unix/sysv/linux/clock_nanosleep.c:78
  2    Thread 0x7f2c90e0b700 (LWP 36) "slog-json"        0x00007f2c9191773d in openlog_internal (logfac=<optimized out>, logstat=<optimized out>, ident=<optimized out>) at ../misc/syslog.c:350
  3    Thread 0x7f2c83fff700 (LWP 39) "default-executo"  0x00007f2c9191773d in openlog_internal (logfac=<optimized out>, logstat=<optimized out>, ident=<optimized out>) at ../misc/syslog.c:350
  4    Thread 0x7f2c835fe700 (LWP 40) "resolver-execut"  0x00007f2c9191773d in openlog_internal (logfac=<optimized out>, logstat=<optimized out>, ident=<optimized out>) at ../misc/syslog.c:350
  5    Thread 0x7f2c82bfd700 (LWP 41) "grpc_global_tim"  0x00007f2c9191773d in openlog_internal (logfac=<optimized out>, logstat=<optimized out>, ident=<optimized out>) at ../misc/syslog.c:350
  6    Thread 0x7f2c90c07700 (LWP 42) "peer-0"           0x00007f2c9191773d in openlog_internal (logfac=<optimized out>, logstat=<optimized out>, ident=<optimized out>) at ../misc/syslog.c:350
  7    Thread 0x7f2c821fc700 (LWP 43) "event_engine"     0x00007f2c9191e46e in __GI_epoll_pwait (epfd=5, events=0x558622cfedf4, maxevents=100, timeout=-1852709778, set=0x0) at ../sysdeps/unix/sysv/linux/epoll_pwait.c:42
  8    Thread 0x7f2c817fb700 (LWP 44) "event_engine"     0x00007f2c9191773d in openlog_internal (logfac=<optimized out>, logstat=<optimized out>, ident=<optimized out>) at ../misc/syslog.c:350
  9    Thread 0x7f2c80dfa700 (LWP 45) "timer_manager"    0x00007f2c9191773d in openlog_internal (logfac=<optimized out>, logstat=<optimized out>, ident=<optimized out>) at ../misc/syslog.c:350
  10   Thread 0x7f2c90a03700 (LWP 46) "reqwest-interna"  0x00007f2c9191e46e in __GI_epoll_pwait (epfd=9, events=0x7f2c64000be0, maxevents=1024, timeout=-1852709778, set=0x0) at ../sysdeps/unix/sysv/linux/epoll_pwait.c:42
  11   Thread 0x7f2c9044c700 (LWP 47) "LedgerSync"       0x00007f2c9191773d in openlog_internal (logfac=<optimized out>, logstat=<optimized out>, ident=<optimized out>) at ../misc/syslog.c:350
  12   Thread 0x7f2c6b4ee700 (LWP 48) "reqwest-interna"  0x00007f2c9191e46e in __GI_epoll_pwait (epfd=19, events=0x7d2c60000be0, maxevents=1024, timeout=-1852709778, set=0x0) at ../sysdeps/unix/sysv/linux/epoll_pwait.c:42
  13   Thread 0x7f2c6a3da700 (LWP 51) "reqwest-interna"  0x00007f2c9191e46e in __GI_epoll_pwait (epfd=25, events=0x7d2c54000be0, maxevents=1024, timeout=-1852709778, set=0x0) at ../sysdeps/unix/sysv/linux/epoll_pwait.c:42
  14   Thread 0x7f2c696c8700 (LWP 52) "WatcherSync"      0x00007f2c918dc23f in __GI___clock_nanosleep (clock_id=clock_id@entry=0, flags=flags@entry=0, req=0x7f2c696c72e0, rem=0x7f2c696c72e0) at ../sysdeps/unix/sysv/linux/clock_nanosleep.c:78
  15   Thread 0x7f2c692c6700 (LWP 53) "FogPubkeyResolv"  0x00007f2c9191773d in openlog_internal (logfac=<optimized out>, logstat=<optimized out>, ident=<optimized out>) at ../misc/syslog.c:350
  16   Thread 0x7f2c690c5700 (LWP 54) "FogPubkeyResolv"  0x00007f2c9191773d in openlog_internal (logfac=<optimized out>, logstat=<optimized out>, ident=<optimized out>) at ../misc/syslog.c:350
  17   Thread 0x7f2c68ec4700 (LWP 55) "mobilecoind"      0x00007f2c918dc23f in __GI___clock_nanosleep (clock_id=clock_id@entry=0, flags=flags@entry=0, req=0x7f2c68ec2c20, rem=0x7f2c68ec2c20) at ../sysdeps/unix/sysv/linux/clock_nanosleep.c:78
  18   Thread 0x7f2c68cc3700 (LWP 56) "T3RPC-0"          0x00007f2c9191773d in openlog_internal (logfac=<optimized out>, logstat=<optimized out>, ident=<optimized out>) at ../misc/syslog.c:350
  19   Thread 0x7f2c68ac2700 (LWP 57) "T3RPC-1"          0x00007f2c9191e46e in __GI_epoll_pwait (epfd=3, events=0x5586223b6f64 <g_epoll_set+4>, maxevents=100, timeout=-1852709778, set=0x0) at ../sysdeps/unix/sysv/linux/epoll_pwait.c:42
  20   Thread 0x7f2c688c1700 (LWP 58) "sync_worker_0"    0x00007f2c9191773d in openlog_internal (logfac=<optimized out>, logstat=<optimized out>, ident=<optimized out>) at ../misc/syslog.c:350
  21   Thread 0x7f2c686c0700 (LWP 59) "sync_worker_1"    0x00007f2c9191773d in openlog_internal (logfac=<optimized out>, logstat=<optimized out>, ident=<optimized out>) at ../misc/syslog.c:350
  22   Thread 0x7f2c684bf700 (LWP 60) "sync"             0x00007f2c918dc23f in __GI___clock_nanosleep (clock_id=clock_id@entry=0, flags=flags@entry=0, req=0x7f2c684be190, rem=0x7f2c684be190) at ../sysdeps/unix/sysv/linux/clock_nanosleep.c:78
  23   Thread 0x7f2c682be700 (LWP 61) "Mobilecoind-RPC"  0x00007f2c9191773d in openlog_internal (logfac=<optimized out>, logstat=<optimized out>, ident=<optimized out>) at ../misc/syslog.c:350
  24   Thread 0x7d2c4d3e9700 (LWP 116) "sync_worker_0"   0x00007f2c9191773d in openlog_internal (logfac=<optimized out>, logstat=<optimized out>, ident=<optimized out>) at ../misc/syslog.c:350
  25   Thread 0x7d2c4d1e8700 (LWP 117) "sync_worker_0"   0x00007f2c9191773d in openlog_internal (logfac=<optimized out>, logstat=<optimized out>, ident=<optimized out>) at ../misc/syslog.c:350
  26   Thread 0x7c2c45dee700 (LWP 118) "grpc_global_tim" 0x00007f2c9191773d in openlog_internal (logfac=<optimized out>, logstat=<optimized out>, ident=<optimized out>) at ../misc/syslog.c:350
  27   Thread 0x7d2c4ffff700 (LWP 230) "event_engine"    0x00007f2c9191773d in openlog_internal (logfac=<optimized out>, logstat=<optimized out>, ident=<optimized out>) at ../misc/syslog.c:350
(gdb) 

And the stacktrace of each thread:

(gdb) thread apply all bt

Thread 27 (Thread 0x7d2c4ffff700 (LWP 230)):
#0  0x00007f2c9191773d in openlog_internal (logfac=<optimized out>, logstat=<optimized out>, ident=<optimized out>) at ../misc/syslog.c:350
#1  openlog (ident=<optimized out>, logstat=<optimized out>, logfac=<optimized out>) at ../misc/syslog.c:388
#2  0x00007f2c907b6bcc in ?? ()
#3  0x00005586214ff326 in AbslInternalPerThreadSemWait_lts_20230125 () at library/core/src/fmt/mod.rs:331
#4  0x0000558620b03192 in absl::lts_20230125::CondVar::WaitCommon(absl::lts_20230125::Mutex*, absl::lts_20230125::synchronization_internal::KernelTimeout) [clone .cold] ()
#5  0x00005586215595ff in grpc_event_engine::experimental::OriginalThreadPool::Queue::Step() () at library/core/src/fmt/mod.rs:331
#6  0x000055862155a348 in grpc_event_engine::experimental::OriginalThreadPool::ThreadFunc(std::shared_ptr<grpc_event_engine::experimental::OriginalThreadPool::State>) () at library/core/src/fmt/mod.rs:331
#7  0x000055862155a6ed in grpc_event_engine::experimental::OriginalThreadPool::StartThread(std::shared_ptr<grpc_event_engine::experimental::OriginalThreadPool::State>, grpc_event_engine::experimental::OriginalThreadPool::StartThreadReason)::{lambda(void*)#1}::_FUN(void*) () at library/core/src/fmt/mod.rs:331
#8  0x000055862124445e in grpc_core::(anonymous namespace)::ThreadInternalsPosix::ThreadInternalsPosix(char const*, void (*)(void*), void*, bool*, grpc_core::Thread::Options const&)::{lambda(void*)#1}::_FUN(void*) () at library/core/src/fmt/mod.rs:331
#9  0x00007f2c91b4e609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#10 0x00007f2c9191e133 in __GI___libc_allocate_once_slow (place=0x7f2c907b6b40, allocate=0x80, deallocate=0x0, closure=0x7f2c9191773d <openlog+381>) at allocate_once.c:27
#11 0x0000000000000000 in ?? ()

Thread 26 (Thread 0x7c2c45dee700 (LWP 118)):
#0  0x00007f2c9191773d in openlog_internal (logfac=<optimized out>, logstat=<optimized out>, ident=<optimized out>) at ../misc/syslog.c:350
#1  openlog (ident=<optimized out>, logstat=<optimized out>, logfac=<optimized out>) at ../misc/syslog.c:388
#2  0x00007f2c907b6900 in ?? ()
#3  0x17cf1e20d2184dd1 in ?? ()
#4  0x00007f2c907b69cc in ?? ()
#5  0x00005586214ff326 in AbslInternalPerThreadSemWait_lts_20230125 () at library/core/src/fmt/mod.rs:331
#6  0x0000558620b03192 in absl::lts_20230125::CondVar::WaitCommon(absl::lts_20230125::Mutex*, absl::lts_20230125::synchronization_internal::KernelTimeout) [clone .cold] ()
#7  0x0000558621235aff in absl::lts_20230125::CondVar::WaitWithTimeout(absl::lts_20230125::Mutex*, absl::lts_20230125::Duration) () at library/core/src/fmt/mod.rs:331
#8  0x0000558621069ab6 in gpr_cv_wait () at library/core/src/fmt/mod.rs:331
#9  0x000055862142eaee in timer_thread(void*) () at library/core/src/fmt/mod.rs:331
#10 0x0000558621244400 in grpc_core::(anonymous namespace)::ThreadInternalsPosix::ThreadInternalsPosix(char const*, void (*)(void*), void*, bool*, grpc_core::Thread::Options const&)::{lambda(void*)#1}::_FUN(void*) () at library/core/src/fmt/mod.rs:331
#11 0x00007f2c91b4e609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#12 0x00007f2c9191e133 in __GI___libc_allocate_once_slow (place=0x7f2c907b6940, allocate=0x189, deallocate=0x0, closure=0x7f2c9191773d <openlog+381>) at allocate_once.c:27
#13 0x0000000000000000 in ?? ()

Thread 25 (Thread 0x7d2c4d1e8700 (LWP 117)):
#0  0x00007f2c9191773d in openlog_internal (logfac=<optimized out>, logstat=<optimized out>, ident=<optimized out>) at ../misc/syslog.c:350
#1  openlog (ident=<optimized out>, logstat=<optimized out>, logfac=<optimized out>) at ../misc/syslog.c:388
#2  0x00007d2c5800b308 in ?? ()
#3  0x0000000000000000 in ?? ()

Thread 24 (Thread 0x7d2c4d3e9700 (LWP 116)):
#0  0x00007f2c9191773d in openlog_internal (logfac=<optimized out>, logstat=<optimized out>, ident=<optimized out>) at ../misc/syslog.c:350
#1  openlog (ident=<optimized out>, logstat=<optimized out>, logfac=<optimized out>) at ../misc/syslog.c:388
#2  0x00007d2c5800b288 in ?? ()
#3  0x0000000000000000 in ?? ()

Thread 23 (Thread 0x7f2c682be700 (LWP 61)):
#0  0x00007f2c9191773d in openlog_internal (logfac=<optimized out>, logstat=<optimized out>, ident=<optimized out>) at ../misc/syslog.c:350
#1  openlog (ident=<optimized out>, logstat=<optimized out>, logfac=<optimized out>) at ../misc/syslog.c:388
#2  0x0000558622cfd6b0 in ?? ()
#3  0x00007f2c682bcf88 in ?? ()
#4  0x0000558622cfd6c0 in ?? ()
#5  0x0000000000281e44 in ?? ()
#6  0x00007f2c682bc9d0 in ?? ()
#7  0x0000558622cfd6b0 in ?? ()
#8  0x0000558622cfd6b0 in ?? ()
#9  0x0000558620bb4a47 in mc_mobilecoind::service::ServiceApi<T,FPR>::get_last_block_infos () at library/core/src/fmt/mod.rs:331
#10 0x0000558620b977d2 in <mc_mobilecoind::service::ServiceApi<T,FPR> as mc_mobilecoind_api::autogenerated_code::mobilecoind_api_grpc::MobilecoindApi>::get_network_status () at library/core/src/fmt/mod.rs:331
#11 0x0000558620c1997b in grpcio::call::server::execute_unary () at library/core/src/fmt/mod.rs:331
#12 0x0000558620bedaae in <grpcio::server::Handler<F> as grpcio::server::CloneableHandler>::handle () at library/core/src/fmt/mod.rs:331
#13 0x000055862105102c in grpcio::call::server::execute () at library/core/src/fmt/mod.rs:331
#14 0x0000558621052ae6 in grpcio::task::callback::UnaryRequest::resolve () at library/core/src/fmt/mod.rs:331
#15 0x0000558621062367 in grpcio::task::CallTag::resolve () at library/core/src/fmt/mod.rs:331
#16 0x0000558621054562 in grpcio::env::poll_queue () at library/core/src/fmt/mod.rs:331
#17 0x0000558621060f05 in std::sys_common::backtrace::__rust_begin_short_backtrace () at library/core/src/fmt/mod.rs:331
#18 0x0000558621057c47 in core::ops::function::FnOnce::call_once{{vtable-shim}} () at library/core/src/fmt/mod.rs:331
#19 0x0000558621c185f5 in <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once () at library/alloc/src/boxed.rs:2007
#20 <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once () at library/alloc/src/boxed.rs:2007
#21 std::sys::unix::thread::Thread::new::thread_start () at library/std/src/sys/unix/thread.rs:108
#22 0x00007f2c91b4e609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#23 0x00007f2c9191e133 in __GI___libc_allocate_once_slow (place=0x558622cfd6c0, allocate=0x89, deallocate=0xc0000001, closure=0x7f2c9191773d <openlog+381>) at allocate_once.c:27
#24 0x0000000000000000 in ?? ()

Thread 22 (Thread 0x7f2c684bf700 (LWP 60)):
#0  0x00007f2c918dc23f in __GI___clock_nanosleep (clock_id=clock_id@entry=0, flags=flags@entry=0, req=0x7f2c684be190, rem=0x7f2c684be190) at ../sysdeps/unix/sysv/linux/clock_nanosleep.c:78
#1  0x00007f2c918e1ec7 in __GI___nanosleep (requested_time=<optimized out>, remaining=<optimized out>) at nanosleep.c:27
#2  0x0000558621c05fd0 in std::sys::unix::thread::Thread::sleep () at library/std/src/sys/unix/thread.rs:241
#3  std::thread::sleep () at library/std/src/thread/mod.rs:872
#4  0x0000558620d06aaf in std::sys_common::backtrace::__rust_begin_short_backtrace () at library/core/src/fmt/mod.rs:331
#5  0x0000558620d23d74 in core::ops::function::FnOnce::call_once{{vtable-shim}} () at library/core/src/fmt/mod.rs:331
#6  0x0000558621c185f5 in <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once () at library/alloc/src/boxed.rs:2007
#7  <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once () at library/alloc/src/boxed.rs:2007
#8  std::sys::unix::thread::Thread::new::thread_start () at library/std/src/sys/unix/thread.rs:108
#9  0x00007f2c91b4e609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#10 0x00007f2c9191e133 in __GI___libc_allocate_once_slow (place=0x0, allocate=0x0, deallocate=0x7f2c684be190, closure=0x7f2c918dc23f <__GI___clock_nanosleep+223>) at allocate_once.c:27
#11 0x0000000000000000 in ?? ()

Thread 21 (Thread 0x7f2c686c0700 (LWP 59)):
#0  0x00007f2c9191773d in openlog_internal (logfac=<optimized out>, logstat=<optimized out>, ident=<optimized out>) at ../misc/syslog.c:350
#1  openlog (ident=<optimized out>, logstat=<optimized out>, logfac=<optimized out>) at ../misc/syslog.c:388
#2  0x0000558622ddac00 in ?? ()
#3  0x0000558622ddab00 in ?? ()
#4  0x00007f2c686bebb0 in ?? ()
#5  0x00007f2c64038580 in ?? ()
#6  0x7fffffffffffffff in ?? ()
#7  0x0000558620d2e062 in crossbeam_channel::context::Context::with::{{closure}} () at library/core/src/fmt/mod.rs:331
#8  0x0000558620d2ebd9 in crossbeam_channel::flavors::list::Channel<T>::recv () at library/core/src/fmt/mod.rs:331
#9  0x0000558620d55a94 in <crossbeam_channel::channel::Iter<T> as core::iter::traits::iterator::Iterator>::next () at library/core/src/fmt/mod.rs:331
#10 0x0000558620d2c128 in mc_mobilecoind::sync::sync_thread_entry_point () at library/core/src/fmt/mod.rs:331
#11 0x0000558620d04a48 in std::sys_common::backtrace::__rust_begin_short_backtrace () at library/core/src/fmt/mod.rs:331
--Type <RET> for more, q to quit, c to continue without paging-- 
#12 0x0000558620d23b84 in core::ops::function::FnOnce::call_once{{vtable-shim}} () at library/core/src/fmt/mod.rs:331
#13 0x0000558621c185f5 in <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once () at library/alloc/src/boxed.rs:2007
#14 <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once () at library/alloc/src/boxed.rs:2007
#15 std::sys::unix::thread::Thread::new::thread_start () at library/std/src/sys/unix/thread.rs:108
#16 0x00007f2c91b4e609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#17 0x00007f2c9191e133 in __GI___libc_allocate_once_slow (place=0x558622ddb218, allocate=0x89, deallocate=0xffffffff, closure=0x7f2c9191773d <openlog+381>) at allocate_once.c:27
#18 0x0000000000000000 in ?? ()

Thread 20 (Thread 0x7f2c688c1700 (LWP 58)):
#0  0x00007f2c9191773d in openlog_internal (logfac=<optimized out>, logstat=<optimized out>, ident=<optimized out>) at ../misc/syslog.c:350
#1  openlog (ident=<optimized out>, logstat=<optimized out>, logfac=<optimized out>) at ../misc/syslog.c:388
#2  0x0000558622ddac00 in ?? ()
#3  0x0000558622ddab00 in ?? ()
#4  0x00007f2c688bfbb0 in ?? ()
#5  0x00007d2c58001d90 in ?? ()
#6  0x7fffffffffffffff in ?? ()
#7  0x0000558620d2e062 in crossbeam_channel::context::Context::with::{{closure}} () at library/core/src/fmt/mod.rs:331
#8  0x0000558620d2ebd9 in crossbeam_channel::flavors::list::Channel<T>::recv () at library/core/src/fmt/mod.rs:331
#9  0x0000558620d55a94 in <crossbeam_channel::channel::Iter<T> as core::iter::traits::iterator::Iterator>::next () at library/core/src/fmt/mod.rs:331
#10 0x0000558620d2c128 in mc_mobilecoind::sync::sync_thread_entry_point () at library/core/src/fmt/mod.rs:331
#11 0x0000558620d04a48 in std::sys_common::backtrace::__rust_begin_short_backtrace () at library/core/src/fmt/mod.rs:331
#12 0x0000558620d23b84 in core::ops::function::FnOnce::call_once{{vtable-shim}} () at library/core/src/fmt/mod.rs:331
#13 0x0000558621c185f5 in <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once () at library/alloc/src/boxed.rs:2007
#14 <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once () at library/alloc/src/boxed.rs:2007
#15 std::sys::unix::thread::Thread::new::thread_start () at library/std/src/sys/unix/thread.rs:108
#16 0x00007f2c91b4e609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#17 0x00007f2c9191e133 in __GI___libc_allocate_once_slow (place=0x558622ddd608, allocate=0x89, deallocate=0xffffffff, closure=0x7f2c9191773d <openlog+381>) at allocate_once.c:27
#18 0x0000000000000000 in ?? ()

Thread 19 (Thread 0x7f2c68ac2700 (LWP 57)):
#0  0x00007f2c9191e46e in __GI_epoll_pwait (epfd=3, events=0x5586223b6f64 <g_epoll_set+4>, maxevents=100, timeout=-1852709778, set=0x0) at ../sysdeps/unix/sysv/linux/epoll_pwait.c:42
#1  0x7fffffffffffffff in ?? ()
#2  0x000000035c0171a0 in ?? ()
#3  0x00005586223b6f64 in g_epoll_set ()
#4  0xffffffff00000064 in ?? ()
#5  0x00007f2c68ac15e0 in ?? ()
#6  0x00005586214182b1 in pollset_work(grpc_pollset*, grpc_pollset_worker**, grpc_core::Timestamp) () at library/core/src/fmt/mod.rs:331
#7  0x0000558621119b6a in pollset_work(grpc_pollset*, grpc_pollset_worker**, grpc_core::Timestamp) () at library/core/src/fmt/mod.rs:331
#8  0x0000558621420b3a in grpc_pollset_work(grpc_pollset*, grpc_pollset_worker**, grpc_core::Timestamp) () at library/core/src/fmt/mod.rs:331
#9  0x00005586211879a3 in cq_next(grpc_completion_queue*, gpr_timespec, void*) () at library/core/src/fmt/mod.rs:331
#10 0x000055862105450a in grpcio::env::poll_queue () at library/core/src/fmt/mod.rs:331
#11 0x0000558621060f05 in std::sys_common::backtrace::__rust_begin_short_backtrace () at library/core/src/fmt/mod.rs:331
#12 0x0000558621057c47 in core::ops::function::FnOnce::call_once{{vtable-shim}} () at library/core/src/fmt/mod.rs:331
#13 0x0000558621c185f5 in <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once () at library/alloc/src/boxed.rs:2007
#14 <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once () at library/alloc/src/boxed.rs:2007
#15 std::sys::unix::thread::Thread::new::thread_start () at library/std/src/sys/unix/thread.rs:108
#16 0x00007f2c91b4e609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#17 0x00007f2c9191e133 in __GI___libc_allocate_once_slow (place=0x3, allocate=0x5586223b6f64 <g_epoll_set+4>, deallocate=0x64, closure=0x7f2c9191e46e <__GI_epoll_pwait+46>) at allocate_once.c:27
#18 0x0000000000000000 in ?? ()

Thread 18 (Thread 0x7f2c68cc3700 (LWP 56)):
#0  0x00007f2c9191773d in openlog_internal (logfac=<optimized out>, logstat=<optimized out>, ident=<optimized out>) at ../misc/syslog.c:350
#1  openlog (ident=<optimized out>, logstat=<optimized out>, logfac=<optimized out>) at ../misc/syslog.c:388
#2  0x00007f2c907b61cc in ?? ()
#3  0x00005586214ff326 in AbslInternalPerThreadSemWait_lts_20230125 () at library/core/src/fmt/mod.rs:331
#4  0x0000558620b03192 in absl::lts_20230125::CondVar::WaitCommon(absl::lts_20230125::Mutex*, absl::lts_20230125::synchronization_internal::KernelTimeout) [clone .cold] ()
#5  0x0000558621069b0f in gpr_cv_wait () at library/core/src/fmt/mod.rs:331
#6  0x0000558621417f09 in pollset_work(grpc_pollset*, grpc_pollset_worker**, grpc_core::Timestamp) () at library/core/src/fmt/mod.rs:331
#7  0x0000558621119b6a in pollset_work(grpc_pollset*, grpc_pollset_worker**, grpc_core::Timestamp) () at library/core/src/fmt/mod.rs:331
#8  0x0000558621420b3a in grpc_pollset_work(grpc_pollset*, grpc_pollset_worker**, grpc_core::Timestamp) () at library/core/src/fmt/mod.rs:331
#9  0x00005586211879a3 in cq_next(grpc_completion_queue*, gpr_timespec, void*) () at library/core/src/fmt/mod.rs:331
#10 0x000055862105450a in grpcio::env::poll_queue () at library/core/src/fmt/mod.rs:331
#11 0x0000558621060f05 in std::sys_common::backtrace::__rust_begin_short_backtrace () at library/core/src/fmt/mod.rs:331
#12 0x0000558621057c47 in core::ops::function::FnOnce::call_once{{vtable-shim}} () at library/core/src/fmt/mod.rs:331
#13 0x0000558621c185f5 in <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once () at library/alloc/src/boxed.rs:2007
#14 <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once () at library/alloc/src/boxed.rs:2007
#15 std::sys::unix::thread::Thread::new::thread_start () at library/std/src/sys/unix/thread.rs:108
#16 0x00007f2c91b4e609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#17 0x00007f2c9191e133 in __GI___libc_allocate_once_slow (place=0x7f2c907b6140, allocate=0x80, deallocate=0x0, closure=0x7f2c9191773d <openlog+381>) at allocate_once.c:27
#18 0x0000000000000000 in ?? ()

Thread 17 (Thread 0x7f2c68ec4700 (LWP 55)):
#0  0x00007f2c918dc23f in __GI___clock_nanosleep (clock_id=clock_id@entry=0, flags=flags@entry=0, req=0x7f2c68ec2c20, rem=0x7f2c68ec2c20) at ../sysdeps/unix/sysv/linux/clock_nanosleep.c:78
#1  0x00007f2c918e1ec7 in __GI___nanosleep (requested_time=<optimized out>, remaining=<optimized out>) at nanosleep.c:27
#2  0x0000558621c05fd0 in std::sys::unix::thread::Thread::sleep () at library/std/src/sys/unix/thread.rs:241
#3  std::thread::sleep () at library/std/src/thread/mod.rs:872
#4  0x0000558620d04ca2 in std::sys_common::backtrace::__rust_begin_short_backtrace () at library/core/src/fmt/mod.rs:331
#5  0x0000558620d23994 in core::ops::function::FnOnce::call_once{{vtable-shim}} () at library/core/src/fmt/mod.rs:331
#6  0x0000558621c185f5 in <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once () at library/alloc/src/boxed.rs:2007
#7  <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once () at library/alloc/src/boxed.rs:2007
#8  std::sys::unix::thread::Thread::new::thread_start () at library/std/src/sys/unix/thread.rs:108
#9  0x00007f2c91b4e609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#10 0x00007f2c9191e133 in __GI___libc_allocate_once_slow (place=0x0, allocate=0x0, deallocate=0x7f2c68ec2c20, closure=0x7f2c918dc23f <__GI___clock_nanosleep+223>) at allocate_once.c:27
#11 0x0000000000000000 in ?? ()

Thread 16 (Thread 0x7f2c690c5700 (LWP 54)):
#0  0x00007f2c9191773d in openlog_internal (logfac=<optimized out>, logstat=<optimized out>, ident=<optimized out>) at ../misc/syslog.c:350
#1  openlog (ident=<optimized out>, logstat=<optimized out>, logfac=<optimized out>) at ../misc/syslog.c:388
#2  0x00007f2c907b5fcc in ?? ()
#3  0x00005586214ff326 in AbslInternalPerThreadSemWait_lts_20230125 () at library/core/src/fmt/mod.rs:331
#4  0x0000558620b03192 in absl::lts_20230125::CondVar::WaitCommon(absl::lts_20230125::Mutex*, absl::lts_20230125::synchronization_internal::KernelTimeout) [clone .cold] ()
#5  0x0000558621069b0f in gpr_cv_wait () at library/core/src/fmt/mod.rs:331
#6  0x0000558621417f09 in pollset_work(grpc_pollset*, grpc_pollset_worker**, grpc_core::Timestamp) () at library/core/src/fmt/mod.rs:331
#7  0x0000558621119b6a in pollset_work(grpc_pollset*, grpc_pollset_worker**, grpc_core::Timestamp) () at library/core/src/fmt/mod.rs:331
#8  0x0000558621420b3a in grpc_pollset_work(grpc_pollset*, grpc_pollset_worker**, grpc_core::Timestamp) () at library/core/src/fmt/mod.rs:331
#9  0x00005586211879a3 in cq_next(grpc_completion_queue*, gpr_timespec, void*) () at library/core/src/fmt/mod.rs:331
#10 0x000055862105450a in grpcio::env::poll_queue () at library/core/src/fmt/mod.rs:331
--Type <RET> for more, q to quit, c to continue without paging--
#11 0x0000558621060f05 in std::sys_common::backtrace::__rust_begin_short_backtrace () at library/core/src/fmt/mod.rs:331
#12 0x0000558621057c47 in core::ops::function::FnOnce::call_once{{vtable-shim}} () at library/core/src/fmt/mod.rs:331
#13 0x0000558621c185f5 in <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once () at library/alloc/src/boxed.rs:2007
#14 <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once () at library/alloc/src/boxed.rs:2007
#15 std::sys::unix::thread::Thread::new::thread_start () at library/std/src/sys/unix/thread.rs:108
#16 0x00007f2c91b4e609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#17 0x00007f2c9191e133 in __GI___libc_allocate_once_slow (place=0x7f2c907b5f40, allocate=0x80, deallocate=0x0, closure=0x7f2c9191773d <openlog+381>) at allocate_once.c:27
#18 0x0000000000000000 in ?? ()

Thread 15 (Thread 0x7f2c692c6700 (LWP 53)):
#0  0x00007f2c9191773d in openlog_internal (logfac=<optimized out>, logstat=<optimized out>, ident=<optimized out>) at ../misc/syslog.c:350
#1  openlog (ident=<optimized out>, logstat=<optimized out>, logfac=<optimized out>) at ../misc/syslog.c:388
#2  0x00007f2c907b5dcc in ?? ()
#3  0x00005586214ff326 in AbslInternalPerThreadSemWait_lts_20230125 () at library/core/src/fmt/mod.rs:331
#4  0x0000558620b03192 in absl::lts_20230125::CondVar::WaitCommon(absl::lts_20230125::Mutex*, absl::lts_20230125::synchronization_internal::KernelTimeout) [clone .cold] ()
#5  0x0000558621069b0f in gpr_cv_wait () at library/core/src/fmt/mod.rs:331
#6  0x0000558621417f09 in pollset_work(grpc_pollset*, grpc_pollset_worker**, grpc_core::Timestamp) () at library/core/src/fmt/mod.rs:331
#7  0x0000558621119b6a in pollset_work(grpc_pollset*, grpc_pollset_worker**, grpc_core::Timestamp) () at library/core/src/fmt/mod.rs:331
#8  0x0000558621420b3a in grpc_pollset_work(grpc_pollset*, grpc_pollset_worker**, grpc_core::Timestamp) () at library/core/src/fmt/mod.rs:331
#9  0x00005586211879a3 in cq_next(grpc_completion_queue*, gpr_timespec, void*) () at library/core/src/fmt/mod.rs:331
#10 0x000055862105450a in grpcio::env::poll_queue () at library/core/src/fmt/mod.rs:331
#11 0x0000558621060f05 in std::sys_common::backtrace::__rust_begin_short_backtrace () at library/core/src/fmt/mod.rs:331
#12 0x0000558621057c47 in core::ops::function::FnOnce::call_once{{vtable-shim}} () at library/core/src/fmt/mod.rs:331
#13 0x0000558621c185f5 in <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once () at library/alloc/src/boxed.rs:2007
#14 <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once () at library/alloc/src/boxed.rs:2007
#15 std::sys::unix::thread::Thread::new::thread_start () at library/std/src/sys/unix/thread.rs:108
#16 0x00007f2c91b4e609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#17 0x00007f2c9191e133 in __GI___libc_allocate_once_slow (place=0x7f2c907b5d40, allocate=0x80, deallocate=0x0, closure=0x7f2c9191773d <openlog+381>) at allocate_once.c:27
#18 0x0000000000000000 in ?? ()

Thread 14 (Thread 0x7f2c696c8700 (LWP 52)):
#0  0x00007f2c918dc23f in __GI___clock_nanosleep (clock_id=clock_id@entry=0, flags=flags@entry=0, req=0x7f2c696c72e0, rem=0x7f2c696c72e0) at ../sysdeps/unix/sysv/linux/clock_nanosleep.c:78
#1  0x00007f2c918e1ec7 in __GI___nanosleep (requested_time=<optimized out>, remaining=<optimized out>) at nanosleep.c:27
#2  0x0000558621c05fd0 in std::sys::unix::thread::Thread::sleep () at library/std/src/sys/unix/thread.rs:241
#3  std::thread::sleep () at library/std/src/thread/mod.rs:872
#4  0x0000558620bd9045 in mc_watcher::watcher::WatcherSyncThread::thread_entrypoint () at library/core/src/fmt/mod.rs:331
#5  0x0000558620c9f553 in std::sys_common::backtrace::__rust_begin_short_backtrace () at library/core/src/fmt/mod.rs:331
#6  0x0000558620be2ee4 in core::ops::function::FnOnce::call_once{{vtable-shim}} () at library/core/src/fmt/mod.rs:331
#7  0x0000558621c185f5 in <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once () at library/alloc/src/boxed.rs:2007
#8  <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once () at library/alloc/src/boxed.rs:2007
#9  std::sys::unix::thread::Thread::new::thread_start () at library/std/src/sys/unix/thread.rs:108
#10 0x00007f2c91b4e609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#11 0x00007f2c9191e133 in __GI___libc_allocate_once_slow (place=0x0, allocate=0x0, deallocate=0x7f2c696c72e0, closure=0x7f2c918dc23f <__GI___clock_nanosleep+223>) at allocate_once.c:27
#12 0x0000000000000000 in ?? ()

Thread 13 (Thread 0x7f2c6a3da700 (LWP 51)):
#0  0x00007f2c9191e46e in __GI_epoll_pwait (epfd=25, events=0x7d2c54000be0, maxevents=1024, timeout=-1852709778, set=0x0) at ../sysdeps/unix/sysv/linux/epoll_pwait.c:42
#1  0x00007d2c54003c80 in ?? ()
#2  0x0000001900000000 in ?? ()
#3  0x00007d2c54000be0 in ?? ()
#4  0x00014fcd00000400 in ?? ()
#5  0x00007d2c00000000 in ?? ()
#6  0x0000558621a4d5c4 in mio::sys::unix::selector::epoll::Selector::select () at library/core/src/fmt/mod.rs:331
#7  0x0000558621a37b2d in tokio::runtime::io::driver::Driver::turn () at library/core/src/fmt/mod.rs:331
#8  0x0000558621a40ba3 in tokio::runtime::time::Driver::park_internal () at library/core/src/fmt/mod.rs:331
#9  0x0000558621a400df in tokio::runtime::scheduler::current_thread::Context::park () at library/core/src/fmt/mod.rs:331
#10 0x00005586218861ed in tokio::runtime::context::scoped::Scoped<T>::set () at library/core/src/fmt/mod.rs:331
#11 0x00005586218e7109 in tokio::runtime::scheduler::current_thread::CurrentThread::block_on () at library/core/src/fmt/mod.rs:331
#12 0x0000558621894bea in std::sys_common::backtrace::__rust_begin_short_backtrace () at library/core/src/fmt/mod.rs:331
#13 0x0000558621895644 in core::ops::function::FnOnce::call_once{{vtable-shim}} () at library/core/src/fmt/mod.rs:331
#14 0x0000558621c185f5 in <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once () at library/alloc/src/boxed.rs:2007
#15 <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once () at library/alloc/src/boxed.rs:2007
#16 std::sys::unix::thread::Thread::new::thread_start () at library/std/src/sys/unix/thread.rs:108
#17 0x00007f2c91b4e609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#18 0x00007f2c9191e133 in __GI___libc_allocate_once_slow (place=0x19, allocate=0x7d2c54000be0, deallocate=0x400, closure=0x7f2c9191e46e <__GI_epoll_pwait+46>) at allocate_once.c:27
#19 0x0000000000000000 in ?? ()

Thread 12 (Thread 0x7f2c6b4ee700 (LWP 48)):
#0  0x00007f2c9191e46e in __GI_epoll_pwait (epfd=19, events=0x7d2c60000be0, maxevents=1024, timeout=-1852709778, set=0x0) at ../sysdeps/unix/sysv/linux/epoll_pwait.c:42
#1  0x00007d2c60003c80 in ?? ()
#2  0x0000001300000000 in ?? ()
#3  0x00007d2c60000be0 in ?? ()
#4  0x00014fcb00000400 in ?? ()
#5  0x00007d2c00000000 in ?? ()
#6  0x0000558621a4d5c4 in mio::sys::unix::selector::epoll::Selector::select () at library/core/src/fmt/mod.rs:331
#7  0x0000558621a37b2d in tokio::runtime::io::driver::Driver::turn () at library/core/src/fmt/mod.rs:331
#8  0x0000558621a40ba3 in tokio::runtime::time::Driver::park_internal () at library/core/src/fmt/mod.rs:331
#9  0x0000558621a400df in tokio::runtime::scheduler::current_thread::Context::park () at library/core/src/fmt/mod.rs:331
#10 0x00005586218861ed in tokio::runtime::context::scoped::Scoped<T>::set () at library/core/src/fmt/mod.rs:331
#11 0x00005586218e7109 in tokio::runtime::scheduler::current_thread::CurrentThread::block_on () at library/core/src/fmt/mod.rs:331
#12 0x0000558621894bea in std::sys_common::backtrace::__rust_begin_short_backtrace () at library/core/src/fmt/mod.rs:331
#13 0x0000558621895644 in core::ops::function::FnOnce::call_once{{vtable-shim}} () at library/core/src/fmt/mod.rs:331
#14 0x0000558621c185f5 in <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once () at library/alloc/src/boxed.rs:2007
#15 <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once () at library/alloc/src/boxed.rs:2007
#16 std::sys::unix::thread::Thread::new::thread_start () at library/std/src/sys/unix/thread.rs:108
#17 0x00007f2c91b4e609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#18 0x00007f2c9191e133 in __GI___libc_allocate_once_slow (place=0x13, allocate=0x7d2c60000be0, deallocate=0x400, closure=0x7f2c9191e46e <__GI_epoll_pwait+46>) at allocate_once.c:27
#19 0x0000000000000000 in ?? ()

Thread 11 (Thread 0x7f2c9044c700 (LWP 47)):
#0  0x00007f2c9191773d in openlog_internal (logfac=<optimized out>, logstat=<optimized out>, ident=<optimized out>) at ../misc/syslog.c:350
#1  openlog (ident=<optimized out>, logstat=<optimized out>, logfac=<optimized out>) at ../misc/syslog.c:388
#2  0x00007f2c9044b400 in ?? ()
#3  0x0000558622cfd6b0 in ?? ()
#4  0x0000000000000000 in ?? ()

Thread 10 (Thread 0x7f2c90a03700 (LWP 46)):
--Type <RET> for more, q to quit, c to continue without paging--
#0  0x00007f2c9191e46e in __GI_epoll_pwait (epfd=9, events=0x7f2c64000be0, maxevents=1024, timeout=-1852709778, set=0x0) at ../sysdeps/unix/sysv/linux/epoll_pwait.c:42
#1  0x00007f2c64003c80 in ?? ()
#2  0x0000000900000000 in ?? ()
#3  0x00007f2c64000be0 in ?? ()
#4  0x00015ef100000400 in ?? ()
#5  0x00007f2c00000000 in ?? ()
#6  0x0000558621a4d5c4 in mio::sys::unix::selector::epoll::Selector::select () at library/core/src/fmt/mod.rs:331
#7  0x0000558621a37b2d in tokio::runtime::io::driver::Driver::turn () at library/core/src/fmt/mod.rs:331
#8  0x0000558621a40ba3 in tokio::runtime::time::Driver::park_internal () at library/core/src/fmt/mod.rs:331
#9  0x0000558621a400df in tokio::runtime::scheduler::current_thread::Context::park () at library/core/src/fmt/mod.rs:331
#10 0x00005586218861ed in tokio::runtime::context::scoped::Scoped<T>::set () at library/core/src/fmt/mod.rs:331
#11 0x00005586218e7109 in tokio::runtime::scheduler::current_thread::CurrentThread::block_on () at library/core/src/fmt/mod.rs:331
#12 0x0000558621894bea in std::sys_common::backtrace::__rust_begin_short_backtrace () at library/core/src/fmt/mod.rs:331
#13 0x0000558621895644 in core::ops::function::FnOnce::call_once{{vtable-shim}} () at library/core/src/fmt/mod.rs:331
#14 0x0000558621c185f5 in <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once () at library/alloc/src/boxed.rs:2007
#15 <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once () at library/alloc/src/boxed.rs:2007
#16 std::sys::unix::thread::Thread::new::thread_start () at library/std/src/sys/unix/thread.rs:108
#17 0x00007f2c91b4e609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#18 0x00007f2c9191e133 in __GI___libc_allocate_once_slow (place=0x9, allocate=0x7f2c64000be0, deallocate=0x400, closure=0x7f2c9191e46e <__GI_epoll_pwait+46>) at allocate_once.c:27
#19 0x0000000000000000 in ?? ()

Thread 9 (Thread 0x7f2c80dfa700 (LWP 45)):
#0  0x00007f2c9191773d in openlog_internal (logfac=<optimized out>, logstat=<optimized out>, ident=<optimized out>) at ../misc/syslog.c:350
#1  openlog (ident=<optimized out>, logstat=<optimized out>, logfac=<optimized out>) at ../misc/syslog.c:388
#2  0x00007f2c907b5b00 in ?? ()
#3  0x17cf1e20d3414080 in ?? ()
#4  0x00007f2c907b5bcc in ?? ()
#5  0x00005586214ff326 in AbslInternalPerThreadSemWait_lts_20230125 () at library/core/src/fmt/mod.rs:331
#6  0x0000558620b03192 in absl::lts_20230125::CondVar::WaitCommon(absl::lts_20230125::Mutex*, absl::lts_20230125::synchronization_internal::KernelTimeout) [clone .cold] ()
#7  0x0000558621235aff in absl::lts_20230125::CondVar::WaitWithTimeout(absl::lts_20230125::Mutex*, absl::lts_20230125::Duration) () at library/core/src/fmt/mod.rs:331
#8  0x00005586214076ed in grpc_event_engine::experimental::TimerManager::WaitUntil(grpc_core::Timestamp) () at library/core/src/fmt/mod.rs:331
#9  0x000055862140783d in grpc_event_engine::experimental::TimerManager::MainLoop() () at library/core/src/fmt/mod.rs:331
#10 0x000055862124445e in grpc_core::(anonymous namespace)::ThreadInternalsPosix::ThreadInternalsPosix(char const*, void (*)(void*), void*, bool*, grpc_core::Thread::Options const&)::{lambda(void*)#1}::_FUN(void*) () at library/core/src/fmt/mod.rs:331
#11 0x00007f2c91b4e609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#12 0x00007f2c9191e133 in __GI___libc_allocate_once_slow (place=0x7f2c907b5b40, allocate=0x189, deallocate=0x0, closure=0x7f2c9191773d <openlog+381>) at allocate_once.c:27
#13 0x0000000000000000 in ?? ()

Thread 8 (Thread 0x7f2c817fb700 (LWP 44)):
#0  0x00007f2c9191773d in openlog_internal (logfac=<optimized out>, logstat=<optimized out>, ident=<optimized out>) at ../misc/syslog.c:350
#1  openlog (ident=<optimized out>, logstat=<optimized out>, logfac=<optimized out>) at ../misc/syslog.c:388
#2  0x00007f2c907b59cc in ?? ()
#3  0x00005586214ff326 in AbslInternalPerThreadSemWait_lts_20230125 () at library/core/src/fmt/mod.rs:331
#4  0x0000558620b03192 in absl::lts_20230125::CondVar::WaitCommon(absl::lts_20230125::Mutex*, absl::lts_20230125::synchronization_internal::KernelTimeout) [clone .cold] ()
#5  0x00005586215595ff in grpc_event_engine::experimental::OriginalThreadPool::Queue::Step() () at library/core/src/fmt/mod.rs:331
#6  0x000055862155a348 in grpc_event_engine::experimental::OriginalThreadPool::ThreadFunc(std::shared_ptr<grpc_event_engine::experimental::OriginalThreadPool::State>) () at library/core/src/fmt/mod.rs:331
#7  0x000055862155a6ed in grpc_event_engine::experimental::OriginalThreadPool::StartThread(std::shared_ptr<grpc_event_engine::experimental::OriginalThreadPool::State>, grpc_event_engine::experimental::OriginalThreadPool::StartThreadReason)::{lambda(void*)#1}::_FUN(void*) () at library/core/src/fmt/mod.rs:331
#8  0x000055862124445e in grpc_core::(anonymous namespace)::ThreadInternalsPosix::ThreadInternalsPosix(char const*, void (*)(void*), void*, bool*, grpc_core::Thread::Options const&)::{lambda(void*)#1}::_FUN(void*) () at library/core/src/fmt/mod.rs:331
#9  0x00007f2c91b4e609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#10 0x00007f2c9191e133 in __GI___libc_allocate_once_slow (place=0x7f2c907b5940, allocate=0x80, deallocate=0x0, closure=0x7f2c9191773d <openlog+381>) at allocate_once.c:27
#11 0x0000000000000000 in ?? ()

Thread 7 (Thread 0x7f2c821fc700 (LWP 43)):
#0  0x00007f2c9191e46e in __GI_epoll_pwait (epfd=5, events=0x558622cfedf4, maxevents=100, timeout=-1852709778, set=0x0) at ../sysdeps/unix/sysv/linux/epoll_pwait.c:42
#1  0x0000000000000020 in ?? ()
#2  0x0000000500000000 in ?? ()
#3  0x0000558622cfedf4 in ?? ()
#4  0x05265c0000000064 in ?? ()
#5  0x0000000000000001 in ?? ()
#6  0x00005586215b7ca7 in grpc_event_engine::experimental::Epoll1Poller::DoEpollWait(std::chrono::duration<long, std::ratio<1l, 1000000000l> >) () at library/core/src/fmt/mod.rs:331
#7  0x00005586215b86d5 in grpc_event_engine::experimental::Epoll1Poller::Work(std::chrono::duration<long, std::ratio<1l, 1000000000l> >, absl::lts_20230125::FunctionRef<void ()>) () at library/core/src/fmt/mod.rs:331
#8  0x00005586213fa991 in grpc_event_engine::experimental::PosixEventEngine::PollerWorkInternal(std::shared_ptr<grpc_event_engine::experimental::PosixEnginePollerManager>) () at library/core/src/fmt/mod.rs:331
#9  0x00005586213fb5b2 in void absl::lts_20230125::internal_any_invocable::LocalInvoker<false, void, grpc_event_engine::experimental::PosixEventEngine::PollerWorkInternal(std::shared_ptr<grpc_event_engine::experimental::PosixEnginePollerManager>)::{lambda()#2}&>(absl::lts_20230125::internal_any_invocable::TypeErasedState*) () at library/core/src/fmt/mod.rs:331
#10 0x0000558621559683 in grpc_event_engine::experimental::OriginalThreadPool::Queue::Step() () at library/core/src/fmt/mod.rs:331
#11 0x000055862155a348 in grpc_event_engine::experimental::OriginalThreadPool::ThreadFunc(std::shared_ptr<grpc_event_engine::experimental::OriginalThreadPool::State>) () at library/core/src/fmt/mod.rs:331
#12 0x000055862155a6ed in grpc_event_engine::experimental::OriginalThreadPool::StartThread(std::shared_ptr<grpc_event_engine::experimental::OriginalThreadPool::State>, grpc_event_engine::experimental::OriginalThreadPool::StartThreadReason)::{lambda(void*)#1}::_FUN(void*) () at library/core/src/fmt/mod.rs:331
#13 0x000055862124445e in grpc_core::(anonymous namespace)::ThreadInternalsPosix::ThreadInternalsPosix(char const*, void (*)(void*), void*, bool*, grpc_core::Thread::Options const&)::{lambda(void*)#1}::_FUN(void*) () at library/core/src/fmt/mod.rs:331
#14 0x00007f2c91b4e609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#15 0x00007f2c9191e133 in __GI___libc_allocate_once_slow (place=0x5, allocate=0x558622cfedf4, deallocate=0x64, closure=0x7f2c9191e46e <__GI_epoll_pwait+46>) at allocate_once.c:27
#16 0x0000000000000000 in ?? ()

Thread 6 (Thread 0x7f2c90c07700 (LWP 42)):
#0  0x00007f2c9191773d in openlog_internal (logfac=<optimized out>, logstat=<optimized out>, ident=<optimized out>) at ../misc/syslog.c:350
#1  openlog (ident=<optimized out>, logstat=<optimized out>, logfac=<optimized out>) at ../misc/syslog.c:388
#2  0x00007f2c907b67cc in ?? ()
#3  0x00005586214ff326 in AbslInternalPerThreadSemWait_lts_20230125 () at library/core/src/fmt/mod.rs:331
#4  0x0000558620b03192 in absl::lts_20230125::CondVar::WaitCommon(absl::lts_20230125::Mutex*, absl::lts_20230125::synchronization_internal::KernelTimeout) [clone .cold] ()
#5  0x0000558621069b0f in gpr_cv_wait () at library/core/src/fmt/mod.rs:331
#6  0x0000558621417f09 in pollset_work(grpc_pollset*, grpc_pollset_worker**, grpc_core::Timestamp) () at library/core/src/fmt/mod.rs:331
#7  0x0000558621119b6a in pollset_work(grpc_pollset*, grpc_pollset_worker**, grpc_core::Timestamp) () at library/core/src/fmt/mod.rs:331
#8  0x0000558621420b3a in grpc_pollset_work(grpc_pollset*, grpc_pollset_worker**, grpc_core::Timestamp) () at library/core/src/fmt/mod.rs:331
#9  0x00005586211879a3 in cq_next(grpc_completion_queue*, gpr_timespec, void*) () at library/core/src/fmt/mod.rs:331
#10 0x000055862105450a in grpcio::env::poll_queue () at library/core/src/fmt/mod.rs:331
#11 0x0000558621060f05 in std::sys_common::backtrace::__rust_begin_short_backtrace () at library/core/src/fmt/mod.rs:331
#12 0x0000558621057c47 in core::ops::function::FnOnce::call_once{{vtable-shim}} () at library/core/src/fmt/mod.rs:331
#13 0x0000558621c185f5 in <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once () at library/alloc/src/boxed.rs:2007
#14 <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once () at library/alloc/src/boxed.rs:2007
#15 std::sys::unix::thread::Thread::new::thread_start () at library/std/src/sys/unix/thread.rs:108
#16 0x00007f2c91b4e609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#17 0x00007f2c9191e133 in __GI___libc_allocate_once_slow (place=0x7f2c907b6740, allocate=0x80, deallocate=0x0, closure=0x7f2c9191773d <openlog+381>) at allocate_once.c:27
#18 0x0000000000000000 in ?? ()

Thread 5 (Thread 0x7f2c82bfd700 (LWP 41)):
#0  0x00007f2c9191773d in openlog_internal (logfac=<optimized out>, logstat=<optimized out>, ident=<optimized out>) at ../misc/syslog.c:350
#1  openlog (ident=<optimized out>, logstat=<optimized out>, logfac=<optimized out>) at ../misc/syslog.c:388
#2  0x00007f2c907b55cc in ?? ()
#3  0x00005586214ff326 in AbslInternalPerThreadSemWait_lts_20230125 () at library/core/src/fmt/mod.rs:331
#4  0x0000558620b03192 in absl::lts_20230125::CondVar::WaitCommon(absl::lts_20230125::Mutex*, absl::lts_20230125::synchronization_internal::KernelTimeout) [clone .cold] ()
--Type <RET> for more, q to quit, c to continue without paging--
#5  0x0000558621069b0f in gpr_cv_wait () at library/core/src/fmt/mod.rs:331
#6  0x000055862142eaee in timer_thread(void*) () at library/core/src/fmt/mod.rs:331
#7  0x0000558621244400 in grpc_core::(anonymous namespace)::ThreadInternalsPosix::ThreadInternalsPosix(char const*, void (*)(void*), void*, bool*, grpc_core::Thread::Options const&)::{lambda(void*)#1}::_FUN(void*) () at library/core/src/fmt/mod.rs:331
#8  0x00007f2c91b4e609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#9  0x00007f2c9191e133 in __GI___libc_allocate_once_slow (place=0x7f2c907b5540, allocate=0x80, deallocate=0x0, closure=0x7f2c9191773d <openlog+381>) at allocate_once.c:27
#10 0x0000000000000000 in ?? ()

Thread 4 (Thread 0x7f2c835fe700 (LWP 40)):
#0  0x00007f2c9191773d in openlog_internal (logfac=<optimized out>, logstat=<optimized out>, ident=<optimized out>) at ../misc/syslog.c:350
#1  openlog (ident=<optimized out>, logstat=<optimized out>, logfac=<optimized out>) at ../misc/syslog.c:388
#2  0x00007f2c907b53cc in ?? ()
#3  0x00005586214ff326 in AbslInternalPerThreadSemWait_lts_20230125 () at library/core/src/fmt/mod.rs:331
#4  0x0000558620b03192 in absl::lts_20230125::CondVar::WaitCommon(absl::lts_20230125::Mutex*, absl::lts_20230125::synchronization_internal::KernelTimeout) [clone .cold] ()
#5  0x0000558621069b0f in gpr_cv_wait () at library/core/src/fmt/mod.rs:331
#6  0x000055862111ad05 in grpc_core::Executor::ThreadMain(void*) () at library/core/src/fmt/mod.rs:331
#7  0x0000558621244400 in grpc_core::(anonymous namespace)::ThreadInternalsPosix::ThreadInternalsPosix(char const*, void (*)(void*), void*, bool*, grpc_core::Thread::Options const&)::{lambda(void*)#1}::_FUN(void*) () at library/core/src/fmt/mod.rs:331
#8  0x00007f2c91b4e609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#9  0x00007f2c9191e133 in __GI___libc_allocate_once_slow (place=0x7f2c907b5340, allocate=0x80, deallocate=0x0, closure=0x7f2c9191773d <openlog+381>) at allocate_once.c:27
#10 0x0000000000000000 in ?? ()

Thread 3 (Thread 0x7f2c83fff700 (LWP 39)):
#0  0x00007f2c9191773d in openlog_internal (logfac=<optimized out>, logstat=<optimized out>, ident=<optimized out>) at ../misc/syslog.c:350
#1  openlog (ident=<optimized out>, logstat=<optimized out>, logfac=<optimized out>) at ../misc/syslog.c:388
#2  0x00007f2c907b51cc in ?? ()
#3  0x00005586214ff326 in AbslInternalPerThreadSemWait_lts_20230125 () at library/core/src/fmt/mod.rs:331
#4  0x0000558620b03192 in absl::lts_20230125::CondVar::WaitCommon(absl::lts_20230125::Mutex*, absl::lts_20230125::synchronization_internal::KernelTimeout) [clone .cold] ()
#5  0x0000558621069b0f in gpr_cv_wait () at library/core/src/fmt/mod.rs:331
#6  0x000055862111ad05 in grpc_core::Executor::ThreadMain(void*) () at library/core/src/fmt/mod.rs:331
#7  0x0000558621244400 in grpc_core::(anonymous namespace)::ThreadInternalsPosix::ThreadInternalsPosix(char const*, void (*)(void*), void*, bool*, grpc_core::Thread::Options const&)::{lambda(void*)#1}::_FUN(void*) () at library/core/src/fmt/mod.rs:331
#8  0x00007f2c91b4e609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#9  0x00007f2c9191e133 in __GI___libc_allocate_once_slow (place=0x7f2c907b5140, allocate=0x80, deallocate=0x0, closure=0x7f2c9191773d <openlog+381>) at allocate_once.c:27
#10 0x0000000000000000 in ?? ()

Thread 2 (Thread 0x7f2c90e0b700 (LWP 36)):
#0  0x00007f2c9191773d in openlog_internal (logfac=<optimized out>, logstat=<optimized out>, ident=<optimized out>) at ../misc/syslog.c:350
#1  openlog (ident=<optimized out>, logstat=<optimized out>, logfac=<optimized out>) at ../misc/syslog.c:388
#2  0x7fffffffffffffff in ?? ()
#3  0x00007f2c8c000bf0 in ?? ()
#4  0x00007f2c90e0a5a0 in ?? ()
#5  0x0000558621c06040 in ?? () at library/std/src/rt.rs:151
#6  0x0000558622cfac00 in ?? ()
#7  0x00005586216a9eba in crossbeam_channel::context::Context::with::{{closure}} () at library/core/src/fmt/mod.rs:331
#8  0x00005586216a8dd0 in crossbeam_channel::channel::Receiver<T>::recv () at library/core/src/fmt/mod.rs:331
#9  0x00005586216aa4b3 in std::panicking::try () at library/core/src/fmt/mod.rs:331
#10 0x00005586216b419b in std::sys_common::backtrace::__rust_begin_short_backtrace () at library/core/src/fmt/mod.rs:331
#11 0x00005586216b10f3 in core::ops::function::FnOnce::call_once{{vtable-shim}} () at library/core/src/fmt/mod.rs:331
#12 0x0000558621c185f5 in <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once () at library/alloc/src/boxed.rs:2007
#13 <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once () at library/alloc/src/boxed.rs:2007
#14 std::sys::unix::thread::Thread::new::thread_start () at library/std/src/sys/unix/thread.rs:108
#15 0x00007f2c91b4e609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#16 0x00007f2c9191e133 in __GI___libc_allocate_once_slow (place=0x558622cfaed8, allocate=0x89, deallocate=0xffffffff, closure=0x7f2c9191773d <openlog+381>) at allocate_once.c:27
#17 0x0000000000000000 in ?? ()

Thread 1 (Thread 0x7f2c917fac80 (LWP 33)):
#0  0x00007f2c918dc23f in __GI___clock_nanosleep (clock_id=clock_id@entry=0, flags=flags@entry=0, req=0x7fff2dd0d190, rem=0x7fff2dd0d190) at ../sysdeps/unix/sysv/linux/clock_nanosleep.c:78
#1  0x00007f2c918e1ec7 in __GI___nanosleep (requested_time=<optimized out>, remaining=<optimized out>) at nanosleep.c:27
#2  0x0000558621c05fd0 in std::sys::unix::thread::Thread::sleep () at library/std/src/sys/unix/thread.rs:241
#3  std::thread::sleep () at library/std/src/thread/mod.rs:872
#4  0x0000558620cb012a in mobilecoind::main () at library/core/src/fmt/mod.rs:331
#5  0x0000558620c9f323 in std::sys_common::backtrace::__rust_begin_short_backtrace () at library/core/src/fmt/mod.rs:331
#6  0x0000558620cb6db9 in std::rt::lang_start::{{closure}} () at library/core/src/fmt/mod.rs:331
#7  0x0000558621c05a7b in core::ops::function::impls::<impl core::ops::function::FnOnce<A> for &F>::call_once () at library/core/src/ops/function.rs:284
#8  std::panicking::try::do_call () at library/std/src/panicking.rs:504
#9  std::panicking::try () at library/std/src/panicking.rs:468
#10 std::panic::catch_unwind () at library/std/src/panic.rs:142
#11 std::rt::lang_start_internal::{{closure}} () at library/std/src/rt.rs:148
#12 std::panicking::try::do_call () at library/std/src/panicking.rs:504
#13 std::panicking::try () at library/std/src/panicking.rs:468
#14 std::panic::catch_unwind () at library/std/src/panic.rs:142
#15 std::rt::lang_start_internal () at library/std/src/rt.rs:148
#16 0x0000558620cb1a05 in main () at library/core/src/fmt/mod.rs:331
(gdb)

Pay attention to thread 23 - 23 Thread 0x7f2c682be700 (LWP 61) "Mobilecoind-RPC":

#9  0x0000558620bb4a47 in mc_mobilecoind::service::ServiceApi<T,FPR>::get_last_block_infos () at library/core/src/fmt/mod.rs:331
#10 0x0000558620b977d2 in <mc_mobilecoind::service::ServiceApi<T,FPR> as mc_mobilecoind_api::autogenerated_code::mobilecoind_api_grpc::MobilecoindApi>::get_network_status () at library/core/src/fmt/mod.rs:331

If this stacktrace is indeed correct, this is pretty weird: get_network_status() first locks self.network_state here.
It then calls get_last_block_infos here which tries to lock the same lock: https://github.com/mobilecoinfoundation/mobilecoin/blob/main/mobilecoind/src/service.rs#L230

Assuming compiler optimization didn't do anything funky here, it is pretty surprising that the first lock succeeded and the second one got stuck.

I couldn't find anything else in the other threads stack traces that could shed some light on it. The self.network_state lock is locked for writing in only one place as far as I can tell: https://github.com/mobilecoinfoundation/mobilecoin/blob/main/ledger/sync/src/ledger_sync/ledger_sync_service_thread.rs#

The stack trace of the ledger sync thread is not very useful:

  11   Thread 0x7f2c9044c700 (LWP 47) "LedgerSync"       0x00007f2c9191773d in openlog_internal (logfac=<optimized out>, logstat=<optimized out>, ident=<optimized out>) at ../misc/syslog.c:350


Thread 11 (Thread 0x7f2c9044c700 (LWP 47)):
#0  0x00007f2c9191773d in openlog_internal (logfac=<optimized out>, logstat=<optimized out>, ident=<optimized out>) at ../misc/syslog.c:350
#1  openlog (ident=<optimized out>, logstat=<optimized out>, logfac=<optimized out>) at ../misc/syslog.c:388
#2  0x00007f2c9044b400 in ?? ()
#3  0x0000558622cfd6b0 in ?? ()
#4  0x0000000000000000 in ?? ()

[eranrund]

This might be relevant: https://www.reddit.com/r/rust/comments/urnqz8/different_behaviors_of_recursive_read_locks_in/
Basically, the write lock has a higher priority than the read lock. When trying to acquire a write lock in between two recursive read locks, the second read lock cannot be acquired, which in turn prevents the release of the first read lock.

[eranrund]

Looks like this is even in the official docs: https://doc.rust-lang.org/std/sync/struct.RwLock.html

So I bet this is whats happening here