Skip to content

Commit

Permalink
logging: add LogError, LogWarning, LogInfo, LogDebug, LogTrace
Browse files Browse the repository at this point in the history
These provide simple and clear ways to write the most common logging
operations:

    LogInfo("msg");
    LogDebug(BCLog::LogFlags::NET, "msg");

    LogError("msg");
    LogWarning("msg");
    LogTrace(BCLog::LogFlags::NET, "msg");

For cases where the level cannot be hardcoded, LogPrintLevel(category,
level, ...) remains available.
  • Loading branch information
ajtowns committed Dec 15, 2023
1 parent fbd7642 commit e50934f
Show file tree
Hide file tree
Showing 4 changed files with 78 additions and 6 deletions.
42 changes: 40 additions & 2 deletions doc/developer-notes.md
Original file line number Diff line number Diff line change
Expand Up @@ -723,6 +723,44 @@ General Bitcoin Core
- *Explanation*: If the test suite is to be updated for a change, this has to
be done first.

Logging
-------

The macros `LogInfo`, `LogDebug`, `LogTrace`, `LogWarning` and `LogError` are available for
logging messages. They should be used as follows:

- `LogDebug(BCLog::CATEGORY, fmt, params...)` is what you want
most of the time, and it should be used for log messages that are
useful for debugging and can reasonably be enabled on a production
system (that has sufficient free storage space). They will be logged
if bitcoind is started with `-debug=category` or `-debug=1`.

- `LogInfo(fmt, params...)` should only be used rarely, eg for startup
messages or for infrequent and important events such as a new block
tip being found or a new outbound connection being made. These log
messages are unconditional so care must be taken that they can't be
used by an attacker to fill up storage.

- `LogError(fmt, params...)` should be used in place of `LogInfo` for
severe problems that require the node (or a subsystem) to shut down
entirely (eg, insufficient storage space).

- `LogWarning(fmt, params...)` should be used in place of `LogInfo` for
severe problems that the node admin should address, but are not
severe enough to warrant shutting down the node (eg, system time
appears to be wrong, unknown soft fork appears to have activated).

- `LogTrace(BCLog::CATEGORY, fmt, params...) should be used in place of
`LogDebug` for log messages that would be unusable on a production
system, eg due to being too noisy in normal use, or too resource
intensive to process. These will be logged if the startup
options `-debug=category -loglevel=category:trace` or `-debug=1
-loglevel=trace` are selected.

Note that the format strings and parameters of `LogDebug` and `LogTrace`
are only evaluated if the logging category is enabled, so you must be
careful to avoid side-effects in those expressions.

Wallet
-------

Expand Down Expand Up @@ -891,7 +929,7 @@ Strings and formatting
`wcstoll`, `wcstombs`, `wcstoul`, `wcstoull`, `wcstoumax`, `wcswidth`,
`wcsxfrm`, `wctob`, `wctomb`, `wctrans`, `wctype`, `wcwidth`, `wprintf`
- For `strprintf`, `LogPrint`, `LogPrintf` formatting characters don't need size specifiers.
- For `strprintf`, `LogInfo`, `LogDebug`, etc formatting characters don't need size specifiers.
- *Rationale*: Bitcoin Core uses tinyformat, which is type safe. Leave them out to avoid confusion.
Expand All @@ -903,7 +941,7 @@ Strings and formatting
- *Rationale*: Although this is guaranteed to be safe starting with C++11, `.data()` communicates the intent better.
- Do not use it when passing strings to `tfm::format`, `strprintf`, `LogPrint[f]`.
- Do not use it when passing strings to `tfm::format`, `strprintf`, `LogInfo`, `LogDebug`, etc.
- *Rationale*: This is redundant. Tinyformat handles strings.
Expand Down
13 changes: 10 additions & 3 deletions src/logging.h
Original file line number Diff line number Diff line change
Expand Up @@ -237,9 +237,12 @@ static inline void LogPrintf_(const std::string& logging_function, const std::st
#define LogPrintLevel_(category, level, ...) LogPrintf_(__func__, __FILE__, __LINE__, category, level, __VA_ARGS__)

// Log unconditionally.
#define LogPrintf(...) LogPrintLevel_(BCLog::LogFlags::NONE, BCLog::Level::Info, __VA_ARGS__)
#define LogInfo(...) LogPrintLevel_(BCLog::LogFlags::ALL, BCLog::Level::Info, __VA_ARGS__)
#define LogWarning(...) LogPrintLevel_(BCLog::LogFlags::ALL, BCLog::Level::Warning, __VA_ARGS__)
#define LogError(...) LogPrintLevel_(BCLog::LogFlags::ALL, BCLog::Level::Error, __VA_ARGS__)

// Log unconditionally, prefixing the output with the passed category name.
// Deprecated unconditional logging.
#define LogPrintf(...) LogInfo(__VA_ARGS__)
#define LogPrintfCategory(category, ...) LogPrintLevel_(category, BCLog::Level::Info, __VA_ARGS__)

// Use a macro instead of a function for conditional logging to prevent
Expand All @@ -254,7 +257,11 @@ static inline void LogPrintf_(const std::string& logging_function, const std::st
} while (0)

// Log conditionally, prefixing the output with the passed category name.
#define LogPrint(category, ...) LogPrintLevel(category, BCLog::Level::Debug, __VA_ARGS__)
#define LogDebug(category, ...) LogPrintLevel(category, BCLog::Level::Debug, __VA_ARGS__)
#define LogTrace(category, ...) LogPrintLevel(category, BCLog::Level::Trace, __VA_ARGS__)

// Deprecated conditional logging
#define LogPrint(category, ...) LogDebug(category, __VA_ARGS__)

template <typename... Args>
bool error(const char* fmt, const Args&... args)
Expand Down
24 changes: 23 additions & 1 deletion src/test/logging_tests.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -105,10 +105,11 @@ BOOST_FIXTURE_TEST_CASE(logging_LogPrintf_, LogSetup)
BOOST_CHECK_EQUAL_COLLECTIONS(log_lines.begin(), log_lines.end(), expected.begin(), expected.end());
}

BOOST_FIXTURE_TEST_CASE(logging_LogPrintMacros, LogSetup)
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");
Expand All @@ -131,6 +132,27 @@ BOOST_FIXTURE_TEST_CASE(logging_LogPrintMacros, LogSetup)
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);
Expand Down
5 changes: 5 additions & 0 deletions test/lint/lint-format-strings.py
Original file line number Diff line number Diff line change
Expand Up @@ -20,6 +20,11 @@
'fprintf,1',
'tfm::format,1', # Assuming tfm::::format(std::ostream&, ...
'LogConnectFailure,1',
'LogError,0',
'LogWarning,0',
'LogInfo,0',
'LogDebug,1',
'LogTrace,1',
'LogPrint,1',
'LogPrintf,0',
'LogPrintfCategory,1',
Expand Down

0 comments on commit e50934f

Please sign in to comment.