Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Merge bitcoin/bitcoin#22736: log, sync: change lock contention from preprocessor directive to log category #5649

Merged
1 commit merged into from
Apr 2, 2024
Merged

Merge bitcoin/bitcoin#22736: log, sync: change lock contention from preprocessor directive to log category #5649

1 commit merged into from
Apr 2, 2024

Conversation

PastaPastaPasta
Copy link
Member

7e69873 sync: remove DEBUG_LOCKCONTENTION preprocessor directives (Jon Atack)
9b08006 log, sync: improve lock contention logging and add time duration (Jon Atack)
3f4c6b8 log, timer: add timing macro in usec LOG_TIME_MICROS_WITH_CATEGORY (Jon Atack)
b7a1744 log, sync: add LOCK logging category, apply it to lock contention (Jon Atack)

Pull request description:

To enable lock contention logging, DEBUG_LOCKCONTENTION has to be defined at compilation. Once built, the logging is not limited to a category and is high frequency, verbose and in all-caps. With these factors combined, it seems likely to be rarely used.

This patch:

  • adds a lock logging category
  • 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
  • removes the conditional compilation directives
  • allows lock contentions to be logged on startup with -debug=lock or at run time with bitcoin-cli logging '["lock"]'
$ bitcoind -signet -debug=lock
2021-09-01T12:40:01Z LockContention: cs_vNodes, net.cpp:1920 started
2021-09-01T12:40:01Z LockContention: cs_vNodes, net.cpp:1920 completed (4μs)
2021-09-01T12:40:01Z LockContention: cs_vNodes, net.cpp:1302 started
2021-09-01T12:40:01Z LockContention: cs_vNodes, net.cpp:1302 completed (4μs)
2021-09-01T12:40:02Z LockContention: cs_vNodes, net.cpp:2242 started
2021-09-01T12:40:02Z LockContention: cs_vNodes, net.cpp:2242 completed (20μs)
2021-09-01T12:43:04Z LockContention: ::cs_main, validation.cpp:4980 started
2021-09-01T12:43:04Z LockContention: ::cs_main, validation.cpp:4980 completed (3μs)

$ bitcoin-cli -signet logging
  "lock": true,

$ bitcoin-cli -signet logging [] '["lock"]'
  "lock": false,

$ bitcoin-cli -signet logging '["lock"]'
  "lock": true, ```

I've tested this with Clang 13 and GCC 10.2.1, on Debian, with and without `--enable-debug`.


## Checklist:
_Go over all the following points, and put an `x` in all the boxes that apply._
- [ ] I have performed a self-review of my own code
- [ ] I have commented my code, particularly in hard-to-understand areas
- [ ] I have added or updated relevant unit/integration/functional/e2e tests
- [ ] I have made corresponding changes to the documentation
- [x] I have assigned this pull request to a milestone _(for repository code-owners and collaborators only)_

@PastaPastaPasta PastaPastaPasta added this to the 20 milestone Oct 25, 2023
knst
knst reviewed Oct 26, 2023
View reviewed changes
src/logging/timer.h
@@ -93,6 +95,8 @@ class Timer
} // namespace BCLog


#define LOG_TIME_MICROS_WITH_CATEGORY(end_msg, log_category) \
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

please update this one:

-#include <sync.h>
+#include <util/macros.h>

Otherwise PR causes:

A new circular dependency in the form of "logging/timer -> sync -> logging/timer" appears to have been introduced.

UdjinM6
UdjinM6 requested changes Oct 26, 2023
View reviewed changes
Copy link

@UdjinM6 UdjinM6 left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

missing changes in test/functional/rpc_misc.py so should be partial

src/logging.h Outdated
@@ -78,6 +78,7 @@ namespace BCLog {
NET_NETCONN = NET | NETCONN, // use this to have something logged in NET and NETCONN as well
//End Dash

LOCK = (1 << 24),
Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

this line should be 20 lines higher, right after I2P = (1 << 22),

@knst knst changed the title Merge bitcoin/bitcoin#22736: log, sync: change lock contention from p reprocessor directive to log category Merge bitcoin/bitcoin#22736: log, sync: change lock contention from preprocessor directive to log category Nov 6, 2023
@github-actions GitHub Actions
Copy link

github-actions bot commented Nov 7, 2023

This pull request has conflicts, please rebase.

@UdjinM6 UdjinM6 modified the milestones: 20, 21, 20.1 Nov 11, 2023
@UdjinM6 UdjinM6 modified the milestones: 20.1, 21 Mar 5, 2024
@PastaPastaPasta PastaPastaPasta force-pushed the backport/22736 branch 2 times, most recently from dc345f5 to 8a45ce8 Compare March 25, 2024 17:08
@DashCoreAutoGuix
Copy link

Guix Automation has began to build this PR tagged as v21.0.0-devpr5649.8a45ce87. A new comment will be made when the image is pushed.

@DashCoreAutoGuix
Copy link

Guix Automation has completed; a release should be present here: https://github.com/dashpay/dash-dev-branches/releases/tag/v21.0.0-devpr5649.8a45ce87. The image should be on dockerhub soon.

@DashCoreAutoGuix
Copy link

Guix Automation has began to build this PR tagged as v21.0.0-devpr5649.93adfe8c. A new comment will be made when the image is pushed.

@DashCoreAutoGuix
Copy link

Guix Automation has completed; a release should be present here: https://github.com/dashpay/dash-dev-branches/releases/tag/v21.0.0-devpr5649.93adfe8c. The image should be on dockerhub soon.

@DashCoreAutoGuix
Copy link

Guix Automation has began to build this PR tagged as v21.0.0-devpr5649.f9eaeedc. A new comment will be made when the image is pushed.

@DashCoreAutoGuix
Copy link

Guix Automation has completed; a release should be present here: https://github.com/dashpay/dash-dev-branches/releases/tag/v21.0.0-devpr5649.f9eaeedc. The image should be on dockerhub soon.

@DashCoreAutoGuix
Copy link

Guix Automation has began to build this PR tagged as v21.0.0-devpr5649.6296fe8b. A new comment will be made when the image is pushed.

@DashCoreAutoGuix
Copy link

Guix Automation has completed; a release should be present here: https://github.com/dashpay/dash-dev-branches/releases/tag/v21.0.0-devpr5649.6296fe8b. The image should be on dockerhub soon.

@DashCoreAutoGuix
Copy link

Guix Automation has began to build this PR tagged as v21.0.0-devpr5649.e9d05e30. A new comment will be made when the image is pushed.

@DashCoreAutoGuix
Copy link

Guix Automation has completed; a release should be present here: https://github.com/dashpay/dash-dev-branches/releases/tag/v21.0.0-devpr5649.e9d05e30. The image should be on dockerhub soon.

@DashCoreAutoGuix
Copy link

Guix Automation has began to build this PR tagged as v21.0.0-devpr5649.95cc1cbb. A new comment will be made when the image is pushed.

@DashCoreAutoGuix
Copy link

Guix Automation has completed; a release should be present here: https://github.com/dashpay/dash-dev-branches/releases/tag/v21.0.0-devpr5649.95cc1cbb. The image should be on dockerhub soon.

@PastaPastaPasta PastaPastaPasta requested review from knst and UdjinM6 April 2, 2024 13:53
UdjinM6
UdjinM6 requested changes Apr 2, 2024
View reviewed changes
Copy link

@UdjinM6 UdjinM6 left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Looks good, pls squash all the fixes and drop partial mark

@PastaPastaPasta
Merge bitcoin#22736: log, sync: change lock contention from preproces…
436a578 
…sor directive to log category

7e69873 sync: remove DEBUG_LOCKCONTENTION preprocessor directives (Jon Atack)
9b08006 log, sync: improve lock contention logging and add time duration (Jon Atack)
3f4c6b8 log, timer: add timing macro in usec LOG_TIME_MICROS_WITH_CATEGORY (Jon Atack)
b7a1744 log, sync: add LOCK logging category, apply it to lock contention (Jon Atack)

Pull request description:

  To enable lock contention logging, `DEBUG_LOCKCONTENTION` has to be defined at compilation. Once built, the logging is not limited to a category and is high frequency, verbose and in all-caps. With these factors combined, it seems likely to be rarely used.

  This patch:
  - adds a `lock` logging category
  - 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
  - removes the conditional compilation directives
  - allows lock contentions to be logged on startup with `-debug=lock` or at run time with `bitcoin-cli logging '["lock"]'`

  ```
  $ bitcoind -signet -debug=lock
  2021-09-01T12:40:01Z LockContention: cs_vNodes, net.cpp:1920 started
  2021-09-01T12:40:01Z LockContention: cs_vNodes, net.cpp:1920 completed (4μs)
  2021-09-01T12:40:01Z LockContention: cs_vNodes, net.cpp:1302 started
  2021-09-01T12:40:01Z LockContention: cs_vNodes, net.cpp:1302 completed (4μs)
  2021-09-01T12:40:02Z LockContention: cs_vNodes, net.cpp:2242 started
  2021-09-01T12:40:02Z LockContention: cs_vNodes, net.cpp:2242 completed (20μs)
  2021-09-01T12:43:04Z LockContention: ::cs_main, validation.cpp:4980 started
  2021-09-01T12:43:04Z LockContention: ::cs_main, validation.cpp:4980 completed (3μs)

  $ bitcoin-cli -signet logging
    "lock": true,

  $ bitcoin-cli -signet logging [] '["lock"]'
    "lock": false,

  $ bitcoin-cli -signet logging '["lock"]'
    "lock": true,
  ```

  I've tested this with Clang 13 and GCC 10.2.1, on Debian, with and without `--enable-debug`.

ACKs for top commit:
  hebasto:
    re-ACK 7e69873, added a contention duration to the log message since my [previous](bitcoin#22736 (review)) review.
  theStack:
    re-ACK 7e69873 🔏 ⏲️

Tree-SHA512: c4b5eb88d3a2c051acaa842b3055ce30efde1f114f61da6e55fcaa27476c1c33a60bc419f7f5ccda532e1bdbe70815222ec2b2b6d9226f29c8e94e598aacfee7
@PastaPastaPasta
Copy link
Member Author

no-diff squash here: https://github.com/dashpay/dash/compare/95cc1cbb3c9de6ef75f4dbc0e5e9074269446df5..c42a4b4284d2beed837bf8df13f3aaf3260228a7
then rebased on develop in
https://github.com/dashpay/dash/compare/c42a4b4284d2beed837bf8df13f3aaf3260228a7..436a5783c733f49757102e09de99d20abe173cf3

@PastaPastaPasta PastaPastaPasta requested a review from UdjinM6 April 2, 2024 17:10
UdjinM6
UdjinM6 approved these changes Apr 2, 2024
View reviewed changes
Copy link

@UdjinM6 UdjinM6 left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

utACK

@DashCoreAutoGuix
Copy link

Guix Automation has began to build this PR tagged as v21.0.0-devpr5649.436a5783. A new comment will be made when the image is pushed.

@DashCoreAutoGuix
Copy link

Guix Automation has completed; a release should be present here: https://github.com/dashpay/dash-dev-branches/releases/tag/v21.0.0-devpr5649.436a5783. The image should be on dockerhub soon.

@PastaPastaPasta PastaPastaPasta closed this pull request by merging all changes into dashpay:develop in 4da2067 Apr 2, 2024
@PastaPastaPasta PastaPastaPasta deleted the backport/22736 branch April 3, 2024 15:28
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Reviewers

@UdjinM6 UdjinM6 UdjinM6 approved these changes

@knst knst Awaiting requested review from knst

Assignees
No one assigned
Labels
guix-build
Projects
None yet
Milestone
21
Development

Successfully merging this pull request may close these issues.
4 participants
@PastaPastaPasta @DashCoreAutoGuix @knst @UdjinM6