Is there any way to profile Puppet recipes? For example, here''s a node (hostname changed to protect the innocent) in our nodes.pp: node host002 { include puppet_client_base include subversion::server # sets up the system to be a subversion server include motd # controls /etc/motd from a template include ntp # handles ntp client config include user::root # ensures root user has correct uid, pw, etc. } class puppet_client_base inherits base { include common::puppet_client } class base { include common::passwd # validates perms and ownership of /etc/passwd, group, etc. include dns::resolv_conf # creates /etc/resolv.conf include ssh # controls /etc/ssh/ssh_config from template include mcollective # installs mcollective and activemq client config } That''s not a huge amount IMHO but it takes around 34 seconds on a system that is otherwise doing nothing. I''m assuming that some package checks are what is taking the longest but I can''t really tell, even from debug output. It would be nice if I could run something like "puppet agent -t --profile" and get output that reports how long classes take to evaluate/apply (perhaps with even deeper breakdowns depending on what is done in each class). I tried the following but couldn''t figure out how to get the current timestamp in puppet: /tmp # cat test.pp class test { notice("entering class $name") package { "vim-common": ensure => present } include foo notice("leaving class $name") } class foo { notice("entering class $name") file { "/tmp/foo": ensure => present } notice("leaving class $name") } include test /tmp # puppet apply test.pp notice: Scope(Class[Test]): entering class test notice: Scope(Class[Foo]): entering class foo notice: Scope(Class[Foo]): leaving class foo notice: Scope(Class[Test]): leaving class test notice: /Stage[main]/Foo/File[/tmp/foo]/ensure: created notice: Finished catalog run in 0.67 seconds /tmp # Is any kind of profiling currently available, feasible, or even on the roadmap? Thanks, Justin -- You received this message because you are subscribed to the Google Groups "Puppet Users" group. To post to this group, send email to puppet-users@googlegroups.com. To unsubscribe from this group, send email to puppet-users+unsubscribe@googlegroups.com. For more options, visit this group at http://groups.google.com/group/puppet-users?hl=en.
On Nov 29, 2011, at 3:15 PM, Justin Lloyd wrote:> Is there any way to profile Puppet recipes?You can try the (undocumented?) options --evaltrace and --summarize to puppet agent. -- You received this message because you are subscribed to the Google Groups "Puppet Users" group. To post to this group, send email to puppet-users@googlegroups.com. To unsubscribe from this group, send email to puppet-users+unsubscribe@googlegroups.com. For more options, visit this group at http://groups.google.com/group/puppet-users?hl=en.
Cool, nice to know about the evaltrace option. Interestingly, in the ~1000 lines of output from "puppetd -t --evaltrace", all are < 1 second and all but about 10 are < 0.1 seconds. The total evaluation time is about 5 seconds with the other ~30 "missing" seconds taking place between these two lines: info: Class[Mcollective]: Evaluated in 0.00 seconds info: /Stage[main]/Mcollective/File[plugins-sbin]: Evaluated in 0.00 seconds Hopefully I can dig deeper from there. Thanks, Justin On Tue, Nov 29, 2011 at 12:22 PM, Phillip Frost <indigo@bitglue.com> wrote:> > On Nov 29, 2011, at 3:15 PM, Justin Lloyd wrote: > > > Is there any way to profile Puppet recipes? > > You can try the (undocumented?) options --evaltrace and --summarize to > puppet agent. > > -- > You received this message because you are subscribed to the Google Groups > "Puppet Users" group. > To post to this group, send email to puppet-users@googlegroups.com. > To unsubscribe from this group, send email to > puppet-users+unsubscribe@googlegroups.com. > For more options, visit this group at > http://groups.google.com/group/puppet-users?hl=en. > >-- You received this message because you are subscribed to the Google Groups "Puppet Users" group. To post to this group, send email to puppet-users@googlegroups.com. To unsubscribe from this group, send email to puppet-users+unsubscribe@googlegroups.com. For more options, visit this group at http://groups.google.com/group/puppet-users?hl=en.
On Tue, Nov 29, 2011 at 15:13, Justin Lloyd <jstnlld@gmail.com> wrote:> Cool, nice to know about the evaltrace option. Interestingly, in the ~1000 > lines of output from "puppetd -t --evaltrace", all are < 1 second and all > but about 10 are < 0.1 seconds. The total evaluation time is about 5 seconds > with the other ~30 "missing" seconds taking place between these two lines: > > info: Class[Mcollective]: Evaluated in 0.00 seconds > info: /Stage[main]/Mcollective/File[plugins-sbin]: Evaluated in 0.00 seconds > > Hopefully I can dig deeper from there.You probably need to run with ''--debug'', and look at something that timestamps the log output lines to track it down. Daniel -- ⎋ Puppet Labs Developer – http://puppetlabs.com ♲ Made with 100 percent post-consumer electrons -- You received this message because you are subscribed to the Google Groups "Puppet Users" group. To post to this group, send email to puppet-users@googlegroups.com. To unsubscribe from this group, send email to puppet-users+unsubscribe@googlegroups.com. For more options, visit this group at http://groups.google.com/group/puppet-users?hl=en.
Turns out I just had to fix the Mcollective/File[plugins-sbin] recipe (second line of the output from my original email) to change ''recurse => inf'' (oops) to ''recurse => remote''. It was checking ownership of all 250 files under /usr/sbin just to add in the 3 files mcollective needed in /usr/sbin. That also fixed a postfix problem we were having and removed about 25 seconds from the puppetd run. :) FWIW, this seems to work nicely to add timestamps externally: puppet agent --{summarize,test,debug,evaltrace} | perl -pe ''s/^/localtime().": "/e'' Thanks for the help! Justin On Tue, Nov 29, 2011 at 3:25 PM, Daniel Pittman <daniel@puppetlabs.com>wrote:> On Tue, Nov 29, 2011 at 15:13, Justin Lloyd <jstnlld@gmail.com> wrote: > > Cool, nice to know about the evaltrace option. Interestingly, in the > ~1000 > > lines of output from "puppetd -t --evaltrace", all are < 1 second and all > > but about 10 are < 0.1 seconds. The total evaluation time is about 5 > seconds > > with the other ~30 "missing" seconds taking place between these two > lines: > > > > info: Class[Mcollective]: Evaluated in 0.00 seconds > > info: /Stage[main]/Mcollective/File[plugins-sbin]: Evaluated in 0.00 > seconds > > > > Hopefully I can dig deeper from there. > > You probably need to run with ''--debug'', and look at something that > timestamps the log output lines to track it down. > > Daniel > -- > ⎋ Puppet Labs Developer – http://puppetlabs.com > ♲ Made with 100 percent post-consumer electrons > > -- > You received this message because you are subscribed to the Google Groups > "Puppet Users" group. > To post to this group, send email to puppet-users@googlegroups.com. > To unsubscribe from this group, send email to > puppet-users+unsubscribe@googlegroups.com. > For more options, visit this group at > http://groups.google.com/group/puppet-users?hl=en. > >-- You received this message because you are subscribed to the Google Groups "Puppet Users" group. To post to this group, send email to puppet-users@googlegroups.com. To unsubscribe from this group, send email to puppet-users+unsubscribe@googlegroups.com. For more options, visit this group at http://groups.google.com/group/puppet-users?hl=en.