Fix logging RPC and -debugexclude with 0/none values, add test coverage, improve docs #27231

jonatack commented at 1:40 AM on March 9, 2023: member

The logging RPC does not work as intended and as documented in its help when 0 or none are passed.

Per the RPC logging help:

$ ./src/bitcoin-cli help logging

In addition, the following are available as category names with special meanings:
  - "all",  "1" : represent all logging categories.
  - "none", "0" : even if other logging categories are specified, ignore all of them.

The behavior and documentation were added in #11191, but over time and extended refactoring, the behavior no longer works in master and versions 22/23/24 (the last supported versions currently) -- passing 0/none has no effect. As there was no test coverage, the regressions went uncaught. In v24, none became unrecognized:

$ ./src/bitcoin-cli logging '["none"]'
error code: -8
error message:
unknown logging category none

During the same time period, passing 1 and all has been operational and documented.

Solution: detect none/0 values and add test coverage in any case, and either:

leave the functionality out, raise with an error message if the values are passed, and update the RPC help documentation, or
fix the behavior by returning early.

Both solutions involve essentially the same code size and complexity. Given that all/1 has been operational, and that none/0 has been documented and appears per the code of the original PR to have been operational, it seems preferable for consistency to support none/0 in symmetry with all/1 and as ACKed, intended, and documented in #11191.

Done by this pull:

add missing RPC logging logic and test coverage
update the -debug and -debugexclude config options to use the same code for consistency in behavior between them, and for consistency with the logging RPC that provides the same behavior for both -include and -exclude
improve the user-facing documentation and examples; can be tested with ./src/bitcoind -h | grep -A12 "\-debug=<\|debugexclude" && ./src/bitcoin-cli help logging

If it is decided to backport a fix, commit Fix RPC logging behavior when "0" and "none" values are passed could probably suffice.

DrahtBot commented at 1:40 AM on March 9, 2023: contributor

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

Code Coverage

For detailed information about the code coverage, see the test coverage report.

Reviews

See the guideline for information on the review process.

Type	Reviewers
ACK	pinheadmz
Ignored review	ajtowns

If your review is incorrectly listed, please react with 👎 to this comment and the bot will ignore it on the next update.

Conflicts

Reviewers, this pull request conflicts with the following ones:

#28318 (logging: Simplify API for level based logging by ajtowns)

If you consider this pull request important, please also help to review the conflicting pull requests. Ideally, start with the one that should be merged first.

DrahtBot added the label RPC/REST/ZMQ on Mar 9, 2023

jonatack marked this as ready for review on Mar 9, 2023

in src/rpc/node.cpp:214 in a5f8a7abd9 outdated

 224 | -            throw JSONRPCError(RPC_INVALID_PARAMETER, "unknown logging category " + cat);
 225 | -        }
 226 | +static void EnableOrDisableLogCategories(UniValue categories, bool enable) {
 227 | +    categories = categories.get_array();
 228 | +    for (size_t i = 0; i < categories.size(); ++i) {
 229 | +        const std::string c{categories[i].get_str()};

maflcko commented at 9:23 AM on March 9, 2023:

    for (const auto& c:categories.get_array().getValues()) {
        const std::string& c{c.get_str()};

no need to create three copies of the same thing

jonatack commented at 6:57 PM on March 9, 2023:

Thanks @MarcoFalke, done as follows.

static void EnableOrDisableLogCategories(const UniValue& categories, bool enable)
{
    const std::vector<UniValue>& category_values{categories.get_array().getValues()};
    for (const auto& category : category_values) {
        const std::string& c{category.get_str()};
        if (c == "0" || c == "none") return; // no-op if one of these logging categories is passed
    }
    for (const auto& category : category_values) {
        const std::string& c{category.get_str()};
        const bool success{enable ? LogInstance().EnableCategory(c) : LogInstance().DisableCategory(c)};
        if (!success) throw JSONRPCError(RPC_INVALID_PARAMETER, "Unknown logging category: " + c);
     }
 }

The following also works, if reviewers prefer that (seems a little more complex, not sure it's worth it).

static void EnableOrDisableLogCategories(const UniValue& categories, bool enable)
{
    std::vector<std::string> cats;
    cats.reserve(categories.size());
    for (const auto& c : categories.get_array().getValues()) {
        cats.emplace_back(c.get_str());
    }
    if (std::any_of(cats.cbegin(), cats.cend(), [](const auto& c) { return c == "0" || c == "none"; })) return;
    for (const auto& c : cats) {
        const bool success{enable ? LogInstance().EnableCategory(c) : LogInstance().DisableCategory(c)};
        if (!success) throw JSONRPCError(RPC_INVALID_PARAMETER, "Unknown logging category: " + c);
     }
 }

jonatack commented at 7:01 PM on March 9, 2023:

(Noting that this logic is similar to that in SetLoggingCategories() in src/init/common.cpp).

fanquake commented at 9:31 AM on March 9, 2023: member

or none are passed, including not recognizing none:

Any idea when/how this was broken?

fanquake commented at 9:38 AM on March 9, 2023: member

Probably in f1379aeca9d3a8c4d3528de4d0af8298cb42fee4 from #25614:

replace the unused BCLog::Level:None string "none" with an empty string as the case will never be hit

So only broken for 24.x.

jonatack commented at 6:51 PM on March 9, 2023: member

The behavior was intended to be added in #11191.

I downloaded and tested v23.1 and the behavior wasn't functional: passing 0 or none had no effect.

In v24, f1379aeca9d3a8c4d3528de4d0af8298cb42fee4 made none not be recognized, but the logic for the intended behavior remained absent anyway.

I've added this information to the PR description.

in src/rpc/node.cpp:211 in a5f8a7abd9 outdated

 221 | -        }
 222 | -
 223 | -        if (!success) {
 224 | -            throw JSONRPCError(RPC_INVALID_PARAMETER, "unknown logging category " + cat);
 225 | -        }
 226 | +static void EnableOrDisableLogCategories(UniValue categories, bool enable) {

maflcko commented at 10:38 AM on March 10, 2023:

static void EnableOrDisableLogCategories(const UniValue& categories, bool enable)
{

nit: While touching this, can avoid the forth copy of the same thing here as well :)

jonatack commented at 6:49 PM on March 10, 2023:

yep :) done as in #27231 (review)

fanquake commented at 3:15 PM on March 10, 2023: member

The behavior was intended to be added in #11191.

It's still not clear if this was broken from the time it was merged, or at some other later point. This also does not work with 22.x, and any earlier versions are EOL.

If it's been broken forever (or at least is in all currently maintained releases), and no ones even noticed, we could take advantage of that, to remove some of the complexity here; do we definitely need multiple different ways of achieving the same logging toggling?

jonatack renamed this:
~~rpc: fix logging RPC when "none" values are passed, add test coverage, improve docs~~
Fix logging RPC and -debugexclude with 0/none values, add test coverage, improve docs
on Mar 10, 2023

jonatack force-pushed on Mar 10, 2023

jonatack marked this as a draft on Mar 10, 2023

jonatack force-pushed on Mar 15, 2023

jonatack force-pushed on Mar 16, 2023

DrahtBot added the label Needs rebase on Mar 23, 2023

jonatack force-pushed on Mar 31, 2023

jonatack commented at 4:04 PM on March 31, 2023: member

Rebased.

could take advantage of that, to remove some of the complexity here; do we definitely need multiple different ways of achieving the same logging toggling?

Exploring this, it doesn't look like there would be much code simplification gained by dropping none for 0 only, which would no longer be in symmetry with all/1 that have been operational for a long time. A couple lines could be saved by removing the -debugexclude config option, but that option is practical to have, as seen by its use in our own unit/fuzz and functional test frameworks.

It seems the way forward from here is to detect none/0 values, add test coverage and then either:

leave the functionality out, raise with an error message if none/0 values are passed, and update the RPC help documentation, or
simply fix the original behavior by returning early.

Both involve similar code size/complexity and the second option seems preferable. The updated code here is about the same length as before, modulo missing test coverage and improved documentation.

In the last pushes I've updated the PR description and first commit message with this info and improved the code and tests. This should be ready for further review!

jonatack marked this as ready for review on Mar 31, 2023

DrahtBot removed the label Needs rebase on Apr 2, 2023

DrahtBot added the label Needs rebase on Apr 3, 2023

jonatack force-pushed on Apr 4, 2023

DrahtBot removed the label Needs rebase on Apr 4, 2023

in src/init/common.cpp:91 in f868de5293 outdated

  99 | +    Assume(std::any_of(DEBUG_LOG_OPTS.cbegin(), DEBUG_LOG_OPTS.cend(), [&](const auto& d) { return opt == d; }));
 100 | +    if (!args.IsArgSet(opt)) return;
 101 | +    const std::vector<std::string>& categories{args.GetArgs(opt)};
 102 | +    if (std::any_of(categories.cbegin(), categories.cend(), [](const auto& c) { return LogInstance().IsNoneCategory(c); })) return;
 103 | +    for (const auto& c : categories) {
 104 | +        const bool success{opt == DEBUG_LOG_OPTS[0] ? LogInstance().EnableCategory(c) : LogInstance().DisableCategory(c)};

pinheadmz commented at 7:13 PM on April 5, 2023:

DEBUG_LOG_OPTS[0]

Feels like this is undoing whatever convenience/readability you set up by defining DEBUG_LOG_OPTS in the first place. Do you think more debug args will be added in the future? Or can we just use

args.IsArgSet("-debug") || args.IsArgSet("-debugexclude") ... etc

jonatack commented at 8:52 PM on April 11, 2023:

This commit is to have the same behavior (and code) for the -debug and -debugexclude config options. I'm not sure what your suggestion is, but I'm happy to look at a working example.

pinheadmz commented at 4:07 PM on April 12, 2023:

Well I meant something like a switch statement with "-debug" and "-debugexclude" literal strings as cases. I think that would make it more readable and if anything is ever added to DEBUG_LOG_OPTS[] it won't necessarily break. But that might just be too long or out of style

jonatack commented at 8:01 PM on April 12, 2023:

Well I meant something like a switch statement with "-debug" and "-debugexclude" literal strings as cases.

The condition in a switch statement must be of integer or enum type, or of a class type implicitly convertible to one.

But we can still use conditionals. Do you like this better?

 static constexpr std::array DEBUG_LOG_OPTS{"-debug", "-debugexclude"};
 
+static bool EnableOrDisable(const std::string& opt, const std::string& category)
+{
+    if (opt == "-debug") return LogInstance().EnableCategory(category);
+    if (opt == "-debugexclude") return LogInstance().DisableCategory(category);
+    NONFATAL_UNREACHABLE();
+}
+
 static void EnableOrDisableLogCategories(const ArgsManager& args, const std::string& opt)
@@ -90,8 +97,7 @@ static void EnableOrDisableLogCategories(const ArgsManager& args, const std::str
     const std::vector<std::string>& categories{args.GetArgs(opt)};
     if (std::any_of(categories.cbegin(), categories.cend(), [](const auto& c) { return LogInstance().IsNoneCategory(c); })) return;
     for (const auto& c : categories) {
-        const bool success{opt == DEBUG_LOG_OPTS[0] ? LogInstance().EnableCategory(c) : LogInstance().DisableCategory(c)};
-        if (!success) InitWarning(strprintf(_("Unsupported logging category %s=%s."), opt, c));
+        if (!EnableOrDisable(opt, c)) InitWarning(strprintf(_("Unsupported logging category %s=%s."), opt, c));
     }
 }

pinheadmz commented at 8:13 PM on April 12, 2023:

Yeah 😬 waddaya think?

jonatack commented at 8:17 PM on April 12, 2023:

Sure, will update. And add the comments mentioned in #27231 (review).

jonatack commented at 9:33 PM on April 12, 2023:

Done, and also dropped DEBUG_LOG_OPTS and the no-longer useful Assume check (the NONFATAL_UNREACHABLE check does it better), and made the two EnableOrDisableLogCategories functions simpler and more similar. Very helpful feedback (thanks!)

diff --git a/src/init/common.cpp b/src/init/common.cpp
index a5b07420d94..c99a512459b 100644
--- a/src/init/common.cpp
+++ b/src/init/common.cpp
@@ -77,26 +77,28 @@ void SetLoggingLevel(const ArgsManager& args)
     }
 }
 
-// We run each of these configuration options through SetLoggingCategories. The order matters;
-// -debugexclude settings take priority over -debug ones, so -debugexclude is run after -debug.
-static constexpr std::array DEBUG_LOG_OPTS{"-debug", "-debugexclude"};
+static bool EnableOrDisable(const std::string& opt, const std::string& category)
+{
+    if (opt == "-debug") return LogInstance().EnableCategory(category);
+    if (opt == "-debugexclude") return LogInstance().DisableCategory(category);
+    NONFATAL_UNREACHABLE();
+}
 
+// Maintain the same logic in both of the EnableOrDisableLogCategories functions in the codebase.
 static void EnableOrDisableLogCategories(const ArgsManager& args, const std::string& opt)
 {
-    if (!args.IsArgSet(opt)) return;
-    Assume(std::any_of(DEBUG_LOG_OPTS.cbegin(), DEBUG_LOG_OPTS.cend(), [&](const auto& d) { return opt == d; }));
     const std::vector<std::string>& categories{args.GetArgs(opt)};
     if (std::any_of(categories.cbegin(), categories.cend(), [](const auto& c) { return LogInstance().IsNoneCategory(c); })) return;
     for (const auto& c : categories) {
-        const bool success{opt == DEBUG_LOG_OPTS[0] ? LogInstance().EnableCategory(c) : LogInstance().DisableCategory(c)};
-        if (!success) InitWarning(strprintf(_("Unsupported logging category %s=%s."), opt, c));
+        if (!EnableOrDisable(opt, c)) InitWarning(strprintf(_("Unsupported logging category %s=%s."), opt, c));
     }
 }
 
 void SetLoggingCategories(const ArgsManager& args)
 {
-    for (const std::string& opt : DEBUG_LOG_OPTS) {
-        EnableOrDisableLogCategories(args, opt);
+    // debugexclude settings take priority over debug ones, so run debugexclude last
+    for (const std::string& opt : {"-debug", "-debugexclude"}) {
+        if (args.IsArgSet(opt)) EnableOrDisableLogCategories(args, opt);
     }
 }
 
diff --git a/src/rpc/node.cpp b/src/rpc/node.cpp
index 3bae7bef722..9c32839231f 100644
--- a/src/rpc/node.cpp
+++ b/src/rpc/node.cpp
@@ -209,14 +209,13 @@ static RPCHelpMan getmemoryinfo()
     };
 }
 
+// Maintain the same logic in both of the EnableOrDisableLogCategories functions in the codebase.
 static void EnableOrDisableLogCategories(const UniValue& categories, bool enable)
 {
-    const std::vector<UniValue>& category_values{categories.get_array().getValues()};
-    for (const auto& category : category_values) {
-        if (LogInstance().IsNoneCategory(category.get_str())) return;
-    }
-    for (const auto& category : category_values) {
-        const std::string& c{category.get_str()};
+    const std::vector<UniValue>& cats{categories.get_array().getValues()};
+    if (std::any_of(cats.cbegin(), cats.cend(), [](const auto& c) { return LogInstance().IsNoneCategory(c.get_str()); })) return;
+    for (const auto& cat : cats) {
+        const std::string& c{cat.get_str()};
         const bool success{enable ? LogInstance().EnableCategory(c) : LogInstance().DisableCategory(c)};
         if (!success) throw JSONRPCError(RPC_INVALID_PARAMETER, "Unsupported logging category: " + c);
     }

</details>

in src/init/common.cpp:32 in fba713a172 outdated

  30 | -        "If <category> is not supplied or if <category> = 1, output all debug and trace logging. <category> can be: " + LogInstance().LogCategoriesString() + ". This option can be specified multiple times to output multiple categories.",
  31 | +    argsman.AddArg("-debug=<category>", "Output debug and trace logging (default: 0). "
  32 | +        "If <category> is omitted, or is 1 or all, output all debug and trace logging. If <category> is 0 or none, any other categories passed are ignored. Other valid values for <category> are: " + LogInstance().LogCategoriesString() + ". This option can be specified multiple times to output multiple categories. See also the -debugexclude configuration option that takes priority over -debug.",
  33 |          ArgsManager::ALLOW_ANY, OptionsCategory::DEBUG_TEST);
  34 | -    argsman.AddArg("-debugexclude=<category>", "Exclude debug and trace logging for a category. Can be used in conjunction with -debug=1 to output debug and trace logging for all categories except the specified category. This option can be specified multiple times to exclude multiple categories.", ArgsManager::ALLOW_ANY, OptionsCategory::DEBUG_TEST);
  35 | +    argsman.AddArg("-debugexclude=<category>", "Exclude debug and trace logging for a category (default: 1). Takes priority over -debug and can be used in conjunction with -debug=1 to output debug and trace logging for all categories except the specified category. If <category> is 1 or all, exclude all debug and trace logging. If <category> is 0 or none, any other categories passed are ignored. Other valid values for <category> are: " + LogInstance().LogCategoriesString() + ". This option can be specified multiple times to exclude multiple categories.", ArgsManager::ALLOW_ANY, OptionsCategory::DEBUG_TEST);

pinheadmz commented at 7:18 PM on April 5, 2023:

Recommend putting "all" and "none" in quotes to be super-duper explicit

jonatack commented at 8:52 PM on April 11, 2023:

I left them without quotes as none of the other category values in the -debug and -debugexclude helps are in quotes. But you may be right that it's nevertheless clearer to add them here. Done.

in src/logging.cpp:227 in a1abce1650 outdated

 223 | @@ -225,7 +224,7 @@ std::string LogCategoryToStr(BCLog::LogFlags category)
 224 |      // Each log category string representation should sync with LogCategories
 225 |      switch (category) {
 226 |      case BCLog::LogFlags::NONE:
 227 | -        return "";
 228 | +        return "0";

pinheadmz commented at 7:20 PM on April 5, 2023:

Why 0 and not "none"?

Like this one:


    case BCLog::LogFlags::ALL:
        return "all";

jonatack commented at 8:52 PM on April 11, 2023:

Thanks for making me re-verify. This case will never be hit and is only present to appease the compiler (error: enumeration value 'NONE' not handled in switch), so leaving it as an empty string, added a comment, and moved it to the last case in the switch.

pinheadmz commented at 4:15 PM on April 12, 2023:

Ah I see, these cases are essentially handled by IsNoneCategory() 👍

in src/logging.cpp:153 in a1abce1650 outdated

 149 | @@ -150,7 +150,6 @@ struct CLogCategoryDesc {
 150 |  const CLogCategoryDesc LogCategories[] =
 151 |  {
 152 |      {BCLog::NONE, "0"},
 153 | -    {BCLog::NONE, ""},

pinheadmz commented at 7:21 PM on April 5, 2023:

not going to add "none" here?

jonatack commented at 8:52 PM on April 11, 2023:

Looking again (thanks!), both of these NONE entries can be dropped. Updated to add prior test coverage to spec affected behavior, then removed them.

in src/rpc/node.cpp:239 in 22e77cc5f7 outdated

 266 | +                   + HelpExampleCli("-named logging", "include='[\"all\"]' exclude='[\"http\"]'")
 267 | +                   + "\nTurn off all logging categories\n"
 268 | +                   + HelpExampleCli("logging", "'[]' '[\"all\"]'")
 269 | +                   + HelpExampleCli("-named logging", "exclude='[\"all\"]'")
 270 | +                   + "\nTurn on all logging categories, except libevent\n"
 271 | +                   + HelpExampleRpc("logging", "[\"all\"], [\"libevent\"]")

pinheadmz commented at 7:24 PM on April 5, 2023:

GREAT

pinheadmz commented at 7:30 PM on April 5, 2023: member

concept ACK github code review, will fine-tooth comb review later this week. Played with build locally and tried out examples from new help message. A few questions...

achow101 added this to the milestone 25.0 on Apr 11, 2023

jonatack force-pushed on Apr 11, 2023

jonatack force-pushed on Apr 12, 2023

in src/init/common.cpp:99 in e9f6fd0e02 outdated

 112 | -            InitWarning(strprintf(_("Unsupported logging category %s=%s."), "-debugexclude", cat));
 113 | -        }
 114 | +void SetLoggingCategories(const ArgsManager& args)
 115 | +{
 116 | +    for (const std::string& opt : DEBUG_LOG_OPTS) {
 117 | +        EnableOrDisableLogCategories(args, opt);

pinheadmz commented at 5:58 PM on April 12, 2023:

Could you combine this into one function? You have another method called EnableOrDisableLogCategories() in node.cpp which might be confusing. And unlike in node.cpp, I don't think the common.cpp method is called anywhere else besides SetLoggingCategories()

jonatack commented at 7:01 PM on April 12, 2023:

Good question. Both of the EnableOrDisableLogCategories() functions are created in this PR. They are doing pretty much the same thing, but are not trivially combinable into one function. If one is changed, it's likely that both should be (maybe a comment to that effect should be added to them -- Edit: done). I therefore wanted both to be standalone functions with the same name in order that searching/git grepping returns both. (Edit: updated this sentence to clarify.)

That, along with how extracting that function simplifies SetLoggingCategories to highlight that both options are being plugged into the same code, were the motivations.

pinheadmz commented at 7:03 PM on April 12, 2023:

Cool, just to be clear I meant combining this EnableOrDisableLogCategories() into SetLoggingCategories() and then you only have one named EnableOrDisableLogCategories() in the code over in node.cpp

That, along with how extracting that function simplifies SetLoggingCategories to highlight that both options are being plugged into the same code, were the motivations.

okie doke 👍

pinheadmz approved

pinheadmz commented at 6:25 PM on April 12, 2023: member

ACK e9f6fd0e028e6a5669926926792c70c31a26c403

reviewed code, built and ran tests locally. played with feature in regtest, tried to break it, couldn't break it.

just one non-busting question below

<details><summary>Show Signature</summary>

pinheadmz's public key is on keybase

</details>

jonatack force-pushed on Apr 12, 2023

pinheadmz approved

pinheadmz commented at 2:51 PM on April 13, 2023: member

ACK 5991eddb98ce59b883ae695752d4e90f32d43960

<details><summary>Show Signature</summary>

pinheadmz's public key is on keybase

</details>

glozow removed this from the milestone 25.0 on Apr 14, 2023

DrahtBot added the label Needs rebase on Jun 20, 2023

jonatack force-pushed on Jun 20, 2023

jonatack commented at 11:37 PM on June 20, 2023: member

Rebased following merge of #27632; only change is to commit 4351f26203c6daab321d478a3992e1723cc60814 per git range-diff ee22ca5 5991edd 630b38e.

DrahtBot removed the label Needs rebase on Jun 20, 2023

in src/init/common.cpp:81 in 630b38e92b outdated

  97 | +    if (opt == "-debug") return LogInstance().EnableCategory(category);
  98 | +    if (opt == "-debugexclude") return LogInstance().DisableCategory(category);
  99 | +    NONFATAL_UNREACHABLE();
 100 | +}
 101 | +
 102 | +// Maintain similar logic in both of the EnableOrDisableLogCategories() functions in the codebase.

pinheadmz commented at 3:40 PM on June 22, 2023:

I still don't totally understand why you need to split this up into three functions, one of which is a kinda-duplicate The comment makes sense but I'm not familiar enough with the general style of the project to determine if having two functions with the same name doing basically the same thing is acceptable.

jonatack commented at 8:05 PM on June 22, 2023:

Doing so

makes clear that -debug and -debugexclude use the same logic
avoids duplicate code for -debug and -debugexclude
separates the logic to be kept the same, into a method that has the same name and logic as EnableOrDisableLogCategories() in the RPC code (for the logging RPC "include" and "exclude" options), which was added back in 2017-2018 and updated since then. Combining the two into a single method seems non-trivial (maybe for a later pull) but this comment and the shared function name grep-ability makes more clear what logic needs to be the same.

(Thanks for coming back to this PR!)

pinheadmz commented at 8:07 PM on June 22, 2023:

OK cool thanks for explaining

pinheadmz approved

pinheadmz commented at 8:11 PM on June 22, 2023: member

re-ACK 630b38e92b4e40d49d69970b6c5bc02aa39ba210

Confirmed refactor since last ACK, making use of util:Result

<details><summary>Show Signature</summary>

pinheadmz's public key is on keybase

</details>

in src/init/common.cpp:103 in 630b38e92b outdated

 115 | -        if (!LogInstance().DisableCategory(cat)) {
 116 | -            return util::Error{strprintf(_("Unsupported logging category %s=%s."), "-debugexclude", cat)};
 117 | +util::Result<void> SetLoggingCategories(const ArgsManager& args)
 118 | +{
 119 | +    // debugexclude settings take priority over debug ones, so run debugexclude last
 120 | +    for (const std::string& opt : {"-debug", "-debugexclude"}) {

ajtowns commented at 2:02 PM on June 23, 2023:

This seems a bit clunky, how about:

// Maintain similar logic in both of the EnableOrDisableLogCategories() functions in the codebase.
static void EnableOrDisableLogCategories(util::Result<void>& result, const ArgsManager& args, const std::string& opt, bool enable)
{
    if (!result) return;
    if (!args.IsArgSet(opt)) return;
    const std::vector<std::string>& categories{args.GetArgs(opt)};
    if (std::any_of(categories.cbegin(), categories.cend(), [](const auto& c) { return LogInstance().IsNoneCategory(c); })) return;
    for (const auto& category : categories) {
        bool success = (enable ? LogInstance().EnableCategory(category) : LogInstance().DisableCategory(category));
        if (!success) {
            result = util::Error{strprintf(_("Unsupported logging category %s=%s."), opt, category)};
            return;
        }
    }
    return;
}

util::Result<void> SetLoggingCategories(const ArgsManager& args)
{
    util::Result<void> result;

    // debugexclude settings take priority over debug ones, so run debugexclude last
    EnableOrDisableLogCategories(result, args, "-debug", /*enable=*/true);
    EnableOrDisableLogCategories(result, args, "-debugexclude", /*enable=*/false);
    if (!result) return util::Error{util::ErrorString(result)};
    return {};
}

(or just return result; at the end -- not sure what the point of return Error(ErrorString(result)) is?)

jonatack commented at 5:49 PM on June 23, 2023:

LGTM (and with just return result;) and this allows dropping the #include <util/check.h> from that file.

pinheadmz commented at 3:53 PM on July 20, 2023:

Great suggestion AJ this are looks a lot better now

ajtowns commented at 2:07 PM on June 23, 2023: contributor

utACK 630b38e92b4e40d49d69970b6c5bc02aa39ba210

jonatack force-pushed on Jun 23, 2023

jonatack commented at 6:09 PM on June 23, 2023: member

Thank you @pinheadmz and @ajtowns for the review; updated commit 0c6c39056851d13c0ca3cea227fac72a4338bed0 per #27231 (review).

--- a/src/init/common.cpp
+++ b/src/init/common.cpp
@@ -11,7 +11,6 @@
 #include <logging.h>
 #include <node/interface_ui.h>
 #include <tinyformat.h>
-#include <util/check.h>
 #include <util/fs.h>
 #include <util/fs_helpers.h>
 #include <util/result.h>
@@ -79,34 +78,29 @@ util::Result<void> SetLoggingLevel(const ArgsManager& args)
     return {};
 }
 
-[[nodiscard]] static bool EnableOrDisable(const std::string& opt, const std::string& category)
-{
-    if (opt == "-debug") return LogInstance().EnableCategory(category);
-    if (opt == "-debugexclude") return LogInstance().DisableCategory(category);
-    NONFATAL_UNREACHABLE();
-}
-
 // Maintain similar logic in both of the EnableOrDisableLogCategories() functions in the codebase.
-[[nodiscard]] static util::Result<void> EnableOrDisableLogCategories(const ArgsManager& args, const std::string& opt)
+static void EnableOrDisableLogCategories(util::Result<void>& result, const ArgsManager& args, const std::string& opt, bool enable)
 {
+    if (!result || !args.IsArgSet(opt)) return;
     const std::vector<std::string>& categories{args.GetArgs(opt)};
-    if (std::any_of(categories.cbegin(), categories.cend(), [](const auto& c) { return LogInstance().IsNoneCategory(c); })) return {};
+    if (std::any_of(categories.cbegin(), categories.cend(), [](const auto& c) { return LogInstance().IsNoneCategory(c); })) return;
     for (const auto& c : categories) {
-        if (!EnableOrDisable(opt, c)) return util::Error{strprintf(_("Unsupported logging category %s=%s."), opt, c)};
+        const bool success{enable ? LogInstance().EnableCategory(c) : LogInstance().DisableCategory(c)};
+        if (!success) {
+            result = util::Error{strprintf(_("Unsupported logging category %s=%s."), opt, c)};
+            return;
+        }
     }
-    return {};
+    return;
 }
 
 util::Result<void> SetLoggingCategories(const ArgsManager& args)
 {
+    util::Result<void> result;
     // debugexclude settings take priority over debug ones, so run debugexclude last
-    for (const std::string& opt : {"-debug", "-debugexclude"}) {
-        if (args.IsArgSet(opt)) {
-            auto result = EnableOrDisableLogCategories(args, opt);
-            if (!result) return util::Error{util::ErrorString(result)};
-        }
-    }
-    return {};
+    EnableOrDisableLogCategories(result, args, "-debug", /*enable=*/true);
+    EnableOrDisableLogCategories(result, args, "-debugexclude", /*enable=*/false);
+    return result;
 }

</details>

in src/test/logging_tests.cpp:265 in 08a367c929 outdated

 259 | @@ -251,4 +260,14 @@ BOOST_FIXTURE_TEST_CASE(logging_Conf, LogSetup)
 260 |      }
 261 |  }
 262 |  
 263 | +BOOST_FIXTURE_TEST_CASE(logging_IsNoneCategory, LogSetup)
 264 | +{
 265 | +    for (const std::string& s : {"none", "0"}) {

luke-jr commented at 1:44 AM on June 30, 2023:

src/test/logging_tests.cpp:262:29: warning: loop variable 's' of type 'const std::string&' {aka 'const std::__cxx11::basic_string<char>&'} binds to a temporary constructed from type 'const char* const' [-Wrange-loop-construct]
  262 |     for (const std::string& s : {"", "NONE", "net", "all", "1"}) {
      |                             ^
src/test/logging_tests.cpp:262:29: note: use non-reference type 'const std::string' {aka 'const std::__cxx11::basic_string<char>'} to make the copy explicit or 'const char* const&' to prevent copying

jonatack commented at 2:25 AM on June 30, 2023:

Thank you, Luke, updated. Is that with GCC? I don't see the warning with Clang 16.0.6.

 BOOST_FIXTURE_TEST_CASE(logging_IsNoneCategory, LogSetup)
 {
-    for (const std::string& s : {"none", "0"}) {
+    for (const char* const& s : {"none", "0"}) {
         BOOST_CHECK(LogInstance().IsNoneCategory(s));
     }
-    for (const std::string& s : {"", "NONE", "net", "all", "1"}) {
+    for (const char* const& s : {"", "NONE", "net", "all", "1"}) {
         BOOST_CHECK(!LogInstance().IsNoneCategory(s));
     }
 }

in test/functional/feature_logging.py:38 in 08a367c929 outdated

  37 | +            "-debugexclude=tor",
  38 | +        ])
  39 |          assert os.path.isfile(self.relative_log_path("foo.log"))
  40 | +        # In addition to net and tor, leveldb/libevent/rand are excluded by the test framework.
  41 | +        for category in ["leveldb", "libevent", "net", "rand", "tor"]:
  42 | +            assert not node.logging()[category]

luke-jr commented at 2:04 AM on June 30, 2023:

Kinda ugly to call node.logging() repeatedly

jonatack commented at 2:22 AM on June 30, 2023:

Good point, updated.

         # In addition to net and tor, leveldb/libevent/rand are excluded by the test framework.
+        result = node.logging()
         for category in ["leveldb", "libevent", "net", "rand", "tor"]:
-            assert not node.logging()[category]
+            assert not result[category]

in test/functional/feature_logging.py:48 in 08a367c929 outdated

  49 | +            f"-debuglogfile={tempname}",
  50 | +            "-debugexclude=none",
  51 | +            "-debugexclude=qt",
  52 | +        ])
  53 |          assert os.path.isfile(tempname)
  54 | +        assert all(v == True for v in node.logging().values())  # -debugexclude=[none,qt] does not exclude qt

luke-jr commented at 2:05 AM on June 30, 2023:

Why aren't libevent/leveldb being excluded here?

jonatack commented at 2:54 AM on June 30, 2023:

Because -debugexclude=none" is passed. It looks like the passed extra args are concatenated to self.args before starting the process, i.e. self.process = subprocess.Popen(self.args + extra_args... in test_framework/test_node.py#L219, so the "none" value cancels the -debugexclude={libevent,leveldb,rand} args in the same file.

jonatack commented at 2:54 AM on June 30, 2023:

Good question, though. I'll add a comment.

jonatack commented at 8:56 PM on June 30, 2023:

Improved the test comment.

-        assert all(v == True for v in node.logging().values())  # -debugexclude=[none,qt] does not exclude qt
+        # Expect the "none" value passed in -debugexclude=[none,qt] to mean that
+        # none of the categories passed with -debugexclude are excluded: neither
+        # qt passed here nor leveldb/libevent/rand passed by the test framework.
+        assert all(v == True for v in node.logging().values())

luke-jr changes_requested

jonatack force-pushed on Jun 30, 2023

jonatack commented at 9:02 PM on June 30, 2023: member

Updated the tests with @luke-jr's review feedback (thanks!)

--- a/src/test/logging_tests.cpp
+++ b/src/test/logging_tests.cpp
@@ -262,11 +262,11 @@ BOOST_FIXTURE_TEST_CASE(logging_Conf, LogSetup)
 
 BOOST_FIXTURE_TEST_CASE(logging_IsNoneCategory, LogSetup)
 {
-    for (const std::string& s : {"none", "0"}) {
-        BOOST_CHECK(LogInstance().IsNoneCategory(s));
+    for (const char* const& c : {"none", "0"}) {
+        BOOST_CHECK(LogInstance().IsNoneCategory(c));
     }
-    for (const std::string& s : {"", "NONE", "net", "all", "1"}) {
-        BOOST_CHECK(!LogInstance().IsNoneCategory(s));
+    for (const char* const& c : {"", "NONE", "net", "all", "1"}) {
+        BOOST_CHECK(!LogInstance().IsNoneCategory(c));
     }
 }
 
diff --git a/test/functional/feature_logging.py b/test/functional/feature_logging.py
index 7958a743853..8448eff4a43 100755
--- a/test/functional/feature_logging.py
+++ b/test/functional/feature_logging.py
@@ -34,8 +34,9 @@ class LoggingTest(BitcoinTestFramework):
         ])
         assert os.path.isfile(self.relative_log_path("foo.log"))
         # In addition to net and tor, leveldb/libevent/rand are excluded by the test framework.
+        result = node.logging()
         for category in ["leveldb", "libevent", "net", "rand", "tor"]:
-            assert not node.logging()[category]
+            assert not result[category]
 
         self.log.info("Test alternative log file name outside datadir and -debugexclude={none,qt}")
         tempname = os.path.join(self.options.tmpdir, "foo.log")
@@ -45,7 +46,10 @@ class LoggingTest(BitcoinTestFramework):
             "-debugexclude=qt",
         ])
         assert os.path.isfile(tempname)
-        assert all(v == True for v in node.logging().values())  # -debugexclude=[none,qt] does not exclude qt
+        # Expect the "none" value passed in -debugexclude=[none,qt] to mean that
+        # none of the categories passed with -debugexclude are excluded: neither
+        # qt passed here nor leveldb/libevent/rand passed by the test framework.
+        assert all(v == True for v in node.logging().values())
 
         self.log.info("Test -debugexclude=1/all excludes all categories")

</details>

jonatack requested review from maflcko on Jul 12, 2023

jonatack requested review from luke-jr on Jul 12, 2023

jonatack requested review from ajtowns on Jul 12, 2023

jonatack requested review from pinheadmz on Jul 12, 2023

pinheadmz approved

pinheadmz commented at 3:58 PM on July 20, 2023: member

re-ACK 93b387fe70174d174b840016da8531ef65ec313e

Confirmed changes were compiler warning fix, better test comment, and very nice clean-up in common.cpp. Built branch and ran tests locally.

<details><summary>Show Signature</summary>

pinheadmz's public key is on keybase

</details>

in src/logging.cpp:287 in 93b387fe70 outdated

 283 | @@ -288,6 +284,8 @@ std::string LogCategoryToStr(BCLog::LogFlags category)
 284 |          return "scan";
 285 |      case BCLog::LogFlags::ALL:
 286 |          return "all";
 287 | +    case BCLog::LogFlags::NONE: // this case is normally never hit

fanquake commented at 12:41 PM on August 1, 2023:

I think we should avoid adding comments like this, because they don't really provide any value to the developer. If anything, a comment explaining what the "not normal" case is, and/or why that's particularly relevant, would be more useful, because that's the first question I'd have after reading this comment. Also unsure why this code has been re-ordered.

jonatack commented at 10:17 PM on August 1, 2023:

Thank you @fanquake for the feedback and having a look. Updated to commit 88211f2b7e12542ba5e65bba4e3398c9592430ea per the diff in #27231 (comment), replacing the comment with clearer code along with added explanation in the commit message.

jonatack force-pushed on Aug 1, 2023

jonatack commented at 10:04 PM on August 1, 2023: member

Updated per git diff 93b387f ce8faad to address @fanquake's review feedback (thanks!) and replace the comment with clearer code.

diff --git a/src/logging.cpp b/src/logging.cpp
index f197943a0bd..d3f61ca54c2 100644
--- a/src/logging.cpp
+++ b/src/logging.cpp
@@ -4,6 +4,7 @@
 // file COPYING or http://www.opensource.org/licenses/mit-license.php.
 
 #include <logging.h>
+#include <util/check.h>
 #include <util/fs.h>
 #include <util/string.h>
 #include <util/threadnames.h>
@@ -284,9 +285,9 @@ std::string LogCategoryToStr(BCLog::LogFlags category)
         return "scan";
     case BCLog::LogFlags::ALL:
         return "all";
-    case BCLog::LogFlags::NONE: // this case is normally never hit
-        return "";
-    }
+    case BCLog::LogFlags::NONE:
+        Assume(false);
+    } // no default case, so the compiler can warn about missing cases
     assert(false);
 }

</details>

jonatack force-pushed on Aug 1, 2023

DrahtBot added the label CI failed on Aug 2, 2023

DrahtBot removed the label CI failed on Aug 2, 2023

Unit tests for LogPrintfCategory and LogPrintLevel with BCLog::ALL/NONE

to specify expected current behavior and check future changes for regressions.

b5d0dd7c25

Functional test that RPC logging does not return all/none categories e87de92856

in src/logging.cpp:289 in ce8faad0b7 outdated

 284 | @@ -288,7 +285,9 @@ std::string LogCategoryToStr(BCLog::LogFlags category)
 285 |          return "scan";
 286 |      case BCLog::LogFlags::ALL:
 287 |          return "all";
 288 | -    }
 289 | +    case BCLog::LogFlags::NONE:
 290 | +        Assume(false);

ajtowns commented at 6:14 AM on August 17, 2023:

What's the point of an Assume(false) that just falls through to an assert(false) ?

jonatack commented at 5:55 PM on August 17, 2023:

Fixed, thank you.

jonatack force-pushed on Aug 17, 2023

jonatack commented at 6:05 PM on August 17, 2023: member

Updated per git range-diff 6ce5e8f ce8faad 05143b2 to take review feedback by @ajtowns (thanks!) and rebase for CI.

DrahtBot added the label CI failed on Aug 18, 2023

DrahtBot removed the label CI failed on Aug 18, 2023

jonatack requested review from pinheadmz on Aug 28, 2023

jonatack commented at 1:14 PM on August 31, 2023: member

This seems close, has been reviewed by five reviewers (thanks!) and updated for their feedback. I propose to give this another week for (re-)ACKs and merge. If it hasn't gone in by then, will revert to https://github.com/bitcoin/bitcoin/commit/630b38e92b4e40d49d69970b6c5bc02aa39ba210 with 2 ACKs and handle the minor updates since that commit in a follow-up.

in src/logging.h:183 in 05143b2b94 outdated

 179 | @@ -180,6 +180,7 @@ namespace BCLog {
 180 |  
 181 |          bool WillLogCategory(LogFlags category) const;
 182 |          bool WillLogCategoryLevel(LogFlags category, Level level) const;
 183 | +        [[nodiscard]] bool IsNoneCategory(const std::string& s) const { return s == "0" || s == "none"; }

ajtowns commented at 3:22 PM on August 31, 2023:

This is really static rather than const.

jonatack commented at 12:36 AM on September 1, 2023:

That's true. Updated from const to static.

in src/logging.cpp:288 in 05143b2b94 outdated

 283 | @@ -288,7 +284,9 @@ std::string LogCategoryToStr(BCLog::LogFlags category)
 284 |          return "scan";
 285 |      case BCLog::LogFlags::ALL:
 286 |          return "all";
 287 | -    }
 288 | +    case BCLog::LogFlags::NONE:
 289 | +        assert(false);

ajtowns commented at 3:23 PM on August 31, 2023:

I think this really means that we should drop BCLog::NONE and replace locations that don't require a category with std::optional<BCLog::LogFlags>

jonatack commented at 4:25 PM on August 31, 2023:

The idea is simplify down to a single Log(category, level) macro.

jonatack commented at 4:27 PM on August 31, 2023:

(or Log{level}(category), though the logs print [category:level], which is a little more consistent with the param order of Log(category, level).

ajtowns commented at 5:23 PM on August 31, 2023:

You'd call Log(std::nullopt, BCLog::Level::Debug) in that case (or have constexpr auto NONE = std::nullopt<LogFlags> and call Log(BCLog::NONE, BCLog::Level::Debug) as normal). If NONE isn't safe for some functions (eg here where it results in an assert(false)), we should just express that in the type system.

jonatack commented at 12:09 AM on September 1, 2023:

Yes, that's a good insight. It looks like it will make sense to do that when removing the deprecated macros.

<details><summary>sample initial diff</summary>

diff --git a/src/logging.cpp b/src/logging.cpp
index 26468aa7396..30c91837748 100644
--- a/src/logging.cpp
+++ b/src/logging.cpp
@@ -139,7 +139,7 @@ bool BCLog::Logger::WillLogCategoryLevel(BCLog::LogFlags category, BCLog::Level
 
 bool BCLog::Logger::DefaultShrinkDebugFile() const
 {
-    return m_categories == BCLog::NONE;
+    return m_categories == 0;
 }
 
 struct CLogCategoryDesc {
@@ -287,8 +287,6 @@ std::string LogCategoryToStr(BCLog::LogFlags category)
         return "txpackages";
     case BCLog::LogFlags::ALL:
         return "all";
-    case BCLog::LogFlags::NONE:
-        assert(false);
     } // no default case, so the compiler can warn about missing cases
     assert(false);
 }
@@ -390,20 +388,19 @@ namespace BCLog {
     }
 } // namespace BCLog
 
-void BCLog::Logger::LogPrintStr(const std::string& str, const std::string& logging_function, const std::string& source_file, int source_line, BCLog::LogFlags category, BCLog::Level level)
+void BCLog::Logger::LogPrintStr(const std::string& str, const std::string& logging_function, const std::string& source_file, int source_line, std::optional<BCLog::LogFlags> category, BCLog::Level level)
 {
     StdLockGuard scoped_lock(m_cs);
     std::string str_prefixed = LogEscapeMessage(str);
 
-    if ((category != LogFlags::NONE || level != Level::None) && m_started_new_line) {
+    if ((category.has_value() && level != Level::None) && m_started_new_line) {
         std::string s{"["};
 
-        if (category != LogFlags::NONE) {
-            s += LogCategoryToStr(category);
+        if (category.has_value()) {
+            s += LogCategoryToStr(category.value());
         }
 
-        if (category != LogFlags::NONE && level != Level::None) {
-            // Only add separator if both flag and level are not NONE
+        if (category.has_value() && level != Level::None) {
             s += ":";
         }
 
diff --git a/src/logging.h b/src/logging.h
index c84d276cb61..325cbe8af66 100644
--- a/src/logging.h
+++ b/src/logging.h
@@ -16,6 +16,7 @@
 #include <functional>
 #include <list>
 #include <mutex>
+#include <optional>
 #include <string>
 #include <unordered_map>
 #include <vector>
@@ -36,7 +37,6 @@ struct LogCategory {
 
 namespace BCLog {
     enum LogFlags : uint32_t {
-        NONE        = 0,
         NET         = (1 <<  0),
         TOR         = (1 <<  1),
         MEMPOOL     = (1 <<  2),
@@ -125,7 +125,7 @@ namespace BCLog {
         std::atomic<bool> m_reopen_file{false};
 
         /** Send a string to the log output */
-        void LogPrintStr(const std::string& str, const std::string& logging_function, const std::string& source_file, int source_line, BCLog::LogFlags category, BCLog::Level level);
+        void LogPrintStr(const std::string& str, const std::string& logging_function, const std::string& source_file, int source_line, std::optional<BCLog::LogFlags> category, BCLog::Level level);
 
         /** Returns whether logs will be written to any output */
         bool Enabled() const
diff --git a/src/qt/transactiondesc.cpp b/src/qt/transactiondesc.cpp
index dae6a2dea97..ebf2346cfb8 100644
--- a/src/qt/transactiondesc.cpp
+++ b/src/qt/transactiondesc.cpp
@@ -340,8 +340,7 @@ QString TransactionDesc::toHTML(interfaces::Node& node, interfaces::Wallet& wall
     //
     // Debug view
     //
-    if (node.getLogCategories() != BCLog::NONE)
-    {
+    if (node.getLogCategories() != 0) {
         strHTML += "<hr><br>" + tr("Debug information") + "<br><br>";
         for (const CTxIn& txin : wtx.tx->vin)

</details>

in src/rpc/node.cpp:195 in 05143b2b94 outdated

 205 | +    const std::vector<UniValue>& cats{categories.get_array().getValues()};
 206 | +    if (std::any_of(cats.cbegin(), cats.cend(), [](const auto& c) { return LogInstance().IsNoneCategory(c.get_str()); })) return;
 207 | +    for (const auto& cat : cats) {
 208 | +        const std::string& c{cat.get_str()};
 209 | +        const bool success{enable ? LogInstance().EnableCategory(c) : LogInstance().DisableCategory(c)};
 210 | +        if (!success) throw JSONRPCError(RPC_INVALID_PARAMETER, "Unsupported logging category: " + c);

ajtowns commented at 3:26 PM on August 31, 2023:

If you specify ["net","sheep"] you get an "Unsupported logging category" error, but if you specify ["none","sheep"] you don't get an error. Same for the -debug config option. Not sure if that's a bug or a feature, though.

jonatack commented at 12:11 AM on September 1, 2023:

Thank you for testing! It is a feature; see the -debug and -debugexclude helps after a81900ae7bef1c6e2c5137ffbb0ddc4bf530ad2a and the RPC logging help since #11191. The behavior now also has test coverage after this pull.

ajtowns commented at 4:23 PM on August 31, 2023: contributor

ACK 05143b2b94cc1d62f27fc73212aa59f9d471f2b8

Fix RPC logging behavior when "0" and "none" values are passed

Per the RPC logging help:

```
In addition, the following are available as category names with special meanings:
  - "all",  "1" : represent all logging categories.
  - "none", "0" : even if other logging categories are specified, ignore all of them.
```

The behavior and documentation were added in #11191, but over time and extended
refactoring, the behavior is not longer working in Bitcoin Core versions
22/23/24 (the last supported versions currently) -- passing `0` or `none` has no
effect.  As there was no test coverage, the regressions went uncaught.  In v24,
`none` became unrecognized.

During the same time period, passing `1` and `all` has been operational and documented.

We therefore need to detect none/0 values and add test coverage in any case, and either:

- leave the functionality out, raise with an error message if none/0 are passed,
  and update the RPC help documentation, or

- fix the behavior by returning early.

Both solutions involve essentially the same code size and complexity.  Given
that all/1 has been operational, and that none/0 has been documented and appears
to have been operational previously, it seems preferable for consistency to
support none/0 in symmetry with all/1, and as ACKed, intended, and documented
since #11191.

---

This commit therefore adds:

- the missing logic to make the functionality work

- a missing logging.h include header

- the relevant info in the logging RPC help doc

6f4127be01

Use same code/behavior for -debug and -debugexclude config options

for consistency between them and for consistency with the logging RPC that uses
the same logic for both -include and -exclude.

Co-authored-by: Anthony Towns <aj@erisian.com.au>
Co-authored-by: Matthew Zipkin <pinheadmz@gmail.com>

70210b1fc8

Update -debug and -debugexclude help documentation

Can be tested with:

./src/bitcoind -h | grep -A12 "\-debug=<\|debugexclude"

d6b55ca5c1

Functional test coverage for RPC logging include/exclude with all/none 9987531a48

Functional test coverage for -debug/-debugexclude config options

and convert some comments to logging.

8330c38df6

log: remove unused BCLog::NONE enums in logging.cpp code

These cases should never be hit and are not needed; the 0/none logging category
logic is handled only by the callers of IsNoneCategory() at these times:

1) during bitcoind startup init

2) when the `logging` RPC is invoked

89303c910e

Improve RPC logging documentation and examples

and make the logging example in the developer notes zsh-compatible
(for instance, zsh is currently the default shell in macOS).

The RPC logging help can be tested with:

./src/bitcoin-cli help logging

94b059ffe4

jonatack force-pushed on Sep 1, 2023

jonatack commented at 12:42 AM on September 1, 2023: member

Updated for @ajtowns' feedback to make IsNoneCategory() a static function in 6f4127b (#27231).

diff --git a/src/logging.h b/src/logging.h
index 4dfb7106327..83c285c905d 100644
--- a/src/logging.h
+++ b/src/logging.h
@@ -180,7 +180,7 @@ namespace BCLog {
 
         bool WillLogCategory(LogFlags category) const;
         bool WillLogCategoryLevel(LogFlags category, Level level) const;
-        [[nodiscard]] bool IsNoneCategory(const std::string& s) const { return s == "0" || s == "none"; }
+        [[nodiscard]] static bool IsNoneCategory(const std::string& s) { return s == "0" || s == "none"; }

ajtowns commented at 5:14 PM on September 5, 2023: contributor

reACK 94b059ffe403a948957152b96f24fba4d9ee31f0

pinheadmz approved

pinheadmz commented at 3:43 PM on September 6, 2023: member

re-ACK 94b059ffe403a948957152b96f24fba4d9ee31f0

confirmed with range diff 93b387fe70 to 94b059ffe4 Changes since last review address AJ's comments, minimal diff Built and tested again locally

<details><summary>Show Signature</summary>

pinheadmz's public key is on keybase

</details>

ajtowns commented at 6:27 AM on September 12, 2023: contributor

The behavior was intended to be added in #11191.

It's still not clear if this was broken from the time it was merged, or at some other later point. This also does not work with 22.x, and any earlier versions are EOL.

If it's been broken forever (or at least is in all currently maintained releases), and no ones even noticed, we could take advantage of that, to remove some of the complexity here; do we definitely need multiple different ways of achieving the same logging toggling?

Has this comment being replied to anywhere already?

It does seem like it would be pretty easy to remove this behaviour -- removing "none" would mean that anyone who specified it would get an error on startup, which is a good clue to fix their config. And you get the same "actually, for this run I want to disable debugging stuff" by adding -nodebug at the end (eg, on the cli) or by specifying "-debugexclude=all". For the logging rpc, just replace the argument with [] instead of adding none seems reasonable.

jonatack commented at 7:37 PM on September 12, 2023: member

Has this comment being replied to anywhere already?

Yes, #27231 (comment) and the pull description contains that discussion as well.

ajtowns commented at 2:25 AM on September 13, 2023: contributor

Exploring this, it doesn't look like there would be much code simplification gained by dropping none for 0 only, which would no longer be in symmetry with all/1 that have been operational for a long time.

Why would you keep the 0 option? Just drop the concept entirely: https://github.com/bitcoin/bitcoin/compare/master...ajtowns:bitcoin:202309-debug-no-none That special case was added well prior to -debugexclude (namely #3067 vs #10123)

jonatack commented at 3:40 PM on September 13, 2023: member

I think that question is addressed in the pull description.

ajtowns commented at 10:36 PM on September 13, 2023: contributor

Why would you keep the 0 option? Just drop the concept entirely: master...ajtowns:bitcoin:202309-debug-no-none That special case was added well prior to -debugexclude (namely #3067 vs #10123)

I think that question is addressed in the pull description.

I would have thought it was obvious that I don't see an answer to that question in the pull description, so that's an impressively unconstructive response. In the PR description, you claim:

leave the functionality out, raise with an error message if the values are passed, and update the RPC help documentation, or

fix the behavior by returning early.

Both solutions involve essentially the same code size and complexity.

But that's trivially not true: removing the code obviously results in a lower code size, and it also reduces the number of special cases that have to be documented and understood by users.

No longer convinced this makes sense.

jonatack commented at 11:08 PM on September 13, 2023: member

I would have thought it was obvious that I don't see an answer to that question in the pull description, so that's an impressively unconstructive response.

It's reasonable to think one could gloss over the long-ish discussion in the OP (or what I attempted to communicate with it), as I think it replies to the question (at least, as I understood it).

Here's the relevant section:

During the same time period, passing `1` and `all` has been operational and documented. 

Solution: detect `none`/`0` values and add test coverage in any case, and either:
    
- leave the functionality out, raise with an error message if the values are passed, and update the RPC
  help documentation, or

- fix the behavior by returning early.

Both solutions involve essentially the same code size and complexity.  Given that `all`/`1` has been
operational, and that `none`/`0` has been documented and appears per the code of the original PR
to have been operational, it seems preferable for consistency to support `none`/`0` in symmetry with
`all`/`1` and as ACKed, intended, and documented in [#11191](/bitcoin-bitcoin/11191/).

But that's trivially not true: removing the code obviously results in a lower code size

No, not if we check for the values and raise with an error message if the values are passed, with relevant test coverage. This ought to be done given that the functionality has been documented in the RPC help for around 7 years now, and perhaps also as it's not clear at what point it broke.

That is what I meant by "Solution: detect none/0 values and add test coverage in any case", for either way requires code, test coverage, and documentation changes. As I wrote, I prefer the route of fixing what was ACKed, intended, and documented in #11191.

This pull improves a lot of things here. It not only fixes broken functionality while using lesser or equal lines of code (apart from test coverage and added docs), it also adds test coverage that has been missing for a long time and improves the documentation. It would be nice to see this finally move forward, and I appreciate your reviews of it!

ajtowns commented at 1:47 AM on September 14, 2023: contributor

Both solutions involve essentially the same code size and complexity.  Given that `all`/`1` has been
operational, and that `none`/`0` has been documented and appears per the code of the original PR
to have been operational, it seems preferable for consistency to support `none`/`0` in symmetry with
`all`/`1` and as ACKed, intended, and documented in [#11191](/bitcoin-bitcoin/11191/).
But that's trivially not true: removing the code obviously results in a lower code size

No, not if we check for the values and raise with an error message if the values are passed, with relevant test coverage.

We already check for invalid categories and issue an error message for those. Doing the same thing for none/0 doesn't require extra code or extra test coverage.

This ought to be done given that the functionality has been documented in the RPC help for around 7 years now, and perhaps also as it's not clear at what point it broke.

FWIW, it broke in #12954 ("This is purely a refactor with no behavior changes." :roll_eyes:) -- previously getCategoryMask evaluated all the strings, returning null if "none" was passed in and erroring out if any were invalid; after that PR EnableOrDisableLogCategories dropped the special handling of "none" and enabled/disabled each category as it went, which means logging ["net", "nosuchcategory"] changed its behaviour from just giving an error, to first enabling net logging, then giving an error.

#11191 was merged 2017-11-30 and #12954 was merged 2018-05-01 so this behaviour only worked for five months if you were running master, and only for the 0.16.x release. 0.16.0 was also the first release that considered logging a public api (#11626).

(I have an alias git-history which runs git log --ignore-cr-at-eol -M -C -L${2},${3}:${1}; so git blame rpc/node.cpp to get the line numbers of the function, then git-history rpc/node.cpp 187 204 makes it easy to trace things through. At least until the refactorings get too intense. AAAA+++ excellent alias, highly recommended)

That is what I meant by "Solution: detect none/0 values and add test coverage in any case", for either way requires code, test coverage, and documentation changes. As I wrote, I prefer the route of fixing what was ACKed, intended, and documented in #11191.

Why? The people who ACKed an old PR aren't gods, and we don't have to take their opinions at the time as gospel. As far as I can see, the other ways we (now) have of getting this behaviour are strictly superior.

The reasons to have that behaviour originally was that "-debug" was originally a bool flag that got upgraded to support multiple distinct categories, and the arg parser at the time wasn't as clever/complicated as it is today. The reason given in 11191 for doing anything was "0","1" are allowed in both array of <include> and <exclude>. "0" is ignored and "1" is treated same as "all". It is confusing, so forbid them. so "forbid them" for none/0 still seems pretty reasonable.

This pull improves a lot of things here. It not only fixes broken functionality while using lesser or equal lines of code (apart from test coverage and added docs), it also adds test coverage that has been missing for a long time and improves the documentation. It would be nice to see this finally move forward, and I appreciate your reviews of it!

These commits have a bunch of extra complexity compared to dropping support for this behaviour:

Fix RPC logging behaviour -- bunch of extra code, with a requirement to keep it in sync with code in init, vs dropping the documentation
Update -debug help docs -- bunch of extra text to read documenting a special case that most people won't want
Functional test coverage for RPC -- the 0/none loop can be omitted entirely (unknown category just means previously listed categories get actioned)

Other commits seem mostly fine with 0/none special casing dropped:

Unit tests for LogPrintfCategory -- fine
Functional test does not return all/none -- fine
Improve RPC logging doc and examples -- fine
Functional test coverage for -debug -- replace -debug=0 with -nodebug, drop -debugexclude=none check
Remove unused NONE enums -- fine-ish

jonatack commented at 7:26 PM on January 8, 2024: member

I'm going to open an alternate pull that does what you suggest and see what reviewers (if any) prefer.

DrahtBot added the label Needs rebase on Jan 10, 2024

DrahtBot commented at 9:13 PM on January 10, 2024: contributor

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

fanquake commented at 1:59 PM on March 6, 2024: member

I'm going to open an alternate pull that does what you suggest and see what reviewers (if any) prefer.

Did this end up getting opened? Moving this PR to draft for now in any case.

fanquake marked this as a draft on Mar 6, 2024

fanquake closed this on Mar 18, 2024

jonatack commented at 4:29 PM on April 8, 2024: member

Will re-open as a new PR, along with the alternative version, as it is a good and mature patch with many updates made for reviews and nits.

bitcoin locked this on Apr 8, 2025