Samba debug

[Andreas Schneider]

On Tuesday, 6 December 2016 07:14:21 CET Martin Schwenke wrote:
> On Mon, 28 Nov 2016 10:47:27 +0100, Andreas Schneider <asn at samba.org>
> 
> wrote:
> > On Monday, 28 November 2016 15:08:50 CET Martin Schwenke wrote:
> > > Amitay and I are in the process of moving to (more directly) use
> > > Samba's debug support.  At the moment we are doing file and syslog
> > > logging using CTDB's own backends, which are hooked into debug.[ch]
> > > using the DEBUG_CALLBACK support.
> > 
> > Hey Martin,
> > 
> > 
> > thanks for looking into this mess!
> > 
> > > We have come across (at least!) a couple of idiosyncrasies in
> > > debug.[ch]...  :-)
> > > 
> > > * Headers and messages can be interleaved in file logging
> > > 
> > >   Header and message are written using 2 separate write() calls (via
> > >   dbghdrclass(), dbgtext()). So, if 2 processes are writing to the same
> > >   log file, then you can get <header1>, <header2>, <message1>,
> > >   <message2>... or other variations.
> > >   
> > >   This could be improved if the above 2 functions added to the buffer
> > >   and a single write() was then used.
> > > 
> > > * When logging to syslog, header information is duplicated
> > > 
> > >   That is the date and time (and maybe PID, progname), are present in
> > >   the output of dbghdrclass() and syslog adds them as well.
> > >   
> > >   All the backends other than file (syslog, systemd, lttng,
> > >   GPFS) probably add their own timestamps.
> > >   
> > >   This could be improved by having dbghdrclass() omit these items and
> > >   have the file backend add those that are configured.
> > > 
> > > For CTDB logging we only really want single-line messages, with an
> > > appropriate non-redundant header.  For file we want a header
> > > (date, time, progname, pid).  For syslog we want to send just a bare
> > > message and have syslog do the rest.
> > > 
> > > Suggestions?  Ideas?  :-)
> > 
> > Please take a look into the options:
> > 	debug prefix timestamp
> > 	timestamp logs
> > 
> > They are related and are totally broken.
> 
> Well, I don't think they're totally broken.  If you read the
> documentation very carefully then "debug prefix timestamp" does what it
> says!
> 
> However, there should really be 3 options:
> 
>   debug location        = Add the file location
>   debug function        = Add the function name
>   debug header prefix   = Don't add a newline after header
> 
> This is all somewhat broken for non-file output, since the header and
> text are logged via separate calls to the backend.

That's what I meant. Some time ago I needed the addional header on stdout and 
well, no chance to get it ...

> I have a branch
> that could fix this, since I've pushed logging of the header into the
> backend.  However, at the moment I still use a separate call for
> the header.  This essentially makes DEBUG_ADD() useless, since it
> prints the last header that was produced - however, at least no time is
> taken to generate the extra header right now.
> 
> > The suggestion I have is that we need tests for the debug system. We have
> > features which do not work and nobody notices.
> > 
> > Testing debug is possible using the Mock object [1][2] support in cmocka
> > [3].
> I agree and will look into it.  However, I don't have an endless bucket
> of time for this.  One problem is that I doubt testing would have
> caught either of the issues I listed above!  ;-)

I think it would, we would have noticed that logging the header to stdout 
wouldn't work if you turn it on :)

However with cmocka and mocking you can mock the fprintf call (or whatever is 
used to put it into a file or stdout) and check that it works correctly :)

If you need help, let me know.


	Andreas


-- 
Andreas Schneider                   GPG-ID: CC014E3D
Samba Team                             asn at samba.org
www.samba.org