XML::TreeBuilder strange benchmarking behaviour

Mandor has asked for the wisdom of the Perl Monks concerning the following question:

Hello fellow monks, I encountered some strange benchmark results when I was testing the performance of my current project. At some point in the code the following simple lines can be found.

$tree -> parse_file ($file); # $tree is a XML::TreeBuilder
my @results = $tree -> look_down ('attr' => 'value');
[download]

Now, watch. First line:

timethis (5000, sub {$tree -> parse_file ($file)});
timethis 5000: 16 wallclock secs (12.98 usr +  1.41 sys = 14.39 CPU) @
+ 347.46/s (n=5000)
[download]

Second line:

timethis (5000, sub {my @results = $tree -> look_down('attr' => 'value
+')});
timethis 5000:  2 wallclock secs ( 1.42 usr +  0.00 sys =  1.42 CPU) @
+ 3516.17/s (n=5000)
[download]

First and second line:

timethis (500, sub {$tree -> parse_file ($file); my @results = $tree -
+> look_down('attr'=> 'value')});
timethis 500: 36 wallclock secs (34.32 usr +  0.19 sys = 34.51 CPU) @ 
+14.49/s (n=500)
[download]

Shouldn't the total speed be something over 300? Am I missing something fundamental? Any ideas?

Comment on XML::TreeBuilder strange benchmarking behaviour Select or Download Code

Replies are listed 'Best First'.
Re: XML::TreeBuilder strange benchmarking behaviour by BrowserUk (Patriarch) on Jul 15, 2003 at 14:30 UTC
You are going about that completely the wrong way. In breif, when you are testing the lines seperately, the chances are that the second line does almost nothing after having been repeated one or two times as there is nowhere left to lookdown() to. However, when you repeat the two lines together, you are re-parsing the file each time, and so the tree is reset and lookdown() starts at the top and has some work to do every iteration. Basically, you cannot profile code that has state by repeating it over and over without reseting the state each time. The answer is to use the right tool for the job. Ie. Profiling and not Benchmarking. Get yourself over to CPAN and grab Devel::Smallprof. It's 10 times easier and a thousand times more accurate than the method your trying right now. Examine what is said, not who speaks. "Efficiency is intelligent laziness." -David Dunham "When I'm working on a problem, I never think about beauty. I think only how to solve the problem. But when I have finished, if the solution is not beautiful, I know it is wrong." -Richard Buckminster Fuller	[reply]

Replies are listed 'Best First'.

Re: XML::TreeBuilder strange benchmarking behaviour
by BrowserUk (Patriarch) on Jul 15, 2003 at 14:30 UTC

You are going about that completely the wrong way.

In breif, when you are testing the lines seperately, the chances are that the second line does almost nothing after having been repeated one or two times as there is nowhere left to lookdown() to.

However, when you repeat the two lines together, you are re-parsing the file each time, and so the tree is reset and lookdown() starts at the top and has some work to do every iteration.

Basically, you cannot profile code that has state by repeating it over and over without reseting the state each time.

The answer is to use the right tool for the job. Ie. Profiling and not Benchmarking. Get yourself over to CPAN and grab Devel::Smallprof. It's 10 times easier and a thousand times more accurate than the method your trying right now.

Examine what is said, not who speaks.

"Efficiency is intelligent laziness." -David Dunham
"When I'm working on a problem, I never think about beauty. I think only how to solve the problem. But when I have finished, if the solution is not beautiful, I know it is wrong." -Richard Buckminster Fuller

[reply]