Re: [boost] Proposal: Logging library

From: Andras Erdei (ccg_at_[hidden])
Date: 2002-04-09 09:00:57

On Tue, 09 Apr 2002 12:31:08 +0200, Markus Schöpflin <markus.schoepflin_at_[hidden]> wrote:

>> IMHO levels are the worst solution. Usually i want things like
>> "get all error messages, but get the warnings only from two modules".
>> There are two independent criteria for enabling/disabling a message:
>> the type and the source of the message. The other problem is that
>> everyone wants different levels, and uses the painfully agreed-on
>> levels differently.

>I agree with your classification of type and source but I think
>that support for predefined levels is a must.

We have once spent almost a month arguing about how many and
which levels we should use (info, diagnostics, warning, error,
fatal etc.), and in the end no one was happy with the result,
so i suspect this'll be even harder here on Boost.

The solution could be to get rid of _predefined_ levels --
why do we have to have them ?

I've played around for years with an almost-level like 
diagnostics library (actually used a bitmap to determine
which messages get through: & instead of <), but i was
never satisfied with it.

OTOH i might be using logging differently than most people;
i haven't fired up my debugger for years, and use the
diagnostics on-the-fly rather than for post-mortem debugging.

>> What i'm contemplating right now is basing the filtering on pattern
>> matching. There is an "enable" filter -- a list of patterns, like
>> ["^WARNING TCPIP *", "^WARNING INTERPRET *unknown*" , "^ERROR *" ];
>> a message not matching any of the patterns on the enable list is ignored.
>> Of course if you tend to be terse, you can use [ "^WT*" , "^WI*unknown*" ,
>>  "^E*" ] or whatever you prefer instead, and start your messages with
>> a single letter indicating the "level" of the message.
>> There is also a "disable" filter -- again a list of patterns which
>> can be used to get rid of some of the messages making it through the
>> enable filter. (In theory a single regexp is sufficient but that
>> would be cumbersome.)

>Interesting. How do you generate the log messages? A simple
>log("WARNING TCPIP whatever")? 

That's how i use it; of course anyone preferring it can
roll his/her own WARNING(), INFO() etc macro, or wrap the
diagnostic interface up in a macro having an additional
parameter. It can even be standard/predefined, but should
be in a separate header. (Why hard-wire it into the 
diagnostics library if we don't have to ?)

In fact i'm planning to have the following macros:

IES_TRACE_FUNCTION

generates an object, whose ctor/dtor changes the indent
level in the log file, creates a new sub-branch in the
tree-view, and logs the function name, source file, 
line # and a timestamp

IES_TRACE_MEMBER

the same for member-functions (also logs the this pointer)

IES_TRACE_BLOCK << p
IES_TRACE_MBLOCK << p

same as the above two, but used for nested scopes (and
VC++, which doesn't have __func__); the only difference
is that these don't display the function name, and usualy 
have an agument -- some mnemonic for the block we are about 
to enter, but can also be used to dump out arguments/locals etc

IES_TRACE_REPORT << p

the actual log macro

For each macro there is a short form (e.g. REPORT instead
of IES_TRACE_REPORT), and i usually use those.

Example:

  void
f( void )
  { FUNCTION ;

    REPORT << "inside f()..." ;

    { BLOCK << "entering a new scope" ;

      REPORT << "some embedded processing" ;

    }   
 
  } // f()

The logs go sequentally into the log file, but in reverse
order into the tree-view (so the most recent messages are
always at the top); easier (and faster) to navigate, but 
requires a bit practice to read logs backwards.

There are three additional macros, IES_TRACE_TRACE( i )
which compiles i in only during debugging (i use it
for profiling, e.g. counting how many times a fn was invoked),
IES_TRACE_TRACED( d ), for declarations, and IES_TRACE_DEBUG,
which pops up a message box besides writing into the log,
and asks whether it should start the debugger (never used it).

Additionally, there is an IES_TRACE_REQUIRES/INVARIANT/ENSURES( c )
for checking pre/post conditions and ivariants, they behave like
assert().

>> What i don't know is whether a full-regexp matching is preferable
>> (with all the speed consequences) or a simple wild-card matching
>> ('*' and '?'/'.').

>Don't you think there is still too much of a speed penalty for using
>a pattern matching algorithm? Especially if you think about multiple
>sinks, and each sink using a different setting of filters.

A simple wildcard (like the one used for filenames) match should 
not be a problem, it can be hand-coded, and will be about as
fast as a strcmp(); the actual i/o will take much more time.

Sinks: Actually i'm only filtering messages which are displayed
real time, in the tree-view. One reason is that the M$ tree-view
implementation goes to a virtual halt if you have a few thousand
entries, the other one is that even in the tree-view it becomes
hard to navigate with that amount of messages. (Actually if right
click on a branch, it gets purged, and that's one of the most 
frequently used functionality in it :O) The log files always
have all the messages, as i'm only browsing those using tools
(grep, my editor) which make it manageable even if it's a few
megabytes.

The diagnostics lib currently in development has separate macros 
for logs which remain in the development code -- those most likely 
again won't have any filtering (and they will only go into a 
round-robin memory buffer when not debugging, and go to a file
ony when the program terminates). Essentially the filtering will 
be done by deciding which macro is used for generating the message. 
(I don't know whether this'll be sufficient, as i haven't used this before.)

br,
andras