Skip to content

Conversation

jonatack
Copy link
Member

@jonatack jonatack commented Apr 5, 2022

This is a more minimal, no-frills version of #24734 for backport. The other fixes and improvements in that pull can be done after.

Copy of the PR 24734 description:

PRs #22736, #22904 and #23223 changed lock contention logging from a DEBUG_LOCKCONTENTION compile-time preprocessor directive to a runtime lock log category and improved the logging output. This changed the locking from using lock() to try_lock():

  • void Mutex::UniqueLock::lock() acquires the mutex and blocks until it gains access to it

  • bool Mutex::UniqueLock::try_lock() doesn't block but instead immediately returns whether it acquired the mutex; it may be used by lock() internally as part of the deadlock-avoidance algorithm

In theory the cost of try_lock might be essentially the same relative to lock. The test-and-set logic of these calls is purported to be ~ constant time, optimised and light/quick if used carefully (i.e. no mutex convoying), compared to system calls, memory/cache coherency and fences, wait queues, and (particularly) lock contentions. See the discussion around #22736 (comment) and after with respect to performance/cost aspects. However, 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.

One alternative to keep the run-time lock logging would be to gate the try_lock call behind the logging conditional, for example as proposed in ccd73de and ACKed here. However, this would add the cost of if (LogAcceptCategory(BCLog::LOCK)) to the hotspot, instead of replacing lock with try_lock, for the most frequent happy path (non-contention).

It turns out we can keep the advantages of the runtime lock contention logging (the ability to turn it on/off at runtime) while out of prudence putting the try_lock() call and lock logging category behind a DEBUG_LOCKCONTENTION compile-time preprocessor directive, and also still retain the lock logging enhancements of the mentioned PRs, as suggested in #24734 (comment) by W. J. van der Laan, in #22736 (comment), and in the linked IRC discussion.

Proposed here and for backport to v23.

@jonatack jonatack force-pushed the change-lock-logging-to-DEBUG_LOCKCONTENTION-one-commit branch from 5fdb3a9 to 4394733 Compare April 5, 2022 10:52
@jonatack
Copy link
Member Author

jonatack commented Apr 5, 2022

Added the developer notes commit and headers changes per IRC feedback.

@DrahtBot
Copy link
Contributor

DrahtBot commented Apr 6, 2022

The following sections might be updated with supplementary metadata relevant to reviewers and maintainers.

Conflicts

Reviewers, this pull request conflicts with the following ones:

  • #24757 (build, ci: add DEBUG_LOCKCONTENTION to --enable-debug and CI by jonatack)
  • #24748 (test/BIP324: functional tests for v2 P2P encryption by stratospher)
  • #24545 (BIP324: Enable v2 P2P encrypted transport by dhruv)
  • #23561 (BIP324: Handshake prerequisites by dhruv)
  • #23443 (p2p: Erlay support signaling by naumenkogs)
  • #23233 (BIP324: Add encrypted p2p transport {de}serializer by dhruv)
  • #21603 (log: Mitigate disk filling attacks by rate limiting LogPrintf by dergoegge)

If you consider this pull request important, please also help to review the conflicting pull requests. Ideally, start with the one that should be merged first.

@laanwj
Copy link
Member

laanwj commented Apr 8, 2022

Code review ACK 4394733

@jonatack
Copy link
Member Author

jonatack commented Apr 8, 2022

Copied over the PR description.

fanquake pushed a commit to fanquake/bitcoin that referenced this pull request Apr 8, 2022
fanquake pushed a commit to fanquake/bitcoin that referenced this pull request Apr 8, 2022
@fanquake fanquake merged commit c1059c9 into bitcoin:master Apr 8, 2022
@jonatack jonatack deleted the change-lock-logging-to-DEBUG_LOCKCONTENTION-one-commit branch April 8, 2022 12:31
@fanquake
Copy link
Member

fanquake commented Apr 8, 2022

Backported in #24807.

sidhujag pushed a commit to syscoin/syscoin that referenced this pull request Apr 8, 2022
laanwj added a commit that referenced this pull request Apr 8, 2022
e3e4be9 RPC: Switch getblockfrompeer back to standard param name blockhash (Luke Dashjr)
69cc83d Add DEBUG_LOCKCONTENTION documentation to the developer notes (Jon Atack)
6374e24 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 e3e4be9
  jonatack:
    Code review and commit metadata ACK e3e4be9

Tree-SHA512: eff2b506379a9396b12b42ed2858e3eb9403a55950d6dec0b5dcc95c4c2998cddf9e0ec88af2f8ac5a7bece4d4537acede1c75f59bbc6616bee273384f87f6b0
Fabcien pushed a commit to Bitcoin-ABC/bitcoin-abc that referenced this pull request Sep 28, 2022
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 [[bitcoin/bitcoin#22736 | core#22736]], [[bitcoin/bitcoin#22904 | core#22904]], [[bitcoin/bitcoin#23223 | core#23223]] and [[bitcoin/bitcoin#24770 | 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
```

Reviewers: #bitcoin_abc, sdulfari

Reviewed By: #bitcoin_abc, sdulfari

Subscribers: sdulfari

Differential Revision: https://reviews.bitcoinabc.org/D12049
@bitcoin bitcoin locked and limited conversation to collaborators Apr 8, 2023
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

5 participants