Logging controls #30486

Categories in the logging system currently work as follows:

• You can set a global log level (defaulting to debug), to trace to enable trace logs in all (enabled) categories (-loglevel=trace), or to info to disable debug logs even enabled categories (-debug=all -loglevel=info will still leave debugging disabled)
• You can override the global log level on a per-category basis, either making it more verbose (override info to debug or trace, or override debug to trace), or to make it less verbose (override a global default of debug or trace to a category specific level of info or debug), eg -loglevel=walletdb:trace -loglevel=net:info
• The log levels are only relevant for "enabled" categories (eg, you have to specify -debug=walletdb -loglevel=walletdb:trace to enable wallet db tracing)
• Enabling/disabling categories can be done at startup via the -debug option, or at runtime via the logging RPC
• Setting the log level is currently only possible at startup via the (currently hidden) -loglevel option

Is this behaviour worth preserving, or can we simplify it? I think it would be simpler and almost as powerful if we set things up as:

• Every category has a log level, that can be either info (default), debug, or trace (trace gives you everything, debug gives you everything but LogTrace(), and info skips both LogDebug() and LogTrace())
• We add a new -trace config option that sets a category's log level to trace, analogously to -debug (so you would just specify -trace=walletdb for wallet db tracing.
• We add an optional third argument to the logging rpc that accepts a list of categories to enable trace logging
• We support -debug=all or -trace=all to do all categories at once, and -debug=all -debugexclude=leveldb as usual to set all categories to debug but one left at info, or -trace=all -debug=walletdb to trace all categories but one left at debug (which offer similar behaviour to -debug=all -loglevel=debug -loglevel=leveldb:info or -debug=all -loglevel=trace -loglevel=walletdb:debug)

(Looking for concept acks/feedback)

I think this issue describes the problems with current logging controls very well but a better solution is possible than the one that's proposed here and implemented in #34038 (with some differences and additions). I implemented an alternate approach in #35387, and since AJ suggested discussing the approaches here, the problems I see with #34038 are that it is:

• Complicated. Users need to understand three separate options (-debug, -trace, -debugexclude) and their nontrivial interactions to configure logging, when a single -loglevel option can cover everything.

• Confusing. -trace=net enables debug and trace logging for net (trace implies debug), even though the name suggests it only enables trace. -debugexclude=net disables both debug and trace, even though the name only mentions debug.

• Ambiguous. When -debug and -trace apply to the same category, trace wins and the debug setting is ignored. This isn't apparent from the option names, and the evaluation order (debug args first, then trace, then exclude) isn't something you'd guess.

• Incomplete. There's no way to set trace as the default log level while keeping specific categories at debug. "Trace everything but debug for net" is a normal configuration to want, and in any standard logging framework it's something like -loglevel=trace,net:debug. With these three options it's not possible, because -trace=all clears all per-category level overrides, so any -debug=<cat> setting is ignored. This issue itself lists -trace=all -debug=walletdb as a supported use case, but it doesn't work in the implementation.

• Incompatible. The logging RPC output format changes from {category: bool} to three arrays (excluded, debug, trace).

• Awkward. To check what level a category is logged at, you have to search three arrays instead of doing a map lookup. To change a level, you place the category into an array instead of assigning it a level directly.

• Unusual. Assigning log levels to categories is the norm across logging frameworks. The include/exclude/trace triple with its evaluation ordering rules won't match what anyone coming from other logging contexts would expect.

In #35387 I fixed -loglevel to work without requiring -debug, and added a loglevel RPC. That gives you one option that covers all logging configuration:

bitcoind -loglevel=trace,net:debug,walletdb:info
bitcoin-cli -named loglevel trace net=debug walletdb=info

The loglevel RPC returns a flat map ({"net": "debug", "walletdb": "trace", ...}). The existing -debug, -debugexclude, and logging RPC all continue to work unchanged. #35387 is fully backwards compatible in a way #34038 is not.

I recognize I'm not neutral here since I wrote the alternative. If there are problems with #35387 I haven't seen, I'm interested to hear them.

I don't believe a single -loglevel is an option; we've supported -debug for years and should not replace it. Having bitcoind -debug=net -trace=walletdb is not a complicated thing for people to understand and is easily documented.

I'm not going to respond to the subjective takes here; I think Ryan has been locked-in on my takes on this topic being wrong for most of this decade and there's simply no agreement on those issues to be had.

Ambiguous. When -debug and -trace apply to the same category, trace wins and the debug setting is ignored. This isn't apparent from the option names, and the evaluation order (debug args first, then trace, then exclude) isn't something you'd guess.

This is the documented behaviour in both the -help and rpc docs, it's not ambiguous, and if you do specify -debug=foo and -trace=foo, I don't think it's likely to be surprising to many that you will see both LogDebug and LogTrace log entries.

Incomplete. There's no way to set trace as the default log level while keeping specific categories at debug

The idea behind trace logging is that it's extremely noisy to the degree that it may not just flood your disk but may affect normal system operation; if you're enabling "every possible trace log even ones I don't know about and haven't considered", the advantage of disabling individual categories seems pretty minimal to me. You can do it with the implementation in #34038 though: start the node with -trace=all and call bitcoin-cli logging ["cat"], eg. We could also change the logic of the command line argument and the logging rpc to have "all" mean "every category except those that were explicitly specified" but that seems a lot of effort for pretty rare use case.

Incompatible. The logging RPC output format changes from {category: bool} to three arrays (excluded, debug, trace).

I'm not particularly wedded to this, but I don't think the incompatibility here is any more severe than changing to a new RPC command as Ryan proposes; and the output format is not difficult to parse for software, and seems easier to parse at a glance for people to me.

The question I would like to see an answer to is if #35387 covers all the use-cases listed in this issue and is fully backwards compatible, what is the reason to prefer #34038?

#34038 requires three different log options that interact with each other (and do not respect command line order), to configure log levels, and despite that complexity doesn't support all the use cases listed in this issue (the "-trace=all -debug=walletdb to trace all categories but one left at debug" use-case). By contrast #35387 lets you straightforwardly configure logging by assigning levels to categories with a single -loglevel option. #35387 is simpler, more general, and matches the way logging is configured in other applications and libraries, instead of presenting a more complicated, unusual, and inflexible logging interface to users.

I also hope it is clear that #35387 is fully backwards compatible and intended to stay that way. -debug just becomes an alias for -loglevel=debug and -debugexclude becomes an alias for -loglevel=info.

#34038 requires three different log options that interact with each other (and do not respect command line order),

As you are well aware, command line ordering not mattering is a fundamental feature of the way our software deals with command-line arguments. The reason we have a separate "debugexclude" option and fixed prioritisation of options is precisely so that it doesn't matter what order the options appear. Your approach in 35387 has exactly the same level of respect for command line order, and the same fixed processing order as sonnet's commit message makes clear: https://github.com/bitcoin/bitcoin/pull/35387/changes/c3700df0201e0d53a28df52450421fdfd2f87b5e

Note that there is also nothing preventing us from introducing a new command line option or RPC interface (with or without deprecating the current options/interfaces) after merging 34038.

As far as an overall answer re 35387 is concerned, personally, I think -loglevel=net:debug is worse than writing -debug=net and I don't believe the corner cases you're focussing on are worth optimising for. I could be convinced of a new RPC interface (see #34038 (review) from a few months ago eg), but I don't think that's a good excuse to block or delay improvements in the existing interface.