Change LogAcceptCategory to use uint32_t rather than sets of strings. #9424

gmaxwell · 2016-12-25T20:33:10Z

This changes the logging categories to boolean flags instead of strings.

This simplifies the acceptance testing by avoiding accessing a scoped
static thread local pointer to a thread local set of strings. It
eliminates the only use of boost::thread_specific_ptr outside of
lockorder debugging.

This change allows log entries to be directed to multiple categories
and makes it easy to change the logging flags at runtime (e.g. via
an RPC, though that isn't done by this commit.)

It also eliminates the fDebug global.

Configuration of unknown logging categories now produces a warning.

gmaxwell · 2016-12-25T20:37:13Z

If we ever need more than 32 categories (there are 19 now) this could be trivially changed to use a uint64_t.

gmaxwell · 2016-12-25T20:45:12Z

src/net_processing.cpp

-        if ((fDebug && vInv.size() > 0) || (vInv.size() == 1))
-            LogPrint("net", "received getdata for: %s peer=%d\n", vInv[0].ToString(), pfrom->id);
+        if (vInv.size() > 0)
+            LogPrint(LOG_NET, "received getdata for: %s peer=%d\n", vInv[0].ToString(), pfrom->id);



The prior code above struck me as somewhat brain-damaged (LogPrint() does nothing when fDebug isn't true), so this chunk could use some more review attention in case I was missing something.

rebroad · 2016-12-26T12:28:44Z

src/util.h

@@ -69,15 +70,50 @@ inline std::string _(const char* psz)
 void SetupEnvironment();
 bool SetupNetworking();

+enum LogFlags : uint32_t {


idea: Would be easier to maintain if it was possible to define LogFlags and CLogCategoryDesc in the same section...

gmaxwell · 2016-12-29T18:00:54Z

One week, no substantive feedback. Closing.

TheBlueMatt · 2016-12-29T18:03:12Z

Concept ACK

paveljanik · 2016-12-30T10:48:37Z

Please reopen. Holidays...

Concept ACK

rebroad · 2016-12-30T13:18:29Z

concept ACK

maflcko · 2016-12-30T14:17:52Z

utACK e348647315b619e6a1d8b614554abb0747047696

paveljanik · 2016-12-30T19:50:16Z

Needs rebase.

paveljanik · 2017-01-08T18:27:14Z

@gmaxwell Please reopen this...

jonasschnelli · 2017-03-30T19:33:19Z

Concept ACK, seems to be a great PR with serval acks. Needs rebase and reopen.

jtimon · 2017-03-30T19:40:46Z

Concept ACK

jnewbery · 2017-03-30T19:43:30Z

Definite concept ACK. Makes #10123 trivial.

laanwj · 2017-03-30T20:19:00Z

Concept ACK.

laanwj · 2017-03-30T20:20:28Z

src/util.h

@@ -69,15 +70,50 @@ inline std::string _(const char* psz)
 void SetupEnvironment();
 bool SetupNetworking();

+enum LogFlags : uint32_t {
+    LOG_NONE        = 0,
+    LOG_NET         = (1 <<  0),


Instead of the LOG_ prefix, I'd propose to use a scoped enum. E.g. LogFlags::NONE LogFlags::NET etc.
(defined using enum class LogFlags)

Oh darn, didn't see this until I'd already done the rebase. Uh, I'll look into it and put it as a commit on top for squashing. (presumably it'll be a more or less trivial change that could be reviewed separately)

19:32 < gmaxwell> wumpus: uh. so boolean operations don't appear to exist for scoped enums. so ... I don't think I can use them without
defining a set of boolean operations for them.
19:32 < sipa> gmaxwell: eh?
19:33 < sipa> ah, scoped enums don't have an implicit conversion to int
19:34 < sipa> you can still explicitly convert them, though
19:34 < sipa> but enums are generally a bad approach for bitfields, as they're intended to be exhaustive
19:34 < gmaxwell> sipa: wumpus suggested that I change the log print thing to use a scoped enum. The original thing that inspired this
change is that rebroad wanted to do some horrible hack to do the logical equivilent of LogPrint(LOG_NET | LOG_MEMPOOL,
...). (and of course the matching also uses it as a bitfield.)
19:35 < sipa> right, a normal enum (which behaves much more like an int) may be more appropriate
19:35 < gmaxwell> well thats what I implemented.
19:37 < sipa> awesöme
19:37 < gmaxwell> in any case. I'm happy to change it to whatever. someone who has an opinion needs to tell me what to do. I think I only
need a couple casts to make the enum class stuff go, but it would be ugly to do "LogPrint(LOG_NET | LOG_MEMPOOL," later
unless we provide | for the type.

It's just that the LOG_ prefix is very common, so it's easy to get namespace collisions. Scoped enums avoid that, the only way any of their members can collide is when the name of the type conflicts, which would be an error in the first place.
Then again if this introduces extra C++ casting uglyness in all usages let's leave it like this...

I could make it BCLOG or something like that, you're right about namespace collisions, my initial sed through to rename the LOG_ accidentally renamed some things it shouldn't.

Another approach would be wrapping it in a C++ namespace (for example:

namespace bclog { enum flags { NET, MEMPOOL, ... }; }

at which point you can use bclog::NET | bclog::MEMPOOL.

JeremyRubin

Concept ACK!

I think it would be nice if there were a semi-convenient way to add new categories without triggering a big recompile though...

JeremyRubin · 2017-03-30T20:27:30Z

src/util.h


 template<typename... Args>
-static inline int LogPrint(const char* category, const char* fmt, const Args&... args)
+static inline int LogPrint(uint32_t category, const char* fmt, const Args&... args)


type should maybe be LogFlags for future upgrades.

Yes, that would add some type safety. It would make it more of a hassle to submit a message to more categories at once but that isn't supported now either.

JeremyRubin · 2017-03-30T20:31:59Z

src/util.h

@@ -56,6 +55,8 @@ extern CTranslationInterface translationInterface;
 extern const char * const BITCOIN_CONF_FILENAME;
 extern const char * const BITCOIN_PID_FILENAME;

+extern std::atomic<uint32_t> logCategories;


isn't this set on init single threadedly? Maybe you can drop the atomics.

I expect the very next logical change will be to add an RPC to turn on and off logging categories. Since all the reads are order relaxed I expect it to emit the same code as a non-atomic read (at least on x86).

I've wanted this for so long! Consider this the next/2 logical change.

Yes being able to change the debug flags at runtime (even if not the libevent and leveldb ones which are processed at startup) would be nice.

JeremyRubin · 2017-03-31T17:00:34Z

Suggestion on how to make the category more extensible without triggering big recompiles:

#define LogPrint(cat, ...) _LogPrint(cat, #cat, __VA_ARGS__)
static inline int _LogPrint(uint32_t category, const char* category_str, const char* fmt, const Args&... args) {
    // ...
    if (category == LOG_USE_IDENT_NAME)
        // use the macro
    // ...
}

then from somefile.cpp

static const uint32_t LOG_SOMEFILE = LOG_USE_IDENT_NAME;
LogPrint(LOG_SOMEFILE, "...");

jnewbery

It looks to me like there are a couple of rebase errors here. Other than that a few nits but looks good. I've tested ab53beaf9c0d8f923f24a50b373968a8c01760d4 manually and against the extended test suite and it works.

One thing to note about the future logging RPC work: I think libevent and leveldb logging levels are set at start up, so they won't be modifiable through the RPC without some additional work. Not a problem for this PR, but something to note since it'd be easy to believe that just updating logCategories would be enough. Perhaps worth putting a comment next to the logCategories variable warning about this?

jnewbery · 2017-03-31T18:50:03Z

src/util.h

+/** Returns a string with the supported log categories */
+std::string ListLogCategories();
+
+/** Return true of str parses as a log category and set the flags in f */


jnewbery · 2017-03-31T18:56:46Z

src/util.h

+std::string ListLogCategories();
+
+/** Return true of str parses as a log category and set the flags in f */
+bool ParseLogCategory(uint32_t *f, const std::string *str);


I prefer a name like SetLogCategory. Parse suggests no side-effects to me.

jnewbery · 2017-03-31T19:03:35Z

src/util.cpp

+    {LOG_COINDB, "coindb"},
+    {LOG_QT, "qt"},
+    {LOG_LEVELDB, "leveldb"},
+    {LOG_ALL, "1"},


Can you add an "all" alias here, ie -debug=all is equivalent to -debug=1

jnewbery · 2017-03-31T19:07:35Z

src/init.cpp

@@ -908,12 +905,23 @@ bool AppInitParameterInteraction()

    // ********************************************************* Step 3: parameter-to-internal-flags

-    fDebug = mapMultiArgs.count("-debug");
+    bool fDebug = mapMultiArgs.count("-debug") > 0;


Now that you've removed the global fDebug bool, you can go ahead and remove it entirely and test the conditions directly (rather than make the variable local), ie:

if (mapMultiArgs.count("-debug") > 0) {

and further below:

if !(GetBoolArg("-nodebug", false) || find(categories.begin(), categories.end(), std::string("0")) != categories.end()) {

Great point.

jnewbery · 2017-03-31T19:15:17Z

src/util.h

-        LogPrintf(__VA_ARGS__); \
-    } \
-} while(0)
+#define LogPrintf(...) LogPrintStr(tfm::format(__VA_ARGS__))


Why have you removed the try/except handling in this macro? (I'm not saying it's wrong, I just don't understand why it was necessary before but not now).

EDIT: I think this is a bad rebase that's reverted #9963

Yep. Fixing.

jnewbery · 2017-03-31T19:17:51Z

src/tinyformat.h

@@ -167,7 +167,7 @@ namespace tinyformat {
 class format_error: public std::runtime_error
 {
 public:
-    format_error(const std::string &what): std::runtime_error(what) {
+    format_error(const std::string &fmtwhat): std::runtime_error(fmtwhat) {


bad rebase?

No. silencing an obnoxious shadowing warning that was making it impossible to see where other issues were.

My only concern is that we occasionally pull updates to tinyformat.cpp from upstream (eg #8274), so any trivial changes like this add to the maintainer's burden when merging. Not sure if @laanwj has an opinion.

Can we just disable the shadowing warnings please, instead of peppering unrelated variable renames in commits?

There you go: #10136

gmaxwell · 2017-04-01T07:13:10Z

I think I addressed all the comments.

laanwj · 2017-04-01T12:47:24Z

Suggestion on how to make the category more extensible without triggering big recompiles:

IMO we shouldn't worry about recompiles when the set of categories changes. That's a rare occurrence, and the way headers depend on each other almost every header change already results in a (near) full recompile.

laanwj · 2017-04-01T13:24:35Z

utACK 21d94e7 apart from the parameter name change in tinyformat.h

This changes the logging categories to boolean flags instead of strings. This simplifies the acceptance testing by avoiding accessing a scoped static thread local pointer to a thread local set of strings. It eliminates the only use of boost::thread_specific_ptr outside of lockorder debugging. This change allows log entries to be directed to multiple categories and makes it easy to change the logging flags at runtime (e.g. via an RPC, though that isn't done by this commit.) It also eliminates the fDebug global. Configuration of unknown logging categories now produces a warning.

gmaxwell · 2017-04-01T19:00:08Z

(Trivally) rebased, squashed, and removed the tinyformat change.

laanwj · 2017-04-02T06:32:52Z

Going to merge this; a change like this will need rebase after every single thing that gets merged, and @gmaxwell addressed all the nits. Further improvements can be done in later PRs.

…s of strings. 6b3bb3d Change LogAcceptCategory to use uint32_t rather than sets of strings. (Gregory Maxwell) Tree-SHA512: ebb5bcf9a7d00a32dd1390b727ff4d29330a038423611da01268d8e1d2c0229e52a1098e751d4e6db73ef4ae862e1e96d38249883fcaf12b68f55ebb01035b34

Merge bitcoin#9424: Change LogAcceptCategory to use uint32_t rather than sets of strings. 6b3bb3d Change LogAcceptCategory to use uint32_t rather than sets of strings. (Gregory Maxwell) Tree-SHA512: ebb5bcf9a7d00a32dd1390b727ff4d29330a038423611da01268d8e1d2c0229e52a1098e751d4e6db73ef4ae862e1e96d38249883fcaf12b68f55ebb01035b34 Signed-off-by: Pasta <Pasta@dash.org> # Conflicts: # src/httpserver.cpp # src/init.cpp # src/net.cpp # src/net_processing.cpp # src/policy/fees.cpp # src/txdb.cpp # src/util.cpp # src/util.h # src/validation.cpp # src/wallet/rpcwallet.cpp # src/wallet/wallet.cpp # src/zmq/zmqpublishnotifier.cpp

Merge bitcoin#9424: Change LogAcceptCategory to use uint32_t rather than sets of strings. 6b3bb3d Change LogAcceptCategory to use uint32_t rather than sets of strings. (Gregory Maxwell) Tree-SHA512: ebb5bcf9a7d00a32dd1390b727ff4d29330a038423611da01268d8e1d2c0229e52a1098e751d4e6db73ef4ae862e1e96d38249883fcaf12b68f55ebb01035b34 Signed-off-by: Pasta <Pasta@dash.org> 31 -> 32 Signed-off-by: Pasta <Pasta@dash.org>

* Contains dashification. disables `-debug dash` Merge bitcoin#9424: Change LogAcceptCategory to use uint32_t rather than sets of strings. 6b3bb3d Change LogAcceptCategory to use uint32_t rather than sets of strings. (Gregory Maxwell) Tree-SHA512: ebb5bcf9a7d00a32dd1390b727ff4d29330a038423611da01268d8e1d2c0229e52a1098e751d4e6db73ef4ae862e1e96d38249883fcaf12b68f55ebb01035b34 Signed-off-by: Pasta <Pasta@dash.org> 31 -> 32 Signed-off-by: Pasta <Pasta@dash.org> * Merge bitcoin#10123: Allow debug logs to be excluded from specified component 3bde556 Add -debugexclude option to switch off logging for specified components (John Newbery) Tree-SHA512: 30202e3f2085fc2fc5dd4bedb92988f4cb162c612a42cf8f6395a7da326f34975ddc347f82bc4ddca6c84c438dc0cc6e87869f90c7ff88105dbeaa52a947fa43 * bump to uint64_t due to added Dash codes Signed-off-by: Pasta <Pasta@dash.org> * bump to uint64_t due to added Dash codes cont. Signed-off-by: Pasta <Pasta@dash.org> * string -> BCLog format Signed-off-by: Pasta <Pasta@dash.org> * uint32_t -> uint64_t Signed-off-by: Pasta <Pasta@dash.org> * Fix CBatchedLogger * Fix most fDebug-s * Fix `debug` rpc * Fix BENCH and RAND conflicts * Add ALERT and use it * Update LogPrint-s in dash-specific code * Tweak few log categories Specifically: - use PRIVATESEND in `CPrivateSendClientManager::GetRandomNotUsedMasternode()` - use ZMQ in `CZMQPublishRawGovernanceVoteNotifier::NotifyGovernanceVote()` and `CZMQPublishRawGovernanceObjectNotifier::NotifyGovernanceObject()` * Drop no longer used MASTERNODE category * Merge bitcoin#10153: logging: Fix off-by-one for shrinkdebugfile default faab624 logging: Fix off-by-one for shrinkdebugfile (MarcoFalke) Tree-SHA512: d6153e06067906172ff0611af9e585a3ecf0a7d56925b6ad7c12e75aa802441047059b9b6f6c78e79916c3f2abc8f1998bfd2d5b84201ec6421f727c08da3c21 * Shift dash-specific log categories to start from `1ul << 32` to avoid potential future conflicts with bitcoin ones * Fix `dash` category * remove debugCategories Signed-off-by: Pasta <Pasta@dash.org> * Prepend "std::" to find call * Check for BCLog::PRIVATESEND instead of logCategories != BCLog::NONE * Use BCLog::MNPAYMENTS category instead of checking for logCategories != BCLog::NONE * Move "End Dash" comment below "ALERT" When adding new entries here, we'll otherwise get confused with ordering and might end up forgetting that adding something Dash specific must continue with the bit after 43.

…of strings c3dc816 [Core] LogAcceptCategory: use uint32_t rather than sets of strings (random-zebra) Pull request description: implemented on top of: - [x] #1449 from bitcoin#9424 > This changes the logging categories to boolean flags instead of strings. This simplifies the acceptance testing by avoiding accessing a scoped static thread local pointer to a thread local set of strings. It eliminates the only use of boost::thread_specific_ptr outside of lockorder debugging. This change allows log entries to be directed to multiple categories and makes it easy to change the logging flags at runtime (e.g. via an RPC, though that isn't done by this commit.) It also eliminates the fDebug global. Configuration of unknown logging categories now produces a warning. We add 4 more debug categories: - BCLog::STAKING - BCLog::MASTERNODE (which includes previous "masternode" and "mnpayments" categories) - BCLog::MNBUDGET - BCLog::LEGACYZC ACKs for top commit: Fuzzbawls: ACK c3dc816 Tree-SHA512: 0c2ffc30df5b4239396c6f2ef6c551bbca5696aa1087b5e12a206fc9b1def9ef6cd9c6f6c0cbbb8da0d667e782848a884514de21609714668d0b5ad87eca8e56

gmaxwell mentioned this pull request Dec 25, 2016

Do not evaluate hidden LogPrint arguments #9417

Merged

gmaxwell commented Dec 25, 2016

View reviewed changes

fanquake added Refactoring Utils/log/libs labels Dec 26, 2016

rebroad reviewed Dec 26, 2016

View reviewed changes

gmaxwell closed this Dec 29, 2016

gmaxwell reopened this Mar 30, 2017

laanwj reviewed Mar 30, 2017

View reviewed changes

JeremyRubin reviewed Mar 31, 2017

View reviewed changes

jnewbery reviewed Mar 31, 2017

View reviewed changes

This was referenced Mar 31, 2017

[test] Suppress test logging spam #10124

Merged

Allow debug logs to be excluded from specified component #10123

Merged

laanwj merged commit 6b3bb3d into bitcoin:master Apr 2, 2017

jonasschnelli mentioned this pull request Apr 2, 2017

Refactor Bumpfee, move core functionality to CWallet #9681

Merged

laanwj mentioned this pull request Apr 3, 2017

Lightweight abstraction of boost::filesystem #9902

Merged

dagurval mentioned this pull request Mar 7, 2018

Change LogAcceptCategory to use uint32_t rather than sets of strings. bitcoinxt/bitcoinxt#353

Merged

UdjinM6 mentioned this pull request May 8, 2019

Don't use boost::thread_specific_ptr in LogAcceptCategory dashpay/dash#2906

Closed

random-zebra mentioned this pull request Mar 20, 2020

[Util] LogAcceptCategory: use uint32_t rather than sets of strings PIVX-Project/PIVX#1437

Merged

1 task

bitcoin locked as resolved and limited conversation to collaborators Sep 8, 2021

Change LogAcceptCategory to use uint32_t rather than sets of strings. #9424

Change LogAcceptCategory to use uint32_t rather than sets of strings. #9424

Conversation

gmaxwell commented Dec 25, 2016

gmaxwell commented Dec 25, 2016

Choose a reason for hiding this comment

rebroad Dec 26, 2016 • edited

Choose a reason for hiding this comment

gmaxwell commented Dec 29, 2016

TheBlueMatt commented Dec 29, 2016

paveljanik commented Dec 30, 2016

rebroad commented Dec 30, 2016 • edited

maflcko commented Dec 30, 2016

paveljanik commented Dec 30, 2016

paveljanik commented Jan 8, 2017

jonasschnelli commented Mar 30, 2017

jtimon commented Mar 30, 2017

jnewbery commented Mar 30, 2017

laanwj commented Mar 30, 2017

laanwj Mar 30, 2017 • edited

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

JeremyRubin left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

JeremyRubin commented Mar 31, 2017

jnewbery left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

gmaxwell commented Apr 1, 2017

laanwj commented Apr 1, 2017 • edited

laanwj commented Apr 1, 2017 • edited

gmaxwell commented Apr 1, 2017

laanwj commented Apr 2, 2017

rebroad Dec 26, 2016 •

edited

rebroad commented Dec 30, 2016 •

edited

laanwj Mar 30, 2017 •

edited

laanwj commented Apr 1, 2017 •

edited

laanwj commented Apr 1, 2017 •

edited