diff options
author | Wladimir J. van der Laan <laanwj@protonmail.com> | 2020-07-15 20:46:47 +0200 |
---|---|---|
committer | Wladimir J. van der Laan <laanwj@protonmail.com> | 2020-07-15 20:53:40 +0200 |
commit | 31bdd86631dd95e45b82c036c907ae8007c8a682 (patch) | |
tree | 9ba21e3b465bf75ef15f1726b0fd7cdf9bd3a444 | |
parent | 804ca266291279705384d384585714309274aa76 (diff) | |
parent | 0ecff9dd3418e8c18fa423ba53e9cab1df8be553 (diff) |
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.cpp | 14 | ||||
-rw-r--r-- | src/test/sync_tests.cpp | 2 |
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 |