Puppet first run timing out

[Cesar Covarrubias]

I'm working on deploying Puppet to our environment and after reinstalling some nodes, I run Puppet for the first time. It appears to be updating some Puppet specific files (see below), and then times out with the error:

"Error: /File[/var/lib/puppet/lib/facter/ip6tables_version.rb]/ensure: change from absent to file failed: execution expired Error: Could not retrieve plugin: execution expired".

The file it errors on varies, depending on how many times the agent has run. Once I run Puppet a few times to get all the updates, and applies all my configs fine. All my DNS settings are correct and have been tested. Is it possible to extend the timeout on this sync? Any other thoughts?

Environment: Centos 6.4 64Bit. ruby 1.8.7 Puppet 3.2.2 Facter 1.7.1

Sample Output:

# puppet agent -t
Info: Retrieving plugin
Notice: /File[/var/lib/puppet/lib/puppet/parser/functions/defined_with_params.rb]/ensure: defined content as '{md5}ffab4433d03f32b551f2ea024a2948fc'
Notice: /File[/var/lib/puppet/lib/puppet/parser/functions/bool2num.rb]/ensure: defined content as '{md5}8e627eee990e811e35e7e838c586bd77'
Notice: /File[/var/lib/puppet/lib/puppet/parser/functions/README.markdown]/ensure: defined content as '{md5}e596ce938864a80fd1e51640cca7f612'
Notice: /File[/var/lib/puppet/lib/puppet/parser/functions/hash.rb]/ensure: defined content as '{md5}75fd86c01d5b1e50be1bc8b22d3d0a61'
Notice: /File[/var/lib/puppet/lib/puppet/parser/functions/prefix.rb]/ensure: defined content as '{md5}6a2d86233c9435afc1738f60a0c34576'
Notice: /File[/var/lib/puppet/lib/puppet/parser/functions/is_integer.rb]/ensure: defined content as '{md5}6520458000b349f1c7ba7c9ed382ae0b'
Notice: /File[/var/lib/puppet/lib/puppet/parser/functions/swapcase.rb]/ensure: defined content as '{md5}4902f38f0b9292afec66d40fee4b02ec'
Notice: /File[/var/lib/puppet/lib/puppet/parser/functions/to_bytes.rb]/ensure: defined content as '{md5}83f23c33adbfa42b2a9d9fc2db3daeb4'
Notice: /File[/var/lib/puppet/lib/puppet/parser/functions/has_interface_with.rb]/ensure: defined content as '{md5}8d3ebca805dc6edb88b6b7a13d404787'
Notice: /File[/var/lib/puppet/lib/puppet/parser/functions/lstrip.rb]/ensure: defined content as '{md5}210b103f78622e099f91cc2956b6f741'
Notice: /File[/var/lib/puppet/lib/puppet/parser/functions/is_array.rb]/ensure: defined content as '{md5}875ca4356cb0d7a10606fb146b4a3d11'
Notice: /File[/var/lib/puppet/lib/puppet/parser/functions/min.rb]/ensure: defined content as '{md5}35f1e50e7f9ff6d5b04e48952d4e13bd'
Notice: /File[/var/lib/puppet/lib/puppet/parser/functions/sort.rb]/ensure: defined content as '{md5}504b033b438461ca4f9764feeb017833'
Notice: /File[/var/lib/puppet/lib/puppet/parser/functions/merge.rb]/ensure: defined content as '{md5}52281fe881b762e2adfef20f58dc4180'
Notice: /File[/var/lib/puppet/lib/puppet/parser/functions/member.rb]/ensure: defined content as '{md5}541e67d06bc4155e79b00843a125e9bc'
Notice: /File[/var/lib/puppet/lib/puppet/parser/functions/capitalize.rb]/ensure: defined content as '{md5}14481fc8c7c83fe002066ebcf6722f17'
Notice: /File[/var/lib/puppet/lib/puppet/parser/functions/values.rb]/ensure: defined content as '{md5}066a6e4170e5034edb9a80463dff2bb5'
Notice: /File[/var/lib/puppet/lib/puppet/parser/functions/chomp.rb]/ensure: defined content as '{md5}7040b3348d2f770f265cf4c8c25c51c5'
Notice: /File[/var/lib/puppet/lib/puppet/parser/functions/unique.rb]/ensure: defined content as '{md5}217ccce6d23235af92923f50f8556963'
Notice: /File[/var/lib/puppet/lib/puppet/parser/functions/shuffle.rb]/ensure: defined content as '{md5}6445e6b4dc62c37b184a60eeaf34414b'
Notice: /File[/var/lib/puppet/lib/puppet/parser/functions/num2bool.rb]/ensure: defined content as '{md5}dbdc81982468ebb8ac24ab78d7097ad3'
Error: /File[/var/lib/puppet/lib/puppet/parser/functions/join_keys_to_values.rb]/ensure: change from absent to file failed: execution expired
Error: Could not retrieve plugin: execution expired
Info: Caching catalog for hostname.domain.com

[jcbollinger]

Puppet is timing out during plugin synchronization, which is normally very fast.  That it times out several times, at different points, before going to completion points to a capacity problem at your master, rather than a problem associated with a specific file or module.  There is a config parameters by which you can tweak the timeout for catalog retrieval, but none specific to plugin sync.  Even if there were such a config option, tweaking it would not resolve the root problem.

There are a host of areas that contribute to aspects of your master's capacity, but the first thing that is usually suggested here is to run the master under apache/passenger, so as to allow multiple clients to be serviced in parallel.  The master's built-in "webrick" server support serving only one client at a time, even if the resources available on the master's host would otherwise be sufficient to handle more.

If you are already running under passenger, or if running that way does not solve the problem, then you may just need to scale up by to multiple masters or beefier ones.  Before you do that, though, it would be worth your while to check for other possible issues such as network congestion and I/O contention.  Also make sure that you master has enough RAM -- it can be a bit of a memory hog, and if it ends up swapping back and forth to disk a lot then that will really kill your performance.  In that vein, if you are using passenger already then tweaking its configuration may help: too many workers may do more harm than good by causing a lot of swapping.


John

[Cesar Covarrubias]

I am already using Passenger. My master is still being minimally utilized, as I'm just now beginning the deployment process. In terms of specs, it is running 4 cores and 8GB of mem and 4GB of swap. During a run, the total system usage is no more than 2GB and no swap. No network congestion and I/O is low on the SAN which these VMs use.

The odd thing is once the hosts get all the libs sync'd, performance is fine on further changes. It's quite perplexing.

--
You received this message because you are subscribed to a topic in the Google Groups "Puppet Users" group.
To unsubscribe from this topic, visit https://groups.google.com/d/topic/puppet-users/Q7Jry3JAc4U/unsubscribe.
To unsubscribe from this group and all its topics, send an email to puppet-users...@googlegroups.com.
To post to this group, send email to puppet...@googlegroups.com.
Visit this group at http://groups.google.com/group/puppet-users.
For more options, visit https://groups.google.com/groups/opt_out.
 
 

--
Very Respectfully,
Cesar Covarrubias

[jcbollinger]

On Wednesday, August 7, 2013 11:46:06 AM UTC-5, Cesar Covarrubias wrote:

I am already using Passenger. My master is still being minimally utilized, as I'm just now beginning the deployment process. In terms of specs, it is running 4 cores and 8GB of mem and 4GB of swap. During a run, the total system usage is no more than 2GB and no swap. No network congestion and I/O is low on the SAN which these VMs use.

The odd thing is once the hosts get all the libs sync'd, performance is fine on further changes. It's quite perplexing.

To be certain that contention by multiple Puppet clients does not contribute to the issue, ensure that the problem still occurs when only one client attempts to sync at a time.  If it does, then the issue probably has something to do with the pattern of communication between client and master, for that's the main thing that differs between an initial run and subsequent ones.

During the initial plugin sync, the master delivers a moderately large number of small files to the client, whereas on subsequent runs it usually delivers only a catalog, and perhaps, later, 'source'd Files declared in your manifests.  There may be a separate connection established between client and master for each synced file, and anything that might slow that down could contribute to the problem.

For instance, if a firewall on client, master, or any device between makes it slow or unreliable to establish connections; if multiple clients are configured with the same IP number; if a router anywhere along the network path is marginal; if a leg of the path is wireless and subject to substantial radio interference; if any part of your network is suffering from a denial-of-service attack; etc. then probabilistically speaking, the effect would be much more noticeable when a successful transaction requires many connections and data transfers than when it requires few.


John

[Pete Hartman]

I'm having a similar problem.

I know for a fact that I am not contending with other agents, because this is in a lab environment and none of my agents is scheduled for periodic runs (yet).

I have successfully run puppet agent -t first time, signed the cert, and run it a second time to pull over stdlib and other modules on agents running RHEL 6 and Solaris 10u10 x86.

But I'm getting this timeout on a Solaris 10u10 box running on a T4-1 SPARC system.

This was my third run:

 # date;puppet agent -t;date
Wed Sep  4 14:12:05 CDT 2013
Info: Retrieving plugin
Notice: /File[/var/lib/puppet/lib/puppet/parser/functions/count.rb]/ensure: defined content as '{md5}9eb74eccd93e2b3c87fd5ea14e329eba'
Notice: /File[/var/lib/puppet/lib/puppet/parser/functions/validate_bool.rb]/ensure: defined content as '{md5}4ddffdf5954b15863d18f392950b88f4'
Notice: /File[/var/lib/puppet/lib/puppet/parser/functions/get_module_path.rb]/ensure: defined content as '{md5}d4bf50da25c0b98d26b75354fa1bcc45'
Notice: /File[/var/lib/puppet/lib/puppet/parser/functions/is_ip_address.rb]/ensure: defined content as '{md5}a714a736c1560e8739aaacd9030cca00'
Error: /File[/var/lib/puppet/lib/puppet/parser/functions/is_numeric.rb]/ensure: change from absent to file failed: execution expired

Error: Could not retrieve plugin: execution expired

Info: Caching catalog for AGENT
Info: Applying configuration version '1378322110'
Notice: Finished catalog run in 0.11 seconds
Wed Sep  4 14:15:58 CDT 2013


Each time I've run it, I get about 10 or so files and then I get "execution expired".

What I'd really like to see is whether I can increase the expiry timeout.


Some other details:  The master is RHEL 6 on a Sun/Oracle X4800, lots and lots of fast cores and memory.  I'm using Puppet Open Source. I'm using passenger.  I have no real modules other than some basic forge modules I've installed to start out with.

[root@MASTER audit]# cd /etc/puppet/modules
[root@MASTER modules]# ls
apache  concat  epel  firewall  inifile  passenger  puppet  puppetdb  ruby  stdlib

I briefly disabled SELinux on the master, but saw no change in behavior.

I'm certain that the firewall is right because other agents have had no problems.  iptables IS enabled, however.

The master and the agent are on the same subnet, so I don't suspect a network performance issue directly.

On Solaris, because the vendor supplied OpenSSL is antique and doesn't include SHA256, we have built our own OpenSSL and our own Ruby using that OpenSSL Library.  Even though SPARC is a 64 bit architecture, Ruby seems to default to a 32 bit build, so we built OpenSSL as 32 bit as well to match.  I've got an open question to the guy responsible for that to see how hard it would be to try to build Ruby as 64 bit, that's likely a next test.

I have not yet run snoop on the communication to see what's going on the network side, but as I say I don't really expect the network to be the problem, between being on the same subnet and success on other systems with higher clock speeds.

Any pointers to other possible causes or somewhere I can (even temporarily) increase the timeout would be appreciated.

[Cory Stoker]

We have lots of puppet clients on crappy bandwidth that would time out
like this as well. The option we changed to fix this is:

#Specify the timeout to wait for catalog in seconds
configtimeout = 600

The default time is like 60 or 120 secs. Another thing you should do
is check out the logs of the web server if you are using passenger.
You should see a ton of "GET" requests when you need to sync plugins.
To force your puppet agent to redownload stuff remove the $vardir/lib
directory on the agent.

> --
> You received this message because you are subscribed to the Google Groups
> "Puppet Users" group.
> To unsubscribe from this group and stop receiving emails from it, send an

[Pete Hartman]

Cool, thank you very much for the information.

> You received this message because you are subscribed to a topic in the Google Groups "Puppet Users" group.
> To unsubscribe from this topic, visit https://groups.google.com/d/topic/puppet-users/Q7Jry3JAc4U/unsubscribe.
> To unsubscribe from this group and all its topics, send an email to puppet-users...@googlegroups.com.

[Pete Hartman]

Being able to set the timeout long enough gave us enough data to find the problem.

Our SPARC build of OpenSSL used some configuration options that were, shall we say, non-optimal :-).

On a corrected OpenSSL build the SPARC times are now in the same ballpark as the x86 times.

Thanks again for your help Cory.

Pete

[Mathew Winstone]

Any chance you can share what configuration options were non-optimal?

We're having some timeout issues as well on CentOS.

[Pete Hartman]

I doubt the problem I was referring to would have any impact on
CentOS. The problem was that we were building on SPARC, and had used
compile options that caused the build to go to a "lowest common
denominator" architecture of SPARC V7, which does not have a lot of
important SPARC V9 assembly instructions for doing block copies and
math. This slowed the crypto routines a LOT.

I suppose there might be some kind of similar behavior under CentOS
with the wrong build options, but I'd be at a complete loss to suggest
what they might be.

> You received this message because you are subscribed to a topic in the

> Google Groups "Puppet Users" group.

> To unsubscribe from this topic, visit
> https://groups.google.com/d/topic/puppet-users/Q7Jry3JAc4U/unsubscribe.
> To unsubscribe from this group and all its topics, send an email to
> puppet-users...@googlegroups.com.
> To view this discussion on the web visit
> https://groups.google.com/d/msgid/puppet-users/42ffc4a2-65e2-4222-b2ea-3da50391a0d7%40googlegroups.com.
> For more options, visit https://groups.google.com/d/optout.