log: Remove brittle and confusing LogPrintLevel

This commit is contained in:
MarcoFalke
2025-12-11 19:59:49 +01:00
parent fac24bbec8
commit fa8a5d215c
6 changed files with 25 additions and 48 deletions

View File

@@ -415,7 +415,7 @@ void Session::CreateIfNotCreatedAlready()
const auto session_type = m_transient ? "transient" : "persistent";
const auto session_id = GetRandHash().GetHex().substr(0, 10); // full is overkill, too verbose in the logs
LogDebug(BCLog::I2P, "Creating %s SAM session %s with %s\n", session_type, session_id, m_control_host.ToString());
LogDebug(BCLog::I2P, "Creating %s I2P SAM session %s with %s\n", session_type, session_id, m_control_host.ToString());
auto sock = Hello();
@@ -452,7 +452,7 @@ void Session::CreateIfNotCreatedAlready()
m_session_id = session_id;
m_control_sock = std::move(sock);
LogPrintLevel(BCLog::I2P, BCLog::Level::Info, "%s SAM session %s created, my address=%s\n",
LogInfo("%s I2P SAM session %s created, my address=%s",
Capitalize(session_type),
m_session_id,
m_my_addr.ToStringAddrPort());
@@ -483,9 +483,9 @@ void Session::Disconnect()
{
if (m_control_sock) {
if (m_session_id.empty()) {
LogPrintLevel(BCLog::I2P, BCLog::Level::Info, "Destroying incomplete SAM session\n");
LogInfo("Destroying incomplete I2P SAM session");
} else {
LogPrintLevel(BCLog::I2P, BCLog::Level::Info, "Destroying SAM session %s\n", m_session_id);
LogInfo("Destroying I2P SAM session %s", m_session_id);
}
m_control_sock.reset();
}

View File

@@ -9,6 +9,7 @@
#include <crypto/siphash.h>
#include <threadsafety.h>
#include <tinyformat.h>
#include <util/check.h>
#include <util/fs.h>
#include <util/string.h>
#include <util/time.h>
@@ -372,22 +373,20 @@ inline void LogPrintFormatInternal(std::source_location&& source_loc, BCLog::Log
// Use a macro instead of a function for conditional logging to prevent
// evaluating arguments when logging for the category is not enabled.
// Log by prefixing the output with the passed category name and severity level. This can either
// log conditionally if the category is allowed or unconditionally if level >= BCLog::Level::Info
// is passed. If this function logs unconditionally, logging to disk is rate-limited. This is
// important so that callers don't need to worry about accidentally introducing a disk-fill
// vulnerability if level >= Info is used. Additionally, users specifying -debug are assumed to be
// Log by prefixing the output with the passed category name and severity level. This logs conditionally if
// the category is allowed. No rate limiting is applied, because users specifying -debug are assumed to be
// developers or power users who are aware that -debug may cause excessive disk usage due to logging.
#define LogPrintLevel(category, level, ...) \
#define detail_LogIfCategoryAndLevelEnabled(category, level, ...) \
do { \
if (LogAcceptCategory((category), (level))) { \
bool rate_limit{level >= BCLog::Level::Info}; \
Assume(!rate_limit);/*Only called with the levels below*/ \
LogPrintLevel_(category, level, rate_limit, __VA_ARGS__); \
} \
} while (0)
// Log conditionally, prefixing the output with the passed category name.
#define LogDebug(category, ...) LogPrintLevel(category, BCLog::Level::Debug, __VA_ARGS__)
#define LogTrace(category, ...) LogPrintLevel(category, BCLog::Level::Trace, __VA_ARGS__)
#define LogDebug(category, ...) detail_LogIfCategoryAndLevelEnabled(category, BCLog::Level::Debug, __VA_ARGS__)
#define LogTrace(category, ...) detail_LogIfCategoryAndLevelEnabled(category, BCLog::Level::Trace, __VA_ARGS__)
#endif // BITCOIN_LOGGING_H

View File

@@ -47,7 +47,7 @@ static void ProcessPCP()
// Local functor to handle result from PCP/NATPMP mapping.
auto handle_mapping = [&](std::variant<MappingResult, MappingError> &res) -> void {
if (MappingResult* mapping = std::get_if<MappingResult>(&res)) {
LogPrintLevel(BCLog::NET, BCLog::Level::Info, "portmap: Added mapping %s\n", mapping->ToString());
LogInfo("portmap: Added mapping %s", mapping->ToString());
AddLocal(mapping->external, LOCAL_MAPPED);
ret = true;
actual_lifetime = std::min(actual_lifetime, mapping->lifetime);

View File

@@ -56,7 +56,7 @@ BOOST_AUTO_TEST_CASE(unlimited_recv)
i2p::sam::Session session(gArgs.GetDataDirNet() / "test_i2p_private_key", sam_proxy, interrupt);
{
ASSERT_DEBUG_LOG("Creating persistent SAM session");
ASSERT_DEBUG_LOG("Creating persistent I2P SAM session");
ASSERT_DEBUG_LOG("too many bytes without a terminator");
i2p::Connection conn;
@@ -121,10 +121,10 @@ BOOST_AUTO_TEST_CASE(listen_ok_accept_fail)
i2p::Connection conn;
for (size_t i = 0; i < 5; ++i) {
ASSERT_DEBUG_LOG("Creating persistent SAM session");
ASSERT_DEBUG_LOG("Persistent SAM session" /* ... created */);
ASSERT_DEBUG_LOG("Creating persistent I2P SAM session");
ASSERT_DEBUG_LOG("Persistent I2P SAM session" /* ... created */);
ASSERT_DEBUG_LOG("Error accepting");
ASSERT_DEBUG_LOG("Destroying SAM session");
ASSERT_DEBUG_LOG("Destroying I2P SAM session");
BOOST_REQUIRE(session.Listen(conn));
BOOST_REQUIRE(!session.Accept(conn));
}
@@ -161,7 +161,7 @@ BOOST_AUTO_TEST_CASE(damaged_private_key)
i2p::sam::Session session(i2p_private_key_file, sam_proxy, interrupt);
{
ASSERT_DEBUG_LOG("Creating persistent SAM session");
ASSERT_DEBUG_LOG("Creating persistent I2P SAM session");
ASSERT_DEBUG_LOG(expected_error);
i2p::Connection conn;

View File

@@ -139,24 +139,6 @@ BOOST_FIXTURE_TEST_CASE(logging_LogPrintStr, LogSetup)
BOOST_CHECK_EQUAL_COLLECTIONS(log_lines.begin(), log_lines.end(), expected.begin(), expected.end());
}
BOOST_FIXTURE_TEST_CASE(logging_LogPrintMacrosDeprecated, LogSetup)
{
LogInstance().EnableCategory(BCLog::NET);
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");
std::vector<std::string> log_lines{ReadDebugLogLines()};
std::vector<std::string> expected{
"[net] foo7: bar7",
"[net:info] foo8: bar8",
"[net:warning] foo9: bar9",
"[net:error] foo10: bar10",
};
BOOST_CHECK_EQUAL_COLLECTIONS(log_lines.begin(), log_lines.end(), expected.begin(), expected.end());
}
BOOST_FIXTURE_TEST_CASE(logging_LogPrintMacros, LogSetup)
{
LogInstance().EnableCategory(BCLog::NET);
@@ -208,24 +190,20 @@ BOOST_FIXTURE_TEST_CASE(logging_SeverityLevels, LogSetup)
LogInstance().SetCategoryLogLevel(/*category_str=*/"net", /*level_str=*/"info");
// Global log level
LogPrintLevel(BCLog::HTTP, BCLog::Level::Info, "foo1: %s\n", "bar1");
LogInfo("info_%s", 1);
LogTrace(BCLog::HTTP, "trace_%s. This log level is lower than the global one.", 2);
LogDebug(BCLog::HTTP, "debug_%s", 3);
LogPrintLevel(BCLog::VALIDATION, BCLog::Level::Warning, "foo3: %s\n", "bar3");
LogPrintLevel(BCLog::RPC, BCLog::Level::Error, "foo4: %s\n", "bar4");
LogWarning("warn_%s", 4);
LogError("err_%s", 5);
// Category-specific log level
LogPrintLevel(BCLog::NET, BCLog::Level::Warning, "foo5: %s\n", "bar5");
LogDebug(BCLog::NET, "debug_%s. This log level is the same as the global one but lower than the category-specific one, which takes precedence.", 6);
LogPrintLevel(BCLog::NET, BCLog::Level::Error, "foo7: %s\n", "bar7");
std::vector<std::string> expected = {
"[http:info] foo1: bar1",
"info_1",
"[http] debug_3",
"[validation:warning] foo3: bar3",
"[rpc:error] foo4: bar4",
"[net:warning] foo5: bar5",
"[net:error] foo7: bar7",
"[warning] warn_4",
"[error] err_5",
};
std::vector<std::string> log_lines{ReadDebugLogLines()};
BOOST_CHECK_EQUAL_COLLECTIONS(log_lines.begin(), log_lines.end(), expected.begin(), expected.end());

View File

@@ -23,12 +23,12 @@ class I2PSessions(BitcoinTestFramework):
self.log.info("Ensure we create a persistent session when -i2pacceptincoming=1")
node0 = self.nodes[0]
with node0.assert_debug_log(expected_msgs=["Creating persistent SAM session"]):
with node0.assert_debug_log(expected_msgs=["Creating persistent I2P SAM session"]):
node0.addnode(node=addr, command="onetry")
self.log.info("Ensure we create a transient session when -i2pacceptincoming=0")
node1 = self.nodes[1]
with node1.assert_debug_log(expected_msgs=["Creating transient SAM session"]):
with node1.assert_debug_log(expected_msgs=["Creating transient I2P SAM session"]):
node1.addnode(node=addr, command="onetry")