Trans wrote:
> mortee, do you think you can run this through a profiler and see what
> you come up with?

Here's what I could produce. I'd gladly say I hope this provides some
meaningful insight to some of you, but the results don't seem to be too
informative...

As you can see, the 40 secs delay (with virtually zero CPU activity) is
spent during the XML::Parser#parse method - but the profiler data for
the same operation shows just a fraction of a second...

mortee

$ head -41 xml-bm-libxml.rb
#!/usr/bin/env ruby
require 'xml/libxml'
require 'benchmark'
require 'ruby-prof'

xml = DATA.read
parserinit_prof = parse_prof = traverse_prof = parser = doc = nil

Benchmark.bm 10 do |b|

        b.report('init') do
                parserinit_prof = RubyProf.profile do
                        parser = XML::Parser.string(xml)
                end
        end

        b.report('parse') do
                parse_prof = RubyProf.profile do
                        doc = parser.parse
                end
        end

        b.report('traverse') do
                traverse_prof = RubyProf.profile do
                        doc.find('//data').each{}
                end
        end

end

puts 'init profile data:'
RubyProf::FlatPrinter.new(parserinit_prof).print

puts 'parse profile data:'
RubyProf::FlatPrinter.new(parse_prof).print

puts 'traverse profile data:'
RubyProf::FlatPrinter.new(traverse_prof).print

__END__
<?xml version="1.0" encoding="UTF-8" standalone="no"?>

$ ./xml-bm-libxml.rb
                user     system      total        real
init        0.015000   0.000000   0.015000 (  0.014000)
parse       0.797000   0.031000   0.828000 ( 40.985000)
traverse    0.094000   0.000000   0.094000 (  0.101000)
init profile data:
Thread ID: 268683600
Total: 0.015

 %self     total     self     wait    child    calls  name
100.00      0.01     0.01     0.00     0.00        1
<Class::XML::Parser>#string
  0.00      0.01     0.00     0.00     0.01        0  Global#[No method]


parse profile data:
Thread ID: 268683600
Total: 0.828

 %self     total     self     wait    child    calls  name
100.00      0.83     0.83     0.00     0.00        1  XML::Parser#parse
  0.00      0.83     0.00     0.00     0.83        0  Global#[No method]


traverse profile data:
Thread ID: 268683600
Total: 0.094

 %self     total     self     wait    child    calls  name
 67.02      0.06     0.06     0.00     0.00        1
XML::XPath::Object#each
 32.98      0.03     0.03     0.00     0.00        1  XML::Document#find
  0.00      0.09     0.00     0.00     0.09        0  Global#[No method]

_______________________________________________
libxml-devel mailing list
libxml-devel@rubyforge.org
http://rubyforge.org/mailman/listinfo/libxml-devel

Reply via email to