Re: [Puppet-dev] Puppet 3 considerably slower than Puppet 2.6

[Dustin J. Mitchell]

How large is the file?

The hash must be performed on the master and the agent, and is
performed over the whole file regardless of the checksum option (bugs
13199 and 18333).

Dustin

[Eric Sorenson]

Hi Allan, could you post the output of a client run with the `--evaltrace --summarize` options? This slowdown is surprising and not what I've seen/heard from other users. 

On May 9, 2013, at 3:20 AM, Allan Yung <alla...@gmail.com> wrote:

I've built a new puppet 3 master but evaluations on clients all take considerably longer than identical evaluations on the existing puppet 2.6 clients.

For example: 

host 1 runs against puppet-server-2.7.14

May  9 10:24:39 host1 puppet-agent[12282]: (/Stage[main]/Jdk/File[/usr/java/truststore]) Evaluated in 0.02 seconds

host 2 runs against puppet-server-3.1.1

May  9 10:25:42 host2 puppet-agent[6821]: (/Stage[main]/Jdk/File[/usr/java/truststore]) Evaluated in 0.78 seconds

The truststores are identical and already exist on the clients so no change has happened

This behaviour is the same for pretty much all file/service evaluations.

Evaluations with the old puppet master tend to take 0.00 - 0.02 seconds, whereas with the new puppet master 0.4 - 0.6 seconds

It doesn't sound like much but it all adds up:

Client runs against the old puppet master generally complete in under 3 seconds

Client runs against the new puppet master take at least 30 seconds

For more elaborate clients the old puppet run might take 8 - 10 seconds, whereas equivalent new puppet clients are hitting around 60 seconds.

I was under the impression that with no changes occurring, puppet would simply be comparing hashes of files from those in the catalog. I can't figure out why new clients are running orders of magnitude slower.

Thanks in advance for any suggestions

--
You received this message because you are subscribed to the Google Groups "Puppet Developers" group.
To unsubscribe from this group and stop receiving emails from it, send an email to puppet-dev+...@googlegroups.com.
To post to this group, send email to puppe...@googlegroups.com.
Visit this group at http://groups.google.com/group/puppet-dev?hl=en.
For more options, visit https://groups.google.com/groups/opt_out.
 
 

Eric Sorenson - eric.s...@puppetlabs.com
#puppet irc: eric0 

[Yannick Perret]

Hello,

I'm migrating our master from an old puppet version to a recent one (3.1.0) (on different machines).
I first installed a first master, and I manage well to run clients from 3 machines against this master.

I then installed a 2nd master and the clients that connect to this master failed.
The output from the client (puppet agent) is a HTML output that contains (in text):

The application has exited during startup (i.e. during the evaluation of config/environment.rb). The error message may have been written to the web server's log file. Please check the web server's log file (i.e. not the (Rails) application's log file) to find out why the application exited.

If that doesn't help, then please use the backtrace below to debug the problem.

Application root:

/etc/puppet/rack

Backtrace:

#	File	Line	Location
0	/opt/ruby-enterprise/lib/ruby/gems/1.8/gems/puppet-3.1.0/lib/puppet/util.rb	518	in `exit'
1	/opt/ruby-enterprise/lib/ruby/gems/1.8/gems/puppet-3.1.0/lib/puppet/util.rb	518	in `exit_on_fail'
2	/opt/ruby-enterprise/lib/ruby/gems/1.8/gems/puppet-3.1.0/lib/puppet/application.rb	362	in `run'
3	/opt/ruby-enterprise/lib/ruby/gems/1.8/gems/puppet-3.1.0/lib/puppet/util/command_line.rb	132	in `run'
4	/opt/ruby-enterprise/lib/ruby/gems/1.8/gems/puppet-3.1.0/lib/puppet/util/command_line.rb	86	in `execute'
5	config.ru	35
6	/opt/ruby-enterprise/lib/ruby/gems/1.8/gems/rack-1.5.2/lib/rack/builder.rb	55	in `instance_eval'
7	/opt/ruby-enterprise/lib/ruby/gems/1.8/gems/rack-1.5.2/lib/rack/builder.rb	55	in `initialize'
8	config.ru	1	in `new'
9	config.ru	1

The same client against the first master works fine (we use a load-balanced system).

What I failed to understand is that I followed the same installation steps for both. I even made a global copy of all the installation directories from the one that works to the one that fail with the same message (a raw tar.gz of /etc/puppet (where I put all the master stuff), of /opt/ruby-enterprise directory (installed with same version, and puppet/facter/rack/... installed from compiled 'gem'), of /etc/httpd/conf.d/).

Some data:
- masters and clients and RHEL6-like machines, both masters are installed with the same automated system, with the same basic configuration
- the SSL seems to work fine as I can see success connections from the httpd ssl logs (from the client)
- I use the ruby-enterprise, same version on both, installed from sources
- I use gem to install puppet, facter, rack, rails and all related stuff, the gem is the one that comes from ruby-enterprise
- as last try I made a global copy of all puppet-master related stuff from the working client (in a tarball) and pushed it on the failing master: it does not change anything.

Any clue about what I missed?

Regards,
--
Y.

[Johan De Wit]

Hu Yannick,


MY first thought goes to a missing ca_server.  This could be one dedicate puppetmaster.  All other masters should be configured to use this one as 'ca_server'

check for the configuration options
*ca_server = <server acting as central ca server> in the [main] section
* ca = false in the [master] section of puppet.conf

Hope this helps

--
You received this message because you are subscribed to the Google Groups "Puppet Developers" group.
To unsubscribe from this group and stop receiving emails from it, send an email to puppet-dev+...@googlegroups.com.
To post to this group, send email to puppe...@googlegroups.com.
Visit this group at http://groups.google.com/group/puppet-dev?hl=en.
For more options, visit https://groups.google.com/groups/opt_out.
 
 

-- 
Johan De Wit

Open Source Consultant 
Red Hat Certified Engineer    (805008667232363)
Puppet Certified Professional 2013 (PCP0000006)
_________________________________________________________

Open-Future           Phone   +32 (0)2/255 70 70
Zavelstraat 72        Fax     +32 (0)2/255 70 71
3071 KORTENBERG       Mobile  +32 (0)474/42 40 73
BELGIUM               http://www.open-future.be
_________________________________________________________

[Eric Sorenson]

This looks like the config.ru is still using the pre-3.x syntax -- this usually lives outside the /etc/puppet directory so it wouldn't have been tarred up.

Check for differences between the hosts in the parent of your apache virtualhost DocumentRoot.

--
You received this message because you are subscribed to the Google Groups "Puppet Developers" group.
To unsubscribe from this group and stop receiving emails from it, send an email to puppet-dev+...@googlegroups.com.
To post to this group, send email to puppe...@googlegroups.com.
Visit this group at http://groups.google.com/group/puppet-dev?hl=en.
For more options, visit https://groups.google.com/groups/opt_out.
 
 

[Yannick Perret]

Le 09/05/2013 22:30, Eric Sorenson a écrit :

This looks like the config.ru is still using the pre-3.x syntax -- this usually lives outside the /etc/puppet directory so it wouldn't have been tarred up.

Check for differences between the hosts in the parent of your apache virtualhost DocumentRoot.

I put my config.ru in /etc/puppet/rack/ subdir. It comes from the puppet subtree installed by gem (3.1.0 : /opt/ruby-enterprise/lib/ruby/gems/1.8/gems/puppet-3.1.0/ext/rack/files/config.ru in my local installation of my ruby-enterprise).

I checked it whatever, and it is the same than the one on the other master.

Regards,
--
Y.

[Yannick Perret]

Le 09/05/2013 22:20, Johan De Wit a écrit :

Hu Yannick,


MY first thought goes to a missing ca_server.  This could be one dedicate puppetmaster.  All other masters should be configured to use this one as 'ca_server'

check for the configuration options
*ca_server = <server acting as central ca server> in the [main] section
* ca = false in the [master] section of puppet.conf

Thanks. I will check this. I guess I missed that part.

By the way, is there any way to have a full "equivalent" set of masters? I mean that having one of them dedicated to CA server (or on an other machine) means that this particular node is not redundant. We use a DNS load-balancing for availability + a TCP-balancing for scalability, and having a "special" node in this pool makes maintenance more complicated.

Regards,
--
Y.

[Yannick Perret]

Le 09/05/2013 22:59, Yannick Perret a écrit :

Le 09/05/2013 22:20, Johan De Wit a écrit :

Hu Yannick,


MY first thought goes to a missing ca_server.  This could be one dedicate puppetmaster.  All other masters should be configured to use this one as 'ca_server'

check for the configuration options
*ca_server = <server acting as central ca server> in the [main] section
* ca = false in the [master] section of puppet.conf

Thanks. I will check this. I guess I missed that part.

By the way, is there any way to have a full "equivalent" set of masters? I mean that having one of them dedicated to CA server (or on an other machine) means that this particular node is not redundant. We use a DNS load-balancing for availability + a TCP-balancing for scalability, and having a "special" node in this pool makes maintenance more complicated.

Hello,
it was not exactly that problem but it was related to that. I made strange things with certs/CA names. It is now corrected and it seems to work fine on both masters.

BTW creating a "false" CA and setting both masters to ca=false seems to work fine (after copying CA-related stuff from 1st master to 2nd master).
Not sure it is very "nice", whatever.

Thanks.
--
Y.

[Allan Yung]

Hi Eric.

For some reason adding the summarize option does not appear to generate any additional output. Here is a client output with evaltrace however:

May 10 13:49:20 host1 puppet-agent[19485]: Reopening log files

May 10 13:49:20 host1 puppet-agent[19488]: Retrieving plugin

May 10 13:49:20 host1 puppet-agent[19488]: Loading facts in /var/lib/puppet/lib/facter/profile.rb

May 10 13:49:20 host1 puppet-agent[19488]: Loading facts in /var/lib/puppet/lib/facter/esdparams.rb

May 10 13:49:43 host1 puppet-agent[19488]: Caching catalog for host1.domain.com

May 10 13:49:57 host1 puppet-agent[19488]: Applying configuration version '1368185004'

May 10 13:50:06 host1 puppet-agent[19488]: (/Schedule[daily]) Starting to evaluate the resource

May 10 13:50:06 host1 puppet-agent[19488]: (/Schedule[daily]) Evaluated in 0.05 seconds

May 10 13:50:06 host1 puppet-agent[19488]: (/Schedule[monthly]) Starting to evaluate the resource

May 10 13:50:06 host1 puppet-agent[19488]: (/Schedule[monthly]) Evaluated in 0.05 seconds

May 10 13:50:06 host1 puppet-agent[19488]: (/Schedule[hourly]) Starting to evaluate the resource

May 10 13:50:06 host1 puppet-agent[19488]: (/Schedule[hourly]) Evaluated in 0.04 seconds

May 10 13:50:06 host1 puppet-agent[19488]: (Stage[main]) Starting to evaluate the resource

May 10 13:50:07 host1 puppet-agent[19488]: (Stage[main]) Evaluated in 0.07 seconds

May 10 13:50:07 host1 puppet-agent[19488]: (Class[Nrpe::Package]) Starting to evaluate the resource

May 10 13:50:07 host1 puppet-agent[19488]: (Class[Nrpe::Package]) Evaluated in 0.11 seconds

May 10 13:50:07 host1 puppet-agent[19488]: (Class[Main]) Starting to evaluate the resource

May 10 13:50:07 host1 puppet-agent[19488]: (Class[Main]) Evaluated in 0.10 seconds

May 10 13:50:07 host1 puppet-agent[19488]: (Class[Sudo]) Starting to evaluate the resource

May 10 13:50:07 host1 puppet-agent[19488]: (Class[Sudo]) Evaluated in 0.10 seconds

May 10 13:50:09 host1 puppet-agent[19488]: (/Stage[main]/Nrpe::Package/Package[nrpe]) Starting to evaluate the resource

May 10 13:50:09 host1 puppet-agent[19488]: (/Stage[main]/Nrpe::Package/Package[nrpe]) Evaluated in 0.10 seconds

May 10 13:50:10 host1 puppet-agent[19488]: (/Stage[main]/Sudo/File[/etc/sudoers.d]) Starting to evaluate the resource

May 10 13:50:10 host1 puppet-agent[19488]: (/Stage[main]/Sudo/File[/etc/sudoers.d]) Evaluated in 0.11 seconds

May 10 13:50:10 host1 puppet-agent[19488]: (Class[Dmt_key]) Starting to evaluate the resource

May 10 13:50:10 host1 puppet-agent[19488]: (Class[Dmt_key]) Evaluated in 0.11 seconds

May 10 13:50:10 host1 puppet-agent[19488]: (Class[Ntp::Package]) Starting to evaluate the resource

May 10 13:50:10 host1 puppet-agent[19488]: (Class[Ntp::Package]) Evaluated in 0.10 seconds

May 10 13:50:10 host1 puppet-agent[19488]: (/Stage[main]/Ntp::Package/Package[ntp]) Starting to evaluate the resource

May 10 13:50:10 host1 puppet-agent[19488]: (/Stage[main]/Ntp::Package/Package[ntp]) Evaluated in 0.10 seconds

May 10 13:50:11 host1 puppet-agent[19488]: (Class[Base]) Starting to evaluate the resource

May 10 13:50:11 host1 puppet-agent[19488]: (Class[Base]) Evaluated in 0.08 seconds

May 10 13:50:11 host1 puppet-agent[19488]: (/Stage[main]/Base/Package[vmware-tools-esx-nox]) Starting to evaluate the resource

May 10 13:50:11 host1 puppet-agent[19488]: (/Stage[main]/Base/Package[vmware-tools-esx-nox]) Evaluated in 0.10 seconds

May 10 13:50:11 host1 puppet-agent[19488]: (Sudo::Sudoers[DomainAdmins]) Starting to evaluate the resource

May 10 13:50:11 host1 puppet-agent[19488]: (Sudo::Sudoers[DomainAdmins]) Evaluated in 0.11 seconds

May 10 13:50:11 host1 puppet-agent[19488]: (/Stage[main]/Sudo/Sudo::Sudoers[DomainAdmins]/File[/etc/sudoers.d/DomainAdmins]) Starting to evaluate the resource

May 10 13:50:11 host1 puppet-agent[19488]: (/Stage[main]/Sudo/Sudo::Sudoers[DomainAdmins]/File[/etc/sudoers.d/DomainAdmins]) Evaluated in 0.16 seconds

May 10 13:50:11 host1 puppet-agent[19488]: (Class[Ldap::Package]) Starting to evaluate the resource

May 10 13:50:12 host1 puppet-agent[19488]: (Class[Ldap::Package]) Evaluated in 0.11 seconds

May 10 13:50:12 host1 puppet-agent[19488]: (/Stage[main]/Ldap::Package/Package[nscd]) Starting to evaluate the resource

May 10 13:50:12 host1 puppet-agent[19488]: (/Stage[main]/Ldap::Package/Package[nscd]) Evaluated in 0.10 seconds

May 10 13:50:12 host1 puppet-agent[19488]: (Class[Ldap::Package]) Starting to evaluate the resource

May 10 13:50:12 host1 puppet-agent[19488]: (Class[Ldap::Package]) Evaluated in 0.10 seconds

May 10 13:50:12 host1 puppet-agent[19488]: (Class[Ntp::Package]) Starting to evaluate the resource

May 10 13:50:12 host1 puppet-agent[19488]: (Class[Ntp::Package]) Evaluated in 0.10 seconds

May 10 13:50:12 host1 puppet-agent[19488]: (Class[Dns]) Starting to evaluate the resource

May 10 13:50:12 host1 puppet-agent[19488]: (Class[Dns]) Evaluated in 0.10 seconds

May 10 13:50:13 host1 puppet-agent[19488]: (Class[Settings]) Starting to evaluate the resource

May 10 13:50:13 host1 puppet-agent[19488]: (Class[Settings]) Evaluated in 0.10 seconds

May 10 13:50:13 host1 puppet-agent[19488]: (Class[Settings]) Starting to evaluate the resource

May 10 13:50:13 host1 puppet-agent[19488]: (Class[Settings]) Evaluated in 0.10 seconds

May 10 13:50:13 host1 puppet-agent[19488]: (Class[Root_user_conf]) Starting to evaluate the resource

May 10 13:50:13 host1 puppet-agent[19488]: (Class[Root_user_conf]) Evaluated in 0.10 seconds

May 10 13:50:13 host1 puppet-agent[19488]: (/Stage[main]/Root_user_conf/File[/root/.bashrc]) Starting to evaluate the resource

May 10 13:50:14 host1 puppet-agent[19488]: (/Stage[main]/Root_user_conf/File[/root/.bashrc]) Evaluated in 0.84 seconds

May 10 13:50:14 host1 puppet-agent[19488]: (Class[Ntp::Config]) Starting to evaluate the resource

May 10 13:50:14 host1 puppet-agent[19488]: (Class[Ntp::Config]) Evaluated in 0.11 seconds

May 10 13:50:14 host1 puppet-agent[19488]: (/Stage[main]/Ntp::Config/File[/etc/ntp.conf]) Starting to evaluate the resource

May 10 13:50:14 host1 puppet-agent[19488]: (/Stage[main]/Ntp::Config/File[/etc/ntp.conf]) Evaluated in 0.15 seconds

May 10 13:50:15 host1 puppet-agent[19488]: (/Stage[main]/Base/Package[vmware-tools-esx-kmods]) Starting to evaluate the resource

May 10 13:50:15 host1 puppet-agent[19488]: (/Stage[main]/Base/Package[vmware-tools-esx-kmods]) Evaluated in 0.10 seconds

May 10 13:50:15 host1 puppet-agent[19488]: (Class[Base]) Starting to evaluate the resource

May 10 13:50:15 host1 puppet-agent[19488]: (Class[Base]) Evaluated in 0.10 seconds

May 10 13:50:15 host1 puppet-agent[19488]: (/Stage[main]/Nrpe::Package/Package[perl-Net-SNMP]) Starting to evaluate the resource

May 10 13:50:15 host1 puppet-agent[19488]: (/Stage[main]/Nrpe::Package/Package[perl-Net-SNMP]) Evaluated in 0.10 seconds

May 10 13:50:15 host1 puppet-agent[19488]: (/Stage[main]/Nrpe::Package/Package[perl-Socket6]) Starting to evaluate the resource

May 10 13:50:15 host1 puppet-agent[19488]: (/Stage[main]/Nrpe::Package/Package[perl-Socket6]) Evaluated in 0.10 seconds

May 10 13:50:15 host1 puppet-agent[19488]: (Class[Sshd::Package]) Starting to evaluate the resource

May 10 13:50:15 host1 puppet-agent[19488]: (Class[Sshd::Package]) Evaluated in 0.11 seconds

May 10 13:50:16 host1 puppet-agent[19488]: (/Stage[main]/Sshd::Package/Package[openssh-server]) Starting to evaluate the resource

May 10 13:50:16 host1 puppet-agent[19488]: (/Stage[main]/Sshd::Package/Package[openssh-server]) Evaluated in 0.10 seconds

May 10 13:50:16 host1 puppet-agent[19488]: (Class[Sshd::Package]) Starting to evaluate the resource

May 10 13:50:16 host1 puppet-agent[19488]: (Class[Sshd::Package]) Evaluated in 0.10 seconds

May 10 13:50:16 host1 puppet-agent[19488]: (Class[Sshd::Config]) Starting to evaluate the resource

May 10 13:50:16 host1 puppet-agent[19488]: (Class[Sshd::Config]) Evaluated in 0.11 seconds

May 10 13:50:16 host1 puppet-agent[19488]: (/Stage[main]/Sshd::Config/Augeas[sshd_config]) Starting to evaluate the resource

May 10 13:50:17 host1 puppet-agent[19488]: (/Stage[main]/Sshd::Config/Augeas[sshd_config]) Evaluated in 0.39 seconds

May 10 13:50:17 host1 puppet-agent[19488]: (/Stage[main]/Ntp::Config/File[/etc/ntp/step-tickers]) Starting to evaluate the resource

May 10 13:50:17 host1 puppet-agent[19488]: (/Stage[main]/Ntp::Config/File[/etc/ntp/step-tickers]) Evaluated in 0.15 seconds

May 10 13:50:17 host1 puppet-agent[19488]: (Class[Ntp::Config]) Starting to evaluate the resource

May 10 13:50:17 host1 puppet-agent[19488]: (Class[Ntp::Config]) Evaluated in 0.10 seconds

May 10 13:50:17 host1 puppet-agent[19488]: (Class[Ntp::Service]) Starting to evaluate the resource

May 10 13:50:17 host1 puppet-agent[19488]: (Class[Ntp::Service]) Evaluated in 0.10 seconds

May 10 13:50:17 host1 puppet-agent[19488]: (/Schedule[never]) Starting to evaluate the resource

May 10 13:50:17 host1 puppet-agent[19488]: (/Schedule[never]) Evaluated in 0.04 seconds

May 10 13:50:18 host1 puppet-agent[19488]: (/Stage[main]/Sudo/File[/etc/sudoers]) Starting to evaluate the resource

May 10 13:50:18 host1 puppet-agent[19488]: (/Stage[main]/Sudo/File[/etc/sudoers]) Evaluated in 0.82 seconds

May 10 13:50:18 host1 puppet-agent[19488]: (/Stage[main]/Nrpe::Package/Package[nagios-plugins]) Starting to evaluate the resource

May 10 13:50:19 host1 puppet-agent[19488]: (/Stage[main]/Nrpe::Package/Package[nagios-plugins]) Evaluated in 0.07 seconds

May 10 13:50:19 host1 puppet-agent[19488]: (Class[Nrpe::Package]) Starting to evaluate the resource

May 10 13:50:19 host1 puppet-agent[19488]: (Class[Nrpe::Package]) Evaluated in 0.10 seconds

May 10 13:50:19 host1 puppet-agent[19488]: (Class[Nrpe::Config]) Starting to evaluate the resource

May 10 13:50:19 host1 puppet-agent[19488]: (Class[Nrpe::Config]) Evaluated in 0.13 seconds

May 10 13:50:19 host1 puppet-agent[19488]: (/Stage[main]/Nrpe::Config/File[/usr/lib64/nagios/plugins/check_cpu.sh]) Starting to evaluate the resource

May 10 13:50:20 host1 puppet-agent[19488]: (/Stage[main]/Nrpe::Config/File[/usr/lib64/nagios/plugins/check_cpu.sh]) Evaluated in 0.83 seconds

May 10 13:50:20 host1 puppet-agent[19488]: (/Stage[main]/Nrpe::Config/File[/usr/lib64/nagios/plugins/check_mem.pl]) Starting to evaluate the resource

May 10 13:50:21 host1 puppet-agent[19488]: (/Stage[main]/Nrpe::Config/File[/usr/lib64/nagios/plugins/check_mem.pl]) Evaluated in 0.83 seconds

May 10 13:50:21 host1 puppet-agent[19488]: (/Stage[main]/Nrpe::Config/File[/usr/lib64/nagios/plugins/check_iostat]) Starting to evaluate the resource

May 10 13:50:22 host1 puppet-agent[19488]: (/Stage[main]/Nrpe::Config/File[/usr/lib64/nagios/plugins/check_iostat]) Evaluated in 0.83 seconds

May 10 13:50:22 host1 puppet-agent[19488]: (/Stage[main]/Root_user_conf/File[/root/.vimrc]) Starting to evaluate the resource

May 10 13:50:23 host1 puppet-agent[19488]: (/Stage[main]/Root_user_conf/File[/root/.vimrc]) Evaluated in 0.86 seconds

May 10 13:50:23 host1 puppet-agent[19488]: (Class[Root_user_conf]) Starting to evaluate the resource

May 10 13:50:23 host1 puppet-agent[19488]: (Class[Root_user_conf]) Evaluated in 0.10 seconds

May 10 13:50:23 host1 puppet-agent[19488]: (/Filebucket[puppet]) Starting to evaluate the resource

May 10 13:50:23 host1 puppet-agent[19488]: (/Filebucket[puppet]) Evaluated in 0.06 seconds

May 10 13:50:23 host1 puppet-agent[19488]: (Sudo::Sudoers[DomainAdmins]) Starting to evaluate the resource

May 10 13:50:23 host1 puppet-agent[19488]: (Sudo::Sudoers[DomainAdmins]) Evaluated in 0.10 seconds

May 10 13:50:24 host1 puppet-agent[19488]: (Class[Sudo]) Starting to evaluate the resource

May 10 13:50:24 host1 puppet-agent[19488]: (Class[Sudo]) Evaluated in 0.10 seconds

May 10 13:50:24 host1 puppet-agent[19488]: (Class[Ldap::Config]) Starting to evaluate the resource

May 10 13:50:24 host1 puppet-agent[19488]: (Class[Ldap::Config]) Evaluated in 0.10 seconds

May 10 13:50:24 host1 puppet-agent[19488]: (/Stage[main]/Ldap::Config/File[/etc/pam_ldap.conf]) Starting to evaluate the resource

May 10 13:50:24 host1 puppet-agent[19488]: (/Stage[main]/Ldap::Config/File[/etc/pam_ldap.conf]) Evaluated in 0.15 seconds

May 10 13:50:24 host1 puppet-agent[19488]: (/Stage[main]/Ldap::Config/File[/etc/ldap.conf]) Starting to evaluate the resource

May 10 13:50:24 host1 puppet-agent[19488]: (/Stage[main]/Ldap::Config/File[/etc/ldap.conf]) Evaluated in 0.16 seconds

May 10 13:50:25 host1 puppet-agent[19488]: (/Stage[main]/Ldap::Config/File[/etc/nslcd.conf]) Starting to evaluate the resource

May 10 13:50:25 host1 puppet-agent[19488]: (/Stage[main]/Ldap::Config/File[/etc/nslcd.conf]) Evaluated in 0.12 seconds

May 10 13:50:25 host1 puppet-agent[19488]: (/Stage[main]/Ldap::Config/File[/etc/pam.d/password-auth-ac]) Starting to evaluate the resource

May 10 13:50:26 host1 puppet-agent[19488]: (/Stage[main]/Ldap::Config/File[/etc/pam.d/password-auth-ac]) Evaluated in 0.83 seconds

May 10 13:50:26 host1 puppet-agent[19488]: (/Stage[main]/Ldap::Config/File[/etc/nsswitch.conf]) Starting to evaluate the resource

May 10 13:50:27 host1 puppet-agent[19488]: (/Stage[main]/Ldap::Config/File[/etc/nsswitch.conf]) Evaluated in 0.86 seconds

May 10 13:50:27 host1 puppet-agent[19488]: (/Schedule[weekly]) Starting to evaluate the resource

May 10 13:50:27 host1 puppet-agent[19488]: (/Schedule[weekly]) Evaluated in 0.04 seconds

May 10 13:50:27 host1 puppet-agent[19488]: (Class[Services]) Starting to evaluate the resource

May 10 13:50:27 host1 puppet-agent[19488]: (Class[Services]) Evaluated in 0.11 seconds

May 10 13:50:27 host1 puppet-agent[19488]: (/Stage[main]/Services/Service[cups]) Starting to evaluate the resource

May 10 13:50:28 host1 puppet-agent[19488]: (/Stage[main]/Services/Service[cups]) Evaluated in 0.60 seconds

May 10 13:50:28 host1 puppet-agent[19488]: (/Stage[main]/Services/Service[iptables]) Starting to evaluate the resource

May 10 13:50:28 host1 puppet-agent[19488]: (/Stage[main]/Services/Service[iptables]) Evaluated in 0.57 seconds

May 10 13:50:28 host1 puppet-agent[19488]: (/Stage[main]/Services/Service[gpm]) Starting to evaluate the resource

May 10 13:50:29 host1 puppet-agent[19488]: (/Stage[main]/Services/Service[gpm]) Evaluated in 0.59 seconds

May 10 13:50:29 host1 puppet-agent[19488]: (/Stage[main]/Services/Service[ip6tables]) Starting to evaluate the resource

May 10 13:50:30 host1 puppet-agent[19488]: (/Stage[main]/Services/Service[ip6tables]) Evaluated in 0.59 seconds

May 10 13:50:30 host1 puppet-agent[19488]: (/Stage[main]/Services/Service[mcstrans]) Starting to evaluate the resource

May 10 13:50:30 host1 puppet-agent[19488]: (/Stage[main]/Services/Service[mcstrans]) Evaluated in 0.56 seconds

May 10 13:50:30 host1 puppet-agent[19488]: (Class[Services]) Starting to evaluate the resource

May 10 13:50:31 host1 puppet-agent[19488]: (Class[Services]) Evaluated in 0.10 seconds

May 10 13:50:31 host1 puppet-agent[19488]: (/Stage[main]/Ntp::Service/Service[ntpd]) Starting to evaluate the resource

May 10 13:50:31 host1 puppet-agent[19488]: (/Stage[main]/Ntp::Service/Service[ntpd]) Evaluated in 0.57 seconds

May 10 13:50:31 host1 puppet-agent[19488]: (Class[Ntp::Service]) Starting to evaluate the resource

May 10 13:50:32 host1 puppet-agent[19488]: (Class[Ntp::Service]) Evaluated in 0.13 seconds

May 10 13:50:32 host1 puppet-agent[19488]: (Class[Ntp]) Starting to evaluate the resource

May 10 13:50:32 host1 puppet-agent[19488]: (Class[Ntp]) Evaluated in 0.11 seconds

May 10 13:50:32 host1 puppet-agent[19488]: (Class[Ntp]) Starting to evaluate the resource

May 10 13:50:32 host1 puppet-agent[19488]: (Class[Ntp]) Evaluated in 0.10 seconds

May 10 13:50:32 host1 puppet-agent[19488]: (/Stage[main]/Nrpe::Config/File[/usr/lib64/nagios/plugins/check_rofs.sh]) Starting to evaluate the resource

May 10 13:50:33 host1 puppet-agent[19488]: (/Stage[main]/Nrpe::Config/File[/usr/lib64/nagios/plugins/check_rofs.sh]) Evaluated in 0.88 seconds

May 10 13:50:33 host1 puppet-agent[19488]: (/Stage[main]/Nrpe::Config/File[/etc/nagios/nrpe.cfg]) Starting to evaluate the resource

May 10 13:50:34 host1 puppet-agent[19488]: (/Stage[main]/Nrpe::Config/File[/etc/nagios/nrpe.cfg]) Evaluated in 0.87 seconds

May 10 13:50:34 host1 puppet-agent[19488]: (Class[Nrpe::Config]) Starting to evaluate the resource

May 10 13:50:34 host1 puppet-agent[19488]: (Class[Nrpe::Config]) Evaluated in 0.10 seconds

May 10 13:50:34 host1 puppet-agent[19488]: (Class[Nrpe::Service]) Starting to evaluate the resource

May 10 13:50:34 host1 puppet-agent[19488]: (Class[Nrpe::Service]) Evaluated in 0.11 seconds

May 10 13:50:34 host1 puppet-agent[19488]: (/Stage[main]/Nrpe::Service/Service[nrpe]) Starting to evaluate the resource

May 10 13:50:35 host1 puppet-agent[19488]: (/Stage[main]/Nrpe::Service/Service[nrpe]) Evaluated in 0.58 seconds

May 10 13:50:35 host1 puppet-agent[19488]: (Class[Nrpe::Service]) Starting to evaluate the resource

May 10 13:50:35 host1 puppet-agent[19488]: (Class[Nrpe::Service]) Evaluated in 0.10 seconds

May 10 13:50:35 host1 puppet-agent[19488]: (Class[Nrpe]) Starting to evaluate the resource

May 10 13:50:36 host1 puppet-agent[19488]: (Class[Nrpe]) Evaluated in 0.11 seconds

May 10 13:50:36 host1 puppet-agent[19488]: (Class[Nrpe]) Starting to evaluate the resource

May 10 13:50:36 host1 puppet-agent[19488]: (Class[Nrpe]) Evaluated in 0.10 seconds

May 10 13:50:36 host1 puppet-agent[19488]: (/Schedule[puppet]) Starting to evaluate the resource

May 10 13:50:36 host1 puppet-agent[19488]: (/Schedule[puppet]) Evaluated in 0.04 seconds

May 10 13:50:36 host1 puppet-agent[19488]: (/Stage[main]/Ldap::Config/File[/etc/pam.d/system-auth-ac]) Starting to evaluate the resource

May 10 13:50:37 host1 puppet-agent[19488]: (/Stage[main]/Ldap::Config/File[/etc/pam.d/system-auth-ac]) Evaluated in 0.83 seconds

May 10 13:50:37 host1 puppet-agent[19488]: (Class[Ldap::Config]) Starting to evaluate the resource

May 10 13:50:37 host1 puppet-agent[19488]: (Class[Ldap::Config]) Evaluated in 0.11 seconds

May 10 13:50:37 host1 puppet-agent[19488]: (Class[Main]) Starting to evaluate the resource

May 10 13:50:37 host1 puppet-agent[19488]: (Class[Main]) Evaluated in 0.10 seconds

May 10 13:50:37 host1 puppet-agent[19488]: (Class[Ldap::Service]) Starting to evaluate the resource

May 10 13:50:37 host1 puppet-agent[19488]: (Class[Ldap::Service]) Evaluated in 0.11 seconds

May 10 13:50:38 host1 puppet-agent[19488]: (/Stage[main]/Ldap::Service/Service[nslcd]) Starting to evaluate the resource

May 10 13:50:38 host1 puppet-agent[19488]: (/Stage[main]/Ldap::Service/Service[nslcd]) Evaluated in 0.59 seconds

May 10 13:50:38 host1 puppet-agent[19488]: (Class[Sshd::Config]) Starting to evaluate the resource

May 10 13:50:38 host1 puppet-agent[19488]: (Class[Sshd::Config]) Evaluated in 0.10 seconds

May 10 13:50:38 host1 puppet-agent[19488]: (Class[Sshd::Service]) Starting to evaluate the resource

May 10 13:50:39 host1 puppet-agent[19488]: (Class[Sshd::Service]) Evaluated in 0.14 seconds

May 10 13:50:39 host1 puppet-agent[19488]: (/Stage[main]/Sshd::Service/Service[sshd]) Starting to evaluate the resource

May 10 13:50:39 host1 puppet-agent[19488]: (/Stage[main]/Sshd::Service/Service[sshd]) Evaluated in 0.58 seconds

May 10 13:50:39 host1 puppet-agent[19488]: (Class[Sshd::Service]) Starting to evaluate the resource

May 10 13:50:39 host1 puppet-agent[19488]: (Class[Sshd::Service]) Evaluated in 0.10 seconds

May 10 13:50:39 host1 puppet-agent[19488]: (Class[Sshd]) Starting to evaluate the resource

May 10 13:50:40 host1 puppet-agent[19488]: (Class[Sshd]) Evaluated in 0.11 seconds

May 10 13:50:40 host1 puppet-agent[19488]: (Class[Sshd]) Starting to evaluate the resource

May 10 13:50:40 host1 puppet-agent[19488]: (Class[Sshd]) Evaluated in 0.11 seconds

May 10 13:50:40 host1 puppet-agent[19488]: (/Stage[main]/Ldap::Service/Service[nscd]) Starting to evaluate the resource

May 10 13:50:41 host1 puppet-agent[19488]: (/Stage[main]/Ldap::Service/Service[nscd]) Evaluated in 0.60 seconds

May 10 13:50:41 host1 puppet-agent[19488]: (Class[Ldap::Service]) Starting to evaluate the resource

May 10 13:50:41 host1 puppet-agent[19488]: (Class[Ldap::Service]) Evaluated in 0.11 seconds

May 10 13:50:41 host1 puppet-agent[19488]: (Class[Ldap]) Starting to evaluate the resource

May 10 13:50:41 host1 puppet-agent[19488]: (Class[Ldap]) Evaluated in 0.11 seconds

May 10 13:50:41 host1 puppet-agent[19488]: (Class[Ldap]) Starting to evaluate the resource

May 10 13:50:41 host1 puppet-agent[19488]: (Class[Ldap]) Evaluated in 0.11 seconds

May 10 13:50:41 host1 puppet-agent[19488]: (/Stage[main]/Dns/File[/etc/resolv.conf]) Starting to evaluate the resource

May 10 13:50:41 host1 puppet-agent[19488]: (/Stage[main]/Dns/File[/etc/resolv.conf]) Evaluated in 0.15 seconds

May 10 13:50:41 host1 puppet-agent[19488]: (Class[Dns]) Starting to evaluate the resource

May 10 13:50:42 host1 puppet-agent[19488]: (Class[Dns]) Evaluated in 0.07 seconds

May 10 13:50:42 host1 puppet-agent[19488]: (/Stage[main]/Dmt_key/Ssh_authorized_key[root]) Starting to evaluate the resource

May 10 13:50:42 host1 puppet-agent[19488]: (/Stage[main]/Dmt_key/Ssh_authorized_key[root]) Evaluated in 0.12 seconds

May 10 13:50:42 host1 puppet-agent[19488]: (Class[Dmt_key]) Starting to evaluate the resource

May 10 13:50:42 host1 puppet-agent[19488]: (Class[Dmt_key]) Evaluated in 0.10 seconds

May 10 13:50:42 host1 puppet-agent[19488]: (Stage[main]) Starting to evaluate the resource

May 10 13:50:42 host1 puppet-agent[19488]: (Stage[main]) Evaluated in 0.17 seconds

May 10 13:50:44 host1 puppet-agent[19488]: Finished catalog run in 46.63 seconds

Regards.

[Allan Yung]

The truststore file is tiny: 82617

Also this doesn't explain the discrepancy between how it is fast on puppet 2, but slow on puppet 3.

Regards

Allan

[Allan Yung]

I'm glad you were able to find a solution to your problem but in the future please open your own thread instead of hijacking an existing one.

Cheers,

Allan

[Ken Barber]

Yeah, I don't think this was intentional Allan - looks like google groups threading is broken somehow in this case and mixing these two threads together. In my email client however, they are separate threads.

ken.

[Ken Barber]

Actually after looking deeper Yannick's first-message has a header item:

In-Reply-To: <DDF22463-63D9-400E...@puppetlabs.com>

So yeah, I'm guessing but it looks like Yannick's initial message was
constructed as a 'reply-to' on another message, subject & content was
changed but google groups kept the old threading due to that header.
Either that, or something else went wrong with google groups to add
that in-reply-to header. *shrug*.

So you two can either put up with it, or start another thread at this
point :-). In gmail at least its threading perfectly fine btw -
probably due to the subject being different. Don't know how other mail
clients are working though :-).

ken.

[Yannick Perret]

Le 10/05/2013 15:20, Ken Barber a écrit :

Yeah, I don't think this was intentional Allan - looks like google groups threading is broken somehow in this case and mixing these two threads together. In my email client however, they are separate threads.

Hmm. Yes not intentional, sorry. Same for me, it is a separated thread in my email client.
Note for later: cleaning subject+content is not enough for hidden tags used by google groups :)

Regards,
--
Y.

[Andy Parker]

Hi Allan,

Thanks for that trace output. Is that from the 3.1 agent or from the
2.6 agent? Could you provide the output from an equivalent run on the
other version so that we can compare?

--
Andrew Parker
an...@puppetlabs.com
Freenode: zaphod42
Twitter: @aparker42
Software Developer

Join us at PuppetConf 2013, August 22-23 in San Francisco -
http://bit.ly/pupconf13
Register now and take advantage of the Early Bird discount - save 25%!

[Allan Yung]

Hi Andrew,

That was from the 3.1 agent talking to the 3.1 master.

If I point a 2.6 agent to the 3.1 master I get the same slow behaviour. Pointing the 2.6 agent back to the 2.6 master gives the fast performance as before.

As part of moving to puppet3/hiera etc the modules have been refactored, so there are differences in the class and method names. They essentially perform the same tasks though.

Here is a trace from a 2.6 agent running against the 2.6 master. As you can see the evaluations happen in a fraction of the time:

May 14 10:05:55 host1 puppet-agent[9526]: Starting Puppet client version 2.6.6

May 14 10:05:55 host1 puppet-agent[9526]: Retrieving plugin

May 14 10:05:56 host1 puppet-agent[9526]: Loading facts in get_esd_env

May 14 10:05:56 host1 puppet-agent[9526]: Loading facts in configured_ipaddress

May 14 10:05:56 host1 puppet-agent[9526]: Loading facts in get_env_group

May 14 10:05:56 host1 puppet-agent[9526]: Loading facts in get_vlan

May 14 10:05:56 host1 puppet-agent[9526]: Loading facts in get_env_group_espoo

May 14 10:05:56 host1 puppet-agent[9526]: Loading facts in cdpr_parent

May 14 10:05:56 host1 puppet-agent[9526]: Loading facts in get_esd_env

May 14 10:05:56 host1 puppet-agent[9526]: Loading facts in configured_ipaddress

May 14 10:05:56 host1 puppet-agent[9526]: Loading facts in get_env_group

May 14 10:05:56 host1 puppet-agent[9526]: Loading facts in get_vlan

May 14 10:05:56 host1 puppet-agent[9526]: Loading facts in get_env_group_espoo

May 14 10:05:56 host1 puppet-agent[9526]: Loading facts in cdpr_parent

May 14 10:05:58 host1 puppet-agent[9526]: Caching catalog for host1.brislabs.com

May 14 10:06:01 host1 puppet-agent[9526]: Applying configuration version '1368517682'

May 14 10:06:01 host1 puppet-agent[9526]: (/Schedule[weekly]) Evaluated in 0.03 seconds

May 14 10:06:01 host1 puppet-agent[9526]: (/Schedule[hourly]) Evaluated in 0.00 seconds

May 14 10:06:01 host1 puppet-agent[9526]: (/Filebucket[puppet]) Evaluated in 0.00 seconds

May 14 10:06:01 host1 puppet-agent[9526]: (/Schedule[never]) Evaluated in 0.00 seconds

May 14 10:06:01 host1 puppet-agent[9526]: (/Schedule[monthly]) Evaluated in 0.00 seconds

May 14 10:06:01 host1 puppet-agent[9526]: (/Stage[pre]/Yumrepos/File[/etc/yum.repos.d]) Evaluated in 0.02 seconds

May 14 10:06:01 host1 puppet-agent[9526]: (/Stage[pre]/Yumrepos/File[/etc/yum.repos.d/redhat.repo]) Evaluated in 0.00 seconds

May 14 10:06:01 host1 puppet-agent[9526]: (/Stage[pre]/Yumrepos_espoo/Repo[updates]/File[updates]) Evaluated in 0.00 seconds

May 14 10:06:01 host1 puppet-agent[9526]: (/Stage[pre]/Yumrepos_espoo/Repo[base]/File[base]) Evaluated in 0.00 seconds

May 14 10:06:01 host1 puppet-agent[9526]: (/Stage[pre]/Yumrepos_espoo/Repo[optional]/File[optional]) Evaluated in 0.00 seconds

May 14 10:06:01 host1 puppet-agent[9526]: (/Stage[pre]/Yumrepos_espoo/Repo[ovimusic]/File[ovimusic]) Evaluated in 0.00 seconds

May 14 10:06:01 host1 puppet-agent[9526]: (/Stage[pre]/Yumrepos_espoo/Repo[supplementary]/File[supplementary]) Evaluated in 0.00 seconds

May 14 10:06:01 host1 puppet-agent[9526]: (/Stage[pre]/Yumrepos_espoo/Repo[oviinfra]/File[oviinfra]) Evaluated in 0.00 seconds

May 14 10:06:01 host1 puppet-agent[9526]: (/Stage[pre]/Resolver_espoo/Resolver::Resolv_conf[scmbasenode]/File[/etc/resolv.conf]) Evaluated in 0.00 seconds

May 14 10:06:01 host1 puppet-agent[9526]: (/Schedule[puppet]) Evaluated in 0.00 seconds

May 14 10:06:01 host1 puppet-agent[9526]: (/Whit[Resolver]) Evaluated in 0.00 seconds

May 14 10:06:01 host1 puppet-agent[9526]: (/Stage[main]/Ldap_new/File[/etc/pam_ldap.conf]) Evaluated in 0.07 seconds

May 14 10:06:01 host1 puppet-agent[9526]: (/Stage[main]/Vmware::Tools/Package[vmware-tools-esx-kmods]) Evaluated in 0.00 seconds

May 14 10:06:01 host1 puppet-agent[9526]: (/Stage[main]//File[/etc/yum.conf]) Evaluated in 0.02 seconds

May 14 10:06:01 host1 puppet-agent[9526]: (/Stage[main]/Ldap_new/File[/etc/pam.d/password-auth-ac]) Evaluated in 0.02 seconds

May 14 10:06:01 host1 puppet-agent[9526]: (/Whit[host1.domain.com]) Evaluated in 0.00 seconds

May 14 10:06:01 host1 puppet-agent[9526]: (/Stage[main]/Nrpe_new/Package[MySQL-shared-compat]) Evaluated in 0.00 seconds

May 14 10:06:01 host1 puppet-agent[9526]: (/Stage[main]/Nrpe_new::Client/Package[libpcap]) Evaluated in 0.00 seconds

May 14 10:06:01 host1 puppet-agent[9526]: (/Whit[Esdparams]) Evaluated in 0.00 seconds

May 14 10:06:01 host1 puppet-agent[9526]: (/Whit[host1.brislabs.com]) Evaluated in 0.00 seconds

May 14 10:06:01 host1 puppet-agent[9526]: (/Stage[main]/Nrpe_new/Package[perl-Digest-SHA1]) Evaluated in 0.00 seconds

May 14 10:06:01 host1 puppet-agent[9526]: (/Whit[scm_basenoderhel61]) Evaluated in 0.00 seconds

May 14 10:06:01 host1 puppet-agent[9526]: (/Stage[main]/Ldap_new/File[/etc/ldap.conf]) Evaluated in 0.02 seconds

May 14 10:06:01 host1 puppet-agent[9526]: (/Stage[main]/Ldap_new/File[/etc/nsswitch.conf]) Evaluated in 0.02 seconds

May 14 10:06:01 host1 puppet-agent[9526]: (/Stage[main]/Ldap_new/File[/etc/pam.d/system-auth-ac]) Evaluated in 0.02 seconds

May 14 10:06:01 host1 puppet-agent[9526]: (/Stage[main]/Cups/Service[cups]) Evaluated in 0.05 seconds

May 14 10:06:01 host1 puppet-agent[9526]: (/Stage[main]/Nrpe_new::Client/Package[ladvd]) Evaluated in 0.00 seconds

May 14 10:06:02 host1 puppet-agent[9526]: (/Stage[main]/Nrpe_new::Client/Service[ladvd]) Evaluated in 0.05 seconds

May 14 10:06:02 host1 puppet-agent[9526]: (/Stage[main]/Scmbasenode/Ntp::Conf[scmbasenode]/File[/etc/ntp.conf]) Evaluated in 0.00 seconds

May 14 10:06:02 host1 puppet-agent[9526]: (/Stage[main]/Scmbasenode/Ntp::Conf[scmbasenode]/Service[ntpd]) Evaluated in 0.05 seconds

May 14 10:06:02 host1 puppet-agent[9526]: (/Whit[Settings]) Evaluated in 0.00 seconds

May 14 10:06:02 host1 puppet-agent[9526]: (/Stage[main]/Dmt-ssh/File[/root/.ssh]) Evaluated in 0.00 seconds

May 14 10:06:02 host1 puppet-agent[9526]: (/Stage[main]/Dmt-ssh/File[/root/.ssh/authorized_keys]) Evaluated in 0.00 seconds

May 14 10:06:02 host1 puppet-agent[9526]: (/Stage[main]/Scmbasenode/Sshd_authorized_key[DMT]/Line[ssh_authorized_key/DMT]/Exec[echo 'ssh-dss LONG_SSH_KEY_HERE The key for DMT' >> '/root/.ssh/authorized_keys']) Evaluated in 0.07 seconds

May 14 10:06:02 host1 puppet-agent[9526]: (/Stage[main]/Nrpe_new/Package[bc]) Evaluated in 0.00 seconds

May 14 10:06:02 host1 puppet-agent[9526]: (/Stage[main]/Ldap_new/File[/etc/nslcd.conf]) Evaluated in 0.02 seconds

May 14 10:06:02 host1 puppet-agent[9526]: (/Stage[main]/Ldap_new/Service[nslcd]) Evaluated in 0.05 seconds

May 14 10:06:02 host1 puppet-agent[9526]: (/Stage[main]/Nrpe_new/Package[perl-Digest-HMAC]) Evaluated in 0.00 seconds

May 14 10:06:02 host1 puppet-agent[9526]: (/Stage[main]/Jdk::Jdk7/Package[jdk]) Evaluated in 0.00 seconds

May 14 10:06:02 host1 puppet-agent[9526]: (/Stage[main]/Jdk/File[/usr/java/truststore]) Evaluated in 0.02 seconds

May 14 10:06:02 host1 puppet-agent[9526]: (/Stage[main]/Dmt-ssh/File[/etc/ssh/sshd_config]) Evaluated in 0.02 seconds

May 14 10:06:02 host1 puppet-agent[9526]: (/Stage[main]/Dmt-ssh/Service[sshd]) Evaluated in 0.02 seconds

May 14 10:06:02 host1 puppet-agent[9526]: (/Whit[Vmware]) Evaluated in 0.00 seconds

May 14 10:06:02 host1 puppet-agent[9526]: (/Stage[main]/Vmware::Tools/Package[vmware-tools-esx-nox]) Evaluated in 0.00 seconds

May 14 10:06:02 host1 puppet-agent[9526]: (/Stage[main]/Sudo/Package[sudo]) Evaluated in 0.00 seconds

May 14 10:06:02 host1 puppet-agent[9526]: (/Stage[main]/Sudo/File[/etc/sudoers]) Evaluated in 0.02 seconds

May 14 10:06:02 host1 puppet-agent[9526]: (/Stage[main]/Nscd/Service[nscd]) Evaluated in 0.05 seconds

May 14 10:06:02 host1 puppet-agent[9526]: (/Stage[main]/Ntp/Package[ntp]) Evaluated in 0.00 seconds

May 14 10:06:02 host1 puppet-agent[9526]: (/Stage[main]/Scmbasenode/Ntp::Conf[scmbasenode]/File[/etc/ntp/step-tickers]) Evaluated in 0.00 seconds

May 14 10:06:02 host1 puppet-agent[9526]: (/Stage[main]/Nrpe_new/Package[perl-Crypt-DES]) Evaluated in 0.00 seconds

May 14 10:06:02 host1 puppet-agent[9526]: (/Stage[main]/Nrpe_new/Package[fping]) Evaluated in 0.00 seconds

May 14 10:06:02 host1 puppet-agent[9526]: (/Stage[main]/Nrpe_new/Package[perl-Socket6]) Evaluated in 0.00 seconds

May 14 10:06:02 host1 puppet-agent[9526]: (/Stage[main]/Nrpe_new/Package[nrpe]) Evaluated in 0.00 seconds

May 14 10:06:02 host1 puppet-agent[9526]: (/Stage[main]/Nrpe_new/Package[nagios-plugins]) Evaluated in 0.00 seconds

May 14 10:06:02 host1 puppet-agent[9526]: (/Stage[main]/Nrpe_new/File[/usr/local/nagios/]) Evaluated in 0.00 seconds

May 14 10:06:02 host1 puppet-agent[9526]: (/Stage[main]/Nrpe_new/File[/usr/local/nagios/libexec/]) Evaluated in 0.00 seconds

May 14 10:06:02 host1 puppet-agent[9526]: (/Stage[main]/Nrpe_new/File[/usr/lib64/nagios/plugins/check_mem.pl]) Evaluated in 0.02 seconds

May 14 10:06:02 host1 puppet-agent[9526]: (/Stage[main]/Nrpe_new/File[/usr/lib64/nagios/plugins/check_jboss.pl]) Evaluated in 0.02 seconds

May 14 10:06:02 host1 puppet-agent[9526]: (/Stage[main]/Nrpe_new/File[/usr/lib64/nagios/plugins/check_cpu.sh]) Evaluated in 0.02 seconds

May 14 10:06:02 host1 puppet-agent[9526]: (/Stage[main]/Nrpe_new/File[/usr/lib64/nagios/plugins/check_openmanage]) Evaluated in 0.02 seconds

May 14 10:06:02 host1 puppet-agent[9526]: (/Stage[main]/Nrpe_new/File[/etc/nagios/nrpe.cfg]) Evaluated in 0.02 seconds

May 14 10:06:02 host1 puppet-agent[9526]: (/Stage[main]/Nrpe_new/Service[nrpe]) Evaluated in 0.04 seconds

May 14 10:06:02 host1 puppet-agent[9526]: (/Stage[main]/Nrpe_new/Package[perl-Net-SNMP]) Evaluated in 0.00 seconds

May 14 10:06:02 host1 puppet-agent[9526]: (/Whit[post]) Evaluated in 0.01 seconds

May 14 10:06:02 host1 puppet-agent[9526]: (/Schedule[daily]) Evaluated in 0.00 seconds

May 14 10:06:02 host1 puppet-agent[9526]: Finished catalog run in 3.31 seconds

Technically this run actually does more than the previous trace (JDK and setting up some yum repos) yet finishes in under 4 seconds.

Regards,

Allan

[Erik Dalén]

Do you have the exact same apache and passenger settings on both masters?

Having too few workers for example would lead it to waiting a lot for every file metadata lookup.

It is also quite sensitive to network latency for similar reasons, are all these hosts located at the same physical location?

Erik Dalén

[Allan Yung]

Hi Erik

The 2.6 master uses mongrel with an apache loadbalancer in front, 3.1 uses passenger (switching between passenger and webrick has no effect on the evaluation speed)

The masters are in the same physical location. I even switch a 2.6 client between masters and experience the slowness only on the 3.1 master.

Does the evaluation time include time to retrieve metadata from the master? It seems unlikely that the client is establishing an SSL connection and doing the md5 comparison in 0.02 seconds (2.6 master). Maybe when talking to the 3.1 master it has to establish a new SSL connection everytime?

Regards,

Allan