Page MenuHomePhabricator

[Part 2] Refactor logging code into a global object
ClosedPublic

Authored by jimpo on Apr 12 2018, 19:30.

Details

Summary

util: Establish global logger object.

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

Test Plan

Run bitcoind with different permutations of:
-logtimestamps, -debug, -printtoconsole, -datadir, -shrinkdebugfile

Diff Detail

Repository
rABC Bitcoin ABC
Lint
Lint Not Applicable
Unit
Tests Not Applicable

Event Timeline

Owners added a reviewer: Restricted Owners Package.Apr 12 2018, 19:30

Added braces around an if statement.

jimpo retitled this revision from util: Establish global logger object. to [Part 2] Refactor logging code into a global object.Apr 12 2018, 19:42
jimpo edited the summary of this revision. (Show Details)

Use global LogPrintf in util.h instead of Logger method.

deadalnix requested changes to this revision.Apr 13 2018, 13:18

You have a problem here, none of this is thread safe.

src/logging.cpp
23 ↗(On Diff #3488)

Why not make this a static variable ? Using a unique pointer here opens the door for all kind of race conditions.

src/logging.h
60 ↗(On Diff #3488)

It's clearly not held by the calling context.

This revision now requires changes to proceed.Apr 13 2018, 13:18

The thread safety is tricky.

No, the unique_ptr is not thread safe, but I'm hoping that it is in the way it is used. If the pointer is only assigned during initialization while there is only one thread and only released on program exit after all threads have been joined, it should only ever have one value when accessed concurrently.

The reason it's a pointer and not just a global Logger value is because that way LogPrintf can check if the pointer is null and skip logging if so. On the flip side, there's no way to tell if an object has been constructed or destructed on program startup/exit. See the comment from the existing code about this:

/**

  • LogPrintf() has been broken a couple of times now by well-meaning people
  • adding mutexes in the most straightforward way. It breaks because it may be
  • called by global destructors during shutdown. Since the order of destruction
  • of static/global objects is undefined, defining a mutex as a global object
  • doesn't work (the mutex gets destroyed, and then some later destructor calls
  • OutputDebugStringF, maybe indirectly, and you get a core dump at shutdown
  • trying to lock the mutex). */

I believe it unsafe for there to just be a global extern BCLog::Logger g_logger. That said, as long as the application joins all threads before exiting and destructing global objects, I think it ought to be safe to use a global unique_ptr. What do you think? I'd really rather not guard access to the logger with a mutex.

src/logging.h
60 ↗(On Diff #3488)

Will fix comment.

Using a unique_ptr is significantly more dangerous that the unique_ptr thing because you don't have the risk of a dangling pointer.

Replaced std::unique_ptr to global logger with a thread-safe GetLogger method as discussed in chat.

Update member variable comment for fStartedNewLine.

Change g_logger to a *const instead of function with mutex.

deadalnix requested changes to this revision.Apr 17 2018, 00:46

As discussed offline, this rely on the initialization order (using the logger before the pointer is initialized would cause a segfault).

Going with a static and an accessor is best for now, using a boost::call_once to initialize what must be. Sadly, this is not ideal, but as long as there are globals using the logger in their constructor/destructor, there are not that many options. These globals need to be clean up first.

This revision now requires changes to proceed.Apr 17 2018, 00:46

Switched back to GetLogger function.

schancel added a subscriber: schancel.
schancel added inline comments.
src/logging.h
12 ↗(On Diff #3529)

Where is this dependency coming from? It looks like mostly code was moved. Is this just something which should have been here to begin with?

src/logging.h
58 ↗(On Diff #3529)

Let's start dropping hungarian notation if possible. I will start writing up a coding conventions document.

src/logging.h
58 ↗(On Diff #3529)

You're right, this can be dropped. This is leftover from when I was using std::call_once.

Remove unused <memory> include.

jasonbcox requested changes to this revision.Apr 20 2018, 00:19
jasonbcox added inline comments.
src/logging.h
58 ↗(On Diff #3529)

Hungarian notation is the prepending of the data type (in this example, 'f'). I think you're referring to something else?

The recommended naming would be: startedNewLine
and for the public members:
printToConsole
printToDebugLog
logTimestamps
logTimeMicros
reopenDebugLog

This revision now requires changes to proceed.Apr 20 2018, 00:19
src/logging.h
58 ↗(On Diff #3529)

See, that is exactly why I was reluctant to start enforcing a naming convention at this time. It will be very time consuming for everybody for little win.

We should strive to eventually have one, but submitter and reviewer time is not well spent doing that kind of back and forth. This is a linter's job to tell the submitter than the code do not follow some convention at arc diff time.

The work on the cmake build will eventually get us to a place where we can leverage clang-tidy to do this. In the mean time, I'm not convinced that the reward is worth the cost. Just like enforcing formatting xouldn't be worth it if we couldn't have clang-format do it automatically.

A few comments, but overall, it looks good.

src/logging.cpp
31 ↗(On Diff #3551)

Why do you insist on making this a pointer ?

static BCLog::Logger logger();
178 ↗(On Diff #3551)

idk if this is bad or not, but this definitely changes the semantic of the code as fStartedNewLine used to be dependent on the caller but has now been made a global.

@jasonbcox @schancel I completely agree on not using Hungarian notation for new code, but changing these variable names would increase the diff size. If you want, I would prefer to rename all of the variables in a future diff that just does the renaming.

src/logging.cpp
31 ↗(On Diff #3551)

See the big block comment above this method.

If you think that is not a concern, I will happily change it to a value. But the current logging code warns that doing so may cause issues.

178 ↗(On Diff #3551)

The caller was always the same though -- LogPrintStr. I definitely consider this to be logger state. Access is protected as it's a private member.

deadalnix added inline comments.
src/logging.cpp
31 ↗(On Diff #3551)

We discussed this offline, it makes sense to use a pointer here.

I'm fine taking care of variable renaming later. I'm with @deadalnix on this, we shouldn't be burning too much time on inconsequential issues like naming.

This revision is now accepted and ready to land.Apr 20 2018, 23:00
This revision was automatically updated to reflect the committed changes.