diff --git a/src/sync.h b/src/sync.h --- a/src/sync.h +++ b/src/sync.h @@ -257,6 +257,8 @@ #define LEAVE_CRITICAL_SECTION(cs) \ { \ + std::string lockname; \ + CheckLastCritical((void *)(&cs), lockname, #cs, __FILE__, __LINE__); \ (cs).unlock(); \ LeaveCritical(); \ } diff --git a/src/sync.cpp b/src/sync.cpp --- a/src/sync.cpp +++ b/src/sync.cpp @@ -176,24 +176,33 @@ void CheckLastCritical(void *cs, std::string &lockname, const char *guardname, const char *file, int line) { - { - LockData &lockdata = GetLockData(); - std::lock_guard lock(lockdata.dd_mutex); - - const LockStack &lock_stack = - lockdata.m_lock_stacks[std::this_thread::get_id()]; - if (!lock_stack.empty()) { - const auto &lastlock = lock_stack.back(); - if (lastlock.first == cs) { - lockname = lastlock.second.Name(); - return; - } + LockData &lockdata = GetLockData(); + std::lock_guard lock(lockdata.dd_mutex); + + const LockStack &lock_stack = + lockdata.m_lock_stacks[std::this_thread::get_id()]; + if (!lock_stack.empty()) { + const auto &lastlock = lock_stack.back(); + if (lastlock.first == cs) { + lockname = lastlock.second.Name(); + return; } } - throw std::system_error( - EPERM, std::generic_category(), - strprintf("%s:%s %s was not most recent critical section locked", file, - line, guardname)); + + LogPrintf("INCONSISTENT LOCK ORDER DETECTED\n"); + LogPrintf("Current lock order (least recent first) is:\n"); + for (const LockStackItem &i : lock_stack) { + LogPrintf(" %s\n", i.second.ToString()); + } + if (g_debug_lockorder_abort) { + tfm::format(std::cerr, + "%s:%s %s was not most recent critical section locked, " + "details in debug log.\n", + file, line, guardname); + abort(); + } + throw std::logic_error( + strprintf("%s was not most recent critical section locked", guardname)); } void LeaveCritical() { diff --git a/src/test/reverselock_tests.cpp b/src/test/reverselock_tests.cpp --- a/src/test/reverselock_tests.cpp +++ b/src/test/reverselock_tests.cpp @@ -46,13 +46,16 @@ WAIT_LOCK(mutex, lock); #ifdef DEBUG_LOCKORDER + bool prev = g_debug_lockorder_abort; + g_debug_lockorder_abort = false; + // Make sure trying to reverse lock a previous lock fails - try { - REVERSE_LOCK(lock2); - BOOST_CHECK(false); // REVERSE_LOCK(lock2) succeeded - } catch (...) { - } + BOOST_CHECK_EXCEPTION( + REVERSE_LOCK(lock2), std::logic_error, + HasReason("lock2 was not most recent critical section locked")); BOOST_CHECK(lock2.owns_lock()); + + g_debug_lockorder_abort = prev; #endif // Make sure trying to reverse lock an unlocked lock fails diff --git a/src/test/sync_tests.cpp b/src/test/sync_tests.cpp --- a/src/test/sync_tests.cpp +++ b/src/test/sync_tests.cpp @@ -28,6 +28,21 @@ BOOST_CHECK(!error_thrown); #endif } + +template +void TestInconsistentLockOrderDetected(MutexType &mutex1, MutexType &mutex2) + NO_THREAD_SAFETY_ANALYSIS { + ENTER_CRITICAL_SECTION(mutex1); + ENTER_CRITICAL_SECTION(mutex2); +#ifdef DEBUG_LOCKORDER + BOOST_CHECK_EXCEPTION( + LEAVE_CRITICAL_SECTION(mutex1), std::logic_error, + HasReason("mutex1 was not most recent critical section locked")); +#endif // DEBUG_LOCKORDER + LEAVE_CRITICAL_SECTION(mutex2); + LEAVE_CRITICAL_SECTION(mutex1); + BOOST_CHECK(LockStackEmpty()); +} } // namespace BOOST_FIXTURE_TEST_SUITE(sync_tests, BasicTestingSetup) @@ -55,4 +70,29 @@ #endif } +BOOST_AUTO_TEST_CASE(inconsistent_lock_order_detected) { +#ifdef DEBUG_LOCKORDER + bool prev = g_debug_lockorder_abort; + g_debug_lockorder_abort = false; +#endif // DEBUG_LOCKORDER + + RecursiveMutex rmutex1, rmutex2; + TestInconsistentLockOrderDetected(rmutex1, rmutex2); + // By checking lock order consistency (CheckLastCritical) before any + // unlocking (LeaveCritical) the lock tracking data must not have been + // broken by exception. + TestInconsistentLockOrderDetected(rmutex1, rmutex2); + + Mutex mutex1, mutex2; + TestInconsistentLockOrderDetected(mutex1, mutex2); + // By checking lock order consistency (CheckLastCritical) before any + // unlocking (LeaveCritical) the lock tracking data must not have been + // broken by exception. + TestInconsistentLockOrderDetected(mutex1, mutex2); + +#ifdef DEBUG_LOCKORDER + g_debug_lockorder_abort = prev; +#endif // DEBUG_LOCKORDER +} + BOOST_AUTO_TEST_SUITE_END() diff --git a/src/wallet/test/wallet_tests.cpp b/src/wallet/test/wallet_tests.cpp --- a/src/wallet/test/wallet_tests.cpp +++ b/src/wallet/test/wallet_tests.cpp @@ -29,6 +29,8 @@ #include #include +extern RecursiveMutex cs_wallets; + BOOST_FIXTURE_TEST_SUITE(wallet_tests, WalletTestingSetup) static std::shared_ptr TestLoadWallet(interfaces::Chain &chain) { @@ -830,7 +832,8 @@ addtx_count = 0; auto handler = HandleLoadWallet( [&](std::unique_ptr wallet_param) - EXCLUSIVE_LOCKS_REQUIRED(wallet_param->wallet()->cs_wallet) { + EXCLUSIVE_LOCKS_REQUIRED(wallet_param->wallet()->cs_wallet, + cs_wallets) { BOOST_CHECK(rescan_completed); m_coinbase_txns.push_back( CreateAndProcessBlock( @@ -850,9 +853,11 @@ BOOST_CHECK(chain->broadcastTransaction( GetConfig(), MakeTransactionRef(mempool_tx), DEFAULT_TRANSACTION_MAXFEE, false, error)); + LEAVE_CRITICAL_SECTION(cs_wallets); LEAVE_CRITICAL_SECTION(wallet_param->wallet()->cs_wallet); SyncWithValidationInterfaceQueue(); ENTER_CRITICAL_SECTION(wallet_param->wallet()->cs_wallet); + ENTER_CRITICAL_SECTION(cs_wallets); }); wallet = TestLoadWallet(*chain); BOOST_CHECK_EQUAL(addtx_count, 4); diff --git a/src/wallet/wallet.cpp b/src/wallet/wallet.cpp --- a/src/wallet/wallet.cpp +++ b/src/wallet/wallet.cpp @@ -45,7 +45,7 @@ "be considered unused, even if the opposite is the case."}, }; -static RecursiveMutex cs_wallets; +RecursiveMutex cs_wallets; static std::vector> vpwallets GUARDED_BY(cs_wallets); static std::list g_load_wallet_fns GUARDED_BY(cs_wallets); diff --git a/test/sanitizer_suppressions/tsan b/test/sanitizer_suppressions/tsan --- a/test/sanitizer_suppressions/tsan +++ b/test/sanitizer_suppressions/tsan @@ -35,7 +35,6 @@ deadlock:CConnman::GetNodeStats deadlock:CChainState::ConnectTip deadlock:UpdateTip -deadlock:wallet_tests::CreateWallet # Lock order inversion due to the large cs_main lock from Shutdown, which comes # before the cs_proofrequest lock