util: Refactor logging code into a global object #12954

jimpo · 2018-04-11T22:03:55Z

This is purely a refactor with no behavior changes.

This creates a new class BCLog::Logger to encapsulate all global logging configuration and state.

laanwj · 2018-04-12T05:57:32Z

Concept ACK, splitting the logging functionality out of util makes sense, util.cpp is large, haphazard and this is a clearly distinguishable concern from the rest.

maflcko · 2018-04-13T13:51:30Z

Concept ACK. Needs rebase

sipa

Concept ACK

sipa · 2018-04-16T02:32:19Z

src/util.h

-    } \
-} while(0)
-#endif
-
 template<typename... Args>
 bool error(const char* fmt, const Args&... args)


I think this should move to logging as well, so the cyclic dependency between logging and util can be avoided.

LogPrintf is also used in TraceThread, and I don't think either of them actually belong in logging (the whole point of this PR is to create a more cohesive separation). I can very easily imagine another method that gets added to util.h in the future requiring logging as well.

The dependency isn't really cyclic -- logging.cpp includes util.h, and util.h includes logging.h, but logging.h does not include util.h.

My view is that you should always treat the .h and the .cpp file as one unit. While this may indeed not be a cyclic dependency for the compiler, it is certainly one between the two modules semantically: logging can't work without util, and util can't work without logging. Finding out why that is the case helps creating a cleaner separation.

You're right that util is going to depend on logging though, as it contains a number of higher level functions. However, It looks like logging only really needs util for finding the debug log path, though. All the rest is in utiltime. This seems easy to fix, by instead having init query the path and call a setter on logging for it for example. If other reviewers are fine with that, we can fix that up in another PR.

Last I looked, when reviewing #13021, I saw another approach to solving the cyclic dependency is to include utiltime.h in logging.cpp and splitting out args and path handling from util.h. Didn’t go all the way to implementing that but would be happy to as a follow-on to #13021.

Lol, didn’t finish reading your comment @sipa. Anyway I’m for it.

Fixed with d903273cf8e51d2789ba8a88c608a66e63dcdc14.

maflcko · 2018-04-17T15:26:52Z

Needs rebase again. (Since this has some Concept ACKs, but is somewhat largish, it might be easier to merge in two steps. First the move-only commit in a separate pull request and then the refactoring in this pull request)

…les. b77b6e2 MOVEONLY: Move logging code from util.{h,cpp} to new files. (Jim Posen) Pull request description: Split out first commit from #12954 to reduce amount of rebasing necessary. This introduces a cyclic dependency between `logging` and `util` that should be cleaned up in a future PR. Tree-SHA512: 695e512f9c2f7b4ca65e367fc924358e3cb2dc531bcbb7a6f62710b2a87280b35aba7793aa272e457fcd65448abe3feb1deb3b8064ed208917ca356b0f410813

jnewbery

Tested ACK d903273cf8e51d2789ba8a88c608a66e63dcdc14. Couple of comments inline but nothing to prevent merge.

jnewbery · 2018-04-20T14:29:18Z

src/logging.h

+         * the timestamp when multiple calls are made that don't end in a
+         * newline.
+         */
+        std::atomic_bool m_started_new_line{true};


Note that this maintains the old (broken) behaviour:

two threads are running. Thread A logs a line that doesn't terminate with a newline (ie a 'continuing' log)

thread B then logs a line. This is treated as a 'continuation' log of thread A's previous log, and is printed on the same line, without a timestamp

thread A's 'continuation' log is printed on a new line, with a timestamp

No need to fix that in this PR.

jnewbery · 2018-04-20T15:13:58Z

src/logging.h

-extern bool fPrintToDebugLog;
-
-extern bool fLogTimestamps;
-extern bool fLogTimeMicros;
 extern bool fLogIPs;


In commit util: Establish global logger object. : any reason to exclude fLogIPs from g_logger?

It's not actually used by the logger, it's just used in the net code. Arguably it should live there instead.

maflcko · 2018-04-21T21:17:11Z

src/logging.cpp

@@ -264,7 +259,7 @@ void BCLog::Logger::ShrinkDebugFile()
        int nBytes = fread(vch.data(), 1, vch.size(), file);


Unrelated nit: Could change int to size_t here, so that it doesn't break when someone changes RECENT_DEBUG_HISTORY_SIZE to 5GB.

jamesob

Tested ACK d903273

./src/qt/bitcoin-qt -regtest -conf="$(pwd)/bitcoin.conf" -debug=1
- Displays all available logs.
./src/qt/bitcoin-qt -testnet -conf="$(pwd)/bitcoin.conf" -debug=0
- Displays only uncategorized logs.
./src/qt/bitcoin-qt -testnet -conf="$(pwd)/bitcoin.conf" -debug=1
- Displays all available logs.
./src/qt/bitcoin-qt -testnet -conf="$(pwd)/bitcoin.conf" -help
- Displays available logging categories for -debug.
./src/bitcoind -debug=foobar
- Warns of invalid logging category.
./src/bitcoind -debug=1 -debugexclude=net,addrman,rand,leveldb
- Displays all available logs (confusing, but this matches behavior on master).
./src/bitcoind -debugexclude=net,addrman,rand,leveldb
- Excludes specified log categories.
./src/bitcoind -testnet -config="$(pwd)/bitcoin.conf" -debug=reindex -reindex
- Shows reindex-related log messages.
./src/bitcoind -testnet -config="$(pwd)/bitcoin.conf" -debug=net -reindex
- Shows no reindex-related log messages, but plenty of net-related ones.

Nice change. The one nit I had definitely shouldn't hold this up.

jamesob · 2018-04-25T18:31:23Z

src/logging.cpp

+        flag = BCLog::ALL;
+        return true;
+    }
+    for (unsigned int i = 0; i < ARRAYLEN(LogCategories); i++) {


nit: seems like you could phrase this more simply as

for (CLogCategoryDesc& cat : LogCategories) { ... }

There doesn't seem to be a need to have the index on hand.

Nice, fixed. Also gets rid of the dependency of logging on utilstrencodings.

The object encapsulates logging configuration, and in a later commit, set up routines will also be moved into the class.

Changing parameter types from pointers to references and uint32_t to BCLog::LogFlags simplies calling code.

-BEGIN VERIFY SCRIPT- sed -i "s/fileout/m_fileout/" src/logging.h src/logging.cpp sed -i "s/mutexDebugLog/m_file_mutex/" src/logging.h src/logging.cpp sed -i "s/vMsgsBeforeOpenLog/m_msgs_before_open/" src/logging.h src/logging.cpp sed -i "s/logCategories/m_categories/" src/logging.h src/logging.cpp sed -i "s/fPrintToConsole/m_print_to_console/" src/logging.h src/logging.cpp src/init.cpp sed -i "s/fPrintToDebugLog/m_print_to_file/" src/logging.h src/logging.cpp src/init.cpp src/test/test_bitcoin.cpp src/bench/bench_bitcoin.cpp sed -i "s/fLogTimestamps/m_log_timestamps/" src/logging.h src/logging.cpp src/init.cpp sed -i "s/fLogTimeMicros/m_log_time_micros/" src/logging.h src/logging.cpp src/init.cpp sed -i "s/fReopenDebugLog/m_reopen_file/" src/logging.h src/logging.cpp src/init.cpp sed -i "s/fStartedNewLine/m_started_new_line/" src/logging.h src/logging.cpp -END VERIFY SCRIPT-

This breaks the cyclic between logging and util.

jnewbery · 2018-04-30T13:17:37Z

utACK 8c2d695. Only difference is changing to range based for loops per #12954 (comment)

sipa · 2018-05-01T02:10:51Z

utACK 8c2d695. Nice to see this encapsulated.

8c2d695 util: Store debug log file path in BCLog::Logger member. (Jim Posen) 8e7b961 scripted-diff: Rename BCLog::Logger member variables. (Jim Posen) 1eac317 util: Refactor GetLogCategory. (Jim Posen) 3316a9e util: Encapsulate logCategories within BCLog::Logger. (Jim Posen) 6a6d764 util: Move debug file management functions into Logger. (Jim Posen) f55f4fc util: Establish global logger object. (Jim Posen) Pull request description: This is purely a refactor with no behavior changes. This creates a new class `BCLog::Logger` to encapsulate all global logging configuration and state. Tree-SHA512: b34811f54a53b7375d7b6f84925453c6f2419d21179379ee28b3843d0f4ff8e22020de84a5e783453ea927e9074e32de8ecd05a6fa50d7bb05502001aaed8e53

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

5c8e968 [Trivial] Document logtimemicros flag in the help (random-zebra) 4daa10a util: Store debug log file path in BCLog::Logger member. (random-zebra) 2f03e85 scripted-diff: Rename BCLog::Logger member variables. (random-zebra) 303700e util: Refactor GetLogCategory. (random-zebra) 0ae18c0 util: Encapsulate logCategories within BCLog::Logger. (random-zebra) a2fb3fd util: Move debug file management functions into Logger. (random-zebra) 5a42d82 util: Establish global logger object. (random-zebra) 15c0da4 [Refactor] Complete boost::filesystem namespace in util (random-zebra) 81ddbf4 MOVEONLY: Move logging code from util.{h,cpp} to new files. (random-zebra) Pull request description: Implemented on top of: - [x] #1449 - [x] #1437 - [x] #1439 - [x] #1450 - [x] #1451 - [x] #1455 This creates a new class BCLog::Logger to encapsulate all global logging configuration and state. Adapted from - bitcoin#13021 - bitcoin#12954 ACKs for top commit: Fuzzbawls: ACK 5c8e968 furszy: utACK 5c8e968 Tree-SHA512: 0b10a031dd7e32b48485236fbdd8249d011049e6f99e1df145b7dea4cab9e6e67e19d1bb13ff48e99eb2487a8399bbb8298fe851ad8873416fc1053aee0379bc

… new files. b77b6e2 MOVEONLY: Move logging code from util.{h,cpp} to new files. (Jim Posen) Pull request description: Split out first commit from bitcoin#12954 to reduce amount of rebasing necessary. This introduces a cyclic dependency between `logging` and `util` that should be cleaned up in a future PR. Tree-SHA512: 695e512f9c2f7b4ca65e367fc924358e3cb2dc531bcbb7a6f62710b2a87280b35aba7793aa272e457fcd65448abe3feb1deb3b8064ed208917ca356b0f410813 Signed-off-by: pasta <pasta@dashboost.org> # Conflicts: # src/Makefile.am # src/util.cpp # src/util.h

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

8c2d695 util: Store debug log file path in BCLog::Logger member. (Jim Posen) 8e7b961 scripted-diff: Rename BCLog::Logger member variables. (Jim Posen) 1eac317 util: Refactor GetLogCategory. (Jim Posen) 3316a9e util: Encapsulate logCategories within BCLog::Logger. (Jim Posen) 6a6d764 util: Move debug file management functions into Logger. (Jim Posen) f55f4fc util: Establish global logger object. (Jim Posen) Pull request description: This is purely a refactor with no behavior changes. This creates a new class `BCLog::Logger` to encapsulate all global logging configuration and state. Tree-SHA512: b34811f54a53b7375d7b6f84925453c6f2419d21179379ee28b3843d0f4ff8e22020de84a5e783453ea927e9074e32de8ecd05a6fa50d7bb05502001aaed8e53

… new files. b77b6e2 MOVEONLY: Move logging code from util.{h,cpp} to new files. (Jim Posen) Pull request description: Split out first commit from bitcoin#12954 to reduce amount of rebasing necessary. This introduces a cyclic dependency between `logging` and `util` that should be cleaned up in a future PR. Tree-SHA512: 695e512f9c2f7b4ca65e367fc924358e3cb2dc531bcbb7a6f62710b2a87280b35aba7793aa272e457fcd65448abe3feb1deb3b8064ed208917ca356b0f410813 Signed-off-by: pasta <pasta@dashboost.org>

fanquake added Utils/log/libs Refactoring labels Apr 11, 2018

PierreRochard mentioned this pull request Apr 15, 2018

[wallet] Add wallet name to log messages #12992

Merged

jimpo force-pushed the logging branch from 293689e to ee5df96 Compare April 16, 2018 02:27

sipa reviewed Apr 16, 2018

View reviewed changes

jimpo force-pushed the logging branch from ee5df96 to f9c5a3e Compare April 16, 2018 05:16

jimpo mentioned this pull request Apr 18, 2018

MOVEONLY: Move logging code from util.{h,cpp} to new files. #13021

Merged

jimpo force-pushed the logging branch from f9c5a3e to d903273 Compare April 20, 2018 08:14

jnewbery reviewed Apr 20, 2018

View reviewed changes

maflcko reviewed Apr 21, 2018

View reviewed changes

jamesob approved these changes Apr 25, 2018

View reviewed changes

jimpo force-pushed the logging branch from d903273 to d0a285a Compare April 27, 2018 23:09

Jim Posen added 3 commits April 27, 2018 16:09

util: Establish global logger object.

f55f4fc

The object encapsulates logging configuration, and in a later commit, set up routines will also be moved into the class.

util: Move debug file management functions into Logger.

6a6d764

util: Encapsulate logCategories within BCLog::Logger.

3316a9e

jimpo force-pushed the logging branch from d0a285a to 8524470 Compare April 27, 2018 23:10

Jim Posen added 3 commits April 29, 2018 14:37

util: Refactor GetLogCategory.

1eac317

Changing parameter types from pointers to references and uint32_t to BCLog::LogFlags simplies calling code.

util: Store debug log file path in BCLog::Logger member.

8c2d695

This breaks the cyclic between logging and util.

jimpo force-pushed the logging branch from 8524470 to 8c2d695 Compare April 29, 2018 21:38

sipa merged commit 8c2d695 into bitcoin:master May 1, 2018

jimpo deleted the logging branch May 1, 2018 05:34

Bushstar mentioned this pull request May 1, 2018

commits from bitcoin/master FeatherCoin/Feathercoin#316

Merged

random-zebra mentioned this pull request Mar 25, 2020

[Util] Refactor logging code into a global object PIVX-Project/PIVX#1459

Merged

6 tasks

kwvg mentioned this pull request May 19, 2021

Merge #19660, #19373, #19841, #13862, #13866, #17280, #17682 and partial #19326, #14978: Auxiliary Backports dashpay/dash#4164

Merged

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

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

util: Refactor logging code into a global object #12954

util: Refactor logging code into a global object #12954

jimpo commented Apr 11, 2018 •

edited

Loading

laanwj commented Apr 12, 2018

maflcko commented Apr 13, 2018

sipa left a comment

sipa Apr 16, 2018

jimpo Apr 16, 2018

sipa Apr 16, 2018

Empact Apr 20, 2018

Empact Apr 20, 2018

jimpo Apr 20, 2018

maflcko commented Apr 17, 2018

jnewbery left a comment

jnewbery Apr 20, 2018

jnewbery Apr 20, 2018

jimpo Apr 23, 2018

maflcko Apr 21, 2018

jamesob left a comment

jamesob Apr 25, 2018

jimpo Apr 30, 2018

jnewbery commented Apr 30, 2018

sipa commented May 1, 2018

		@@ -264,7 +259,7 @@ void BCLog::Logger::ShrinkDebugFile()
		int nBytes = fread(vch.data(), 1, vch.size(), file);

util: Refactor logging code into a global object #12954

util: Refactor logging code into a global object #12954

Conversation

jimpo commented Apr 11, 2018 • edited Loading

laanwj commented Apr 12, 2018

maflcko commented Apr 13, 2018

sipa 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

maflcko commented Apr 17, 2018

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

jamesob left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

jnewbery commented Apr 30, 2018

sipa commented May 1, 2018

jimpo commented Apr 11, 2018 •

edited

Loading