BIND 10 #1704: log output mixed

[BIND 10 Development]

#1704: log output mixed
-------------------------------------+-------------------------------------
                   Reporter:  jreed  |                 Owner:  stephen
                       Type:         |                Status:  reopened
  defect                             |             Milestone:
                   Priority:         |  Sprint-20120501
  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 muks):

 Replying to [comment:24 stephen]:
 > I'm not certain that's an exact comparison with the logging output.
 >
 > If line flushing is enabled, log4cplus appears to call ostream::flush()
 to flush the buffer after writing each line.  printf() does not flush its
 buffer even if you terminate the string with "\n".  To get the same
 behaviour as log4cplus with line flushing enabled, you would need to call
 fflush(stdout) after each printf().

 The default buffering behavior is applicable when stdout writes to a tty.
 stdout is line-buffered in that case (it will flush when it sees a '\n').
 When writing to a pipe, I don't know if this still applies.

 Regarding the explicit flushing, I have tried using fflush(stdout) after
 every printf() in the example above, and the same mixing up happens.

 > Having said that, we are assuming that each underlying call to write(2)
 to the console cannot interrupt another call to write(2) made by a
 different process (which may be running at the same time on a multi-core
 system).  I've not managed to find anything that guarantees this.

 With strace, it can be seen that for the string lengths in the example
 above, write()s block till they're done. They don't return with partial
 counts (i.e., upon a printf() that flushes, libc doesn't call write() more
 than once per a buffer). BTW, even in a single core system, another
 process can be scheduled as the write() is blocked on I/O.

 > > If multiple processes have to write legibly to a single output, we
 will have to use some sort of locking or have a logging server.
 > I think locking and unlocking a single BIND10-wide mutex would be the
 easiest.

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