Skip to content

Conversation

@ryanofsky
Copy link
Contributor

@ryanofsky ryanofsky commented Jan 16, 2024

Allow LogDebug(), LogTrace(), LogInfo(), LogWarning(), and LogError() macros to accept context arguments to provide more information in log messages and more control over logging to callers.

This functionality is used in followup PRs:

  • #30342 - To let libbitcoinkernel send output to specfic BCLog::Logger instances instead of a global instance, so output can be disambiguated and applications can have more control over logging.

  • #30343 - To replace custom WalletLogPrintf calls with standard logging calls that automatically include wallet names and don't log everything at info level.

This PR does not change behavior of current log prints or require them to be updated. It includes tests and documentation covering the new functionality.


Note: Originally this PR also removed some restrictions around passing category constants to log macros to try to make them more consistent, but these changes were too controversial and have been dropped.

@DrahtBot
Copy link
Contributor

DrahtBot commented Jan 16, 2024

The following sections might be updated with supplementary metadata relevant to reviewers and maintainers.

Code Coverage & Benchmarks

For details see: https://corecheck.dev/bitcoin/bitcoin/pulls/29256.

Reviews

See the guideline for information on the review process.

Type Reviewers
Concept NACK ajtowns, hodlinator
Concept ACK sedited, jonatack

If your review is incorrectly listed, please copy-paste <!--meta-tag:bot-skip--> into the comment that the bot should ignore.

Conflicts

Reviewers, this pull request conflicts with the following ones:

  • #34088 (log: Use __func__ for -logsourcelocations by maflcko)
  • #34038 (logging: API improvements by ajtowns)

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.

LLM Linter (✨ experimental)

Possible typos and grammar issues:

  • If severity level is Info or higher, uses basic rate limiting to mitigate disk filling attacks. -> If the severity level is Info or higher, logging uses basic rate limiting to mitigate disk-filling attacks. [Missing subject and slightly awkward phrasing made the sentence grammatically incomplete; adding "the" and "logging uses" clarifies the subject and action; added hyphen in "disk-filling" for clarity.]

2025-12-16

@ajtowns
Copy link
Contributor

ajtowns commented Jan 16, 2024

Concept NACK from me, this seems much uglier and trickier to work with. I've already written in depth about why the current approach makes sense, so I'll be brief here.

Make them always accept log categories to make it possible to only log messages from a particular component.

Being able to avoid logging critical messages is adding a bug, not a feature.

Make them less verbose by not requiring BCLog category constants to be specified in individual log prints

"+841 -626" and adding a dummy parameter to most calls does not make things less verbose, and it's also much harder to search for net related logging when the individual log statements just say m_log rather than BCLog::NET.

Make them compatible with wallet logging, which includes the wallet name in log messages

The only thing needed here is renaming from Printf to Info...

@ryanofsky
Copy link
Contributor Author

ryanofsky commented Jan 17, 2024

Hi AJ, this is a draft, and there will be some more changes which may address your concerns.

Make them always accept log categories to make it possible to only log messages from a particular component.

Being able to avoid logging critical messages is adding a bug, not a feature.

Agree, but the idea here is not to discard log messages, the idea just is to attach meaningful metadata to log messages so they can be filtered by component.

Make them less verbose by not requiring BCLog category constants to be specified in individual log prints

"+841 -626" and adding a dummy parameter to most calls does not make things less verbose, and it's also much harder to search for net related logging when the individual log statements just say m_log rather than BCLog::NET.

I can probably make the description clearer, but the idea here is that this will make the code less noisy:

-LogPrintLevel(BCLog::NET, BCLog::Level::Warning, "getsockname failed\n");
+LogWarning(log, "getsockname failed\n");

It is true this sacrifices ability to grep by category constants in the source code, and maybe in your judgement that is an unacceptable cost? But in my opinion, if we ever using same category constants in disparate parts of source code, or different category constants in the same part of the source code, it means source code is badly organized and we should fix that instead of resorting to a coping mechanism of searching for constants instead of searching by source path. In my experience, I've haven't used logging frameworks that have encouraged category constants to be scattered and mixed like this, and I don't think it is a good idea.

The "+841 -626" refactoring is definitely 💩-y and I plan to drop it from this PR. The change to the log macros is meant to facilitate that refactoring, not the other way around. I do think we should stop relying on the global logging instance for libbitcoinkernel code, but probably can keep using it elsewhere.

Make them compatible with wallet logging, which includes the wallet name in log messages

The only thing needed here is renaming from Printf to Info...

Probably something is lost in communication here, but the idea is to let wallet code use same LogDebug(), LogTrace(), LogInfo(), LogWarning(), LogError() macros other code uses. It just adds a little formatting hook so the wallet name is automatically included when the log source is the wallet. This way full functionality of #29256 is available to the wallet and we can drop WalletLogPrintf and not have dedicated wallet logging functions.

@DrahtBot
Copy link
Contributor

🚧 At least one of the CI tasks failed. Make sure to run all tests locally, according to the
documentation.

Possibly this is due to a silent merge conflict (the changes in this pull request being
incompatible with the current code in the target branch). If so, make sure to rebase on the latest
commit of the target branch.

Leave a comment here, if you need help tracking down a confusing failure.

Debug: https://github.com/bitcoin/bitcoin/runs/20586125687

@ajtowns
Copy link
Contributor

ajtowns commented Jan 19, 2024

Agree, but the idea here is not to discard log messages, the idea just is to attach meaningful metadata to log messages so they can be filtered by component.

Filtering is discarding.

If you just want to find log messages, that what's grep is for, and if you want to make it more fine-grained than "hey this is an important log message/warning/error", that's what -logsourcelocations is for.

If it's any help, I think it's better to think of the sections as not related to which section of the code they appear in so much (again, that's what -logsourcelocations is for), but as a subset of the "debug" part, in that they let you filter/discard various parts of the full debug log that you would get with -debug=1.

-LogPrintLevel(BCLog::NET, BCLog::Level::Warning, "getsockname failed\n");
+LogWarning(log, "getsockname failed\n");

The current code there is noisy because it uses LogPrintLevel. The change you're actually making is:

-LogWarning("getsockname failed\n");
+LogWarning(log, "getsockname failed\n");

which is adding characters, without adding any information to the reader.

It is true this sacrifices ability to grep by category constants in the source code, and maybe in your judgement that is an unacceptable cost?

I think LogDebug(BCLog::NET, "oh no, it all went wrong\n") is better than LogDebug(m_log, "oh no, it all went wrong). All the characters in the former are doing something useful; m_log in the latter isn't (if it weren't for macro magic, we'd write m_log.Debug("...") instead, which would be okay at least). I don't think moving the category away from the line of code it's affecting is very useful; and if you want to group all the logs from an individual file together (the way putting m_log{BCLog::NET} at the top of the file/class does), then, again, that's what logsourcelocations is for...

But in my opinion, if we ever using same category constants in disparate parts of source code, or different category constants in the same part of the source code, it means source code is badly organized and we should fix that instead of resorting to a coping mechanism of searching for constants instead of searching by source path.

That's something that already happens: BCLog::NET is in timedata and headersync and banman and net and net_processing; BCLog::VALIDATION is in validation and validationinterface and flatfile (thought there was a pr to fix that one) and signet; BCLog::MEMPOOL is in txmempool, validation and net_processing. It doesn't mean the source code is badly organised, it means different parts of the source are generating related log messages.

In my experience, I've haven't used logging frameworks that have encouraged category constants to be scattered and mixed like this, and I don't think it is a good idea.

I don't think there is anything here "encouraging" these categories to be scattered or mixed; most of them are specific to a small set of related files: TOR:torcontrol, HTTP:httpserver, ZMQ:zmq/, WALLETDB:wallet/, ESTIMATEFEE:policy/fees.cpp, SELECTCOINS:wallet/coinselection, REINDEX:validation, CMPCTBLOCK:blockencodings, RAND:random.cpp, etc.

And you obviously have worked with code designed this way: that's how LogPrint has worked in this codebase since it was implemented in #3009.

Probably something is lost in communication here, but the idea is to let wallet code use same LogDebug(), LogTrace(), LogInfo(), LogWarning(), LogError() macros other code uses.

Updating TraceSqlCallback to call LogTrace rather than LogPrintf would be an improvement as those messages would get categorised properly; but otherwise this seems like massive overkill just to avoid writing "[%s] ...", walletname, ....

It just adds a little formatting hook so the wallet name is automatically included when the log source is the wallet. This way full functionality of #29256 is available to the wallet and we can drop WalletLogPrintf and not have dedicated wallet logging functions.

A +190 -109 diff because you don't like a one-line wrapper function seems crazy to me.

Do you have some reason to think there's large amounts of additional wallet debug logs that would be introduced if it didn't involve writing [%s], walletname or are there a bunch of the current unconditional WalletLogPrintf calls that should be silenced and only available when debugging is enabled?

ryanofsky added a commit to ryanofsky/bitcoin that referenced this pull request Oct 15, 2025
Disallow passing BCLog category constants to LogInfo(), LogWarning(), and
LogError() macros, and disallow omitting BCLog categories when calling
LogDebug() and LogTrace() macros.

Additionally, drop category information from log output at higher levels as
suggested by Hodlinator
bitcoin#29256 (comment).

None of these restrictions are technically necessary, and not everybody
believes they are good. However, they have existed since the
Log{Trace,Debug,Info,Warning,Error} macros were introduced in bitcoin#28318, and
removing these restrictions is orthogonal to the goals of this PR which are:
(1) to allow the Log macros to work without accessing global state and (2) to
support local logging customization with additional metadata.

This change just more clearly documents the current logging restrictions and
provides better error messages to developers when enforcing them.

Co-Authored-By: Hodlinator <172445034+hodlinator@users.noreply.github.com>
ryanofsky added a commit to ryanofsky/bitcoin that referenced this pull request Oct 16, 2025
Disallow passing BCLog category constants to LogInfo(), LogWarning(), and
LogError() macros, and disallow omitting BCLog categories when calling
LogDebug() and LogTrace() macros.

Additionally, drop category information from log output at higher levels as
suggested by Hodlinator
bitcoin#29256 (comment).

None of these restrictions are technically necessary, and not everybody
believes they are good. However, they have existed since the
Log{Trace,Debug,Info,Warning,Error} macros were introduced in bitcoin#28318, and
removing these restrictions is orthogonal to the goals of this PR which are:
(1) to allow the Log macros to work without accessing global state and (2) to
support local logging customization with additional metadata.

This change just more clearly documents the current logging restrictions and
provides better error messages to developers when enforcing them.

Co-Authored-By: Hodlinator <172445034+hodlinator@users.noreply.github.com>
ryanofsky added a commit to ryanofsky/bitcoin that referenced this pull request Oct 16, 2025
Disallow passing BCLog category constants to LogInfo(), LogWarning(), and
LogError() macros, and disallow omitting BCLog categories when calling
LogDebug() and LogTrace() macros.

Additionally, drop category information from log output at higher levels as
suggested by Hodlinator
bitcoin#29256 (comment).

None of these restrictions are technically necessary, and not everybody
believes they are good. However, they have existed since the
Log{Trace,Debug,Info,Warning,Error} macros were introduced in bitcoin#28318, and
removing these restrictions is orthogonal to the goals of this PR which are:
(1) to allow the Log macros to work without accessing global state and (2) to
support local logging customization with additional metadata.

This change just more clearly documents the current logging restrictions and
provides better error messages to developers when enforcing them.

Co-Authored-By: Hodlinator <172445034+hodlinator@users.noreply.github.com>
ryanofsky added a commit to ryanofsky/bitcoin that referenced this pull request Nov 10, 2025
Disallow passing BCLog category constants to LogInfo(), LogWarning(), and
LogError() macros, and disallow omitting BCLog categories when calling
LogDebug() and LogTrace() macros.

Additionally, drop category information from log output at higher levels as
suggested by Hodlinator
bitcoin#29256 (comment).

None of these restrictions are technically necessary, and not everybody
believes they are good. However, they have existed since the
Log{Trace,Debug,Info,Warning,Error} macros were introduced in bitcoin#28318, and
removing these restrictions is orthogonal to the goals of this PR which are:
(1) to allow the Log macros to work without accessing global state and (2) to
support local logging customization with additional metadata.

This change just more clearly documents the current logging restrictions and
provides better error messages to developers when enforcing them.

Co-Authored-By: Hodlinator <172445034+hodlinator@users.noreply.github.com>
ryanofsky added a commit to ryanofsky/bitcoin that referenced this pull request Nov 10, 2025
Disallow passing BCLog category constants to LogInfo(), LogWarning(), and
LogError() macros, and disallow omitting BCLog categories when calling
LogDebug() and LogTrace() macros.

Additionally, drop category information from log output at higher levels as
suggested by Hodlinator
bitcoin#29256 (comment).

None of these restrictions are technically necessary, and not everybody
believes they are good. However, they have existed since the
Log{Trace,Debug,Info,Warning,Error} macros were introduced in bitcoin#28318, and
removing these restrictions is orthogonal to the goals of this PR which are:
(1) to allow the Log macros to work without accessing global state and (2) to
support local logging customization with additional metadata.

This change just more clearly documents the current logging restrictions and
provides better error messages to developers when enforcing them.

Co-Authored-By: Hodlinator <172445034+hodlinator@users.noreply.github.com>
ryanofsky added a commit to ryanofsky/bitcoin that referenced this pull request Dec 12, 2025
Disallow passing BCLog category constants to LogInfo(), LogWarning(), and
LogError() macros, and disallow omitting BCLog categories when calling
LogDebug() and LogTrace() macros.

Additionally, drop category information from log output at higher levels as
suggested by Hodlinator
bitcoin#29256 (comment).

None of these restrictions are technically necessary, and not everybody
believes they are good. However, they have existed since the
Log{Trace,Debug,Info,Warning,Error} macros were introduced in bitcoin#28318, and
removing these restrictions is orthogonal to the goals of this PR which are:
(1) to allow the Log macros to work without accessing global state and (2) to
support local logging customization with additional metadata.

This change just more clearly documents the current logging restrictions and
provides better error messages to developers when enforcing them.

Co-Authored-By: Hodlinator <172445034+hodlinator@users.noreply.github.com>
ryanofsky added a commit to ryanofsky/bitcoin that referenced this pull request Dec 12, 2025
Disallow passing BCLog category constants to LogInfo(), LogWarning(), and
LogError() macros, and disallow omitting BCLog categories when calling
LogDebug() and LogTrace() macros.

Additionally, drop category information from log output at higher levels as
suggested by Hodlinator
bitcoin#29256 (comment).

None of these restrictions are technically necessary, and not everybody
believes they are good. However, they have existed since the
Log{Trace,Debug,Info,Warning,Error} macros were introduced in bitcoin#28318, and
removing these restrictions is orthogonal to the goals of this PR which are:
(1) to allow the Log macros to work without accessing global state and (2) to
support local logging customization with additional metadata.

This change just more clearly documents the current logging restrictions and
provides better error messages to developers when enforcing them.

Co-Authored-By: Hodlinator <172445034+hodlinator@users.noreply.github.com>
ryanofsky and others added 5 commits December 15, 2025 10:42
Test will be extended in next commit to cover support for context objects.
Allow LogDebug(), LogTrace(), LogInfo(), LogWarning(), and LogError() macros to
accept context arguments to provide more information in log messages and more
control over logging to callers.

This functionality is used in followup PRs:

- bitcoin#30342 - To let libbitcoinkernel send
  output to specfic `BCLog::Logger` instances instead of a global instance, so
  output can be disambiguated and applications can have more control over
  logging.

- bitcoin#30343 - To replace custom
  `WalletLogPrintf` calls with standard logging calls that automatically include
  wallet names and don't log everything at info level.

This commit does not change behavior of current log prints or require them to
be updated. It includes tests and documentation covering the new functionality.

Co-Authored-By: Hodlinator <172445034+hodlinator@users.noreply.github.com>
Custom log contexts allow overridding log formatting and adding metadata such
as request ids or wallet names to log messages while still using standard
macros for logging. This is used to replace WalletLogPrintf() functions with
LogInfo() calls in followup PR bitcoin#30343.
Disallow passing BCLog category constants to LogInfo(), LogWarning(), and
LogError() macros, and disallow omitting BCLog categories when calling
LogDebug() and LogTrace() macros.

Additionally, drop category information from log output at higher levels as
suggested by Hodlinator
bitcoin#29256 (comment).

None of these restrictions are technically necessary, and not everybody
believes they are good. However, they have existed since the
Log{Trace,Debug,Info,Warning,Error} macros were introduced in bitcoin#28318, and
removing these restrictions is orthogonal to the goals of this PR which are:
(1) to allow the Log macros to work without accessing global state and (2) to
support local logging customization with additional metadata.

This change just more clearly documents the current logging restrictions and
provides better error messages to developers when enforcing them.

Co-Authored-By: Hodlinator <172445034+hodlinator@users.noreply.github.com>
ryanofsky added a commit to ryanofsky/bitcoin that referenced this pull request Dec 16, 2025
Disallow passing BCLog category constants to LogInfo(), LogWarning(), and
LogError() macros, and disallow omitting BCLog categories when calling
LogDebug() and LogTrace() macros.

Additionally, drop category information from log output at higher levels as
suggested by Hodlinator
bitcoin#29256 (comment).

None of these restrictions are technically necessary, and not everybody
believes they are good. However, they have existed since the
Log{Trace,Debug,Info,Warning,Error} macros were introduced in bitcoin#28318, and
removing these restrictions is orthogonal to the goals of this PR which are:
(1) to allow the Log macros to work without accessing global state and (2) to
support local logging customization with additional metadata.

This change just more clearly documents the current logging restrictions and
provides better error messages to developers when enforcing them.

Co-Authored-By: Hodlinator <172445034+hodlinator@users.noreply.github.com>
@DrahtBot
Copy link
Contributor

🐙 This pull request conflicts with the target branch and needs rebase.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Projects

None yet

Development

Successfully merging this pull request may close these issues.

8 participants