sync: Improve CheckLastCritical()

hebasto · hebasto · commit c5e3e74f70c2 · 2020-12-10T20:46:29.000+02:00
This commit adds actual lock stack logging if check fails.
diff --git a/src/sync.cpp b/src/sync.cpp
@@ -228,20 +228,28 @@ template void EnterCritical(const char*, const char*, int, boost::mutex*, bool);
 
 void CheckLastCritical(void* cs, std::string& lockname, const char* guardname, const char* file, int line)
 {
-    {
-        LockData& lockdata = GetLockData();
-        std::lock_guard<std::mutex> 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<std::mutex> 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
@@ -48,12 +48,14 @@ BOOST_AUTO_TEST_CASE(reverselock_errors)
     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
