Skip to content

Commit 736eb4d

Browse files
fanquakefanquake
committed
Merge #19982: test: Fix inconsistent lock order in wallet_tests/CreateWallet
e1e68b6 test: Fix inconsistent lock order in wallet_tests/CreateWallet (Hennadii Stepanov) cb23fe0 [skip ci] sync: Check precondition in LEAVE_CRITICAL_SECTION() macro (Hennadii Stepanov) c5e3e74 sync: Improve CheckLastCritical() (Hennadii Stepanov) Pull request description: This PR: - fixes #19049 that was caused by #16426 - removes `wallet_tests::CreateWallet` suppression from the `test/sanitizer_suppressions/tsan` The example of the improved `CheckLastCritical()`/`LEAVE_CRITICAL_SECTION()` log (could be got when compiled without the last commit): ``` 2020-09-20T08:34:28.429485Z [test] INCONSISTENT LOCK ORDER DETECTED 2020-09-20T08:34:28.429493Z [test] Current lock order (least recent first) is: 2020-09-20T08:34:28.429501Z [test] 'walletInstance->cs_wallet' in wallet/wallet.cpp:4007 (in thread 'test') 2020-09-20T08:34:28.429508Z [test] 'cs_wallets' in wallet/wallet.cpp:4089 (in thread 'test') ``` Currently, there are other "naked" `LEAVE_CRITICAL_SECTION()` in the code base: https://github.com/bitcoin/bitcoin/blob/b99a1633b270e0e89479b2bb2ae19a8a8dc0fa05/src/rpc/mining.cpp#L698 https://github.com/bitcoin/bitcoin/blob/b99a1633b270e0e89479b2bb2ae19a8a8dc0fa05/src/checkqueue.h#L208 ACKs for top commit: MarcoFalke: review ACK e1e68b6 💂 ryanofsky: Code review ACK e1e68b6. Just trivial rebase and suggested switch to BOOST_CHECK_EXCEPTION since last review vasild: ACK e1e68b6 Tree-SHA512: a627680eac3af4b4c02772473d68322ce8d3811bf6b035d3485ccc97d35755bef933cffabd3f20b126f89e3301eccecec3f769df34415fb7c426c967b6ce36e6
2 parents da957cd + e1e68b6 commit 736eb4d

File tree

7 files changed

+75
-23
lines changed

7 files changed

+75
-23
lines changed

‎src/sync.cpp‎

Lines changed: 20 additions & 12 deletions
Original file line numberDiff line numberDiff line change
@@ -228,20 +228,28 @@ template void EnterCritical(const char*, const char*, int, boost::mutex*, bool);
228228

229229
void CheckLastCritical(void* cs, std::string& lockname, const char* guardname, const char* file, int line)
230230
{
231-
{
232-
LockData& lockdata = GetLockData();
233-
std::lock_guard<std::mutex> lock(lockdata.dd_mutex);
234-
235-
const LockStack& lock_stack = lockdata.m_lock_stacks[std::this_thread::get_id()];
236-
if (!lock_stack.empty()) {
237-
const auto& lastlock = lock_stack.back();
238-
if (lastlock.first == cs) {
239-
lockname = lastlock.second.Name();
240-
return;
241-
}
231+
LockData& lockdata = GetLockData();
232+
std::lock_guard<std::mutex> lock(lockdata.dd_mutex);
233+
234+
const LockStack& lock_stack = lockdata.m_lock_stacks[std::this_thread::get_id()];
235+
if (!lock_stack.empty()) {
236+
const auto& lastlock = lock_stack.back();
237+
if (lastlock.first == cs) {
238+
lockname = lastlock.second.Name();
239+
return;
242240
}
243241
}
244-
throw std::system_error(EPERM, std::generic_category(), strprintf("%s:%s %s was not most recent critical section locked", file, line, guardname));
242+
243+
LogPrintf("INCONSISTENT LOCK ORDER DETECTED\n");
244+
LogPrintf("Current lock order (least recent first) is:\n");
245+
for (const LockStackItem& i : lock_stack) {
246+
LogPrintf(" %s\n", i.second.ToString());
247+
}
248+
if (g_debug_lockorder_abort) {
249+
tfm::format(std::cerr, "%s:%s %s was not most recent critical section locked, details in debug log.\n", file, line, guardname);
250+
abort();
251+
}
252+
throw std::logic_error(strprintf("%s was not most recent critical section locked", guardname));
245253
}
246254

247255
void LeaveCritical()

‎src/sync.h‎

Lines changed: 6 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -242,10 +242,12 @@ using DebugLock = UniqueLock<typename std::remove_reference<typename std::remove
242242
(cs).lock(); \
243243
}
244244

245-
#define LEAVE_CRITICAL_SECTION(cs) \
246-
{ \
247-
(cs).unlock(); \
248-
LeaveCritical(); \
245+
#define LEAVE_CRITICAL_SECTION(cs) \
246+
{ \
247+
std::string lockname; \
248+
CheckLastCritical((void*)(&cs), lockname, #cs, __FILE__, __LINE__); \
249+
(cs).unlock(); \
250+
LeaveCritical(); \
249251
}
250252

251253
//! Run code while locking a mutex.

‎src/test/reverselock_tests.cpp‎

Lines changed: 6 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -48,12 +48,14 @@ BOOST_AUTO_TEST_CASE(reverselock_errors)
4848
WAIT_LOCK(mutex, lock);
4949

5050
#ifdef DEBUG_LOCKORDER
51+
bool prev = g_debug_lockorder_abort;
52+
g_debug_lockorder_abort = false;
53+
5154
// Make sure trying to reverse lock a previous lock fails
52-
try {
53-
REVERSE_LOCK(lock2);
54-
BOOST_CHECK(false); // REVERSE_LOCK(lock2) succeeded
55-
} catch(...) { }
55+
BOOST_CHECK_EXCEPTION(REVERSE_LOCK(lock2), std::logic_error, HasReason("lock2 was not most recent critical section locked"));
5656
BOOST_CHECK(lock2.owns_lock());
57+
58+
g_debug_lockorder_abort = prev;
5759
#endif
5860

5961
// Make sure trying to reverse lock an unlocked lock fails

‎src/test/sync_tests.cpp‎

Lines changed: 37 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -62,6 +62,19 @@ void TestDoubleLock(bool should_throw)
6262
g_debug_lockorder_abort = prev;
6363
}
6464
#endif /* DEBUG_LOCKORDER */
65+
66+
template <typename MutexType>
67+
void TestInconsistentLockOrderDetected(MutexType& mutex1, MutexType& mutex2) NO_THREAD_SAFETY_ANALYSIS
68+
{
69+
ENTER_CRITICAL_SECTION(mutex1);
70+
ENTER_CRITICAL_SECTION(mutex2);
71+
#ifdef DEBUG_LOCKORDER
72+
BOOST_CHECK_EXCEPTION(LEAVE_CRITICAL_SECTION(mutex1), std::logic_error, HasReason("mutex1 was not most recent critical section locked"));
73+
#endif // DEBUG_LOCKORDER
74+
LEAVE_CRITICAL_SECTION(mutex2);
75+
LEAVE_CRITICAL_SECTION(mutex1);
76+
BOOST_CHECK(LockStackEmpty());
77+
}
6578
} // namespace
6679

6780
BOOST_FIXTURE_TEST_SUITE(sync_tests, BasicTestingSetup)
@@ -108,4 +121,28 @@ BOOST_AUTO_TEST_CASE(double_lock_recursive_mutex)
108121
}
109122
#endif /* DEBUG_LOCKORDER */
110123

124+
BOOST_AUTO_TEST_CASE(inconsistent_lock_order_detected)
125+
{
126+
#ifdef DEBUG_LOCKORDER
127+
bool prev = g_debug_lockorder_abort;
128+
g_debug_lockorder_abort = false;
129+
#endif // DEBUG_LOCKORDER
130+
131+
RecursiveMutex rmutex1, rmutex2;
132+
TestInconsistentLockOrderDetected(rmutex1, rmutex2);
133+
// By checking lock order consistency (CheckLastCritical) before any unlocking (LeaveCritical)
134+
// the lock tracking data must not have been broken by exception.
135+
TestInconsistentLockOrderDetected(rmutex1, rmutex2);
136+
137+
Mutex mutex1, mutex2;
138+
TestInconsistentLockOrderDetected(mutex1, mutex2);
139+
// By checking lock order consistency (CheckLastCritical) before any unlocking (LeaveCritical)
140+
// the lock tracking data must not have been broken by exception.
141+
TestInconsistentLockOrderDetected(mutex1, mutex2);
142+
143+
#ifdef DEBUG_LOCKORDER
144+
g_debug_lockorder_abort = prev;
145+
#endif // DEBUG_LOCKORDER
146+
}
147+
111148
BOOST_AUTO_TEST_SUITE_END()

‎src/wallet/test/wallet_tests.cpp‎

Lines changed: 5 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -28,6 +28,8 @@ RPCHelpMan importmulti();
2828
RPCHelpMan dumpwallet();
2929
RPCHelpMan importwallet();
3030

31+
extern RecursiveMutex cs_wallets;
32+
3133
// Ensure that fee levels defined in the wallet are at least as high
3234
// as the default levels for node policy.
3335
static_assert(DEFAULT_TRANSACTION_MINFEE >= DEFAULT_MIN_RELAY_TX_FEE, "wallet minimum fee is smaller than default relay fee");
@@ -761,16 +763,18 @@ BOOST_FIXTURE_TEST_CASE(CreateWallet, TestChain100Setup)
761763
// deadlock during the sync and simulates a new block notification happening
762764
// as soon as possible.
763765
addtx_count = 0;
764-
auto handler = HandleLoadWallet([&](std::unique_ptr<interfaces::Wallet> wallet) EXCLUSIVE_LOCKS_REQUIRED(wallet->wallet()->cs_wallet) {
766+
auto handler = HandleLoadWallet([&](std::unique_ptr<interfaces::Wallet> wallet) EXCLUSIVE_LOCKS_REQUIRED(wallet->wallet()->cs_wallet, cs_wallets) {
765767
BOOST_CHECK(rescan_completed);
766768
m_coinbase_txns.push_back(CreateAndProcessBlock({}, GetScriptForRawPubKey(coinbaseKey.GetPubKey())).vtx[0]);
767769
block_tx = TestSimpleSpend(*m_coinbase_txns[2], 0, coinbaseKey, GetScriptForRawPubKey(key.GetPubKey()));
768770
m_coinbase_txns.push_back(CreateAndProcessBlock({block_tx}, GetScriptForRawPubKey(coinbaseKey.GetPubKey())).vtx[0]);
769771
mempool_tx = TestSimpleSpend(*m_coinbase_txns[3], 0, coinbaseKey, GetScriptForRawPubKey(key.GetPubKey()));
770772
BOOST_CHECK(m_node.chain->broadcastTransaction(MakeTransactionRef(mempool_tx), DEFAULT_TRANSACTION_MAXFEE, false, error));
773+
LEAVE_CRITICAL_SECTION(cs_wallets);
771774
LEAVE_CRITICAL_SECTION(wallet->wallet()->cs_wallet);
772775
SyncWithValidationInterfaceQueue();
773776
ENTER_CRITICAL_SECTION(wallet->wallet()->cs_wallet);
777+
ENTER_CRITICAL_SECTION(cs_wallets);
774778
});
775779
wallet = TestLoadWallet(*m_node.chain);
776780
BOOST_CHECK_EQUAL(addtx_count, 4);

‎src/wallet/wallet.cpp‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -52,7 +52,7 @@ const std::map<uint64_t,std::string> WALLET_FLAG_CAVEATS{
5252

5353
static const size_t OUTPUT_GROUP_MAX_ENTRIES = 10;
5454

55-
static RecursiveMutex cs_wallets;
55+
RecursiveMutex cs_wallets;
5656
static std::vector<std::shared_ptr<CWallet>> vpwallets GUARDED_BY(cs_wallets);
5757
static std::list<LoadWalletFn> g_load_wallet_fns GUARDED_BY(cs_wallets);
5858

‎test/sanitizer_suppressions/tsan‎

Lines changed: 0 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -32,7 +32,6 @@ deadlock:CConnman::ForNode
3232
deadlock:CConnman::GetNodeStats
3333
deadlock:CChainState::ConnectTip
3434
deadlock:UpdateTip
35-
deadlock:wallet_tests::CreateWallet
3635

3736
# WalletBatch (unidentified deadlock)
3837
deadlock:WalletBatch

0 commit comments

Comments
 (0)