Logging Library -- Formal Review Request
Hi all, 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...."; Additions to v1.3.2 - can be compiled as a static/dynamic runtime (works as a DLL as well) - removed dependency on boost_thread Note: I did not test this on Unix, but it should work. If anybody can take a look at detail/ts_posix.hpp, I'd appreciate it. - solved other small issues, based on feedback - slightly improved documentation -- 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!
On 4/25/05, John Torjo <john.lists@torjo.com> 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_.
Nicely done John. I'm glad to see this (hopefully) moving toward the finish line. Unfortunately this release is missing the size-based and time-based rollover appenders I suggested some time ago. I think these are desirable to many users and should be included in some form in the initial implementation. I'm attaching them to this message. Here's the gmane link to my original posting which explains the implementations in more detail: http://article.gmane.org/gmane.comp.lib.boost.devel/113491
- removed dependency on boost_thread Note: I did not test this on Unix, but it should work. If anybody can take a look at detail/ts_posix.hpp, I'd appreciate it.
The member initialization of m_mutex on line 53 of ts_posix.hpp is invalid and should be removed. Also, in examples/multiple_threads/use_logs.cpp, g++ doesn't like this line: thread ( bind(writer_thread,idx) ); I had to give the unnnamed thread object a name to get the code to compile. -- Caleb Epstein caleb dot epstein at gmail dot com
On Mon, 25 Apr 2005 14:43:57 +0200 John Torjo <john.lists@torjo.com> wrote:
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....";
Along the same lines as other comments, but a little different... There should be more than one logging variable. You said the above roughly translates to: if ( is_log_enabled(app) ) app_log() << "testing" << i ...; However, this restricts the application to one single logging status. I want something like: if ( is_log_enabled(logvar_foo, app) app_log(logvar_foo) << "testing" << i ...; which allows the application to have many different logging state objects. In addition, I think any logging statement should be able to be conditionally compiled away. This should also be based on a value. For example, I should be able to specify on the command line something like: compile away all logging statements below level-x, or compile away all logging statements for domain foo, below level-x. I guess I am looking for more flexibility. Any logging statement should be able to be compiled away. Any logging statement should be able to check multiple levels against one of many different logging state objects.
On 4/26/05, Jody Hagins <jody-boost-011304@atdesk.com> wrote:
On Mon, 25 Apr 2005 14:43:57 +0200 John Torjo <john.lists@torjo.com> wrote:
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....";
Along the same lines as other comments, but a little different...
There should be more than one logging variable. You said the above roughly translates to:
if ( is_log_enabled(app) ) app_log() << "testing" << i ...;
However, this restricts the application to one single logging status. I want something like:
if ( is_log_enabled(logvar_foo, app) app_log(logvar_foo) << "testing" << i ...;
which allows the application to have many different logging state objects.
In addition, I think any logging statement should be able to be conditionally compiled away. This should also be based on a value. For example, I should be able to specify on the command line something like: compile away all logging statements below level-x, or compile away all logging statements for domain foo, below level-x.
I guess I am looking for more flexibility. Any logging statement should be able to be compiled away. Any logging statement should be able to check multiple levels against one of many different logging state objects.
I think John's approach to having multiple log "levels" is to just use a separate log for each one (e.g. you might have logs called trace, debug, warning, info, and fatal). Logs are either enabled or disabled; there is no "level" or above-some-threshold-type checking as with some other common implementations. As far as conditional compilation goes, I think John has agreed to add a new macro that would enclose an entire logging call and could be compiled out of production code. -- Caleb Epstein caleb dot epstein at gmail dot com
On Tue, 26 Apr 2005 12:16:03 -0400 Caleb Epstein <caleb.epstein@gmail.com> wrote:
I think John's approach to having multiple log "levels" is to just use a separate log for each one (e.g. you might have logs called trace, debug, warning, info, and fatal). Logs are either enabled or disabled; there is no "level" or above-some-threshold-type checking as with some other common implementations.
Unfortunately, you lose relativity in logs, which is very important in diagnosing failures. Suppose a problem occurs that gets logged to the "fatal" log. Really, to find out all surrounding context, you need to merge all logs. Unless there is a common sequence number or something like that, you have no way of really knowing what sequence of events led to the problem since they are scattered about in a number of logs. You can make good guesses, but in large that handle multiple requests at the same time, it becomes very difficult. I'd prefer a common log, which records levels. I also think the concept of multiple log variables is important in large systems, where different subsystems may have different log levels (e.g, turn on all logging for new subsystems, and only critical logging for other subsystems).
On 4/26/05, Jody Hagins <jody-boost-011304@atdesk.com> wrote:
On Tue, 26 Apr 2005 12:16:03 -0400 Caleb Epstein <caleb.epstein@gmail.com> wrote:
I think John's approach to having multiple log "levels" is to just use a separate log for each one (e.g. you might have logs called trace, debug, warning, info, and fatal). Logs are either enabled or disabled; there is no "level" or above-some-threshold-type checking as with some other common implementations.
Unfortunately, you lose relativity in logs, which is very important in diagnosing failures. Suppose a problem occurs that gets logged to the "fatal" log. Really, to find out all surrounding context, you need to merge all logs. Unless there is a common sequence number or something like that, you have no way of really knowing what sequence of events led to the problem since they are scattered about in a number of logs. You can make good guesses, but in large that handle multiple requests at the same time, it becomes very difficult.
Note that the presence of multiple logs does *not* imply multiple files. You can use a single appender for everything: add_appender ("*", write_to_file ("app.all.txt"));
I'd prefer a common log, which records levels.
I don't see any harm in this, I'm just trying to communicate my impression of John's implementation. Around the time John announced version 1.3 of the Logging lib (2004-10-28), there was some discussion around structured log "records" (e.g. an object that could capture information related to a log message like a severity, timestamp and possibly a thread ID). See http://thread.gmane.org/gmane.comp.lib.boost.devel/112436 for some discussion on this topic, specifically posts from Johan Nilsson, John, and Darryl Green.
I also think the concept of multiple log variables is important in large systems, where different subsystems may have different log levels (e.g, turn on all logging for new subsystems, and only critical logging for other subsystems).
How about something like this? enable_logs ("*"); disable_logs ("*.debug"); enable_logs ("*net.debug"); -- Caleb Epstein caleb dot epstein at gmail dot com
I think John's approach to having multiple log "levels" is to just use a separate log for each one (e.g. you might have logs called trace, debug, warning, info, and fatal). Logs are either enabled or disabled; there is no "level" or above-some-threshold-type checking as with some other common implementations.
Unfortunately, you lose relativity in logs, which is very important in diagnosing failures. Suppose a problem occurs that gets logged to the "fatal" log. Really, to find out all surrounding context, you need to merge all logs. Unless there is a common sequence number or something like that, you have no way of really knowing what sequence of events led to the problem since they are scattered about in a number of logs. You can make good guesses, but in large that handle multiple requests at the same time, it becomes very difficult.
From my experience (and I wrote several logging solutions used in
I am sorry to jump into the middle of discussion, but I wanted to comment on that: production) logging system is required to provide an explicit log level support. Any other solution is simply unacceptable. The same applies to keyword and category.
Note that the presence of multiple logs does *not* imply multiple files. You can use a single appender for everything:
add_appender ("*", write_to_file ("app.all.txt"));
Now you have multiple agents writing into the same file. It not only adding extra headache with synchronization. Most probably disable any buffering and still inconvenient to use.
I'd prefer a common log, which records levels.
Second that. Gennadiy
On Tue, 26 Apr 2005 14:11:31 -0400 "Gennadiy Rozental" <gennadiy.rozental@thomson.com> wrote:
I am sorry to jump into the middle of discussion, but I wanted to comment on that:
From my experience (and I wrote several logging solutions used in production) logging system is required to provide an explicit log level support. Any other solution is simply unacceptable. The same applies to keyword and category.
Could you please expand on the above, as I am not sure what you are trying to say.
"Jody Hagins" <jody-boost-011304@atdesk.com> wrote in message news:20050426144137.36cec38f.jody-boost-011304@atdesk.com...
On Tue, 26 Apr 2005 14:11:31 -0400 "Gennadiy Rozental" <gennadiy.rozental@thomson.com> wrote:
I am sorry to jump into the middle of discussion, but I wanted to comment on that:
From my experience (and I wrote several logging solutions used in production) logging system is required to provide an explicit log level support. Any other solution is simply unacceptable. The same applies to keyword and category.
Could you please expand on the above, as I am not sure what you are trying to say.
IMO logging library is required to support trace entry filtering based on: 1. Log level DEBUG, WARNING, ... CRITICAL 2. Category program flow, data flow, arguments, e.t.c 3. Keyword Any subsystem of the end-user system could define unique keyword and trace entries should be marked by it. For example: "XMLparser", "SocketLib" e.t.c Gennadiy
Jody Hagins wrote:
On Tue, 26 Apr 2005 12:16:03 -0400 Caleb Epstein <caleb.epstein@gmail.com> wrote:
I think John's approach to having multiple log "levels" is to just use a separate log for each one (e.g. you might have logs called trace, debug, warning, info, and fatal). Logs are either enabled or disabled; there is no "level" or above-some-threshold-type checking as with some other common implementations.
Unfortunately, you lose relativity in logs, which is very important in diagnosing failures. Suppose a problem occurs that gets logged to the
I'm not sure we're talking about the same thing. If you have not read the docs, I'd suggest you do. Note that right here, we're talking about a logical log. You can specify this log's destination(s) and/or modifiers (that is, prepend time, thread ID, append an enter if not already there, etc.) And, you can enable/disable logs. BOOST_LOG(app) << "testing " << i << '-' << j; If you wish, you can have all your logs write to the same file. Or, certain logs can even write to multiple locations. For example, my "dbg" logs always writes to a file, and to the Debug Output Window. As for "However, this restricts the application to one single logging status", I'm not sure I understand. Based on, lets say, command-line parameters, you can choose to enable/disable any logs you like. 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!
Caleb Epstein wrote:
On 4/26/05, Jody Hagins <jody-boost-011304@atdesk.com> wrote:
On Mon, 25 Apr 2005 14:43:57 +0200 John Torjo <john.lists@torjo.com> wrote:
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....";
Along the same lines as other comments, but a little different...
There should be more than one logging variable. You said the above roughly translates to:
if ( is_log_enabled(app) ) app_log() << "testing" << i ...;
However, this restricts the application to one single logging status. I want something like:
if ( is_log_enabled(logvar_foo, app) app_log(logvar_foo) << "testing" << i ...;
which allows the application to have many different logging state objects.
In addition, I think any logging statement should be able to be conditionally compiled away. This should also be based on a value. For example, I should be able to specify on the command line something like: compile away all logging statements below level-x, or compile away all logging statements for domain foo, below level-x.
I guess I am looking for more flexibility. Any logging statement should be able to be compiled away. Any logging statement should be able to check multiple levels against one of many different logging state objects.
I think John's approach to having multiple log "levels" is to just use a separate log for each one (e.g. you might have logs called trace, debug, warning, info, and fatal). Logs are either enabled or disabled; there is no "level" or above-some-threshold-type checking as with some other common implementations.
As far as conditional compilation goes, I think John has agreed to add a new macro that would enclose an entire logging call and could be compiled out of production code.
Further to the statement above and the other replies to this post by Jody and Gennadiy, I would like to add that - in my opinion - categories and levels are two *orthogonal* concepts. Although John's approach works, it gets laborious soon: Suppose I have n categories and m levels, then I need n*m logs with the current approach, but only n categories + m levels when the two aspects are implemented separately. I have to agree that I would appreciate if levels could be added as a distinct feature. -- Andreas
Andreas Wachowski wrote:
Caleb Epstein wrote:
On 4/26/05, Jody Hagins <jody-boost-011304@atdesk.com> wrote:
On Mon, 25 Apr 2005 14:43:57 +0200 John Torjo <john.lists@torjo.com> wrote:
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....";
Along the same lines as other comments, but a little different...
There should be more than one logging variable. You said the above roughly translates to:
if ( is_log_enabled(app) ) app_log() << "testing" << i ...;
However, this restricts the application to one single logging status. I want something like:
if ( is_log_enabled(logvar_foo, app) app_log(logvar_foo) << "testing" << i ...;
which allows the application to have many different logging state objects.
In addition, I think any logging statement should be able to be conditionally compiled away. This should also be based on a value. For example, I should be able to specify on the command line something like: compile away all logging statements below level-x, or compile away all logging statements for domain foo, below level-x.
I guess I am looking for more flexibility. Any logging statement should be able to be compiled away. Any logging statement should be able to check multiple levels against one of many different logging state objects.
I think John's approach to having multiple log "levels" is to just use a separate log for each one (e.g. you might have logs called trace, debug, warning, info, and fatal). Logs are either enabled or disabled; there is no "level" or above-some-threshold-type checking as with some other common implementations.
As far as conditional compilation goes, I think John has agreed to add a new macro that would enclose an entire logging call and could be compiled out of production code.
Further to the statement above and the other replies to this post by Jody and Gennadiy, I would like to add that - in my opinion - categories and levels are two *orthogonal* concepts. Although John's approach works, it gets laborious soon:
Suppose I have n categories and m levels, then I need n*m logs with the current approach, but only n categories + m levels when the two aspects are implemented separately.
I have to agree that I would appreciate if levels could be added as a distinct feature.
I strongly agree with this statement. I once wrote my own logging lib and had both categories and levels. It really helped during debugging/monitoring to be able to focus on different categories at different levels of detail, just by tuning numbers. John's lib looks great and has many advanced features, however I miss this basic functionality. greetings, Roland
-- Andreas
_______________________________________________ Unsubscribe & other changes: http://lists.boost.org/mailman/listinfo.cgi/boost
-- Roland Weiss - Postdoctoral Researcher - Formal Methods Group WSI-TI, Sand 13, Room 126, University of Tuebingen, 72076 Tuebingen, Germany Tel: +49 7071 2975940 (07071/29-75940) / Fax: +49 7071 29-5062 (07071/29-5062) E-Mail: roland.weiss@uni-tuebingen.de WWW: http://www-ti.informatik.uni-tuebingen.de/~weissr
John Torjo wrote:
I've just updated the Boost Log Library: http://torjo.com/code/logging-v132.zip
It's good to see progress on logging and what I've seen so far looks promising. However...
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....";
...while I like the feeling of the stream approach from a user's perspective, there is one (IMHO important) feature that can not be implemented with it: Exception guards. To illustrate my point, consider a "pure MACRO approach" like this: std::string f() { throw 42; } BOOST_LOG( app, "Huhu!" + f() ); where BOOST_LOG is: #define BOOST_LOG( logger, message ) \ do { if( logger.is_enabled() ) { \ try { logger.print( message ); } \ catch( const std::exception& e ) { \ logger.print( "Can't log \"" #message "\", e.what(): \"" + \ std::string( e.what() ) + "\"" ); \ } \ catch( ... ) { \ logger.print( "Can't log \"" #message "\", unknown exception" ); \ } \ } } while( false ) This feature helped us several times in the company when a log-message, calling some complicated functions, failed in a production system. As long as the above technique is applied, the log-file contains a good hint for us what's wrong and the product is still running without the customer noticing. Regards, Daniel
"Daniel Frey" <d.frey@gmx.de> wrote in message news:d4tshu$h4t$1@sea.gmane.org...
John Torjo wrote:
I've just updated the Boost Log Library: http://torjo.com/code/logging-v132.zip
It's good to see progress on logging and what I've seen so far looks promising. However...
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....";
...while I like the feeling of the stream approach from a user's perspective, there is one (IMHO important) feature that can not be implemented with it: Exception guards.
Another thing (from the same domain) that I found especially difficult to deal with in my logging implementation is "intermixed logging": BOOST_LOG(..) << "Print result of f(): " << f(); ... void f() { BOOST_LOG(..) << "Enter f()"; ... BOOST_LOG(..) << "Exit f()"; } Now to make it properly formatter isn't trivial at all. Gennadiy
Another thing (from the same domain) that I found especially difficult to deal with in my logging implementation is "intermixed logging":
BOOST_LOG(..) << "Print result of f(): " << f();
... void f() { BOOST_LOG(..) << "Enter f()"; ... BOOST_LOG(..) << "Exit f()"; }
Now to make it properly formatter isn't trivial at all.
(For the example to make sense f() shouldn't be void; I've assumed it is int). Can a logging library really help here? Don't you have to write: int f_ret=f();BOOST_LOG(..) << "Print result of f(): "<<f_ret; For when you want logging to compile out completely then a LOG_PREPARE() macro may be useful: BOOST_LOG_PREPARE(int f_ret=f()); BOOST_LOG(.., "Print result of f(): "<<f_ret); Darren
"Darren Cook" <darren@dcook.org> wrote in message news:4272B304.3000100@dcook.org...
Another thing (from the same domain) that I found especially difficult to deal with in my logging implementation is "intermixed logging":
BOOST_LOG(..) << "Print result of f(): " << f();
... void f() { BOOST_LOG(..) << "Enter f()"; ... BOOST_LOG(..) << "Exit f()"; }
Now to make it properly formatter isn't trivial at all.
(For the example to make sense f() shouldn't be void; I've assumed it is int).
Yep. My fault.
Can a logging library really help here? Don't you have to write: int f_ret=f();BOOST_LOG(..) << "Print result of f(): "<<f_ret;
No. It's not really convinient isn't it? I understand that f log statements will interfere with original log statement. The trick is to make sure that all prefixes are printed correctly: a.cpp:14: Print result of f(): b.cpp:75: Enter f() b.cpp:95: Exit f() a.cpp:14: 1234 Gennadiy
On 4/29/05, Gennadiy Rozental <gennadiy.rozental@thomson.com> wrote:
"Darren Cook" <darren@dcook.org> wrote in message news:4272B304.3000100@dcook.org...
Another thing (from the same domain) that I found especially difficult to deal with in my logging implementation is "intermixed logging":
BOOST_LOG(..) << "Print result of f(): " << f();
... void f() { BOOST_LOG(..) << "Enter f()"; ... BOOST_LOG(..) << "Exit f()"; }
Now to make it properly formatter isn't trivial at all.
(For the example to make sense f() shouldn't be void; I've assumed it is int).
Yep. My fault.
Can a logging library really help here? Don't you have to write: int f_ret=f();BOOST_LOG(..) << "Print result of f(): "<<f_ret;
No. It's not really convinient isn't it?
I understand that f log statements will interfere with original log statement. The trick is to make sure that all prefixes are printed correctly:
a.cpp:14: Print result of f(): b.cpp:75: Enter f() b.cpp:95: Exit f() a.cpp:14: 1234
The proposed implementation yields this (modulo any prefixes): Enter f() Exit f() Print result of f(): 1234 Because each message is built up in a temporary stream and then fired off to the logger in its entirety. Gennadiy: to do what you suggest would seem to me to require (a) no buffering and (b) an interface which is likely not thread-safe. Or am I missing something. -- Caleb Epstein caleb dot epstein at gmail dot com
Caleb Epstein wrote:
On 4/29/05, Gennadiy Rozental <gennadiy.rozental@thomson.com> wrote:
"Darren Cook" <darren@dcook.org> wrote in message news:4272B304.3000100@dcook.org...
Another thing (from the same domain) that I found especially difficult to deal with in my logging implementation is "intermixed logging":
BOOST_LOG(..) << "Print result of f(): " << f();
... void f() { BOOST_LOG(..) << "Enter f()"; ... BOOST_LOG(..) << "Exit f()"; }
Now to make it properly formatter isn't trivial at all.
Gennadiy: to do what you suggest would seem to me to require (a) no buffering and (b) an interface which is likely not thread-safe. Or am I missing something.
Gennadiy, correct me if I'm wrong but as you wrote your post as a reply to mine, I can see a connection: You seem to prefer the unbuffered logging to have at least the partial information before an exception occurs and to avoid complexity in the implementation of the logging library by avoiding the buffering code, right? FWIW, I think buffering should still be used, with an occasional <<std::flush here and there. The main problem is, that it's not sufficient to have a normal buffered stream (which usually has a fixed-sized buffer), but to handle an unlimited buffer. This involves memory managment, although I have to admit that the code I showed "solves" this by moving the problem to the user's expression. But then, maybe, I completely missed your point :) Regards, Daniel
Gennadiy: to do what you suggest would seem to me to require (a) no buffering and (b) an interface which is likely not thread-safe. Or am I missing something.
Gennadiy, correct me if I'm wrong but as you wrote your post as a reply to mine, I can see a connection: You seem to prefer the unbuffered logging to have at least the partial information before an exception occurs and to avoid complexity in the implementation of the logging library by avoiding the buffering code, right?
I did not had any buffering in mind. See my other post. May be you could explain me more how buffering affect order of log entries in stream. Gennadiy
Gennadiy Rozental wrote:
Gennadiy: to do what you suggest would seem to me to require (a) no buffering and (b) an interface which is likely not thread-safe. Or am I missing something.
Gennadiy, correct me if I'm wrong but as you wrote your post as a reply to mine, I can see a connection: You seem to prefer the unbuffered logging to have at least the partial information before an exception occurs and to avoid complexity in the implementation of the logging library by avoiding the buffering code, right?
I did not had any buffering in mind. See my other post. May be you could explain me more how buffering affect order of log entries in stream.
Consider threading and how we can avoid problems with multiple threads writing log messages. One option is to simply lock the log stream while it is in use. You can output the log messages part bit by bit now, but this might lead to deadlocks. Example: BOOST_LOG(app) << "Hello" << f() << g() << "world!"; The BOOST_LOG() locks app for other threads. It is unlocked when the complete expression is evaluated. This can be easily achived, but what if f() makes another thread output something to app? And g() waits for the result from f()'s subthread? => Deadlock. Another choice is not to lock app. Actually, this is preferable anyway as locking should be avoided whenever possible. What we need now is a way to output the log-message as an atomic operation. This can only be done when we are able to cache the complete message before flushing the buffer. But then, this cannot be done with a fixed sized buffer. As a consequence, I think that a fixed sized buffer potentionally leads to intermixed logging in a multithread environment. Or is there something I'm missing? Regards, Daniel
a.cpp:14: Print result of f(): b.cpp:75: Enter f() b.cpp:95: Exit f() a.cpp:14: 1234
The proposed implementation yields this (modulo any prefixes):
Enter f() Exit f() Print result of f(): 1234
Because each message is built up in a temporary stream and then fired off to the logger in its entirety.
Gennadiy: to do what you suggest would seem to me to require (a) no buffering and (b) an interface which is likely not thread-safe. Or am I missing something.
Sorry. I am not that deep ;)) First of all I am not familiar with detail of this submission and second I just talking from user prospective. And from that prospective what proposed implementation yields may not be ucceptable cause it break order of events. I wonder what it's going to pring in more complicated cases: BOOST_LOG(..) << "Print result of f(): " << f() << " and g()" << g(); void f() { BOOST_LOG(..) << "Enter f()"; BOOST_LOG(..) << "f() inside uses m(): " << m(); BOOST_LOG(..) << "Exit f()"; } void g() { BOOST_LOG(..) << "Enter g()"; BOOST_LOG(..) << "g() inside uses m(): " << m(); BOOST_LOG(..) << "Exit g()"; } Gennadiy P.S. Could you explain a bit more how cashing and threading are involved here
On 4/30/05, Gennadiy Rozental <gennadiy.rozental@thomson.com> wrote:
Sorry. I am not that deep ;)) First of all I am not familiar with detail of this submission and second I just talking from user prospective. And from that prospective what proposed implementation yields may not be ucceptable cause it break order of events.
I wonder what it's going to pring in more complicated cases:
BOOST_LOG(..) << "Print result of f(): " << f() << " and g()" << g();
void f() { BOOST_LOG(..) << "Enter f()";
BOOST_LOG(..) << "f() inside uses m(): " << m();
BOOST_LOG(..) << "Exit f()"; }
void g() { BOOST_LOG(..) << "Enter g()";
BOOST_LOG(..) << "g() inside uses m(): " << m();
BOOST_LOG(..) << "Exit g()"; }
Gennadiy
P.S. Could you explain a bit more how cashing and threading are involved here
Within any block (or a block nested within that block), writes to will appear in the proper order. If my reading of the code is correct, the way the BOOST_LOG macro works when a log is enabled is to (oversimplifying) return a proxy stream object ("logger_keeper" which inherits from "enabled_logger") which will be the target of the operator<< calls. When this proxy object is destroyed, the entire message gets written. So something like this: BOOST_LOG (x) << "Result of f: " << f (). Turns into something more like (expanding out the code inside the classes and greatly oversimplifying, but this iis the gist): if (!x.is_enabled ()) ; else { ostringstream s; s << "Result of f: " << f (); write_msg (logger::manager (), x, s.str ()); } So if there are nested logging calls inside of "f" that are destined for the logger "x", they will hit the output device *before* the caller's message does. You suggested something like this:
a.cpp:14: Print result of f(): b.cpp:75: Enter f() b.cpp:95: Exit f() a.cpp:14: 1234
If I understand the behavior you desire, the string "Print result of f(): " would be logged either (1) immediately or (2) as soon as there were any logging calls from a different scope (e.g. the "Enter f()"). The first option to me suggests no buffering between the loggers ("x" in this case) and the output devices (the things that write to files etc). This would likely offer poor performance, and would lead to intermixing of output from multiple threads just like plain iostreams. In other words, if multiple threads are writing to the same logger simultaneously, their messages would potentially be fragmented and mixed wherever they are separated by an <<. Perhaps a thread-specific stream could be used to prevent this. The second option is an interesting one, but is similar or identical to the first case I believe. The target of the operator<< calls could keep a stack of the logging "scope" and pop that stack whenever a scope is exited (e.g. a BOOST_LOG call is complete). Whenever the scope changed, the desired prefix (e.g. filename, line number, timestamp, thread ID, etc) would be emitted. This would need to be kept in thread-specific storage for the same reaons mentioned above. Am I totally off base here in terms of what you're suggesting and how it might be implemented? -- Caleb Epstein caleb dot epstein at gmail dot com
I wonder what it's going to pring in more complicated cases:
BOOST_LOG(..) << "Print result of f(): " << f() << " and g()" << g();
void f() { BOOST_LOG(..) << "Enter f()";
BOOST_LOG(..) << "f() inside uses m(): " << m();
BOOST_LOG(..) << "Exit f()"; }
void g() { BOOST_LOG(..) << "Enter g()";
BOOST_LOG(..) << "g() inside uses m(): " << m();
BOOST_LOG(..) << "Exit g()"; }
Gennadiy
P.S. Could you explain a bit more how cashing and threading are involved here
Within any block (or a block nested within that block), writes to will appear in the proper order. If my reading of the code is correct, the way the BOOST_LOG macro works when a log is enabled is to (oversimplifying) return a proxy stream object ("logger_keeper" which inherits from "enabled_logger") which will be the target of the operator<< calls. When this proxy object is destroyed, the entire message gets written.
So something like this:
BOOST_LOG (x) << "Result of f: " << f ().
Turns into something more like (expanding out the code inside the classes and greatly oversimplifying, but this iis the gist):
if (!x.is_enabled ()) ; else { ostringstream s; s << "Result of f: " << f (); write_msg (logger::manager (), x, s.str ()); }
So if there are nested logging calls inside of "f" that are destined for the logger "x", they will hit the output device *before* the caller's message does.
This means that in example like above Logs from m() calls will be printed before f() and g(). And nobody will be able to tell which one is from where. It's completely unacceptable IMO. Threading/no threading, cashing /no cashing Log is NOT allowed to change an order of events.
You suggested something like this:
a.cpp:14: Print result of f(): b.cpp:75: Enter f() b.cpp:95: Exit f() a.cpp:14: 1234
If I understand the behavior you desire, the string "Print result of f(): " would be logged either (1) immediately or (2) as soon as there were any logging calls from a different scope (e.g. the "Enter f()").
From my standpoint there is only one possible strategy: log trace entries one after another the way program flow goes.
The first option to me suggests no buffering between the loggers ("x" in this case) and the output devices (the things that write to files etc). This would likely offer poor performance, and would lead to intermixing of output from multiple threads just like plain iostreams.
Now about bufferin/cashing. IMO is completely independent issue. It should be on a different level in hierarchy. Most probably somewhere on appender/sink level. Loggers just do the logging, sinks manage the device. As for threading, intermixing of output could be just what I want. In other case I could use independent sinks per thread.
In other words, if multiple threads are writing to the same logger simultaneously, their messages would potentially be fragmented and mixed wherever they are separated by an <<. Perhaps a thread-specific stream could be used to prevent this.
To prevent log entry fragmenting caused by multiple threads locks should be used.
Am I totally off base here in terms of what you're suggesting and how it might be implemented?
My primary point is that log should reflect 1:1 everything that happened in program, without any order change. As a result some log entries my be fragmented (same thread fragmentation) and logger should be able to properly set up all prefixes. Gennadiy
Gennadiy Rozental <gennadiy.rozental <at> thomson.com> writes:
So something like this:
BOOST_LOG (x) << "Result of f: " << f ().
Turns into something more like (expanding out the code inside the classes and greatly oversimplifying, but this iis the gist):
if (!x.is_enabled ()) ; else { ostringstream s; s << "Result of f: " << f (); write_msg (logger::manager (), x, s.str ()); }
So if there are nested logging calls inside of "f" that are destined for the logger "x", they will hit the output device *before* the caller's message does.
This means that in example like above Logs from m() calls will be printed before f() and g(). And nobody will be able to tell which one is from where. It's completely unacceptable IMO. Threading/no threading, cashing /no cashing Log is NOT allowed to change an order of events.
But the order hasn't been changed - it just isn't what you expected. I'm not sure why you didn't expect it - it seems reasonable (to me) that the result of evaluating the complete expression is logged. If some subexpression has a side effect that writes to a log, its results will be logged when the sub-expression is complete. That is "in order" afaiks. What about this: time_t slow_time() { BOOST_LOG(x) << "going to sleep at " << time(0); sleep(1); time_t t; BOOST_LOG(x) << "waking up at " << t = time(0); return t; } void f() { BOOST_LOG(x) << "slow_time returned " << slow_time() << " then " << slow_time(); } Resulting in (I ran this test a long time ago, boot time isn't bad either :-) : going to sleep at 0 waking up at 1 going to sleep at 1 waking up at 2 slow time returned 1 then 2 Looks in order to me. I'm still not sure what the alternative is? Darryl.
going to sleep at 0 waking up at 1 going to sleep at 1 waking up at 2 slow time returned 1 then 2
Looks in order to me. I'm still not sure what the alternative is?
Me neither :) 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!
What about this:
time_t slow_time() { BOOST_LOG(x) << "going to sleep at " << time(0); sleep(1); time_t t; BOOST_LOG(x) << "waking up at " << t = time(0); return t; }
void f() { BOOST_LOG(x) << "slow_time returned " << slow_time() << " then " << slow_time(); }
Resulting in (I ran this test a long time ago, boot time isn't bad either :-) :
going to sleep at 0 waking up at 1 going to sleep at 1 waking up at 2 slow time returned 1 then 2
I have several questions about this: 1. How do you know in general which log present trace of first invocation, and which one second: void acess_db( ... ) { if( some error ) log << "invalid account key" << key; } int get_balance(...){ ... if( !access_db(...) ) return 0; } ... log << "Mary has balance: " << get_balance() << " and John has balance: " << get_balance() Let say an output is:
access_db Invalid account key: 25 < access_db access_db < access_db Mary has balance: 0 and John has balance: 100
----------------------------------------- Could you say where an error occurred (without looking into code and knowledge how log system is working)? Would it be like this: Mary has balance:
access_db Invalid account key: 25 < access_db 0 and John has balance: access_db < access_db 100
It would be clear. I understand that later is slightly less readable but In my experience usually what happened is that log entry fragmenting occur only on hi levels of log (or in case of error). While with regular log level and normal log flow it's not an issue. 2. How does the log system know when to dump the cash? Does it introduce any scope guards? 3. How deep it will work? And how many different cashed we could have the same time? 4. What kind of overhead it introduces? Now instead of directly writing into stream we keep second copy of every piece of log essentially doubling the memory usage and increasing log overhead, isn't it?
Looks in order to me. I'm still not sure what the alternative is?
It may be desirable in some circumstances. But it may be not. IMO Log should follow program flow 1:1. Including order of events during log entry output. Gennadiy
From: "Gennadiy Rozental" <gennadiy.rozental@thomson.com>
2. How does the log system know when to dump the cash? Does it introduce any scope guards?
I'd like a log system like that; just dump the cash in my bank account, please! 8-) (Sorry Gennadiy, I couldn't help myself.) -- Rob Stewart stewart@sig.com Software Engineer http://www.sig.com Susquehanna International Group, LLP using std::disclaimer;
Gennadiy Rozental <gennadiy.rozental <at> thomson.com> writes:
I have several questions about this:
1. How do you know in general which log present trace of first invocation, and which one second:
void acess_db( ... ) { if( some error ) log << "invalid account key" << key; }
int get_balance(...){ ... if( !access_db(...) ) return 0; }
...
log << "Mary has balance: " << get_balance() << " and John has balance: " << get_balance()
Let say an output is:
access_db Invalid account key: 25 < access_db access_db < access_db Mary has balance: 0 and John has balance: 100
-----------------------------------------
Could you say where an error occurred (without looking into code and knowledge how log system is working)?
No, I can't. But then there is an awful lot of stuff in detailed logs that falls into the same category, with or without reordering.
Would it be like this:
Mary has balance:
access_db Invalid account key: 25 < access_db 0 and John has balance: access_db < access_db 100
It would be clear.
Yes. However, I have thought of LOG(x) << "foo" << a() << b(); as a request to build then log a message, not as a reqest to write to a log stream. All the logging systems I'm familiar with have the same concept (eg syslog, windows nt event log).
I understand that later is slightly less readable but In my experience usually what happened is that log entry fragmenting occur only on hi levels of log (or in case of error). While with regular log level and normal log flow it's not an issue.
Ok. The only think I can think of that preserves the log message concept while giving the stream view that you want is to record some sort of nesting level and either cache to give something like the following directly, or just include a level tag used by a viewer to format as: Mary has balance: 0 and John has balance: 100
access_db Invalid account key: 25 < access_db access_db < access_db Next log message is back here
I'm not sure if that is close enough?
2. How does the log system know when to dump the cash? Does it introduce any scope guards?
Do you mean the cache used on startup or the buffering used to build a log message? I'll try to answer both - pick the applicable one... The cache is only used to avoid missing log info from static c'tors etc. that may run before the logging system itself has been configured (logs connected to appenders). Once the logging is initialized, the cache is not used. The buffer is only used to build a single message. Its scope is the single LOG(x) << ...; expression.
3. How deep it will work? And how many different cashed we could have the same time?
The cache is limited to prevent excessive memory use if the user forgets to configure the log. The buffer to build a message is used to build a single message.
4. What kind of overhead it introduces? Now instead of directly writing into stream we keep second copy of every piece of log essentially doubling the memory usage and increasing log overhead, isn't it?
I'm too confused about what you were asking above to answer this, sorry.
Looks in order to me. I'm still not sure what the alternative is?
It may be desirable in some circumstances. But it may be not. IMO Log should follow program flow 1:1. Including order of events during log entry output.
But then it isn't just a log, it's the whole tree ;-) I do see your point now though. I just can't quite see how to fit it into an event logging system. The above thoughts about tracing actual program flow also fail to consider how to reconcile this with the idea of multiple logs and appenders. In general you can have an L x A connection matrix of logs and appenders. It is quite likely I'd write my access_db messages to the db_log, and my account_balance etc messages to the acct_log. These 2 logs may or may not both be connected to the same (set of) appenders. I guess the merging/reordering could only work when the writes were to the same log. Darryl.
Gennadiy Rozental wrote:
What about this:
time_t slow_time() { BOOST_LOG(x) << "going to sleep at " << time(0); sleep(1); time_t t; BOOST_LOG(x) << "waking up at " << t = time(0); return t; }
void f() { BOOST_LOG(x) << "slow_time returned " << slow_time() << " then " << slow_time(); }
Resulting in (I ran this test a long time ago, boot time isn't bad either :-) :
going to sleep at 0 waking up at 1 going to sleep at 1 waking up at 2 slow time returned 1 then 2
I have several questions about this:
1. How do you know in general which log present trace of first invocation, and which one second:
void acess_db( ... ) { if( some error ) log << "invalid account key" << key; }
int get_balance(...){ ... if( !access_db(...) ) return 0; }
...
log << "Mary has balance: " << get_balance() << " and John has balance: " << get_balance()
I would assume you meant something like: log << "Mary has balance: " << get_balance("mary") << " and John has balance: " << get_balance("john"); If so, when you have a bad key, you should have some extra information to log (the name, or something).
2. How does the log system know when to dump the cash? Does it
introduce any scope guards? Have you actually taken a look at the code? A temporary variable is created, and in its destructor I perform the logging.
4. What kind of overhead it introduces? Now instead of directly
stream we keep second copy of every piece of log essentially doubling
writing into the
memory usage and increasing log overhead, isn't it?
Have you actually tested it in a multi-threading environment, or is this just your guts? 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!
log << "Mary has balance: " << get_balance("mary") << " and John has balance: " << get_balance("john");
If so, when you have a bad key, you should have some extra information to log (the name, or something).
get_ballance has name. access_db does not.
4. What kind of overhead it introduces? Now instead of directly writing into stream we keep second copy of every piece of log essentially doubling the memory usage and increasing log overhead, isn't it?
Have you actually tested it in a multi-threading environment, or is this just your guts?
How MT is related to my question? You introduces extra buffering level. I am asking how efficient it is. Gennadiy
On 5/19/05, Gennadiy Rozental <gennadiy.rozental@thomson.com> wrote:
4. What kind of overhead it introduces? Now instead of directly writing into stream we keep second copy of every piece of log essentially doubling the memory usage and increasing log overhead, isn't it?
Have you actually tested it in a multi-threading environment, or is this just your guts?
How MT is related to my question? You introduces extra buffering level. I am asking how efficient it is.
There should be no doubling of messages, though they are copied from one place to another. Generally messages are formatted in a temporary ostringstream and then written to files or other sinks via appender functions. user code -> ostringstream -> modifier functions (if any) -> appenders There is a special appender called ts_appender that buffers formatted messages in a string until the time arrives to flush them to their ultimate destination. user code -> ostringstream -> modifier functions (if any) -> string buffer [background thread]: string buffer -> appenders -- Caleb Epstein caleb dot epstein at gmail dot com
a.cpp:14: Print result of f(): b.cpp:75: Enter f() b.cpp:95: Exit f() a.cpp:14: 1234
I really don't understand why you'd want this. And more to the point, I'm really curious how you could implement this in C++: // show what you want above. BOOST_LOG(app) << "result of f() " << f(); And finally, I don't know why you'd want the above. What if f() then calls g(), and so on, all this functions doing some logging. Would you actually prefer: a.cpp:14: result of f() [100 lines of other logged messages] a.cpp:14: 1234 To: [100 lines of other logged messages] a.cpp:14: result of f(): 1234 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" <john.lists@torjo.com> wrote in message news:42788C90.9050504@torjo.com...
a.cpp:14: Print result of f(): b.cpp:75: Enter f() b.cpp:95: Exit f() a.cpp:14: 1234
I really don't understand why you'd want this. And more to the point, I'm really curious how you could implement this in C++:
It's a bit ricky. But doable.
// show what you want above. BOOST_LOG(app) << "result of f() " << f();
And finally, I don't know why you'd want the above. What if f() then calls g(), and so on, all this functions doing some logging. Would you actually prefer:
a.cpp:14: result of f() [100 lines of other logged messages] a.cpp:14: 1234
To:
[100 lines of other logged messages] a.cpp:14: result of f(): 1234
Yes. I would. Because it's an actual program flow. Would it be int r = f(); BOOST_LOG(app) << "result of f() " << r; I definitely would like to see a second. Gennadiy. Gennadiy.
At 19:42 29/04/2005, you wrote:
"Daniel Frey" <d.frey@gmx.de> wrote in message news:d4tshu$h4t$1@sea.gmane.org...
John Torjo wrote:
I've just updated the Boost Log Library: http://torjo.com/code/logging-v132.zip
It's good to see progress on logging and what I've seen so far looks promising. However...
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....";
...while I like the feeling of the stream approach from a user's perspective, there is one (IMHO important) feature that can not be implemented with it: Exception guards.
Another thing (from the same domain) that I found especially difficult to deal with in my logging implementation is "intermixed logging":
BOOST_LOG(..) << "Print result of f(): " << f();
... void f() { BOOST_LOG(..) << "Enter f()"; ... BOOST_LOG(..) << "Exit f()"; }
Now to make it properly formatter isn't trivial at all.
Gennadiy
I must admit I haven't looked at the proposed implementation due to time issues, tho I'm very interested in a logging library. Like most people have written my own... with various traces / levels and logging to a file / std out / across a tcp/ip connection etc, and hence such a library a very worthwhile addition to Boost in my opinion. But sorry I don't see what the issue is about properly formatting... perhaps you could explain a bit more please? From my point of view if you have something like; class log { public: void output(const std::string& message); // threadsafe write msg to log }; class logger { public: logger(log& l) : l(l) {} ~logger() { l.output(buffer) { friend logger& operator << (logger&, const char*); // write to buffer }; Your example would end up with Enter f() Exit f() Print result of f(): ... Regards Mark
Your example would end up with
Enter f() Exit f() Print result of f(): ...
And that's what happens now ;) 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 19:03 29/04/2005, you wrote:
John Torjo wrote:
I've just updated the Boost Log Library: http://torjo.com/code/logging-v132.zip
It's good to see progress on logging and what I've seen so far looks promising. However...
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....";
...while I like the feeling of the stream approach from a user's perspective,
I agree.
there is one (IMHO important) feature that can not be implemented with it: Exception guards.
To illustrate my point, consider a "pure MACRO approach" like this:
std::string f() { throw 42; }
BOOST_LOG( app, "Huhu!" + f() );
where BOOST_LOG is:
#define BOOST_LOG( logger, message ) \ do { if( logger.is_enabled() ) { \ try { logger.print( message ); } \ catch( const std::exception& e ) { \ logger.print( "Can't log \"" #message "\", e.what(): \"" + \ std::string( e.what() ) + "\"" ); \ } \ catch( ... ) { \ logger.print( "Can't log \"" #message "\", unknown exception" ); \ } \ } } while( false )
What happens if logger.print() throws (say because there isn't enough disk space to write a log to)? I've always taken the other view (being a developer for server applications that have to run 24/7) that if you can't write to the log, you don't jeopardise the application.
This feature helped us several times in the company when a log-message, calling some complicated functions, failed in a production system. As long as the above technique is applied, the log-file contains a good hint for us what's wrong and the product is still running without the customer noticing.
Regards, Daniel
Regards Mark
Mark Blewett wrote:
At 19:03 29/04/2005, you wrote:
BOOST_LOG( app, "Huhu!" + f() );
where BOOST_LOG is:
#define BOOST_LOG( logger, message ) \ do { if( logger.is_enabled() ) { \ try { logger.print( message ); } \ catch( const std::exception& e ) { \ logger.print( "Can't log \"" #message "\", e.what(): \"" + \ std::string( e.what() ) + "\"" ); \ } \ catch( ... ) { \ logger.print( "Can't log \"" #message "\", unknown exception" ); \ } \ } } while( false )
What happens if logger.print() throws (say because there isn't enough disk space to write a log to)?
First of all, it should be clear that the above is just a sketch. The code we have is a bit more complicated and I might even describe some features that are possible but not yet implemented in our companies code base. But to answer your question: Basically logger.print() protects itself, inside its implementation. If the logging itself fails (not the evaluation of the expression to log), the log system handles the situation on its own. As an example, if the log-target is a file and the disk is full, it just stops logging, probably trying to inform someone via EMail or whatever other options are available, depending on the context.
I've always taken the other view (being a developer for server applications that have to run 24/7) that if you can't write to the log, you don't jeopardise the application.
If the application is meant to run 24/7, how do you react on a "disk-full" error? In the end, it's just the log-system. By definition (YMMV), the application should be feature complete even without any log-messages. I know that some people put important information in log-messages that are part of the applications functionality, but to me this always seemed like a bad idea. Thus, in case anything fails during logging, we try to handle the situation as gently as possible to keep the application running. Regards, Daniel
Daniel Frey wrote:
John Torjo wrote:
I've just updated the Boost Log Library: http://torjo.com/code/logging-v132.zip
It's good to see progress on logging and what I've seen so far looks promising. However...
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....";
...while I like the feeling of the stream approach from a user's perspective, there is one (IMHO important) feature that can not be implemented with it: Exception guards.
When there's a will, there's a way ;) You do raise a very valid point -- about exceptions. I will add exception guards. 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:
Daniel Frey wrote:
John Torjo wrote:
I've just updated the Boost Log Library: http://torjo.com/code/logging-v132.zip
It's good to see progress on logging and what I've seen so far looks promising. However...
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....";
...while I like the feeling of the stream approach from a user's perspective, there is one (IMHO important) feature that can not be implemented with it: Exception guards.
When there's a will, there's a way ;)
You do raise a very valid point -- about exceptions. I will add exception guards.
Looking at the latest version (-v133.zip), I neither found them in the code nor on the ToDo-list. And I can't imagine how you could be able to add them with the current design, but I might be missing something. Care to share your ideas how to do it even in case the technique probably won't make it into your library? I'm just curious to learn a new trick :)) Another point: IIRC, some month ago we talked about the logging library in an earlier version. I proposed to allow if( app ) { ... } instead of if( BOOST_IS_LOG_ENABLED(app) ) { ... } and you agreed it makes sense. AFAIR it appeared to be very easy, but the library evolved since then. Is it still possible in the current library? Regards, Daniel
Daniel Frey wrote:
John Torjo wrote:
Daniel Frey wrote:
John Torjo wrote:
I've just updated the Boost Log Library: http://torjo.com/code/logging-v132.zip
It's good to see progress on logging and what I've seen so far looks promising. However...
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....";
...while I like the feeling of the stream approach from a user's perspective, there is one (IMHO important) feature that can not be implemented with it: Exception guards.
When there's a will, there's a way ;)
You do raise a very valid point -- about exceptions. I will add exception guards.
Looking at the latest version (-v133.zip), I neither found them in the code nor on the ToDo-list. And I can't imagine how you could be able to add them with the current design, but I might be missing something. Care to share your ideas how to do it even in case the technique probably won't make it into your library? I'm just curious to learn a new trick :))
As far as I can think right now, it should be something like : if ( std::uncaught_exception()) return; // there's an exception try { do_logging; } catch(...) { // an exception occured while logging // eventually could call an on_logging_exception handler // then, eat this exception (it occured while logging) } Of course, this just came out of the top of my head, at 5am in the morning, so it's probably going to be a little more complex ;)
Another point: IIRC, some month ago we talked about the logging library in an earlier version. I proposed to allow
if( app ) { ... }
instead of
if( BOOST_IS_LOG_ENABLED(app) ) { ... }
and you agreed it makes sense. AFAIR it appeared to be very easy, but the library evolved since then. Is it still possible in the current library?
It is, with one small elaboration. At this time, when doing BOOST_DEFINE_LOG(app), BOOST_DECLARE_LOG(app), internally, I append something like "_log" to the actual log name, as to not collide with any other possible uses of 'app' as a variable or whatever. Thus, you could say: // note: it even works now if ( app_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!
John Torjo wrote:
Daniel Frey wrote:
John Torjo wrote:
Daniel Frey wrote:
John Torjo wrote:
I've just updated the Boost Log Library: http://torjo.com/code/logging-v132.zip
It's good to see progress on logging and what I've seen so far looks promising. However...
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....";
...while I like the feeling of the stream approach from a user's perspective, there is one (IMHO important) feature that can not be implemented with it: Exception guards.
When there's a will, there's a way ;)
You do raise a very valid point -- about exceptions. I will add exception guards.
Looking at the latest version (-v133.zip), I neither found them in the code nor on the ToDo-list. And I can't imagine how you could be able to add them with the current design, but I might be missing something. Care to share your ideas how to do it even in case the technique probably won't make it into your library? I'm just curious to learn a new trick :))
As far as I can think right now, it should be something like :
if ( std::uncaught_exception()) return; // there's an exception
try { do_logging; } catch(...) { // an exception occured while logging // eventually could call an on_logging_exception handler // then, eat this exception (it occured while logging) }
That's not the point. The point is, how you can catch exceptions with your stream-like interface: std::string f() { throw 42; } BOOST_LOG(app) << "Huhu!" << f(); This should IMHO write something like Expression " << "Huhu!" << f();" can't be logged to the log-stream as outlined in my message some levels up in this thread.
Another point: IIRC, some month ago we talked about the logging library in an earlier version. I proposed to allow
if( app ) { ... }
instead of
if( BOOST_IS_LOG_ENABLED(app) ) { ... }
and you agreed it makes sense. AFAIR it appeared to be very easy, but the library evolved since then. Is it still possible in the current library?
It is, with one small elaboration. At this time, when doing BOOST_DEFINE_LOG(app), BOOST_DECLARE_LOG(app), internally, I append something like "_log" to the actual log name, as to not collide with any other possible uses of 'app' as a variable or whatever.
Thus, you could say:
// note: it even works now if ( app_log() ) { ... }
Why do you add _log anyway? Now you still have potential clashes with a variable app_log, but it's no longer as direct and transparent as simply saying that BOOST_DEFINE_LOG(X) reserves X. I'd definitly prefer the latter, just my 2c. And in case you really want to avoid clashes and you don't expose the name to the user, you might consider prepending something like BOOST_LOG_ to the names. Regards, Daniel
John Torjo wrote:
Hi all,
I've just updated the Boost Log Library:
Thanks for all your feedback. I've updated the lib so that it allows enabling/disabling of logs at compile-time, what Darren Cook asked. In order to allow enable/disable at compile-time, all you need to do is declare the log like this: // instead of BOOST_DECLARE_LOG(some_log_name) BOOST_DECLARE_LOG_DEBUG(some_log_name) Or, you can specify your own constant that can be 1 (enable the log) or 0 (disable the log). #define TESTING 1 // or #define TESTING 0 // if TESTING is 1, the 'test' log is enabled // if TESTING is 0, the 'test' log is disabled BOOST_DECLARE_LOG_COMPILE_TIME(test, TESTING) (note: there's also an example: compile_time_logs) Download the latest versin: http://torjo.com/code/logging-v132.zip I've seen that some of you have requested "levels", and yes, I should add them. I hope I'll have time to implement them soon (less than a month). Anyway, I'll request a formal review after implementing levels as well. 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!
On Fri, 29 Apr 2005 22:59:45 +0200 John Torjo <john.lists@torjo.com> wrote:
I've seen that some of you have requested "levels", and yes, I should add them. I hope I'll have time to implement them soon (less than a month).
Thanks!!! Also, an application should have multiple levels at the same time (i.e., an app may want to have a different level of debug logging per component, library, class, whatever).
Thanks!!!
Also, an application should have multiple levels at the same time (i.e., an app may want to have a different level of debug logging per component, library, class, whatever). _______________________________________________
This is an interesting request, and I assume it'll change the way I implement multiple levels. Is this a desireable feature? What do you all think? In other words, if I understand correctly, you want to be able to set the level of each log (independently of other logs). In this case, instead of enabling/disabling logs, I can simply set the level of the logs -- and have a level called DISABLED (which is equivalent to disabling one 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!
John Torjo wrote:
Also, an application should have multiple levels at the same time (i.e., an app may want to have a different level of debug logging per component, library, class, whatever). _______________________________________________
This is an interesting request, and I assume it'll change the way I implement multiple levels.
Is this a desireable feature? What do you all think?
It's a requirement for me. -Dave
On Fri, 06 May 2005 14:01:28 -0500 David Greene <greened@obbligato.org> wrote:
John Torjo wrote:
Also, an application should have multiple levels at the same time (i.e., > an app may want to have a different level of debug logging per > component, library, class, whatever). _______________________________________________
This is an interesting request, and I assume it'll change the way I implement multiple levels.
Is this a desireable feature? What do you all think?
It's a requirement for me.
Ditto, obviously ;->
Hi John, John Torjo <john.lists <at> torjo.com> writes:
I've seen that some of you have requested "levels", and yes, I should add them. I hope I'll have time to implement them soon (less than a month).
I think you (or anyone) should be able to implement levels by changing the manager only, although I guess that depends on what "implement levels" really means. I also think appenders/modifers should be able to be removed as well as added. It seems to me that the manager should deal with appender add/remove (or connect/disconnect if you prefer) in a way similar to enable/disable (or levels). However, to be able to do that appenders (or connections to them) need to be comparable. It should be possible to write a manager to do this (eg one that indexes appenders by name), but the logger interface won't let me. Given the various requests/discussion surrounding exactly how some parts of logging should best be done, I still think the simplified manager-log_impl interface I proposed previously, where the manager provides an appender/modifier vector to the log_impl, has both performance advantages and allows more flexibility in manager implementation/features. However, it probably isn't general or clean enough an interface, and this could be addressed by providing a concept something like the following, to replace the (not customisable at present) logger_impl. struct sink { void write(const log_types::stream &s); bool enabled(log_types::level l); }; The rest of the interface (actual type) is log_manager defined. A sink with the current semantics + level support implemented by extending the enabled flag to be a level (something you previously talked me out of, but I'm definitely happy to see it return) would look something like: struct sink { template <class IT> sink(log_types::level l, IT first, IT last) : m_level(l) { set_sinks(first, last); } // used by manager to update level similar to enabled updates now void set_level(log_types::level l) { m_level = l; } // used by manager to add or remove appenders and/or modifers // ordering of these is manager (IT type actually) defined - // the sink/logger doesn't care. template <class IT> void set_sinks(IT first, IT last) { sinks_ptr p = new sink_vec(first, last); // needs a lock here, or magic shared_ptr::replace magic :-) m_sinks = p; } void write(const log_manager::stream &s) { { // needs lock here or some other magic sinks_ptr p = m_sinks; } // no need to lock here - allow whatever level // of concurrency appenders support if (!p) return; log_manager::string msg = s.str(); for (sink_func *fp = p->first(); fp != p->last(), fp++) { (*fp)(msg); } } bool enabled(log_types::level l) { return l >= m_level; } typedef boost::function< void(log_manager::string&) > sink_func; typedef std::vector< sink_func > sink_vec; typedef boost::shared_ptr<sink_vec> sinks_ptr; sinks_ptr m_sinks; log_types::level m_level; // mutex needed if no replace/atomic_ptr; }; I'm assuming above that you intend to introduce a feature similar to the one your original postings re. your logging library convinced me to drop - one where the enabledness is not a bool but a scalar used as a threshold against some level specified in the log command? Something like: BOOST_ENABLE_LOG(my_log, WARN); BOOST_LOG(my_log, ERROR) << "This is an error"; BOOST_LOG(my_log, DEBUG) << "This is debug"; which would output: "This is an error" (above specified level) but not "This is debug" (below level)? I hope the code above is legible - its just typed into gmane from memory + reference to your latest code, so don't expect it to be correct! Regards Darryl.
Hi Darryl, Sorry for the late reply...
I think you (or anyone) should be able to implement levels by changing the manager only, although I guess that depends on what "implement levels" really means.
I also think appenders/modifers should be able to be removed as well as added. It seems to me that the manager should deal with appender add/remove (or connect/disconnect if you prefer) in a way similar to enable/disable (or levels).
Yup, you are correct.
However, to be able to do that appenders (or connections to them) need to be comparable. It should be possible to write a manager to do this (eg one that indexes appenders by name), but the logger interface won't let me.
Given the various requests/discussion surrounding exactly how some parts of logging should best be done, I still think the simplified manager-log_impl interface I proposed previously, where the manager provides an appender/modifier vector to the log_impl, has both performance advantages and allows more flexibility in manager implementation/features. However, it probably isn't general or clean enough an interface, and this could be addressed by providing a concept something like the following, to replace the (not customisable at present) logger_impl.
I really like the sink concept. I could do something like: get_sink("app.*").set_level(LEVEL_DEBUG); get_sink("app.*").add_appender(some_appender); get_sink("app.*").del_appender(some_appender); The easiest way to implement deletion of appenders/modifiers, is to allow naming them. Once an appender has a name, when you say: get_sink("app.*").del_appender( "my_cool_appender"); it will remove it. This will remove all appenders with that name. I think this would be quite an easy to use solution. What do you think? 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 <john.lists <at> torjo.com> writes:
Hi Darryl,
Sorry for the late reply...
No worries.
I really like the sink concept. I could do something like:
get_sink("app.*").set_level(LEVEL_DEBUG); get_sink("app.*").add_appender(some_appender); get_sink("app.*").del_appender(some_appender);
Something like that, yes. Though I would spell it log_mgr.add_appender("app.*", some_appender) or (if a singleton log_mgr) get_log_mgr().add_appender("app.*", some_appender)
The easiest way to implement deletion of appenders/modifiers, is to allow naming them. Once an appender has a name, when you say:
get_sink("app.*").del_appender( "my_cool_appender");
it will remove it. This will remove all appenders with that name. I think this would be quite an easy to use solution.
What do you think?
Yes, names are fine - I'd certainly use that approach in the default manager. I still think the actual sink should be oblivious to this, as I said:
However, to be able to do that appenders (or connections to them) need to be comparable. It should be possible to write a manager to do this (eg one that indexes appenders by name), but the logger interface won't let me.
c u Darryl.
Darryl Green wrote:
John Torjo <john.lists <at> torjo.com> writes:
Hi Darryl,
Sorry for the late reply...
No worries.
I really like the sink concept. I could do something like:
get_sink("app.*").set_level(LEVEL_DEBUG); get_sink("app.*").add_appender(some_appender); get_sink("app.*").del_appender(some_appender);
Something like that, yes. Though I would spell it log_mgr.add_appender("app.*", some_appender) or (if a singleton log_mgr) get_log_mgr().add_appender("app.*", some_appender)
The reason I chose the above was for extensibility - every new feature would be appended to the sink -- much easier to find, IMO. 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 updated the lib so that it allows enabling/disabling of logs at compile-time, what Darren Cook asked.
[...]
Download the latest versin: http://torjo.com/code/logging-v132.zip
John, would you mind to use a new version number if you update the library? I think it would make it easier for the rest of us to talk about a certain version. Thanks, Daniel
Daniel Frey wrote:
John Torjo wrote:
I've updated the lib so that it allows enabling/disabling of logs at compile-time, what Darren Cook asked.
[...]
Download the latest versin: http://torjo.com/code/logging-v132.zip
John, would you mind to use a new version number if you update the library? I think it would make it easier for the rest of us to talk about a certain version.
Yup, sorry - will do so next. It's just that I need to update several other HTML pages, and I'm kind of lazy ;) 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!
Hello, I used John's logging library for a project at work and it worked well. Note that this review is for the previous version, not the one currently on the website, which I haven't tried yet. * What is your analysis of the design? Before trying this library I tried some other C++ logging libraries, including all the Log4J clones. For various reasons I rejected all of those - some of them wouldn't even compile, and their documentation was lacking. I also had my own logging code but it was in a more C style of programming and I wanted something that was in C++. Compared to the Log4J clones, I found John's library to be easy to understand. There are two shortcomings that I found: - Whenever you restart your program it wipes out the previous log file. I could have coded around this, but it wasn't a big deal to me. It would be nice to have it automatically rename or append to the old log file instead of just replacing it, IMO. - No log rotation. This library does not support log rotation (at least in the version I tried). I didn't need this feature for my project, but I'm sure it will be a frequently requested feature. * What is your evaluation of the documentation? Great. * What is your evaluation of the potential usefulness of the library. Nearly essential. Just about every program I've written uses some kind of logging. * Did you try to use the library? With what compiler? Did you have any problems? VS.NET '03 on Win2k, which didn't have any problems. * How much effort did you put into your evaluation? I used it in the program I was working on, which was multithreaded, with each thread printing log messages. I was able to run it on even the slowest computers without any problem. * Are you knowledgeable about the problem domain? I'm no expert. I just wanted to use a logging library which used streams instead of printf-style formatting and worked with multiple threads. This library has fewer features than others, but it gets the job done. * Do you think the library should be accepted as a Boost library? Yes, but I suggest the author adds log rotation, because it is a feature lots of people need. -Matt
The proposed Logging library hasn't entered any formal review period yet, so isn't sending a review like this premature? Or is this standard practice? The feedback is certainly helpful. On 5/5/05, Matthew P. Cashdollar <mpc@innographx.com> wrote:
It would be nice to have it automatically rename or append to the old log file instead of just replacing it, IMO.
You can do this by passing the second argument to the write_to_file ctor: write_to_file (const log_types::log_name_string_type& file_name, bool overwrite = true); I think this default should be changed to false though, as I suspect that is what most users would prefer.
- No log rotation. This library does not support log rotation (at least in the version I tried). I didn't need this feature for my project, but I'm sure it will be a frequently requested feature.
I have implemented two different classes of rolling appenders for John's library and sent them to this list on several occasions. I do so again with this mail in the hopes that John will include them with the next release. They include: rolling_file_appender - size-based log rollover. Keeps up to <n> files each no larger than <m> bytes. Removes the <n>+1st log when rolling over. Depends on Boost.Filesystem. periodic_file_appender - time-based log rollover. Rotates logs based on a rollover period, specified in seconds. The user can specify a filename "prototype" and a factory method that will be used to generate the actual log filenames (e.g. filename = filename_factory (filename_prototype)). I use this, for example, to create date-stamped log filenames. Includes {hourly,daily,weekly,monthly,yearly}_file_appender convenience functions. No logfile backup/removal policy. No external dependencies. -- Caleb Epstein caleb dot epstein at gmail dot com
Hi Matt, Many thanks for the review!
It would be nice to have it automatically rename or append to the old log file instead of just replacing it, IMO.
- No log rotation. This library does not support log rotation (at least in the version I tried). I didn't need this feature for my project, but I'm sure it will be a frequently requested feature.
Yes, I will do it. I like log rotation myself ;)
* Do you think the library should be accepted as a Boost library?
Yes, but I suggest the author adds log rotation, because it is a feature lots of people need.
Yup, consider it done ;) 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 (8)
-
Andreas Wachowski -
Caleb Epstein -
Daniel Frey -
Darren Cook -
Darryl Green -
David Greene -
Gennadiy Rozental -
Jody Hagins -
John Torjo -
Mark Blewett -
Matthew P. Cashdollar -
Rob Stewart -
Roland J. Weiss