John Torjo <john.lists <at> torjo.com> writes:

How about std::ostream ;) ?

Seriously, depending on your application, you can have so many possibilities to implement logging using std::ostream streams. For instance, you can implement thread-safety in less than 80 lines of code.

Why is there no standard idiom for thread-safe access to an ostream? Are there any caveats to the use of streams with this protection? Matt

From: "Neal D. Becker" <ndbecker2@verizon.net>

John Torjo wrote:

...

Neal D. Becker wrote:

...

I notice boost doesn't have a logging library. I have seen several floating around. Are there any recommendations?

How about std::ostream ;) ?

Also, disabling writing to a stream is fairly easy, by setting the failbit of a stream object: out.setstate( std::ios::failbit); // nothing gets written to this log any more

Interesting idea. I would like the overhead of disabled loggers to be relatively small. Would you think this technique might be useful in that case? (Of course, relatively small is a relative term).

Every insertion and every mf you call on the stream must occur and must check the failbit flag. It would, therefore, have noticeable overhead. Is it a problem? Maybe. You could time an app with the logging compiled away (via preprocessor) and with the failbit set. -- Rob Stewart stewart@sig.com Software Engineer http://www.sig.com Susquehanna International Group, LLP using std::disclaimer;

I think it's the wrong approach. In our company we have implemented logging through macros which has one very important property: When I write

LOG_DEBUG( whatever() );

I have a macro like this: std::ostream *logfile=&std::cout; //Go to screen if not set #define LOG(expr) \ *logfile<<"\n"<<BOOST_CURRENT_FUNCTION<<":"<<__LINE__<<":\n"<<expr // To disable logging: //#define LOG(expr) (void(0)) I can then use like this: LOG("e="<<e<<", data:"<<*p); The problem comes when I have a function that takes an ostream; then I have to expose the internals: LOG("Here is data:");LOG(obj->debug_info(*logfile,true,false)); Is there a better way? Darren

Thanks for the reply. I think your solution solves different problems (conditional inclusion; not including streamed data as macro parameter). Having read other messages in this thread I think I should pass a 2nd param to the LOG macro: an identifier that returns the ostream to use. But next time I need logging I'll probably try one of the log4J projects mentioned. Darren

...

The problem comes when I have a function that takes an ostream; then I have to expose the internals:

LOG("Here is data:");LOG(obj->debug_info(*logfile,true,false));

Is there a better way?

Yes, #define SOME_LOG_MACRO( MiscParams) \ if ( ! ShouldLog( MiscParams) ) \ { /* Don't execute, or log anything */ \ } \ else /* create something that returns an ostream& derived instance */ (MiscParams).GetStream ()

You can then use: SOME_LOG_MACRO( xxx) << "foo:" << foo << " bar:" << bar; and it will only execute the << methods if logging is enabled, or if it's necessary based on whatever you define. Plus, the streamed data doesn't have to be included in the macro as a parameter.

Cheers...

_______________________________________________ Unsubscribe & other changes: http://lists.boost.org/mailman/listinfo.cgi/boost

At 23:03 18/03/2004, you wrote:

Rob Stewart wrote:

...

From: "Neal D. Becker" <ndbecker2@verizon.net>

...

John Torjo wrote:

...

Neal D. Becker wrote:

...

I notice boost doesn't have a logging library. I have seen several floating around. Are there any recommendations?

How about std::ostream ;) ?

Also, disabling writing to a stream is fairly easy, by setting the failbit of a stream object: out.setstate( std::ios::failbit); // nothing gets written to this log any more

Interesting idea. I would like the overhead of disabled loggers to be relatively small. Would you think this technique might be useful in that case? (Of course, relatively small is a relative term).

Every insertion and every mf you call on the stream must occur and must check the failbit flag. It would, therefore, have noticeable overhead. Is it a problem? Maybe. You could time an app with the logging compiled away (via preprocessor) and with the failbit set.

I think it's the wrong approach. In our company we have implemented logging through macros which has one very important property: When I write

LOG_DEBUG( whatever() );

into my source, then whatever() is only evaluated when the debug-logger is active. The macro basically expands to something like this:

if( Base::hasLogger( LogLevel::DEBUG ) ) Base::log( whatever(), LogLevel::DEBUG );

I think this cannot be done without macros as normal function calls (including operator<< for streams) need to evaluate their arguments before they are called. As the difference in the application execution speed can vary by a factor of 1000, this is a very valuable optimization for us. My 2¢.

Personally I think restricting boost to disabling logging on a #define is a double negative... ie a no no. It would be fine if boost was just used in developing "packaged" software, but in the real world where customers buy a big product *and* support, its very useful to be able to turn debugging on/off at runtime with the delivered solution. Having said that the previous post I think that's on the right lines, tho in the code we use don't hide behind a macro, for example my preferred syntax if (debug_trace.enabled()) { report(debug_trace, .... ) << "Somethings gone wrong x=" << x; } Very simple to use... you just have to instill into the team that reports stream operators cost, and you better check if the trace is enabled :o) I guess you could get the best of both worlds and wrap it up in a macro #define BOOST_LOG(Trace, ...., Message) \ if (Trace.enabled()) { report(Trace, .... ) << Message; } which is kind of getting to something similar to the previous post. Regards Mark --- Outgoing mail is certified Virus Free. Checked by AVG anti-virus system (http://www.grisoft.com). Version: 6.0.614 / Virus Database: 393 - Release Date: 05/03/2004

I think it's the wrong approach. In our company we have implemented logging through macros which has one very important property: When I write

LOG_DEBUG( whatever() );

into my source, then whatever() is only evaluated when the debug-logger is active. The macro basically expands to something like this:

if( Base::hasLogger( LogLevel::DEBUG ) ) Base::log( whatever(), LogLevel::DEBUG );

I think this cannot be done without macros as normal function calls (including operator<< for streams) need to evaluate their arguments before they are called. As the difference in the application execution speed can vary by a factor of 1000, this is a very valuable optimization for us. My 2¢.

Man, you must be doing a LOT of logging ;) I do quite a lot of logging myself, but I've never needed anything like above. Anyway, in my code I have functions, which return a log_stream (a thread-safe wrapper over a stream). And use it like this: activity_log() << "My app. started at" << time(0) << std::endl; error_log() << "should have not arrived here" << std::endl; // etc. And if I truly want, I can implement an operator bool(), and be able to disable it at runtime, like this: if (activity_log()) activity_log() << ...; Best, John

Daniel Frey wrote:

John Torjo wrote:

...

...

I think it's the wrong approach. In our company we have implemented logging through macros which has one very important property: When I write

LOG_DEBUG( whatever() );

into my source, then whatever() is only evaluated when the debug-logger is active. The macro basically expands to something like this:

if( Base::hasLogger( LogLevel::DEBUG ) ) Base::log( whatever(), LogLevel::DEBUG );

I think this cannot be done without macros as normal function calls (including operator<< for streams) need to evaluate their arguments before they are called. As the difference in the application execution speed can vary by a factor of 1000, this is a very valuable optimization for us. My 2¢.

Man, you must be doing a LOT of logging ;)

Well, too much for my taste, but some other team-members (namely by boss :) insists on logging almost everything. And I have to admit that it can be a real help from time-to-time. I just wish I would be allowed to implement a better hasLogger() so I can selectively enable only the log-messages/areas/levels/... that I'm interested in :)

...

I do quite a lot of logging myself, but I've never needed anything like above.

Maybe because when the framework doesn't support the feature I mentioned above, you won't add anything that makes the programm 1000x slower to your logging? ;)

...

Anyway, in my code I have functions, which return a log_stream (a thread-safe wrapper over a stream).

And use it like this:

activity_log() << "My app. started at" << time(0) << std::endl; error_log() << "should have not arrived here" << std::endl; // etc.

And if I truly want, I can implement an operator bool(), and be able to disable it at runtime, like this:

if (activity_log()) activity_log() << ...;

Hm, too verbose for my taste. With the macro, you get it for free.

True. I can also add a macro, something like: log(activity) << ...; Best, John

Daniel Frey wrote:

John Torjo wrote:

...

Daniel Frey wrote:

...

John Torjo wrote:

...

if (activity_log()) activity_log() << ...;

Hm, too verbose for my taste. With the macro, you get it for free.

True. I can also add a macro, something like:

log(activity) << ...;

OK, although there is more to keep in mind. In our logging system, we also added a try/catch macro around the expression that is to be logged. The reason is, that we never want a log-message to abort the program. I attached our actual implementation ('attached' to prevent reformatting), obviously I can't show the complete system :)

totally understandable. But why the try/catch inside the macros, instead of inside the ::Base::Log::log function? Best, John

Daniel Frey wrote:

John Torjo wrote:

...

totally understandable. But why the try/catch inside the macros, instead of inside the ::Base::Log::log function?

No particular reason. It just worked, so I guess no one here ever saw any reason to do change it. Maybe the original design was influenced by the existing interface of log() which accepted only one log-level, not two. Anyway, that's easy to change and now that I think about it, it seems to be a good idea to move the try/catch away from the macro to prevent code bloat. Thanks for the idea :)

Forget that. I now remember that there was a reason why the try/catch must be placed in the macro: We tested the log-system itself thoroughly, so the exception is not thrown from some bug in the log-system. Instead, the expression passed to the macro may throw. This mean that we cannot add the try/catch inside log(), as it is too late - the exception (if any) is thrown when the parameters for the call are evaluated. Thus, the try/catch must be part of the macro. Regards, Daniel -- Daniel Frey aixigo AG - financial solutions & technology Schloß-Rahe-Straße 15, 52072 Aachen, Germany fon: +49 (0)241 936737-42, fax: +49 (0)241 936737-99 eMail: daniel.frey@aixigo.de, web: http://www.aixigo.de

Geoff Leyland wrote:

Hi,

Why not do something like

my_log("this_module_logging_flag_notes") << "Doing something in this_module"; my_log("that_module_logging_flag_errors") << "Something went wrong in that_module";

where a log object is either (depending on a compile time setting) a proxy for a stream or a not_logger than has

this is not such a hard thing to do ;) I've implemented some log classes like this in the (far) past ;) But what you would actually want is an enumerator or something, so that you can write things like: log<error>() << "some error"; log<activity>() << "some activity"; And with compile switches you can turn on/off error/activity/etc. logs. But what about runtime? When it comes to logging, I really want a lot to be able to turn on/off such features at runtime. So, maybe a better result would be: log(error) << "some error; log(activity) << "some activity"; and log(x) be a macro in the lines of 'if(x) x' Best, John

You'd probably still need a macro for log so you could get a file and line number, though.

What would be REALLY nice would be if C++ had a built in stack tracing facility. In the past I've written a tracing library to keep track of the stack (and turn tracing and logging on and off above and below particular functions) and I once found 68000 stack tracing assembler for the old mac os, which was really nice. I should really get around to implementing something like that again...

cheers, Geoff

On 19/03/2004, at 6:32 PM, John Torjo wrote:

...

...

I think it's the wrong approach. In our company we have implemented logging through macros which has one very important property: When I write

LOG_DEBUG( whatever() );

into my source, then whatever() is only evaluated when the debug-logger is active. The macro basically expands to something like this:

if( Base::hasLogger( LogLevel::DEBUG ) ) Base::log( whatever(), LogLevel::DEBUG );

I think this cannot be done without macros as normal function calls (including operator<< for streams) need to evaluate their arguments before they are called. As the difference in the application execution speed can vary by a factor of 1000, this is a very valuable optimization for us. My 2¢.

Man, you must be doing a LOT of logging ;) I do quite a lot of logging myself, but I've never needed anything like above.

Anyway, in my code I have functions, which return a log_stream (a thread-safe wrapper over a stream).

And use it like this:

activity_log() << "My app. started at" << time(0) << std::endl; error_log() << "should have not arrived here" << std::endl; // etc.

And if I truly want, I can implement an operator bool(), and be able to disable it at runtime, like this:

if (activity_log()) activity_log() << ...;

Best, John

_______________________________________________ Unsubscribe & other changes: http://lists.boost.org/mailman/listinfo.cgi/boost

Geoff Leyland wrote:

...

log<error>() << "some error"; log<activity>() << "some activity"; ... I tend to work with the idea that either I want no logging at all, with no code generated, or that logging is built in and I'm prepared to take quite a hit for its overhead. I like using strings for keys because I'm too disorganised to get all the enums I need in one place in a large project. However I think in a lot of cases, string keys would be to heavy for the run-time decision "log or not", which needs to be quick, even if you're generating the (large) stream code. ... void large_function(void) { unsigned activity_log(get_log_index("my_activity")); ... log(activity_index) << "blah";

You can also use something like: Logger& l = get_logger("boost::new_interesting_library::error); l << "blah"; In other words: 1. It's possible to have one object for each log category, must like libcwd does. You don't have to index logger with category at all and there's no overhead at all. 2. At the same time you can get logger for specific program part and category using string key -- must like in Log4j and the clones. - Volodya

On Behalf Of Simon J. Julier

I like this approach and I personally think that setting logging levels in any specific part of a program is a must. The reason (which might say bad things about how we write software!) is that in my experience different libraries have different levels of maturity and hence different levels of logging. e.g., library X is fairly mature and needs very little logging. library Y is semi-mature and needs reasonably verbose logging. library Z is brand new and should be logged exhaustively. Anything which uses a global approach would force all log statements to the highest common demoninator and would force everything to be extremely verbose. Furthermore, having the option to compile out logging statements means that people can leave a lot of logging hard coded into the code simply because there is no incentive to remove it. (Which everybody finds out when you enable logging again....)

It is also nice when you can turn logging levels up and down without restarting your app, though you still want the option to compile it out of there for some sections of code. I find having inherited loggers handy to partition which loggers are being turned on, usually along the lines of namespace.namespace2.class...., but whatever suits your app. log4cplus, for example, can use this approach: log4cplus::ConfigureAndWatchThread configureThread(config_file_name, seconds_to_wait_before_polling * 1000); where is spins off a thread to watch your config file which suits some styles of apps. Change your config file, wait the poll time and your logging level has changed. Can be useful especially when you write dumb code like I'm prone too ;-) Esp. handy when you can add a remote logger into the mix without a restart. Could add a further global run time and compile time level awareness to minimize the overhead. Matt Hurd.