John Peacock wrote:
> Branko Čibej wrote:
>
>> The first mistake everybody seems to make is to forget that parameter
>> evaluation takes time, so they put debug level checks into the
>> logging functions themselves. You wouldn't _balieve_ the kind of
>> slowdown this can cause.
>
>
> Could you elaborate on this a little? I'm not sure I know what you
> are referring to.
>
> I believe there are two major ways to structure log code (ignoring
> compile-time #ifdef):
>
> 1) Anywhere you want to log something, call a common log routine with
> a log type (error, info, and debug) and a message; the log routine the
> decides what to send where;
>
> 2) Anywhere you want to log something, call a specific routine for the
> type of log message;
>
> In both cases, the call to the logger routine should be wrapped by a
> check against a global loglevel variable.
>
> if ( loglevel > 0 ) /* log everything */ {log_this(DEBUG,"message")}
> if ( loglevel == 1 ) /* log info only */ {log_this(INFO,"message")}
>
> Is this last point what you were worried about? Some of that could
> even be hidden by a macro.
>
> I would prefer to use the 1st mode above, as it makes for a slightly
> cleaner interface and makes it much easier to have a single output
> stream (if so desired).
Now you're scaring me. I wrote two logging libraries for in-house use,
and it seems that you're just starting to struggle with the basics. :-)
The first most common mistake is to do this:<>
<><> void logger(int level, const char *format, ...) {
if (level > global_log_level)
/* do your stuff */
}
<><><>The reason why this is a problem is that the message parameters
are evaluated at the point of call, regardless of the value of
global_log_level. This is clearly bad.
As you noted correctly, the log level check must be done at the call
point, in such a way that you avoid evaluating the parameters. If you
have a printf-like logger, as above, and don't have C99 with vararg
macros, you usually do something like this:
void logger (const char *format, ...);
#define LOG(lvl, args) \
((lvl) > global_log_level ? logger args : (void)0)
//...
LOG(INFO, ("this is number %d", some_expensive_function()));
This will avoid calling some_expensive_function if the INFO level isn't
turned on, but will incur the cost of reading from the global variable
if you do it often (and I believe compilers typically won't store the
value in a register).
You can avoid _that_ cost by adding a LOG_INIT macro that copies the
global value to the stack, e..g,
#define LOG_INIT() const int local_log_level = global_log_level
You then put LOG_INIT at the start of each function, and use
local_log_level in the LOG macro.
Things become more interesting when you want to also trace function
execution. I can show you an example of how that's done efficiently, but
that's really not _that_ important for svnserve.
All in all, I'd prefer to go with a mature library like log4c because it
gives us lots of control over the output format, output location,
logging levels, and such. Pulling the logging logic out of httpd and
dumping it into APR(-util?) may be appropriate, although probably less
flexible.
-- Brane
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@subversion.tigris.org
For additional commands, e-mail: dev-help@subversion.tigris.org
Received on Tue May 18 23:47:00 2004