From: Darryl Green (darryl.green_at_[hidden])
Date: 2005-11-15 05:42:14


Andrew Schweitzer <a.schweitzer.grps <at> gmail.com> writes:
>
> Using GetTickCount and GetThreadTimes on Windows XP Pro, recorded time
> to execute some simple pieces of logging code in a loop. Divided by loop
> iterations to get time per iteration. This is a 3Ghz Pentium. Not sure
> how good these tests are, but here's the results:
>
> results:
> elapsed ms thread time ms ns / call
                (GetTickCount)
> (GetThreadTimes) (in thread)
> cout 1329 421 42100
> enabled log 1469 453 45300
> cout "disabled" 15 15 15
> disabled log 531 531 531

Compiler/version? Optimization settings? How long does a single or a very small
number of iterations of the disabled cout and disable log take?

>
> Here's a little detail on tests
> cout, 10,000 times, l_dw increments each loop:
> cout << l_dw << endl;
>
> enabled log, 10,000 times:
> //outside loop:
> enable_logs("lgTest");
> //in loop:
> BOOST_SCOPEDLOG(l_lgTest) << l_dw << endl;
>
> cout "disabled", 1,000,000 times:
> //outside loop:
> bool l_bEnabled = false;
> //in loop:
> if(l_bEnabled)
> {
> cout << l_dw << endl;
> }

The disabled cout test, if it really is as simple a bit of code as that should
take something close to 0 time to execute - which it does. If you put the if
(l_bEnabled) test in a separate compilation unit to the loop body is
performance the same?

>
> disabled log, 1,000,000 times:
> //outside loop:
> disable_logs("lgTest"); //this not in loop
> //in loop:
> BOOST_SCOPEDLOG(l_lgTest) << l_dw << endl;

This involves at least the creation and destruction of a small temporary
object, a function call to a separate compilation unit and an inderection
through a shared ptr (not expensive) 500 odd ns seems broadly ok for that I
guess - so something like 2 million disabled log messages/second.... Don't
accidentally enable all logs/that log.... If you have a system with 100 logs,
and only 1 enabled, the other 99 logs (being called at the same rate) are using
the same amount of CPU as your 1 enabled log - not too bad - not as good as it
could be either I'd guess.

Some performance test should be added to the code before it is released - what
enabled/disabled performance ratio do you think is needed for a "pass"? What
sort of "nop function" do you think the disabled log needs to be equivalent to
to pass?