BIND 10 #2445: suppress initial log

BIND 10 Development do-not-reply at isc.org
Wed Dec 5 21:10:48 UTC 2012


#2445: suppress initial log
-------------------------------------+-------------------------------------
            Reporter:  jinmei        |                        Owner:
                Type:  defect        |  jinmei
            Priority:  medium        |                       Status:
           Component:  Boss of BIND  |  reviewing
            Keywords:                |                    Milestone:
           Sensitive:  0             |  Sprint-20121218
         Sub-Project:  Core          |                   Resolution:
Estimated Difficulty:  4             |                 CVSS Scoring:
         Total Hours:  0             |              Defect Severity:  N/A
                                     |  Feature Depending on Ticket:
                                     |          Add Hours to Ticket:  0
                                     |                    Internal?:  0
-------------------------------------+-------------------------------------
Changes (by jelte):

 * owner:  jelte => jinmei


Comment:

 And here are the comments about the other comments:

 Replying to [comment:12 jinmei]:
 > Basic approach looks good.  I have several points to discuss in detail
 > though.
 >
 > '''changelog'''
 >
 > I think we need a changelog entry for this task.
 >

 ack, proposal:

 [bug/func?]     jelte
 The system no longer prints initial log messages to stdout regardless of
 what logging configuration is present, but it temporarily stores any log
 messages until the configuration is processed. If there is no specific
 configuration, or if the configuration cannot be accessed, it will still
 fall back to stdout.
 Note that there are still a few instances where output is printed, these
 shall be addressed separately.

 > '''log_buffer.h'''
 >
 > - If I understand it correctly, I think `friend` is too strong a tool
 >   in this case:
 > {{{#!cpp
 >     friend class LogBufferTest;
 > }}}
 >   AFAICS (and also as commented in the code) the only purpose for the
 >   `friend` is to give `LogBufferTest` read-only access to `stored_`.
 >   In that case I'd rather provide a read-only getter for the vector,
 >   noting it's only for testing and it's possible we'll remove/change
 >   the interface (so normal apps shouldn't use it).  Also AFAIC, we
 >   could even hide the fact that it's a vector: all we need for the
 >   test seems to be an interface to return the number of stored
 >   messages.

 Yeah, I can just add a getBufferSize(), done.

 > - flush() isn't documented.

 done

 > - `flush_stdout` should be renamed `flushStdout` (or something) per
 naming convention.
 > - it directly depends on log4cplus internal.  My first question is
 >   whether it's a good idea or we should introduce a higher level
 >   interface for the concept of buffering.  If the answer to the first
 >   question is yes, maybe it's better to clarify the intent by renaming
 >   log_buffer.h to log_buffer_impl.h.  Same for .cc

 dunno, part of the reason this whole set of classes works in a non-obvious
 matter is because of the many pimpls there already :)

 Of course a related question is whether some of the things we do would
 even be possible if we'd change the logging system (and whether it would
 require rewriting the public side as well anyway).

 Also, there is the problem that this internal event type is simply is what
 we get (in the sublass of log4cplus::Appender). We could of course move
 *that* to some file with a hint in its name, and then wrap it in our own
 extra super/subclass pair, with its own replay() call. But at some point I
 think we need to stop adding classes tbh.

 Note, originally I had put both of these classes within an unnamed
 namespace in logger_manager_impl.cc, but then testing was a problem.

 > - is it okay to store `InternalLoggingEvent` objects in a vector?
 >   This class seems to be inheritable according to the log4cplus doc,
 >   so in general there can be a risk of slicing due to the inevitable
 >   copy in the vector.  To be really safe, I guess we should make a
 >   pointer-based copy by `InternalLoggingEvent::clone()`, release it
 >   from auto_ptr, move it to shared_ptr, and then store it in a vector.
 >

 oh right, of course.

 > '''log_buffer.cc'''
 >
 > - I'd include `<iostream>` if we keep using std::cout etc (but see below
 too)

 added (in the third commit about the other change, forgot about this one)

 > - with this implementation, the singleton `LogBuffer` object will be
 >   destoryed at an unpredictable timing, and its `stored_` member could
 >   be a non empty (though which may be less likely in practice) vector
 >   of a third-party type (`InternalLoggingEvent`).  I'm afraid it's
 >   quite fragile in terms of "static destruction" fiasco.
 >

 hence the original potentially superfluous copies, and the only-dump-to-
 stdout instead of trying to still use the log4cplus system. But do the
 above changes (store shared ptrs to clones) alleviate your concern here?

 > - `LogBuffer` constructor: a minor point in this case, but I'd
 initialize
 >   `flushed_` in the initialization list.
 >

 done

 > - `LogBuffer` destructor: flush_stdout() seems to do non trivial task,
 >   and it can throw.  If the dumping behavior isn't crucial, I'm simply
 >   releasing the stuff here; if it's necessary, I'd at least ensure no
 >   exception (if any) leaks from the destructor:
 > {{{#!cpp
 > LogBuffer::~LogBuffer() {
 >     try {
 >         flush_stdout();
 >     } catch (...) {}
 > }
 > }}}
 >

 Ok

 > - `LogBuffer::flush`: why is `event` copied?
 > {{{#!cpp
 >         const log4cplus::spi::InternalLoggingEvent event(stored_.at(i));
 > }}}
 >   I guess a reference should suffice here.  See also discussion about
 >   copying event objects and slicing above.

 Yeah, i changed this to a normal iterator when doing the above

 > - `LogBuffer::flush`: what if it throws before clear()?
 >

 then it is not cleared :) (I considered copying the vector, and removing
 items as they are flushed one by one, but tbh it did not seem worth the
 trouble)

 > '''log_buffer_unittest.cc'''
 >
 > - Isn't it better to use a mock appender to inspect what happens
 >   on flush()?

 I originally had one, but it was really the same as the existing one.
 Apart from testing that it is empty after flush, and that the events have
 been passed on to whatever appender is now in the logger, I'm not sure
 what else it should test anyway (actual output it tested through the other
 script test)

 > - I don't understand why we need this trick (or what exactly it does):
 > {{{#!cpp
 >         // If any log messages are left, we don't care, get rid of them,
 >         // by flushing them to a null appender
 >         log4cplus::SharedAppenderPtr null_appender(
 >             new log4cplus::NullAppender());
 >         logger.removeAllAppenders();
 >         logger.addAppender(null_appender);
 >         buffer1.flush();
 >         buffer2.flush();
 > }}}
 >   Maybe some more comments are needed.

 Added, it simply prevents the 'Foo' messages to be dumped to stdout (they
 need to go *somewhere*)

 > - `LogBuffer::add()` doesn't seem to be directly tested.

 added

 > - `BufferAppender::append()` doesn't seem to be directly tested.

 i just made it protected (to reflect the original, a property I had
 missed), so unless we want to reintroduce a friend again (or yet another
 subclass), this would be quite hard :)

 > - Related to the point of directly relying on log4cplus API, I wonder
 >   whether the original intent is to exclude tests directly depending
 >   on log4cplus from the unittests.  I think direct unit tests are a
 >   good practice anyway, but maybe you want to ask Stephen about the
 >   original plan.
 >

 I guess this other point ties in more to whether we should forcibly hide
 the type as deep as possible. (but in that case the tests would still need
 to create them somehow)

 > '''buffer_logger_test.cc'''
 >
 > - I'd hide usage() in an unnamed namespace.
 >

 ok

 > '''buffer_manager_impl.h'''
 >
 > - `createBufferAppender`: has a non existent parameter description:
 > {{{#!cpp
 >     /// \param opt Output options for this appender.
 > }}}
 >

 oops :) removed

 > '''buffer_manager_impl.cc'''
 >
 > - why is scoped_ptr.hpp included?
 >

 because i forgot to remove it, done now

 > - `processSpecification`: due to the complexity I cannot be 100% sure,
 >   but if I understand it correctly this change breaks existing
 >   behavior.  Consider the case only severity level is set without any
 >   output option.  Previously existing appenders are preserved, but
 >   they are now cleaned up and replaced with a single default appender.
 >

 see other comment

 > - `processSpecification`: this change also seems to be fragile:
 > {{{#!diff
 > -    log4cplus::Logger logger = log4cplus::Logger::getInstance(
 > +    log4cplus::Logger logger;
 > +    // If this is an 'empty' specification, just set the root logger
 > +    if (spec.getName() == "") {
 > +        logger = log4cplus::Logger::getInstance(getRootLoggerName());
 > +    } else {
 > +        logger = log4cplus::Logger::getInstance(
 >                                     expandLoggerName(spec.getName()));
 > +    }
 > }}}
 >   I guess it's intended to be called via `LoggerManager::process()`,
 >   but what if a spec whose name is "" is explicitly given?  In the
 >   previous code it result in
 > {{{#!cpp
 >         logger = log4cplus::Logger::getInstance(expandLoggerName(""));
 > }}}
 >   but now it results in
 > {{{#!cpp
 >         logger = log4cplus::Logger::getInstance(getRootLoggerName());
 > }}}
 >
 > - Considering these, I guess we should handle cases with buffering
 >   more explicitly, instead of abusing existing states of the class.
 >   For example, introduce a member variable to indicate whether any
 >   spec has been given, and flush-buffer-and-remove-it only for the
 >   first time it's configured.
 >

 partly see other comment, but i did pull it out and change the 'no-
 specification' process version.


 > '''cfgmgr.py'''
 >
 > - I don't understand the purpose of the changes (and there's no test
 >   for these changes).  Please explain and/or add comments.
 >

 Added comments (we need to trigger the process() call to flush the buffers
 in case there is no explicit config)

 > '''log/README'''
 >
 > - I'd also note that process() is normally called from
 >   `ModuleCCSession` if the program uses the config framework (so it
 >   doesn't do it explicitly in its program code).
 > {{{
 > be flushed according to the specification. Note that if this option is
 used,
 > the program SHOULD call one of the LoggerManager's process() calls. If
 the
 > }}}
 >

 added

 > '''python log.cc'''
 >
 > - supporting keyworded parameters is nice, but we should probably test
 >   it.

 added, but only whether they are recognized (and fail on wrong types); I
 don't believe we have any provisioning for checking whether they got
 interpreted as expected...

 > - there's an unbalanced parenthesis
 > {{{
 >         "severity (optional): one of 'DEBUG', 'INFO', 'WARN', 'ERROR' or
 "
 >         "'FATAL')\n"
 > }}}

 removed :)

 > - s/pointed/point/?
 > {{{
 >         "to be stored internally until log_config_update is called, at "
 >         "which pointed they shall be logged."},
 > }}}

 fixed

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


More information about the bind10-tickets mailing list