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.

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

Investigate lock-order-inversion in newer ThreadSanitizer output #299

Open
tsaubergine opened this issue Aug 15, 2023 · 0 comments
Open

Comments

@tsaubergine
Copy link
Member

See if this is a real problem or a false positive:

==================
WARNING: ThreadSanitizer: lock-order-inversion (potential deadlock) (pid=796905)
  Cycle in lock order graph: M1429 (0x7b100002c1d0) => M1435 (0x7b100002c190) => M1429

  Mutex M1435 acquired here while holding mutex M1429 in thread T19:
    #0 pthread_mutex_lock ../../../../src/libsanitizer/sanitizer_common/sanitizer_common_interceptors.inc:4240 (libtsan.so.0+0x53908)
goby_test_middleware_basic [    #1 __gthread_mutex_lock /usr/include/x86_64-linux-gnu/c++/11/bits/gthr-default.h:749 (goby_test_middleware_basic+0x22d7d7)
    #2 std::mutex::lock() <null> (goby_test_middleware_basic+0x233074)
    #3 std::unique_lock<std::mutex>::lock() <null> (goby_test_middleware_basic+0x28c4f3)
    #4 std::unique_lock<std::mutex>::unique_lock(std::mutex&) <null> (goby_test_middleware_basic+0x2769e6)
    #5 std::cv_status std::_V2::condition_variable_any::wait_until<std::unique_lock<std::timed_mutex>, std::chrono::_V2::steady_clock, std::chrono::duration<long, std::ratio<1l, 1000000000l> > >(std::unique_lock<std::timed_mutex>&, std::chrono::time_point<std::chrono::_V2::steady_clock, std::chrono::duration<long, std::ratio<1l, 1000000000l> > > const&) <null> (goby_test_middleware_basic+0x2cb5da)
    #6 int goby::middleware::PollerInterface::_poll_all<std::chrono::_V2::steady_clock, std::chrono::duration<long, std::ratio<1l, 1000000000l> > >(std::chrono::time_point<std::chrono::_V2::steady_clock, std::chrono::duration<long, std::ratio<1l, 1000000000l> > > const&) <null> (goby_test_middleware_basic+0x2b114b)
    #7 int goby::middleware::PollerInterface::poll<std::chrono::_V2::steady_clock, std::chrono::duration<long, std::ratio<1l, 1000000000l> > >(std::chrono::time_point<std::chrono::_V2::steady_clock, std::chrono::duration<long, std::ratio<1l, 1000000000l> > > const&) <null> (goby_test_middleware_basic+0x296fc3)
    #8 goby::middleware::Thread<goby::middleware::intervehicle::protobuf::PortalConfig_LinkConfig, goby::middleware::InterProcessForwarder<goby::middleware::InterThreadTransporter> >::run_once() <null> (goby_test_middleware_basic+0x27cc28)
    #9 goby::middleware::Thread<goby::middleware::intervehicle::protobuf::PortalConfig_LinkConfig, goby::middleware::InterProcessForwarder<goby::middleware::InterThreadTransporter> >::run(std::atomic<bool>&) <null> (goby_test_middleware_basic+0x267aa1)
    #10 goby::middleware::InterVehiclePortal<goby::zeromq::InterProcessPortalImplementation<goby::middleware::InterThreadTransporter, goby::middleware::InterProcessPortalBase> >::_init()::{lambda()#6}::operator()() const <null> (goby_test_middleware_basic+0x2554c3)
    #11 void std::__invoke_impl<void, goby::middleware::InterVehiclePortal<goby::zeromq::InterProcessPortalImplementation<goby::middleware::InterThreadTransporter, goby::middleware::InterProcessPortalBase> >::_init()::{lambda()#6}>(std::__invoke_other, goby::middleware::InterVehiclePortal<goby::zeromq::InterProcessPortalImplementation<goby::middleware::InterThreadTransporter, goby::middleware::InterProcessPortalBase> >::_init()::{lambda()#6}&&) <null> (goby_test_middleware_basic+0x3ad133)
    #12 std::__invoke_result<goby::middleware::InterVehiclePortal<goby::zeromq::InterProcessPortalImplementation<goby::middleware::InterThreadTransporter, goby::middleware::InterProcessPortalBase> >::_init()::{lambda()#6}>::type std::__invoke<goby::middleware::InterVehiclePortal<goby::zeromq::InterProcessPortalImplementation<goby::middleware::InterThreadTransporter, goby::middleware::InterProcessPortalBase> >::_init()::{lambda()#6}>(goby::middleware::InterVehiclePortal<goby::zeromq::InterProcessPortalImplementation<goby::middleware::InterThreadTransporter, goby::middleware::InterProcessPortalBase> >::_init()::{lambda()#6}&&) <null> (goby_test_middleware_basic+0x3a314a)
2023-Aug-15 04:04:19.868135]: D3: Buffering publication of 5 bytes to [/slow;0/DCCL/goby.test.zeromq.protobuf.CTDSample/796905/faf28d0ff88699fd/]
    #13 void std::thread::_Invoker<std::tuple<goby::middleware::InterVehiclePortal<goby::zeromq::InterProcessPortalImplementation<goby::middleware::InterThreadTransporter, goby::middleware::InterProcessPortalBase> >::_init()::{lambda()#6}> >::_M_invoke<0ul>(std::_Index_tuple<0ul>) <null> (goby_test_middleware_basic+0x39495c)
    #14 std::thread::_Invoker<std::tuple<goby::middleware::InterVehiclePortal<goby::zeromq::InterProcessPortalImplementation<goby::middleware::InterThreadTransporter, goby::middleware::InterProcessPortalBase> >::_init()::{lambda()#6}> >::operator()() <null> (goby_test_middleware_basic+0x38c336)
    #15 std::thread::_State_impl<std::thread::_Invoker<std::tuple<goby::middleware::InterVehiclePortal<goby::zeromq::InterProcessPortalImplementation<goby::middleware::InterThreadTransporter, goby::middleware::InterProcessPortalBase> >::_init()::{lambda()#6}> > >::_M_run() <null> (goby_test_middleware_basic+0x382700)
    #16 <null> <null> (libstdc++.so.6+0xdc252)

  Mutex M1429 previously acquired by the same thread here:
goby_test_middleware_basic [    #0 pthread_mutex_lock ../../../../src/libsanitizer/sanitizer_common/sanitizer_common_interceptors.inc:4240 (libtsan.so.0+0x53908)
    #1 __gthread_mutex_lock /usr/include/x86_64-linux-gnu/c++/11/bits/gthr-default.h:749 (goby_test_middleware_basic+0x22d7d7)
    #2 std::timed_mutex::lock() <null> (goby_test_middleware_basic+0x233246)
    #3 std::unique_lock<std::timed_mutex>::lock() <null> (goby_test_middleware_basic+0x2b141d)
    #4 std::unique_lock<std::timed_mutex>::unique_lock(std::timed_mutex&) <null> (goby_test_middleware_basic+0x297174)
    #5 int goby::middleware::PollerInterface::_poll_all<std::chrono::_V2::steady_clock, std::chrono::duration<long, std::ratio<1l, 1000000000l> > >(std::chrono::time_point<std::chrono::_V2::steady_clock, std::chrono::duration<long, std::ratio<1l, 1000000000l> > > const&) <null> (goby_test_middleware_basic+0x2b0fcb)
    #6 int goby::middleware::PollerInterface::poll<std::chrono::_V2::steady_clock, std::chrono::duration<long, std::ratio<1l, 1000000000l> > >(std::chrono::time_point<std::chrono::_V2::steady_clock, std::chrono::duration<long, std::ratio<1l, 1000000000l> > > const&) <null> (goby_test_middleware_basic+0x296fc3)
    #7 goby::middleware::Thread<goby::middleware::intervehicle::protobuf::PortalConfig_LinkConfig, goby::middleware::InterProcessForwarder<goby::middleware::InterThreadTransporter> >::run_once() <null> (goby_test_middleware_basic+0x27cc28)
    #8 goby::middleware::Thread<goby::middleware::intervehicle::protobuf::PortalConfig_LinkConfig, goby::middleware::InterProcessForwarder<goby::middleware::InterThreadTransporter> >::run(std::atomic<bool>&) <null> (goby_test_middleware_basic+0x267aa1)
    #9 goby::middleware::InterVehiclePortal<goby::zeromq::InterProcessPortalImplementation<goby::middleware::InterThreadTransporter, goby::middleware::InterProcessPortalBase> >::_init()::{lambda()#6}::operator()() const <null> (goby_test_middleware_basic+0x2554c3)
2023-Aug-15 04:04:19.868585]: D3: Buffering publication of 9 bytes to [/slow;0/PROTOBUF/goby.test.zeromq.protobuf.CTDSample/796905/faf28d0ff88699fd/]
    #10 void std::__invoke_impl<void, goby::middleware::InterVehiclePortal<goby::zeromq::InterProcessPortalImplementation<goby::middleware::InterThreadTransporter, goby::middleware::InterProcessPortalBase> >::_init()::{lambda()#6}>(std::__invoke_other, goby::middleware::InterVehiclePortal<goby::zeromq::InterProcessPortalImplementation<goby::middleware::InterThreadTransporter, goby::middleware::InterProcessPortalBase> >::_init()::{lambda()#6}&&) <null> (goby_test_middleware_basic+0x3ad133)
    #11 std::__invoke_result<goby::middleware::InterVehiclePortal<goby::zeromq::InterProcessPortalImplementation<goby::middleware::InterThreadTransporter, goby::middleware::InterProcessPortalBase> >::_init()::{lambda()#6}>::type std::__invoke<goby::middleware::InterVehiclePortal<goby::zeromq::InterProcessPortalImplementation<goby::middleware::InterThreadTransporter, goby::middleware::InterProcessPortalBase> >::_init()::{lambda()#6}>(goby::middleware::InterVehiclePortal<goby::zeromq::InterProcessPortalImplementation<goby::middleware::InterThreadTransporter, goby::middleware::InterProcessPortalBase> >::_init()::{lambda()#6}&&) <null> (goby_test_middleware_basic+0x3a314a)
    #12 void std::thread::_Invoker<std::tuple<goby::middleware::InterVehiclePortal<goby::zeromq::InterProcessPortalImplementation<goby::middleware::InterThreadTransporter, goby::middleware::InterProcessPortalBase> >::_init()::{lambda()#6}> >::_M_invoke<0ul>(std::_Index_tuple<0ul>) <null> (goby_test_middleware_basic+0x39495c)
    #13 std::thread::_Invoker<std::tuple<goby::middleware::InterVehiclePortal<goby::zeromq::InterProcessPortalImplementation<goby::middleware::InterThreadTransporter, goby::middleware::InterProcessPortalBase> >::_init()::{lambda()#6}> >::operator()() <null> (goby_test_middleware_basic+0x38c336)
    #14 std::thread::_State_impl<std::thread::_Invoker<std::tuple<goby::middleware::InterVehiclePortal<goby::zeromq::InterProcessPortalImplementation<goby::middleware::InterThreadTransporter, goby::middleware::InterProcessPortalBase> >::_init()::{lambda()#6}> > >::_M_run() <null> (goby_test_middleware_basic+0x382700)
    #15 <null> <null> (libstdc++.so.6+0xdc252)

  Mutex M1429 acquired here while holding mutex M1435 in thread T19:
    #0 pthread_mutex_lock ../../../../src/libsanitizer/sanitizer_common/sanitizer_common_interceptors.inc:4240 (libtsan.so.0+0x53908)
    #1 __gthread_mutex_lock /usr/include/x86_64-linux-gnu/c++/11/bits/gthr-default.h:749 (goby_test_middleware_basic+0x22d7d7)
    #2 std::timed_mutex::lock() <null> (goby_test_middleware_basic+0x233246)
    #3 std::unique_lock<std::timed_mutex>::lock() <null> (goby_test_middleware_basic+0x2b141d)
    #4 std::_V2::condition_variable_any::_Unlock<std::unique_lock<std::timed_mutex> >::~_Unlock() <null> (goby_test_middleware_basic+0x2b1689)
    #5 std::cv_status std::_V2::condition_variable_any::wait_until<std::unique_lock<std::timed_mutex>, std::chrono::_V2::steady_clock, std::chrono::duration<long, std::ratio<1l, 1000000000l> > >(std::unique_lock<std::timed_mutex>&, std::chrono::time_point<std::chrono::_V2::steady_clock, std::chrono::duration<long, std::ratio<1l, 1000000000l> > > const&) <null> (goby_test_middleware_basic+0x2cb63d)
    #6 int goby::middleware::PollerInterface::_poll_all<std::chrono::_V2::steady_clock, std::chrono::duration<long, std::ratio<1l, 1000000000l> > >(std::chrono::time_point<std::chrono::_V2::steady_clock, std::chrono::duration<long, std::ratio<1l, 1000000000l> > > const&) <null> (goby_test_middleware_basic+0x2b114b)
    #7 int goby::middleware::PollerInterface::poll<std::chrono::_V2::steady_clock, std::chrono::duration<long, std::ratio<1l, 1000000000l> > >(std::chrono::time_point<std::chrono::_V2::steady_clock, std::chrono::duration<long, std::ratio<1l, 1000000000l> > > const&) <null> (goby_test_middleware_basic+0x296fc3)
    #8 goby::middleware::Thread<goby::middleware::intervehicle::protobuf::PortalConfig_LinkConfig, goby::middleware::InterProcessForwarder<goby::middleware::InterThreadTransporter> >::run_once() <null> (goby_test_middleware_basic+0x27cc28)
    #9 goby::middleware::Thread<goby::middleware::intervehicle::protobuf::PortalConfig_LinkConfig, goby::middleware::InterProcessForwarder<goby::middleware::InterThreadTransporter> >::run(std::atomic<bool>&) <null> (goby_test_middleware_basic+0x267aa1)
    #10 goby::middleware::InterVehiclePortal<goby::zeromq::InterProcessPortalImplementation<goby::middleware::InterThreadTransporter, goby::middleware::InterProcessPortalBase> >::_init()::{lambda()#6}::operator()() const <null> (goby_test_middleware_basic+0x2554c3)
    #11 void std::__invoke_impl<void, goby::middleware::InterVehiclePortal<goby::zeromq::InterProcessPortalImplementation<goby::middleware::InterThreadTransporter, goby::middleware::InterProcessPortalBase> >::_init()::{lambda()#6}>(std::__invoke_other, goby::middleware::InterVehiclePortal<goby::zeromq::InterProcessPortalImplementation<goby::middleware::InterThreadTransporter, goby::middleware::InterProcessPortalBase> >::_init()::{lambda()#6}&&) <null> (goby_test_middleware_basic+0x3ad133)
    #12 std::__invoke_result<goby::middleware::InterVehiclePortal<goby::zeromq::InterProcessPortalImplementation<goby::middleware::InterThreadTransporter, goby::middleware::InterProcessPortalBase> >::_init()::{lambda()#6}>::type std::__invoke<goby::middleware::InterVehiclePortal<goby::zeromq::InterProcessPortalImplementation<goby::middleware::InterThreadTransporter, goby::middleware::InterProcessPortalBase> >::_init()::{lambda()#6}>(goby::middleware::InterVehiclePortal<goby::zeromq::InterProcessPortalImplementation<goby::middleware::InterThreadTransporter, goby::middleware::InterProcessPortalBase> >::_init()::{lambda()#6}&&) <null> (goby_test_middleware_basic+0x3a314a)
    #13 void std::thread::_Invoker<std::tuple<goby::middleware::InterVehiclePortal<goby::zeromq::InterProcessPortalImplementation<goby::middleware::InterThreadTransporter, goby::middleware::InterProcessPortalBase> >::_init()::{lambda()#6}> >::_M_invoke<0ul>(std::_Index_tuple<0ul>) <null> (goby_test_middleware_basic+0x39495c)
    #14 std::thread::_Invoker<std::tuple<goby::middleware::InterVehiclePortal<goby::zeromq::InterProcessPortalImplementation<goby::middleware::InterThreadTransporter, goby::middleware::InterProcessPortalBase> >::_init()::{lambda()#6}> >::operator()() <null> (goby_test_middleware_basic+0x38c336)
    #15 std::thread::_State_impl<std::thread::_Invoker<std::tuple<goby::middleware::InterVehiclePortal<goby::zeromq::InterProcessPortalImplementation<goby::middleware::InterThreadTransporter, goby::middleware::InterProcessPortalBase> >::_init()::{lambda()#6}> > >::_M_run() <null> (goby_test_middleware_basic+0x382700)
    #16 <null> <null> (libstdc++.so.6+0xdc252)

  Mutex M1435 previously acquired by the same thread here:
    #0 pthread_mutex_lock ../../../../src/libsanitizer/sanitizer_common/sanitizer_common_interceptors.inc:4240 (libtsan.so.0+0x53908)
    #1 __gthread_mutex_lock /usr/include/x86_64-linux-gnu/c++/11/bits/gthr-default.h:749 (goby_test_middleware_basic+0x22d7d7)
    #2 std::mutex::lock() <null> (goby_test_middleware_basic+0x233074)
    #3 std::unique_lock<std::mutex>::lock() <null> (goby_test_middleware_basic+0x28c4f3)
    #4 std::unique_lock<std::mutex>::unique_lock(std::mutex&) <null> (goby_test_middleware_basic+0x2769e6)
    #5 std::cv_status std::_V2::condition_variable_any::wait_until<std::unique_lock<std::timed_mutex>, std::chrono::_V2::steady_clock, std::chrono::duration<long, std::ratio<1l, 1000000000l> > >(std::unique_lock<std::timed_mutex>&, std::chrono::time_point<std::chrono::_V2::steady_clock, std::chrono::duration<long, std::ratio<1l, 1000000000l> > > const&) <null> (goby_test_middleware_basic+0x2cb5da)
    #6 int goby::middleware::PollerInterface::_poll_all<std::chrono::_V2::steady_clock, std::chrono::duration<long, std::ratio<1l, 1000000000l> > >(std::chrono::time_point<std::chrono::_V2::steady_clock, std::chrono::duration<long, std::ratio<1l, 1000000000l> > > const&) <null> (goby_test_middleware_basic+0x2b114b)
    #7 int goby::middleware::PollerInterface::poll<std::chrono::_V2::steady_clock, std::chrono::duration<long, std::ratio<1l, 1000000000l> > >(std::chrono::time_point<std::chrono::_V2::steady_clock, std::chrono::duration<long, std::ratio<1l, 1000000000l> > > const&) <null> (goby_test_middleware_basic+0x296fc3)
    #8 goby::middleware::Thread<goby::middleware::intervehicle::protobuf::PortalConfig_LinkConfig, goby::middleware::InterProcessForwarder<goby::middleware::InterThreadTransporter> >::run_once() <null> (goby_test_middleware_basic+0x27cc28)
    #9 goby::middleware::Thread<goby::middleware::intervehicle::protobuf::PortalConfig_LinkConfig, goby::middleware::InterProcessForwarder<goby::middleware::InterThreadTransporter> >::run(std::atomic<bool>&) <null> (goby_test_middleware_basic+0x267aa1)
    #10 goby::middleware::InterVehiclePortal<goby::zeromq::InterProcessPortalImplementation<goby::middleware::InterThreadTransporter, goby::middleware::InterProcessPortalBase> >::_init()::{lambda()#6}::operator()() const <null> (goby_test_middleware_basic+0x2554c3)
    #11 void std::__invoke_impl<void, goby::middleware::InterVehiclePortal<goby::zeromq::InterProcessPortalImplementation<goby::middleware::InterThreadTransporter, goby::middleware::InterProcessPortalBase> >::_init()::{lambda()#6}>(std::__invoke_other, goby::middleware::InterVehiclePortal<goby::zeromq::InterProcessPortalImplementation<goby::middleware::InterThreadTransporter, goby::middleware::InterProcessPortalBase> >::_init()::{lambda()#6}&&) <null> (goby_test_middleware_basic+0x3ad133)
    #12 std::__invoke_result<goby::middleware::InterVehiclePortal<goby::zeromq::InterProcessPortalImplementation<goby::middleware::InterThreadTransporter, goby::middleware::InterProcessPortalBase> >::_init()::{lambda()#6}>::type std::__invoke<goby::middleware::InterVehiclePortal<goby::zeromq::InterProcessPortalImplementation<goby::middleware::InterThreadTransporter, goby::middleware::InterProcessPortalBase> >::_init()::{lambda()#6}>(goby::middleware::InterVehiclePortal<goby::zeromq::InterProcessPortalImplementation<goby::middleware::InterThreadTransporter, goby::middleware::InterProcessPortalBase> >::_init()::{lambda()#6}&&) <null> (goby_test_middleware_basic+0x3a314a)
    #13 void std::thread::_Invoker<std::tuple<goby::middleware::InterVehiclePortal<goby::zeromq::InterProcessPortalImplementation<goby::middleware::InterThreadTransporter, goby::middleware::InterProcessPortalBase> >::_init()::{lambda()#6}> >::_M_invoke<0ul>(std::_Index_tuple<0ul>) <null> (goby_test_middleware_basic+0x39495c)
    #14 std::thread::_Invoker<std::tuple<goby::middleware::InterVehiclePortal<goby::zeromq::InterProcessPortalImplementation<goby::middleware::InterThreadTransporter, goby::middleware::InterProcessPortalBase> >::_init()::{lambda()#6}> >::operator()() <null> (goby_test_middleware_basic+0x38c336)
    #15 std::thread::_State_impl<std::thread::_Invoker<std::tuple<goby::middleware::InterVehiclePortal<goby::zeromq::InterProcessPortalImplementation<goby::middleware::InterThreadTransporter, goby::middleware::InterProcessPortalBase> >::_init()::{lambda()#6}> > >::_M_run() <null> (goby_test_middleware_basic+0x382700)
    #16 <null> <null> (libstdc++.so.6+0xdc252)

  Thread T19 (tid=796925, running) created by main thread at:
    #0 pthread_create ../../../../src/libsanitizer/tsan/tsan_interceptors_posix.cpp:969 (libtsan.so.0+0x605b8)
    #1 std::thread::_M_start_thread(std::unique_ptr<std::thread::_State, std::default_delete<std::thread::_State> >, void (*)()) <null> (libstdc++.so.6+0xdc328)
    #2 goby::middleware::InterVehiclePortal<goby::zeromq::InterProcessPortalImplementation<goby::middleware::InterThreadTransporter, goby::middleware::InterProcessPortalBase> >::_init() <null> (goby_test_middleware_basic+0x255cd5)
    #3 goby::middleware::InterVehiclePortal<goby::zeromq::InterProcessPortalImplementation<goby::middleware::InterThreadTransporter, goby::middleware::InterProcessPortalBase> >::InterVehiclePortal(goby::zeromq::InterProcessPortalImplementation<goby::middleware::InterThreadTransporter, goby::middleware::InterProcessPortalBase>&, goby::middleware::intervehicle::protobuf::PortalConfig const&) <null> (goby_test_middleware_basic+0x247fd4)
    #4 main /home/toby/opensource/goby3/src/test/zeromq/middleware_basic/test.cpp:124 (goby_test_middleware_basic+0x22e58b)

SUMMARY: ThreadSanitizer: lock-order-inversion (potential deadlock) /usr/include/x86_64-linux-gnu/c++/11/bits/gthr-default.h:749 in __gthread_mutex_lock
==================

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

1 participant