mirror of
https://github.com/bitcoin/bitcoin.git
synced 2025-03-10 09:06:15 +01:00
197 lines
7.9 KiB
C++
197 lines
7.9 KiB
C++
// Copyright (c) 2019-2021 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 <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>
|
|
|
|
BOOST_FIXTURE_TEST_SUITE(logging_tests, BasicTestingSetup)
|
|
|
|
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)
|
|
{
|
|
SetMockTime(1);
|
|
auto micro_timer = BCLog::Timer<std::chrono::microseconds>("tests", "end_msg");
|
|
SetMockTime(2);
|
|
BOOST_CHECK_EQUAL(micro_timer.LogMsg("test micros"), "tests: test micros (1000000μs)");
|
|
|
|
SetMockTime(1);
|
|
auto ms_timer = BCLog::Timer<std::chrono::milliseconds>("tests", "end_msg");
|
|
SetMockTime(2);
|
|
BOOST_CHECK_EQUAL(ms_timer.LogMsg("test ms"), "tests: test ms (1000.00ms)");
|
|
|
|
SetMockTime(1);
|
|
auto sec_timer = BCLog::Timer<std::chrono::seconds>("tests", "end_msg");
|
|
SetMockTime(2);
|
|
BOOST_CHECK_EQUAL(sec_timer.LogMsg("test secs"), "tests: test secs (1.00s)");
|
|
}
|
|
|
|
BOOST_FIXTURE_TEST_CASE(logging_LogPrintf_, LogSetup)
|
|
{
|
|
LogInstance().m_log_sourcelocations = true;
|
|
LogPrintf_("fn1", "src1", 1, BCLog::LogFlags::NET, BCLog::Level::Debug, "foo1: %s", "bar1\n");
|
|
LogPrintf_("fn2", "src2", 2, BCLog::LogFlags::NET, BCLog::Level::None, "foo2: %s", "bar2\n");
|
|
LogPrintf_("fn3", "src3", 3, BCLog::LogFlags::NONE, BCLog::Level::Debug, "foo3: %s", "bar3\n");
|
|
LogPrintf_("fn4", "src4", 4, BCLog::LogFlags::NONE, BCLog::Level::None, "foo4: %s", "bar4\n");
|
|
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:debug] foo1: bar1",
|
|
"[src2:2] [fn2] [net] foo2: bar2",
|
|
"[src3:3] [fn3] [debug] foo3: bar3",
|
|
"[src4:4] [fn4] foo4: bar4",
|
|
};
|
|
BOOST_CHECK_EQUAL_COLLECTIONS(log_lines.begin(), log_lines.end(), expected.begin(), expected.end());
|
|
}
|
|
|
|
BOOST_FIXTURE_TEST_CASE(logging_LogPrintMacros, LogSetup)
|
|
{
|
|
LogPrintf("foo5: %s\n", "bar5");
|
|
LogPrint(BCLog::NET, "foo6: %s\n", "bar6");
|
|
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:debug] foo7: bar7",
|
|
"[net:info] foo8: bar8",
|
|
"[net:warning] foo9: bar9",
|
|
"[net:error] foo10: bar10",
|
|
"[validation] foo11: bar11",
|
|
};
|
|
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::Info);
|
|
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::Debug, "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 lower than the category-specific one.\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_AUTO_TEST_SUITE_END()
|