0
0
Fork 0
mirror of https://github.com/bitcoin/bitcoin.git synced 2025-02-25 12:51:55 -05:00
bitcoin-bitcoin-core/src/test/logging_tests.cpp
Ryan Ofsky 4f74c59334 util: Move util/string.h functions to util namespace
There are no changes to behavior. Changes in this commit are all additions, and
are easiest to review using "git diff -U0 --word-diff-regex=." options.

Motivation for this change is to keep util functions with really generic names
like "Split" and "Join" out of the global namespace so it is easier to see
where these functions are defined, and so they don't interfere with function
overloading, especially since the util library is a dependency of the kernel
library and intended to be used with external code.
2024-05-16 10:16:08 -05:00

283 lines
11 KiB
C++

// Copyright (c) 2019-2022 The Bitcoin Core developers
// Distributed under the MIT software license, see the accompanying
// file COPYING or http://www.opensource.org/licenses/mit-license.php.
#include <init/common.h>
#include <logging.h>
#include <logging/timer.h>
#include <test/util/setup_common.h>
#include <util/string.h>
#include <chrono>
#include <fstream>
#include <iostream>
#include <unordered_map>
#include <utility>
#include <vector>
#include <boost/test/unit_test.hpp>
using util::SplitString;
using util::TrimString;
BOOST_FIXTURE_TEST_SUITE(logging_tests, BasicTestingSetup)
static void ResetLogger()
{
LogInstance().SetLogLevel(BCLog::DEFAULT_LOG_LEVEL);
LogInstance().SetCategoryLogLevel({});
}
struct LogSetup : public BasicTestingSetup {
fs::path prev_log_path;
fs::path tmp_log_path;
bool prev_reopen_file;
bool prev_print_to_file;
bool prev_log_timestamps;
bool prev_log_threadnames;
bool prev_log_sourcelocations;
std::unordered_map<BCLog::LogFlags, BCLog::Level> prev_category_levels;
BCLog::Level prev_log_level;
LogSetup() : prev_log_path{LogInstance().m_file_path},
tmp_log_path{m_args.GetDataDirBase() / "tmp_debug.log"},
prev_reopen_file{LogInstance().m_reopen_file},
prev_print_to_file{LogInstance().m_print_to_file},
prev_log_timestamps{LogInstance().m_log_timestamps},
prev_log_threadnames{LogInstance().m_log_threadnames},
prev_log_sourcelocations{LogInstance().m_log_sourcelocations},
prev_category_levels{LogInstance().CategoryLevels()},
prev_log_level{LogInstance().LogLevel()}
{
LogInstance().m_file_path = tmp_log_path;
LogInstance().m_reopen_file = true;
LogInstance().m_print_to_file = true;
LogInstance().m_log_timestamps = false;
LogInstance().m_log_threadnames = false;
// Prevent tests from failing when the line number of the logs changes.
LogInstance().m_log_sourcelocations = false;
LogInstance().SetLogLevel(BCLog::Level::Debug);
LogInstance().SetCategoryLogLevel({});
}
~LogSetup()
{
LogInstance().m_file_path = prev_log_path;
LogPrintf("Sentinel log to reopen log file\n");
LogInstance().m_print_to_file = prev_print_to_file;
LogInstance().m_reopen_file = prev_reopen_file;
LogInstance().m_log_timestamps = prev_log_timestamps;
LogInstance().m_log_threadnames = prev_log_threadnames;
LogInstance().m_log_sourcelocations = prev_log_sourcelocations;
LogInstance().SetLogLevel(prev_log_level);
LogInstance().SetCategoryLogLevel(prev_category_levels);
}
};
BOOST_AUTO_TEST_CASE(logging_timer)
{
auto micro_timer = BCLog::Timer<std::chrono::microseconds>("tests", "end_msg");
const std::string_view result_prefix{"tests: msg ("};
BOOST_CHECK_EQUAL(micro_timer.LogMsg("msg").substr(0, result_prefix.size()), result_prefix);
}
BOOST_FIXTURE_TEST_CASE(logging_LogPrintf_, LogSetup)
{
LogInstance().m_log_sourcelocations = true;
LogPrintf_("fn1", "src1", 1, BCLog::LogFlags::NET, BCLog::Level::Debug, "foo1: %s\n", "bar1");
LogPrintf_("fn2", "src2", 2, BCLog::LogFlags::NET, BCLog::Level::Info, "foo2: %s\n", "bar2");
LogPrintf_("fn3", "src3", 3, BCLog::LogFlags::ALL, BCLog::Level::Debug, "foo3: %s\n", "bar3");
LogPrintf_("fn4", "src4", 4, BCLog::LogFlags::ALL, BCLog::Level::Info, "foo4: %s\n", "bar4");
LogPrintf_("fn5", "src5", 5, BCLog::LogFlags::NONE, BCLog::Level::Debug, "foo5: %s\n", "bar5");
LogPrintf_("fn6", "src6", 6, BCLog::LogFlags::NONE, BCLog::Level::Info, "foo6: %s\n", "bar6");
std::ifstream file{tmp_log_path};
std::vector<std::string> log_lines;
for (std::string log; std::getline(file, log);) {
log_lines.push_back(log);
}
std::vector<std::string> expected = {
"[src1:1] [fn1] [net] foo1: bar1",
"[src2:2] [fn2] [net:info] foo2: bar2",
"[src3:3] [fn3] [debug] foo3: bar3",
"[src4:4] [fn4] foo4: bar4",
"[src5:5] [fn5] [debug] foo5: bar5",
"[src6:6] [fn6] foo6: bar6",
};
BOOST_CHECK_EQUAL_COLLECTIONS(log_lines.begin(), log_lines.end(), expected.begin(), expected.end());
}
BOOST_FIXTURE_TEST_CASE(logging_LogPrintMacrosDeprecated, LogSetup)
{
LogPrintf("foo5: %s\n", "bar5");
LogPrint(BCLog::NET, "foo6: %s\n", "bar6");
LogPrintLevel(BCLog::NET, BCLog::Level::Trace, "foo4: %s\n", "bar4"); // not logged
LogPrintLevel(BCLog::NET, BCLog::Level::Debug, "foo7: %s\n", "bar7");
LogPrintLevel(BCLog::NET, BCLog::Level::Info, "foo8: %s\n", "bar8");
LogPrintLevel(BCLog::NET, BCLog::Level::Warning, "foo9: %s\n", "bar9");
LogPrintLevel(BCLog::NET, BCLog::Level::Error, "foo10: %s\n", "bar10");
LogPrintfCategory(BCLog::VALIDATION, "foo11: %s\n", "bar11");
std::ifstream file{tmp_log_path};
std::vector<std::string> log_lines;
for (std::string log; std::getline(file, log);) {
log_lines.push_back(log);
}
std::vector<std::string> expected = {
"foo5: bar5",
"[net] foo6: bar6",
"[net] foo7: bar7",
"[net:info] foo8: bar8",
"[net:warning] foo9: bar9",
"[net:error] foo10: bar10",
"[validation:info] foo11: bar11",
};
BOOST_CHECK_EQUAL_COLLECTIONS(log_lines.begin(), log_lines.end(), expected.begin(), expected.end());
}
BOOST_FIXTURE_TEST_CASE(logging_LogPrintMacros, LogSetup)
{
LogTrace(BCLog::NET, "foo6: %s\n", "bar6"); // not logged
LogDebug(BCLog::NET, "foo7: %s\n", "bar7");
LogInfo("foo8: %s\n", "bar8");
LogWarning("foo9: %s\n", "bar9");
LogError("foo10: %s\n", "bar10");
std::ifstream file{tmp_log_path};
std::vector<std::string> log_lines;
for (std::string log; std::getline(file, log);) {
log_lines.push_back(log);
}
std::vector<std::string> expected = {
"[net] foo7: bar7",
"foo8: bar8",
"[warning] foo9: bar9",
"[error] foo10: bar10",
};
BOOST_CHECK_EQUAL_COLLECTIONS(log_lines.begin(), log_lines.end(), expected.begin(), expected.end());
}
BOOST_FIXTURE_TEST_CASE(logging_LogPrintMacros_CategoryName, LogSetup)
{
LogInstance().EnableCategory(BCLog::LogFlags::ALL);
const auto concatenated_category_names = LogInstance().LogCategoriesString();
std::vector<std::pair<BCLog::LogFlags, std::string>> expected_category_names;
const auto category_names = SplitString(concatenated_category_names, ',');
for (const auto& category_name : category_names) {
BCLog::LogFlags category;
const auto trimmed_category_name = TrimString(category_name);
BOOST_REQUIRE(GetLogCategory(category, trimmed_category_name));
expected_category_names.emplace_back(category, trimmed_category_name);
}
std::vector<std::string> expected;
for (const auto& [category, name] : expected_category_names) {
LogPrint(category, "foo: %s\n", "bar");
std::string expected_log = "[";
expected_log += name;
expected_log += "] foo: bar";
expected.push_back(expected_log);
}
std::ifstream file{tmp_log_path};
std::vector<std::string> log_lines;
for (std::string log; std::getline(file, log);) {
log_lines.push_back(log);
}
BOOST_CHECK_EQUAL_COLLECTIONS(log_lines.begin(), log_lines.end(), expected.begin(), expected.end());
}
BOOST_FIXTURE_TEST_CASE(logging_SeverityLevels, LogSetup)
{
LogInstance().EnableCategory(BCLog::LogFlags::ALL);
LogInstance().SetLogLevel(BCLog::Level::Debug);
LogInstance().SetCategoryLogLevel(/*category_str=*/"net", /*level_str=*/"info");
// Global log level
LogPrintLevel(BCLog::HTTP, BCLog::Level::Info, "foo1: %s\n", "bar1");
LogPrintLevel(BCLog::MEMPOOL, BCLog::Level::Trace, "foo2: %s. This log level is lower than the global one.\n", "bar2");
LogPrintLevel(BCLog::VALIDATION, BCLog::Level::Warning, "foo3: %s\n", "bar3");
LogPrintLevel(BCLog::RPC, BCLog::Level::Error, "foo4: %s\n", "bar4");
// Category-specific log level
LogPrintLevel(BCLog::NET, BCLog::Level::Warning, "foo5: %s\n", "bar5");
LogPrintLevel(BCLog::NET, BCLog::Level::Debug, "foo6: %s. This log level is the same as the global one but lower than the category-specific one, which takes precedence. \n", "bar6");
LogPrintLevel(BCLog::NET, BCLog::Level::Error, "foo7: %s\n", "bar7");
std::vector<std::string> expected = {
"[http:info] foo1: bar1",
"[validation:warning] foo3: bar3",
"[rpc:error] foo4: bar4",
"[net:warning] foo5: bar5",
"[net:error] foo7: bar7",
};
std::ifstream file{tmp_log_path};
std::vector<std::string> log_lines;
for (std::string log; std::getline(file, log);) {
log_lines.push_back(log);
}
BOOST_CHECK_EQUAL_COLLECTIONS(log_lines.begin(), log_lines.end(), expected.begin(), expected.end());
}
BOOST_FIXTURE_TEST_CASE(logging_Conf, LogSetup)
{
// Set global log level
{
ResetLogger();
ArgsManager args;
args.AddArg("-loglevel", "...", ArgsManager::ALLOW_ANY, OptionsCategory::DEBUG_TEST);
const char* argv_test[] = {"bitcoind", "-loglevel=debug"};
std::string err;
BOOST_REQUIRE(args.ParseParameters(2, argv_test, err));
auto result = init::SetLoggingLevel(args);
BOOST_REQUIRE(result);
BOOST_CHECK_EQUAL(LogInstance().LogLevel(), BCLog::Level::Debug);
}
// Set category-specific log level
{
ResetLogger();
ArgsManager args;
args.AddArg("-loglevel", "...", ArgsManager::ALLOW_ANY, OptionsCategory::DEBUG_TEST);
const char* argv_test[] = {"bitcoind", "-loglevel=net:trace"};
std::string err;
BOOST_REQUIRE(args.ParseParameters(2, argv_test, err));
auto result = init::SetLoggingLevel(args);
BOOST_REQUIRE(result);
BOOST_CHECK_EQUAL(LogInstance().LogLevel(), BCLog::DEFAULT_LOG_LEVEL);
const auto& category_levels{LogInstance().CategoryLevels()};
const auto net_it{category_levels.find(BCLog::LogFlags::NET)};
BOOST_REQUIRE(net_it != category_levels.end());
BOOST_CHECK_EQUAL(net_it->second, BCLog::Level::Trace);
}
// Set both global log level and category-specific log level
{
ResetLogger();
ArgsManager args;
args.AddArg("-loglevel", "...", ArgsManager::ALLOW_ANY, OptionsCategory::DEBUG_TEST);
const char* argv_test[] = {"bitcoind", "-loglevel=debug", "-loglevel=net:trace", "-loglevel=http:info"};
std::string err;
BOOST_REQUIRE(args.ParseParameters(4, argv_test, err));
auto result = init::SetLoggingLevel(args);
BOOST_REQUIRE(result);
BOOST_CHECK_EQUAL(LogInstance().LogLevel(), BCLog::Level::Debug);
const auto& category_levels{LogInstance().CategoryLevels()};
BOOST_CHECK_EQUAL(category_levels.size(), 2);
const auto net_it{category_levels.find(BCLog::LogFlags::NET)};
BOOST_CHECK(net_it != category_levels.end());
BOOST_CHECK_EQUAL(net_it->second, BCLog::Level::Trace);
const auto http_it{category_levels.find(BCLog::LogFlags::HTTP)};
BOOST_CHECK(http_it != category_levels.end());
BOOST_CHECK_EQUAL(http_it->second, BCLog::Level::Info);
}
}
BOOST_AUTO_TEST_SUITE_END()