Re: [boost] Boost.Logging: formal review

From: Gennadiy Rozental (gennadiy.rozental_at_[hidden])
Date: 2005-11-14 11:33:20

>> 1. Design: Lightweight interface
>> Log library brings a lot of dependencies. In some case I do not want this 
>> if
>
> Care to exemplify? What are the dependencies?

<iostream>
<sstream>
<vector>
<fstream>
<cstdlib>
<ctime>
<boost/function.hpp>
....
more

I may need to use logging in some headers I prefer to keep lightweight. In 
this case lightweight interface is used.

>> 5. Implementation/Design: log entry data copying.
>> Modifiers implemented by applying modifier for string that represent 
>> entry
>> data. This model is inefficient in following regards:
>>   a) you need to make a copy of original entry data for every output.
>>   b) you need to prepend the strings in most cases - which is inefficient
>> operation.
>>   c) you couldn't share the work for different outputs - you need to 
>> repeat
>> it for every string
>>
>> IMO better model would be to apply modifiers to outputs instead.
>>
>
> Yes, I will consider this. IMO, is better to have a working model, which
> can be optimized later.

You couldn't change an API post review and introduce completely new 
modifiers model. It's a different library that needs different review

>> Actually since macros are not primary interface in different subsystems 
>> log
>> may look different. Couple examples:
>>
>> 1. LOG( INFO, PROG_FLOW, "SocketLib" ) << "Connection esteblished to: " 
>> <<
>> address;
>> 2. LOG( DEBUG, RETURN_VALUE ) << "Fetched value: " << v;
>> Here a LOG macro refer to some keyword by name. Usually I have keyword 
>> per
>> file, per library or per class.
>> 3. DEBUG_LOG( DATA_FLOW ) << "Input msg: " < msg;
>> Here DEBUG_LOG automatically apply DEBUG level and refer to keyword by 
>> name
>>
>
> This IMO is too much to type, and I personally wouldn't use it in
> real-life apps.

How DLOG( DATA_FLOW) is more to type then BOOST_LOG( DEBUG )? Depends on 
what you prefer one may select more or less verbose statement. But most 
importantly: in my view Filters should be configurable. IOW you just need 
log level - it's your choice. But if  I need more filters I should be able 
to specify them.

>>>>Also multithreaded application should support filtering based on thread
>>>>id.
>>>
>>>And what's stopping you from making an appender that does just this?
>>>
>>>// trivial example
>>>struct only_for_thread_id {
>>>  only_for_thread_id(int tid, appender_func forward_to)
>>>    : tid(tid), forward_to(forward_to) {}
>>>  void operator()(const std::string&,const std::string & msg) {
>>>    if ( ::GetCurrentThreadId() == tid) forward_to(msg);
>>>  }
>>>  int tid;
>>>  appender_func forward_to;
>>>}
>>
>>
>> You must be kidding, right? I want filtering on log level. So that entry
>> appear or not appear in all outputs.
>
> Please read what you just wrote a couple of lines above: "filtering
> based on thread id."

Sorry typo. I want filtering on thread id. So that entry appear or not 
appear in all outputs based on which is current thread id.

>>>>need to keep track of it's name to be able to remove it and it's index 
>>>>to
>>>>know how modifiers are ordered. This ability to configure log remotely 
>>>>in
>>>>many locations makes it impossible to really know what and how is 
>>>>written
>>>>into log.
>>>>   My preferred way to configure the log is with use of configuration
>>>>string. First of all it's simplify an interface and you immediately see
>>>>how
>>>>your log entries going to look like. Here is an example:
>>>>"keyword=*,-ACD;categ=prog_flow,return
>>>>value,-details;l=debug;track=on;roll=10000;prefix=file ( line ) - time
>>>>:;timeformat=%s:%m".
>>>
>>>You can implement Configuration Support on top of the current library.
>>
>>
>> I do not see how it possible and why should I do this on top of useless 
>> API.
>
> Funny, but I think your last statement is quite useless.

Ok Useless is wrong word. I meant to say that I would never use it since 
single configure string is so much more clear and convenient.

>>>And besides, if you want to configure logging, you'll still need to
>>>identify each log, appender and manipulator by a string.
>>
>>
>> Why is that? I do not want or need to know log name to configure it. I 
>> have
>> an instance.
>
> Because when you have some setting in the configuration file, you need
> whom it refers to. Therefore, you need to have some log-to-string
> correspondence.

I don't see how log name comes into play here (it could but only if end user 
will choose to). I may have single log that doesn't care about the name at 
all. Or I may have 2 different named config parameters:

config.get( "system_log_config" )
config.get( "admin_log_config" )

But this strings has nothing to do with log names either.

>>>>Much more reliable solution is to use some kind of startup log that does
>>>>not
>>>>require configuration.
>>>>
>>>
>>>And where would that log write to? What if it's very important data?
>>>To console? What if you don't have console?
>>
>>
>> I think I covered that in my last statement.
>
> Well, I don't think it's covered.

Let me repeat: Much more reliable solution is to use some kind of startup 
log.
IOW we use dedicated log that only used during startup.

>>>And lets face it -- when one starts using a logging lib, will at least
>>>trace one call to the debug lib. If he sees the line doesn't show up
>>>anywhere, he'll most likely read the docs. If you take a look at the
>>
>>
>> I don't see how reading the docs will help. Solution is dangerous in it's
>> nature.
>
> When you'll come up with something better, I'll use it. Until then...

I think I did.

>>>Basic Usage, you'll see the 'flush_log_cache()' call.
>>>
>>>Besides, even if you don't call it and you write 256 messages to a log,
>>>the caching will automatically turn itself off and flush. The same
>>
>>
>> And what if log is not configured yet? What will happened? We will loose 
>> all
>> those 256 messages or program will crash?
>
> Ok, I have not handled this case yet. I need to handle it -- have a

This is my point.

>>>>7. Misfeature: log hierarchies
>>>>I personally never have a need for that and have some difficulties to
>>>>imagine why would anyone have. You could probably have it on top of
>>>>existent
>>>>solution as add-on. If it doesn't require any new interfaces (or some
>>>
>>>Have you heard of modules, and sub-modules? What if each
>>>module/sub-module was to have a log to write to?
>>
>>
>> I primarily use one file for everything. Why would I want 10 different
>> files? So to figure out what happened I will need to jump through 10
>
> You can have multiple logs that output to the same file.

And how about thread safety: Don't you lock on log level?
And what if I want to filter out specific subsystem? Do I need to 
register/unregister outputs?  But this will still cause log statement to be 
executed.

Why would I do that instead of common filtering mechanism with multiple 
filters?

>> different output comparing timestamps? (*if* they are printed). I do
>> *rarely* use more than additional logs for information dedicated to
>> different target audience (operation departments, end users). But this is
>> not driven by module/submodule hierarchy. To mark the modules I use much
>> better idiom - keyword (all within bounds of same log).
>
> I'm not even gonna ask why yours is such a better idiom...

Because I have single idiom "filters", why you propose numerous different 
ways to do this task. And filters are less prone to be misused.

>>>Please enlighten me: how can you implement a disabled log at macro level?
>>
>> Numerous ways. Here is from top of my head:
>>
>> struct nil_stream {}
>>
>> template<typename T>
>> nil_stream const& operator<<( nil_stream const& ns, T const&) { return 
>> ns; }
>>
>> #define LOG( .... ) if(true) {} else nil_stream() <<
>
> Amazing...
> You can turn on/off ***all*** logging... Wow!

Why all? I could use different macro with different logs? Macro are not 
primary interface. And as I told you in practice there is no need to do this 
at all.

> And to think that BOOST_LOG allows you to turn on/off certain logs -- 
> allowing for some information to be logged while what's not important is
> turned off... Your solution is indeed much better...

This is still the case for me. Even more that.

> Not to say that if you write something like:
>
> LOG << some_lengthy_function();
>
> some_lengthy_function() will still be executed, even though logging is
> disabled...

How did you case to such conclusion? Since when false branch gets executed?

>>>>II. Implementation flaws
>>>>------------------
>>>>
>>>>2. Multithreading support implementation
>>>>  a) For some unclear reason author chose to reimplement some of
>>>>Boost.Threads functionality in some places (and in some places
>>>>Boost.Thread
>>>>is used always). I believe log library shouldn't do this.
>>>
>>>It was requested -- some users wanted to remove dependency on
>>>Boost.Thread.
>>
>>
>> Well it still wrong. You couldn't justify that by user's request. BTW you 
>> do
>> depend on Boost.Threads still.
>
> ???
> If you use ts_appender(), yes.
> Otherwise, not.

So you do. You couldn't have it both ways.

>>>>4. collection in use
>>>>appender_array and modifier_array are better be implemented using lists
>>>
>>>Have you done some tests, or is this just a gut feeling?
>>
>>
>> I did not provide any tests, did you? And it's not a gut feeling. In 
>> places
>> where it's important you never need random access.
>
> It's not about random access. It's about so many tests have shown that
> std::vector is faster than std::list, especially when the vectors are
> small - in the case of logger_impl.

Again: I do not see a single test case. And unless you are using random 
access I believe you statement is wrong. Why would we have lists at all? you 
primarily use this collections for forward traversing and inserting removing 
operations. I would assume list would behave better.

>>>>5. exception support
>>>>
>>>>try {
>>>>    LOG << "aaa" << foo()
>>>>}
>>>>catch(...) {
>>>>    LOG << "exception"
>>>>}
>>>>
>>>>This construct doesn't seems generate what is expected if foo() throws 
>>>>an
>>>>exception
>>>
>>>What is expected?
>>
>>
>> Try to run this and you will see.
>
> It tries to print as much as possible from the original "LOG << "aaa" <<
>  foo()" expression, and then it prints "exception".
>
> What do you expect?

First of all in my test (VC7.1) it did not print aaa and it printed second 
statement on the same line

[aaa] ... [aaa] exception

>>>>If we do why all the appenders are so heavy?
>>>>
>>>
>>>I don't understand what you mean.
>>
>>
>> So costly to copy.
>
> How would you know?

Just do sizeof(logger). Keep in mind that your design assumes that may copy 
logger for *every* log entry.

Gennadiy