RE: [boost] Logging Library -- Formal Review Request

John Torjo wrote:
I've just updated the Boost Log Library: http://torjo.com/code/logging-v132.zip
I would also like to ask for a _Formal Review_.
The Boost Log Library is a small library, who: * makes it very easy to declare/define new logs * allows you very simple access to logs * allows for log hierarchies, and for modifying log hierarchies * allows for easy and efficient enabling/disabling of logs/log hierarchies * allows for easy manipulation of log behaviors (the log's destination(s) and/or adjusting the original message) * is thread-safe
Using the library in code is easy and straightforward:
int i = 1, j = 2, k = 3; BOOST_LOG(app) << "testing " << i << '-' << j << '-' << k << std::endl; BOOST_LOG(dbg) << "this is a debug message, i=" << i << std::endl; BOOST_LOG(info) << "I just wanted to tell you something....";
Hi. If I understand right the code, even if log is disabled, I do pay for constructing log messages. Am I right? If so why do you force this? Roman

Hi. If I understand right the code, even if log is disabled, I do pay for constructing log messages. Am I right? If so why do you force this?
No, you donot pay. BOOST_LOG(app) << "testing " << i << '-' << j << '-' << k; Is the equivalent of: if ( is_log_enabled(app) ) app_log() << "testing" << i ...; Best, John -- John Torjo, Contributing editor, C/C++ Users Journal -- "Win32 GUI Generics" -- generics & GUI do mix, after all -- http://www.torjo.com/win32gui/ -v1.6.3 (Resource Splitter) -- http://www.torjo.com/cb/ - Click, Build, Run!

At Monday 2005-04-25 09:47, you wrote:
Hi. If I understand right the code, even if log is disabled, I do pay for constructing log messages. Am I right? If so why do you force this?
No, you donot pay.
BOOST_LOG(app) << "testing " << i << '-' << j << '-' << k;
Is the equivalent of:
if ( is_log_enabled(app) ) app_log() << "testing" << i ...;
don't you think you'd better make it if(!is_log_enabled(app));else app_log() << "testing" << i ...; just in case there is an if / else in the neighborhood
Best, John
-- John Torjo, Contributing editor, C/C++ Users Journal -- "Win32 GUI Generics" -- generics & GUI do mix, after all -- http://www.torjo.com/win32gui/ -v1.6.3 (Resource Splitter) -- http://www.torjo.com/cb/ - Click, Build, Run!
_______________________________________________ Unsubscribe & other changes: http://lists.boost.org/mailman/listinfo.cgi/boost
Victor A. Wagner Jr. http://rudbek.com The five most dangerous words in the English language: "There oughta be a law"

On 4/25/05, Victor A. Wagner Jr. <vawjr@rudbek.com> wrote:
don't you think you'd better make it if(!is_log_enabled(app));else app_log() << "testing" << i ...; just in case there is an if / else in the neighborhood
It is already implemented as you suggest. FWIW, I always thought the "right" way to do multi-line macros was to use do { /* stuff */ } while (0). I picked this up from the comp.lang.c FAQ if memory serves (http://www.eskimo.com/~scs/C-faq/q10.4.html) -- Caleb Epstein caleb dot epstein at gmail dot com

Caleb Epstein wrote:
On 4/25/05, Victor A. Wagner Jr. <vawjr@rudbek.com> wrote:
don't you think you'd better make it if(!is_log_enabled(app));else app_log() << "testing" << i ...; just in case there is an if / else in the neighborhood
It is already implemented as you suggest. FWIW, I always thought the "right" way to do multi-line macros was to use do { /* stuff */ } while (0). I picked this up from the comp.lang.c FAQ if memory serves (http://www.eskimo.com/~scs/C-faq/q10.4.html)
Yeah, but in C++ the idiom is different: "do { /* stuff */ } while (false)". :o) Now seriously, I'm sure you meant "statements in sequence", not "multi-line". Andrei P.S. Thanks for the help with flex_string, Caleb.

if ( is_log_enabled(app) ) app_log() << "testing" << i ...;
don't you think you'd better make it if(!is_log_enabled(app));else app_log() << "testing" << i ...; just in case there is an if / else in the neighborhood
Actually, that's exactly how it's done :) I was just explaining the concept. Best, John -- John Torjo, Contributing editor, C/C++ Users Journal -- "Win32 GUI Generics" -- generics & GUI do mix, after all -- http://www.torjo.com/win32gui/ -v1.6.3 (Resource Splitter) -- http://www.torjo.com/cb/ - Click, Build, Run!

John Torjo wrote:
Hi. If I understand right the code, even if log is disabled, I do pay for constructing log messages. Am I right? If so why do you force this?
No, you donot pay.
BOOST_LOG(app) << "testing " << i << '-' << j << '-' << k;
Is the equivalent of:
if ( is_log_enabled(app) ) app_log() << "testing" << i ...;
Hopefully the actual expansion uses a if/else statement so as to avoid wreaking havoc in calling code? if ( !is_log_enabled(app) ) ; else app_log() << "testing" << i ...; Andrei

John Torjo wrote:
Hi. If I understand right the code, even if log is disabled, I do pay for constructing log messages. Am I right? If so why do you force this?
No, you donot pay.
BOOST_LOG(app) << "testing " << i << '-' << j << '-' << k;
Is the equivalent of:
if ( is_log_enabled(app) ) app_log() << "testing" << i ...;
Best, John
Is it the case however that we'll have to pay the cost of evaluating whatever arguments are supplied (for example if some of them are function calls etc.)? As in: BOOST_LOG(app) << "testing " << fctn() << '-' << j << '-' << k; Will fctn() be called if !is_log_enabled(app)? Thanks, John

Is it the case however that we'll have to pay the cost of evaluating whatever arguments are supplied (for example if some of them are function calls etc.)?
As in:
BOOST_LOG(app) << "testing " << fctn() << '-' << j << '-' << k;
Will fctn() be called if !is_log_enabled(app)?
Nope, it will not be called. Best, John -- John Torjo, Contributing editor, C/C++ Users Journal -- "Win32 GUI Generics" -- generics & GUI do mix, after all -- http://www.torjo.com/win32gui/ -v1.6.3 (Resource Splitter) -- http://www.torjo.com/cb/ - Click, Build, Run!

Hi. If I understand right the code, even if log is disabled, I do pay for constructing log messages. Am I right? If so why do you force this?
No, you donot pay.
BOOST_LOG(app) << "testing " << i << '-' << j << '-' << k;
Is the equivalent of:
if ( is_log_enabled(app) ) app_log() << "testing" << i ...;
But it is still taking up space; not to mention CPU usage doing a run-time check to see if a log is enabled. I think it is very important that we can choose to build with all logging code removed. This has been discussed before, and I thought you were going to include an alternative macro, something like: BOOST_LOG(app,"testing " << i << '-' << j << '-' << k); (Would that compile? If so I think this should be the main macro, and the above format the alternative.) Darren

Darren Cook wrote:
Hi. If I understand right the code, even if log is disabled, I do pay for constructing log messages. Am I right? If so why do you force this?
No, you donot pay.
BOOST_LOG(app) << "testing " << i << '-' << j << '-' << k;
Is the equivalent of:
if ( is_log_enabled(app) ) app_log() << "testing" << i ...;
But it is still taking up space; not to mention CPU usage doing a run-time check to see if a log is enabled.
Depending on how the check is performed, the overhead is virtually nonexistent.
I think it is very important that we can choose to build with all logging code removed. This has been discussed before, and I thought you were going to include an alternative macro, something like: BOOST_LOG(app,"testing " << i << '-' << j << '-' << k);
Well, you can count my vote against this method. For you, the entire point of doing it this way is so that the logging can be compiled out - which, at least in my view, is a huge mistake. I have my opinions about the 'style' of this type of logging as well (where the entire streamed message is simply an 'argument' to a fictitious 'method') - as opposed to the proposed method which is certainly much more natural (in a stream << xxxx way). Having worked on quite a few large-scale commercial software products using an extensive logging framework for quite a few years now, I can attest that, short of embedded deployment, there is almost never a reason to compile out tracing code. It's far, far too important for debugging customer problems (where you can't just launch the debugger and snoop around). All you frequently have to diagnose a problem in the field are the log files. Logging isn't a nice to have, it's an absolute requirement.
(Would that compile? If so I think this should be the main macro, and the above format the alternative.)
I at least, strongly disagree - but you already knew that. :) I think the logging methods should be designed for the majority of the users. If the majority of the users believe they should always have diagnostic logging methods available to be turned on at any time during runtime, then the 'if (test) ; else stream' macro should be the 'standard' way of doing things. If the majority of users want the logging to just be there occasionally and see it only as a 'printf' alternative in debug builds as opposed to a diagnostic tool available at the flick of a switch, then by all means, the sometimes there, sometimes not, wrap it all in a single macro argument style should win out. Patrick Bennett

couldn't a macro disable code like: stream << a << b << c making operator << a "do nothing" function? I dont think it will have any overhead in the release code... maybe just for strings "of this type" that normally isnt optimized away... On 4/26/05, Patrick Bennett <patrick.bennett@inin.com> wrote:
Darren Cook wrote:
Hi. If I understand right the code, even if log is disabled, I do pay for constructing log messages. Am I right? If so why do you force this?
No, you donot pay.
BOOST_LOG(app) << "testing " << i << '-' << j << '-' << k;
Is the equivalent of:
if ( is_log_enabled(app) ) app_log() << "testing" << i ...;
But it is still taking up space; not to mention CPU usage doing a run-time check to see if a log is enabled.
Depending on how the check is performed, the overhead is virtually nonexistent.
I think it is very important that we can choose to build with all logging code removed. This has been discussed before, and I thought you were going to include an alternative macro, something like: BOOST_LOG(app,"testing " << i << '-' << j << '-' << k);
Well, you can count my vote against this method. For you, the entire point of doing it this way is so that the logging can be compiled out - which, at least in my view, is a huge mistake. I have my opinions about the 'style' of this type of logging as well (where the entire streamed message is simply an 'argument' to a fictitious 'method') - as opposed to the proposed method which is certainly much more natural (in a stream << xxxx way). Having worked on quite a few large-scale commercial software products using an extensive logging framework for quite a few years now, I can attest that, short of embedded deployment, there is almost never a reason to compile out tracing code. It's far, far too important for debugging customer problems (where you can't just launch the debugger and snoop around). All you frequently have to diagnose a problem in the field are the log files. Logging isn't a nice to have, it's an absolute requirement.
(Would that compile? If so I think this should be the main macro, and the above format the alternative.)
I at least, strongly disagree - but you already knew that. :) I think the logging methods should be designed for the majority of the users. If the majority of the users believe they should always have diagnostic logging methods available to be turned on at any time during runtime, then the 'if (test) ; else stream' macro should be the 'standard' way of doing things. If the majority of users want the logging to just be there occasionally and see it only as a 'printf' alternative in debug builds as opposed to a diagnostic tool available at the flick of a switch, then by all means, the sometimes there, sometimes not, wrap it all in a single macro argument style should win out.
Patrick Bennett
_______________________________________________ Unsubscribe & other changes: http://lists.boost.org/mailman/listinfo.cgi/boost
-- Felipe Magno de Almeida UIN: 2113442 email: felipe.almeida at ic unicamp br, felipe.m.almeida at gmail com, felipe at synergy com I am a C, modern C++, MFC, ODBC, Windows Services, MAPI developer from synergy, and Computer Science student from State University of Campinas(UNICAMP). To know more about: Unicamp: http://www.ic.unicamp.br Synergy: http://www.synergy.com.br current work: http://www.mintercept.com "There is no dark side of the moon really. Matter of fact it's all dark."

Felipe Magno de Almeida wrote:
couldn't a macro disable code like: stream << a << b << c making operator << a "do nothing" function? I dont think it will have any overhead in the release code... maybe just for strings "of this type" that normally isnt optimized away...
Could it completely 'remove' the code? Not that I know of. Although, there's no reason a decent compiler wouldn't detect something like this (which the macro could be changed into with a 'don't compile' compilation option) and not emit code for it. if (1) ; else someStream() << a << b << c; Patrick Bennett

I mean something like: #ifndef NDEBUG inline #endif log_stream &operator <<(log_stream &stream, int i) { #ifdef NDEBUG code that puts the int in the stream #endif return stream; } I dont see why a compiler would be passing the stream around, mainly with the operator being inline. That way we dont need to use macros in the client code, that makes the code a little ugly in my opinion... The only problem that I see is for: stream << "testing"; where at least in my compiler (VC7.1) these strings are shipped even when not used... for embedded systems these strings really get the code much bigger... As I've tried it with BREW... On 4/26/05, Patrick Bennett <patrick.bennett@inin.com> wrote:
Felipe Magno de Almeida wrote:
couldn't a macro disable code like: stream << a << b << c making operator << a "do nothing" function? I dont think it will have any overhead in the release code... maybe just for strings "of this type" that normally isnt optimized away...
Could it completely 'remove' the code? Not that I know of. Although, there's no reason a decent compiler wouldn't detect something like this (which the macro could be changed into with a 'don't compile' compilation option) and not emit code for it. if (1) ; else someStream() << a << b << c;
Patrick Bennett
_______________________________________________ Unsubscribe & other changes: http://lists.boost.org/mailman/listinfo.cgi/boost
-- Felipe Magno de Almeida UIN: 2113442 email: felipe.almeida at ic unicamp br, felipe.m.almeida at gmail com, felipe at synergy com I am a C, modern C++, MFC, ODBC, Windows Services, MAPI developer from synergy, and Computer Science student from State University of Campinas(UNICAMP). To know more about: Unicamp: http://www.ic.unicamp.br Synergy: http://www.synergy.com.br current work: http://www.mintercept.com "There is no dark side of the moon really. Matter of fact it's all dark."

Felipe Magno de Almeida wrote:
I mean something like:
#ifndef NDEBUG inline #endif log_stream &operator <<(log_stream &stream, int i) { #ifdef NDEBUG code that puts the int in the stream #endif return stream; } I dont see why a compiler would be passing the stream around, mainly with the operator being inline. That way we dont need to use macros in the client code, that makes the code a little ugly in my opinion... The only problem that I see is for: stream << "testing"; where at least in my compiler (VC7.1) these strings are shipped even when not used... for embedded systems these strings really get the code much bigger... As I've tried it with BREW...
And let's not forget: stream << long_computing_func(); Best, John -- John Torjo, Contributing editor, C/C++ Users Journal -- "Win32 GUI Generics" -- generics & GUI do mix, after all -- http://www.torjo.com/win32gui/ -v1.6.3 (Resource Splitter) -- http://www.torjo.com/cb/ - Click, Build, Run!

But it is still taking up space; not to mention CPU usage doing a run-time check to see if a log is enabled.
Depending on how the check is performed, the overhead is virtually nonexistent.
But still there :-).
BOOST_LOG(app,"testing " << i << '-' << j << '-' << k);
Well, you can count my vote against this method. For you, the entire point of doing it this way is so that the logging can be compiled out -
It is also slightly shorter. It seems just as natural to me.
Having worked on quite a few large-scale commercial software ... ...there is almost never a reason to compile out tracing code.
Yes, I usually leave in log lines on my large-scale commercial projects as well. But I want to have both: I want some log statements I can insert while debugging time-critical code and disable at compile time, and others that are always there but that I can choose to switch on and off at run-time. And I want both in the same project. Perhaps then BOOST_LOG_DBG() is a better name for the one that can be compiled out. Or BOOST_LOGD(). Darren

Perhaps then BOOST_LOG_DBG() is a better name for the one that can be compiled out. Or BOOST_LOGD().
Yup, Darren you're completely right. I will add this facility somewhere this week. I want to make it so you can twiggle from compile-time or run-time log, when you declare the log, like this: // tests with 'is_log_enabled()' BOOST_DECLARE_LOG(some_log). // in release mode, completely turned off BOOST_DECLARE_LOG_DBG(some_log). Best, John -- John Torjo, Contributing editor, C/C++ Users Journal -- "Win32 GUI Generics" -- generics & GUI do mix, after all -- http://www.torjo.com/win32gui/ -v1.6.3 (Resource Splitter) -- http://www.torjo.com/cb/ - Click, Build, Run!

Patrick Bennett writes:
Having worked on quite a few large-scale commercial software products using an extensive logging framework for quite a few years now, I can attest that, short of embedded deployment, there is almost never a reason to compile out tracing code.
Except for, when the tracing code comes with serious performance penalties. Then you really want to be able to compile a version with all the debugging and tracing statements removed. Peter

-----Original Message----- From: boost-bounces@lists.boost.org [mailto:boost-bounces@lists.boost.org] On Behalf Of Darren Cook Sent: Monday, April 25, 2005 7:03 PM To: boost@lists.boost.org Subject: Re: [boost] Logging Library -- Formal Review Request
Hi. If I understand right the code, even if log is disabled, I do pay for constructing log messages. Am I right? If so why do you force this?
No, you donot pay.
BOOST_LOG(app) << "testing " << i << '-' << j << '-' << k;
Is the equivalent of:
if ( is_log_enabled(app) ) app_log() << "testing" << i ...;
But it is still taking up space; not to mention CPU usage doing a run-time check to see if a log is enabled.
I'm a little late to the game but FWIW I agree with Darren, in our application we would like to log our bottleneck code, we cannot afford to pay for functions we don't use. In my own logging library I solved the problem by having both dynamic and static logging. In the static version the logging flags are defined and tested at compile time, if a particular logging statement is not activated based on the log flags it is completely eliminated. For dynamic logging the test is left because the log flags can be changed at runtime. The type of logging is selected by a macro. One approach to logging is to build two binaries for each release, the first has all logging turned off, this is the version that is installed on the customer's machine. The second has dynamic logging present, so that when we need to get a log report we can have the user run the second binary as a drop in replacement, with the appropriate flags passed as a parameter. It's not a perfect solution but it's the closest you can get to the best of both worlds- performance and good diagnostic information.

John Torjo wrote:
Hi. If I understand right the code, even if log is disabled, I do pay for constructing log messages. Am I right? If so why do you force this?
No, you donot pay.
BOOST_LOG(app) << "testing " << i << '-' << j << '-' << k;
Is the equivalent of:
if ( is_log_enabled(app) ) app_log() << "testing" << i ...;
And you need to 1. #include <something> 2. Compile the 'if', and the operators<<, and what not. Consider that I want to add logging to a header-only library, say some BGL. algorithm I don't want all users of BGL to depend on a logging library. They just should be able to #define BOOST_GRAPH_SOME_ALGORITH_LOGGING and get logging for the specified algorithm -- only if needed. - Volodya

And you need to
1. #include <something> 2. Compile the 'if', and the operators<<, and what not.
Consider that I want to add logging to a header-only library, say some BGL. algorithm I don't want all users of BGL to depend on a logging library. They just should be able to #define BOOST_GRAPH_SOME_ALGORITH_LOGGING and get logging for the specified algorithm -- only if needed.
See my other post to Darren. Is this what you mean? Best, John -- John Torjo, Contributing editor, C/C++ Users Journal -- "Win32 GUI Generics" -- generics & GUI do mix, after all -- http://www.torjo.com/win32gui/ -v1.6.3 (Resource Splitter) -- http://www.torjo.com/cb/ - Click, Build, Run!

John Torjo wrote:
I've just updated the Boost Log Library: http://torjo.com/code/logging-v132.zip
* How much effort did you put into your evaluation? I've only read the documentation, not tried the library (i have given a quick try to a previous version, but that was long ago). * What is your evaluation of the potential usefulness of the library? A logging library is a must have, just like a multi-threading and a windowing library, but i am afraid that developing a one size fits all logging library is not much simpler than doing so for these other two. This library is already much better than most i have seen, but it is not useful for me without several changes. * What is your evaluation of the documentation? It is too brief. * What is your evaluation of the design/implementation? I would like to see three components: - the viewer application on John's page should be officially part of the library, with the option of running it as a separate application/running it as a thread in the application being developed - the current libary should be split into a logging primitives (building blocks) part - and into several "..._style_log.hpp" interfaces, supporting the different styles and bells & whistles and different default settings people ask for My main concern about logging is that it changes application behaviour: often there are bugs that only surface in release code because logging is slow and it introduces synchronizing, so logging should be as fast as possible, and locks should be avoided whenever possible. My style would be: Appenders: do not cache and do not use a dedicated writer thread, but each thread automagically creates it's own separate logfile. The files are kept open, flushed after each log entry, and the streams used for formatting the log entries are kept and reused. The log files are created in a system-dependent directory (e.g. %TEMP% on windoze), and the logs from the previous run are removed automagically. Modifiers: a global counter prefix, an indenter and a clock (secs elapsed since application start); and source file name, line number postfix. I do not want to declare and define and initialize logs, just include a header, and then write "LOG << ..."; i do not want to give names to logfiles, and i don't want runtime configurable logs and log levels and multiline log entries and calling functions that log from inside "LOG << ..." statements and i do not want to pay (with runtime and additional typing) for the features i do not use. I think a lot of the current library functionality can be moved into the viewer: it can merge the per-thread logfiles or scatter log entries based on a prefix (thus no need for named logs and different threads writing the same file), it can calculate entry times from the file creation date and clock stamp (to avoid time- consuming date formatting modifiers) etc. Also, having indentation in the logs allows the viewer to display the log contents as a tree-view making log browsing much simpler. * Do you think the library should be accepted as a Boost library? Not yet, i would rather put a link and a strong suggestion to use it on the boost webpage, and include it in boost only after it has been used in several projects. br, andras

Hi Andras, Many thanks for the pre-evaluation!
* What is your evaluation of the documentation?
It is too brief.
Yes, indeed, I do need to provide more examples, usage scenarios, etc.
* What is your evaluation of the design/implementation?
I would like to see three components:
- the viewer application on John's page should be officially part of the library, with the option of running it as a separate application/running it as a thread in the application being developed
No problem there ;) However, you should note that at this time, the viewer application is Windows-only.
- the current libary should be split into a logging primitives (building blocks) part
- and into several "..._style_log.hpp" interfaces, supporting the different styles and bells & whistles and different default settings people ask for
This is an interesting idea. In the future, I want to ask people to provide me with different scenarios in which they use logging. This, based on how many such scenarios I find, could then end up into what you say.
My main concern about logging is that it changes application behaviour: often there are bugs that only surface in release code because logging is slow and it introduces synchronizing, so logging should be as fast as possible, and locks should be avoided whenever possible.
Locks are avoided whenever possible.
My style would be:
Appenders: do not cache and do not use a dedicated writer thread, but each thread automagically creates it's own separate logfile. The files are kept open, flushed after each log entry, and the streams used for formatting the log entries are kept and reused. The log files are created in a system-dependent directory (e.g. %TEMP% on windoze), and the logs from the previous run are removed automagically.
Modifiers: a global counter prefix, an indenter and a clock (secs elapsed since application start); and source file name, line number postfix.
I do not want to declare and define and initialize logs, just include a header, and then write "LOG << ..."; i do not want to give names to logfiles, and i don't want runtime configurable logs and log levels and multiline log entries and calling functions that log from inside "LOG << ..." statements and i do not want to pay (with runtime and additional typing) for the features i do not use.
Ok, so we could say we have the first scenario ;)
I think a lot of the current library functionality can be moved into the viewer: it can merge the per-thread logfiles or scatter log entries based on a prefix (thus no need for named logs and different threads writing the same file), it can calculate entry times from the file creation date and clock stamp (to avoid time- consuming date formatting modifiers) etc. Also, having indentation in the logs allows the viewer to display the log contents as a tree-view making log browsing much simpler.
Yes, that's the reason I created the viewer. However, I made the logging library flexible (or at least I hope so :)), so users can tweak the lib to their needs.Logging can be so much more that writing to one file.
* Do you think the library should be accepted as a Boost library?
Not yet, i would rather put a link and a strong suggestion to use it on the boost webpage, and include it in boost only after it has been used in several projects.
Sure thing ;) Note that I have used in in a quite a few projects (more than 6, I think; from which 2 projects were quite large), and have received (private) feedback from other people who have successfully used it in their apps. Best, John -- John Torjo, Contributing editor, C/C++ Users Journal -- "Win32 GUI Generics" -- generics & GUI do mix, after all -- http://www.torjo.com/win32gui/ -v1.6.3 (Resource Splitter) -- http://www.torjo.com/cb/ - Click, Build, Run!
participants (13)
-
Andras Erdei
-
Andrei Alexandrescu (See Website For Email)
-
Caleb Epstein
-
Darren Cook
-
Felipe Magno de Almeida
-
John Eddy
-
John Torjo
-
Patrick Bennett
-
Peter Simons
-
Roman Yakovenko
-
Terence Wilson
-
Victor A. Wagner Jr.
-
Vladimir Prus