BIND 10 #1704: log output mixed

[BIND 10 Development]

#1704: log output mixed
-------------------------------------+-------------------------------------
                   Reporter:  jreed  |                 Owner:  jinmei
                       Type:         |                Status:  reviewing
  defect                             |             Milestone:
                   Priority:         |  Sprint-20120529
  medium                             |            Resolution:
                  Component:         |             Sensitive:  0
  logging                            |           Sub-Project:  Core
                   Keywords:         |  Estimated Difficulty:  15
            Defect Severity:  N/A    |           Total Hours:  0
Feature Depending on Ticket:         |
        Add Hours to Ticket:  0      |
                  Internal?:  0      |
-------------------------------------+-------------------------------------

Comment (by jinmei):

 Okay...I was impressed about the effort of making it testable, but I'd
 like to have some more design level discussion.

 First, I have to say I'm not really excited about making the `Logger`
 class and the way it's used.  I'm not sure why some of the
 `Logger` or `LoggerImpl` classes have virtual methods (these classes
 doesn't seem to be used as a base class), but ignoring these
 (ineffective) "virtual" declarations, the wrapper trick really
 introduces polymorphism with its own costs such as vtable lookups.
 Since some of the logger related methods are expected to be very
 efficient (e.g., getSeverity()), I'd like to keep the overhead as
 small as possible, especially if the added overhead is just for
 testing.

 Second, the definition of LoggerWrapper seems to be too ad hoc.  It's
 mostly a just redundant wrapper and only with fatal() being a virtual
 method.  There's no documentation about it, so the class definition
 just looks so awkward unless you read every other part of the code
 including the tests that use it.

 Third, with this change it exposes the originally private `LoggerImpl`
 at the application-facing `Logger` level as a mutable pointer.  While
 I understand sometimes ugliness is the least bad for better
 testability, this hack seems to be too dangerous and dirty.

 Fourth, the separate file lock class isn't tested.  Actually, as a
 separate class it should be easier to test (also as Stephen
 commented), and once we can confirm this class really handles
 inter-process synchronization, we'd be able to simplify the logger
 tests with some level of abstraction.  That would also address the
 above concerns.

 So, if I may, I'd like to suggest something like this:

 - Introduce a base class for interprocess synchronization (at this
   level it could even be any type of conceptual lock; doesn't have to
   be file based).
 - Define a flock based derived class.  write tests for it.  also note
   that it could be a trivial wrapper for something like
   boost::file_lock, in which case we could even omit our own tests, to
   the extent we trust that library.
 - Also define a mock lock class for tests.  It could be, e.g., just
   dumps log message for lock/unlock operations.
 - The `Logger(Impl)` class holds a pointer to the base
   interprocess-sync class.  By default, it instantiates the file-lock
   based one and holds it.
 - Allow an application of the `Logger` to dynamically replace the
   internal lock object for `Logger`.  The logger test uses the mock
   lock class, and simply checks if log output is encapsulated with
   lock and unlock.  No interprocess checking is necessary here.
 - Within the logger, we still use a lightweight wrapper like the
   util::file_lock class for exception safety.  It would be constructed
   with a reference (or pointer) to the base lock class instead of FD.

 This way, we could separate the complicated interprocess test case
 from logging specific tests, which have their own complexity.  Also,
 we don't have to tweak the main logging related classes.  And, the
 synchronization class can be further flexible: for example, it could
 even be a "null" lock if the user knows there should be no lock issue
 or it's very performance sensitive and the user is willing to accept
 the consequence of omitting the lock such as mixed log outputs.

 What do you think?

 Comments on some other points:

 - the file permission trick seems to be acceptable (while subtle), but
   I'm not sure if the log library is the right place to implement it.
   Logging itself is pretty generic, while the permission issue is very
   specific to how the entire BIND 10 system is working.  So, making it
   group writable may not always be appropriate.  Now the boss process
   tries to remove the file at the end of its lifetime, I wonder
   whether it makes sense if we have the boss process creates the file
   with necessary permission setting at the beginning, and let the
   logging library just open it.

 - similar to the previous point, since we have other standalone progams
   that (perhaps implicitly) use the logging (at least dbtool for now,
   and I guess it's also the case for loadzone), we might even want to
   make the file path or whether to use locks customizable.  If we
   write a "zone checker" script, e.g, which can be run by anyone as an
   ordinary user, we don't want to make it emit noisy logs or even fail
   to run because of the logging issue, right?

 - As for changelog, it basically looks okay, but I'd note log file
   permission issue.  Also, for that reason, I'd add the '*' mark.

 - As for the note about environment variables, I was thinking about
   part of doxygen.  But in the case of logging, it may also be part of
   README because it already has it.  Definitely not the guide.

 Below I'm making some general comments on the code itself, although
 they may become moot depending on the result of the design level
 discussions above.

 '''general'''

 I've noticed several editorial/style issues and fixed them.  They are
 basically documented in the style guide wiki.  Please take a look at
 it again.

 '''log_messages'''

 - I don't like to include test specific log message
   (LOG_LOCK_TEST_MESSAGE) in the main source.

 '''file_lock.cc/h'''

 - naming convention: file_lock class should be (something like) FileLock
 - why is the destructor defined as virtual?
 - documentation: overall class description is needed.  In general all
   methods need documentation.  If any of the method can throw an
   exception, it should be documented (if it never throws it's better
   to say so explicitly).  Parameters need to be described (also for
   the constructor).

 '''logger_impl.h'''

 On LoggerWrapper: my compiler complains if it doesn't explicitly
 define the destructor and make it virtual:
 {{{#!cpp
     virtual ~LoggerWrapper() {}
 }}}
 when it has other virtual method.

-- 
Ticket URL: <http://bind10.isc.org/ticket/1704#comment:46>
BIND 10 Development <http://bind10.isc.org>
BIND 10 Development