Project

General

Profile

Actions

Bug #17942

closed

Timeout during Puppet class import, slow re-initialization of Puppet 3

Added by Yvan Broccard over 7 years ago. Updated almost 7 years ago.

Status:
Rejected
Priority:
Normal
Assignee:
-
Category:
Puppet
Target version:
-
Difficulty:
Triaged:
Fixed in Releases:
Found in Releases:

Description

I'm not able to import Puppet classes or environments from foreman-proxy. The foreman-proxy is running on the puppetmaster, and plugins "puppet" and "puppetca" have been enabled on this smart proxy. There is a timeout. I tried to query the proxy directly with curl with a tcpdump running and nothing but Keepalive messages are seen on the wire.

For example :
URL=puppet/environments
PORT=8000
time curl http://vmctldeploy10.rsvgnw.local:${PORT}/${URL}
["admybr","testing","production","lab"]

But if my URL is this, I never get an answer :
URL=puppet/environments/production/classes

In the Foreman WebUI, it's just waiting when I try either to import classes, import environnments, or query the foreman-proxy.

In the example above, I switched to HTTP on port 8000 instead of HTTPS/8443 in the hope of eliminating SSL issues, so the proxy is listening on both protocols, but the behaviour is the same.
I've spent quite some time on this and I can't find the error, it seems I'm the only one to have this.

Some other errors appears in the foreman server log as well, for example ERF50-5345 :

2017-01-05 07:43:09 4382433b [app] [I] Redirected to https://vmctldeploy30.rsvgnw.local/environments
2017-01-05 07:43:09 4382433b [app] [W] ProxyAPI operation FAILED | ProxyAPI::ProxyException: ERF12-4115 [ProxyAPI::ProxyException]: Unable to get classes from Puppet for lab ([RestClient::RequestTimeout]: Request Timeout) for proxy https://vmctldeploy10.rsvgnw.local:8443/puppet | /usr/share/foreman/lib/proxy_api/puppet.rb:27:in `rescue in classes' | /usr/share/foreman/lib/proxy_api/puppet.rb:21:in `classes' | /usr/share/foreman/app/services/puppet_class_importer.rb:153:in `actual_classes' | /usr/share/foreman/app/services/puppet_class_importer.rb:77:in `new_classes_for' | /usr/share/foreman/app/services/puppet_class_importer.rb:24:in `block in changes'
--
2017-01-05 14:00:34 f8013754 [app] [I] Completed 200 OK in 31964ms (Views: 33.8ms | ActiveRecord: 27.0ms)
2017-01-05 14:00:34 f8013754 [app] [W] Failed to counts | Foreman::WrappedException: ERF50-5345 [Foreman::WrappedException]: Unable to connect ([ProxyAPI::ProxyException]: ERF12-5356 [ProxyAPI::ProxyException]: Unable to get PuppetCA certificates ([RestClient...) | /usr/share/foreman/app/services/proxy_status/base.rb:55:in `rescue in fetch_proxy_data' | /usr/share/foreman/app/services/proxy_status/base.rb:47:in `fetch_proxy_data' | /usr/share/foreman/app/services/proxy_status/puppetca.rb:4:in `certs' | /usr/share/foreman/app/controllers/puppetca_controller.rb:12:in `counts' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_controller/metal/implicit_render.rb:4:in `send_action'
--
2017-01-05 14:00:35 f8013754 [app] [I] Completed 200 OK in 29380ms (Views: 607.0ms | ActiveRecord: 9.1ms)
2017-01-05 14:20:14 f8013754 [app] [W] Failed to puppet_environments | Foreman::WrappedException: ERF50-5345 [Foreman::WrappedException]: Unable to connect ([ProxyAPI::ProxyException]: ERF12-4115 [ProxyAPI::ProxyException]: Unable to get classes from Puppet for admybr ([R...) | /usr/share/foreman/app/services/proxy_status/base.rb:55:in `rescue in fetch_proxy_data' | /usr/share/foreman/app/services/proxy_status/base.rb:47:in `fetch_proxy_data' | /usr/share/foreman/app/services/proxy_status/puppet.rb:4:in `environment_stats' | /usr/share/foreman/app/controllers/smart_proxies_controller.rb:59:in `puppet_environments' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_controller/metal/implicit_render.rb:4:in `send_action'
--
2017-01-05 16:34:44 f8013754 [app] [I] Redirected to https://vmctldeploy30.rsvgnw.local/environments
2017-01-05 16:34:44 f8013754 [app] [W] ProxyAPI operation FAILED | ProxyAPI::ProxyException: ERF12-4115 [ProxyAPI::ProxyException]: Unable to get classes from Puppet for admybr ([RestClient::RequestTimeout]: Request Timeout) for proxy https://vmctldeploy10.rsvgnw.local:8443/puppet | /usr/share/foreman/lib/proxy_api/puppet.rb:27:in `rescue in classes' | /usr/share/foreman/lib/proxy_api/puppet.rb:21:in `classes' | /usr/share/foreman/app/services/puppet_class_importer.rb:153:in `actual_classes' | /usr/share/foreman/app/services/puppet_class_importer.rb:77:in `new_classes_for' | /usr/share/foreman/app/services/puppet_class_importer.rb:38:in `changes'


Files

foreman-debug-nC4ao.tar.xz foreman-debug-nC4ao.tar.xz 460 KB Yvan Broccard, 01/05/2017 10:37 AM

Related issues 2 (0 open2 closed)

Related to Smart Proxy - Bug #18369: Foreman-proxy timeout - Error: ERF12-4115 [ProxyAPI::ProxyException]Duplicate02/02/2017Actions
Related to Smart Proxy - Bug #18290: "Puppet is taking too long to respond" during class import with Puppet 4.xClosed01/27/2017Actions
Actions #1

Updated by Yvan Broccard over 7 years ago

Error: ERF12-4115 [ProxyAPI::ProxyException]: Unable to get classes from Puppet for admybr ([RestClient::RequestTimeout]: Request Timeout) for proxy https://vmctldeploy10.rsvgnw.local:8443/puppet

Actions #2

Updated by Dominic Cleal over 7 years ago

proxy.log shows very slow iteration over manifests across multiple environments, measured in minutes per manifest. It's unclear from the log if this is during a request (which would explain timeouts) or from the startup process.

D, [2017-01-05T03:42:44.276364 #113893] DEBUG -- : Scanning oradb classes in /etc/puppet/environments/production/modules/oradb/manifests/listener.pp
D, [2017-01-05T03:42:44.276805 #113893] DEBUG -- : Initializing from Puppet config file: /etc/puppet/puppet.conf
D, [2017-01-05T03:46:23.462033 #113893] DEBUG -- : Scanning oradb classes in /etc/puppet/environments/production/modules/oradb/manifests/installem_agent.pp
D, [2017-01-05T03:46:23.462328 #113893] DEBUG -- : Initializing from Puppet config file: /etc/puppet/puppet.conf

Superficially similar to #14266, which I've not confirmed has been fully resolved in the smart proxy.

Note that this only affects Puppet 3, which is now EOL. With Puppet 4 the API should make this obsolete, and since 4.4+ caching is also supported.

Actions #3

Updated by Tim Meusel over 7 years ago

Hi.

I get the same issues in my Puppet 4 environment. The Webinterface says:

Error: ERF12-4115 [ProxyAPI::ProxyException]: Unable to get classes from Puppet for puppet4 ([RestClient::ServiceUnavailable]: 503 Service Unavailable) for proxy https://*.de:8443/puppet

The foreman-proxy.log:

D, [2017-01-20T18:28:25.102324 ] DEBUG -- : accept: 10.111.2.251:55644 
D, [2017-01-20T18:28:25.103942 ] DEBUG -- : Rack::Handler::WEBrick is invoked. 
D, [2017-01-20T18:28:25.104827 ] DEBUG -- : verifying remote client 10.111.2.251 against trusted_hosts ["*.de"] 
E, [2017-01-20T18:28:40.106095 ] ERROR -- : Puppet is taking too long to respond, please try again later. 
D, [2017-01-20T18:28:40.106214 ] DEBUG -- : Puppet is taking too long to respond, please try again later. 
I, [2017-01-20T18:28:40.106599 ]  INFO -- : 10.111.2.251 - - [20/Jan/2017:18:28:40 +0100] "GET /puppet/environments/puppet4/classes HTTP/1.1" 503 61 15.0020 

99% of the requests fail, just a few work. I digged around with curl and time, working and nonworking requests run around 15s. I'm running foreman 1.14.0

Actions #4

Updated by Anonymous over 7 years ago

When puppet 4 and puppet environment-classes api are used, smart-proxy will attempt to initialize puppet classes cache on startup. Should that fail, it will skip cache initialization and attempt to fetch classes on next request. It will return a time-out error to the client after waiting for puppet's response for 15 seconds. After that, smart-proxy will continue to await the response for another 285 seconds in the background. Could you try repeating your query again after a minute or two? Could you also check smart-proxy logs to see if there are any errors there?

I would also check how fast puppet server responds and if there are any errors in puppet logs.

Actions #5

Updated by Tim Meusel over 7 years ago

The cache is created during startup:

I, [2017-01-20T17:58:58.281767 ]  INFO -- : Started puppet class cache initialization
D, [2017-01-20T17:59:00.408362 ] DEBUG -- : Initializing puppet class cache for 'puppet4' environment
D, [2017-01-20T17:59:00.408857 ] DEBUG -- : Initializing puppet class cache for 'production' environment
D, [2017-01-20T17:59:00.409331 ] DEBUG -- : Initializing puppet class cache for 'puppet4fabricdev' environment
D, [2017-01-20T17:59:00.409610 ] DEBUG -- : Initializing puppet class cache for 'common' environment
I, [2017-01-20T17:59:26.025801 ]  INFO -- : Finished puppet class cache initialization

I've a lot of stdlib deprecation warnings in my puppetserver logs, but I can't spot anything related to this. The foreman-proxy only throws the timeouts I pasted in my first comment. I'm able to get the list via curl from https://localhost:8443/puppet/environments/puppet4/classes after a bit of time, but unable via the webinterface. Tried it for 10 minutes - no luck. Is it possible to increase the timeouts somewhere?

Actions #6

Updated by Anonymous over 7 years ago

This is quite odd -- it looks like your puppet server responses are very slow: it should return classes pretty quickly once its classes cache is initialized (which, I think, happens on first request). The fact that even repeated requests that should just return 304s time-out (they should come back pretty much instantaneously) also makes me think that there might be a problem with puppet setup. Even more strange is that it only takes 26 seconds to retrieve classes for all environments on startup.

Could you try to use curl to retrieve classes from puppet directly and note the response times?

Actions #7

Updated by Tim Meusel over 7 years ago

yeah very strange. I would expect that the puppetserver caches it and further calls are fast and working if one ever suceeded, but thats not the case. I've no idea how Puppet implemented the API. I will see if I can increase the debug output for the puppetserver, maybe I will find some errors there.

Actions #8

Updated by Anonymous over 7 years ago

Could you try using curl with GET method to puppet/v3/environment_classes?environment=<environment_name> to retrieve classes from puppet server directly and note the response times?

Actions #9

Updated by Tim Meusel over 7 years ago

Did 4 calls, all needed 21s for the same env

Actions #10

Updated by Anonymous over 7 years ago

You should be getting an ETAG with each response. What are the response times if you add "If-None-Match" header with a value appropriate for the environment you are querying?

Actions #11

Updated by Dominic Cleal over 7 years ago

Caching must be enabled (via environment-class-cache-enabled in puppetserver.conf) for ETAG and caching support in Puppet Server, it isn't the default.

I don't think this is related to the original bug report which was on Puppet 3, please file a new issue or open a thread on foreman-users.

Actions #12

Updated by Tim Meusel over 7 years ago

Thanks Dominic, I enabled the caching and everything is working now \o/

Actions #13

Updated by Slagian Momirovici about 7 years ago

  • Related to Bug #18369: Foreman-proxy timeout - Error: ERF12-4115 [ProxyAPI::ProxyException] added
Actions #14

Updated by Dominic Cleal about 7 years ago

  • Subject changed from Foreman-proxy timeout with ERF12-4115 when trying to import classes from Puppet to Timeout during Puppet class import, slow re-initialization of Puppet 3
Actions #15

Updated by Dominic Cleal about 7 years ago

  • Related to Bug #18290: "Puppet is taking too long to respond" during class import with Puppet 4.x added
Actions #16

Updated by Dominic Cleal about 7 years ago

#18290 covers a similar problem (possibly as described in comments above) when using Puppet 4. The two are otherwise not related.

Actions #17

Updated by Anonymous almost 7 years ago

  • Status changed from New to Rejected

Puppet 3 is EOL and the Puppet 4 problem is fixed.

Actions

Also available in: Atom PDF