On Tue, 13 Nov 2012 11:08:57 -0800, Luke Kanies <[email protected]> wrote: >> The run with 2.7.19 takes around ten minutes wallclock time. 3.0.1 takes >> around nine minutes wallclock for a complete "puppet agent --test". The >> difference is approximately the time saved on master compiling the >> catalog. I'm not concerned about the two minutes spent actually managing >> 3000 resources (~0.04s per resource). I'm concerned about the other seven >> minutes overhead. > > Any idea what that other seven minutes is? > > That seems completely pathalogical.
I'm still scratching at the surface. I've attached the complete --verbose --noop log from master and agent. Since I've got no comparison, perhaps one of you can point out something. Best Regards, David -- You received this message because you are subscribed to the Google Groups "Puppet Developers" group. To post to this group, send email to [email protected]. To unsubscribe from this group, send email to [email protected]. For more options, visit this group at http://groups.google.com/group/puppet-dev?hl=en.
Nov 14 07:43:28 inhas60228 puppet-agent[10359]: Ignoring --listen on onetime run Nov 14 07:43:29 inhas60228 puppet-agent[10359]: Retrieving plugin Nov 14 07:43:30 inhas60228 puppet-agent[10359]: Loading facts in /var/log/puppet/lib/facter/mysql_exists.rb Nov 14 07:43:30 inhas60228 puppet-agent[10359]: Loading facts in /var/log/puppet/lib/facter/netlocation.rb Nov 14 07:43:30 inhas60228 puppet-agent[10359]: Loading facts in /var/log/puppet/lib/facter/rack.rb Nov 14 07:43:30 inhas60228 puppet-agent[10359]: Loading facts in /var/log/puppet/lib/facter/slot.rb Nov 14 07:43:33 inhas60228 puppet-master[1037]: (Scope(Class[main])) Configuring inhas60228.eu.boehringer.com for environment david Nov 14 07:43:51 inhas60228 puppet-master[1037]: (Scope(Icinga::Host[rdgcne0925.am.boehringer.com])) no parent for rdgcne0925.am.boehringer.com specified and none found from ipaddress (10.96.185.225) Nov 14 07:43:51 inhas60228 puppet-master[1037]: (Scope(Icinga::Host[rdgcne0927.am.boehringer.com])) no parent for rdgcne0927.am.boehringer.com specified and none found from ipaddress (10.96.185.227) Nov 14 07:43:51 inhas60228 puppet-master[1037]: (Scope(Icinga::Host[rdgcne0928.am.boehringer.com])) no parent for rdgcne0928.am.boehringer.com specified and none found from ipaddress (10.96.185.228) Nov 14 07:43:51 inhas60228 puppet-master[1037]: (Scope(Icinga::Host[rdgcne0930.am.boehringer.com])) no parent for rdgcne0930.am.boehringer.com specified and none found from ipaddress (10.96.185.230) Nov 14 07:43:51 inhas60228 puppet-master[1037]: (Scope(Icinga::Host[rdgcne0932.am.boehringer.com])) no parent for rdgcne0932.am.boehringer.com specified and none found from ipaddress (10.96.185.232) Nov 14 07:43:51 inhas60228 puppet-master[1037]: (Scope(Icinga::Host[vieasnccm1.eu.boehringer.com])) no parent for vieasnccm1.eu.boehringer.com specified and none found from ipaddress (10.1.1.100) Nov 14 07:43:51 inhas60228 puppet-master[1037]: (Scope(Icinga::Host[vieasnccn1.eu.boehringer.com])) no parent for vieasnccn1.eu.boehringer.com specified and none found from ipaddress (10.1.1.1) Nov 14 07:43:51 inhas60228 puppet-master[1037]: (Scope(Icinga::Host[viepcldx-e35.eu.boehringer.com])) no parent for viepcldx-e35.eu.boehringer.com specified and none found from ipaddress (172.20.68.178) Nov 14 07:43:51 inhas60228 puppet-master[1037]: (Scope(Icinga::Host[viepcldx-e36.eu.boehringer.com])) no parent for viepcldx-e36.eu.boehringer.com specified and none found from ipaddress (172.20.73.7) Nov 14 07:43:51 inhas60228 puppet-master[1037]: (Scope(Icinga::Host[viepcldx-e40.eu.boehringer.com])) no parent for viepcldx-e40.eu.boehringer.com specified and none found from ipaddress (172.20.68.66) Nov 14 07:43:51 inhas60228 puppet-master[1037]: (Scope(Icinga::Host[viepcldx-e41.eu.boehringer.com])) no parent for viepcldx-e41.eu.boehringer.com specified and none found from ipaddress (172.20.68.37) Nov 14 07:43:51 inhas60228 puppet-master[1037]: (Scope(Icinga::Host[viepcldx-e44.eu.boehringer.com])) no parent for viepcldx-e44.eu.boehringer.com specified and none found from ipaddress (172.20.68.97) Nov 14 07:43:51 inhas60228 puppet-master[1037]: (Scope(Icinga::Host[viepcldx-e46.eu.boehringer.com])) no parent for viepcldx-e46.eu.boehringer.com specified and none found from ipaddress (172.20.72.174) Nov 14 07:43:51 inhas60228 puppet-master[1037]: (Scope(Mysql::Database[puppet-dashboard])) Should configure mysql nrpe check Nov 14 07:43:51 inhas60228 puppet-master[1037]: (Scope(Mysql::Database[puppet])) Should configure mysql nrpe check Nov 14 07:43:51 inhas60228 puppet-master[1037]: (Scope(Mysql::Database[puppet-test])) Should configure mysql nrpe check Nov 14 07:43:52 inhas60228 puppet-master[1037]: (Scope(Icinga::Host[rdgcne0931.am.boehringer.com])) no parent for rdgcne0931.am.boehringer.com specified and none found from ipaddress (10.96.185.231) Nov 14 07:43:52 inhas60228 puppet-master[1037]: (Scope(Icinga::Host[vieasnccn2.eu.boehringer.com])) no parent for vieasnccn2.eu.boehringer.com specified and none found from ipaddress (10.1.1.2) Nov 14 07:43:52 inhas60228 puppet-master[1037]: (Scope(Icinga::Host[vieasnccn3.eu.boehringer.com])) no parent for vieasnccn3.eu.boehringer.com specified and none found from ipaddress (10.1.1.3) Nov 14 07:43:52 inhas60228 puppet-master[1037]: (Scope(Icinga::Host[vieasnccn4.eu.boehringer.com])) no parent for vieasnccn4.eu.boehringer.com specified and none found from ipaddress (10.1.1.4) Nov 14 07:43:52 inhas60228 puppet-master[1037]: (Scope(Icinga::Host[viepcldx-e02.eu.boehringer.com])) no parent for viepcldx-e02.eu.boehringer.com specified and none found from ipaddress (172.20.72.196) Nov 14 07:43:52 inhas60228 puppet-master[1037]: (Scope(Icinga::Host[viepcldx-e30.eu.boehringer.com])) no parent for viepcldx-e30.eu.boehringer.com specified and none found from ipaddress (172.20.68.22) Nov 14 07:44:48 inhas60228 puppet-master[1037]: Compiled catalog for inhas60228.eu.boehringer.com in environment david in 75.51 seconds Nov 14 07:49:28 inhas60228 puppet-agent[10359]: (/Stage[main]/Users/User[root]/password) current_value [old password hash redacted], should be [new password hash redacted] (noop) Nov 14 07:50:05 inhas60228 puppet-agent[10359]: (Icinga::Implementation::Conffile[/etc/icinga/conf.d/servers_host.example.com_check_mysql.cfg]) Would have triggered 'refresh' from 1 events Nov 14 07:50:05 inhas60228 puppet-agent[10359]: (/Stage[main]/Mysql::Server::Base/Icinga::Nrpe_check[check_mysql]/Icinga::Service[[email protected]]/Icinga::Implementation::Conffile[/etc/icinga/conf.d/servers_host.example.com_check_mysql.cfg]/File[/etc/icinga/conf.d/servers_host.example.com_check_mysql.cfg]/ensure) current_value absent, should be present (noop) Nov 14 07:50:05 inhas60228 puppet-agent[10359]: (/Stage[main]/Mysql::Server::Base/Icinga::Nrpe_check[check_mysql]/Icinga::Service[[email protected]]/Icinga::Implementation::Conffile[/etc/icinga/conf.d/servers_host.example.com_check_mysql.cfg]/File[/etc/icinga/conf.d/servers_host.example.com_check_mysql.cfg]) Scheduling refresh of Service[icinga] Nov 14 07:50:08 inhas60228 puppet-agent[10359]: (/Stage[main]/Mysql::Server::Base/Icinga::Nrpe_check[check_mysql]/Icinga::Service[[email protected]]/Nagios_service[[email protected]]/ensure) current_value absent, should be present (noop) Nov 14 07:50:08 inhas60228 puppet-agent[10359]: (/Stage[main]/Mysql::Server::Base/Icinga::Nrpe_check[check_mysql]/Icinga::Service[[email protected]]/Nagios_service[[email protected]]) Scheduling refresh of Service[icinga] Nov 14 07:50:16 inhas60228 puppet-agent[10359]: (Icinga::Service[[email protected]]) Would have triggered 'refresh' from 2 events Nov 14 07:50:32 inhas60228 puppet-agent[10359]: (/Stage[main]/Puppet/File[/etc/puppet/puppet.conf]/content) Nov 14 07:50:32 inhas60228 puppet-agent[10359]: (/Stage[main]/Puppet/File[/etc/puppet/puppet.conf]/content) Nov 14 07:50:32 inhas60228 puppet-agent[10359]: (/Stage[main]/Puppet/File[/etc/puppet/puppet.conf]/content) Nov 14 07:50:32 inhas60228 puppet-agent[10359]: (/Stage[main]/Puppet/File[/etc/puppet/puppet.conf]/content) Nov 14 07:50:32 inhas60228 puppet-agent[10359]: (/Stage[main]/Puppet/File[/etc/puppet/puppet.conf]/content) ########################################################################### Nov 14 07:50:32 inhas60228 puppet-agent[10359]: (/Stage[main]/Puppet/File[/etc/puppet/puppet.conf]/content) ########################################################################### Nov 14 07:50:32 inhas60228 puppet-agent[10359]: (/Stage[main]/Puppet/File[/etc/puppet/puppet.conf]/content) @@ -1,5 +1,5 @@ Nov 14 07:50:32 inhas60228 puppet-agent[10359]: (/Stage[main]/Puppet/File[/etc/puppet/puppet.conf]/content) @@ -56,7 +56,7 @@ Nov 14 07:50:32 inhas60228 puppet-agent[10359]: (/Stage[main]/Puppet/File[/etc/puppet/puppet.conf]/content) current_value {md5}cff281f293aa4ef80361811120b37bac, should be {md5}9393bf1186c1db57d3a2c2d5eb044c46 (noop) Nov 14 07:50:32 inhas60228 puppet-agent[10359]: (/Stage[main]/Puppet/File[/etc/puppet/puppet.conf]/content) # dynamic environments Nov 14 07:50:32 inhas60228 puppet-agent[10359]: (/Stage[main]/Puppet/File[/etc/puppet/puppet.conf]/content) --- /etc/puppet/puppet.conf#0112012-11-12 13:25:45.294064520 +0100 Nov 14 07:50:32 inhas60228 puppet-agent[10359]: (/Stage[main]/Puppet/File[/etc/puppet/puppet.conf]/content) [main] Nov 14 07:50:32 inhas60228 puppet-agent[10359]: (/Stage[main]/Puppet/File[/etc/puppet/puppet.conf]/content) + reports = puppet_dashboard Nov 14 07:50:32 inhas60228 puppet-agent[10359]: (/Stage[main]/Puppet/File[/etc/puppet/puppet.conf]/content) - reports = puppet_dashboard, foreman Nov 14 07:50:32 inhas60228 puppet-agent[10359]: (/Stage[main]/Puppet/File[/etc/puppet/puppet.conf]/content) storeconfigs_backend = puppetdb Nov 14 07:50:32 inhas60228 puppet-agent[10359]: (/Stage[main]/Puppet/File[/etc/puppet/puppet.conf]/content) storeconfigs = true Nov 14 07:50:32 inhas60228 puppet-agent[10359]: (/Stage[main]/Puppet/File[/etc/puppet/puppet.conf]/content) +# this file is maintained by puppet Nov 14 07:50:32 inhas60228 puppet-agent[10359]: (/Stage[main]/Puppet/File[/etc/puppet/puppet.conf]/content) -# this file is maintained by puppet: puppet.conf-db.27.erb Nov 14 07:50:32 inhas60228 puppet-agent[10359]: (/Stage[main]/Puppet/File[/etc/puppet/puppet.conf]/content) +++ /tmp/puppet-file20121114-10359-z36jec-0#0112012-11-14 07:50:32.819294609 +0100 Nov 14 07:50:32 inhas60228 puppet-agent[10359]: (/Stage[main]/Puppet/File[/etc/puppet/puppet.conf]/content) trace = true Nov 14 07:50:41 inhas60228 puppet-agent[10359]: (Class[Puppet]) Would have triggered 'refresh' from 1 events Nov 14 07:50:49 inhas60228 puppet-agent[10359]: (Icinga::Nrpe_check[check_mysql]) Would have triggered 'refresh' from 1 events Nov 14 07:50:50 inhas60228 puppet-agent[10359]: (Class[Mysql::Server::Base]) Would have triggered 'refresh' from 1 events Nov 14 07:50:56 inhas60228 puppet-agent[10359]: (Class[Users]) Would have triggered 'refresh' from 1 events Nov 14 07:50:58 inhas60228 puppet-agent[10359]: (Class[Icinga::Sensor_base]) Would have triggered 'refresh' from 3 events Nov 14 07:50:58 inhas60228 puppet-agent[10359]: (/Stage[main]/Icinga::Sensor_base/Service[icinga]) Scheduling refresh of Service[nsca] Nov 14 07:50:58 inhas60228 puppet-agent[10359]: (/Stage[main]/Icinga::Sensor_base/Service[icinga]) Scheduling refresh of Service[xinetd] Nov 14 07:50:58 inhas60228 puppet-agent[10359]: (/Stage[main]/Icinga::Sensor_base/Service[icinga]) Would have triggered 'refresh' from 2 events Nov 14 07:50:58 inhas60228 puppet-agent[10359]: (/Stage[main]/Icinga::Sensor_base/Service[nsca]) Would have triggered 'refresh' from 1 events Nov 14 07:50:58 inhas60228 puppet-agent[10359]: (/Stage[main]/Icinga::Sensor_base/Service[xinetd]) Would have triggered 'refresh' from 1 events Nov 14 07:50:59 inhas60228 puppet-agent[10359]: (Stage[main]) Would have triggered 'refresh' from 4 events Nov 14 07:51:00 inhas60228 puppet-agent[10359]: Finished catalog run in 125.23 seconds Nov 14 07:51:42 returned to bash prompt: real 8m14.790s user 2m20.098s sys 0m44.515s
