log, refactor: Allow log macros to accept context arguments

ryanofsky commented at 10:09 pm on January 16, 2024: contributor

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

For example, with this change wallet code can log with (in #30343):

0-        WalletLogPrintf("Error: cannot erase address book entry data\n");
1+        LogError(m_log, "Error: cannot erase address book entry data\n");

And kernel code can log with (in #30342):

0-        LogDebug(BCLog::VALIDATION, "Block mutated: %s\n", state.ToString());
1+        LogDebug(log, "Block mutated: %s\n", state.ToString());

where m_log / log types can vary and be defined by the subsystem. This allows subsystems to attach extra context to log messages like wallet names, or request ids. It also allows more than a single log stream to exist, and for messages to be logged to specified streams. Having a single global log stream works very well for bitcoind and will not change. But it limits functionality of libbitcoinkernel, forcing all potential users of the library, including applications written in different languages and running in different environments (like jupyter notebooks) to use shared global state and not be able to do things like get an isolated log trace from one operation.

The change is fully backwards compatible and does not require any updates to code that wants to continue using the macros as they are. The implementation of the macros is also improved. They now provide improved error messages when called with the wrong arguments. And they only call underlying ShouldLog Log and Format hooks as needed to avoid unnecessary work. The PR also adds more test coverage and documentation.

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.

This is based on #34778. The non-base commits are:

DrahtBot commented at 10:09 pm on January 16, 2024: contributor

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	hodlinator, ajtowns
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:

#34806 (refactor: logging: Various API improvements by ajtowns)
#34730 (util/log: Combine the warning/error log levels into a single alert level by ajtowns)
#34729 (Reduce log noise by ajtowns)
#34639 (iwyu: Document or remove some pragma: export and other improvements by hebasto)
#34514 (refactor: remove unnecessary std::move for trivially copyable types by l0rinc)
#33727 (zmq: Log bind error at Error level, abort startup on init error by isrod)

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:

testring -> testing [typo: “testring” should be “testing”]
readble -> readable [typo: “readble” should be “readable”]

2026-03-09 15:44:05

ajtowns commented at 10:34 pm on January 16, 2024: contributor

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…

DrahtBot added the label Needs rebase on Jan 16, 2024

ryanofsky commented at 4:41 am on January 17, 2024: contributor

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:

0-LogPrintLevel(BCLog::NET, BCLog::Level::Warning, "getsockname failed\n");
1+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 :hankey:-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.

ryanofsky force-pushed on Jan 17, 2024

DrahtBot removed the label Needs rebase on Jan 17, 2024

ryanofsky force-pushed on Jan 17, 2024

DrahtBot added the label CI failed on Jan 17, 2024

DrahtBot commented at 7:15 pm on January 17, 2024: 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

ryanofsky force-pushed on Jan 17, 2024

DrahtBot removed the label CI failed on Jan 17, 2024

ryanofsky marked this as ready for review on Jan 17, 2024

ryanofsky force-pushed on Jan 18, 2024

ajtowns commented at 6:12 am on January 19, 2024: contributor

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.

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

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

0-LogWarning("getsockname failed\n");
1+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?

DrahtBot added the label CI failed on Jan 19, 2024

DrahtBot removed the label CI failed on Jan 19, 2024

willcl-ark added the label Utils/log/libs on Jan 24, 2024

ryanofsky commented at 8:03 pm on January 25, 2024: contributor

@ajtowns, to try to steer this discussion in a more constructive direction, would it be possible for you to make a list of the biggest harms you believe this PR would cause if it were merged? And if you have ideas on how the harms you see could be avoided, while the problems I am trying to solve (see “Problems this PR attempts to solve” in the PR description) could be addressed, it would be really helpful to know about. Maybe the harms you see this PR causing and the problems this PR is trying to solve are in direct contradiction, but it’s not obvious to me that this is the case, so maybe there is a way out of our disagreement here. In the meantime, I responded to your last message below.

re: #29256 (comment)

Filtering is discarding.

It’s really not. You can view logs into a text editor or log viewer and highlight categories of messages you are interested in while not discarding other messages.

I am just trying to add some basic flexibility here. If you don’t want to attach categories to log messages, you don’t have to, you can write LogWarning({}, "uncategorizable warning"). The PR just makes the log macros consistently accept a source parameter, so code has flexibility to set a category, set a log destination, add metadata to log messages, control log formatting, do a combination of these things, or do none of these things.

0-LogWarning("getsockname failed\n");
1+LogWarning(log, "getsockname failed\n");
which is adding characters, without adding any information to the reader.

This adds 5 characters, but also adds category information that was previously absent to the output. You can find examples of where the API changes in this PR increase verbosity, and examples where they decrease it, and I think there should be less verbosity on net. I also think some of this discussion around verbosity misses the bigger picture, and is a distraction from the actual goal of the PR, which is to add context to log messages, and give code that needs it control over logging behavior. But if making the log parameter optional is a requirement for you, it should be possible to implement that here and never increase verbosity in any case.

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 agree m_log.Debug("...") would be better than LogDebug(m_log, "...") but I don’t understand why the former would be ok, but the latter is unacceptable. You definitely have much stronger opinions about verbosity than me, so maybe we can try to engage more constructively on this. I think on net, this PR should reduce verbosity, but maybe more improvements are possible that could alleviate your concerns.

I don’t think moving the category away from the line of code it’s affecting is very useful

That’s ok, since allowing this was a side effect, not a major goal of this PR. But LogDebug(m_log, "debug message") can be easier to write and read than LogDebug(BCLog::TXRECONCILIATION, "debug message"), especially if the code has a lot of log prints and the category is repeated a lot. In any case, you aren’t forced to choose one approach or the other. The PR allows both.

It doesn’t mean the source code is badly organised, it means different parts of the source are generating related log messages.

Ok, we definitely disagree on how well the code is organized. IMO, validation.cpp doing BCLog::MEMPOOL prints is messed up. But this is a tangent. I think log sources should encourage better organization, but this PR does not force anything or break anything that works now.

I don’t think there is anything here “encouraging” these categories to be scattered or mixed

I don’t want to make a big deal out of this, but just to clarify, I think the status quo where trace and debug macros require BCLog::LogFlags arguments and can’t take source arguments makes it easier to mix up categories, intentionally and unintentionally. The alternative where source objects can be used for error/warning/info prints, not just debug/trace prints, and can tag everything with the same category should make it easier to be consistent if you want to be consistent (and not get in the way if you don’t want to).

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, ....

I don’t see the massive overkill. This is a reasonable PR that adds documentation, tests, and doesn’t change very much code. We don’t want to require every individual wallet log print to include "[%s] ...", walletname, ... boilerplate for obvious reasons, I think. The problems with the WalletLogPrintf function are:

It is only capable of logging at info level, does not provide a way to log at higher or lower levels.
It evaluates its arguments unconditionally, so if it were extended to log at lower levels, it would either be inefficient or need to duplicate preprocessor code from logging.h to be as efficient.
It is inconsistent with the rest of the codebase. It is nice if the same logging macros can be used everywhere, and the same features can be used everywhere. It also ensures logging is consistent within the wallet and only one logging API is used there.

DrahtBot added the label CI failed on Jan 25, 2024

ryanofsky commented at 3:45 am on January 29, 2024: contributor

re: #29256 (comment)

But if making the log parameter optional is a requirement for you, it should be possible to implement that here and never increase verbosity in any case.

It turns out making the category argument completely optional is not too hard to implement: 69e69b2a82c95f8040be093a29e5f84c37641f3a. So you could write:

0LogWarning("uncategorizable warning")

instead of

0LogWarning({}, "uncategorizable warning")

if that is the blocker here.

ajtowns commented at 5:32 am on January 29, 2024: contributor

And if you have ideas on how the harms you see could be avoided, while the problems I am trying to solve (see “Problems this PR attempts to solve” in the PR description) could be addressed,

I think the problem you are actually attempting to solve is “I, ryanofsky, find this weird and I don’t like it”, and I don’t think code changes are the way of solving that, any more than code changes are the right way to solve the problem “Bitcoin is weird and I don’t like it”. I think you’re wrong, but you seem unwilling to consider changing your opinion, so I’m pretty doubtful this is going to be productive. However, in case I’m wrong:

These macros cannot be used directly in wallet code because wallet log prints are supposed to automatically attach wallet names to log messages.

The only cases where wallet names are automatically attached to log messages are in info level calls, which can be trivially dealt with by changing the existing wrapper to call LogInfo, and with an optional scripted diff renaming the wrapper as well.

These macros cannot be used at all in libbitcoinkernel code because they do not allow specifying a logger instance.

This, also, is not true: the assumption of these macros is that there is a global BCLog::Logger instance, which is already provided by LogInstance(). If we want to allow apps to configure libbitcoinkernel’s logging in future, we could allow them to setup that global instance, or provide their own callbacks for it to use, in much the same way libevent allows you to setup callbacks. That’s not something that needs changing.

Filtering is discarding.

It’s really not. You can view logs into a text editor or log viewer and highlight categories of messages you are interested in while not discarding other messages.

That’s not filtering, that’s ‘grepping’. If you don’t want to filter, but just want to highlight, then, as I’ve said repeatedly, logsourcelocations is what you want; the only benefit categories have compared to that is that categories can be (and by default are) filtered/discarded. logsourcelocations gives you much more exact information, is precisely separated by source file as you want, works with every level of log message, and requires no code changes or ongoing development effort to support.

I am just trying to add some basic flexibility here. If you don’t want to attach categories to log messages, you don’t have to, you can write LogWarning({}, "uncategorizable warning").

In that case you will not be able to use your log viewer to highlight that message when you’re looking for it, which defeats your claimed goal. (Except, of course, you can select it for highlight, by looking for [warning] markers)

The PR just makes the log macros consistently accept a source parameter,

Can you please try using the logsourcelocations option before replying again? I really don’t see how it doesn’t already do everything you want, but you’ve ignored it every time I’ve mentioned it.

0-LogWarning("getsockname failed\n");
1+LogWarning(log, "getsockname failed\n");
which is adding characters, without adding any information to the reader.

The reader of the source code, is who I’m referring to here.

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 agree m_log.Debug("...") would be better than LogDebug(m_log, "...")

I don’t think m_log.Debug() would be better than LogDebug – in my opinion having a global log instance is the right thing here, and both having multiple references to a global log instance or having multiple log instances that all then coordinate writing to a single log would be worse.

As I’ve already said, I think m_log.SetCategory(NET); m_log.Debug("connected to foo") is much worse than LogDebug(NET, "connected to foo"). Having to keep more context/state in your head when you’re looking at code makes things harder, and it tends to make tool use go from “usually works” to “never works” (eg, grep -RIl 'Log.*NET').

It doesn’t mean the source code is badly organised, it means different parts of the source are generating related log messages.

Ok, we definitely disagree on how well the code is organized. IMO, validation.cpp doing BCLog::MEMPOOL prints is messed up. But this is a tangent. I think log sources should encourage better organization, but this PR does not force anything or break anything that works now.

validation.cpp is where we have the code for “is this valid for the mempool”, because we thought the word “valid” was more important than the word “mempool” in that sentence. BCLog::VALIDATION on the other hand is limited to blocks and headers, allowing it to be much less noisy than anything that triggers for every transaction, like BCLog::MEMPOOL. None of that is any indication of whether the code is well or badly organised.

I don’t think there is anything here “encouraging” these categories to be scattered or mixed

I don’t want to make a big deal out of this, but just to clarify, I think the status quo where trace and debug macros require BCLog::LogFlags arguments and can’t take source arguments makes it easier to mix up categories, intentionally and unintentionally.

I think by “source arguments” you mean “a context argument”, and there’s no reason they couldn’t – you can write LogDebug(m_log_category, "stuff"); right now just as easily as you could LogDebug(m_log, "stuff"); after this PR. That would still be a bad idea, though, as having the name of the log category obvious in the code is helpful.

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, ....

I don’t see the massive overkill.

If there’s a way of getting 99% of the benefits with a +1-1 change, then a +300-200 change is overkill in general.

This is a reasonable PR that adds documentation, tests, and doesn’t change very much code. We don’t want to require every individual wallet log print to include "[%s] ...", walletname, ... boilerplate for obvious reasons, I think. The problems with the WalletLogPrintf function are:
1. It is only capable of logging at info level, does not provide a way to log at higher or lower levels.

Why do you think that is a problem? None of the other existing cases need to add walletname boilerplate. What wallet-specific event (if it’s not wallet specific, it doesn’t need to be tagged with a wallet name) shouldn’t be unconditionally logged (if an event is affecting the thing that holds all your funds, isn’t that one of the most important things to log)?

2. It evaluates its arguments unconditionally, so if it were extended to log at lower levels, it would either be inefficient or need to duplicate preprocessor code from logging.h to be as efficient.

That it only logs at info level means it is unconditionally logged, so all the arguments are naturally unconditionally evaluated.

3. It is inconsistent with the rest of the codebase.

It’s inconsistent with your idea of how the codebase should be, but it’s completely consistent with how the codebase actually is. Which is fine: changing the codebase to match better ideas is how you improve it. But things aren’t going to improve if we can’t recognise how things actually are in the first place.

DrahtBot removed the label CI failed on Jan 30, 2024

DrahtBot commented at 12:18 pm on February 10, 2024: 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/20597453668

DrahtBot added the label CI failed on Feb 10, 2024

vasild commented at 9:00 am on February 16, 2024: contributor

Make them all accept log categories, to make it possible to filter or highlight log messages from a particular component.

This seems like a step in the right direction. Currently we log messages unconditionally that don’t have a category. But this is mixing two separate things - facility and severity. I have always found this confusing.

They got it right decades ago with syslog(3). Every log message has a facility and a severity. Because we don’t want users to configure their systems in such a way as to dangerously omit important messages, then we don’t provide a way to omit messages with higher severity than e.g. “info” or “notice”. This is unrelated to the facility.

If some parts of this PR cause controversy, could it be reduced to the non-controversial things?

ryanofsky force-pushed on Feb 27, 2024

ryanofsky commented at 11:05 pm on February 27, 2024: contributor

Updated 99feed7350b5fc3ae3157dd395ae6260c5bfc092 -> 0cd1616d47e61e125eb3e573573c0c56fba6b775 (pr/bclog.12 -> pr/bclog.13, compare) making the log macros backwards compatible to avoid any controversial changes. Rebased 0cd1616d47e61e125eb3e573573c0c56fba6b775 -> 93d37f7d655409e6830475a10f4c9f16e35c76cd (pr/bclog.13 -> pr/bclog.14, compare) due to silent conflicts with #26836. Updated 93d37f7d655409e6830475a10f4c9f16e35c76cd -> a91fbbd61551702f26f734f3cdd1c080f9d51628 (pr/bclog.14 -> pr/bclog.15, compare) to fix tidy failure https://cirrus-ci.com/task/6362757050662912, and try to work around MSVC compiler bug https://github.com/bitcoin/bitcoin/actions/runs/8072891468/job/22055528830?pr=29256, and clean up some documentation.

If some parts of this PR cause controversy, could it be reduced to the non-controversial things?

I made a try at this in the latest push. I think most of the criticism of this PR from AJ is saying that the changes here are unnecessary, not really that they are harmful, so I made the logging macros completely backwards compatible using the approach I mentioned #29256 (comment), and only kept the changes I think are essential. I think this should help.

ryanofsky force-pushed on Feb 27, 2024

ryanofsky force-pushed on Feb 28, 2024

DrahtBot removed the label CI failed on Feb 28, 2024

DrahtBot added the label Needs rebase on Mar 12, 2024

ryanofsky force-pushed on Mar 28, 2024

DrahtBot removed the label Needs rebase on Mar 28, 2024

DrahtBot added the label CI failed on Apr 20, 2024

DrahtBot removed the label CI failed on Apr 23, 2024

ajtowns commented at 12:05 pm on April 30, 2024: contributor

I think most of the criticism of this PR from AJ is saying that the changes here are unnecessary, not really that they are harmful,

I said “As I’ve already said, I think m_log.SetCategory(NET); m_log.Debug("connected to foo") is much worse than LogDebug(NET, "connected to foo").” Does that really not come across as me saying they’re harmful? I really don’t think I’m being that unclear. Anyway, I’ll bow out, I’m already sorry for touching this.

ryanofsky commented at 1:06 pm on April 30, 2024: contributor

I think most of the criticism of this PR from AJ is saying that the changes here are unnecessary, not really that they are harmful,

I said “As I’ve already said, I think m_log.SetCategory(NET); m_log.Debug("connected to foo") is much worse than LogDebug(NET, "connected to foo").” Does that really not come across as me saying they’re harmful? I really don’t think I’m being that unclear. Anyway, I’ll bow out, I’m already sorry for touching this.

I think it’s possible you might be referring to some changes in an earlier version of this PR. The PR allows the syntax you like and support it as a first-class usage! It does change wallet code, however to look like LogDebug(m_log, "debug message") to include wallet filenames in log messages. So if that is the harm which this PR causes, I want to acknowledge it, and I will update the PR description. @ajtowns we’ve definitely had difficulty communicating here and in some other issues, and I’m sorry for the dismissive comments I initially left on #28318, which on the whole I think is actually a good PR. I especially regret it you are “sorry for touching this”, because #28318 is a real improvement, and your comments on this PR have made it better too, and motivated all the work and simplifications I’ve made to it since it was opened.

ajtowns commented at 3:05 pm on April 30, 2024: contributor

I think most of the criticism of this PR from AJ is saying that the changes here are unnecessary, not really that they are harmful,

I said “As I’ve already said, I think m_log.SetCategory(NET); m_log.Debug("connected to foo") is much worse than LogDebug(NET, "connected to foo").” Does that really not come across as me saying they’re harmful? I really don’t think I’m being that unclear. Anyway, I’ll bow out, I’m already sorry for touching this.

I think it’s possible you might be referring to some changes in an earlier version of this PR.

That was the clearest example of saying that something was harmful, as evidence that I don’t think you summarised my criticism accurately. English is my first language, so it’s not like I can switch to another one to try to get my point across better… My main criticism of what remains is:

Can you please try using the logsourcelocations option before replying again? I really don’t see how it doesn’t already do everything you want, but you’ve ignored it every time I’ve mentioned it.

I’ll rephrase how I see things again for whatever that’s worth:

being able to match a log entry with where it came from in the source is super valuable
-logsourcelocations does that automatically for us, which is far less effort than manually specifying a category, and by giving a specific filename and line number, does a far better job of it as well
the only reason to keep the manual categories around at all is for selectively enabling/disabling noisy logs
the only noisy logs we have are those in the debug and trace levels (anything else would be a bug)
having those be manually specified rather than automatic is a win, as it allows us to rearrange our source code without accidentally breaking the configs of users who’ve enabled some noisy logs
adding those categories for non-noisy log messages is just busy work: it doesn’t make it easier to find the source location of the debug message than -logsourcelocations does, and it doesn’t help reduce log noise because those log messages aren’t noisy in the first place

The macros in #28318 pretty much fall out from that. I suppose an alternative would be to have Log(INFO, "foo") and LogNoisy(DEBUG, NET, "bar") or so.

There are probably things logsourcelocations is bad at; if so, why not improve it so the benefits hit everywhere automatically?

The PR allows the syntax you like and support it as a first-class usage!

I think specifying a category sometimes and not others depending on who happened to author that section of the code is a terrible idea. But I mean, it’s not any more terrible than having “LogPrint” and “LogPrintf” having significantly different behaviour, so it’s not like it’s a disaster. Anyway, it’s certainly not worth 15+ months of time/energy.

ryanofsky commented at 4:33 pm on April 30, 2024: contributor

Thanks, I added a link directly to this comment in the summary so those who are interested can follow the chain of reasoning.

To reiterate my own point of view, -logsourcelocation does not solve the same problem this PR solves because it does not (1) let libitcoinkernel applications call validation functions and control which Logger object they write to, and (2) allow code like wallet code and index code to easily include additional metadata in log messages (wallet names and index names) while using convenient LogDebug(), LogTrace(), LogInfo(), LogWarning(), and LogError() macros.

ajtowns commented at 10:06 am on May 2, 2024: contributor

To reiterate my own point of view, -logsourcelocation does not solve the same problem this PR solves because it does not

That ignores bullets (1), (2) and (5) from your OP (as it stands today).

It also ignores comments like vasild’s, jamesob’s, luke-jr’s, jonatack’s, laanwj’s or your own. There’s a valid disagreement there, isn’t there? Can’t we discuss it like engineers and work out what actual tradeoffs are lurking behind the intuition/gut feels? I’ve tried to spell out my reasoning both before and after the PR got merged as well as having brought it up at the irc meeting to try to trigger discussion, but the response has just to reiterate the disagreement without any analysis or engagement with the reasoning that I’ve offered for doing it this way? Why? That makes no sense to me. I’m willing to be convinced I’ve made a mistake; but someone has to show me where I made the mistake, or at least do a show of hands that the majority prefers something else.

I mean, am I incorrect in reading the previous two comments as “here are the reasons I think this solution make sense: A, B, C, D, E, F” and “okay, that’s nice, I’m going to completely ignore them, besides, X and Y are still important”? Other than “uh, okay, I guess I know when I’m not wanted”, how else am I meant to take it? What’s the chance a response addressing X and Y will just also get equally ignored?

(FWIW, I’d strongly contend that just declaring things should be such-and-such a way without being willing either talk through the tradeoffs and maybe find some mutually preferable solution, or to happily say “oh well, not what I’d consider perfect, but not so bad, let’s press on!” is a pretty major contributor to things not progressing very fast. I can understand that habit in bitcoin broadly – you explain why BTC is great and people shrug or call it a ponzi, and the only thing you can do is wait to be proven right, so you start just skipping straight to the final step – but I don’t understand it in the context of code changes at all…)

Anyway, on to X and Y:

(1) let libitcoinkernel applications call validation functions and control which Logger object they write to,

Doing that meaningfully means changing all the logging in all the bitcoin-kernel related modules (eg validation, mempool, blockstorage, scheduler, …) to explicitly specify a logger rather than using the global functions, which seems like a lot of pointless busy work? I can’t imagine why we’d want to support having multiple bitcoin-kernel instances in a single executable logging to different loggers; if someone wants to do that, it seems easy enough to just launch two separate processes.

The alternative would be to just have applications manipulate the global logger directly, which is how things already work, perhaps turning it into an atomic unique_ptr or similar and making many of its function virtual to allow overriding?. I’m just not really sure what the problem here is that’s worth fixing; we already buffer log messages until StartLogging is called, and libbitcoin-kernel continuing to have a global logger instance seems simple and efficient for both us and any potential users of the library.

(If we did want to do that anyway for some reason, then waiting until std::source_location is available would let us use log.Debug(...) syntax via template functions rather than having to use a macro and writing LogDebug(log, ...). So rushing this change now seems bad even if the goal makes sense in some way I don’t see)

(The phrasing in the OP is currently “The new macros cannot be used in libbitcoinkernel code because they do not allow specifying a logger instance.” but that seems just false – there’s a bunch of LogInfo() calls in kernel/*.cpp already, and all the LogPrintf and LogPrint calls in validation are just aliases of LogInfo and LogDebug)

and (2) allow code like wallet code and index code to easily include additional metadata in log messages (wallet names and index names) while using convenient LogDebug(), LogTrace(), LogInfo(), LogWarning(), and LogError() macros.

We could do that simply by renaming WalletLogPrintf to WalletLogInfo, with behaviour no worse than today. There just isn’t currently a need for non-info-level logs that report the wallet’s name (which makes sense: in general ops on a wallet are important enough to be an “INFO” event).

Having WalletLogPrintf (or whatever) wrap around LogInfo sucks a bit, because it means -logsourcelocations reports the wrapper location rather than the caller. But a fix for that will be easy “real-soon-now” (#29077) when we can use std::source_location.

Changing wallet/sqlite’s TraceSqlCallback to use LogTrace instead of LogPrintf is something we could do today that would improve things by making the output correctly indicate that it’s trace-level rather than info-level, and be correctly annotated with the debug category that enables it to be logged. Again, that only needs a few characters changed, not a fundamental revamp.

Here’s a patchset that does those wallet changes: it’s a one line change for the trace logging, and two scripted diffs. Easy to do, easy to review, and “allows the wallet code to easily include its metadata in log messages while using convenient LogInfo macros/functions”. If we want to improve things further (like using std::source_location when it’s available or introducing some wallet-specific warnings or debug messages) we could still easily do that in the future.

sedited commented at 7:26 pm on June 25, 2024: contributor

Concept ACK

Re #29256 (comment)

Doing that meaningfully means changing all the logging in all the bitcoin-kernel related modules (eg validation, mempool, blockstorage, scheduler, …) to explicitly specify a logger rather than using the global functions, which seems like a lot of pointless busy work? I can’t imagine why we’d want to support having multiple bitcoin-kernel instances in a single executable logging to different loggers; if someone wants to do that, it seems easy enough to just launch two separate processes.

There are use cases for having e.g. two chainstate managers running in parallel. Take a block file linearizer replacing the scripts in contrib/linearize as an example; you have one that reads blocks in their indexed order and another that writes blocks and their index back to another location on disk. Having something to distinguishing logs issued between the two sounds useful. In my eyes an important utility of the library is exactly that, you don’t have to use multiple processes or go through the rpc to interact with Bitcoin Core’s data structures and validation rules.

ryanofsky commented at 8:55 pm on June 25, 2024: contributor

re: #29256 (comment)

AJ, thanks for the response. I want to let your comment stand, and not reply in detail right away to wait for input on this PR from other potential reviewers. I think your views on importance of hardcoding category constants in certain log statements, and on not allowing categories to be specified in other log statements are atypical, or at least will not be as strongly felt by other reviewers.

But your response does help me understand your concerns better, and your preferred solution of letting wallet code use its own logging functions, and having kernel code continue to use a global logger. It is also maybe a sign of hope to me that you seem to like log.Debug(...) syntax while disliking LogDebug(log, ...) syntax. I personally don’t see much distinction between the two syntaxes, other than that latter allows arguments to be conditionally evaluated. But not evaluating arguments seems less important to me than being able to log in a consistent way across the codebase, so this offers hope for compromise.

I also want to say again that I respect your opinions and appreciate you paying attention to this PR. Your earlier comments directly led to a number of improvements in the PR since it was opened.

ajtowns commented at 8:05 am on June 26, 2024: contributor

Take a block file linearizer replacing the scripts in contrib/linearize as an example; you have one that reads blocks in their indexed order and another that writes blocks and their index back to another location on disk.

I don’t think we should be reworking logging in our entire codebase in order to have a slight improvement in the hypothetical case where we replace some python scripts in contrib with C++ code? If this is worth doing, surely there is a much better example of why.

Having something to distinguishing logs issued between the two sounds useful

To me, this suggests that a “context” parameter would be more appropriate than an “instance” one – eg LogInfo(walletctx, "opened wallet, and sent all your funds to the genesis address, haha\n"); where the logging system would automatically invoke msg = walletctx(msg) when provided, in order to prefix the wallet name to the message or similar, but only after verifying logging is actually enabled. That’s much more constrained behaviour than an instance parameter – it just adds context information to a log message rather than allowing you to change the priority/category, or have completely different logging parameters (log file location, log to stdout, display source location, etc). The difference between LogInfo(m_wallet_ctx, "...") and the existing WalletLogPrintf("...") seems pretty minor to me.

There are two different ways you might want to add context information: internally to a module, in the way that the wallet does, which would imply the ctx variable is established within the module and is private/local to that module. In that case, a similar approach to the one here would make sense – have it be an optional parameter that the wallet module uses.

The other way is to have the context be provided externally to a module, so that you can create two instances of the module with different logging contexts that the caller controls. The latter seems like what you’re imagining for the contrib/linearize example; but in that case, every module needs to pull in a context from its caller, much more like #30338. I don’t see how the latter would mesh well with modules like wallet that also want to add internal context (would we have chained contexts? would the context object manage that?), and it seems like unnecessary complexity to me.

ryanofsky force-pushed on Jun 26, 2024

ryanofsky commented at 6:19 pm on June 26, 2024: contributor

With the latest push, this PR is now much smaller, and now mostly consists of documentation and test changes.

I wanted to split this up in order to be able to base #30342 on a smaller changeset. The wallet changes that were previously part of this PR were moved to #30343.

Rebased ce0004e42d37786f98cdf9d55b976b935dcf1ba1 -> 5f64eab013a58967af37a59c863c2ab6d45ba6e8 (pr/bclog.16 -> pr/bclog.17, compare) updating the PR as described.

in doc/developer-notes.md:1 in 5f64eab013

hodlinator commented at 9:09 pm on June 26, 2024:

source feels a bit abstract and special case, it would be good to keep LogDebug(BCLog::CATEGORY, ... examples as the most prominent as they are the common case.

ryanofsky commented at 3:11 am on June 27, 2024:

re: #29256 (review)

source feels a bit abstract and special case, it would be good to keep LogDebug(BCLog::CATEGORY, ... examples as the most prominent as they are the common case.

Great point, reverted this. There’s no need to change this document anymore since the current version of this PR is backwards compatible (unlike the original version) so the original recommendations are still good. There’s more complete reference documentation in the logging header.

hodlinator commented at 8:29 pm on December 14, 2024:

If we were to go ahead with something close to what this PR is, I think it would be good to mention in developer-notes.md that LogInfo/Warning/Error take an optional category or source. - Or at the very least hint at there being more flexibility which is documented together with the macro implementations.

in src/logging.h:218 in 5f64eab013 outdated

213+    //! formatting hook.
214+    struct Source {
215+        LogFlags category;
216+        Logger& logger;
217+
218+        Source(LogFlags category = LogFlags::ALL, Logger& logger = LogInstance()) : category{category}, logger{logger} {}

hodlinator commented at 9:13 pm on June 26, 2024:

Could do with a comment such as // Implicitly constructible from a LogFlags value in order to be created by LogDebug(BCLog::NET, ...) etc. if the current approach is kept.

ryanofsky commented at 3:11 am on June 27, 2024:

re: #29256 (review)

Could do with a comment such as // Implicitly constructible from a LogFlags value in order to be created by LogDebug(BCLog::NET, ...) etc. if the current approach is kept.

Thank you! Added.

in src/logging.h:215 in 5f64eab013 outdated

207@@ -201,9 +208,36 @@ namespace BCLog {
208         bool DefaultShrinkDebugFile() const;
209     };
210 
211+    //! Object representing a particular source of log messages. Holds a logging
212+    //! category, a reference to the logger object to output to, and a
213+    //! formatting hook.
214+    struct Source {
215+        LogFlags category;

hodlinator commented at 9:13 pm on June 26, 2024:

0        const LogFlags category;

ryanofsky commented at 3:11 am on June 27, 2024:

re: #29256 (review)

Thanks again, but for now I did not take this suggestion. I think making individual struct members const can unnecessarily restrict the ways the struct can be initialized. I think the safety benefits of making the category member const are better enforced and more explicit when the entire struct is const, which should be best practice and already the case everywhere.

in src/test/logging_tests.cpp:98 in 5f64eab013 outdated

93+    LogWarning(log, "warning %s\n", "arg");
94+    LogInfo(log, "info %s\n", "arg");
95+    LogDebug(log, "debug %s\n", "arg");
96+    LogTrace(log, "trace %s\n", "arg");
97+
98+    std::vector<std::string> expected = {

hodlinator commented at 9:21 pm on June 26, 2024:

Could be made constexpr here and in other places:

0    constexpr auto EXPECTED = std::to_array({

ryanofsky commented at 3:11 am on June 27, 2024:

re: #29256 (review)

Could be made constexpr here and in other places:

Thanks! I don’t think there’s an obvious way to make these constexpr, but they should be const, so changed the declarations here, below, and in the next PR.

hodlinator commented at 1:29 pm on June 27, 2024:

I suggested constexpr auto EXPECTED = std::to_array({ above but maybe it doesn’t work for you? Should support constexpr that way under C++20 as far as I can tell. Are you using some fancy interface to GitHub that doesn’t yet show suggestion-embeds?

hodlinator commented at 1:51 pm on June 27, 2024:

Could go even more old-school and do:

0    constexpr const char* EXPECTED[]{
1        ...
2    BOOST_CHECK_EQUAL_COLLECTIONS(log_lines.begin(), log_lines.end(), std::cbegin(EXPECTED), std::cend(EXPECTED));

ryanofsky commented at 2:08 pm on June 28, 2024:

re: #29256 (review)

I suggested constexpr auto EXPECTED = std::to_array({ above but maybe it doesn’t work for you? Should support constexpr that way under C++20 as far as I can tell. Are you using some fancy interface to GitHub that doesn’t yet show suggestion-embeds?

No sorry, that works perfectly. I was just careless and only noticed constexpr without seeing the rest of it. Added your suggestion to this PR and followup PR #30343.

in src/test/logging_tests.cpp:208 in 5f64eab013 outdated

202@@ -86,6 +203,9 @@ BOOST_AUTO_TEST_CASE(logging_timer)
203 BOOST_FIXTURE_TEST_CASE(logging_LogPrintf_, LogSetup)
204 {
205     LogInstance().m_log_sourcelocations = true;
206+    auto LogPrintf_ = [](const std::string&fun, const std::string&file, int line, BCLog::LogFlags category, BCLog::Level level, const auto&... args) {
207+        LogInstance().LogPrintStr(strprintf(args...), fun, file, line, category, level);
208+    };

hodlinator commented at 9:48 pm on June 26, 2024:

Feels like a half-baked workaround for having removed the global LogPrintf_.

ryanofsky commented at 3:11 am on June 27, 2024:

re: #29256 (review)

Feels like a half-baked workaround for having removed the global LogPrintf_.

Yes, good catch. I wanted to leave the test case below unchanged in the main commit to check (and let it be obvious) that the new logging features do not change any current behavior. But it’s not good to leave behind a reference to an old function with a confusing name, so I added a new commit afterwards to modernize the test.

hodlinator changes_requested

hodlinator commented at 10:02 pm on June 26, 2024: contributor

NACK 5f64eab013a58967af37a59c863c2ab6d45ba6e8

At first glance it seems good to be able to specify an optional category to LogInfo, but it risks encouraging inflating LogInfo usage over LogDebug. This could open up future arguments like “you can just filter out the whole category if you don’t like my added LogInfo”. How about disallowing category for LogInfo like we currently do, but optionally accept something like source for the occasional exception like wallet code in #30343?

It’s better to keep requiring either a category (or a source) for LogDebug & LogTrace as they are many and it makes them easier to filter.

ryanofsky referenced this in commit 38d3298ea7 on Jun 27, 2024

ryanofsky force-pushed on Jun 27, 2024

ryanofsky commented at 3:42 am on June 27, 2024: contributor

Updated 5f64eab013a58967af37a59c863c2ab6d45ba6e8 -> 38d3298ea7e547797871140a02df3e7d60d34d36 (pr/bclog.17 -> pr/bclog.18, compare) with suggested changes.

re: #29256#pullrequestreview-2142978382

Thank you for the close review!

On disallowing category arguments in LogInfo, that is an interesting line of reasoning that would not have occurred to me. Your suggestion to only accept source arguments not category arguments for LogInfo would probably be ok and is something I can implement.

If I understand correctly, you are worried that if it is possible to specify categories in LogInfo, then developers will be tempted to add spammy LogInfo prints that will drown out useful information, when they should be using LogDebug instead, because developers will assume that users can filter out categories they are not interested in. I think this is something worth thinking about, but I’m not sure if you know that logging options (before and after this PR) actually do not support filtering out Info/Warning/Error messages at all, by category or otherwise. These are considered unconditional logging levels, so users would need to write scripts or use external software to filter these. I’m not sure if that fact might change your opinion, but it should be concrete rationale that would push back against developers adding spammy LogInfo prints.

It’s also interesting that your reason for not wanting to allow category arguments in LogInfo is sort of the opposite of AJ’s reason for not wanting to allow categories in LogInfo (though the reasons are technically compatible). AJ believes it is unsafe to allow specify category arguments in LogInfo and LogWarning and LogError statements because it creates the risk that users will write external scripts or filters that drop entire categories and leave themselves unaware of important log information. (EDIT: Rereading AJ’s comments, I’m not sure this paragraph actually represents what he thinks, so striking it out.)

I do think there are plausible reasons to want to disallow attaching categories to certain log statements. If the only way I can make progress on this PR is to refuse to allow categories to be specified, I can make changes implementing that. But doing this would not be my starting point because I think generally category information is useful, and as long as we don’t add unsafe options to our own software to filter out entire categories, I think we should try to provide users with category information and let them decide how to use it.

ajtowns commented at 2:47 pm on June 27, 2024: contributor

Rereading AJ’s comments, I’m not sure this paragraph actually represents what he thinks, so striking it out.

Thanks for that, it was bumming me out thinking about how to try and clarify it.

I really prefer your approach in #30348 and #30347 where you identify a specific objective problem and separately propose a targeted fix for exactly that problem.

logging options (before and after this PR) actually do not support filtering out Info/Warning/Error messages at all, by category or otherwise

Note that filtering out Info messages was previously a feature the logging system (and in particular, Info messages with a category would be filtered out by default). That feature was removed in https://github.com/bitcoin/bitcoin/pull/28318/commits/ab34dc6012351e7b8aab871dd9d2b38ade1cd9bc .

I’ll have another go at explaining my point of view:

But doing this would not be my starting point because I think generally category information is useful,

I don’t think category information is useful except for enabling log message filtering. It’s not useful otherwise, because -logsourcelocations is strictly superior in multiple ways (it’s automatic, it doesn’t need to be updated if we refactor things, and it gives more detailed information). For messages we don’t want users to filter, we shouldn’t provide a category, as that would provide no benefit at all.

hodlinator commented at 8:40 pm on June 27, 2024: contributor

On disallowing category arguments in LogInfo, that is an interesting line of reasoning that would not have occurred to me. Your suggestion to only accept source arguments not category arguments for LogInfo would probably be ok and is something I can implement.

I do think there are plausible reasons to want to disallow attaching categories to certain log statements. If the only way I can make progress on this PR is to refuse to allow categories to be specified, I can make changes implementing that.

Cool! Hoping that’s something @ajtowns could agree to allowing something like an optional source being passed to LogInfo etc to make the wallet code and other exceptions nicer without suddenly also accepting category everywhere.

The fact that there’s something behind the immediate macro level preventing LogInfo/LogError/LogWarning from being filtered is a weaker argument to use in pushing against added logging outside of LogDebug/LogTrace statements, than them not even accepting a category to potentially filter on. Gotta respect an opinionated API. :)

ryanofsky referenced this in commit 681b21f7ca on Jun 28, 2024

ryanofsky force-pushed on Jun 28, 2024

ryanofsky commented at 2:23 pm on June 28, 2024: contributor

re: #29256 (comment)

The fact that there’s something behind the immediate macro level preventing LogInfo/LogError/LogWarning from being filtered is a weaker argument to use in pushing against added logging outside of LogDebug/LogTrace statements, than them not even accepting a category to potentially filter on. Gotta respect an opinionated API. :)

Understood. If the current restrictions which prevent categories from being filtered out are not enough, a developer restriction to prevent categories constants from being specified could be a stronger tool to do the things you and maybe AJ are trying to accomplish. I implemented that restriction in 44afae705a12252149adbe7ac6d3646052b8bf3b and would be ok with adding it this PR if it solves problems for you and AJ, even if I don’t personally see a need for the API to be so restrictive.

I will say one nice thing about the approach in 44afae705a12252149adbe7ac6d3646052b8bf3b is that someone tries to write a LogInfo statement that includes a category they will get a clear static_assert error explaining that they need to drop the category argument or reduce the log level, instead of just seeing preprocessor and strprintf errors which are harder to decipher.

Updated 38d3298ea7e547797871140a02df3e7d60d34d36 -> 681b21f7ca07f0e1411354baa01649e7b1f30e8c (pr/bclog.18 -> pr/bclog.19, compare) with suggested constexpr change (thank you for the suggestion!)

jonatack commented at 4:58 pm on June 28, 2024: member

All consistent, now accepting the same parameters All compatible with log categories, to make it possible to filter or highlight log messages from a particular component All compatible with wallet logging, which includes the wallet name in log messages Require less verbosity, by not needing category constants to be repeated in log prints from a common source. Not tied to one hardcoded global Logger instance

I think I’d be Concept ACK on these, though I’ve somewhat tuned out since the unfortunate deviation the severity-based logging has taken since #28318 for the reasons I’ve stated there and in other PRs.

We’ve just over-wrought everything when it could be simple and open. A number of other developers think the same but don’t speak up much because it seems pointless to do so.

Aside, and unsure it is an issue of discussion: Unless proven otherwise in practice later on, I do not think we need to be overly paranoid and helicopter parenting yet with respect to node operators footgunning themselves en masse with custom log level settings. Only developers and more technically aware users are likely to use them.

ryanofsky commented at 5:22 pm on June 28, 2024: contributor

re: #29256 (comment)

We’ve just over-complicated everything when it could be simple and open. I know a number of other developers think the same but don’t speak up much because it seems pointless to do so.

Curious, when you say “over-complicated”, are you referring to the implementation of the logging code, or to the usage of the logging API? Or to effects of logging settings?

I don’t think the logging API is too complicated. I think #28318 made it more self documenting and simpler.

On the other hand, I would say that the macro definitions used to implement the logging API are pretty complicated. This PR does try to improve them by making the implementation sequential and documenting every part of it. But I think it is ok for the implementation to be complicated if the interface is simple, and if there are legitimate reasons to make it complicated, like not evaluating arguments when debug logging is turned off.

I’m not sure about interpretation of logging settings, but I haven’t been involved in those PRs.

ajtowns commented at 6:49 pm on June 28, 2024: contributor

AJ, thanks for the response. I want to let your comment stand, and not reply in detail right away to wait for input on this PR from other potential reviewers.

That comment had already stood for eight weeks, and included an example patchset of changes that could improve things with regards to your complaints about wallet logging, while discussion continued on this. Instead we’ve had no progress and no discussion, which seems to me to be pretty counter productive. I’ve opened up what I assume is the least controversial of those as #30355 if you have any interest.

jonatack commented at 6:52 pm on June 28, 2024: member

Curious, when you say “over-complicated”, are you referring to the implementation of the logging code, or to the usage of the logging API? Or to effects of logging settings?

All of these, I think. The idea was:

one Log(level, cat, msg) macro with a consistent API replace the current macros
the -debug and -loglevel config options and logging RPC soft-aligned into a single user-facing logging API
the printed logs to be the same format for each Log call, apart from custom options
developer documentation in the Log macro and the level/category enums, where grepping would lead you directly

Instead (from memory, I’m maybe not up to date), we now have:

a larger slew of macros
an inconsistent API and printed log that vary depending on which of the new level macros is called
various restrictions on calls and usage
documentation in various places
all these ducks to keep in a row

None of that seems necessary (unless there is a technical obstacle?)

I suggest doing the simplest consistent implementation and API we can come up. Easier for both users and developers. Those seem more valuable than e.g. saving characters that developers might copy/paste when adding new logging.

ryanofsky commented at 7:54 pm on June 28, 2024: contributor

re: #29256 (comment)

Thanks I appreciate the clarification, and I agree with most of those points, except I genuinely do think having one convenience macro for each log level is nice. And LogPrintLevel exists so it is even possible to ignore the convenience macros if you want to do that.

Just as an observation, I get the sense that I am not the only one who likes the convenience macros, and that when other people read your comments complaining about the existence of these macros, it might make them discount the value of other things you are saying. So I don’t know if it would help, but it might be better if you could come to a grudging acceptance of the macros, and think about not bringing them up if they aren’t essential to points you are making. It might help other points be better received and understood.

hodlinator commented at 10:25 pm on June 28, 2024: contributor

(For what it is worth, I’m used to thin convenience macros for logging from other codebases. In the ecosystem we also have https://github.com/ElementsProject/lightning/blob/master/lightningd/log.h which follows the same pattern).

I implemented that restriction in 44afae705a12252149adbe7ac6d3646052b8bf3b and would be ok with adding it this PR if it solves problems for you and AJ, even if I don’t personally see a need for the API to be so restrictive.

The API feels good to me, nice touch with the static_assert! Wish the implementation of the combined functionality were simpler, but don’t have the throughput to attempt boiling it down right now.

Side note: LogPrintfCategory surprised me in that it is logging with categories at Info-level. Seems to be only used by tests and benchmarks.. maybe uses of it could be removed as it was deprecated in the last release, or changed to use LogDebug?

DrahtBot added the label Needs rebase on Jul 26, 2024

ryanofsky referenced this in commit db2e3ff6fe on Aug 7, 2024

ryanofsky referenced this in commit 46f5e27e86 on Aug 7, 2024

ryanofsky force-pushed on Aug 7, 2024

DrahtBot removed the label Needs rebase on Aug 7, 2024

DrahtBot added the label Needs rebase on Sep 2, 2024

ryanofsky referenced this in commit 117de1cc26 on Dec 9, 2024

ryanofsky force-pushed on Dec 9, 2024

DrahtBot removed the label Needs rebase on Dec 9, 2024

ryanofsky commented at 2:00 pm on December 10, 2024: contributor

Rebased 46f5e27e86f9bd2c88df86f0d652fedab1bd0f21 -> 48b3c951aa256c6be0cc50461de00f758d92dcb4 (pr/bclog.20 -> pr/bclog.21, compare) due to conflicts with with #31174 and other PRs. Updated 48b3c951aa256c6be0cc50461de00f758d92dcb4 -> 5db1958e60aef9d3604448c21e1f397e561480ee (pr/bclog.21 -> pr/bclog.22, compare) to fix MSVC error C3495 https://github.com/bitcoin/bitcoin/actions/runs/12242607762/job/34150305407?pr=29256

If reviewers agree with previous feedback that allowing category arguments to be passed to LogError/LogWarning/LogInfo macros is dangerous because it encourages developers to add log spam and encourages users to ignore important messages, I can add commit 0b5cbf9ee8ca39b91c6c635d27df94ec618be5cb here so specifying categories will remain forbidden. Would prefer not to do this because providing a consistent API and providing context with log messages seem like tangible benefits to me, while the current restrictions seem like an indirect and ineffective solution to log spam, but I could live with the restrictions if having them unblocks #30342 and #30343.

in src/logging.h:306 in 5db1958e60 outdated

334-        }                                                 \
335+//! Internal helper to return first arg in a __VA_ARGS__ pack. This could be
336+//! simplified to `#define _FirstArg(arg, ...) arg` if not for a preprocessor
337+//! bug in Visual C++.
338+#define _FirstArgImpl(arg, ...) arg
339+#define _FirstArg(args) _FirstArgImpl args

hodlinator commented at 11:21 pm on December 13, 2024:

This looks less weird, would it be equivalent in this case or defeat the purpose?

0#define _FirstArg(args) _FirstArgImpl(args)

ryanofsky commented at 5:39 pm on April 3, 2025:

re: #29256 (review)

This looks less weird, would it be equivalent in this case or defeat the purpose?

Yeah, that doesn’t really work here because args contains multiple arguments already enclosed in parentheses, so adding extra parentheses prevents them from being separated.

in src/logging.h:283 in 5db1958e60 outdated

301-#define LogWarning(...) LogPrintLevel_(BCLog::LogFlags::ALL, BCLog::Level::Warning, __VA_ARGS__)
302-#define LogError(...) LogPrintLevel_(BCLog::LogFlags::ALL, BCLog::Level::Error, __VA_ARGS__)
303+//! Internal helper to get log source object from macro argument, if argument is
304+//! BCLog::Source object or a category constant that BCLog::Source can be
305+//! constructed from.
306+static inline const BCLog::Source& _LogSource(const BCLog::Source& source LIFETIMEBOUND) { return source; }

hodlinator commented at 11:33 pm on December 13, 2024:

Maybe best to avoid introducing identifiers starting with underscore, especially if followed by uppercase?

https://stackoverflow.com/a/228848

ryanofsky commented at 5:40 pm on April 3, 2025:

re: #29256 (review)

Maybe best to avoid introducing identifiers starting with underscore, especially if followed by uppercase?

https://stackoverflow.com/a/228848

Thanks, I had no idea those were reserved. Switched to a detail namespace for the functions and trailing underscore for the macros.

in src/logging.h:317 in 5db1958e60 outdated

345+            const auto& func = __func__;                                  \
346+            _LogFormat([&](auto&& source, auto&& message) {               \
347+                source.logger.LogPrintStr(message, func, __FILE__,        \
348+                    __LINE__, source.category, (level));                  \
349+            }, _LogSource(_FirstArg((__VA_ARGS__))), __VA_ARGS__);        \
350+        }                                                                 \

hodlinator commented at 11:37 pm on December 13, 2024:

nit: Could potentially avoid repeated Source construction:

0        auto log_source = _LogSource(_FirstArg((__VA_ARGS__)));           \
1        if (LogEnabled(log_source, (level))) {                            \
2            const auto& func = __func__;                                  \
3            _LogFormat([&](auto&& source, auto&& message) {               \
4                source.logger.LogPrintStr(message, func, __FILE__,        \
5                    __LINE__, source.category, (level));                  \
6            }, log_source, __VA_ARGS__);                                  \
7        }                                                                 \

ryanofsky commented at 5:41 pm on April 3, 2025:

re: #29256 (review)

nit: Could potentially avoid repeated Source construction:

Thanks that is cleaner. Switched to this approach.

hodlinator changes_requested

hodlinator commented at 10:11 pm on December 14, 2024: contributor

Code reviewed 5db1958e60aef9d3604448c21e1f397e561480ee + 0b5cbf9ee8ca39b91c6c635d27df94ec618be5cb

PR style

I think it would be clearer to introduce the logging_source_args-test by itself in an initial commit without any behavioral changes to the logging system, to then have following commits demonstrate how the output changes.

Subjective title

The PR title (and commit messages) is/are misleading/heavily subjective: “Improve new LogDebug/Trace/Info/Warning/Error Macros” More objective: “Make LogInfo/Warning/Error accept category and stop requiring it for LogDebug/Trace”

But that title doesn’t manage to also squeeze in what I think is the undisputedly useful part here - the log-source concept (required by child PRs #30342 and #30343). I wish that would be introduced without the other API changes.

Suggested change

0b5cbf9ee8ca39b91c6c635d27df94ec618be5cb disallowing categories for high priority levels does not go far enough, it is even more important that categories still be required for Debug/Trace IMO, to prevent spamming across categories. Took a stab at implementing that in additional commit ~~86c7b578cb4563a09783d95e95adc437c04447bc~~ cebc9e2a22892abf70f16f08a0cbfb12a98291b5. (It also resets the category for high priority levels).

With my change the PR title could more or less be changed to “Add log source and non-global logging support”.

To me it still feels like we should live with the consciously made API decisions from #28318 a bit longer without having to change them.

ryanofsky renamed this:
~~Improve new LogDebug/Trace/Info/Warning/Error Macros~~
log, refactor: Allow log macros to accept context arguments
on Apr 3, 2025

ryanofsky force-pushed on Apr 3, 2025

DrahtBot added the label CI failed on Apr 3, 2025

DrahtBot commented at 5:37 pm on April 3, 2025: contributor

🚧 At least one of the CI tasks failed. Debug: https://github.com/bitcoin/bitcoin/runs/39937528078

Try to run the tests locally, according to the documentation. However, a CI failure may still happen due to a number of reasons, for example:

Possibly 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.
A sanitizer issue, which can only be found by compiling with the sanitizer and running the affected test.
An intermittent issue.

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

ryanofsky commented at 5:53 pm on April 3, 2025: contributor

Rebased 5db1958e60aef9d3604448c21e1f397e561480ee -> 07295ff649e72e267b6f285dcf0f670e676019ef (pr/bclog.22 -> pr/bclog.23, compare) with suggested changes adding back #28318 restrictions. Updated 07295ff649e72e267b6f285dcf0f670e676019ef -> 2ebcc54b886dd7e54688bf7e0a6238e354a35236 (pr/bclog.23 -> pr/bclog.24, compare) to fix CI “no return statement in function” errors from GCC Updated 2ebcc54b886dd7e54688bf7e0a6238e354a35236 -> 176ad35e69b2f0ba94b4db47c66a583b1bf87744 (pr/bclog.24 -> pr/bclog.25, compare) to fix CI errors from older clang versions and add new unit test in separate commit as suggested.

Updated 176ad35e69b2f0ba94b4db47c66a583b1bf87744 -> 093d58e055b10a1031c97b24de5e029221f176d7 (pr/bclog.25 -> pr/bclog.26, compare) with minor tweaks to declarations and commit messages.

re: #29256#pullrequestreview-2503381924

Thanks @hodlinator. I really appreciate you figuring out how to implement the restrictions from #28318. Even though I don’t like them, I don’t think they add a very big cost, so I’ve incorporated them to help narrow the scope of this PR and unblock it.

I’m still unable to wrap my head around the appeal of a logging framework with an inconsistent API that yells at you if you supply too much context for important messages, and yells at you if you give too little context for less important messages. I can follow the logic which leads to the conclusion that the restrictions are good, but it’s not compelling to me, and seems like it just makes the logging framework jankier for developers and users and different from logging frameworks that are well regarded anywhere else. But dropping the restrictions is not the main goal of this PR, so I’m ok with keeping them.

I think it would be clearer to introduce the logging_source_args-test by itself in an initial commit without any behavioral changes to the logging system, to then have following commits demonstrate how the output changes.

Missed this suggestion but will implement in the next push. Need to fix some issues happening in CI anyway. (UPDATE: Implemented this suggestion now).–

Rebased 093d58e055b10a1031c97b24de5e029221f176d7 -> d032022ff59204b85b2057ab9a88f4d2842dbde9 (pr/bclog.26 -> pr/bclog.27, compare)

Updated d032022ff59204b85b2057ab9a88f4d2842dbde9 -> a66d1e27f11b2c061879dbee02b889fad5cc2669 (pr/bclog.27 -> pr/bclog.28, compare) to fix silent conflict with #33517 (https://github.com/bitcoin/bitcoin/actions/runs/18514130088?pr=29256)

Updated a66d1e27f11b2c061879dbee02b889fad5cc2669 -> 8428899fb97ea5f71e879f958b4f10846f28e73a (pr/bclog.28 -> pr/bclog.29, compare) to fix source_location print, not using location inside lambda

Rebased 8428899fb97ea5f71e879f958b4f10846f28e73a -> 3e4c8b9320783f2985937e9f326df3bc532e7905 (pr/bclog.29 -> pr/bclog.30, compare)

Rebased 3e4c8b9320783f2985937e9f326df3bc532e7905 -> cecf87c92a459b462d98d43c3e5c0b87286c1e4e (pr/bclog.30 -> pr/bclog.31, compare)

Rebased cecf87c92a459b462d98d43c3e5c0b87286c1e4e -> c566ebc71083e93b6898e37549fc42eb524dcf10 (pr/bclog.31 -> pr/bclog.32, compare)

Rebased c566ebc71083e93b6898e37549fc42eb524dcf10 -> 326c62d1d327549526f2975342bd64c82231a16a (pr/bclog.32 -> pr/bclog.33, compare) due to conflicts

Updated 326c62d1d327549526f2975342bd64c82231a16a -> 1ceea94931b72bc1f949fbaab1f26a0ef6eb4a21 (pr/bclog.33 -> pr/bclog.34, compare) to fix clang-tidy and iwyu errors https://github.com/bitcoin/bitcoin/actions/runs/21103601009

Rebased 1ceea94931b72bc1f949fbaab1f26a0ef6eb4a21 -> e19ce37359227849ec55d45dfd33303ccaceeccf (pr/bclog.34 -> pr/bclog.35, compare) due to conflict with #34465, reimplementing macros to use new util::log::Log/ShouldLog interface and restore info/warning/error argument evaluation behavior, cherry-picking stickies verify log argument evaluation semantics test from #34465#pullrequestreview-3763887226

Updated e19ce37359227849ec55d45dfd33303ccaceeccf -> 487f7e77cf8569b15a86631e03439dd648703822 (pr/bclog.35 -> pr/bclog.36, compare) to fix IWYU errors https://github.com/bitcoin/bitcoin/actions/runs/21826859168/job/62975817002?pr=29256, also updatimg commit messages

Rebased 487f7e77cf8569b15a86631e03439dd648703822 -> 6d91998175b40939001e01ae2cd78571bff392b7 (pr/bclog.36 -> pr/bclog.37, compare) with some tweaks and update for adyshimony review #30343#pullrequestreview-3871171023

ryanofsky force-pushed on Apr 3, 2025

ryanofsky force-pushed on Apr 4, 2025

DrahtBot removed the label CI failed on Apr 4, 2025

in src/test/logging_tests.cpp:101 in 093d58e055

 96+    LogTrace(log, "trace %s\n", "arg");
 97+
 98+    constexpr auto expected{std::to_array({
 99+        "[net:error] error arg\n",
100+        "[net:warning] warning arg\n",
101+        "[net:info] info arg\n",

hodlinator commented at 12:22 pm on April 12, 2025:

This still goes against the intent of #28318 in my opinion, by adding categories to output of LogError/LogWarning/LogInfo when used with context.
This also changes behavior insofar as adding [.*info] -prefixes for LogInfo(), which were intentionally avoided in #28318:

https://github.com/bitcoin/bitcoin/blob/e60fc7d5d34f23cccbff6e4f5f3d716fa8dad50c/src/test/logging_tests.cpp#L139-L149

See other comment about suggested change to LogPrint_() to address both above points.

Especially LogInfo() without any prefix would feel less “naked” if you were to import the test with CustomLogContext from fea5da15eef4479729aa27868277a720fdfe36e8 (#30343) into this PR to demonstrate usage. Doing so would also give a greater sense of completeness here IMO.

ryanofsky commented at 4:29 pm on March 3, 2026:

re: #29256 (review)

See other comment about suggested change to LogPrint_() to address both above points.

Thanks! Done

Especially LogInfo() without any prefix would feel less “naked” if you were to import the test with CustomLogContext from fea5da1 ([wallet, logging: Replace WalletLogPrintf() with LogInfo() #30343](https://github.com/bitcoin/bitcoin/pull/30343)) into this PR to demonstrate usage. Doing so would also give a greater sense of completeness here IMO.

This makes sense, and also simplifies #30343. It’s done now in the “Add support for custom log sources” commit.

in src/test/logging_tests.cpp:92 in 093d58e055

87+
88+    std::vector<std::string> messages;
89+    logger.PushBackCallback([&](const std::string& s) { messages.push_back(s); });
90+
91+    BCLog::Context log{logger, BCLog::NET};
92+    LogError(log, "error %s\n", "arg");

hodlinator commented at 12:22 pm on April 12, 2025:

nit: Superfluous newlines here and in the other new test case below:

0    LogError(log, "error %s", "arg");

ryanofsky commented at 4:24 pm on March 3, 2026:

re: #29256 (review)

nit: Superfluous newlines here and in the other new test case below:

Thanks! These are removed now

in src/logging.h:340 in 093d58e055

371+        const auto& ctx{BCLog::detail::GetContext<take_category>(FirstArg_((__VA_ARGS__)))}; \
372+        if (LogEnabled(ctx, (level))) {                                        \
373+            const auto& func = __func__;                                       \
374+            BCLog::detail::Format([&](auto&& message) {                        \
375+                ctx.logger.LogPrintStr(message, func, __FILE__, __LINE__,      \
376+                    ctx.category, (level));                                    \

hodlinator commented at 2:49 pm on April 12, 2025:

LogPrint_() - Highly suggest one remaining change to maintain output behavior for LogError/LogWarning/LogInfo when used with context:

0                    take_category ? ctx.category : BCLog::LogFlags::ALL,       \
1                    (level));                                                  \

One can still use the escape hatch of LogPrintLevel() or LogPrintStr() if one wants things like [net:info] -prefixes.

Looking back, this is a reinvention of that part of my change in cebc9e2a22892abf70f16f08a0cbfb12a98291b5 from #29256#pullrequestreview-2503381924. Curious to at least hear your thoughts. Not a definite blocker as context-support is after all something new.

ryanofsky commented at 4:25 pm on March 3, 2026:

re: #29256 (review)

Highly suggest one remaining change to maintain output behavior for LogError/LogWarning/LogInfo when used with context:

Thanks! Applied change here

hodlinator commented at 10:08 pm on April 12, 2025: contributor

Code reviewed 093d58e055b10a1031c97b24de5e029221f176d7

Thank you for changing the end result of this PR to abide by the API decisions of #28318!

(Still think it’s a bit odd to open up the gates in eaac991552abe9bfbffc22d99a8baee659ae3173 to then return to closer to master behavior in 093d58e055b10a1031c97b24de5e029221f176d7. But no blocker).

While the API has been “reverted”, I still think there’s a shift in behavior (output) - see inline comments.

(Sorry I didn’t get to this sooner, somehow only registered that you had rebased before looking back at this today).

DrahtBot added the label Needs rebase on Jul 9, 2025

ryanofsky referenced this in commit d032022ff5 on Oct 15, 2025

ryanofsky force-pushed on Oct 15, 2025

DrahtBot removed the label Needs rebase on Oct 15, 2025

ryanofsky force-pushed on Oct 16, 2025

ryanofsky referenced this in commit a66d1e27f1 on Oct 16, 2025

ryanofsky referenced this in commit 8428899fb9 on Oct 16, 2025

ryanofsky force-pushed on Oct 16, 2025

ryanofsky force-pushed on Nov 10, 2025

ryanofsky referenced this in commit 3e4c8b9320 on Nov 10, 2025

ryanofsky referenced this in commit 0b6b767ab0 on Nov 10, 2025

DrahtBot added the label Needs rebase on Dec 6, 2025

ryanofsky referenced this in commit d32ad18068 on Dec 12, 2025

ryanofsky force-pushed on Dec 12, 2025

ryanofsky referenced this in commit cecf87c92a on Dec 12, 2025

DrahtBot removed the label Needs rebase on Dec 12, 2025

DrahtBot added the label Needs rebase on Dec 14, 2025

ryanofsky referenced this in commit c566ebc710 on Dec 16, 2025

ryanofsky force-pushed on Dec 16, 2025

ryanofsky referenced this in commit 35459502c1 on Dec 16, 2025

DrahtBot removed the label Needs rebase on Dec 16, 2025

DrahtBot added the label Needs rebase on Dec 18, 2025

ryanofsky force-pushed on Jan 18, 2026

ryanofsky referenced this in commit 326c62d1d3 on Jan 18, 2026

ryanofsky referenced this in commit 257cd10d9a on Jan 18, 2026

DrahtBot removed the label Needs rebase on Jan 18, 2026

DrahtBot added the label CI failed on Jan 18, 2026

DrahtBot commented at 2:48 am on January 18, 2026: contributor

🚧 At least one of the CI tasks failed. Task iwyu: https://github.com/bitcoin/bitcoin/actions/runs/21103601009/job/60691387379 LLM reason (✨ experimental): IWYU (include-what-you-use) check failed, causing the CI job to exit with an error.

Try to run the tests locally, according to the documentation. However, a CI failure may still happen due to a number of reasons, for example:

Possibly 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.
A sanitizer issue, which can only be found by compiling with the sanitizer and running the affected test.
An intermittent issue.

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

ryanofsky force-pushed on Jan 18, 2026

ryanofsky referenced this in commit 1ceea94931 on Jan 18, 2026

DrahtBot removed the label CI failed on Jan 18, 2026

DrahtBot added the label Needs rebase on Feb 8, 2026

ryanofsky force-pushed on Feb 9, 2026

ryanofsky referenced this in commit e19ce37359 on Feb 9, 2026

ryanofsky referenced this in commit 7d4654b27e on Feb 9, 2026

ryanofsky referenced this in commit 487f7e77cf on Feb 9, 2026

ryanofsky force-pushed on Feb 9, 2026

DrahtBot added the label CI failed on Feb 9, 2026

DrahtBot commented at 2:32 pm on February 9, 2026: contributor

🚧 At least one of the CI tasks failed. Task iwyu: https://github.com/bitcoin/bitcoin/actions/runs/21826859168/job/62975817002 LLM reason (✨ experimental): IWYU error detected (include-what-you-use failure) causing the CI to fail.

Try to run the tests locally, according to the documentation. However, a CI failure may still happen due to a number of reasons, for example:

Possibly 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.
A sanitizer issue, which can only be found by compiling with the sanitizer and running the affected test.
An intermittent issue.

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

DrahtBot removed the label Needs rebase on Feb 9, 2026

DrahtBot removed the label CI failed on Feb 9, 2026

ryanofsky referenced this in commit 8294ddd63a on Mar 2, 2026

ryanofsky force-pushed on Mar 2, 2026

ryanofsky referenced this in commit 6d91998175 on Mar 2, 2026

in src/util/log.h:109 in 6d91998175

121-        .category = flag,
122+    //! Trigger compile error if caller tries to pass a category constant as a
123+    //! first argument to a logging call that specifies take_category == false.
124+    //! There is no technical reason why all logging calls could not accept
125+    //! category arguments, but for various reasons, such as (1) not wanting to
126+    //! allow users filter by category at high priority levels, and (2) wanting

l0rinc commented at 11:45 am on March 2, 2026:

6d91998 log refactor: Disallow category args to logging macros:

0    //! allow users to filter by category at high priority levels, and (2) wanting

ryanofsky commented at 3:07 pm on March 4, 2026:

re: #29256 (review)

Thanks, added “to”

in src/util/log.h:162 in 6d91998175

199-        }                                                              \
200+// NOLINTBEGIN(bugprone-lambda-function-name)
201+#define LogPrint_(level, should_ratelimit, take_category, ...)                                     \
202+    do {                                                                                           \
203+        const auto& _source{util::log::detail::GetSource<take_category>(FirstArg_((__VA_ARGS__)))}; \
204+        if (util::log::ShouldLog(_source.logger, _source.category, (level))) {                     \

l0rinc commented at 11:46 am on March 2, 2026:

6d91998 log refactor: Disallow category args to logging macros:

Why does ShouldLog rely on _source.category even when take_category is false? Later, we swap it to .category = take_category ? source.category : BCLog::LogFlags::ALL, so it seems cleaner to check what we will actually be logging:

0        auto category{take_category ? _source.category : BCLog::LogFlags::ALL}; \
1        if (util::log::ShouldLog(_source.logger, category, (level))) {                            \

Nit: the trailing \ are unaligned now, and my OCD is flaring up.

ryanofsky commented at 3:13 pm on March 4, 2026:

re: #29256 (review)

6d91998 log refactor: Disallow category args to logging macros: Why does ShouldLog rely on _source.category even when take_category is false

Good point that this inconsistency does not make sense. After #34465, interpretation of category values should be happend at log-handling level, and log-generating macros should not be involved. I split off a new commit “log refactor: Ensure categories are not logged at info and higher levels” from the existing commit “log refactor: Disallow category args to logging macros” to separate the two parts of this change and implement it more cleanly.

Nit: the trailing \ are unaligned now, and my OCD is flaring up.

Fixed this too :)

in src/test/logging_tests.cpp:146 in 9a07d8c0ca outdated

141+    std::ifstream file{tmp_log_path.std_path()};
142+    std::vector<std::string> log_lines;
143+    for (std::string log; std::getline(file, log);) {
144+        log_lines.push_back(log);
145+    }
146+    BOOST_CHECK_EQUAL_COLLECTIONS(log_lines.begin(), log_lines.end(), expected.begin(), expected.end());

l0rinc commented at 3:35 pm on March 3, 2026:

9a07d8c log test: Add test for currently accepted logging arguments:

Can we use ReadDebugLogLines instead like we do in logging_LogPrintStr?

 0    const auto log_lines{ReadDebugLogLines()};
 1    constexpr auto expected{std::to_array({
 2        "[error] error",
 3        "[warning] warning",
 4        "info",
 5
 6        "[error] error arg",
 7        "[warning] warning arg",
 8        "info arg",
 9
10        "[net] debug",
11        "[net:trace] trace",
12
13        "[net] debug arg",
14        "[net:trace] trace arg",
15    })};
16    BOOST_CHECK_EQUAL_COLLECTIONS(log_lines.begin(), log_lines.end(), expected.begin(), expected.end());

ryanofsky commented at 3:14 pm on March 4, 2026:

re: #29256 (review)

Can we use ReadDebugLogLines instead like we do in logging_LogPrintStr?

Yes nice suggestion, should be done in all commits now.

in src/test/logging_tests.cpp:126 in 9a07d8c0ca outdated

121+    LogDebug(BCLog::NET, "debug");
122+    LogTrace(BCLog::NET, "trace");
123+    LogDebug(BCLog::NET, "debug %s", "arg");
124+    LogTrace(BCLog::NET, "trace %s", "arg");
125+
126+    constexpr auto expected{std::to_array({

l0rinc commented at 3:37 pm on March 3, 2026:

9a07d8c log test: Add test for currently accepted logging arguments:

nit: we might as well include <array> now that we’re here

ryanofsky commented at 3:14 pm on March 4, 2026:

re: #29256 (review)

nit: we might as well include <array> now that we’re here

Added this

in src/test/logging_tests.cpp:515 in 1987fb2fb0

506@@ -507,4 +507,26 @@ BOOST_FIXTURE_TEST_CASE(logging_filesize_rate_limit, LogSetup)
507     }
508 }
509 
510+BOOST_FIXTURE_TEST_CASE(logging_arg_evaluation, LogSetup)
511+{
512+    size_t counter{0};
513+    auto side_effect = [&counter]() {
514+        return ++counter;
515+    };

l0rinc commented at 3:39 pm on March 3, 2026:

1987fb2 log test: verify log argument evaluation semantics:

nit: () isn’t needed here:

0    auto side_effect = [&counter] { return ++counter; };

ryanofsky commented at 3:15 pm on March 4, 2026:

re: #29256 (review)

nit: () isn’t needed here:

Thanks, and latest version drops this lambda to simplify the test

in src/test/logging_tests.cpp:519 in 1987fb2fb0

514+        return ++counter;
515+    };
516+
517+    // Even when logging is disabled, Info or higher should still evaluate its arguments
518+    LogInstance().DisconnectTestLogger();
519+    LogInstance().DisableLogging();

l0rinc commented at 3:40 pm on March 3, 2026:

1987fb2 log test: verify log argument evaluation semantics:

These conditions should also hold when they are enabled. Can we try a loop instead?

ryanofsky commented at 3:16 pm on March 4, 2026:

re: #29256 (review)

These conditions should also hold when they are enabled. Can we try a loop instead?

Makes sense, applied your other suggestion adding the loop.

in src/test/logging_tests.cpp:529 in 1987fb2fb0

524+    BOOST_CHECK_EQUAL(counter, 3);
525+
526+    // Skip argument evaluation when category is disabled
527+    LogDebug(BCLog::NET, "debug (%i)", side_effect());
528+    LogTrace(BCLog::NET, "trace (%i)", side_effect());
529+    BOOST_CHECK_EQUAL(counter, 3);

l0rinc commented at 3:45 pm on March 3, 2026:

1987fb2 log test: verify log argument evaluation semantics:

Nit: no biggie, but it might be simpler and more conceptually symmetric to untangle this from the previous ones by resetting the counter before the run and asserting 0 here.

 0BOOST_FIXTURE_TEST_CASE(logging_arg_evaluation, LogSetup)
 1{
 2    int counter{0};
 3    auto side_effect = [&counter] { return ++counter; };
 4
 5    for (bool enable_logger : {true, false}) {
 6        LogInstance().DisconnectTestLogger();
 7        if (enable_logger) {
 8            BOOST_REQUIRE(LogInstance().StartLogging());
 9        } else {
10            LogInstance().DisableLogging();
11        }
12        BOOST_REQUIRE_EQUAL(enable_logger, LogInstance().Enabled());
13
14        // Info or higher should always evaluate the arguments.
15        counter = 0;
16        LogError("error (%s)", side_effect());
17        LogWarning("warning (%s)", side_effect());
18        LogInfo("info (%s)", side_effect());
19        BOOST_CHECK_EQUAL(counter, 3);
20
21        // Debug/Trace should skip argument evaluation when category is disabled.
22        counter = 0;
23        LogDebug(BCLog::NET, "debug (%s)", side_effect());
24        LogTrace(BCLog::NET, "trace (%s)", side_effect());
25        BOOST_CHECK_EQUAL(counter, 0);
26    }
27}

(applied all suggestions to the example)

ryanofsky commented at 3:17 pm on March 4, 2026:

re: #29256 (review)

Nit: no biggie, but it might be simpler and more conceptually symmetric to untangle this from the previous ones by resetting the counter before the run and asserting 0 here.

Thanks, applied your suggestion with a simplification dropping the lambda as well.

in src/test/logging_tests.cpp:521 in 1987fb2fb0

516+
517+    // Even when logging is disabled, Info or higher should still evaluate its arguments
518+    LogInstance().DisconnectTestLogger();
519+    LogInstance().DisableLogging();
520+    BOOST_CHECK(!LogInstance().Enabled());
521+    LogError("error (%i)", side_effect());

l0rinc commented at 3:45 pm on March 3, 2026:

1987fb2 log test: verify log argument evaluation semantics:

for simplicity we could just use %s everywhere

ryanofsky commented at 3:18 pm on March 4, 2026:

re: #29256 (review)

for simplicity we could just use %s everywhere

Thanks included this with your suggestion

in src/test/logging_tests.cpp:517 in 1987fb2fb0

512+    size_t counter{0};
513+    auto side_effect = [&counter]() {
514+        return ++counter;
515+    };
516+
517+    // Even when logging is disabled, Info or higher should still evaluate its arguments

l0rinc commented at 3:49 pm on March 3, 2026:

1987fb2 log test: verify log argument evaluation semantics:

super-nit: its arguments? shouldn’t it be the(ir) arguments?

ryanofsky commented at 3:19 pm on March 4, 2026:

re: #29256 (review)

super-nit: its arguments? shouldn’t it be the(ir) arguments?

Included the fix in your suggestion

in src/test/logging_tests.cpp:113 in ee3fb8cf39

108+{
109+    BCLog::Logger logger;
110+    logger.m_log_timestamps = false;
111+    logger.EnableCategory(BCLog::LogFlags::ALL);
112+    logger.SetLogLevel(BCLog::Level::Trace);
113+    logger.StartLogging();

l0rinc commented at 4:09 pm on March 3, 2026:

ee3fb8c log refactor: Allow log macros to accept source arguments:

nit:

0    BOOST_REQUIRE(logger.StartLogging());

ryanofsky commented at 3:19 pm on March 4, 2026:

re: #29256 (review)

Thanks, added BOOST_REQUIRE

in src/logging.cpp:614 in ee3fb8cf39 outdated

613 
614-void util::log::Log(util::log::Entry entry)
615+void util::log::Log(Logger* log, Entry entry)
616 {
617-    BCLog::Logger& logger{LogInstance()};
618+    auto& logger{log ? *static_cast<BCLog::Logger*>(log) : LogInstance()};

l0rinc commented at 5:03 pm on March 3, 2026:

ee3fb8c log refactor: Allow log macros to accept source arguments:

I don’t get why this is needed. If the parameter is available, we always cast it. It seems like an abstraction failure.

ryanofsky commented at 3:48 pm on March 4, 2026:

re: #29256 (review)

I don’t get why this is needed. If the parameter is available, we always cast it. It seems like an abstraction failure.

It is an abstraction, but I don’t think it’s a failure. The use-case for this is #34374 which drops the BCLog::Logger dependency from libbitcoinkernel and switches to a simpler KernelLogger class.

The idea is that the log-generating macros in util/log.h should not care about how log entries are formatted or where log messages are stored. Those things are the responsibility of a Logger class the application can direct log messages to in the ShouldLog and Log hooks it provides when the application is linked.

The Logger definition should be opaque, so one option could be to pass it as a void*. But using a base class pointer instead of a void pointer provides a little more compile-time safety for the link-time logger option.

If you think it would be better, we could keep the dependency on BCLog::Logger for now and get rid of the static cast as shown in the diff below. Ultimately though unless we want BCLog::Logger to be part of libbitcoinkernel we will need to drop this dependency.

 0--- a/src/logging.cpp
 1+++ b/src/logging.cpp
 2@@ -607,13 +607,13 @@ bool BCLog::Logger::SetCategoryLogLevel(std::string_view category_str, std::stri
 3 
 4 bool util::log::ShouldLog(Logger* log, Category category, Level level)
 5 {
 6-    auto& logger{log ? *static_cast<BCLog::Logger*>(log) : LogInstance()};
 7+    auto& logger{log ? *log : LogInstance()};
 8     return logger.WillLogCategoryLevel(static_cast<BCLog::LogFlags>(category), level);
 9 }
10 
11 void util::log::Log(Logger* log, Entry entry)
12 {
13-    auto& logger{log ? *static_cast<BCLog::Logger*>(log) : LogInstance()};
14+    auto& logger{log ? *log : LogInstance()};
15     if (logger.Enabled()) {
16         logger.LogPrintStr(std::move(entry.message), std::move(entry.source_loc), static_cast<BCLog::LogFlags>(entry.category), entry.level, entry.should_ratelimit);
17     }
18--- a/src/logging.h
19+++ b/src/logging.h
20@@ -124,7 +124,7 @@ namespace BCLog {
21         bool SuppressionsActive() const { return m_suppression_active; }
22     };
23 
24-    class Logger : public util::log::Logger
25+    class Logger
26     {
27     public:
28         struct BufferedLog {
29--- a/src/util/log.h
30+++ b/src/util/log.h
31@@ -36,12 +36,16 @@ private:
32     std::source_location m_loc;
33 };
34 
35+namespace BCLog {
36+class Logger;
37+} // namespace BCLog
38+
39 namespace util::log {
40 /** Opaque to util::log; interpreted by consumers (e.g., BCLog::LogFlags). */
41 using Category = uint64_t;
42 
43 /** Base class inherited by log consumers. Opaque like category, used for basic type-checking. */
44-class Logger{};
45+using Logger = BCLog::Logger;
46 
47 //! Log level constants. Most code will not need to use these directly and can
48 //! use LogTrace, LogDebug, LogInfo, LogWarning, and LogError macros defined

in src/util/log.h:83 in ee3fb8cf39 outdated

85+    Logger* logger;
86+
87+    explicit Source(Category category = BCLog::LogFlags::ALL, Logger* logger = nullptr) : category{category}, logger{logger} {}
88+
89+    template <typename... Args>
90+    std::string Format(util::ConstevalFormatString<sizeof...(Args)> fmt, const Args&... args) const

l0rinc commented at 5:24 pm on March 3, 2026:

ee3fb8c log refactor: Allow log macros to accept source arguments:

This commit is suddenly quite complicated compared to the previous ones. Can we split it up by feature? I’m not sure I understand why we suddenly have an explosion of docs/getters/casts. It seems like there are at least three sub-features here.

ryanofsky commented at 4:09 pm on March 4, 2026:

re: #29256 (review)

This commit is suddenly quite complicated compared to the previous ones. Can we split it up by feature?

I tried to simplify this and split it up a little, so this might look better now.

The “Allow log macros to accept context arguments” commit 8517c14b77aafda9f34400f122b644b12864d3a4 is reimplementing the log macros, not incrementally adding features. I think the easiest way to understand it is to look at the new definition of the macros, and get an idea of how they work by themselves before trying to compare to the previous implemenation. This should be a lot easier than trying to understand how they work from diffs.

It is possible there may be ways change the header more gradually too, and I’m open to suggestions. I just suspect line-by-line diffs might ultimately not be very helpful here.

in src/test/logging_tests.cpp:203 in a2a2bd7898

199@@ -200,6 +200,43 @@ BOOST_FIXTURE_TEST_CASE(logging_context_args, LogSetup)
200     BOOST_CHECK_EQUAL_COLLECTIONS(log_lines.begin(), log_lines.end(), expected.begin(), expected.end());
201 }
202 
203+struct CustomLogSource : public util::log::Source {

l0rinc commented at 5:28 pm on March 3, 2026:

a2a2bd7 log refactor: Add support for custom log sources:

Might be cleaner to have these as a local lambda and type that cleanly just executes a lambda, instead of having to know about the exact test implementation, e.g.

 0using Fmt1 = util::ConstevalFormatString<1>;
 1struct CustomLogSource : util::log::Source {
 2    using LogFormatter = std::function<std::string(Fmt1, const char*)>;
 3    LogFormatter m_fmt;
 4    explicit CustomLogSource(BCLog::LogFlags s, LogFormatter fmt) : Source{s}, m_fmt{std::move(fmt)} {}
 5    std::string Format(Fmt1 fmt, const char* arg) const { return m_fmt(fmt, arg); }
 6};
 7
 8int counter{0};
 9auto log = CustomLogSource{BCLog::VALIDATION, [&counter](Fmt1 fmt, const char* arg) {
10    return tfm::format("Custom #%d %s", ++counter, tfm::format(fmt, arg));
11}};

nit1: public is implicit nit2: explicit is not implicit :p

hodlinator commented at 9:24 am on March 4, 2026:

Would prefer avoiding extra lambdas.

Here’s a solution that allows making Format() non-const:

 0diff --git a/src/test/logging_tests.cpp b/src/test/logging_tests.cpp
 1index 0690affd7c..430a626559 100644
 2--- a/src/test/logging_tests.cpp
 3+++ b/src/test/logging_tests.cpp
 4@@ -210,24 +210,23 @@ BOOST_FIXTURE_TEST_CASE(logging_context_args, LogSetup)
 5     BOOST_CHECK_EQUAL_COLLECTIONS(log_lines.begin(), log_lines.end(), expected.begin(), expected.end());
 6 }
 7 
 8-struct CustomLogSource : public util::log::Source {
 9-    CustomLogSource(int& counter) : Source{BCLog::VALIDATION}, m_counter{counter} {}
10+struct CustomLogSource : util::log::Source {
11+    CustomLogSource() : Source{BCLog::VALIDATION} {}
12 
13     template <typename... Args>
14-    std::string Format(util::ConstevalFormatString<sizeof...(Args)> fmt, const Args&... args) const
15+    std::string Format(util::ConstevalFormatString<sizeof...(Args)> fmt, const Args&... args)
16     {
17         return tfm::format("Custom #%d %s", ++m_counter, tfm::format(fmt, args...));
18     }
19 
20-    int& m_counter;
21+    int m_counter{0};
22 };
23 
24 BOOST_FIXTURE_TEST_CASE(logging_CustomSource, LogSetup)
25 {
26     LogInstance().EnableCategory(BCLog::LogFlags::ALL);
27     LogInstance().SetLogLevel(BCLog::Level::Debug);
28-    int counter{0};
29-    CustomLogSource log{counter};
30+    CustomLogSource log;
31     LogTrace(log, "foo0: %s", "bar0"); // not logged
32     LogDebug(log, "foo1: %s", "bar1");
33     LogInfo(log, "foo2: %s", "bar2");
34diff --git a/src/util/log.h b/src/util/log.h
35index f81f5653d8..268e1ae591 100644
36--- a/src/util/log.h
37+++ b/src/util/log.h
38@@ -97,7 +97,7 @@ namespace detail {
39 //! Internal helper to get log source object from the first macro argument.
40 template <bool take_category, typename Source>
41 requires (Source::log_source)
42-const Source& GetSource(const Source& source LIFETIMEBOUND) { return source; }
43+Source& GetSource(Source& source LIFETIMEBOUND) { return source; }
44 
45 template <bool take_category>
46 Source GetSource(Category category)
47@@ -158,7 +158,7 @@ void Log(Level level, bool should_ratelimit, bool take_category, SourceLocation&
48 // NOLINTBEGIN(bugprone-lambda-function-name)
49 #define LogPrint_(level, should_ratelimit, take_category, ...)                                     \
50     do {                                                                                           \
51-        const auto& _source{util::log::detail::GetSource<take_category>(FirstArg_((__VA_ARGS__)))}; \
52+        auto&& _source{util::log::detail::GetSource<take_category>(FirstArg_((__VA_ARGS__)))};     \
53         if (util::log::ShouldLog(_source.logger, _source.category, (level))) {                     \
54             util::log::detail::Log((level), (should_ratelimit), take_category,                     \
55                                    SourceLocation{__func__}, _source, __VA_ARGS__);                \

l0rinc commented at 11:16 am on March 4, 2026:

Would prefer avoiding extra lambdas.

The names should be adjusted after my suggestion; that’s true (maybe FormatHookSource, FormatSpy, FormatDelegate). But lambdas would narrow the scope, untangle the data from the behavior in a functional style, and make it simpler to describe the intent of each participant at a higher level, since they’re not doing multiple custom things. I’m also fine with your suggestions; I’ll let Russ decide.

ryanofsky commented at 4:13 pm on March 4, 2026:

re: #29256 (review)

Mostly went with hodlinator’s suggestion here just because my hope for this test is to show a simple working example of a custom context object, and I feel like lambdas get in the way of that goal. I made some other changes here: namely avoiding inheritance that may address l0rinc’s other concerns, and definitely would be interested to know if there are other things that could be improved here.

in src/test/logging_tests.cpp:228 in a2a2bd7898

223+    LogInfo(log, "foo2: %s", "bar2");
224+    LogWarning(log, "foo3: %s", "bar3");
225+    LogError(log, "foo4: %s", "bar4");
226+    std::ifstream file{tmp_log_path.std_path()};
227+    std::vector<std::string> log_lines;
228+    for (std::string log; std::getline(file, log);) {

l0rinc commented at 5:31 pm on March 3, 2026:

a2a2bd7 log refactor: Add support for custom log sources:

We already have a log in this scope:

Declaration of ’log’ hides previous local declaration

But we can probably use the helper here instead:

0    const auto log_lines{ReadDebugLogLines()};

ryanofsky commented at 4:14 pm on March 4, 2026:

re: #29256 (review)

Thanks, switched to ReadDebugLogLines here as well

in src/test/logging_tests.cpp:207 in a2a2bd7898

199@@ -200,6 +200,43 @@ BOOST_FIXTURE_TEST_CASE(logging_context_args, LogSetup)
200     BOOST_CHECK_EQUAL_COLLECTIONS(log_lines.begin(), log_lines.end(), expected.begin(), expected.end());
201 }
202 
203+struct CustomLogSource : public util::log::Source {
204+    CustomLogSource(int& counter) : Source{BCLog::VALIDATION}, m_counter{counter} {}
205+
206+    template <typename... Args>
207+    std::string Format(util::ConstevalFormatString<sizeof...(Args)> fmt, const Args&... args) const

l0rinc commented at 5:50 pm on March 3, 2026:

a2a2bd7 log refactor: Add support for custom log sources:

I don’t like that compilation passes if I change anything here. It’s just an incidental interface that will simply fail the test if I rename it to Format2.

I know that adding a HasMemberFormat concept is ugly, but I really dislike these accidental interfaces.

ryanofsky commented at 4:16 pm on March 4, 2026:

re: #29256 (review)

I know that adding a HasMemberFormat concept is ugly, but I really dislike these accidental interfaces.

I don’t actually think concepts would help with this particular problem, because it’s just caused by inheritance. If you rename an overridden method in a subclass, the parent method will be called instead and this couldn’t really be detected without something like an override keyword that works on nonvirtual methods.

Addressed the problem here just by eliminating the inheritance, which wasn’t really necessary.

in src/util/log.h:211 in 6d91998175

212-#define LogWarning(...) LogPrint_(util::log::Level::Warning, true, __VA_ARGS__)
213-#define LogInfo(...) LogPrint_(util::log::Level::Info, true, __VA_ARGS__)
214-#define LogDebug(...) LogPrint_(util::log::Level::Debug, false, __VA_ARGS__)
215-#define LogTrace(...) LogPrint_(util::log::Level::Trace, false, __VA_ARGS__)
216-#define LogPrintLevel_(source, level, should_ratelimit, ...) LogPrint_((level), (should_ratelimit), (source), __VA_ARGS__)
217+#define LogError(...) LogPrint_(util::log::Level::Error, true, false, __VA_ARGS__)

l0rinc commented at 6:38 pm on March 3, 2026:

6d91998 log refactor: Disallow category args to logging macros:

Nit: can you please add name hints? This true/false zoo is making it harder to understand what each one does.

ryanofsky commented at 4:17 pm on March 4, 2026:

re: #29256 (review)

Nit: can you please add name hints? This true/false zoo is making it harder to understand what each one does.

Thanks, added name hints in both relevant commits

in src/test/logging_tests.cpp:145 in 6d91998175 outdated

141@@ -142,13 +142,23 @@ BOOST_FIXTURE_TEST_CASE(logging_context_args, LogSetup)
142     LogError("error");
143     LogWarning("warning");
144     LogInfo("info");
145+    // LogDebug("debug"); // Not allowed because category is required!

l0rinc commented at 6:43 pm on March 3, 2026:

6d91998 log refactor: Disallow category args to logging macros:

Verified each separately, and they all throw if uncommented. 👍

in src/util/log.h:100 in a2a2bd7898

 94@@ -94,7 +95,9 @@ struct Source {
 95 
 96 namespace detail {
 97 //! Internal helper to get log source object from the first macro argument.
 98-inline const Source& GetSource(const Source& source LIFETIMEBOUND) { return source; }
 99+template <typename Source>
100+requires (Source::log_source)
101+const Source& GetSource(const Source& source LIFETIMEBOUND) { return source; }

l0rinc commented at 6:59 pm on March 3, 2026:

a2a2bd7 log refactor: Add support for custom log sources:

Hmm, is the intent here to require inheritance from util::log::Source?

0template <typename T>
1requires (std::is_base_of_v<Source, std::remove_cvref_t<T>>)
2const T& GetSource(const T& source LIFETIMEBOUND) { return source; }

Which would allow the deletion of log_source from Source. Note: renamed the template parameter to avoid the name collision.

ryanofsky commented at 4:20 pm on March 4, 2026:

re: #29256 (review)

Hmm, is the intent here to require inheritance from util::log::Source?

That’s not really the intent, although inheritance could be useful in some cases. Updated the test to stop using inheritance to make intent clear, and also avoid the other method naming concern you had.

l0rinc changes_requested

l0rinc commented at 7:08 pm on March 3, 2026: contributor

I went over the commits. I don’t yet have a conceptual opinion about it. I usually go bottom-up here.

There are still a few things that I would like to be split; a few of the commits are too big for me to fully comprehend. I left lots of comments and suggestions in that area.

I would also like to understand whether @ajtowns and @hodlinator still disagree with the change.

ajtowns commented at 4:34 am on March 4, 2026: contributor

Just to reiterate: Concept NACK. This PR isn’t solving any problems other than its author’s aesthetic objection to the current logging API, which date back to when #28318 was merged.

I’m still unable to wrap my head around the appeal of a logging framework with an inconsistent API

If you don’t understand what you’re trying to change, you shouldn’t be changing it. The logging API we have is designed to be as simple as possible given our performance requirements (cf #33517), and also be simple/convenient to use. How and why that is the case has already been explained repeatedly.

It is also extremely tedious to have spent four months working on #28318 (after spending a bunch more time reviewing earlier PRs that weren’t making progress), specifically request design feedback early in that process, and then, immediately upon the PR being merged, have a maintainer file an array of issues and PRs (let’s see: this one, #29256, was a week after merge; then all of #30342, #30343, #30347, #30361, #30364 were end of June, with 4 of those 6 still pending about 2 years later) trying to undermine that work, and then maintain them for years after, while also limiting your response to critical feedback to remarks like “I want to let your comment stand, and not reply in detail”. Of course, as a practical matter, just opening new PRs and ignoring objections until people stop bothering to object is quite possibly an effective way of getting your preferred aesthetic adopted; it’s not a good way of making good software though.

ryanofsky commented at 8:18 am on March 4, 2026: contributor

@ajtowns I’m sorry for disagreements we’ve had in the past, and regret rude and dismissive comments I’ve made, and definitely think we got off on the wrong foot. But since this PR has been opened, I’ve adjusted it to do literally every single thing you have asked for, including things that I do not agree with (removing category information from log output, not accepting a consistent set of macro arguments) to avoid endless disagreement and focus the PR on it’s primary goals (allowing separate logging streams #30342, making the use of globals optional instead of required #33847, allowing subsystems to attach context information log messages #30343).

I understand you may not care about these goals, which is fine, and I hope that your last nack and comment is a helpful vent for your understandable frustrations with me as a detail-oriented and nitpicky developer. But I also hope that any reviewers and maintainers who are interested in this PR can weigh the comments here appropriately and not give undue weigh to a nack which does not mention specific downsides of a change.

in src/util/log.h:76 in 6d91998175

78-using Level = util::log::Level;
79-} // namespace BCLog
80+//! Object representing a source of log messages. Holds a logging category, an
81+//! optional log pointer which can be used by the application's log handler to
82+//! determine where to log to, and a Format hook to control message formatting.
83+struct Source {

hodlinator commented at 8:44 am on March 4, 2026:

nit: In a previous push you used the name Context which is less ambiguous vs SourceLocation which has since been introduced above.

The first commit’s message still mentions “context objects”.

Personally I prefer Context, but Source is okay.

ryanofsky commented at 4:21 pm on March 4, 2026:

re: #29256 (review)

Personally I prefer Context, but Source is okay.

Thanks, I switched back to Context for now. I think the name is mostly relevant to discussion in the PR, and after that it should just be an infrequently referenced class name.

in src/util/log.h:192 in 6d91998175 outdated

229+//! For more information about log levels, see the -debug and -loglevel
230+//! documentation, or the "Logging" section of developer notes.
231+//!
232+//! `LogDebug` and `LogTrace` macros should take an initial category argument,
233+//! so messages can be filtered by category, but categories can be omitted at
234+//! higher levels:

hodlinator commented at 8:58 am on March 4, 2026:

Would this be somewhat more correct in the final commit?

0//! `LogDebug` and `LogTrace` macros require an initial category argument unless given a log source (which provides it).
1//! That enables Debug and Trace messages to be filtered by category. Higher levels do not take a category (but may be passed a log source):

in src/signet.cpp:16 in 6d91998175 outdated

12@@ -13,7 +13,6 @@
13 #include <script/script.h>
14 #include <streams.h>
15 #include <uint256.h>
16-#include <util/check.h>

hodlinator commented at 9:14 am on March 4, 2026:

nit: This and the change to src/zmq/zmqutil.cpp seem unrelated?

ryanofsky commented at 4:23 pm on March 4, 2026:

nit: This and the change to src/zmq/zmqutil.cpp seem unrelated?

I believe this is needed to avoid IWYU failures because the macros no longer call Assume

hodlinator commented at 10:59 am on March 4, 2026: contributor

Reviewing 6d91998175b40939001e01ae2cd78571bff392b7

Publishing some comments early as one of them suggests an alternative to a recent suggestion.

ajtowns commented at 12:51 pm on March 4, 2026: contributor

I’m sorry for disagreements we’ve had in the past,

Disagreements are great; best thing about AI is I have someone on call 24/7 who’ll argue with me about any stupid technical detail for as long as I want. What is frustrating here is not that you’re not disagreeing with me, it’s that you’re just dismissing my concerns, and hoping you’ll get enough other ACKs to get away with merging the PR anyway, and weirdly, you’re happy to explicitly spell that out:

But I also hope that any reviewers and maintainers who are interested in this PR can weigh the comments here appropriately and not give undue weigh to a nack which does not mention specific downsides of a change.

I can’t imagine why you would think saying “sorry” with one breath and “hey everyone, just ignore this guy” in the next would come across as an attempt to get things on the right foot.

Anyway, explicit downsides? As at 2026-03-04 12:08 UTC, you motivate this PR by two goals:

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.

I’ve objected to the latter of these earlier in this PR writing:

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?

That’s now become a +438-130 diff (+116-78 if you ignore this PR and only consider the followup), and not a single use of the new API uses anything other than LogInfo; even the single existing LogTrace entry in wallet/sqlite.cpp isn’t touched. This is a lot of code churn, a bunch of additional code, and more complexity at every call site, for no benefit at all.

As for the former, adding multiple logger instances to the bitcoinkernel project still seems to be a massive design error to me: one that is far easier met by users who want independent validation instances using separate processes, and one that drives the kernel further away for the needs of the node software. I wrote about that at 2024-05-02 in this PR. Your response to that was silence for a month, followed by the non-responsive “I want to let your comment stand”, and the mass of “LogError and LogWarning are broken” issues/PRs.

So, no, I don’t believe you’ve “adjusted it to do literally every single thing you have asked for”. I think this idea is fundamentally mistaken at the conceptual level, and while I’m still willing to discuss it and bounce ideas around (cf #30386, #30355, #34729, #34730, later commits in #34038), you’ve burnt a lot of my potential good will on the topic, and for whatever reason you seem determined to actively continue to do so. If you want the cheat code to actually get on my good side, just skip the apologies and completely ignore any uncomfortable history and debate objective tech ideas with me.

ryanofsky referenced this in commit fe17020b09 on Mar 4, 2026

ryanofsky force-pushed on Mar 4, 2026

ryanofsky commented at 4:27 pm on March 4, 2026: contributor

Thanks for the reviews and thanks for the reply AJ. I think I addressed most of the individual review comments, but there are a few things remaining and I plan to follow up soon.

Updated 6d91998175b40939001e01ae2cd78571bff392b7 -> fe17020b09ca223be907ed964bfc63b7a4fe8e1b (pr/bclog.37 -> pr/bclog.38, compare) with various suggested changes.

Rebased fe17020b09ca223be907ed964bfc63b7a4fe8e1b -> 724b5aed21d6abe6345d8b556d7f6b4ff4a8494a (pr/bclog.38 -> pr/bclog.39, compare) on top of base PR #34778 which helps simplify the changes here

ryanofsky commented at 6:23 pm on March 4, 2026: contributor

re: #29256 (comment) @ajtowns So your previous concerns which were about harms you thought this PR caused (like log categories being shown, allowing users to filter messages by category, allowing users to miss important messages they filtered) have been addressed.

Your current set of concerns is not about harms this PR is causing, or about harms the followup PRs are causing (other than existing and creating code diffs), but are statements that you don’t think the goals of these PRs are useful or interesting. I feel like this is ok and we can leave it at that? Not everybody needs to be interested in every PR. It’s a strength of this project that different people will motivated to implement different features, and focus on different design benefits, and the project as a whole will be better off with no single person caring about every feature and benefit.

I am happy to talk about benefits of these PRs, and any specific tradeoffs you see. I just feel like there is an exit ramp here, and we can each work on things we feel are useful and important without clashing unnecessarily?

ajtowns commented at 2:24 pm on March 5, 2026: contributor

re: #29256 (comment)

@ajtowns So your previous concerns which were about harms you thought this PR caused (like log categories being shown, allowing users to filter messages by category, allowing users to miss important messages they filtered) have been addressed.

Your original description of this PR listed a different set of goals to the current description of this PR. My early remarks were addressing the goals you claimed at the time (both in this PR and in your comments to #28318 that preceded it).

Your current set of concerns is not about harms this PR is causing,

That is not an accurate statement of my view.

or about harms the followup PRs are causing (other than existing and creating code diffs), but are statements that you don’t think the goals of these PRs are useful or interesting.

No, I believe this PR and its followups actively make the codebase worse, and any similar PR aimed at making a similar change would also make the codebase worse. That is what “Concept NACK” means.

Or are you trying to argue that I’ve only objected to the followup PRs, and it would be fine to reject those but still merge this PR, and setup a new API that’s merely never used? I would hope that any contributor to this codebase would Concept NACK a new internal API that has no uses.

I am happy to talk about benefits of these PRs,

It’s currently, what, 617 days since you didn’t want to reply “right away” to discuss one set of comments that’s still applicable to these PRs. I suppose I could believe you’re happy to talk about the benefits of your PRs to an uncritical audience, but you continue to give a very convincing demonstration that you don’t have much interest in discussing objections to them.

I said previously “If you want the cheat code to actually get on my good side, just [..] debate objective tech ideas with me”. You’re again explicitly choosing to only respond to the political/emotional aspects while ignoring the technical issues I re-raised in that comment.

and any specific tradeoffs you see. I just feel like there is an exit ramp here, and we can each work on things we feel are useful and important without clashing unnecessarily?

I would rather not clash unnecessarily, which is why I’ve been silent on this PR since, what, 2024-06-29, and likewise why I don’t bother reviewing or commenting on ArgsManager changes much anymore after #16545. But I was explicitly asked for my opinion, and I’ve also observed you rushing another PR through with the explicit justification of making these code easier to get accepted. I think both the concerns I was raising in that and the IPC/logging performance issue linked in my previous comment also arise from the mistaken attitude that our logging system should be some generic API, rather than one focused on precisely our needs. So it’s become hard to justify continuing to be silent.

log test: verify log argument evaluation semantics

Test that LogInfo/LogWarning/LogError always evaluate their arguments
even when logging is disabled.

ajtowns pointed out this behavior was important and could affect non-logging
code if changed in
https://github.com/bitcoin/bitcoin/pull/34374#discussion_r2734793117

Co-authored-by: l0rinc <pap.lorinc@gmail.com>

449fc7ce3b

log test: Add test for all accepted logging arguments

Add new logging test to call macros with all allowed combinations of macro
arguments.

The new test replaces a less comprehensive test that doesn't cover log
statements without format arguments. It's also moved to the top of the test
suite because it's a good illustration of what typical log prints look like,
what logging calls are allowed and disallowed, and what the resulting log
output looks like.

1ee5ae0c17

log refactor: Ensure categories are not logged at info and higher levels

Previously this used to be possible through the LogPrintLevel call but now that
call is removed, this change is just an internal refactoring and has no visible
effect except in tests.

8f3e279bb9

log refactor: log macro rewrite

Rewrite log macros to fix a number of issues: lack of control over rate
limiting, unnecessary strprintf calls during fuzzing, confusing error messages
when macros are called with the wrong arguments.

More specifically, benefits are:

- Control over rate limiting: `LogPrintLevel_` hack used to bypass rate limiting
  is dropped. A `LogPrint` macro is added that can control rate limiting (as
  well as other options if they are added in the future).

- Unnecessary `strprintf` calls are now skipped in bitcoind when
  `-noprinttoconsole -nodebuglogfile` options are used, and skipped in tests and
  kernel applications when logging is disabled. This change should not affect
  bitcoind noticeably, but it could speed up fuzz tests calling functions that
  log.

- Clearer error messages: Differences between macros accepting and not accepting
  category arguments has been a source of confusion. Now if you pass a category
  to a macro which does not accept it, or forget to pass a category to a macro
  which requires it, you will see a clear error message telling you to add or
  remove the category instead of more confusing macro errors.

- Previously you could call `LogPrintLevel_` to bypass restrictions on passing
  category arguments. Now `LogPrint` enforces all requirements.

- Previously "always evaluate arguments" behavior at Info and higher levels
  looked accidental and was undocumented
  (https://github.com/bitcoin/bitcoin/pull/34374#discussion_r2734793117). Now
  the behavior is documented and explicit.

- There is now a single macro, `LogPrint` implementing all logging functionality
  and enforcing all restrictions, instead of different sets of macros with
  branching code paths and unexplained differences.

Co-Authored-By: Hodlinator <172445034+hodlinator@users.noreply.github.com>
Co-Authored-By: stickies-v <stickies-v@protonmail.com>

e983d97a91

Merge branch 'pr/relog' into pr/bclog 7055a641bc

log refactor: Allow log macros to accept context arguments

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:

- https://github.com/bitcoin/bitcoin/pull/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.

- https://github.com/bitcoin/bitcoin/pull/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>
Co-Authored-By: stickies-v <stickies-v@protonmail.com>

502820b5a5

doc: Add documentation about log levels and macros c410293dfa

log refactor: Add support for custom log contexts

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 #30343.

724b5aed21

ryanofsky referenced this in commit acb596dcd0 on Mar 9, 2026

ryanofsky force-pushed on Mar 9, 2026

ryanofsky marked this as a draft on Mar 9, 2026

DrahtBot added the label Needs rebase on Mar 23, 2026

DrahtBot commented at 3:46 am on March 23, 2026: contributor

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

log, refactor: Allow log macros to accept context arguments #29256

Code Coverage & Benchmarks

Reviews

Conflicts

LLM Linter (✨ experimental)

PR style

Subjective title

Suggested change