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

pull jonatack wants to merge 9 commits into bitcoin:master from jonatack:2023-03-logging-fixes-and-test-coverage changing 8 files +148 −66
  1. jonatack commented at 1:40 am on March 9, 2023: contributor

    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:

    0$ ./src/bitcoin-cli help logging
    1
    2In addition, the following are available as category names with special meanings:
    3  - "all",  "1" : represent all logging categories.
    4  - "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:

    0$ ./src/bitcoin-cli logging '["none"]'
    1error code: -8
    2error message:
    3unknown 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.

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

  3. DrahtBot added the label RPC/REST/ZMQ on Mar 9, 2023
  4. jonatack marked this as ready for review on Mar 9, 2023
  5. 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:
    0    for (const auto& c:categories.get_array().getValues()) {
    1        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.

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

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

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

    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).
  6. 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?

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

  8. jonatack commented at 6:51 pm on March 9, 2023: contributor

    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.

  9. 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:
    0static void EnableOrDisableLogCategories(const UniValue& categories, bool enable)
    1{
    

    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)
  10. 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?

  11. 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
  12. jonatack force-pushed on Mar 10, 2023
  13. jonatack marked this as a draft on Mar 10, 2023
  14. jonatack force-pushed on Mar 15, 2023
  15. jonatack force-pushed on Mar 16, 2023
  16. DrahtBot added the label Needs rebase on Mar 23, 2023
  17. jonatack force-pushed on Mar 31, 2023
  18. jonatack commented at 4:04 pm on March 31, 2023: contributor

    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!

  19. jonatack marked this as ready for review on Mar 31, 2023
  20. DrahtBot removed the label Needs rebase on Apr 2, 2023
  21. DrahtBot added the label Needs rebase on Apr 3, 2023
  22. jonatack force-pushed on Apr 4, 2023
  23. DrahtBot removed the label Needs rebase on Apr 4, 2023
  24. 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?

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

    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!)

     0diff --git a/src/init/common.cpp b/src/init/common.cpp
     1index a5b07420d94..c99a512459b 100644
     2--- a/src/init/common.cpp
     3+++ b/src/init/common.cpp
     4@@ -77,26 +77,28 @@ void SetLoggingLevel(const ArgsManager& args)
     5     }
     6 }
     7 
     8-// We run each of these configuration options through SetLoggingCategories. The order matters;
     9-// -debugexclude settings take priority over -debug ones, so -debugexclude is run after -debug.
    10-static constexpr std::array DEBUG_LOG_OPTS{"-debug", "-debugexclude"};
    11+static bool EnableOrDisable(const std::string& opt, const std::string& category)
    12+{
    13+    if (opt == "-debug") return LogInstance().EnableCategory(category);
    14+    if (opt == "-debugexclude") return LogInstance().DisableCategory(category);
    15+    NONFATAL_UNREACHABLE();
    16+}
    17 
    18+// Maintain the same logic in both of the EnableOrDisableLogCategories functions in the codebase.
    19 static void EnableOrDisableLogCategories(const ArgsManager& args, const std::string& opt)
    20 {
    21-    if (!args.IsArgSet(opt)) return;
    22-    Assume(std::any_of(DEBUG_LOG_OPTS.cbegin(), DEBUG_LOG_OPTS.cend(), [&](const auto& d) { return opt == d; }));
    23     const std::vector<std::string>& categories{args.GetArgs(opt)};
    24     if (std::any_of(categories.cbegin(), categories.cend(), [](const auto& c) { return LogInstance().IsNoneCategory(c); })) return;
    25     for (const auto& c : categories) {
    26-        const bool success{opt == DEBUG_LOG_OPTS[0] ? LogInstance().EnableCategory(c) : LogInstance().DisableCategory(c)};
    27-        if (!success) InitWarning(strprintf(_("Unsupported logging category %s=%s."), opt, c));
    28+        if (!EnableOrDisable(opt, c)) InitWarning(strprintf(_("Unsupported logging category %s=%s."), opt, c));
    29     }
    30 }
    31 
    32 void SetLoggingCategories(const ArgsManager& args)
    33 {
    34-    for (const std::string& opt : DEBUG_LOG_OPTS) {
    35-        EnableOrDisableLogCategories(args, opt);
    36+    // debugexclude settings take priority over debug ones, so run debugexclude last
    37+    for (const std::string& opt : {"-debug", "-debugexclude"}) {
    38+        if (args.IsArgSet(opt)) EnableOrDisableLogCategories(args, opt);
    39     }
    40 }
    41 
    42diff --git a/src/rpc/node.cpp b/src/rpc/node.cpp
    43index 3bae7bef722..9c32839231f 100644
    44--- a/src/rpc/node.cpp
    45+++ b/src/rpc/node.cpp
    46@@ -209,14 +209,13 @@ static RPCHelpMan getmemoryinfo()
    47     };
    48 }
    49 
    50+// Maintain the same logic in both of the EnableOrDisableLogCategories functions in the codebase.
    51 static void EnableOrDisableLogCategories(const UniValue& categories, bool enable)
    52 {
    53-    const std::vector<UniValue>& category_values{categories.get_array().getValues()};
    54-    for (const auto& category : category_values) {
    55-        if (LogInstance().IsNoneCategory(category.get_str())) return;
    56-    }
    57-    for (const auto& category : category_values) {
    58-        const std::string& c{category.get_str()};
    59+    const std::vector<UniValue>& cats{categories.get_array().getValues()};
    60+    if (std::any_of(cats.cbegin(), cats.cend(), [](const auto& c) { return LogInstance().IsNoneCategory(c.get_str()); })) return;
    61+    for (const auto& cat : cats) {
    62+        const std::string& c{cat.get_str()};
    63         const bool success{enable ? LogInstance().EnableCategory(c) : LogInstance().DisableCategory(c)};
    64         if (!success) throw JSONRPCError(RPC_INVALID_PARAMETER, "Unsupported logging category: " + c);
    65     }
    
  25. 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.
  26. 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:

    0
    1    case BCLog::LogFlags::ALL:
    2        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() 👍
  27. 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.
  28. 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
  29. 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…
  30. achow101 added this to the milestone 25.0 on Apr 11, 2023
  31. jonatack force-pushed on Apr 11, 2023
  32. jonatack force-pushed on Apr 12, 2023
  33. 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 👍

  34. pinheadmz approved
  35. 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

     0-----BEGIN PGP SIGNED MESSAGE-----
     1Hash: SHA256
     2
     3ACK e9f6fd0e028e6a5669926926792c70c31a26c403
     4-----BEGIN PGP SIGNATURE-----
     5
     6iQIzBAEBCAAdFiEE5hdzzW4BBA4vG9eM5+KYS2KJyToFAmQ29zkACgkQ5+KYS2KJ
     7yTqh4hAAwBBMTmfeyYhdSTLpO2hma6GolZdUdvzOYdMhADsucUvihZIic8o70MZU
     8hzoqnYsGdTvw31MxoBDWre10y9jBvXfK0vtrkC8A7nzMNBHVaVTqFfsVayUQ4TMm
     96PPrKJm1TbdAUc5/aiv6B3FEiCdUx2hlugWyFnzxLt3sPS8pnPMQ8GMdyxo7+0Mh
    10OYsRLxCvwnMFHMGh/mA3do7Znj28f3QM4xKGYV7OA/GeghqNl75Oo3+7pGB/Rq5D
    11JXfqjLN4/pAvZ78dr5k6O8Xgz/tlsCtPs5gJo+aaVwPv0my5fpCO3GbegD76ybuK
    123teZPSCufYe7XBNOQVnkXB4EtnhwrXPEXz/xAAOssBKhQrfk7TV4sovi4pRrNxec
    13rAVO3Fc9H0weHywxi1DO56/0F9oLNVBWJMLmV1t9/FF/lrIHvWDTwvywKg1N/mpQ
    14MY4NKmBLVD0kLdczmEhdpPua2400WwYWm/ypPXjOJhGuS7pmJW2WNOXv06NNXaxm
    15h/4byxYhgB6AkffZ5IQM5+6gEXixWbFDmV/eEciydB0VnNv1+nJctZ1QxyVUnaZ9
    16ZfBRm9e99Q9JHtOkvF8UF3X5bLP9bCqOhCThqjWsxy6shzpkkkhBE0O+HDkJEHsz
    17cyKvlcNo4a2OX0EkITmX195G3MYqFK0RATitcM5e3SZEA7wkdVg=
    18=DtQx
    19-----END PGP SIGNATURE-----
    

    pinheadmz’s public key is on keybase

  36. jonatack force-pushed on Apr 12, 2023
  37. pinheadmz approved
  38. pinheadmz commented at 2:51 pm on April 13, 2023: member

    ACK 5991eddb98ce59b883ae695752d4e90f32d43960

     0-----BEGIN PGP SIGNED MESSAGE-----
     1Hash: SHA256
     2
     3ACK 5991eddb98ce59b883ae695752d4e90f32d43960
     4-----BEGIN PGP SIGNATURE-----
     5
     6iQIzBAEBCAAdFiEE5hdzzW4BBA4vG9eM5+KYS2KJyToFAmQ4FuQACgkQ5+KYS2KJ
     7yTqVKQ//TIOVSamur/OBGsHB1lgx9C3wyqQFSg+RzImVrDvquEhTDdwfjWI56DzL
     8sYWxaSDjHLP+4jYK7x3O4QoZJW1iJDlz56PhakxtDSzWMIr0WIfHGpTV6oH1p4Uh
     9Kaz57R6Y71G4ADMqeR48MqLK/B7vMuEKhzUUmGk14O/8bPUHk7HJE70b5F3zOTb9
    10EBu/NtFd3D5rdRCSTMbmkvkuZ8ezAzoROTT+X08ge1Rf2RwVHeMklY74apx12+qT
    11n4xklbM1YZ/6HN40uCxGXnhgYtqhwAk8I94Zz5J8lJTh7UbXDrYcWiyGd3x6Ph7Y
    126ZmSP7cgCXTAHx92Hb6QHysInJZVcd/SP11PhdWkgSAvLpKHcXiZiPOMUKz6p4Ih
    13O3i/BvsaGR0HkPxCQ0x9XDoABHFGNT3YT64dYiCxbwBb9yPiNzZYTOexH8iZOIQp
    14iftnh/d+iZSIiPZP1uVctfrUsr9U+ECIV0hFOheC7yDygxYI3QIyzFYj2kzxfm0c
    15YwBAgCSnl0uxGHryFtya3fr5Y0zFk+wlhhm04nLM5VVbxq3kQmfg8+CKPJ8MayCh
    16LRc89eL53ijefy5pmCXEZvMLJIX9bcdLVTRJPe4JS5lRh+fmSP2rEyPffymnXL1P
    1751es/2so7kOxu4chEr178/+GY4uZjIPxd1MOMxl11QE7ug8COXQ=
    18=sU3Z
    19-----END PGP SIGNATURE-----
    

    pinheadmz’s public key is on keybase

  39. glozow removed this from the milestone 25.0 on Apr 14, 2023
  40. DrahtBot added the label Needs rebase on Jun 20, 2023
  41. jonatack force-pushed on Jun 20, 2023
  42. jonatack commented at 11:37 pm on June 20, 2023: contributor
    Rebased following merge of #27632; only change is to commit 4351f26203c6daab321d478a3992e1723cc60814 per git range-diff ee22ca5 5991edd 630b38e.
  43. DrahtBot removed the label Needs rebase on Jun 20, 2023
  44. 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
  45. pinheadmz approved
  46. pinheadmz commented at 8:11 pm on June 22, 2023: member

    re-ACK 630b38e92b4e40d49d69970b6c5bc02aa39ba210

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

     0-----BEGIN PGP SIGNED MESSAGE-----
     1Hash: SHA256
     2
     3ACK 630b38e92b4e40d49d69970b6c5bc02aa39ba210
     4-----BEGIN PGP SIGNATURE-----
     5
     6iQIzBAEBCAAdFiEE5hdzzW4BBA4vG9eM5+KYS2KJyToFAmSUqggACgkQ5+KYS2KJ
     7yTqixA/+NOb+9zG4txOdmcIJWSVwPIu7nU59E9EfRvutPPMOw12R0tqm5+B1TvYQ
     8LxZCFVTck5fe+dAjy0v0wEimrfyY7fJzfxp+HC+ksNWkh88xrgfVFPIzSLwmHx4Z
     9Ake54SuSEICD7FUJ8G43Q5uNkgG+/rzQ73iLdiY9fdmex6y2kW5yXoPlwhczjRJo
    10lGV7JXVC0yZjwuey9LhQdCHpyr0rc9rUZ3MD3Wfc4fH+NH/20VkOQimA1ux1KSe4
    11wY0ezbMW0AyeH3WAnnk+c3G8+Y+k88s4f6J/uxfKuyFz52Cz1vfyK/vudabqTvxL
    12AyZ/P++n1gqBZkyOmzHhKYxv0jtFBHb5OtIj25tZoP33/AlL3iy8ZjD6aUN3tYfU
    138dzRiUD7vTYauKnd6QKyGJEGKir8D24UVE34PUM7o1l2GtwK386s3Lr4CfRdVYyP
    14P0BkL638CgkMzyF5HhQVLoxr/jdpOQdvzd3KY6yzenMdBH8aD5TydwBswvGb4EGd
    15hvn7txdklo+ZkJLc4A4b7zNjB32NWx2JWUqTr8qV/oKgUPrpo9q2SPB3kqOB9zhV
    16L1b7VJxVE9xreteU+zOgVVQ9PRtgzXSRJUnC+nCgCZrJm/MMy9iqN54aLFdMmDCf
    17Xy3kkky33ElyubH7r6NHYARqXoDoxfmMJm3J5EQ72SSDI+j8KX8=
    18=cmua
    19-----END PGP SIGNATURE-----
    

    pinheadmz’s public key is on keybase

  47. 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:

     0// Maintain similar logic in both of the EnableOrDisableLogCategories() functions in the codebase.
     1static void EnableOrDisableLogCategories(util::Result<void>& result, const ArgsManager& args, const std::string& opt, bool enable)
     2{
     3    if (!result) return;
     4    if (!args.IsArgSet(opt)) return;
     5    const std::vector<std::string>& categories{args.GetArgs(opt)};
     6    if (std::any_of(categories.cbegin(), categories.cend(), [](const auto& c) { return LogInstance().IsNoneCategory(c); })) return;
     7    for (const auto& category : categories) {
     8        bool success = (enable ? LogInstance().EnableCategory(category) : LogInstance().DisableCategory(category));
     9        if (!success) {
    10            result = util::Error{strprintf(_("Unsupported logging category %s=%s."), opt, category)};
    11            return;
    12        }
    13    }
    14    return;
    15}
    16
    17util::Result<void> SetLoggingCategories(const ArgsManager& args)
    18{
    19    util::Result<void> result;
    20
    21    // debugexclude settings take priority over debug ones, so run debugexclude last
    22    EnableOrDisableLogCategories(result, args, "-debug", /*enable=*/true);
    23    EnableOrDisableLogCategories(result, args, "-debugexclude", /*enable=*/false);
    24    if (!result) return util::Error{util::ErrorString(result)};
    25    return {};
    26}
    

    (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
  48. ajtowns commented at 2:07 pm on June 23, 2023: contributor
    utACK 630b38e92b4e40d49d69970b6c5bc02aa39ba210
  49. jonatack force-pushed on Jun 23, 2023
  50. jonatack commented at 6:09 pm on June 23, 2023: contributor

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

     0--- a/src/init/common.cpp
     1+++ b/src/init/common.cpp
     2@@ -11,7 +11,6 @@
     3 #include <logging.h>
     4 #include <node/interface_ui.h>
     5 #include <tinyformat.h>
     6-#include <util/check.h>
     7 #include <util/fs.h>
     8 #include <util/fs_helpers.h>
     9 #include <util/result.h>
    10@@ -79,34 +78,29 @@ util::Result<void> SetLoggingLevel(const ArgsManager& args)
    11     return {};
    12 }
    13 
    14-[[nodiscard]] static bool EnableOrDisable(const std::string& opt, const std::string& category)
    15-{
    16-    if (opt == "-debug") return LogInstance().EnableCategory(category);
    17-    if (opt == "-debugexclude") return LogInstance().DisableCategory(category);
    18-    NONFATAL_UNREACHABLE();
    19-}
    20-
    21 // Maintain similar logic in both of the EnableOrDisableLogCategories() functions in the codebase.
    22-[[nodiscard]] static util::Result<void> EnableOrDisableLogCategories(const ArgsManager& args, const std::string& opt)
    23+static void EnableOrDisableLogCategories(util::Result<void>& result, const ArgsManager& args, const std::string& opt, bool enable)
    24 {
    25+    if (!result || !args.IsArgSet(opt)) return;
    26     const std::vector<std::string>& categories{args.GetArgs(opt)};
    27-    if (std::any_of(categories.cbegin(), categories.cend(), [](const auto& c) { return LogInstance().IsNoneCategory(c); })) return {};
    28+    if (std::any_of(categories.cbegin(), categories.cend(), [](const auto& c) { return LogInstance().IsNoneCategory(c); })) return;
    29     for (const auto& c : categories) {
    30-        if (!EnableOrDisable(opt, c)) return util::Error{strprintf(_("Unsupported logging category %s=%s."), opt, c)};
    31+        const bool success{enable ? LogInstance().EnableCategory(c) : LogInstance().DisableCategory(c)};
    32+        if (!success) {
    33+            result = util::Error{strprintf(_("Unsupported logging category %s=%s."), opt, c)};
    34+            return;
    35+        }
    36     }
    37-    return {};
    38+    return;
    39 }
    40 
    41 util::Result<void> SetLoggingCategories(const ArgsManager& args)
    42 {
    43+    util::Result<void> result;
    44     // debugexclude settings take priority over debug ones, so run debugexclude last
    45-    for (const std::string& opt : {"-debug", "-debugexclude"}) {
    46-        if (args.IsArgSet(opt)) {
    47-            auto result = EnableOrDisableLogCategories(args, opt);
    48-            if (!result) return util::Error{util::ErrorString(result)};
    49-        }
    50-    }
    51-    return {};
    52+    EnableOrDisableLogCategories(result, args, "-debug", /*enable=*/true);
    53+    EnableOrDisableLogCategories(result, args, "-debugexclude", /*enable=*/false);
    54+    return result;
    55 }
    
  51. 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:
    0src/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]
    1  262 |     for (const std::string& s : {"", "NONE", "net", "all", "1"}) {
    2      |                             ^
    3src/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.

     0 BOOST_FIXTURE_TEST_CASE(logging_IsNoneCategory, LogSetup)
     1 {
     2-    for (const std::string& s : {"none", "0"}) {
     3+    for (const char* const& s : {"none", "0"}) {
     4         BOOST_CHECK(LogInstance().IsNoneCategory(s));
     5     }
     6-    for (const std::string& s : {"", "NONE", "net", "all", "1"}) {
     7+    for (const char* const& s : {"", "NONE", "net", "all", "1"}) {
     8         BOOST_CHECK(!LogInstance().IsNoneCategory(s));
     9     }
    10 }
    
  52. 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.

    0         # In addition to net and tor, leveldb/libevent/rand are excluded by the test framework.
    1+        result = node.logging()
    2         for category in ["leveldb", "libevent", "net", "rand", "tor"]:
    3-            assert not node.logging()[category]
    4+            assert not result[category]
    
  53. 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.

    0-        assert all(v == True for v in node.logging().values())  # -debugexclude=[none,qt] does not exclude qt
    1+        # Expect the "none" value passed in -debugexclude=[none,qt] to mean that
    2+        # none of the categories passed with -debugexclude are excluded: neither
    3+        # qt passed here nor leveldb/libevent/rand passed by the test framework.
    4+        assert all(v == True for v in node.logging().values())
    
  54. luke-jr changes_requested
  55. jonatack force-pushed on Jun 30, 2023
  56. jonatack commented at 9:02 pm on June 30, 2023: contributor

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

     0--- a/src/test/logging_tests.cpp
     1+++ b/src/test/logging_tests.cpp
     2@@ -262,11 +262,11 @@ BOOST_FIXTURE_TEST_CASE(logging_Conf, LogSetup)
     3 
     4 BOOST_FIXTURE_TEST_CASE(logging_IsNoneCategory, LogSetup)
     5 {
     6-    for (const std::string& s : {"none", "0"}) {
     7-        BOOST_CHECK(LogInstance().IsNoneCategory(s));
     8+    for (const char* const& c : {"none", "0"}) {
     9+        BOOST_CHECK(LogInstance().IsNoneCategory(c));
    10     }
    11-    for (const std::string& s : {"", "NONE", "net", "all", "1"}) {
    12-        BOOST_CHECK(!LogInstance().IsNoneCategory(s));
    13+    for (const char* const& c : {"", "NONE", "net", "all", "1"}) {
    14+        BOOST_CHECK(!LogInstance().IsNoneCategory(c));
    15     }
    16 }
    17 
    18diff --git a/test/functional/feature_logging.py b/test/functional/feature_logging.py
    19index 7958a743853..8448eff4a43 100755
    20--- a/test/functional/feature_logging.py
    21+++ b/test/functional/feature_logging.py
    22@@ -34,8 +34,9 @@ class LoggingTest(BitcoinTestFramework):
    23         ])
    24         assert os.path.isfile(self.relative_log_path("foo.log"))
    25         # In addition to net and tor, leveldb/libevent/rand are excluded by the test framework.
    26+        result = node.logging()
    27         for category in ["leveldb", "libevent", "net", "rand", "tor"]:
    28-            assert not node.logging()[category]
    29+            assert not result[category]
    30 
    31         self.log.info("Test alternative log file name outside datadir and -debugexclude={none,qt}")
    32         tempname = os.path.join(self.options.tmpdir, "foo.log")
    33@@ -45,7 +46,10 @@ class LoggingTest(BitcoinTestFramework):
    34             "-debugexclude=qt",
    35         ])
    36         assert os.path.isfile(tempname)
    37-        assert all(v == True for v in node.logging().values())  # -debugexclude=[none,qt] does not exclude qt
    38+        # Expect the "none" value passed in -debugexclude=[none,qt] to mean that
    39+        # none of the categories passed with -debugexclude are excluded: neither
    40+        # qt passed here nor leveldb/libevent/rand passed by the test framework.
    41+        assert all(v == True for v in node.logging().values())
    42 
    43         self.log.info("Test -debugexclude=1/all excludes all categories")
    
  57. jonatack requested review from maflcko on Jul 12, 2023
  58. jonatack requested review from luke-jr on Jul 12, 2023
  59. jonatack requested review from ajtowns on Jul 12, 2023
  60. jonatack requested review from pinheadmz on Jul 12, 2023
  61. pinheadmz approved
  62. 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.

     0-----BEGIN PGP SIGNED MESSAGE-----
     1Hash: SHA256
     2
     3ACK 93b387fe70174d174b840016da8531ef65ec313e
     4-----BEGIN PGP SIGNATURE-----
     5
     6iQIzBAEBCAAdFiEE5hdzzW4BBA4vG9eM5+KYS2KJyToFAmS5WPgACgkQ5+KYS2KJ
     7yTp7mxAAwSLI2Fqz8+sRsHF7c/wzERlqZm7Ma8tg9ob0yyvD7Q0t89rCtcDSKL9c
     8dO2l5DcHotexApg26sp3gfRlQCB7Pv24aCyHeCYl336AcXL57YHbbDu9f/Ct3PRE
     9+3QoK9b4BiJ2D3db77gJGgmq9QhrnCmCk41bRA5VIyAi3scy4y9lzisRjRswIDji
    10PnbSJR2qZVO9iDux5Ia7KSHsLxjjC7KhhbhQdDq0LzyK0tQvnyC6+2S8yZVDhxv4
    11+XyUgsU+YBv49eYPrHid6MVjH58QBBjwBfLGccnqI/ZPb5nogmfFjokj4W8/QRiy
    12W5nMrCPZYXwRspSn+XbX3Ivzez9mw51Zj3CvQ0tABgMFOTx1ZUESEYwk1SgxjTyV
    13p2jFMinQVBYeH77IygL2AWeHoha1FCr4zlaLRDBd08MYVccMK+xEL4XGbsNOYWen
    14mQlBbpPB49YcB2Vs+ZAlHVX4Bp5TKpfVSPEttAyJrn2nXXGPde2gbB3gOIabLK8U
    151fAEeG8JZW5Qs4Hl46B51SdpdCe64WkY2lKTWwNZjpmL5YM0ufbPfPscfnpd3Myg
    16bJfj+6P1N9UhizVYN+Bzm/zDKS/S6zv4DvV8FF13HhGVtlQ+BhGmRa1qr6xSilu8
    17hxJTLm6bs+2a2/dFQVuhgMMz3Uwt/6tZsIkyX5AgmouDGSkGbTQ=
    18=kvhB
    19-----END PGP SIGNATURE-----
    

    pinheadmz’s public key is on keybase

  63. 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.
  64. jonatack force-pushed on Aug 1, 2023
  65. jonatack commented at 10:04 pm on August 1, 2023: contributor

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

     0diff --git a/src/logging.cpp b/src/logging.cpp
     1index f197943a0bd..d3f61ca54c2 100644
     2--- a/src/logging.cpp
     3+++ b/src/logging.cpp
     4@@ -4,6 +4,7 @@
     5 // file COPYING or http://www.opensource.org/licenses/mit-license.php.
     6 
     7 #include <logging.h>
     8+#include <util/check.h>
     9 #include <util/fs.h>
    10 #include <util/string.h>
    11 #include <util/threadnames.h>
    12@@ -284,9 +285,9 @@ std::string LogCategoryToStr(BCLog::LogFlags category)
    13         return "scan";
    14     case BCLog::LogFlags::ALL:
    15         return "all";
    16-    case BCLog::LogFlags::NONE: // this case is normally never hit
    17-        return "";
    18-    }
    19+    case BCLog::LogFlags::NONE:
    20+        Assume(false);
    21+    } // no default case, so the compiler can warn about missing cases
    22     assert(false);
    23 }
    
  66. jonatack force-pushed on Aug 1, 2023
  67. DrahtBot added the label CI failed on Aug 2, 2023
  68. DrahtBot removed the label CI failed on Aug 2, 2023
  69. Unit tests for LogPrintfCategory and LogPrintLevel with BCLog::ALL/NONE
    to specify expected current behavior and check future changes for regressions.
    b5d0dd7c25
  70. Functional test that RPC logging does not return all/none categories e87de92856
  71. 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.
  72. jonatack force-pushed on Aug 17, 2023
  73. jonatack commented at 6:05 pm on August 17, 2023: contributor
    Updated per git range-diff 6ce5e8f ce8faad 05143b2 to take review feedback by @ajtowns (thanks!) and rebase for CI.
  74. DrahtBot added the label CI failed on Aug 18, 2023
  75. DrahtBot removed the label CI failed on Aug 18, 2023
  76. jonatack requested review from pinheadmz on Aug 28, 2023
  77. jonatack commented at 1:14 pm on August 31, 2023: contributor
    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.
  78. 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 0:36 am on September 1, 2023:
    That’s true. Updated from const to static.
  79. 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 0: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.

     0diff --git a/src/logging.cpp b/src/logging.cpp
     1index 26468aa7396..30c91837748 100644
     2--- a/src/logging.cpp
     3+++ b/src/logging.cpp
     4@@ -139,7 +139,7 @@ bool BCLog::Logger::WillLogCategoryLevel(BCLog::LogFlags category, BCLog::Level
     5 
     6 bool BCLog::Logger::DefaultShrinkDebugFile() const
     7 {
     8-    return m_categories == BCLog::NONE;
     9+    return m_categories == 0;
    10 }
    11 
    12 struct CLogCategoryDesc {
    13@@ -287,8 +287,6 @@ std::string LogCategoryToStr(BCLog::LogFlags category)
    14         return "txpackages";
    15     case BCLog::LogFlags::ALL:
    16         return "all";
    17-    case BCLog::LogFlags::NONE:
    18-        assert(false);
    19     } // no default case, so the compiler can warn about missing cases
    20     assert(false);
    21 }
    22@@ -390,20 +388,19 @@ namespace BCLog {
    23     }
    24 } // namespace BCLog
    25 
    26-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)
    27+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)
    28 {
    29     StdLockGuard scoped_lock(m_cs);
    30     std::string str_prefixed = LogEscapeMessage(str);
    31 
    32-    if ((category != LogFlags::NONE || level != Level::None) && m_started_new_line) {
    33+    if ((category.has_value() && level != Level::None) && m_started_new_line) {
    34         std::string s{"["};
    35 
    36-        if (category != LogFlags::NONE) {
    37-            s += LogCategoryToStr(category);
    38+        if (category.has_value()) {
    39+            s += LogCategoryToStr(category.value());
    40         }
    41 
    42-        if (category != LogFlags::NONE && level != Level::None) {
    43-            // Only add separator if both flag and level are not NONE
    44+        if (category.has_value() && level != Level::None) {
    45             s += ":";
    46         }
    47 
    48diff --git a/src/logging.h b/src/logging.h
    49index c84d276cb61..325cbe8af66 100644
    50--- a/src/logging.h
    51+++ b/src/logging.h
    52@@ -16,6 +16,7 @@
    53 #include <functional>
    54 #include <list>
    55 #include <mutex>
    56+#include <optional>
    57 #include <string>
    58 #include <unordered_map>
    59 #include <vector>
    60@@ -36,7 +37,6 @@ struct LogCategory {
    61 
    62 namespace BCLog {
    63     enum LogFlags : uint32_t {
    64-        NONE        = 0,
    65         NET         = (1 <<  0),
    66         TOR         = (1 <<  1),
    67         MEMPOOL     = (1 <<  2),
    68@@ -125,7 +125,7 @@ namespace BCLog {
    69         std::atomic<bool> m_reopen_file{false};
    70 
    71         /** Send a string to the log output */
    72-        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);
    73+        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);
    74 
    75         /** Returns whether logs will be written to any output */
    76         bool Enabled() const
    77diff --git a/src/qt/transactiondesc.cpp b/src/qt/transactiondesc.cpp
    78index dae6a2dea97..ebf2346cfb8 100644
    79--- a/src/qt/transactiondesc.cpp
    80+++ b/src/qt/transactiondesc.cpp
    81@@ -340,8 +340,7 @@ QString TransactionDesc::toHTML(interfaces::Node& node, interfaces::Wallet& wall
    82     //
    83     // Debug view
    84     //
    85-    if (node.getLogCategories() != BCLog::NONE)
    86-    {
    87+    if (node.getLogCategories() != 0) {
    88         strHTML += "<hr><br>" + tr("Debug information") + "<br><br>";
    89         for (const CTxIn& txin : wtx.tx->vin)
    
  80. 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 0: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.
  81. ajtowns commented at 4:23 pm on August 31, 2023: contributor
    ACK 05143b2b94cc1d62f27fc73212aa59f9d471f2b8
  82. 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
  83. 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
  84. Update -debug and -debugexclude help documentation
    Can be tested with:
    
    ./src/bitcoind -h | grep -A12 "\-debug=<\|debugexclude"
    d6b55ca5c1
  85. Functional test coverage for RPC logging include/exclude with all/none 9987531a48
  86. Functional test coverage for -debug/-debugexclude config options
    and convert some comments to logging.
    8330c38df6
  87. 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
  88. 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
  89. jonatack force-pushed on Sep 1, 2023
  90. jonatack commented at 0:42 am on September 1, 2023: contributor

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

    0diff --git a/src/logging.h b/src/logging.h
    1index 4dfb7106327..83c285c905d 100644
    2--- a/src/logging.h
    3+++ b/src/logging.h
    4@@ -180,7 +180,7 @@ namespace BCLog {
    5 
    6         bool WillLogCategory(LogFlags category) const;
    7         bool WillLogCategoryLevel(LogFlags category, Level level) const;
    8-        [[nodiscard]] bool IsNoneCategory(const std::string& s) const { return s == "0" || s == "none"; }
    9+        [[nodiscard]] static bool IsNoneCategory(const std::string& s) { return s == "0" || s == "none"; }
    
  91. ajtowns commented at 5:14 pm on September 5, 2023: contributor
    reACK 94b059ffe403a948957152b96f24fba4d9ee31f0
  92. pinheadmz approved
  93. 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

     0-----BEGIN PGP SIGNED MESSAGE-----
     1Hash: SHA256
     2
     3ACK 94b059ffe403a948957152b96f24fba4d9ee31f0
     4-----BEGIN PGP SIGNATURE-----
     5
     6iQIzBAEBCAAdFiEE5hdzzW4BBA4vG9eM5+KYS2KJyToFAmT4nZIACgkQ5+KYS2KJ
     7yTpNDQ//Qlf3FswTPrPl8KG9iZAZvzA0CVvIeBRdFZWgtDJ1cGnIllxEsnVfE7R9
     8J6EXUEdZ+XCvzfVxLaLR9W23dWtRttNjC+cx/i7GexIYlAQfI4FGECuMitXXEYsR
     9pYujKEQ/6SETiI8TBJC3OqiWhBodDzzfzdevhiKKbX2dKY9c22OqTSP9TI6XJQfw
    10R8iqZuj4Tps4jUrNYoWQmo8C71KReVnCdDi3jeKKKXeGFfkb/hJNDqRRqtyLvqd2
    11Ih/N67BbjtHjtJ2U16x2qFN5xyyBer/nXRirM9GKTKrt6ZpDhY6k2k3h5pVOfKGg
    12JCUyKLh7N1sWplUbHVQQ+1SHSM9deuwHu/Ld9iuRcBydz4EM9J4oxskVE68CZclT
    13zynxdsAxoWvxuADMsKj94WY2zsJTr/mnJaq+d6prXTYTkdpxCi9BSno5GxJrIfRX
    14H7gwqAVxsx8npJbsUmkawB8NBI9xeeYiam1jhipFsWLyovPEAw5APao3/kuVNu58
    15sMz9ui0dUohtfbPsZoUbimSNofSc5anELjAxT3ekQFImCxHaZSf6/LQ+muNG/qRg
    16aGrK4fNXsRQX39BIv4E0fYTMm8Ud+r6LuRDTs+z1OEOt+VKVcGs4amQ4jMdtZios
    17nPeS3TZzKwWVYsjQCZ2LQyICDPkAIFxIRHLWtubrh/WYPM+Leik=
    18=jmH2
    19-----END PGP SIGNATURE-----
    

    pinheadmz’s public key is on keybase

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

  95. jonatack commented at 7:37 pm on September 12, 2023: contributor

    Has this comment being replied to anywhere already?

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

  96. 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)

  97. jonatack commented at 3:40 pm on September 13, 2023: contributor
    I think that question is addressed in the pull description.
  98. 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.

  99. jonatack commented at 11:08 pm on September 13, 2023: contributor

    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:

     0During the same time period, passing `1` and `all` has been operational and documented. 
     1
     2Solution: detect `none`/`0` values and add test coverage in any case, and either:
     3    
     4- leave the functionality out, raise with an error message if the values are passed, and update the RPC
     5  help documentation, or
     6
     7- fix the behavior by returning early.
     8
     9Both solutions involve essentially the same code size and complexity.  Given that `all`/`1` has been
    10operational, and that `none`/`0` has been documented and appears per the code of the original PR
    11to have been operational, it seems preferable for consistency to support `none`/`0` in symmetry with
    12`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!

  100. ajtowns commented at 1:47 am on September 14, 2023: contributor
    0Both solutions involve essentially the same code size and complexity.  Given that `all`/`1` has been
    1operational, and that `none`/`0` has been documented and appears per the code of the original PR
    2to have been operational, it seems preferable for consistency to support `none`/`0` in symmetry with
    3`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
  101. jonatack commented at 7:26 pm on January 8, 2024: contributor
    I’m going to open an alternate pull that does what you suggest and see what reviewers (if any) prefer.
  102. DrahtBot added the label Needs rebase on Jan 10, 2024
  103. DrahtBot commented at 9:13 pm on January 10, 2024: contributor

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

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

  105. fanquake marked this as a draft on Mar 6, 2024
  106. fanquake closed this on Mar 18, 2024

  107. jonatack commented at 4:29 pm on April 8, 2024: contributor
    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.

github-metadata-mirror

This is a metadata mirror of the GitHub repository bitcoin/bitcoin. This site is not affiliated with GitHub. Content is generated from a GitHub metadata backup.
generated: 2024-07-03 10:13 UTC

This site is hosted by @0xB10C
More mirrored repositories can be found on mirror.b10c.me