Passing information to printf like functions

[hg]

I have a function called logprintf that take a printf-like syntax.
On top of that I want to implement a debug-printf function which calls
logprintf but prefix the information using a string:

void _dbglogprintf(const char *szFormat, ...)
{
char szOutput[4096];
va_list arglist;

sprintf(szOutput, "DEBUG: ");

va_start(arglist, szFormat);
vsprintf(szOutput + strlen(szOutput), szFormat, arglist);
va_end(arglist);

logprintf(szOutput);
}

The following works but will obviously cause a buffer overflow when
the string becomes too long.
I want to avoid such problems.
However the obstacle is that logprintf must be called only once since
it prints out information such as time-stamps. If it would be called
twice it would duplicate this information without any good reason.
However I couldn't see if there is a function which allows me to take
the existing arglist and combine it with my own strings.

Thanks.

-- Henrik

 

[Gianni Mariani]

However I couldn't see if there is a function which allows me to take
the existing arglist and combine it with my own strings.

There is a vsnprintf method.

The problems you cite are one reason why the C++ stream methods are what
they are. The logging interfaces that I have used more recently have
moved totally away from the printf.

A little off topic is another chunk of advice. I have found that the
format of the log information should not be embedded throughout the
application code - it makes it much harder to implement automated log
management tools. The Austria C++ logging interface does things
differently. This is what a typical "log" looks like:


AT_STARTLOG( l_lm, l_loglevel, AT_LOGLEVEL_SEVERE,"SomeDescription" )
at_log("Some Variable") << 55 << 123.456;
at_log("Some Other Variable") << "YUP";
AT_ENDLOG

-or-

AT_LOG( l_lm, l_loglevel, AT_LOGLEVEL_SEVERE,"SomeDescription" )

Yes, AT_STARTLOG and AT_ENDLOG are macros, there are reasons why it
makes sense to do that too. In a large body of code using the logging
interface, you want to catch problems with mis-use - the macros make it
easy to do that.

OK - notice that the "at_log" object is local to the body of code
between AT_STARTLOG and AT_ENDLOG. This means you can place any complex
information processing inside the log block and not pay the penalty
otherwise.

I'll stop the rave there... If you can drop the printf model for
logging, drop it now !

 

[James Kanze]

(e-mail address removed) wrote:

There is a vsnprintf method.

The problems you cite are one reason why the C++ stream
methods are what they are. The logging interfaces that I have
used more recently have moved totally away from the printf.

Drop the recently, and that corresponds to my experience as
well. The rare cases which did try to use a printf like log
always ended up in trouble. The iostream idiom, on the other
hand, while sometimes a little awkward for some types of
formatting (e.g. tables), is perfect for logs.

A little off topic is another chunk of advice. I have found
that the format of the log information should not be embedded
throughout the application code - it makes it much harder to
implement automated log management tools.

By this, I presume you mean that if it is embedded through the
application code, the format won't be identical everywhere, so
automated tools won't be able to handle it.

In my own work (using the ostream model, of course), the actual
formatting is usually handled by a filtering streambuf. Done
correctly, this can allow different formatting for different
destinations (email, syslog, a file, etc.). More importantly,
it allows multiple destinations, and can ensure synchronization.

The Austria C++ logging interface does things
differently. This is what a typical "log" looks like:

AT_STARTLOG( l_lm, l_loglevel, AT_LOGLEVEL_SEVERE,"SomeDescription" )
at_log("Some Variable") << 55 << 123.456;
at_log("Some Other Variable") << "YUP";
AT_ENDLOG

AT_LOG( l_lm, l_loglevel, AT_LOGLEVEL_SEVERE,"SomeDescription" )

Yes, AT_STARTLOG and AT_ENDLOG are macros, there are reasons
why it makes sense to do that too.

If for no other reason that you want to automatically make
__FILE__ and __LINE__ available to the logger.

I'm not sure I like the block, though. I use something like:

LOG( severity ) << ...

My experience has been that the more the programmer has to write
to log something, the less will be logged, so I try to keep it
as simple as possible.

In a large body of code using the logging interface, you want
to catch problems with mis-use - the macros make it easy to do
that.

OK - notice that the "at_log" object is local to the body of
code between AT_STARTLOG and AT_ENDLOG. This means you can
place any complex information processing inside the log block
and not pay the penalty otherwise.

The AT_STARTLOG macro contains an "if () {"?

I'm generally very opposed to macros modifying syntax, but I
sort of like this idea. I'll have to check if I can configure
my editor to recognize the strings as opening and closing
blocks, however, so that it will indent correctly.

In practice, I've not had any real problems with my idiom,
above. The operator<< are called for each argument, but they
are inline, and don't do anything if logging is not active, so
in practice, all it means is that I get three or four tests of
the variable, rather than only one. (It also means that if the
programmer outputs complicated expressions in the log, then
these are evaluated. It's been my experience that they don't.)

 

[Gianni Mariani]

By this, I presume you mean that if it is embedded through the
application code, the format won't be identical everywhere, so
automated tools won't be able to handle it.

In my own work (using the ostream model, of course), the actual
formatting is usually handled by a filtering streambuf. Done
correctly, this can allow different formatting for different
destinations (email, syslog, a file, etc.). More importantly,
it allows multiple destinations, and can ensure synchronization.

Yes - exactly.

If for no other reason that you want to automatically make
__FILE__ and __LINE__ available to the logger.

I'm not sure I like the block, though. I use something like:

LOG( severity ) << ...

The AT_STARTLOG macro is an if that can be used to eliminate whole
levels of logging code - which removes the whole - "I don't like to do
logging because it slows down the code" issue from the discussion.

My experience has been that the more the programmer has to write
to log something, the less will be logged, so I try to keep it
as simple as possible.

If it's a cut-n-paste mostly, then it's not an issue.

The first time I did the logging interface we did something like:

STARTLOG( ... ) { at_log("A") << aval; }

The problem was the carelessness of the "}" - it was prone to looking
like regular code. We never ever had an issue with that in the
STARTLOG/ENDLOG paradigm.

The AT_STARTLOG macro contains an "if () {"?

I'm generally very opposed to macros modifying syntax, but I
sort of like this idea. I'll have to check if I can configure
my editor to recognize the strings as opening and closing
blocks, however, so that it will indent correctly.

In practice, I've not had any real problems with my idiom,
above. The operator<< are called for each argument, but they
are inline, and don't do anything if logging is not active, so
in practice, all it means is that I get three or four tests of
the variable, rather than only one. (It also means that if the
programmer outputs complicated expressions in the log, then
these are evaluated. It's been my experience that they don't.)

Best

 

[James Kanze]

The AT_STARTLOG macro is an if that can be used to eliminate
whole levels of logging code - which removes the whole - "I
don't like to do logging because it slows down the code" issue
from the discussion.

That's more or less what I figured.

My own measurements suggest that if the code invoked in the LOG
macro is written carefully, the performance of my version, when
logging is disabled, is not a problem. It resolves to three or
four tests of a boolean, rather than one, but in most contexts,
that's really not worth mentionning. In reality, of course...in
practice, you often have to argue about hypothetical performance
problems in order to get it accepted, and more than once in the
past, I've had to do something like:

LOG( severity, "text" << value ... ) ;

; logging was only "acceptable" if it were possible to compile
it completely out, in order to guarantee 0 overhead. (There are
probably applications where that approach is justified, but I've
never worked on one.)

If it's a cut-n-paste mostly, then it's not an issue.

It has been for some programmers I've worked with, in the past.

The first time I did the logging interface we did something like:

STARTLOG( ... ) { at_log("A") << aval; }

The problem was the carelessness of the "}" - it was prone to
looking like regular code. We never ever had an issue with
that in the STARTLOG/ENDLOG paradigm.

I agree that your current situation seems better. In some ways,
I almost prefer it to mine. But I've had problems getting even
mine to be used, because it's "too much extra typing".

(Part of the problem might be that in the past, we've never
standardized on an editor. Here, everyone uses either emacs or
vim---perhaps offering configurations for the two which give a
hot key to insert the framework would make it more acceptable.
In the past, however, there have been too many different
editors in use, some not nearly as configurable as emacs or
vim.)