Puppet performance troubleshooting: using the built-in profiler in standalone puppet apply

Want to help support this blog? Try out Oh Dear, the best all-in-one monitoring tool for your entire website, co-founded by me (the guy that wrote this blogpost). Start with a 10-day trial, no strings attached.

We offer uptime monitoring, SSL checks, broken links checking, performance & cronjob monitoring, branded status pages & so much more. Try us out today!

Profile image of Mattias Geniar

Mattias Geniar, December 24, 2013

Follow me on Twitter as @mattiasgeniar

Previously, it was only possible to do Profiling of a Puppet run with the client/server model, where you need a puppet master running. The master would compile the catalog and could provide debug/profiling information. However, if you’re testing Puppet manifests/modules using a typical Vagrant setup, you most-likely don’t have a puppet master. And it would be cool to have performance metrics of catalog compilation even on standalone puppet runs.

Enter Puppet 3.4.

Because of this pull request that was merged in 3.4, we can now use profiling with standalone ‘puppet apply’ environments. So especially useful in Vagrant-style developing.

How does this work? Add the –debug, –profile and –logdest to the Puppet Apply runs.

A normal run:

$ puppet apply

A run with debugging and profile information:

$ puppet apply --profile --debug --logdest=/tmp/file_to_log_profiling_info_to.log

And voila: you have all the performance metrics you need in your logdest-file. To find all your performance metrics, search for PROFILE in your logfile.

$ grep 'PROFILE' /tmp/file_to_log_profiling_info_to.log

Output can be similar to this, with all the timings of the catalog compilation.

$ grep 'PROFILE' /tmp/file_to_log_profiling_info_to.log
Puppet (debug): PROFILE [apply] 1 Setup server facts for compiling: took 0.0005 seconds
Puppet (debug): PROFILE [apply] 2.4.50 Called include: took 0.0224 seconds
Puppet (debug): PROFILE [apply] 2.4.51 Called include: took 0.0327 seconds
Puppet (debug): PROFILE [apply] 2.4.52.1 Called template: took 0.0994 seconds
...
Puppet (debug): PROFILE [apply] 2.6.1.2.2 Evaluated resource Selinux::Module[zabbix-agent]: took 0.0111 seconds
...
Puppet (debug): PROFILE [apply] 2.6.1.2.3 Evaluated resource Motd::Register_module[zabbix_agent]: took 0.0244 seconds
...
Puppet (debug): PROFILE [apply] 2.6.1.2.4 Evaluated resource Motd::Register_module[ntp]: took 0.0228 seconds
...
Puppet (debug): PROFILE [apply] 2.6.1.2.43 Evaluated resource Nginx::Proxy[site.tld]: took 0.0330 seconds
...
Puppet (debug): PROFILE [apply] 2 Compiled catalog for host.tld in environment production: took 15.9748 seconds
Puppet (debug): PROFILE [apply] 3 Filtered result for catalog host.tld: took 1.2557 seconds

Thanks Puppetlabs!



Want to subscribe to the cron.weekly newsletter?

I write a weekly-ish newsletter on Linux, open source & webdevelopment called cron.weekly.

It features the latest news, guides & tutorials and new open source projects. You can sign up via email below.

No spam. Just some good, practical Linux & open source content.