Merge bitcoin/bitcoin#24807: [23.x] Final rc4 backports

e3e4be9cd5 RPC: Switch getblockfrompeer back to standard param name blockhash (Luke Dashjr)
69cc83df69 Add DEBUG_LOCKCONTENTION documentation to the developer notes (Jon Atack)
6374e24887 Put lock logging behind DEBUG_LOCKCONTENTION preprocessor directive (Jon Atack)

Pull request description:

  Backports:
  * #24770
  * #24806

ACKs for top commit:
  laanwj:
    Commit list and code review ACK e3e4be9cd5
  jonatack:
    Code review and commit metadata ACK e3e4be9cd5

Tree-SHA512: eff2b506379a9396b12b42ed2858e3eb9403a55950d6dec0b5dcc95c4c2998cddf9e0ec88af2f8ac5a7bece4d4537acede1c75f59bbc6616bee273384f87f6b0
This commit is contained in:
laanwj 2022-04-08 15:51:40 +02:00
commit 308a2022c0
No known key found for this signature in database
GPG key ID: 1E4AED62986CD25D
8 changed files with 34 additions and 8 deletions

View file

@ -17,6 +17,7 @@ Developer Notes
- [`debug.log`](#debuglog) - [`debug.log`](#debuglog)
- [Signet, testnet, and regtest modes](#signet-testnet-and-regtest-modes) - [Signet, testnet, and regtest modes](#signet-testnet-and-regtest-modes)
- [DEBUG_LOCKORDER](#debug_lockorder) - [DEBUG_LOCKORDER](#debug_lockorder)
- [DEBUG_LOCKCONTENTION](#debug_lockcontention)
- [Valgrind suppressions file](#valgrind-suppressions-file) - [Valgrind suppressions file](#valgrind-suppressions-file)
- [Compiling for test coverage](#compiling-for-test-coverage) - [Compiling for test coverage](#compiling-for-test-coverage)
- [Performance profiling with perf](#performance-profiling-with-perf) - [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 run-time checks to keep track of which locks are held and adds warnings to the
`debug.log` file if inconsistencies are detected. `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 ### Assertions and Checks
The util file `src/util/check.h` offers helpers to protect against coding and The util file `src/util/check.h` offers helpers to protect against coding and

View file

@ -160,7 +160,9 @@ const CLogCategoryDesc LogCategories[] =
{BCLog::VALIDATION, "validation"}, {BCLog::VALIDATION, "validation"},
{BCLog::I2P, "i2p"}, {BCLog::I2P, "i2p"},
{BCLog::IPC, "ipc"}, {BCLog::IPC, "ipc"},
#ifdef DEBUG_LOCKCONTENTION
{BCLog::LOCK, "lock"}, {BCLog::LOCK, "lock"},
#endif
{BCLog::UTIL, "util"}, {BCLog::UTIL, "util"},
{BCLog::BLOCKSTORE, "blockstorage"}, {BCLog::BLOCKSTORE, "blockstorage"},
{BCLog::ALL, "1"}, {BCLog::ALL, "1"},

View file

@ -60,7 +60,9 @@ namespace BCLog {
VALIDATION = (1 << 21), VALIDATION = (1 << 21),
I2P = (1 << 22), I2P = (1 << 22),
IPC = (1 << 23), IPC = (1 << 23),
#ifdef DEBUG_LOCKCONTENTION
LOCK = (1 << 24), LOCK = (1 << 24),
#endif
UTIL = (1 << 25), UTIL = (1 << 25),
BLOCKSTORE = (1 << 26), BLOCKSTORE = (1 << 26),
ALL = ~(uint32_t)0, ALL = ~(uint32_t)0,

View file

@ -13,6 +13,7 @@
#include <crypto/siphash.h> #include <crypto/siphash.h>
#include <hash.h> #include <hash.h>
#include <i2p.h> #include <i2p.h>
#include <logging.h>
#include <net_permissions.h> #include <net_permissions.h>
#include <netaddress.h> #include <netaddress.h>
#include <netbase.h> #include <netbase.h>
@ -32,6 +33,7 @@
#include <cstdint> #include <cstdint>
#include <deque> #include <deque>
#include <functional> #include <functional>
#include <list>
#include <map> #include <map>
#include <memory> #include <memory>
#include <optional> #include <optional>

View file

@ -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" "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.", "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)"}, {"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, "", {}}, RPCResult{RPCResult::Type::OBJ, "", /*optional=*/false, "", {}},
@ -809,7 +809,7 @@ static RPCHelpMan getblockfrompeer()
ChainstateManager& chainman = EnsureChainman(node); ChainstateManager& chainman = EnsureChainman(node);
PeerManager& peerman = EnsurePeerman(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 NodeId peer_id{request.params[1].get_int64()};
const CBlockIndex* const index = WITH_LOCK(cs_main, return chainman.m_blockman.LookupBlockIndex(block_hash);); const CBlockIndex* const index = WITH_LOCK(cs_main, return chainman.m_blockman.LookupBlockIndex(block_hash););

View file

@ -6,8 +6,11 @@
#ifndef BITCOIN_SYNC_H #ifndef BITCOIN_SYNC_H
#define BITCOIN_SYNC_H #define BITCOIN_SYNC_H
#ifdef DEBUG_LOCKCONTENTION
#include <logging.h> #include <logging.h>
#include <logging/timer.h> #include <logging/timer.h>
#endif
#include <threadsafety.h> #include <threadsafety.h>
#include <util/macros.h> #include <util/macros.h>
@ -136,8 +139,10 @@ private:
void Enter(const char* pszName, const char* pszFile, int nLine) void Enter(const char* pszName, const char* pszFile, int nLine)
{ {
EnterCritical(pszName, pszFile, nLine, Base::mutex()); EnterCritical(pszName, pszFile, nLine, Base::mutex());
#ifdef DEBUG_LOCKCONTENTION
if (Base::try_lock()) return; if (Base::try_lock()) return;
LOG_TIME_MICROS_WITH_CATEGORY(strprintf("lock contention %s, %s:%d", pszName, pszFile, nLine), BCLog::LOCK); LOG_TIME_MICROS_WITH_CATEGORY(strprintf("lock contention %s, %s:%d", pszName, pszFile, nLine), BCLog::LOCK);
#endif
Base::lock(); Base::lock();
} }

View file

@ -19,13 +19,17 @@
#include <vector> #include <vector>
/** /**
* Identical to TestingSetup but excludes lock contention logging, as some of * Identical to TestingSetup but excludes lock contention logging if
* these tests are designed to be heavily contested to trigger race conditions * `DEBUG_LOCKCONTENTION` is defined, as some of these tests are designed to be
* or other issues. * heavily contested to trigger race conditions or other issues.
*/ */
struct NoLockLoggingTestingSetup : public TestingSetup { struct NoLockLoggingTestingSetup : public TestingSetup {
NoLockLoggingTestingSetup() NoLockLoggingTestingSetup()
#ifdef DEBUG_LOCKCONTENTION
: TestingSetup{CBaseChainParams::MAIN, /*extra_args=*/{"-debugexclude=lock"}} {} : TestingSetup{CBaseChainParams::MAIN, /*extra_args=*/{"-debugexclude=lock"}} {}
#else
: TestingSetup{CBaseChainParams::MAIN} {}
#endif
}; };
BOOST_FIXTURE_TEST_SUITE(checkqueue_tests, NoLockLoggingTestingSetup) BOOST_FIXTURE_TEST_SUITE(checkqueue_tests, NoLockLoggingTestingSetup)

View file

@ -56,9 +56,6 @@ class RpcMiscTest(BitcoinTestFramework):
self.log.info("test logging rpc and help") 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. # Test toggling a logging category on/off/on with the logging RPC.
assert_equal(node.logging()['qt'], True) assert_equal(node.logging()['qt'], True)
node.logging(exclude=['qt']) node.logging(exclude=['qt'])