Re: [boost] [log] Boost.Log formal review

Subject: Re: [boost] [log] Boost.Log formal review
From: Andrey Semashev (andrey.semashev_at_[hidden])
Date: 2010-03-10 13:52:41

On 03/10/2010 10:07 AM, Vladimir Prus wrote:
> Andrey Semashev wrote:
>>
>> Well, it's not that expensive as you may think. The view composition
>> is a single memory allocation (not counting ones that may take place
>> during attribute values acquisition) and no tree rebalancing or
>> anything like that. There are also no memory allocations and copying
>> for attribute names.
>
> Do you have any performance measurements to back up the above statement,
> and generally to give the idea of runtime performance, compiler performance
> and code size implications of using Boost.Log?

Partially, that was discussed before the review. There is no document on 
performance comparisons, but there is a discussion thread [1] with 
testing results against log4cxx. The brief outcome is as follows:

* When no or nearly no log records are dropped by filters, Boost.Log is 
faster by ratio around 0.95.
* When most or all log records are dropped by filters or logging is 
completely disabled, Boost.Log is slower up to 2 times.
* In multithreaded tests, having the similar settings, either both 
libraries tie, or Boost.Log is faster with ratio around 0.85.
* In tests of formatting the main bottleneck is date/time formatting, 
which is done by Boost.DateTime. Up to 5.5 times slower than log4cxx in 
these cases. Without date/time (severity and message only) Boost.Log is 
faster (around 0.9).

A few comments on these numbers. The figures are the ratio of execution 
times of Boost.Log and log4cxx. The measurements were done on a 
dual-core machine, under Windows Vista. MSVC 9 + STLPort was used. The 
tests did not produce any output, all log records were discarded.

The performance depends greatly on the STL version being used, in case 
of Boost.Log, and the one being shipped with MSVC is not a good one if 
you seek for performance. Use STLPort instead.

The performance drop for cases when nearly no log records pass filtering 
is not that significant, if absolute numbers are considered. My guess is 
that the most part of that difference is due to the call for the filter 
and its implementation (which includes an ad-hoc multimethod call). 
Considering the flexibility of attributes and filtering Boost.Log 
provides, I'd say it's a fair trade.

The more considerable concern is the case when logging is disabled. In 
this case no filtering or attribute values view composition is done, yet 
the performance drop is there, and it's the most significant (it's those 
"2 times slower"). This needs closer investigation. But again, we're 
talking of a few CPU ticks here.

The date/time formatting is the major slowdown. I have a few thoughts on 
optimizing Boost.DateTime, which I can implement when things around 
Boost.Log are settled.

No tests identified that the attribute values view composition is the 
performance bottleneck. I think, it is optimized well enough, and in 
order to further improve performance, other parts of the library should 
be improved.

I did not test other aspects that you mentioned, such as compile times 
or code size. But I didn't see any extraordinary code bloats in the 
library examples or other uses of the library. Compile times also stay 
reasonable, with more or less modern compilers.

[1] http://tinyurl.com/ya85vwf