log, sync: add LOCK logging category, apply it to lock contention
ClosedPublic
Actions

Authored by PiRK on Sep 23 2022, 16:32.

Details

Reviewers

sdulfari

Group Reviewers

Restricted Project

Commits

rABC5d9c53f2a697: log, sync: add LOCK logging category, apply it to lock contention

Summary

This diff:

adds a LOCK logging category if DEBUG_LOCKCONTENTION is defined at compilation.
adds a timing macro in microseconds, LOG_TIME_MICROS_WITH_CATEGORY
updates BCLog::LogMsg() to omit irrelevant decimals for microseconds and skip unneeded code and math.
improves the lock contention logging, drops the all-caps, and displays the duration in microseconds
makes unexpected time type in BCLog::LogMsg() a compile-time error
add a paragraph of documentation to developer-notes.md

Lock contention logging in checkqueue_tests is disabled, as some of these tests are designed to be heavily contested to trigger race conditions or other issues. This created very large log files when run with DEBUG_LOCKCONTENTION defined.

This is a backport of core#22736, core#22904, core#23223 and core#24770

The first pull request implements the lock category, the other pull requests are important follow-ups (mixed with minor refactorings) fixing various regressions (bugs and suspected performance issues).

Co-authored-by: Hennadii Stepanov <32963518+hebasto@users.noreply.github.com>
Co-authored-by: practicalswift <practicalswift@users.noreply.github.com>
Co-authored-by: Martin Ankerl <martin.ankerl@gmail.com>

Test Plan

ninja all check-all

Follow the instructions in the new documentation and check that the logging works:

cmake .. -GNinja -DCMAKE_CXX_FLAGS="-DDEBUG_LOCKCONTENTION"
ninja
src/bitcoind -h | grep -A8 "debug=<category>"
src/bitcoind -debug=lock

Diff Detail

Repository

rABC Bitcoin ABC

Branch

pr22736

Lint

Lint Passed

Unit

No Test Coverage

Build Status

Buildable 20175
Build 40035: Build Diff	lint-circular-dependencies · build-without-wallet · build-diff · build-debug · build-clang-tidy · build-clang
Build 40034: arc lint + arc unit

Event Timeline

PiRK created this revision.Sep 23 2022, 16:32

Herald added a reviewer: Restricted Project. · View Herald TranscriptSep 23 2022, 16:32

PiRK requested review of this revision.Sep 23 2022, 16:32

teamcity edited the summary of this revision. (Show Details)Sep 23 2022, 16:33

Harbormaster completed remote builds in B20157: Diff 35161.Sep 23 2022, 16:48

Which change was from https://github.com/bitcoin/bitcoin/pull/24470 ? I could not find it.

doc/developer-notes.md
282–283 ↗	(On Diff #35161)	DEBUG_LOCKCONTENTION is just a logging category and not strictly related to RPC.
src/net.h
40 ↗	(On Diff #35161)	Are either of these includes necessary?
src/sync.h
141 ↗	(On Diff #35161)	Is the #ifdef intended to remain?
test/functional/rpc_misc.py
62 ↗	(On Diff #35161)	Why remove this check?

This revision now requires changes to proceed.Sep 23 2022, 21:35

PiRK edited the summary of this revision. (Show Details)Sep 25 2022, 11:11

In D12049#269788, @sdulfari wrote:

Which change was from https://github.com/bitcoin/bitcoin/pull/24470 ? I could not find it.

I made a mistake in the PR number. I fixed it in the description (https://github.com/bitcoin/bitcoin/pull/24770 )

doc/developer-notes.md
282–283 ↗	(On Diff #35161)	OK.
src/net.h
40 ↗	(On Diff #35161)	I'm not sure why these were added in this stack, but they are correct: there are 3 `std::list` in this file, and it uses `BCLog` from looging.h. It probably worked until now only because of indirect inclusion via other libraries. For reference: https://github.com/bitcoin/bitcoin/pull/24770#issuecomment-1088557064
src/sync.h
141 ↗	(On Diff #35161)	yes. Thats the PR that previously had a typo in the the description: https://github.com/bitcoin/bitcoin/pull/24770 The rationale for keeping the `DEBUG_LOCKCONTENTION` flag is there are reasonable concerns (see here and here) that Base::try_lock() may be potentially costly or risky compared to Base::lock() in this very frequently called code.
test/functional/rpc_misc.py
62 ↗	(On Diff #35161)	Now the number of logging categories depends on a compile time flag. I briefly considered looking for a way to adjust the test (similar to how some tests are skipped when the wallet is not compiled), but the test does not seem very valuable and will have to be maintained every time a category is added. I does not seem to be worth the effort.

improve documentation

Harbormaster completed remote builds in B20175: Diff 35184.Sep 25 2022, 11:51

Thanks for fixing the last backport link. I've reviewed the remainder and they look ok.

test/functional/rpc_misc.py
62 ↗	(On Diff #35161)	Categories are not added often, so this is not very concerning. What about changing this to assert_greater_or_equal? That way we keep the check that a minimum number of categories exist, but toggling additional categories on will not break the test.