diff options
Diffstat (limited to 'src')
| -rw-r--r-- | src/logging.cpp | 1 | ||||
| -rw-r--r-- | src/logging.h | 1 | ||||
| -rw-r--r-- | src/logging/timer.h | 12 | ||||
| -rw-r--r-- | src/sync.cpp | 11 | ||||
| -rw-r--r-- | src/sync.h | 19 | ||||
| -rw-r--r-- | src/test/logging_tests.cpp | 2 |
6 files changed, 21 insertions, 25 deletions
diff --git a/src/logging.cpp b/src/logging.cpp index b456108b61..eb2c750296 100644 --- a/src/logging.cpp +++ b/src/logging.cpp @@ -159,6 +159,7 @@ const CLogCategoryDesc LogCategories[] = {BCLog::VALIDATION, "validation"}, {BCLog::I2P, "i2p"}, {BCLog::IPC, "ipc"}, + {BCLog::LOCK, "lock"}, {BCLog::ALL, "1"}, {BCLog::ALL, "all"}, }; diff --git a/src/logging.h b/src/logging.h index 38d73863e7..53a89d28bd 100644 --- a/src/logging.h +++ b/src/logging.h @@ -59,6 +59,7 @@ namespace BCLog { VALIDATION = (1 << 21), I2P = (1 << 22), IPC = (1 << 23), + LOCK = (1 << 24), ALL = ~(uint32_t)0, }; diff --git a/src/logging/timer.h b/src/logging/timer.h index 159920e397..647e3fa30e 100644 --- a/src/logging/timer.h +++ b/src/logging/timer.h @@ -58,12 +58,14 @@ public: return strprintf("%s: %s", m_prefix, msg); } - std::string units = ""; + if (std::is_same<TimeType, std::chrono::microseconds>::value) { + return strprintf("%s: %s (%iμs)", m_prefix, msg, end_time.count()); + } + + std::string units; float divisor = 1; - if (std::is_same<TimeType, std::chrono::microseconds>::value) { - units = "μs"; - } else if (std::is_same<TimeType, std::chrono::milliseconds>::value) { + if (std::is_same<TimeType, std::chrono::milliseconds>::value) { units = "ms"; divisor = 1000.; } else if (std::is_same<TimeType, std::chrono::seconds>::value) { @@ -93,6 +95,8 @@ private: } // namespace BCLog +#define LOG_TIME_MICROS_WITH_CATEGORY(end_msg, log_category) \ + BCLog::Timer<std::chrono::microseconds> PASTE2(logging_timer, __COUNTER__)(__func__, end_msg, log_category) #define LOG_TIME_MILLIS_WITH_CATEGORY(end_msg, log_category) \ BCLog::Timer<std::chrono::milliseconds> PASTE2(logging_timer, __COUNTER__)(__func__, end_msg, log_category) #define LOG_TIME_SECONDS(end_msg) \ diff --git a/src/sync.cpp b/src/sync.cpp index a2b62c2286..eace86d9dd 100644 --- a/src/sync.cpp +++ b/src/sync.cpp @@ -9,6 +9,7 @@ #include <sync.h> #include <logging.h> +#include <logging/timer.h> #include <tinyformat.h> #include <util/strencodings.h> #include <util/threadnames.h> @@ -23,16 +24,10 @@ #include <utility> #include <vector> -#ifdef DEBUG_LOCKCONTENTION -#if !defined(HAVE_THREAD_LOCAL) -static_assert(false, "thread_local is not supported"); -#endif -void PrintLockContention(const char* pszName, const char* pszFile, int nLine) +void LockContention(const char* pszName, const char* pszFile, int nLine) { - LogPrintf("LOCKCONTENTION: %s\n", pszName); - LogPrintf("Locker: %s:%d\n", pszFile, nLine); + LOG_TIME_MICROS_WITH_CATEGORY(strprintf("%s, %s:%d", pszName, pszFile, nLine), BCLog::LOCK); } -#endif /* DEBUG_LOCKCONTENTION */ #ifdef DEBUG_LOCKORDER // diff --git a/src/sync.h b/src/sync.h index 146c228592..bf15c0b4eb 100644 --- a/src/sync.h +++ b/src/sync.h @@ -126,9 +126,8 @@ using RecursiveMutex = AnnotatedMixin<std::recursive_mutex>; /** Wrapped mutex: supports waiting but not recursive locking */ typedef AnnotatedMixin<std::mutex> Mutex; -#ifdef DEBUG_LOCKCONTENTION -void PrintLockContention(const char* pszName, const char* pszFile, int nLine); -#endif +/** Prints a lock contention to the log */ +void LockContention(const char* pszName, const char* pszFile, int nLine); /** Wrapper around std::unique_lock style lock for Mutex. */ template <typename Mutex, typename Base = typename Mutex::UniqueLock> @@ -138,22 +137,18 @@ private: void Enter(const char* pszName, const char* pszFile, int nLine) { EnterCritical(pszName, pszFile, nLine, Base::mutex()); -#ifdef DEBUG_LOCKCONTENTION - if (!Base::try_lock()) { - PrintLockContention(pszName, pszFile, nLine); -#endif - Base::lock(); -#ifdef DEBUG_LOCKCONTENTION - } -#endif + if (Base::try_lock()) return; + LockContention(pszName, pszFile, nLine); // log the contention + Base::lock(); } bool TryEnter(const char* pszName, const char* pszFile, int nLine) { EnterCritical(pszName, pszFile, nLine, Base::mutex(), true); Base::try_lock(); - if (!Base::owns_lock()) + if (!Base::owns_lock()) { LeaveCritical(); + } return Base::owns_lock(); } diff --git a/src/test/logging_tests.cpp b/src/test/logging_tests.cpp index e99c6e0fc8..e2e31c62d7 100644 --- a/src/test/logging_tests.cpp +++ b/src/test/logging_tests.cpp @@ -27,7 +27,7 @@ BOOST_AUTO_TEST_CASE(logging_timer) SetMockTime(1); auto micro_timer = BCLog::Timer<std::chrono::microseconds>("tests", "end_msg"); SetMockTime(2); - BOOST_CHECK_EQUAL(micro_timer.LogMsg("test micros"), "tests: test micros (1000000.00μs)"); + BOOST_CHECK_EQUAL(micro_timer.LogMsg("test micros"), "tests: test micros (1000000μs)"); } BOOST_AUTO_TEST_SUITE_END() |