
My review of the proposed logging library follows. Summary: I was disappointed by the amount of code needed to get the most basic logging working. The use of macros to declare loggers seems like a bad design choice. The absence of support for syslog was surprising. I encountered many compiler warnings. The documentation was unsatisfactory. Many of the features that I would have liked to see were missing. Despite all this, John seems to be enthusiastic and responsive: there is a real chance that he will be able to fix many of these problems. Detail: In order to evaluate the library I decided to apply it to Decimail, an IMAP mail server that I wrote. It currently does some fairly basic logging of the IMAP conversation, enabled by a flag in its configuration, to syslog. Most of the programs that I've written do some sort of logging. Typically it's something as simple as: #include <iostreams> cerr << "starting to frobnicate\n"; or #include <syslog.h> syslog(LOG_INFO,"starting to frobnicate"); or #include <assert.h> assert(frob!=-1); These techniques are all very simple to use, and I feel that a logging library needs to be equally straightforward for basic operations: #include <boost/logging.hpp> log << "starting to frobnicate"; Of course it needs to offer more features than that - but the most basic use needs to be simple. (If it's not that simple, then potential users will instead just write to cerr as above; as their needs slowly grow they'll add their own ad-hoc logging functions; it will then be too late to take the leap to a logging library.) So I started by reading the main_intro.html and getting_started.html docs. I eventually got to "Example 1", which described how I had to add two new files to my project (21 lines) and call an initialisation function from main(). I could then log by changing my code as follows: if (Configuration::singleton().get_bool("imapd_log_imap",false)) { //syslog(LOG_MAIL|LOG_DEBUG,"{%d} S: * %s",num,msg.c_str()); L_ << "{" << num << "} S: * " << msg; } Having fixed one error in the example (g_l_filter vs. g_log_filter) and copious warnings I was able to see log output on the console (twice?) and in a file. This was all a lot more effort than I was expecting, but it did seem to work. I found the use of macros in example 1 unsatisfactory. Specifically, the logger "object" which I declare in the header and to which I send my log messages (L_ in the code above) is actually a macro, not an object. This means that I have to handle it with great care. For example, say I currently have: void do_something(ostream& log_to, .......) { log_to << "starting to do something"; ... } and I want to convert this to use this library. I write: void do_something(logger& log_to, .......) { log_to << "starting to do something"; ... } This fails - and probably with an incomprehesible error message. The motivation for the macro is sensible: it evaluates to something like if (l.level > current_level) l so that time-consuming functions in the log line are not evaluated if they will not actually be stored. But I would much prefer to see this optimisation made more explicit, so that the user can tell what's going on and avoid it if they want or need to: logger l; l << "message"; // wasteful if logging is disabled, but do I care - foo(l); // - because this works as expected. LOG_IF_ENABLED(l) << expensive_function(); // if I do care, I can invoke a macro explicitly #define ll LOG_IF_ENABLED(l) // or if I want conciseness I can _choose_ to do this ll << expensive_function(); Or I could do this, without a macro at all, if I were the sort of person who felt that all macros were evil: if (l.enabled()) l << expensive_function(); I think that what's practically needed to make this work is to bundle together the current filter and logger objects into a single _object_, rather than bundling them together using a macro. Next I tried to use the library's "filter" mechanism in place of the if-condition you can see above. I looked at "Step 1: Filtering the message" at workflow.html, expecting to find a filter that I could initialise with my condition (as a value, or by reference to a variable, or passing a functor or function-pointer). But it seems that all of the provided filter classes are things to provide various sorts of thread-safety. Writing my own is not difficult, though it might be more conventional to use a functor (i.e. operator()()) rather than a class with an is_enabled member [this would allow you to use things like lambda expressions, I think]. So I wrote: struct log_imap_filter { bool is_enabled() const { return Configuration::singleton().get_bool("imapd_log_imap",false); } }; Using this involved more macros: // log.hh: typedef log_imap_filter filter_type; BOOST_DECLARE_LOG_FILTER(g_log_filter, filter_type) // log.cc: BOOST_DEFINE_LOG_FILTER(g_log_filter, filter_type ) I don't know why these need to be macros. It seems to obfuscate what is going on to me. The last thing that I needed to replace my syslog call was to specify the log level, which I noticed in workflow.html under "Step 2A: Gathering the message". (The fact that I couldn't find any description of this fairly central functionality anywhere else, e.g. in any of the pages in the tutorial section, seems typical of the documentation). Based on that example, I tried: L_(dbg) << "happily debugging"; which failed to compile. I haven't worked out what I should have written. I did try it with a namespace prefix. The final thing that I looked at in detail was scoped logging. When I'm writing more detailed logging code (e.g. for debugging) I generally make it scoped, i.e. reporting interesting function entries and normally exits. I like to indent each scope by a few characters in the log output, e.g. void foo() { cerr << "foo starting\n"; for(int i=0; i<5; ++i) { blah(i); } cerr << "foo done.\n"; } void blah(int i) { cerr << " blah " << i << "\n"; // note indentation ... } I read the scoped_logs.html page, and it seems that the BOOST_SCOPED_LOG[_CTX] macro deals with the starting/ending business. Compared to my explicit start/done output above, it has the feature that the done message will be generated if the function returns using an explicit return statement or if it throws an exception. This may be an advantage or a disadvantage: with my code, the absence of the done message would suggest that an exception might have occurred. Ideally the end-of-scope log message would indicate whether it was invoked during exception handling; could that be done using compiler-magic? But why does it have to be a macro? And there doesn't seem to be any indentation or other way of matching up the start and end messages. If they were matched up, then a log file viewer tool could provide collapse/expand tree view functionality (does Purify still do something like that?). I was also surprised that no use was made of __LINE__, __FUNCTION__ etc. in the scoped logging or other macros. I also don't see any way to couple the scoped logging features with enabling and disabling logging. Specifically, I might detect that something of interest is happening and want to increase the log level within that scope: void foo() { scoped_log sl(log); for (int i=0; i<100; ++i) { scoped_enabled_logging_if s(log, i==42); blah(i); // logging enabled in here only if i is 42 } } I didn't look in much detail at the "destinations" functionality, but I'd like to note some of the features that syslog offers for files that it writes to: - Flushing of files after each message is optional. Not flushing helps performance, but it might mean that critical messages are lost before a crash. - Enormous numbers of identical messages within a short period are compressed to a single line, "last message repeated 193247 times". - Periodic "MARK" lines can be generated to show that the application is still running. Other features that I've seen in applications that do their own logging to files include: - Creating new files for each sub-process or thread, by appending a thread identifier to the filename. - Truncating individual messages to some limit (e.g. to avoid logging a rogue char* that points to a huge block of stuff with a \0 a megabyte later), or individual fields within the log message. In my quick review I didn't see any of that functionality. The rolling_file feature looks useful for long-running applications where it's necessary to move the log files (e.g. to compress them) without interrupting the process. I suggest referring to the logrotate utility for how this sort of thing is often handled on Unix servers; for example, it can be configured to send a signal to a process to tell it to close and re-open its log file with the same filename. Finally I'd like to look at how the user can control the logging. I don't see any built-in functionality for this. I have a couple of suggestions: environment variables and command-line options. An environment variable could be used as follows. The code would do something like this: g_l()->writer().write(::getenv("MYAPP_LOG_FMT"), ::getenv("MYAPP_LOG_DEST")); The programmer's choice of format and destination may or may not override the user's choice via the variables. The user could then control the format and destination when invoking the program: $ export MYAPP_LOG_FMT='%time%($hh:$mm.$ss.$mili) [%idx%] |\n' $ export MYAPP_LOG_DEST='file(debug.log)' $ myapp Firefox has something a bit like that IIRC. For command-line integration, I suggest providing an initialisation function that processes argc and argv looking for debug options, and strips them: int main(int argc, char* argv[]) { log.init(argc,argv); // modifies argc and argc // following code doesn't see debug options ... } DirectFB has something like that. Again you could use this to define formats and destinations. You could also give the user control over scoped filtering via a command-line interface. For example: $ myapp --log:default=none --log:parser=debug --log:scheduler=info The names 'parser' and 'scheduler' would match scoped log-enable blocks. I could imagine hierarchical names too. I've used one commercial C++ application that has this sort of logging (you can indicate component, log level and destination), and it proved useful. Conclusion: * What is your evaluation of the design? Breaks up the problem into a sensible set of components. Basic usage requires too much effort. Lacks many features that I would find useful. Pervasive use of macros is unappealing. * What is your evaluation of the implementation? Seems to work. Many compiler warnings do not inspire confidence in code quality. Have not reviewed the code in any detail. * What is your evaluation of the documentation? Poor. But in part, that's because it is documenting the considerable effort required to get basic functionality working. * What is your evaluation of the potential usefulness of the library? Everyone needs logging. If they do it using this library, they'll have to write a lot of code themselves to implement their own filters, destinations and so on. In practice they won't bother and will write their own ad-hoc code. * Did you try to use the library? With what compiler? Did you have any problems? Yes, with gcc-4.1 on Linux. I encountered various warnings which John has already resolved. * How much effort did you put into your evaluation? About 6 hours. * Are you knowledgeable about the problem domain? I've written and used numerous programs with logging features, but have never attempted to write a logging library. And finally, every review should answer this question: * Do you think the library should be accepted as a Boost library? No, not in its current form. Phil.