RE: [boost] Re: [function] timing trivia

On Behalf Of Pavel Vozenilek Subject: [boost] Re: [function] timing trivia
"Matthew Hurd" <matt@finray.net> wrote
[snip boost::function benchmark info]
Can't explain it. Boost function can't be faster for the 10 million loop by more than a millisecond. I see none of this whacky behaviour with release optimized code.
Can you post complete test code somewhere?
/Pavel
Probably small enough to post here... (12KB) Open the .sln, compile and run the "test" project and you should see something similar to: This is an Intel P43.2 I'm running on now and I'm getting output like: --------------------------------------------------------------------- quick time before overhead estimate= 393.5650855126686 nanoseconds time including previous console output = 1.157412246893155 milliseconds overhead estimate = 127.8459831920134 nanoseconds quick time after overhead estimation = 95.25779139797076 nanoseconds time including previous console output = 1.160907957159062 milliseconds --------------------------------------------------------------------- new timer for checking static carry --------------------------------------------------------------------- quick time -1.253391992078558 nanoseconds quick time -5.013567968314233 nanoseconds overhead estimate = 127.8459831920134 nanoseconds quick time 2.506783984157143 nanoseconds quick time -5.013567968314233 nanoseconds --------------------------------------------------------------------- check timing jitter on a simple loop --------------------------------------------------------------------- --------------------------------------------------------------------- estimating indirect function call overhead --------------------------------------------------------------------- --------------------------------------------------------------------- boost function measurements --------------------------------------------------------------------- median time = 250.698 microseconds 90% range size = 6.26696 nanoseconds widest range size (max - min) = 149443 nanoseconds minimum time = 250.695 microseconds maximum time = 400.138 microseconds 50% range = (250.695, 250.701) microseconds 50% range size = 6.26696 nanoseconds stop the optimiser eliding garbage = 3.33328e+017 stop the optimiser eliding garbage = 3.33328e+017 --------------------------------------------------------------------- direct in-line --------------------------------------------------------------------- median time = 250.691 microseconds 90% range size = 6.26696 nanoseconds widest range size (max - min) = 29324.4 nanoseconds minimum time = 250.688 microseconds maximum time = 280.013 microseconds 50% range = (250.688, 250.692) microseconds 50% range size = 3.76018 nanoseconds stop the optimiser eliding garbage = 3.33328e+017 stop the optimiser eliding garbage = 3.33328e+017 Press any key to continue . . . You see here I look at the median time for boost function and direct-inline and see only a 7 ns difference which is probably smaller than I can truly measure I suspect... At the top of looper.hpp there is #define MAX_FN_LOOP 1e5 which controls the iterations in the timing loop. If my hacked up untidy code is buggy or if you have some insight I would love to hear about it. Regards, Matt Hurd _______________________ Susquehanna Pacific P/L hurdm@sig.com +61.2.8226.5029 _______________________ IMPORTANT: The information contained in this email and/or its attachments is confidential. If you are not the intended recipient, please notify the sender immediately by reply and immediately delete this message and all its attachments. Any review, use, reproduction, disclosure or dissemination of this message or any attachment by an unintended recipient is strictly prohibited. Neither this message nor any attachment is intended as or should be construed as an offer, solicitation or recommendation to buy or sell any security or other financial instrument. Neither the sender, his or her employer nor any of their respective affiliates makes any warranties as to the completeness or accuracy of any of the information contained herein or that this message or any of its attachments is free of viruses.

"Hurd, Matthew" <hurdm@sig.com> wrote
This is an Intel P43.2 I'm running on now and I'm getting output like:
boost function measurements: median time = 250.698 microseconds direct in-line: median time = 250.691 microseconds
You see here I look at the median time for boost function and direct-inline and see only a 7 ns difference which is probably smaller than I can truly measure I suspect...
I wrote my own test (the most simple one, call function/boost::fn in loop and measuring total time). The numbers I got give me ~18 microseconds overhead per single boost::function call (raw call takes ~404 microseconds). I use Intel C++ 8.0 plugged in VC6 IDE,, release mode, Athlon XP 2200+, W2K. /Pavel ------- test (shortened) ----- #define MAX_FN_LOOP 1e5 static double not_empty() { static double sum; static double i; sum = 0.0; for (i = 0.0; i < MAX_FN_LOOP ; ++i) { sum += i * i; } return sum; } void test1() { DWORD tick1 = GetTickCount(); double x = 0; for (int i = 0; i < 100000; ++i) { x += not_empty(); } DWORD tick2 = GetTickCount(); } void test2() { DWORD tick1 = GetTickCount(); boost::function< double (void)> fn = ¬_empty; double x = 0; for (int i = 0; i < 100000; ++i) { x += fn(); } DWORD tick2 = GetTickCount(); } ---------------------------------- test1() and test2() took each 30-40 seconds. GetTickCount() resolution is at least 10 milliseconds.
participants (2)
-
Hurd, Matthew
-
Pavel Vozenilek