-
Notifications
You must be signed in to change notification settings - Fork 38.8k
logging: threshold log level #25287
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
logging: threshold log level #25287
Conversation
|
Concept ACK. I'm glad to see a category-specific config option. These should probably be added to the logging RPC as well in a follow-up. |
e1ce4a9 to
2091d52
Compare
|
The following sections might be updated with supplementary metadata relevant to reviewers and maintainers. ConflictsReviewers, this pull request conflicts with the following ones:
If you consider this pull request important, please also help to review the conflicting pull requests. Ideally, start with the one that should be merged first. |
2091d52 to
9536dc1
Compare
9536dc1 to
63f6957
Compare
|
Concept ACK, this is more or less what I had in mind.
Yep! |
src/logging.cpp
Outdated
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
In the first commit, find() on a std::unordered_set has constant-to-linear (size of the container) complexity, whereas if you build a std::array instead, access with [] or .at will be constant time (and the array can be constexpr; git grep the codebase for "constexpr std::array" for examples).
nit suggestion
- if (it == LogCategoryToStr.end()) {
- s += "unknown";
- } else {
- s += it->second;
- }
+ s += it == LogCategoryToStr.end() ? "unknown" : it->second;There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I am not really sure how to do that.
LogCategory enum values are bit flags (ie 1 << i) with the exception of None (0) and All(~0) instead of the default enum values (ie 0,1,2,..,n-1) that easily correspond to indexes of an array.
Some solutions I can think of:
- Refactor
LogCategoryuse the default enum values (ie0,1,...) and create another helper function (ieLogCategoryToFlag(flag){ return 1 << flag;} - Create a custom hash function for
LogCategoryToStrunordered_mapthat returns a unique hash value for each enum value. This will guarantee that thefind()will execute in constant time.- Hash function could possibly be
flag % SOME_PRIME.
- Hash function could possibly be
However, I am not too sure if this additional complexity is worth it as the size of LogCategoryToStr is bounded
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Resolved the nit 👍🏻
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Thanks for looking into it! I guess at some point this might be refactored but doesn't necessarily need to be done here.
src/logging.cpp
Outdated
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
In the first commit, a few suggestions
@@ -138,7 +138,7 @@ struct CLogCategoryDesc {
}
};
-const CLogCategoryDesc LogCategories[]{
+static CLogCategoryDesc LogCategories[]{
{BCLog::NONE, "none"},
{BCLog::NET, "net"},
{BCLog::TOR, "tor"},
@@ -174,10 +174,10 @@ const CLogCategoryDesc LogCategories[]{
{BCLog::ALL, "1"},
};
-// Ignore last 2 extra mappings of NONE and ALL.
-const std::unordered_map<BCLog::LogFlags, std::string> LogCategoryToStr{
+static std::unordered_map<BCLog::LogFlags, std::string> LogCategoryToStr{
LogCategories,
- LogCategories + std::size(LogCategories) - 2};
+ LogCategories + std::size(LogCategories) - 2 // ignore last 2 extra mappings of NONE and ALL
+};There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Wouldn't it make sense to do it the other way around?
First build LogCategoryToStr, then build LogCategoryDesc from that, adding the ALL=1 and NONE=0 instead of cutting them off. I think that's neater and less error prone.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
In the first commit, a few suggestions
Done 👍🏻
First build LogCategoryToStr, then build LogCategoryDesc from that, adding the ALL=1 and NONE=0 instead of cutting them off. I think that's neater and less error prone.
Agreed, building LogCategories from LogCategoryToStr is definitely cleaner!
However, I am unable to think of a trivial method to implement it as currently both LogCategories and LogCategoryToStr are global variables where the values are added in its constructor. To build LogCategories from LogCategoryToStr, we will most probably need to change LogCategories type from an array to a class that allows us to add our own construction logic (build from LogCategoryToStr and add ALL=1 and NONE=0).
If changing LogCategories to a class is the desired approach, I will split the first commit into a separate PR.
src/logging.cpp
Outdated
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Suggestions:
- order the params by in-param, then out-param
- pass the string in-param by reference to const rather than by value
- return a std::optional here instead of bool with a level out-param
- use a switch statement (with no default case, grep doc/developer-notes.md for "
switchstatement on an enumeration example") - function can be
staticand is missing a line break before
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Done, went with the return std::optional suggestion.
use a switch statement (with no default case, grep doc/developer-notes.md for "switch statement on an enumeration example")
I am unable to use a switch statement with level_str. If I am not wrong, c++ only allows switch statements with integral types and enumerators.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Oops, yes, you're right about switch statements.
|
I tested these commits cherry-picked on top of #25203 and it seems to be working fine, modulo the comments above. |
a68df86 to
81715dd
Compare
- Ignore logs that have lower severity than the threshold level - Allow users to specify the global level and category specific level through bitcoind arguements
81715dd to
05ee8a9
Compare
|
@jonatack thanks for the detailed review! Addressed your comments in the latest commit. |
jonatack
left a comment
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Tested, a few more suggestions.
| Tools and Utilities | ||
| ------------------- | ||
|
|
||
| - Allow configuration of global and category specific threshold log levels. (#25287) |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Suggestion:
-- Allow configuration of global and category specific threshold log levels. (#25287)
+- A new `-loglevel` configuration option allows setting global and per-category
+ log severity levels: error, warning, info, debug (default: info). (#25287)(This entry doesn't seem likely to cause a merge conflict, so it can probably be added directly to doc/release-notes.md)
| ArgsManager::ALLOW_ANY, OptionsCategory::DEBUG_TEST); | ||
| argsman.AddArg("-debugexclude=<category>", "Exclude debugging information for a category. Can be used in conjunction with -debug=1 to output debug logs for all categories except the specified category. This option can be specified multiple times to exclude multiple categories.", ArgsManager::ALLOW_ANY, OptionsCategory::DEBUG_TEST); | ||
| argsman.AddArg("-logips", strprintf("Include IP addresses in debug output (default: %u)", DEFAULT_LOGIPS), ArgsManager::ALLOW_ANY, OptionsCategory::DEBUG_TEST); | ||
| argsman.AddArg("-loglevel=<level>|<category>:<level>", strprintf("Set the global or per-category logging severity level; log messages of lower severity will not be printed to the debug log (default=%s). If <category>:<level> is supplied, the setting will override the global one. <category> can be: %s, <level> can be: %s. This option may be specified multiple times to set multiple category-specific levels.", BCLog::LogLevelToStr(BCLog::DEFAULT_LOG_LEVEL), LogInstance().LogCategoriesString(), LogInstance().LogLevelsString()), ArgsManager::DISALLOW_NEGATION | ArgsManager::DISALLOW_ELISION, OptionsCategory::DEBUG_TEST); |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Second iteration on this to hopefully make it shorter and clearer while providing the log levels at the start
| argsman.AddArg("-loglevel=<level>|<category>:<level>", strprintf("Set the global or per-category logging severity level; log messages of lower severity will not be printed to the debug log (default=%s). If <category>:<level> is supplied, the setting will override the global one. <category> can be: %s, <level> can be: %s. This option may be specified multiple times to set multiple category-specific levels.", BCLog::LogLevelToStr(BCLog::DEFAULT_LOG_LEVEL), LogInstance().LogCategoriesString(), LogInstance().LogLevelsString()), ArgsManager::DISALLOW_NEGATION | ArgsManager::DISALLOW_ELISION, OptionsCategory::DEBUG_TEST); | |
| argsman.AddArg("-loglevel=<level>|<category>:<level>", strprintf("Set the global or per-category logging severity level: %s (default=%s). If <category>:<level> is supplied, the setting will override the global one and may be specified multiple times to set multiple category-specific levels. <category> can be: %s.", LogInstance().LogLevelsString(), BCLog::LogLevelToStr(BCLog::DEFAULT_LOG_LEVEL), LogInstance().LogCategoriesString()), ArgsManager::DISALLOW_NEGATION | ArgsManager::DISALLOW_ELISION, OptionsCategory::DEBUG_TEST); |
$ ./src/bitcoind -h | grep -A9 loglevel
-loglevel=<level>|<category>:<level>
Set the global or per-category logging severity level: debug, none,
info, warning, error (default=info). If <category>:<level> is
supplied, the setting will override the global one and may be
specified multiple times to set multiple category-specific
levels. <category> can be: addrman, bench, blockstorage,
cmpctblock, coindb, estimatefee, http, i2p, ipc, leveldb,
libevent, lock, mempool, mempoolrej, net, proxy, prune, qt, rand,
reindex, rpc, selectcoins, tor, util, validation, walletdb, zmq.
| if (loglevel.find_first_of(':', 3) == std::string::npos) { | ||
| // user passed a global log level (-loglevel=<level>) | ||
| if (!LogInstance().SetLogLevel(loglevel)) { | ||
| InitWarning(strprintf(_("Unsupported global threshold logging level provided -loglevel=%s. Valid values: debug, none, info, warning, error."), loglevel)); |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
| InitWarning(strprintf(_("Unsupported global threshold logging level provided -loglevel=%s. Valid values: debug, none, info, warning, error."), loglevel)); | |
| InitWarning(strprintf(_("Unsupported global logging level -loglevel=%s. Valid values: %s"), loglevel, LogInstance().LogLevelsString())); |
| // user passed a category-specific log level (-loglevel=<category>:<level>) | ||
| const auto toks = SplitString(loglevel, ':'); | ||
| if (!(toks.size() == 2 && LogInstance().SetCategoryLogLevel(toks[0], toks[1]))) { | ||
| InitWarning(strprintf(_("Unsupported category-specific logging level provided -loglevel=%s. Expected -loglevel=<category>:<loglevel>."), loglevel)); |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
| InitWarning(strprintf(_("Unsupported category-specific logging level provided -loglevel=%s. Expected -loglevel=<category>:<loglevel>."), loglevel)); | |
| InitWarning(strprintf(_("Unsupported category-specific logging level -loglevel=%s. Expected -loglevel=<category>:<loglevel>"), loglevel)); |
|
|
||
| std::vector<BCLog::Level> BCLog::Logger::LogLevelsList() const | ||
| { | ||
| return {BCLog::Level::Debug, BCLog::Level::None, BCLog::Level::Info, BCLog::Level::Warning, BCLog::Level::Error}; |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
It might be better to construct this vector programmatically to have a single point of truth, i.e. BCLog::Level.
| * If there is no category-specific threshold log level, all logs with severity level lower than | ||
| * m_threshold_level will be ignored. | ||
| */ | ||
| Level m_threshold_level{Level::Info}; |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I'd find this data member naming clearer as m_severity_level or m_log_level (I prefer the latter), maybe that is just me.
mzumsande
left a comment
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I didn't deeply review the code yet, but I tested this a little bit.
# global log level = debug $ ./src/bitcoind -signet -loglevel=debug $ grep -o "net:debug" ~/.bitcoin/signet/debug.log | wc -l 4
-
This didn't work for me; the new
-logleveloption seems to be completely ineffective unless I also specify a category, e.g.-debug=all. Not sure if this is expected, but it's not clear to me from the-logleveldocumentation. -
Warnings are unconditionally logged, even if I specify
-loglevel=error -debug=all. This is not what I would have expected from the documentation.
More generally, it is a bit confusing that there is a global threshold>= warningthat applies even if no-debug=XXXwas specified, and in addition a default threshold>= infoif-debug=XXXwas specified. I guess it could make sense in order to have specialised logging that does not create huge logfiles, but it is a change from the old behavior that if a user chooses a category, everything from that is logged by default.
|
Thanks for looking @mzumsande. The discussion in #25306 might be helpful, as well as testing this on top of #25203. FWIW I discussed this pull offline with @klementtan; he is busy right now with a new job and I'm continuing his work with a new pull. |
|
Pulled the commits here into #25203, updated with review feedback, some clean-up, and moving the refactoring commits to after the functional ones. Will continue with sub-PRs from that parent. |
9580480 Update debug logging section in the developer notes (Jon Atack) 1abaa31 Update -debug and -debugexclude help docs for severity level logging (Jon Atack) 45f9282 Create BCLog::Level::Trace log severity level (Jon Atack) 2a8712d Unit test coverage for -loglevel configuration option (klementtan) eb7bee5 Create -loglevel configuration option (klementtan) 98a1f9c Unit test coverage for log severity levels (klementtan) 9c7507b Create BCLog::Logger::LogLevelsString() helper function (klementtan) 8fe3457 Update LogAcceptCategory() and unit tests with log severity levels (klementtan) c2797cf Add BCLog::Logger::SetLogLevel()/SetCategoryLogLevel() for string inputs (klementtan) f6c0cc0 Add BCLog::Logger::m_category_log_levels data member and getter/setter (Jon Atack) 2978b38 Add BCLog::Logger::m_log_level data member and getter/setter (Jon Atack) f1379ae Simplify BCLog::Level enum class and LogLevelToStr() function (Jon Atack) Pull request description: This is an updated version of bitcoin/bitcoin#25287 and the next steps in parent PR #25203 implementing, with Klement Tan, user-configurable, per-category severity log levels based on an idea by John Newbery and refined in GitHub discussions by Wladimir Van der Laan and Marco Falke. - simplify the `BCLog::Level` enum class and the `LogLevelToStr()` function and add documentation - update the logging logic to filter logs by log level both globally and per-category - add a hidden `-loglevel` help-debug config option to allow testing setting the global or per-category severity level on startup for logging categories enabled with the `-debug` configuration option or the logging RPC (Klement Tan) - add a `trace` log severity level selectable by the user; the plan is for the current debug messages to become trace, LogPrint ones to become debug, and LogPrintf ones to become info, warning, or error ``` $ ./src/bitcoind -help-debug | grep -A10 loglevel -loglevel=<level>|<category>:<level> Set the global or per-category severity level for logging categories enabled with the -debug configuration option or the logging RPC: info, debug, trace (default=info); warning and error levels are always logged. If <category>:<level> is supplied, the setting will override the global one and may be specified multiple times to set multiple category-specific levels. <category> can be: addrman, bench, blockstorage, cmpctblock, coindb, estimatefee, http, i2p, ipc, leveldb, libevent, lock, mempool, mempoolrej, net, proxy, prune, qt, rand, reindex, rpc, selectcoins, tor, util, validation, walletdb, zmq. ``` See the individual commit messages for details. ACKs for top commit: jonatack: One final push per `git range-diff a5d5569 ce3c4c9 9580480` (should be trivial to re-ACK) to ensure this pull changes no default behavior in any way for users or the tests/CI in order to be completely v24 compatible, to update the unit test setup in general, and to update the debug logging section in the developer notes. klementtan: reACK bitcoin/bitcoin@9580480 1440000bytes: reACK bitcoin/bitcoin@9580480 vasild: ACK 9580480 dunxen: reACK 9580480 brunoerg: reACK 9580480 Tree-SHA512: 476a638e0581f40b5d058a9992691722e8b546471ec85e07cbc990798d1197fbffbd02e1b3d081b4978404e07a428378cdc8e159c0004b81f58be7fb01b7cba0
Overview: This PR allows logs below the threshold severity level to be ignored (a continuation of #24464).
Notable changes:
LogCategoryToStrandLogCategories(addresses logging: Add severity level to logs #24464 (comment))Levels::info)-loglevel=<level>(ie:-loglevel=warning)-loglevel=<category>:<level>(ie:-loglevel=net:warning)Testing:
Global log level: