8000 bench: update logging benchmarks by jonatack · Pull Request #26957 · bitcoin/bitcoin · GitHub
[go: up one dir, main page]
More Web Proxy on the site http://driver.im/
Skip to content

bench: update logging benchmarks #26957

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.

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

Merged
merged 6 commits into from
Mar 23, 2023

Conversation

jonatack
Copy link
Member
@jonatack jonatack commented Jan 23, 2023

Update our logging benchmarks for evaluating ongoing work like #25203 and refactoring proposals like #26619 and #26697.

  • make the logging benchmarks order-independent (Larry Ruane)
  • add missing benchmarks for the LogPrintLevel and LogPrintfCategory macros that our logging is migrating to; at some later point it should be feasible to drop some of the previous logging benchmarks
  • update the logging benchmark naming to be clear which benchmark corresponds to which log macro, and update the ordering to be the same as the output
  • add clarifying documentation to the logging benchmarks
  • improve the -debuglogfile config option help to be clearer; can be tested by running ./src/bitcoind -help | grep -A4 '\-debuglogfile'

Reviewers can run the logging benchmarks with:

./src/bench/bench_bitcoin -filter='LogP*.*'

@DrahtBot
Copy link
Contributor
DrahtBot commented Jan 23, 2023

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

Reviews

See the guideline for information on the review process.

Type Reviewers
ACK LarryRuane, martinus, achow101
Concept ACK kouloumos

If your review is incorrectly listed, please react with 👎 to this comment and the bot will ignore it on the next update.

Conflicts

Reviewers, this pull request conflicts with the following ones:

  • #27231 (Fix logging RPC and -debugexclude with 0/none values, add test coverage, improve docs by jonatack)

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.

@jonatack jonatack force-pushed the 2023-01-update-logging-benchmarks branch 2 times, most recently from d2f7abd to 9d708db Compare January 23, 2023 19:15
Copy link
Contributor
@kouloumos kouloumos left a comment

Choose a reason for hiding this comment

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

Concept ACK
The addition of the new macros makes sense as well as the new names for the benchmarks.

Just one observation: although I initially was sceptical about the {No,Yo} naming scheme, looking at the updated {With,Without} it seems that is now harder to skim through the list.

@jonatack jonatack force-pushed the 2023-01-update-logging-benchmarks branch from 9d708db to a0e092e Compare February 24, 2023 21:55
@jonatack
Copy link
Member Author

Thank you @kouloumos and @LarryRuane for the excellent reviewing. Updated per git diff 9d708db a0e092e

Copy link
Contributor
@LarryRuane LarryRuane left a comment

Choose a reason for hiding this comment

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

ACK a0e092e

$ ./src/bench/bench_bitcoin -filter='LogP*.*'
|               ns/op |                op/s |    err% |     total | benchmark
|--------------------:|--------------------:|--------:|----------:|:----------
|            2,716.93 |          368,062.78 |    0.5% |      0.01 | `LogPrintLevelWithThreadNames`
|            2,691.57 |          371,529.69 |    0.4% |      0.01 | `LogPrintLevelWithoutThreadNames`
|            2,657.64 |          376,273.25 |    0.3% |      0.01 | `LogPrintWithCategory`
|                4.15 |      241,089,995.32 |    0.3% |      0.01 | `LogPrintWithoutCategory`
|            2,705.19 |          369,659.92 |    0.2% |      0.01 | `LogPrintfCategoryWithThreadNames`
|            2,651.54 |          377,138.94 |    0.1% |      0.01 | `LogPrintfCategoryWithoutThreadNames`
|            2,649.92 |          377,370.03 |    0.3% |      0.01 | `LogPrintfWithThreadNames`
|            2,613.43 |          382,638.59 |    0.3% |      0.01 | `LogPrintfWithoutThreadNames`
|               48.00 |       20,832,403.39 |    0.3% |      0.01 | `LogWithoutWriteToFile`

I believe these are the (rough) results we expect. If you retouch, consider adding a comment at the top of the file probably, stating the expected results -- that is, that all but two of the tests should have similar performance, but that LogPrintWithoutCategory should be about 3 orders of magnitude faster than most of the tests, and LogWithoutWriteToFile should be about 2 orders of magnitude faster than most of the tests. Maybe even explain briefly why -- for example, LogWithoutWriteToFile is still logging somewhere (?) but not to a file, which is why it's faster, while LogPrintWithoutCategory should be almost a no-op. Something like that, just so when people run this benchmark, they'll know roughly what's expected without having to dig in and really understand the code.

LarryRuane and others added 4 commits March 6, 2023 12:45
The global logging object instance is not re-created for each run, so when
multiple logging benchmarks are run, each one after the first one still has
the logging categories enabled from the previous ones.  This commit disables
all categories at the start of each benchmark.
to better track which benchmark corresponds to which log macro.
for these new macros that our logging is planned to migrate to.  At some
point it may be feasible to drop some of the previous logging benchmarks.
@jonatack
Copy link
Member Author
jonatack commented Mar 7, 2023

consider adding a comment at the top of the file probably, stating the expected results

Good idea @LarryRuane (thanks!). Done.

jonatack added 2 commits March 7, 2023 09:32
and clarify the intention behind the -nodebuglogfile bench.

Co-authored-by: "kouloumos <kouloumosa@gmail.com>"
Co-authored-by: "Larry Ruane <larryruane@gmail.com>"
@jonatack jonatack force-pushed the 2023-01-update-logging-benchmarks branch from a0e092e to 8c47d59 Compare March 7, 2023 17:36
@LarryRuane
Copy link
Contributor

ACK 8c47d59
The commits are very clean.

@martinus
Copy link
Contributor
martinus commented Mar 18, 2023

code review & tested ACK 8c47d59, here are my benchmark results:

ns/op op/s err% ins/op cyc/op IPC bra/op miss% total benchmark
3,822.12 261,634.61 0.3% 22,931.00 8,536.02 2.686 4,512.00 0.1% 0.53 LogPrintLevelWithThreadNames
3,776.34 264,807.01 0.4% 22,494.01 8,370.09 2.687 4,403.00 0.1% 0.48 LogPrintLevelWithoutThreadNames
3,733.48 267,846.56 0.5% 22,252.00 8,272.50 2.690 4,351.00 0.1% 0.54 LogPrintWithCategory
7.25 137,992,883.01 0.5% 71.00 23.04 3.081 16.00 0.0% 0.67 LogPrintWithoutCategory
3,779.40 264,592.05 0.3% 22,773.01 8,416.90 2.706 4,473.00 0.1% 0.54 LogPrintfCategoryWithThreadNames
3,709.16 269,602.50 0.4% 22,122.00 8,208.57 2.695 4,318.00 0.1% 0.53 LogPrintfCategoryWithoutThreadNames
3,737.44 267,562.59 0.4% 22,495.01 8,290.13 2.713 4,399.00 0.1% 0.53 LogPrintfWithThreadNames
3,630.74 275,425.89 0.1% 21,844.00 7,989.23 2.734 4,244.00 0.1% 0.53 LogPrintfWithoutThreadNames
100.84 9,916,479.93 0.0% 802.00 320.90 2.499 186.00 0.0% 0.55 LogWithoutWriteToFile

By the way, here is a nice way to create & share detailed benchmark results, see the results here: https://share.firefox.dev/3Z02boN

How to do this:

  1. Run a benchmark for a few seconds and record data with perf
    perf record --call-graph lbr ./src/bench/bench_bitcoin -filter="LogPrintLevelWithoutThreadNames" -min-time=5000
  2. Convert into data readable with https://profiler.firefox.com/
    perf script -F +pid > /tmp/test.perf
  3. Drag & drop test.perf into https://profiler.firefox.com/, upload the data, and create a permalink to it

@LarryRuane
Copy link
Contributor

Here's a suggestion about benchmarking in general, wonder what you think. The idea is a kind of performance regression testing.

If there are a set of related benchmarks, as there are here, there may be some expected performance relationship between them. (Above I suggested that Jon add a comment describing this relationship, and he did.) It would be cool if this could somehow be specified in the code and checked automatically, and a failure raised if the runtime ratio between the sub-benchmarks exceeded some threshold. So for example, if a bug was introduced that made LogPrintWithoutCategory run at about the same speed as the other types of logging, flag an error.

What do you think? (Obviously not for this PR, but as a separate PR.)

@jonatack
Copy link
Member Author
jonatack commented Mar 18, 2023

@LarryRuane Perhaps reviving https://bitcoinperf.com/ to track changes in benchmarks over time, and alert when it observes a deviation threshold reached, could be a way to implement it. Maybe it could be hooked into the CI at some point.

@fanquake fanquake removed their assignment Mar 20, 2023
@achow101
Copy link
Member

ACK 8c47d59

@achow101 achow101 merged commit 630756c into bitcoin:master Mar 23, 2023
@jonatack jonatack deleted the 2023-01-update-logging-benchmarks branch March 23, 2023 21:14
sidhujag pushed a commit to syscoin/syscoin that referenced this pull request Mar 24, 2023
8c47d59 doc: improve -debuglogfile help to be a bit clearer (jonatack)
20d89d6 bench: document expected results in logging benchmarks (jonatack)
d8deba8 bench: add LogPrintfCategory and LogPrintLevel benchmarks (Jon Atack)
102b203 bench: order the logging benchmark code by output (Jon Atack)
4b3fdbf bench: update logging benchmark naming for clarity (Jon Atack)
4684aa8 bench: allow logging benchmarks to be order-independent (Larry Ruane)

Pull request description:

  Update our logging benchmarks for evaluating ongoing work like bitcoin#25203 and refactoring proposals like bitcoin#26619 and bitcoin#26697.

  - make the logging benchmarks order-independent (Larry Ruane)
  - add missing benchmarks for the `LogPrintLevel` and `LogPrintfCategory` macros that our logging is migrating to; at some later point it should be feasible to drop some of the previous logging benchmarks
  - update the logging benchmark naming to be clear which benchmark corresponds to which log macro, and update the ordering to be the same as the output
  - add clarifying documentation to the logging benchmarks
  - improve the `-debuglogfile` config option help to be clearer; can be tested by running `./src/bitcoind -help | grep -A4 '\-debuglogfile'`

  Reviewers can run the logging benchmarks with:
  ```bash
  ./src/bench/bench_bitcoin -filter='LogP*.*'
  ```

ACKs for top commit:
  LarryRuane:
    ACK 8c47d59
  martinus:
    code review & tested ACK 8c47d59, here are my benchmark results:
  achow101:
    ACK 8c47d59

Tree-SHA512: 705f8720c9ceaf14a1945039c7578a0c17a12215cbc44908099af4ac444561c3f95d833c5a91b325cdd4470737d8a01e2da64db2d542dd7c9a3747fbfdbf213e
@bitcoin bitcoin locked and limited conversation to collaborators Mar 22, 2024
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
Projects
None yet
Development

Successfully merging this pull request may close these issues.

8 participants
0