diff --git a/doc/developer-notes.md b/doc/developer-notes.md index 5d81f32d21..f4a7095392 100644 --- a/doc/developer-notes.md +++ b/doc/developer-notes.md @@ -17,6 +17,7 @@ Developer Notes - [`debug.log`](#debuglog) - [Testnet and Regtest modes](#testnet-and-regtest-modes) - [DEBUG_LOCKORDER](#debug_lockorder) + - [DEBUG_LOCKCONTENTION](#debug_lockcontention) - [Valgrind suppressions file](#valgrind-suppressions-file) - [Compiling for test coverage](#compiling-for-test-coverage) - [Performance profiling with perf](#performance-profiling-with-perf) @@ -412,6 +413,19 @@ configure option adds `-DDEBUG_LOCKORDER` to the compiler flags. This inserts run-time checks to keep track of which locks are held and adds warnings to the `debug.log` file if inconsistencies are detected. +### DEBUG_LOCKCONTENTION + +Defining `DEBUG_LOCKCONTENTION` adds a "lock" logging category to the logging +RPC that, when enabled, logs the location and duration of each lock contention +to the `debug.log` file. + +To enable it, run configure with `-DDEBUG_LOCKCONTENTION` added to your +CPPFLAGS, e.g. `CPPFLAGS="-DDEBUG_LOCKCONTENTION"`, then build and run dashd. + +You can then use the `-debug=lock` configuration option at dashd startup or +`dash-cli logging '["lock"]'` at runtime to turn on lock contention logging. +It can be toggled off again with `dash-cli logging [] '["lock"]'`. + ### Assertions and Checks The util file `src/util/check.h` offers helpers to protect against coding and diff --git a/src/evo/creditpool.h b/src/evo/creditpool.h index 5da980df65..4d4169974d 100644 --- a/src/evo/creditpool.h +++ b/src/evo/creditpool.h @@ -10,6 +10,7 @@ #include #include #include +#include #include #include diff --git a/src/llmq/quorums.h b/src/llmq/quorums.h index fac31afb02..415b4c60fd 100644 --- a/src/llmq/quorums.h +++ b/src/llmq/quorums.h @@ -15,6 +15,7 @@ #include #include #include +#include #include #include diff --git a/src/logging.cpp b/src/logging.cpp index ddb6c57fbd..5ac21e344b 100644 --- a/src/logging.cpp +++ b/src/logging.cpp @@ -160,7 +160,9 @@ const CLogCategoryDesc LogCategories[] = {BCLog::VALIDATION, "validation"}, {BCLog::I2P, "i2p"}, {BCLog::IPC, "ipc"}, +#ifdef DEBUG_LOCKCONTENTION {BCLog::LOCK, "lock"}, +#endif {BCLog::BLOCKSTORE, "blockstorage"}, {BCLog::TXRECONCILIATION, "txreconciliation"}, {BCLog::ALL, "1"}, diff --git a/src/logging.h b/src/logging.h index b12a22cb63..c88bae4957 100644 --- a/src/logging.h +++ b/src/logging.h @@ -61,7 +61,9 @@ namespace BCLog { VALIDATION = (1 << 21), I2P = (1 << 22), IPC = (1 << 23), +#ifdef DEBUG_LOCKCONTENTION LOCK = (1 << 24), +#endif BLOCKSTORE = (1 << 26), TXRECONCILIATION = (1 << 27), diff --git a/src/net.h b/src/net.h index 89ea78a4b9..3ac5523e21 100644 --- a/src/net.h +++ b/src/net.h @@ -16,6 +16,7 @@ #include #include #include +#include #include #include #include @@ -42,6 +43,7 @@ #include #include #include +#include #include #include #include diff --git a/src/stats/rawsender.cpp b/src/stats/rawsender.cpp index eb423e37d5..8b56875f2f 100644 --- a/src/stats/rawsender.cpp +++ b/src/stats/rawsender.cpp @@ -5,6 +5,7 @@ #include +#include #include #include #include diff --git a/src/sync.h b/src/sync.h index 7206ac387a..dfe5846d7c 100644 --- a/src/sync.h +++ b/src/sync.h @@ -6,8 +6,11 @@ #ifndef BITCOIN_SYNC_H #define BITCOIN_SYNC_H +#ifdef DEBUG_LOCKCONTENTION #include #include +#endif + #include #include @@ -161,8 +164,10 @@ private: void Enter(const char* pszName, const char* pszFile, int nLine) { EnterCritical(pszName, pszFile, nLine, Base::mutex()); +#ifdef DEBUG_LOCKCONTENTION if (Base::try_lock()) return; LOG_TIME_MICROS_WITH_CATEGORY(strprintf("lock contention %s, %s:%d", pszName, pszFile, nLine), BCLog::LOCK); +#endif Base::lock(); } diff --git a/src/test/checkqueue_tests.cpp b/src/test/checkqueue_tests.cpp index d0e5404057..b7ccc71cdc 100644 --- a/src/test/checkqueue_tests.cpp +++ b/src/test/checkqueue_tests.cpp @@ -18,13 +18,17 @@ #include /** - * Identical to TestingSetup but excludes lock contention logging, as some of - * these tests are designed to be heavily contested to trigger race conditions - * or other issues. + * Identical to TestingSetup but excludes lock contention logging if + * `DEBUG_LOCKCONTENTION` is defined, as some of these tests are designed to be + * heavily contested to trigger race conditions or other issues. */ struct NoLockLoggingTestingSetup : public TestingSetup { NoLockLoggingTestingSetup() +#ifdef DEBUG_LOCKCONTENTION : TestingSetup{CBaseChainParams::MAIN, /*extra_args=*/{"-debugexclude=lock"}} {} +#else + : TestingSetup{CBaseChainParams::MAIN} {} +#endif }; BOOST_FIXTURE_TEST_SUITE(checkqueue_tests, NoLockLoggingTestingSetup) diff --git a/test/functional/rpc_misc.py b/test/functional/rpc_misc.py index 1d141d8e1c..cd69f65ddb 100755 --- a/test/functional/rpc_misc.py +++ b/test/functional/rpc_misc.py @@ -56,9 +56,6 @@ class RpcMiscTest(BitcoinTestFramework): self.log.info("test logging rpc and help") - # Test logging RPC returns the expected number of logging categories. - assert_equal(len(node.logging()), 40) - # Test toggling a logging category on/off/on with the logging RPC. assert_equal(node.logging()['qt'], True) node.logging(exclude=['qt'])