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      |
-------------------------------------+-------------------------------------
Changes (by muks):

 * owner:  muks => jinmei


Comment:

 Replying to [comment:56 jinmei]:
 > Sorry, on even a closer look, I still found a substantial issue:
 > We need to tweak the lock file path for all test.  Otherwise a test
 > could crash like this if the path isn't writable for the test:
 > {{{
 > [ RUN      ] DataSrcTest.Query
 > *** Exception derived from isc::exception thrown:
 >     file: interprocess_sync_file.cc
 >     line: 67
 >     what: Unable to use interprocess sync lockfile:
 /usr/var/bind10-devel/logger_lockfile
 > terminate called throwing an exception/bin/sh: line 1: 73461 Abort trap:
 6
 > }}}
 >
 > So, I suggest this:
 > - first, use a separate environment variable than B10_FROM_BUILD, e.g.
 >   B10_LOCKFILE_DIR_FROM_BUILD.  The former is generic and can be used
 >   for a different purpose only for some selected situations.  Now we
 >   are going to set it (almost) always for all tests, it could break
 >   something if we use the generic variable.
 > - second, set the variable in logger_unittest_support.cc:initLogger().
 >   rather than in each test's run_unittests.  The latter approach is a
 >   duplicate and would be easy to miss.
 > - btw, as far as I can see log/tests/run_initializer_unittests doesn't
 >   need to set this variable.  That should be same for
 >   init_logger_test.sh or tests/run_unittests if we add this trick in
 >   initLogger().  Or even any other of them.  Please check.

 These points are addressed now. Many unittests needed the
 B10_LOCKFILE_DIR_FROM_BUILD set. I've also added a null InterprocessSync
 implementation so that logger_example (which is a standalone utility) can
 use it. I've verified that make check at toplevel passes without the
 install prefix dir being available.

 > '''styles'''
 >
 > there are still some issues.  I've fixed them.

 :)

 > '''documentation'''
 >
 > I originally planned to defer or ignore this, but now we still need to
 > do some more ting...I'd explain a bit more about
 > `InterprocessSyncLocker`:
 >   - describe parameters
 >   - describe return value (and for false on lock/unlock, whether it
 >     can normally happen or not, and what the caller would have
 >     to do with it)
 >   - any possible exceptions (and requirement on this point for derived
 >     classes)

 Done.

 > '''bind10_test'''
 >
 > - not a big deal, but since this is already auto generated, you could
 >   embed @abs_top_builddir@ in the py.in file rather than set it via
 >   the Makefile.  But that's a minor point, so I'd leave it to you.
 > - I think it's safe to create/delete the dir in setup/teardown
 >   methods.  please also check this doesn't break distcheck.
 > - isn't it better to use os.path.exists than os.path.isfile?
 > - what's the purpose of the explicit close?
 > {{{#!python
 >                 open(fname, "w").close()
 > }}}
 >   If it's for the false positive about open file like due to the
 >   stupidity of Python as we discussed #1828, I'd avoid making our own
 >   code look counter intuitive due to that (besides, my python
 >   interpreter doesn't complain about it without close() even if it
 >   barks for other false positive cases).  If we really want to keep
 >   it, please add a comment about why we bother to do that.

 The .close() pretty much indicates that we don't (directly) use that file
 beyond that point. It doesn't appear to me as cluttered code.

 > - I'd confirm the file exists after the possible open:
 > {{{#!python
 >             if not os.path.isfile(fname):
 >                 open(fname, "w").close()
 >             self.assertTrue(os.path.isfile(fname))
 > }}}

 Done. I've added a few more such asserts to make everything go lock-step.

 > Replying to [comment:55 muks]:
 > > > '''logger.h'''
 > > >
 > > > - What happens if we pass NULL to `setInterprocessSync`?  (it may
 > > >   depend on that, but) I'd clarify this method is exception free,
 > > >   and that when non NULL the pointer must be delete-able and the
 > > >   ownership is transferred to `Logger` (so the caller doesn't have
 to
 > > >   / shouldn't delete it)
 > >
 > > A valid sync object always has to be present. I've made NULL do no
 change
 > > now.
 >
 > Hmm, frankly, I don't like this behavior: if NULL isn't expected I'd
 > throw; otherwise I'd use it somewhat useful, like "disabling lock".
 > But at this stage for this ticket I won't argue.

 I've made the code throw now, updated the doc and have added a unit test
 that checks it.

 > > > '''log test'''
 > > >
 > > > - I suspect we don't have the chicken-egg problem here.
 >
 > What about this?  I believe we can just auto generate .cc and .h.  But
 > again, we should probably prioritize completing this ticket than
 > trying to solve all small problems...

 This is also done now. The .cc and .h are generated by the .mes file and
 are no longer checked in the tree.

 > > > - technically, we should test the lock is acquired before the log
 > > >   output and released after that.  The Lock test doesn't actually
 > > >   confirm it.  But now that we've spent too much time on this
 ticket, if
 > > >   it's not easy to achieve, the current test is probably okay as a
 > > >   compromise.
 > >
 > > This will require something similar to the last design. It would
 > > need a wrapper around log4cplus so that logging calls are
 > > intercepted by a mock object *between* the lock/unlock. It would
 > > result in the same sort of ugliness as before.
 >
 > I don't necessarily think so; I can imagine having the mock
 > lock/unlock produce additional logs, then check the ordering of the
 > resulting logged message some way.  This approach shouldn't require a
 > change to the base and main (non test) classes.  But that probably
 > requires an additional setup like a checker script, and due to the
 > excessive time we've spent for this ticket, I should probably live
 > with the current test.

 This has been implemented now.

 If the branch looks ok, let's get this in.

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