[PATCH] debug: Add minimalist D_* macros

[Martin Schwenke]

On Mon, 5 Dec 2016 10:32:22 -0700, Christof Schmitt <cs at samba.org>
wrote:

> On Mon, Dec 05, 2016 at 12:06:08PM +1100, Amitay Isaacs wrote:
> > On Thu, Dec 1, 2016 at 3:57 PM, Martin Schwenke <martin at meltin.net> wrote:
> >   
> > > These don't include the function name or any other header.
> > >
> > > Please review and maybe push...
> > >
> > > peace & happiness,
> > > martin
> > >  
> > 
> > Since no one has NACKed it, pushed to autobuild. :-)  
> 
> I am probably late to this, but could you explain the intended use a bit?
> 
> My thoughts: In the past the preference was to always include the
> function name in each message, that was the reason for adding it to the
> DBG_* macros. Is the preference now (for ctdb?) to not have the function
> names in each message?

Summary: for many state change messages, as opposed to low-level
debugging messages, the location information adds clutter rather than
adding useful information.

At the moment the default debug level in CTDB is NOTICE.  We print a
bunch of state-change messages that tell us what CTDB is doing.  For
those we really don't need to know where it is in the code.

I think it comes down to there being 2 types of things you want to
debug:

1. Bugs in the program (smbd, CTDB) itself.

2. System issues (cluster filesystem, communication, overload, ...).

So, I think what the location information is useful for diagnosing (1),
it ends up cluttering the logs when you're trying to do (2).

In CTDB we end up doing a lot of (2) (and expect people running CTDB to
be able to do some of that too).  Sometimes we need (1) as well.  I
can imagine that CTDB will end up using both types of macros, provided
we can fix problems (see below).

The other thing is that we do different kinds of logging for some
subprocesses.  We're only now getting to the stage where we can
initialise logging in a long-lived subprocess and avoid all of the
debug going through the main ctdbd process.  That is, we're going to
have multiple processes logging directly to file/syslog.

However, in some short-lived processes we don't want to add the
overhead of setting up a connection to a socket.  It is better for
those to log to stderr and have the parent process capture the output.
Until now we've avoided DEBUG() in some of those.  However, with
minimalist macros like D_ERR() and D_NOTICE() available, it makes more
sense to use debugging macros instead of rolling our own solution to get
messages to stderr.

Almost finally, we're writing a lot of new code right now and wanted to
use non-baroque macros (i.e. not DEBUG(DEBUG_ERR, ("foo %s\n", bar()));)
in the new code.  So, we wanted something basic right now so we could
get on with writing the important code and get back out of the logging
business.  Being in the logging business isn't productive...  unless
you're in the logging business...  :-)

> My preference would be to have one set of entry points into the debug
> code, and use those consistently through Samba. If we want to support
> both styles (with and without function name prefix), then this could
> become a config option for debug.c or it could be hardcoded for each
> backend.

Yeah, true.

However, another problem is that the DBG_PREFIX() uses 3 writes to log
(header, function, text), increasing the chance of file-logged
messages being split.  That's no reason to add another entry point but
it is going to be hard to fix the DBG_*() macros without simply
dropping DBG_PREFIX().

As I've just (finally) replied to Andreas:

  > 	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

I'm not sure our users want that level of complexity, though.

I think we need to distinguish between what our users need to see when
something goes wrong and what we, as developers, need for debugging...

peace & happiness,
martin