Bug 1250083 - Smart proxy puppet classes REST timeout of 60 seconds too small
Smart proxy puppet classes REST timeout of 60 seconds too small
Status: CLOSED NOTABUG
Product: Red Hat Satellite 6
Classification: Red Hat
Component: Content Management (Show other bugs)
6.1.0
Unspecified Unspecified
unspecified Severity medium (vote)
: Unspecified
: --
Assigned To: Katello Bug Bin
Katello QA List
: Triaged
Depends On:
Blocks: 1122832
  Show dependency treegraph
 
Reported: 2015-08-04 09:29 EDT by Peter Vreman
Modified: 2015-12-03 10:51 EST (History)
4 users (show)

See Also:
Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
Environment:
Last Closed: 2015-08-27 09:13:59 EDT
Type: Bug
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---


Attachments (Terms of Use)

  None (edit)
Description Peter Vreman 2015-08-04 09:29:43 EDT
Description of problem:
The REST timeout of 60 seconds to retrieve the list of puppet classes from foreman smart proxy can be too small when the Sat6 is under load.

But initial response time of a request is without caching is 77 seconds, this is still too slow that the REST from Katello call times out after 60 seconds.
A second call to the smart proxy takes only 3 seconds, so the caching is working for that case:

# zgrep hg_crash_ foreman-proxy/proxy.log-20150804.gz
10.92.14.128 - - [03/Aug/2015 12:54:19] "GET /puppet/environments/KT_Hilti_Library_hg_crash_18/classes HTTP/1.1" 200 11417 76.6783
10.92.14.128 - - [03/Aug/2015 12:56:51] "GET /puppet/environments/KT_Hilti_Library_hg_crash_18/classes HTTP/1.1" 200 11417 3.5445


The correspond log from katello, that shows it times out 16 seconds before the smart proxy finished processing the request, that is matches nicely with a REST timeout setting of 60 seconds:

2015-08-03 12:54:03 [E] ERF12-4115 [ProxyAPI::ProxyException]: Impossible d'obtenir les classes Puppet pour KT_Hilti_Library_hg_crash_18 ([RestClient::RequestTimeout]: Request Timeout) pour le proxy https://li-lc-1578.hag.hilti.com:9090/puppet (ProxyAPI::ProxyException)
/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:155:in `actual_classes'
/usr/share/foreman/app/services/puppet_class_importer.rb:78:in `new_classes_for'
/usr/share/foreman/app/services/puppet_class_importer.rb:39:in `changes'
/opt/rh/ruby193/root/usr/share/gems/gems/katello-2.2.0.51/app/services/katello/puppet_class_importer_extensions.rb:22:in `update_environment'
/opt/rh/ruby193/root/usr/share/gems/gems/katello-2.2.0.51/app/lib/katello/foreman.rb:36:in `update_puppet_environment'
/opt/rh/ruby193/root/usr/share/gems/gems/katello-2.2.0.51/app/lib/actions/katello/foreman/content_update.rb:32:in `finalize'
/opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.7.7/lib/dynflow/action.rb:503:in `block (2 levels) in execute_finalize'
/opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.7.7/lib/dynflow/middleware/stack.rb:26:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.7.7/lib/dynflow/middleware/stack.rb:26:in `pass'
/opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.7.7/lib/dynflow/middleware.rb:16:in `pass'


Testing from the commandline using curl with a clean caches and heavy disk IO it can be reproduced:

# <reboot server to have no caches>

# <start repository sync with heavy disk io>

# nproc && uptime
8
 13:19:17 up 36 min,  3 users,  load average: 9.07, 9.35, 5.80

# puppetenv=$(ls -1 /etc/puppet/environments | grep -v example | head -n1)

# puppetenv=$(ls -1 /etc/puppet/environments | grep -v example | head -n1)                                                                                  [crash] root@li-lc-1578:~# time curl --cert /etc/foreman/client_cert.pem --key /etc/foreman/client_key.pem --cacert /etc/foreman/proxy_ca.pem -k -H "Accept: application/json" https://$(hostname -f):9090/puppet/environments/$puppetenv/classes > /dev/null
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
100 11417  100 11417    0     0    157      0  0:01:12  0:01:12 --:--:--  2814

real    1m12.527s
user    0m0.191s
sys     0m0.056s

# time find /etc/puppet/environments/$puppetenv/modules -name '*.pp' | while read f; do grep '^class [[:alpha:]]' $f; done | wc -l
77

real    0m1.229s
user    0m0.160s
sys     0m0.380s


Version-Release number of selected component (if applicable):


How reproducible:


Steps to Reproduce:
1. Create Content View A
1. Add 50 puppet modules with 100 classes
2. Start a Load using Repository Sync:
2a. Select all repositories
2b. Click Sync now Redhat channel sync 
3. Publish Content View A
4. Watch the response time of smart-proxy


Actual results:
Timeout when in 

Expected results:


Additional info:
Comment 2 Mike McCune 2015-08-25 00:35:39 EDT
PROPOSED WORKAROUND:

Increase timeout in /etc/foreman/plugins/katello.yaml

Change rest_client_timeout to 240

rest_client_timeout: 240

run:

katello-service restart
Comment 3 Peter Vreman 2015-08-26 06:11:53 EDT
Hi Mike,

I already have a timeout of 120 in my configuration.

[crash] root@li-lc-1578:~# grep rest_client_timeout /etc/foreman/plugins/katello.yaml
  rest_client_timeout: 120

This BZ is about a timeout connecting to the foreman smart proxy occurring after 60 seconds.
After a bit of grepping it found that there is a different Foreman setting involved:

[crash] root@li-lc-1578:/usr/share/foreman# grep -r proxy_request_timeout *
app/models/setting/general.rb:        self.set('proxy_request_timeout', N_("Max timeout for REST client requests to smart-proxy"), 60)
lib/proxy_api/resource.rb:      @connect_params = {:timeout => Setting[:proxy_request_timeout], :open_timeout => 10, :headers => { :accept => :json },

That see that it is even available in the Foreman UI under Settings:

proxy_request_timeout 	60 	Max timeout for REST client requests to smart-proxy

I will update it for our system to be a bitter large.
This case can be closed.

Note You need to log in before you can comment on or make changes to this bug.