-
Notifications
You must be signed in to change notification settings - Fork 36.6k
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
Severity-based logging, step 2 #25614
Conversation
🕵️ @harding has been requested to review this pull request as specified in the REVIEWERS file. |
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. |
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.
Approach ACK and crACK 5326f46 (except for some minor comments)
5326f46
to
9405e02
Compare
Updated with review feedack by @klementtan (thanks!) per |
9405e02
to
706805d
Compare
Code review ACK and tested ACK 706805d Testing: # Absence of debug log when loglevel=INFO
$ ./src/bitcoind -signet -loglevel=info
$ grep -o "net:debug" ~/.bitcoin/signet/debug.log | wc -l
0
# Debug log present when loglevel=DEBUG
$ ./src/bitcoind -signet -loglevel=debug
$ grep -o "net:debug" ~/.bitcoin/signet/debug.log | wc -l
2
# Category-specific log level. loglevel=net:info
$ ./src/bitcoind -signet -loglevel=net:info
Bitcoin Core starting
$ grep -o "net:debug" ~/.bitcoin/signet/debug.log | wc -l
0 |
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.
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.
Code looks good but I think this is missing some documentation on how -loglevel
and -debug
relate to each other. Otherwise I think some users may be confused.
d50fd76
to
3b777e3
Compare
Updated to address @fjahr's #25614 (review) suggestion in the -loglevel help with
|
3b777e3
to
63215dd
Compare
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.
utACK 63215dd
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.
Code review and tested ACK 63215dd
I tried a few categories and global log levels and saw expected output in logs.
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.
crACK 63215dd
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.
tACK 63215dd
LGTM
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.
Since the new log level Trace
is unused outside of tests, is it assumed that some of the existent Debug
log messages can/should be converted to Trace
, or is it that just newly added logging will be using Trace
?
Out of the scope of this PR: -debug=
should be renamed to -log=
, I guess, because now it could be confusing with the exposed levels. E.g. -debug=net -loglevel=net:info
looks self-contradictory to me - is it going to log >=debug
(due to -debug=net
) or >=info
due to loglevel=net:info
?
Generally, the current debug messages become trace, LogPrint ones become debug, and LogPrintf ones become info, warning, or error (discussion in #25306). Edit: added this info to the pull description. |
63215dd
to
b99dc23
Compare
7aa7576
to
9580480
Compare
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.
reACK 9580480
@vasild, @dunxen, @brunoerg, @w0xlt, @jarolrod, @mzumsande, @klementtan mind having a last look here? |
Given that this is primarily for devs, is there a reason to ship this in 24.0 this late before the feature freeze? (Sorry if this has been discussed before, haven't read the whole discussion) |
The reason is to unblock the parent PR that has been stuck on this step for months, during which it becomes increasingly harder to maintain due to changes merged in the codebase since, as there is logging throughout the codebase. I also see refactoring PRs merged right now with much less accumulated review. This PR has been carefully reworked not to change behavior. Merging would allow review to begin on the next steps in the parent and signal that this migration may realistically happen, which would encourage continued work and review. |
If the parent PR isn't going into 24.0, it's not clear why this change would need to be merged into 24.0 to unblock it. In fact, it would seem better, if this (broader) migration is going to happen, to perform all the refactoring/changes within the same release cycle (i.e 25.0), rather than shipping some small part of it now, which has been massaged to not actually change any behaviour. |
15 accumulated ACKs but maintainers not in favor. Up for grabs. |
I am in favour of this configuration option, my question was solely about the milestone |
Pushing this back needlessly only serves to stop momentum and discourage people from investing further time working on it or reviewing it. A lot of time and effort went into it to be ready for this release and unblock progress. |
I think that was a needlessly negative comment. The changes were improvements, which is why I iterated on it, and there is no reason to change behavior yet for the few existing LogPrintLevel statements with a |
Apologies if you thought so. I was mostly referring to what you said here: "This PR has been carefully reworked not to change behavior.".
I never said they weren't. My point was that this PR initially contained (iirc) more user-facing / behaviour changes; but was then altered to not change any behaviour (except for introducing a new option), seemingly so that it could be included for 24.0. However it's still not clear (to me) why this needs to go into 24.0, especially if it's the first step in a larger (quite invasive) refactoring, which, as I mentioned above, I think if we are going to do, it would make more sense to do inside a single release cycle. Also, there's review suggestions above, such as "Rename -loglevel to -log". If this is something we might do, then why rush to merge this now, only to have to change (and maybe go through deprecating) the option name again later, when we could instead just merge this change as I understand that the parent PR might be unruly to maintain, but that's also to be expected if it's a major refactor, made up of a very large number of commits, that also touches many different areas of the codebase, including some of the most heavily trafficked (i.e p2p). |
Work began on this on March 2 with #24464 and the goal was to have it done for v24. After an initial flurry, progress has been blocked at this step (and #25586 went nowhere). If we couldn't do it for v24 after an early start, the same will be given as a reason not to move forward with later steps 6 months from now for v25, and any progress would needlessly be pushed back and discouraged.
It's odd to read "rush to merge" for this pull along with its predecessor #25287, both opened in June and having quite a lot of review. Meanwhile, less-reviewed changes, often with fix-ups needed, are merged regularly without friction. The process looks arbitrary. The suggestion you mention would only make sense if both (a) -debug were to be renamed to -log, and (b) the functionality of both -debug and -loglevel were to be combined. I am not sure there is consensus on doing both of those, nor on the resulting UX, and it's way out of scope here. Furthermore, there would be no need to create a deprecation process for a debug-only -loglevel option that would also not apply to renaming the established -debug option, if such a deprecation process exists; I have not seen one in the past years. Using hypotheticals like that as arguments to gatekeep this, with the number of ACKs and amount of review over two PRs (here and #25287) it has seen, doesn't make sense. |
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.
ACK 9580480
(in case this gets reopened)
reACK 9580480 |
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.
reACK 9580480
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.
reACK 9580480
-loglevel
configuration option and a trace
log level
Renamed and re-opened thanks to 5 re-ACKs (20 total), feature freeze postponed to Sept 1 per #24987 (comment), and numerous private messages of support (thank you). |
std::string BCLog::Logger::LogLevelsString() const | ||
{ | ||
const auto& levels = LogLevelsList(); | ||
return Join(std::vector<BCLog::Level>{levels.begin(), levels.end()}, ", ", [this](BCLog::Level level) { return LogLevelToStr(level); }); |
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.
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, will touch up in the parent (leaving unresolved until it's done).
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.
some questions
@@ -55,6 +57,26 @@ void SetLoggingOptions(const ArgsManager& args) | |||
fLogIPs = args.GetBoolArg("-logips", DEFAULT_LOGIPS); | |||
} | |||
|
|||
void SetLoggingLevel(const ArgsManager& args) | |||
{ | |||
if (args.IsArgSet("-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.
Why is this check needed, given that you set DISALLOW_NEGATION
and DISALLOW_ELISION
?
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 looks unnecessary to me, given that the entire body of the if
is a for-loop that would iterate 0 times if this check is removed and -loglevel
is not set, right? Is that true even if DISALLOW_ELISION
is not used?
{ | ||
if (args.IsArgSet("-loglevel")) { | ||
for (const std::string& level_str : args.GetArgs("-loglevel")) { | ||
if (level_str.find_first_of(':', 3) == std::string::npos) { |
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.
Where does the 3
come from?
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.
Also, if you ran SplitString
first, this check could just be if (toks.size() == 1)
?
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.
Also, if you ran
SplitString
first, this check could just beif (toks.size() == 1)
?
Thanks, will touch up in the parent.
StdLockGuard scoped_lock(m_cs); | ||
return m_category_log_levels; | ||
} | ||
void SetCategoryLogLevel(const std::unordered_map<LogFlags, Level>& levels) |
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 a fan of adding test-only code to the core codebase. This may live in the unit tests or test library.
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.
Will move it to the tests.
This is an updated version of #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.
BCLog::Level
enum class and theLogLevelToStr()
function and add documentation-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)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 errorSee the individual commit messages for details.