[rpc] Add logging rpc

jnewbery commented at 6:16 pm on April 4, 2017: member

Adds an RPC to get/set active logging categories.

First commit allows all categories except libevent to be reconfigured during runtime. Second commit modifies InitHTTPServer() to allow leveldb logging to be reconfigured during runtime.

jnewbery renamed this:
~~[rpc Add logging rpc~~
[rpc] Add logging rpc
on Apr 4, 2017

jnewbery force-pushed on Apr 4, 2017

fanquake added the label RPC/REST/ZMQ on Apr 4, 2017

in src/httpserver.cpp:388 in 0365458af7 outdated

390-    if (LogAcceptCategory(BCLog::LIBEVENT)) {
391-        event_enable_debug_logging(EVENT_DBG_ALL);
392-    } else {
393-        event_enable_debug_logging(EVENT_DBG_NONE);
394-    }
395+    event_enable_debug_logging(EVENT_DBG_ALL);

laanwj commented at 5:52 am on April 5, 2017:

Don’t do this! This existed for a reason. What you did will reduce libevent performance extremely by always enabling their internal debugging. Same is probably true for leveldb. I’d prefer just not to allow to switch those at runtime. (unless it can be done in a thread-safe way later on, but I don’t think so)

jnewbery commented at 2:05 pm on April 5, 2017:

Are you sure? I’ve tested this and logging is only enabled when libevent is built in debug mode:

https://github.com/libevent/libevent/blob/2e52bace9f9998826bd3819af328efc8d18decf9/log-internal.h#L46

and

https://github.com/libevent/libevent/blob/2e52bace9f9998826bd3819af328efc8d18decf9/log-internal.h#L86

I would have thought that if we’re running libevent in debug, then performance is already hosed.

If I’m wrong, I left this as a separate commit so we can leave it out if needed. The first commit forbids trying to change libevent logging during runtime and stands on its own.

leveldb: #9999 always hands a logging class to leveldb at startup, even if logging is disabled. I don’t know if that affects performance. This PR doesn’t change that behaviour.

laanwj commented at 9:48 am on April 6, 2017:

Yes, it is possible to compile libevent wholesale without debug messages. However, most distributions enable them. Even if it is compiled with debug messages, normally they just sink at the libevent side before even being formatted: https://github.com/libevent/libevent/blob/master/log-internal.h#L80 Remember that libevent debugging is extremely noisy. It always is - the mask is currently unused - there are no specific flags. There will be significant overhead to dropping the messages at our side, after formatting. That’s worth it for the questionable advantage of being able to enable it during runtime.

jnewbery commented at 8:09 pm on April 6, 2017:

Turns out libevent logging can be changed at runtime: https://github.com/libevent/libevent/blob/2e52bace9f9998826bd3819af328efc8d18decf9/whatsnew-2.1.txt#L269

I’ve pushed a new commit that leaves InitHTTPServer() unchanged and uses event_enable_debug_logging() to update logging.

laanwj commented at 6:49 am on April 5, 2017: member

Concept ACK ofcourse

jonasschnelli commented at 6:53 am on April 5, 2017: contributor

Oh. That’s great. Concept ACK. Will test soon.

jnewbery force-pushed on Apr 6, 2017

jnewbery commented at 8:10 pm on April 6, 2017: member

Pushed a new commit that I hope addresses @laanwj’s point here: #10150 (review)

in src/rpc/misc.cpp:594 in ea4ae762bb outdated

574+            + HelpExampleCli("logging", "\"[\\\"all\\\"]\" \"[\\\"http\\\"]\"")
575+            + HelpExampleRpc("logging", "[\"all\"], \"[libevent]\"")
576+        );
577+    }
578+
579+    if (request.params.size() > 0 && request.params[0].isArray()) {

laanwj commented at 8:52 pm on April 6, 2017:

It looks like this code is almost duplicated with the exclude case (except the |/& and true/false). Might make sense to roll this into a function that converts a list of flag strings into a bitmask and apply that wholesale.

jnewbery commented at 7:40 pm on April 7, 2017:

sounds sensible. Done

laanwj commented at 12:25 pm on April 10, 2017:

Yup, thanks, much better

jnewbery force-pushed on Apr 7, 2017

in src/rpc/misc.cpp:609 in bc3ad60b41 outdated

604+    UniValue result(UniValue::VOBJ);
605+    std::vector<CLogCategoryActive> vLogCatActive = ListActiveLogCategories();
606+    for (const auto& logCatActive : vLogCatActive) {
607+        result.pushKV(logCatActive.category, logCatActive.active);
608+    }
609+    result.pushKV("WARNING", "libevent logging cannot be updated when using libevent before v2.1.1.");

laanwj commented at 12:24 pm on April 10, 2017:

If you add this warning I’d suggest it be context-sensitive:

libevent logging is being updated
the libevent version is older than 2.1.1

Though you could also make it an error in that case! (e.g. make UpdateHTTPServerLogging return false and then raise a JSON exception here)

jnewbery commented at 1:06 pm on April 10, 2017:

I initially tried doing something like that, but it’s a bit tricky:

we only want to raise an error if only libevent logging is changed (ie if the user wants to include or exclude “all”, then we shouldn’t throw an error simply because “all” includes libevent).
I’ve already applied the include/excude bitmasks by this point, and we need the before/after state to know whether to throw.

I’ll see if I can come up with something sensible.

laanwj commented at 1:15 pm on April 10, 2017:

I’m perfectly fine with removing this warning from this pull and doing that later. I just don’t think it should be added unconditionally.

I’ve already applied the include/excude bitmasks by this point, and we need the before/after state to know whether to throw.

Sure. if((before ^ after) & BCLog::LIBEVENT) would work :-) Though it’s probably best to do the check inside UpdateHTTPServerLogging because there you have the previous state, the desired new state, and the libevent version information available.

we only want to raise an error if only libevent logging is changed

That’s a good point, and indeed speaks for making it a warning instead.

jnewbery force-pushed on Apr 10, 2017

jnewbery commented at 2:55 pm on April 10, 2017: member

Pushed an updated version that hopefully addresses @laanwj’s comments. Changes:

UpdateHTTPServerLogging() is now called by InitHTTPServer(). This contains the #if LIBEVENT_VERSION_NUMBER >= 0x02010100 preprocessor logic to one place.
UpdateHTTPServerLogging() now removes the BCLog::LIBEVENT bit flag if the libevent version does not support debug logging. That means that a call to the logging RPC will return the correct value for libevent (0 if libevent logging is not supported).
the logging RPC will throw an error if:
- the libevent version does not support debug logging; and
- the user tries to update only the BCLog::LIBEVENT flag

Set BCLog::LIBEVENT correctly for old libevent versions. 4d9950d3bc

[rpc] Add logging RPC

Adds an RPC to get and set currently active logging categories.

5255aca3f4

allow libevent logging to be updated during runtime 7fd50c3b70

in src/httpserver.cpp:443 in df35edb2ee outdated

438+        event_enable_debug_logging(EVENT_DBG_NONE);
439+    }
440+    return true;
441+#else
442+    // Can't update libevent logging if version < 02010100
443+    logCategories &= ~BCLog::LIBEVENT;

laanwj commented at 3:05 pm on April 10, 2017:

Looks good to me. One nit: I don’t think this global flag should be changed here as a side-effect. Maybe move the “disable the flag in logCategories if this function returns false” logic outside the function.

jnewbery commented at 9:07 pm on April 10, 2017:

ok, changed so that the caller updates the logCategories bitfield (happens in two places - InitHTTPServer() and the logging() rpc).

jnewbery force-pushed on Apr 10, 2017

laanwj commented at 5:57 pm on April 12, 2017: member

Tested ACK 7fd50c3

laanwj merged this on Apr 12, 2017

laanwj closed this on Apr 12, 2017

laanwj referenced this in commit 350b22497c on Apr 12, 2017

jnewbery deleted the branch on Apr 12, 2017

PastaPastaPasta referenced this in commit f8947817f5 on Jun 10, 2019

PastaPastaPasta referenced this in commit dbbb41e041 on Jun 10, 2019

PastaPastaPasta referenced this in commit d1c805c396 on Jun 10, 2019

PastaPastaPasta referenced this in commit 698e7bfbfe on Jun 11, 2019

PastaPastaPasta referenced this in commit 6a42f7341a on Jun 15, 2019

PastaPastaPasta referenced this in commit 41111b0a7f on Jun 19, 2019

PastaPastaPasta referenced this in commit ceb9b19f70 on Jun 19, 2019

PastaPastaPasta referenced this in commit 97b433a98e on Jun 19, 2019

PastaPastaPasta referenced this in commit ac06dc6f18 on Jun 19, 2019

PastaPastaPasta referenced this in commit b3f9d49fa5 on Jun 19, 2019

PastaPastaPasta referenced this in commit 70a164fd8a on Jun 19, 2019

PastaPastaPasta referenced this in commit a01db8728e on Jun 19, 2019

PastaPastaPasta referenced this in commit 4a26043d04 on Jun 20, 2019

jasonbcox referenced this in commit a1f767f4b1 on Oct 25, 2019

barrystyle referenced this in commit 57edac99bd on Jan 22, 2020

random-zebra referenced this in commit 1fa5156a97 on Apr 6, 2020

jonspock referenced this in commit d1d90548d8 on Oct 1, 2020

jonspock referenced this in commit 54b62ff4b4 on Oct 5, 2020

jonspock referenced this in commit 219a16e9e6 on Oct 10, 2020

rebroad commented at 11:58 pm on April 28, 2021: contributor

The help message could IMHO make it clearer how to enable and disable logging. I’ve tried “logging exclude estimatefee”, “logging estimatefee false”, “logging estimatefee exclude”, and they all give a “Error parsing JSON” error.

Is it possible to toggle logging from the console?

DrahtBot locked this on Aug 18, 2022

[rpc] Add logging rpc #10150