[rpc] Add logging rpc #10150

jnewbery · 2017-04-04T18:16:49Z

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.

laanwj · 2017-04-05T05:52:41Z

src/httpserver.cpp

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)

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.

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.

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 · 2017-04-05T06:49:39Z

Concept ACK ofcourse

jonasschnelli · 2017-04-05T06:53:06Z

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

jnewbery · 2017-04-06T20:10:02Z

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

laanwj · 2017-04-06T20:52:27Z

src/rpc/misc.cpp

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.

sounds sensible. Done

Yup, thanks, much better

laanwj · 2017-04-10T12:24:52Z

src/rpc/misc.cpp

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)

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.

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 · 2017-04-10T14:55:25Z

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

laanwj · 2017-04-10T15:05:56Z

src/httpserver.cpp

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.

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

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

laanwj · 2017-04-12T17:57:17Z

Tested ACK 7fd50c3

7fd50c3 allow libevent logging to be updated during runtime (John Newbery) 5255aca [rpc] Add logging RPC (John Newbery) 4d9950d Set BCLog::LIBEVENT correctly for old libevent versions. (John Newbery) Tree-SHA512: d6788a7205372c0528da71eca052910dfb055f2940ca884f422ff3db66e23a2b49c6a15b8f27d5255554fe5c5a928f5dd903fdc63b0bd6c8fa7783e77bb30fe8

Summary: PR10150: 7fd50c3 allow libevent logging to be updated during runtime (John Newbery) 5255aca [rpc] Add logging RPC (John Newbery) 4d9950d Set BCLog::LIBEVENT correctly for old libevent versions. (John Newbery) Tree-SHA512: d6788a7205372c0528da71eca052910dfb055f2940ca884f422ff3db66e23a2b49c6a15b8f27d5255554fe5c5a928f5dd903fdc63b0bd6c8fa7783e77bb30fe8 Our logging code was refactored some time ago in a way that looks a lot like Core PR12954. Functionally, however, we are still behind in comparison to Core when their refactor occurred. That has made this backport very complicated. I have made comments on each change that directly link to the PR it was backported from to assist in review. As mentioned in the summary, some changes had to be modified to bridge the gap between the state of Core's logging code before and after the refactor in PR12954. Backport of Core PR10150: bitcoin/bitcoin#10150 As is, Core's logging code as seen in PR10150 is incompatible with our own logging code. I Also pulled the `EnableOrDisableLogCategories()` function and the updated libevent filter code and `Logger::GetCategoryMask()` function from Core PR12954 which is a refactor of Core's logging code that makes it more closely mirror our own. bitcoin/bitcoin#12954 Test Plan: make check ./bitcoind ./bitcoin-cli help `logging` rpc should not show up in the list of commands. ./bitcoin-cli help logging This should display `logging` rpc help ./bitcoin-cli logging This should display the list of logging options all set to false (default). ./bitcoin-cli logging "[\"all"\"] ./bitcoin-cli getbestblockhash check debug.log The first line should output the list of logging options all set to true if your libevent version is at or above v2.1.1. Otherwise, every option except libevent will be set to true. The second line should cause the logger to write some extra debug information to the `debug.log` file. ./bitcoin-cli logging "[]" "[\"all\"]" ./bitcoin-cli getbestblockhash check debug.log The first line should output the list of logging options all set to false again. The second line should cause the logger to revert back to its original logging behavior, outputting no extra logging information to `debug.log`. ./bitcoin-cli logging "[\"libevent"\"] If your version of libevent is below v2.1.1, you should receive an error stating `libevent logging cannot be updated when using libevent before v2.1.1.` If your libevent is version is at or above 2.1.1, then it should proceed as normal. Tested by changing line 431 in httpserver.cpp from `#if LIBEVENT_VERSION_NUMBER >= 0x02010100` to `#if LIBEVENT_VERSION_NUMBER < 0x02010100`. Reviewers: deadalnix, Fabien, jasonbcox, markblundeberg, O1 Bitcoin ABC, #bitcoin_abc Reviewed By: deadalnix, Fabien, jasonbcox, O1 Bitcoin ABC, #bitcoin_abc Differential Revision: https://reviews.bitcoinabc.org/D3464

f66e50e [Doc] Add logging RPC to release notes (random-zebra) bf55911 allow libevent logging to be updated during runtime (random-zebra) ec43b51 Set BCLog::LIBEVENT correctly for old libevent versions. (random-zebra) cbaf724 [rpc] Add logging rpc (random-zebra) Pull request description: Implemented on top of: - [x] #1449 - [x] #1437 - [x] #1439 - [x] #1450 Backports bitcoin#10150 > 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. ACKs for top commit: furszy: Really nice 👍 , ACK f66e50e . Fuzzbawls: ACK f66e50e Tree-SHA512: 7b735628d341fb8661eb76f57dadc78e69ea63c62edb778450b3d9e3b7137ce06e08ceab835967b923401a9687e5b2605722a9f256e6ed85fc372a0e46086b8f

Summary: PR10150: 7fd50c3 allow libevent logging to be updated during runtime (John Newbery) 5255aca [rpc] Add logging RPC (John Newbery) 4d9950d Set BCLog::LIBEVENT correctly for old libevent versions. (John Newbery) Tree-SHA512: d6788a7205372c0528da71eca052910dfb055f2940ca884f422ff3db66e23a2b49c6a15b8f27d5255554fe5c5a928f5dd903fdc63b0bd6c8fa7783e77bb30fe8 Our logging code was refactored some time ago in a way that looks a lot like Core PR12954. Functionally, however, we are still behind in comparison to Core when their refactor occurred. That has made this backport very complicated. I have made comments on each change that directly link to the PR it was backported from to assist in review. As mentioned in the summary, some changes had to be modified to bridge the gap between the state of Core's logging code before and after the refactor in PR12954. Backport of Core PR10150: bitcoin/bitcoin#10150 As is, Core's logging code as seen in PR10150 is incompatible with our own logging code. I Also pulled the `EnableOrDisableLogCategories()` function and the updated libevent filter code and `Logger::GetCategoryMask()` function from Core PR12954 which is a refactor of Core's logging code that makes it more closely mirror our own. bitcoin/bitcoin#12954 Test Plan: make check ./bitcoind ./bitcoin-cli help `logging` rpc should not show up in the list of commands. ./bitcoin-cli help logging This should display `logging` rpc help ./bitcoin-cli logging This should display the list of logging options all set to false (default). ./bitcoin-cli logging "[\"all"\"] ./bitcoin-cli getbestblockhash check debug.log The first line should output the list of logging options all set to true if your libevent version is at or above v2.1.1. Otherwise, every option except libevent will be set to true. The second line should cause the logger to write some extra debug information to the `debug.log` file. ./bitcoin-cli logging "[]" "[\"all\"]" ./bitcoin-cli getbestblockhash check debug.log The first line should output the list of logging options all set to false again. The second line should cause the logger to revert back to its original logging behavior, outputting no extra logging information to `debug.log`. ./bitcoin-cli logging "[\"libevent"\"] If your version of libevent is below v2.1.1, you should receive an error stating `libevent logging cannot be updated when using libevent before v2.1.1.` If your libevent is version is at or above 2.1.1, then it should proceed as normal. Tested by changing line 431 in httpserver.cpp from `#if LIBEVENT_VERSION_NUMBER >= 0x02010100` to `#if LIBEVENT_VERSION_NUMBER < 0x02010100`. Reviewers: deadalnix, Fabien, jasonbcox, markblundeberg, O1 Bitcoin ABC, #bitcoin_abc Reviewed By: deadalnix, Fabien, jasonbcox, O1 Bitcoin ABC, #bitcoin_abc Differential Revision: https://reviews.bitcoinabc.org/D3464

rebroad · 2021-04-28T23:58:07Z

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?

jnewbery changed the title ~~[rpc Add logging rpc~~ [rpc] Add logging rpc Apr 4, 2017

jnewbery force-pushed the logging_rpc branch from 9d6826d to 0365458 Compare April 4, 2017 18:58

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

laanwj reviewed Apr 5, 2017

View reviewed changes

jnewbery force-pushed the logging_rpc branch from 0365458 to ea4ae76 Compare April 6, 2017 20:06

laanwj reviewed Apr 6, 2017

View reviewed changes

jnewbery force-pushed the logging_rpc branch 3 times, most recently from 0f927ff to bc3ad60 Compare April 7, 2017 19:41

laanwj reviewed Apr 10, 2017

View reviewed changes

jnewbery force-pushed the logging_rpc branch 2 times, most recently from 2832101 to df35edb Compare April 10, 2017 14:50

laanwj reviewed Apr 10, 2017

View reviewed changes

jnewbery added 3 commits April 10, 2017 17:05

Set BCLog::LIBEVENT correctly for old libevent versions.

4d9950d

[rpc] Add logging RPC

5255aca

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

allow libevent logging to be updated during runtime

7fd50c3

jnewbery force-pushed the logging_rpc branch from df35edb to 7fd50c3 Compare April 10, 2017 21:06

laanwj merged commit 7fd50c3 into bitcoin:master Apr 12, 2017

jnewbery deleted the logging_rpc branch April 12, 2017 18:00

codablock mentioned this pull request Jun 21, 2019

Backports 0.15 pr15 dashpay/dash#2986

Merged

random-zebra mentioned this pull request Mar 23, 2020

[RPC] Add logging RPC PIVX-Project/PIVX#1451

Merged

4 tasks

lyricidal mentioned this pull request Sep 28, 2021

[Upstream] [RPC] Add logging RPC PRCYCoin/PRCYCoin#125

Merged

bitcoin locked as resolved and limited conversation to collaborators Aug 18, 2022

[rpc] Add logging rpc #10150

[rpc] Add logging rpc #10150

Uh oh!

Conversation

jnewbery commented Apr 4, 2017 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

laanwj Apr 5, 2017 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

laanwj commented Apr 5, 2017

Uh oh!

jonasschnelli commented Apr 5, 2017

Uh oh!

jnewbery commented Apr 6, 2017

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

laanwj Apr 10, 2017 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

laanwj Apr 10, 2017 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

jnewbery commented Apr 10, 2017

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

laanwj commented Apr 12, 2017

Uh oh!

rebroad commented Apr 28, 2021

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

5 participants

jnewbery commented Apr 4, 2017 •

edited

Loading

laanwj Apr 5, 2017 •

edited

Loading

laanwj Apr 10, 2017 •

edited

Loading

laanwj Apr 10, 2017 •

edited

Loading