Foreman » Smart Proxy

Dominic Cleal wrote:

Could you please show the corresponding smart proxy logs behind the 503 error received? Debug logs from the startup of the smart proxy may also be useful to show the active configuration.

Hi,

Sure

D, [2017-01-26T09:24:47.271886 ] DEBUG -- : Rack::Handler::WEBrick is mounted on /.
I, [2017-01-26T09:24:47.272065 ] INFO -- : WEBrick::HTTPServer#start: pid=57900 port=8443
D, [2017-01-26T09:24:47.293966 ] DEBUG -- : Initializing puppet class cache for 'production' environment
D, [2017-01-26T09:24:47.294306 ] DEBUG -- : Initializing puppet class cache for 'dev' environment
I, [2017-01-26T09:25:09.410181 ] INFO -- : Finished puppet class cache initialization
D, [2017-01-26T09:25:26.436903 ] DEBUG -- : accept:<IP>:45794
D, [2017-01-26T09:25:26.454296 ] DEBUG -- : Rack::Handler::WEBrick is invoked.
D, [2017-01-26T09:25:26.476200 ] DEBUG -- : verifying remote client <IP> against trusted_hosts ["<HOST>l"]
I, [2017-01-26T09:25:26.560670 ] INFO -- : <IP> - - [26/Jan/2017:09:25:26 +0000] "GET /puppet/environments HTTP/1.1" 200 20 0.0847

D, [2017-01-26T09:25:26.602187 ] DEBUG -- : close: <IP>:45794
D, [2017-01-26T09:25:26.662192 ] DEBUG -- : accept: <IP>:45796
D, [2017-01-26T09:25:26.663510 ] DEBUG -- : Rack::Handler::WEBrick is invoked.
D, [2017-01-26T09:25:26.664222 ] DEBUG -- : verifying remote client <IP> against trusted_hosts ["<HOST>"]
I, [2017-01-26T09:25:26.742639 ] INFO -- : <IP> - - [26/Jan/2017:09:25:26 +0000] "GET /puppet/environments/production/classes HTTP/1.1" 200 2 0.0786

D, [2017-01-26T09:25:26.783797 ] DEBUG -- : close: <IP>:45796
D, [2017-01-26T09:25:28.177582 ] DEBUG -- : accept: <IP>:45806
D, [2017-01-26T09:25:28.179288 ] DEBUG -- : Rack::Handler::WEBrick is invoked.
D, [2017-01-26T09:25:28.180054 ] DEBUG -- : verifying remote client 10.34.180.152 against trusted_hosts ["<HOST>"]
E, [2017-01-26T09:25:43.181061 ] ERROR -- : Puppet is taking too long to respond, please try again later.
D, [2017-01-26T09:25:43.181207 ] DEBUG -- : Puppet is taking too long to respond, please try again later.
I, [2017-01-26T09:25:43.181566 ] INFO -- : <IP> - - [26/Jan/2017:09:25:43 +0000] "GET /puppet/environments/dev/classes HTTP/1.1" 503 61 15.0017

The environment classes impl added in #15095 is likely too aggressive with the default 15 second timeout, and it should probably have a higher default.

It makes more sense to have a short client timeout when the Puppet Server environment classes API has caching enabled (as then a subsequent query will have cached a value, and the P.S. API will quickly respond with a 304), but not so much in a default configuration where caching is disabled. In the non-caching case, the timeout should be higher to wait for a full response from Puppet Server.

One approach is to increase the timeout. It's trivial, but there still will be a puppet environment with sufficient number of classes to trigger this issue again. I would suggest an alternative: leave the timeout as is (maybe increase it slightly). Poll puppet server every couple of minutes in background and update local cache (+ etag if available). On an api request for classes attempt to pull classes from the puppet server, return locally cached classes on a timeout. This way we know we are always getting data that's reasonably recent (no more than a couple of minutes old).

Thoughts?

If the data is old by a couple of minutes then it's likely to cause staleness issues for all users automating Foreman's environment imports, or even for users changing an environment manually and importing. It could also create significant background load for large environments.