Profiling puppetmasterd with ruby-prof

So I’m not hugely happy with the CPU consumption of puppetmasterd under heavy load, and so I’ve been trying to work out where the bottlenecks lie.

Unfortunately I’ve yet to find a smoking gun, but here’s a reasonably simple way to produce profiles of puppetmasterd.

• Install ruby-prof from gems.
• Stop any apache/mongrel/nginx instances of puppetmasterd you may have running
• Edit /usr/sbin/puppetmasterd and replace the last few lines with:
  require ‘rubygems’
  require ‘ruby-prof’

  result = RubyProf.profile do
    require ‘puppet/application/puppetmasterd’
    Puppet::Application[:puppetmasterd].run
  end

  printer = RubyProf::GraphHtmlPrinter.new(result)

  File.open(‘/tmp/ruby-profile.html’, ‘w’) do |file|
    printer.print(file, {:min_percent => 10, :print_file => true})
  end

• Start a webrick puppetmasterd with –no-daemonize
• Do a client run against it
• Hit Ctrl-C to interrupt your puppetmasterd
• wait for the html output to be generated

It’s worth filtering the min_percent value. Without it, I ended up with 300+MB HTML files with no images that took my dev server a long time to write to disk. With it, I end up with a couple of megs.

You can see an example output at:
http://www.explanatorygap.net/crap/ruby-profile.html

with the interesting thread being at:
http://www.explanatorygap.net/crap/ruby-profile.html#70121801903160

Interpretation suggestions welcome :)

Edit:

Brice had a great suggestion of using CallTreePrinter instead of GraphHtmlPrinter and analysing the output with kcachegrind (which is utterly amazing). Obviously your output file shouldn’t be html then…

I’ve put a CallTree output up here.

puppet | RSS 2.0 | Respond | Trackback |