BIND 10 #2198: make sure InterprocessSyncLocker is thread safe

[BIND 10 Development]

#2198: make sure InterprocessSyncLocker is thread safe
-------------------------------------+-------------------------------------
            Reporter:  jinmei        |                        Owner:
                Type:  defect        |  vorner
            Priority:  medium        |                       Status:
           Component:  logging       |  reviewing
            Keywords:                |                    Milestone:
           Sensitive:  0             |  Sprint-20130402
         Sub-Project:  Core          |                   Resolution:
Estimated Difficulty:  5             |                 CVSS Scoring:
         Total Hours:  3.85          |              Defect Severity:  N/A
                                     |  Feature Depending on Ticket:
                                     |          Add Hours to Ticket:  0
                                     |                    Internal?:  0
-------------------------------------+-------------------------------------

Comment (by vorner):

 Hello

 Looking at the code, it looks sane an mostly OK. Just, around the
 lock()/unlock()/tryLock methods in mutex, the comments say not to use the
 method directly. But the methods are private. I guess the comment is
 useless there.

 Also, I think we do lock correctly. I confirmed by writing a multi-process
 & multi-threaded program that does only logging. It produced no garbled
 messages. The programs are attached, if you want to have a look.

 However, the problems with logging in lettuce still stays. I don't know
 how much it is related to this ticket, but:
  * I run the lettuce with redirection to pipe, by `run_lettuce.sh | tee
 output.log`, so I can examine the log even if it scrolls up too far. That
 may be related.
  * After some time of experimenting, I managed to catch the problem with
 strace running. This is the garbled output:
 {{{
 2013-03-29 13:10:41.565 DEBUG [b10-msgq.msgq/2318] MSGQ_RECV_HDR Received
 header: {'type': 'getlname'}
 2013-03-29 13:10:41.560 DEBUG [b10-cmdctl.cmdctl2013-03-29 13:10:41.566/
 DEBUG2361 [] b10-msgq.msgq/2318
 ] MSGQ_RECV_HDR Received header: {'type': 'subscribe', 'group': 'Xfrin',
 'instance': '*'}2013-03-29 13:10:41.566
  DEBUG [b10-cmdctl.pycc /DEBUG2361 [b10-msgq.msgq/PYCC_LNAME_RECEIVED
 received local name: 515584c1_8 at ruth2318
 ] MSGQ_SUBS_NEW_TARGET Creating new target for subscription to group
 'Xfrin' for instance '*'2013-03-29 13:10:41.566
  DEBUG [b10-cmdctl.pycc/2361] PYCC_LNAME_RECEIVED received local name:
 515584c1_9 at ruth
 2013-03-29 13:10:41.567 DEBUG [b10-cmdctl.config/2361]
 CONFIG_LOG_WILD_MATCH will use logging configuration for wildcard logger *
 }}}

 Relevant strace files are attached to ticket.

 From how it looks, it seems we do the logging, but the write() calls are
 buffered and delayed for later time for some reason.

 I don't have a concrete idea what to do about it. I think we still do need
 the locking and it should be merged (once the detail up there are
 handled), but it obviously is not enough.

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