aboutsummaryrefslogtreecommitdiff
diff options
context:
space:
mode:
authorWladimir J. van der Laan <laanwj@protonmail.com>2020-07-15 20:46:47 +0200
committerWladimir J. van der Laan <laanwj@protonmail.com>2020-07-15 20:53:40 +0200
commit31bdd86631dd95e45b82c036c907ae8007c8a682 (patch)
tree9ba21e3b465bf75ef15f1726b0fd7cdf9bd3a444
parent804ca266291279705384d384585714309274aa76 (diff)
parent0ecff9dd3418e8c18fa423ba53e9cab1df8be553 (diff)
downloadbitcoin-31bdd86631dd95e45b82c036c907ae8007c8a682.tar.xz
Merge #19353: Fix mistakenly swapped "previous" and "current" lock orders
0ecff9dd3418e8c18fa423ba53e9cab1df8be553 Improve "detected inconsistent lock order" error message (Hennadii Stepanov) bbe9cf4fe4ff9a8d1ea557fb763c76100db07679 test: Improve "potential deadlock detected" exception message (Hennadii Stepanov) 35599344c886b62f198e35fd940c1ab15c4a9f90 Fix mistakenly swapped "previous" and "current" lock orders (Hennadii Stepanov) Pull request description: In master (8ef15e8a86038225afef2487ca23abc10ca5dffa) the "previous" and "current" lock orders are mistakenly swapped. This PR: - fixes printed lock orders - improves the `sync_tests` unit test - makes the "detected inconsistent lock order" error message pointing to the lock location rather `tfm::format()` location. Debugger output example with this PR (with modified code, of course): ``` 2020-06-22T15:46:56Z [msghand] POTENTIAL DEADLOCK DETECTED 2020-06-22T15:46:56Z [msghand] Previous lock order was: 2020-06-22T15:46:56Z [msghand] (2) 'cs_main' in net_processing.cpp:2545 (in thread 'msghand') 2020-06-22T15:46:56Z [msghand] (1) 'g_cs_orphans' in net_processing.cpp:1400 (in thread 'msghand') 2020-06-22T15:46:56Z [msghand] Current lock order is: 2020-06-22T15:46:56Z [msghand] (1) 'g_cs_orphans' in net_processing.cpp:2816 (in thread 'msghand') 2020-06-22T15:46:56Z [msghand] (2) 'cs_main' in net_processing.cpp:2816 (in thread 'msghand') Assertion failed: detected inconsistent lock order for 'cs_main' in net_processing.cpp:2816 (in thread 'msghand'), details in debug log. Process 131393 stopped * thread #15, name = 'b-msghand', stop reason = signal SIGABRT frame #0: 0x00007ffff775c18b libc.so.6`__GI_raise(sig=2) at raise.c:51:1 (lldb) bt * thread #15, name = 'b-msghand', stop reason = signal SIGABRT * frame #0: 0x00007ffff775c18b libc.so.6`__GI_raise(sig=2) at raise.c:51:1 frame #1: 0x00007ffff773b859 libc.so.6`__GI_abort at abort.c:79:7 frame #2: 0x0000555555e5b196 bitcoind`(anonymous namespace)::potential_deadlock_detected(mismatch=0x00007fff99ff6f30, s1=size=2, s2=size=2, lock_location=0x00007fff99ff7010) at sync.cpp:134:9 frame #3: 0x0000555555e5a1b1 bitcoind`(anonymous namespace)::push_lock(c=0x0000555556379220, locklocation=0x00007fff99ff7010) at sync.cpp:158:13 frame #4: 0x0000555555e59e8a bitcoind`EnterCritical(pszName="cs_main", pszFile="net_processing.cpp", nLine=2816, cs=0x0000555556379220, fTry=false) at sync.cpp:177:5 frame #5: 0x00005555555b0500 bitcoind`UniqueLock<AnnotatedMixin<std::recursive_mutex>, std::unique_lock<std::recursive_mutex> >::Enter(this=0x00007fff99ff8c20, pszName="cs_main", pszFile="net_processing.cpp", nLine=2816) at sync.h:134:9 frame #6: 0x00005555555b017f bitcoind`UniqueLock<AnnotatedMixin<std::recursive_mutex>, std::unique_lock<std::recursive_mutex> >::UniqueLock(this=0x00007fff99ff8c20, mutexIn=0x0000555556379220, pszName="cs_main", pszFile="net_processing.cpp", nLine=2816, fTry=false) at sync.h:160:13 frame #7: 0x00005555556aa57e bitcoind`ProcessMessage(pfrom=0x00007fff90001180, msg_type=error: summary string parsing error, vRecv=0x00007fff9c005ac0, nTimeReceived=1592840815980751, chainparams=0x00005555564b7110, chainman=0x0000555556380880, mempool=0x0000555556380ae0, connman=0x000055555657aa20, banman=0x00005555565167b0, interruptMsgProc=0x00005555565cae90) at net_processing.cpp:2816:9 ``` ACKs for top commit: laanwj: ACK 0ecff9dd3418e8c18fa423ba53e9cab1df8be553 vasild: ACK 0ecff9dd Tree-SHA512: ff285de8dd3198b5b33c4bfbdadf9b1448189c96143b9696bc4f41c07e784c00851ec169cf3ed45cc325f3617ba6783620803234f57fcce28bf6bc3d6a7234fb
-rw-r--r--src/sync.cpp14
-rw-r--r--src/test/sync_tests.cpp2
2 files changed, 10 insertions, 6 deletions
diff --git a/src/sync.cpp b/src/sync.cpp
index 9abdedbed4..10f0483189 100644
--- a/src/sync.cpp
+++ b/src/sync.cpp
@@ -60,7 +60,7 @@ struct CLockLocation {
std::string ToString() const
{
return strprintf(
- "%s %s:%s%s (in thread %s)",
+ "'%s' in %s:%s%s (in thread '%s')",
mutexName, sourceFile, sourceLine, (fTry ? " (TRY)" : ""), m_thread_name);
}
@@ -105,7 +105,7 @@ static void potential_deadlock_detected(const LockPair& mismatch, const LockStac
{
LogPrintf("POTENTIAL DEADLOCK DETECTED\n");
LogPrintf("Previous lock order was:\n");
- for (const LockStackItem& i : s2) {
+ for (const LockStackItem& i : s1) {
if (i.first == mismatch.first) {
LogPrintf(" (1)"); /* Continued */
}
@@ -114,21 +114,25 @@ static void potential_deadlock_detected(const LockPair& mismatch, const LockStac
}
LogPrintf(" %s\n", i.second.ToString());
}
+
+ std::string mutex_a, mutex_b;
LogPrintf("Current lock order is:\n");
- for (const LockStackItem& i : s1) {
+ for (const LockStackItem& i : s2) {
if (i.first == mismatch.first) {
LogPrintf(" (1)"); /* Continued */
+ mutex_a = i.second.Name();
}
if (i.first == mismatch.second) {
LogPrintf(" (2)"); /* Continued */
+ mutex_b = i.second.Name();
}
LogPrintf(" %s\n", i.second.ToString());
}
if (g_debug_lockorder_abort) {
- tfm::format(std::cerr, "Assertion failed: detected inconsistent lock order at %s:%i, details in debug log.\n", __FILE__, __LINE__);
+ tfm::format(std::cerr, "Assertion failed: detected inconsistent lock order for %s, details in debug log.\n", s2.back().second.ToString());
abort();
}
- throw std::logic_error("potential deadlock detected");
+ throw std::logic_error(strprintf("potential deadlock detected: %s -> %s -> %s", mutex_b, mutex_a, mutex_b));
}
static void push_lock(void* c, const CLockLocation& locklocation)
diff --git a/src/test/sync_tests.cpp b/src/test/sync_tests.cpp
index 5c6c2ee38e..3ea8714f3a 100644
--- a/src/test/sync_tests.cpp
+++ b/src/test/sync_tests.cpp
@@ -18,7 +18,7 @@ void TestPotentialDeadLockDetected(MutexType& mutex1, MutexType& mutex2)
try {
LOCK2(mutex2, mutex1);
} catch (const std::logic_error& e) {
- BOOST_CHECK_EQUAL(e.what(), "potential deadlock detected");
+ BOOST_CHECK_EQUAL(e.what(), "potential deadlock detected: mutex1 -> mutex2 -> mutex1");
error_thrown = true;
}
#ifdef DEBUG_LOCKORDER