From 6374e24887e3957cfcf17841a8c48cac2ffbda4f Mon Sep 17 00:00:00 2001 From: Jon Atack Date: Fri, 1 Apr 2022 12:23:01 +0200 Subject: [PATCH 1/3] Put lock logging behind DEBUG_LOCKCONTENTION preprocessor directive Github-Pull: #24770 Rebased-From: 39a34b6877945908759f6a2322f60852e521e2ee --- src/logging.cpp | 2 ++ src/logging.h | 2 ++ src/net.h | 2 ++ src/sync.h | 5 +++++ src/test/checkqueue_tests.cpp | 10 +++++++--- test/functional/rpc_misc.py | 3 --- 6 files changed, 18 insertions(+), 6 deletions(-) diff --git a/src/logging.cpp b/src/logging.cpp index 764941c8ea5..a5e5fdb4cd2 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::UTIL, "util"}, {BCLog::BLOCKSTORE, "blockstorage"}, {BCLog::ALL, "1"}, diff --git a/src/logging.h b/src/logging.h index 710e6c4c322..ae8cad906c9 100644 --- a/src/logging.h +++ b/src/logging.h @@ -60,7 +60,9 @@ namespace BCLog { VALIDATION = (1 << 21), I2P = (1 << 22), IPC = (1 << 23), +#ifdef DEBUG_LOCKCONTENTION LOCK = (1 << 24), +#endif UTIL = (1 << 25), BLOCKSTORE = (1 << 26), ALL = ~(uint32_t)0, diff --git a/src/net.h b/src/net.h index a38310938b3..2e0a45b874a 100644 --- a/src/net.h +++ b/src/net.h @@ -13,6 +13,7 @@ #include #include #include +#include #include #include #include @@ -32,6 +33,7 @@ #include #include #include +#include #include #include #include diff --git a/src/sync.h b/src/sync.h index 85000a9151b..af7595e6fab 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 @@ -136,8 +139,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 153ccd984b6..0d95bd76706 100644 --- a/src/test/checkqueue_tests.cpp +++ b/src/test/checkqueue_tests.cpp @@ -19,13 +19,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 2f1796d7cc0..f64aae72234 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()), 27) - # Test toggling a logging category on/off/on with the logging RPC. assert_equal(node.logging()['qt'], True) node.logging(exclude=['qt']) From 69cc83df69e5a9306a0090df0dade38d5383af4d Mon Sep 17 00:00:00 2001 From: Jon Atack Date: Mon, 4 Apr 2022 11:42:27 +0200 Subject: [PATCH 2/3] Add DEBUG_LOCKCONTENTION documentation to the developer notes Github-Pull: #24770 Rebassedd-From: 43947333315d07f59e1247bd76e0ba9d35a99e31 --- doc/developer-notes.md | 14 ++++++++++++++ 1 file changed, 14 insertions(+) diff --git a/doc/developer-notes.md b/doc/developer-notes.md index bfb64093e19..5bb927c44e3 100644 --- a/doc/developer-notes.md +++ b/doc/developer-notes.md @@ -17,6 +17,7 @@ Developer Notes - [`debug.log`](#debuglog) - [Signet, testnet, and regtest modes](#signet-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) @@ -316,6 +317,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 bitcoind. + +You can then use the `-debug=lock` configuration option at bitcoind startup or +`bitcoin-cli logging '["lock"]'` at runtime to turn on lock contention logging. +It can be toggled off again with `bitcoin-cli logging [] '["lock"]'`. + ### Assertions and Checks The util file `src/util/check.h` offers helpers to protect against coding and From e3e4be9cd513c85311634a8128e018dbf8748888 Mon Sep 17 00:00:00 2001 From: Luke Dashjr Date: Wed, 9 Feb 2022 01:10:39 +0000 Subject: [PATCH 3/3] RPC: Switch getblockfrompeer back to standard param name blockhash This commit partially reverts 923312fbf6a89efde1739da0b7209694d4f892ba. Github-Pull: #24806 Rebased-From: 88917f93cc01b5e881072b0e476b74d20b7673c4 --- src/rpc/blockchain.cpp | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/src/rpc/blockchain.cpp b/src/rpc/blockchain.cpp index ef572cf8f84..c066f6f569f 100644 --- a/src/rpc/blockchain.cpp +++ b/src/rpc/blockchain.cpp @@ -795,7 +795,7 @@ static RPCHelpMan getblockfrompeer() "Subsequent calls for the same block and a new peer will cause the response from the previous peer to be ignored.\n\n" "Returns an empty JSON object if the request was successfully scheduled.", { - {"block_hash", RPCArg::Type::STR_HEX, RPCArg::Optional::NO, "The block hash to try to fetch"}, + {"blockhash", RPCArg::Type::STR_HEX, RPCArg::Optional::NO, "The block hash to try to fetch"}, {"peer_id", RPCArg::Type::NUM, RPCArg::Optional::NO, "The peer to fetch it from (see getpeerinfo for peer IDs)"}, }, RPCResult{RPCResult::Type::OBJ, "", /*optional=*/false, "", {}}, @@ -809,7 +809,7 @@ static RPCHelpMan getblockfrompeer() ChainstateManager& chainman = EnsureChainman(node); PeerManager& peerman = EnsurePeerman(node); - const uint256& block_hash{ParseHashV(request.params[0], "block_hash")}; + const uint256& block_hash{ParseHashV(request.params[0], "blockhash")}; const NodeId peer_id{request.params[1].get_int64()}; const CBlockIndex* const index = WITH_LOCK(cs_main, return chainman.m_blockman.LookupBlockIndex(block_hash););