Re: [boost] A meta-proposal for logging

From: Greer, Joe (jgreer_at_[hidden])
Date: 2007-04-05 09:13:50

> -----Original Message-----
> From: boost-bounces_at_[hidden]
[mailto:boost-bounces_at_[hidden]]
> On Behalf Of Richard Day
> 
> Simple examples.
> 
> DBG_LOG( "Null pointer we are now dying a hard death" );
> vs
> logger << CLASS_WARNING << "File not found : " << filename << endl;
> 
> With two completely different in many respects requirements satisfying
> everyones needs is the issue.
> 
[Joe] I agree.  In fact, in the system I currently use, my usage pattern
is a hybrid.  My log messages look something like:

CDBG(TRACE, "network") << "Some network related message." << endl;

Where the macro invokes some tests to see if that message is desired
before evaluating the rest of it.  i.e. it would expand to:

If (!isLoggingDesired(TRACE,"network")) {} else logger

Some other ramblings I have about the system I put together for use here
at work are...

We write services that run 24/7 and want the log messages continually
available to be written, so I put together the following system. The
system is channel centric.  Each channel has associated with it zero or
more appenders (sinks); a formatter which formats messages for the
channel; and a mechanism for determining if a message is desired.  The
macro (briefly described above) gathers up information associated with
the log message, tests to see if the message should see the light of
day, and if it should then constructs the message and passes it to the
channel to be formatted and dumped out.  All pretty normal stuff.

The things I wished we could do with it are:

We have a format that gets associated with each log.  The formatter is
currently constructed using a stream-like syntax which looks something
like:

nsi::logging::CLogger::Instance()->GetFormatter() << L"[" <<
nsi::logging::Channel << L"](" << nsi::logging::ThreadId << L") " <<
nsi::logging::Time(L"%y%m%d %H:%M:%S") << L" " <<
nsi::logging::FunctionName << L": " << nsi::logging::Msg <<
nsi::logging::fmtendl;

At the time, I thought this was pretty cool.  The above basically puts
out the name of the channel surrounded by square brackets, followed by
the thread id surrounded in parenthesis, then a timestamp in strftime
format, the name of the function containing the log message
(__FUNCTION__ in vc8), then the message.  There are other things that I
made available to go in here, but this is what we generally used.  This
was very convenient because we then didn't have to specify the normal
stuff for each log message and it made centralized control of the
information we wanted for each log messages possible.  What I found
though is that it is hard to change that format via a configuration file
without recompiling things. I really wish I had gone ahead and made a
format string for this so I could just pass in a string like
"[%Chnl][%TID] %y%m%d%H%M%S %FNC: %Msg", then this could have been
changed in a configuration file.  I've been thinking that it would
probably be possible to set up a mechanism for registering a string
token with the system and a functor to provide the formatting such that
this could be changed by users of the logging system.  I have also
wanted to be able to have different information with different sinks.
For example, to the OutputDebug log, I could get rid of the timestamp,
but in a file I would want almost all available information since that
is more likely to be used in a postmortem situation.

The other conclusion I came to was that I probably would replace the
channel concept with a more generalized keyword filter.  That is, in the
above situation, the text in the macro selected the channel to be used.
What I found in our use was that the channel wasn't really used for
anything except selecting which messages were to be displayed.  We
never, for example, wanted "network" messages going to one file and
"fileio" messages going to a different one.  That meant we had an awful
lot of mechanism for what basically boiled down to a filter.  Today, I
would probably just treat the name as a keyword and filter based on the
keywords that were selected and allow more than one logger to co-exist
for the purpose of having different messages going to different sinks,
though we never really needed that.

Anyway, that is the experiences we had with the system I wrote.  The
thing I want to push for as a writer of services is the ability to
easily change things while the system is running.  I realize this would
require some hooks that would need executed periodically, to see if
things changed, but don't do anything to prevent this.

joe