Skip to content

Commit

Permalink
Merge bitcoin#26957: bench: update logging benchmarks
Browse files Browse the repository at this point in the history
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
  • Loading branch information
achow101 committed Mar 23, 2023
2 parents 2305643 + 8c47d59 commit 630756c
Show file tree
Hide file tree
Showing 2 changed files with 56 additions and 13 deletions.
67 changes: 55 additions & 12 deletions src/bench/logging.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -6,9 +6,17 @@
#include <logging.h>
#include <test/util/setup_common.h>

// All but 2 of the benchmarks should have roughly similar performance:
//
// LogPrintWithoutCategory should be ~3 orders of magnitude faster, as nothing is logged.
//
// LogWithoutWriteToFile should be ~2 orders of magnitude faster, as it avoids disk writes.

static void Logging(benchmark::Bench& bench, const std::vector<const char*>& extra_args, const std::function<void()>& log)
{
// Reset any enabled logging categories from a previous benchmark run.
LogInstance().DisableCategory(BCLog::LogFlags::ALL);

TestingSetup test_setup{
CBaseChainParams::REGTEST,
extra_args,
Expand All @@ -17,32 +25,67 @@ static void Logging(benchmark::Bench& bench, const std::vector<const char*>& ext
bench.run([&] { log(); });
}

static void LoggingYoThreadNames(benchmark::Bench& bench)
static void LogPrintLevelWithThreadNames(benchmark::Bench& bench)
{
Logging(bench, {"-logthreadnames=1"}, [] { LogPrintf("%s\n", "test"); });
Logging(bench, {"-logthreadnames=1", "-debug=net"}, [] {
LogPrintLevel(BCLog::NET, BCLog::Level::Error, "%s\n", "test"); });
}
static void LoggingNoThreadNames(benchmark::Bench& bench)

static void LogPrintLevelWithoutThreadNames(benchmark::Bench& bench)
{
Logging(bench, {"-logthreadnames=0"}, [] { LogPrintf("%s\n", "test"); });
Logging(bench, {"-logthreadnames=0", "-debug=net"}, [] {
LogPrintLevel(BCLog::NET, BCLog::Level::Error, "%s\n", "test"); });
}
static void LoggingYoCategory(benchmark::Bench& bench)

static void LogPrintWithCategory(benchmark::Bench& bench)
{
Logging(bench, {"-logthreadnames=0", "-debug=net"}, [] { LogPrint(BCLog::NET, "%s\n", "test"); });
}
static void LoggingNoCategory(benchmark::Bench& bench)

static void LogPrintWithoutCategory(benchmark::Bench& bench)
{
Logging(bench, {"-logthreadnames=0", "-debug=0"}, [] { LogPrint(BCLog::NET, "%s\n", "test"); });
}
static void LoggingNoFile(benchmark::Bench& bench)

static void LogPrintfCategoryWithThreadNames(benchmark::Bench& bench)
{
Logging(bench, {"-logthreadnames=1", "-debug=net"}, [] {
LogPrintfCategory(BCLog::NET, "%s\n", "test");
});
}

static void LogPrintfCategoryWithoutThreadNames(benchmark::Bench& bench)
{
Logging(bench, {"-logthreadnames=0", "-debug=net"}, [] {
LogPrintfCategory(BCLog::NET, "%s\n", "test");
});
}

static void LogPrintfWithThreadNames(benchmark::Bench& bench)
{
Logging(bench, {"-logthreadnames=1"}, [] { LogPrintf("%s\n", "test"); });
}

static void LogPrintfWithoutThreadNames(benchmark::Bench& bench)
{
Logging(bench, {"-logthreadnames=0"}, [] { LogPrintf("%s\n", "test"); });
}

static void LogWithoutWriteToFile(benchmark::Bench& bench)
{
// Disable writing the log to a file, as used for unit tests and fuzzing in `MakeNoLogFileContext`.
Logging(bench, {"-nodebuglogfile", "-debug=1"}, [] {
LogPrintf("%s\n", "test");
LogPrint(BCLog::NET, "%s\n", "test");
});
}

BENCHMARK(LoggingYoThreadNames, benchmark::PriorityLevel::HIGH);
BENCHMARK(LoggingNoThreadNames, benchmark::PriorityLevel::HIGH);
BENCHMARK(LoggingYoCategory, benchmark::PriorityLevel::HIGH);
BENCHMARK(LoggingNoCategory, benchmark::PriorityLevel::HIGH);
BENCHMARK(LoggingNoFile, benchmark::PriorityLevel::HIGH);
BENCHMARK(LogPrintLevelWithThreadNames, benchmark::PriorityLevel::HIGH);
BENCHMARK(LogPrintLevelWithoutThreadNames, benchmark::PriorityLevel::HIGH);
BENCHMARK(LogPrintWithCategory, benchmark::PriorityLevel::HIGH);
BENCHMARK(LogPrintWithoutCategory, benchmark::PriorityLevel::HIGH);
BENCHMARK(LogPrintfCategoryWithThreadNames, benchmark::PriorityLevel::HIGH);
BENCHMARK(LogPrintfCategoryWithoutThreadNames, benchmark::PriorityLevel::HIGH);
BENCHMARK(LogPrintfWithThreadNames, benchmark::PriorityLevel::HIGH);
BENCHMARK(LogPrintfWithoutThreadNames, benchmark::PriorityLevel::HIGH);
BENCHMARK(LogWithoutWriteToFile, benchmark::PriorityLevel::HIGH);
2 changes: 1 addition & 1 deletion src/init/common.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -23,7 +23,7 @@
namespace init {
void AddLoggingArgs(ArgsManager& argsman)
{
argsman.AddArg("-debuglogfile=<file>", strprintf("Specify location of debug log file. Relative paths will be prefixed by a net-specific datadir location. (-nodebuglogfile to disable; default: %s)", DEFAULT_DEBUGLOGFILE), ArgsManager::ALLOW_ANY, OptionsCategory::OPTIONS);
argsman.AddArg("-debuglogfile=<file>", strprintf("Specify location of debug log file (default: %s). Relative paths will be prefixed by a net-specific datadir location. Pass -nodebuglogfile to disable writing the log to a file.", DEFAULT_DEBUGLOGFILE), ArgsManager::ALLOW_ANY, OptionsCategory::OPTIONS);
argsman.AddArg("-debug=<category>", "Output debug and trace logging (default: -nodebug, supplying <category> is optional). "
"If <category> is not supplied or if <category> = 1, output all debug and trace logging. <category> can be: " + LogInstance().LogCategoriesString() + ". This option can be specified multiple times to output multiple categories.",
ArgsManager::ALLOW_ANY, OptionsCategory::DEBUG_TEST);
Expand Down

0 comments on commit 630756c

Please sign in to comment.