Fails if upstream forge is down

[sgran]

Hi,

In the proxy code, the gets to the upstream forge aren't wrapped in any exception handling, so on those rare occasions that the upstream forge is down, the caching proxy fails even if it could satisfy the module request locally.

Can it not fall back to only serving local data when upstream is down?

Cheers,

[i11]

Hi,

Thanks for reporting it. Sure thing, I'll take a looking at it later today.

[i11]

It took me a bit longer than I have anticipated, but 1.6.0 was released. There will be directory backend added with every proxied one for serving modules from cache. Let me know how that works for you.

[i11]

Minor improvements in 1.7.0. Tested and it works for me. Please feel free to re-open the issue if it still persists.

[craiggenner]

I've updated to 1.7.0 and I'm seeing a problem with this release under conditions connected with this issue.

I've blocked traffic returning from the forge api to simulate it being unavailable, and now on start up (running as daemon) I see the following:

[2015-06-23 13:14:14] INFO  Detecting API version for https://forgeapi.puppetlabs.com...
/usr/lib/ruby/1.9.1/net/http.rb:763:in `initialize': execution expired (Timeout::Error)
    from /usr/lib/ruby/1.9.1/net/http.rb:763:in `open'
    from /usr/lib/ruby/1.9.1/net/http.rb:763:in `block in connect'
    from /usr/lib/ruby/1.9.1/timeout.rb:55:in `timeout'
    from /usr/lib/ruby/1.9.1/timeout.rb:100:in `timeout'
    from /usr/lib/ruby/1.9.1/net/http.rb:763:in `connect'
    from /usr/lib/ruby/1.9.1/net/http.rb:756:in `do_start'
    from /usr/lib/ruby/1.9.1/net/http.rb:745:in `start'
    from /usr/lib/ruby/1.9.1/open-uri.rb:306:in `open_http'
    from /usr/lib/ruby/1.9.1/open-uri.rb:775:in `buffer_open'
    from /usr/lib/ruby/1.9.1/open-uri.rb:203:in `block in open_loop'
    from /usr/lib/ruby/1.9.1/open-uri.rb:201:in `catch'
    from /usr/lib/ruby/1.9.1/open-uri.rb:201:in `open_loop'
    from /usr/lib/ruby/1.9.1/open-uri.rb:146:in `open_uri'
    from /var/lib/gems/1.9.1/gems/open_uri_redirections-0.2.1/lib/open-uri/redirections_patch.rb:55:in `open_uri'
    from /usr/lib/ruby/1.9.1/open-uri.rb:677:in `open'
    from /usr/lib/ruby/1.9.1/open-uri.rb:33:in `open'
    from /var/lib/gems/1.9.1/gems/puppet-forge-server-1.7.0/lib/puppet_forge_server/http/http_client.rb:43:in `block in open_uri'
    from /var/lib/gems/1.9.1/gems/puppet-forge-server-1.7.0/lib/puppet_forge_server/http/http_client.rb:42:in `open_uri'
    from /var/lib/gems/1.9.1/gems/puppet-forge-server-1.7.0/lib/puppet_forge_server/http/http_client.rb:29:in `get'
    from /var/lib/gems/1.9.1/gems/puppet-forge-server-1.7.0/lib/puppet_forge_server/utils/http.rb:23:in `get_api_version'
    from /var/lib/gems/1.9.1/gems/puppet-forge-server-1.7.0/lib/puppet_forge_server/server.rb:102:in `block (2 levels) in backends'
    from /var/lib/gems/1.9.1/gems/puppet-forge-server-1.7.0/lib/puppet_forge_server/server.rb:98:in `map'
    from /var/lib/gems/1.9.1/gems/puppet-forge-server-1.7.0/lib/puppet_forge_server/server.rb:98:in `block in backends'
    from /var/lib/gems/1.9.1/gems/puppet-forge-server-1.7.0/lib/puppet_forge_server/server.rb:97:in `each'
    from /var/lib/gems/1.9.1/gems/puppet-forge-server-1.7.0/lib/puppet_forge_server/server.rb:97:in `map'
    from /var/lib/gems/1.9.1/gems/puppet-forge-server-1.7.0/lib/puppet_forge_server/server.rb:97:in `backends'
    from /var/lib/gems/1.9.1/gems/puppet-forge-server-1.7.0/lib/puppet_forge_server/server.rb:30:in `go'
    from /var/lib/gems/1.9.1/gems/puppet-forge-server-1.7.0/bin/puppet-forge-server:21:in `<top (required)>'
    from /usr/local/bin/puppet-forge-server:23:in `load'
    from /usr/local/bin/puppet-forge-server:23:in `<main>'

I've been able to reduce the impact of this with the following patch:

diff --git a/lib/puppet_forge_server/http/http_client.rb b/lib/puppet_forge_server/http/http_client.rb
index f43767a..e5603ba 100644
--- a/lib/puppet_forge_server/http/http_client.rb
+++ b/lib/puppet_forge_server/http/http_client.rb
@@ -20,8 +20,16 @@ require 'timeout'

 module PuppetForgeServer::Http
   class HttpClient
+    def initialize
+      @log = PuppetForgeServer::Logger.get
+    end
+
     def get(url)
-      open_uri(url).read
+      begin
+        open_uri(url).read
+      rescue
+        nil
+      end
     end

     def download(url)
@@ -30,8 +38,12 @@ module PuppetForgeServer::Http

     private
     def open_uri(url)
-      ::Timeout.timeout(10) do
-        open(url, 'User-Agent' => "Puppet-Forge-Server/#{PuppetForgeServer::VERSION}", :allow_redirections => :safe)
+      begin
+        ::Timeout.timeout(10) do
+          open(url, 'User-Agent' => "Puppet-Forge-Server/#{PuppetForgeServer::VERSION}", :allow_redirections => :safe)
+        end
+      rescue ::Timeout::Error
+        @log.error("Timeout connecting to: "+url)
       end
     end
   end

(I'm about to submit a merge request with this in it)

With this the process starts as a daemon and is able to start serving requests for both the directory and the proxy backend.

But if I run puppet-forge-server through apache/passenger I see problems. For directory modules it's happy to serve them to the client. But for proxy modules (that are already cached) it gives a 400 Bad Request to the client.

I can't see anything in the logs, but have been able to capture this:

[pid 14267] writev(10, [{"Status: ", 8}, {"400", 3}, {"\r\n", 2}, {"Content-Type", 12}, {": ", 2}, {"application/json", 16}, {"\r\n", 2}, {"Content-Length", 14}, {": ", 2}, {"61", 2}, {"\r\n", 2}, {"X-Content-Type-Options", 22}, {": ", 2}, {"nosniff", 7}, {"\r\n", 2}, {"\r\n", 2}], 16) = 100
[pid 14267] ppoll([{fd=10, events=POLLOUT}], 1, NULL, NULL, 8) = 1 ([{fd=10, revents=POLLOUT}])
[pid 14267] write(10, "{\"errors\":[\"'puppetlabs/stdlib' is not a valid module slug\"]}", 61) = 6

This comes from lib/puppet_forge_server/app/version3.rb, but at this point I'm a little lost as to why it's doing this under apache and not when run as a daemon.

Any ideas?

[i11]

Timeout exception is caught a bit higher in the backend classes, so it should be passed on from the HttpClient I'll do some troubleshouting a bit later today. In the mean time you should be fine with 1.6.0.

[craiggenner]

No problems, this is only my test area so far. :-)

[i11]

Ok. So the timeout you've got while starting a server is normal and expected behavior is proxied forge can't be reached. This issue was about handling official forge being down for a short while while the serer is already running and modules were proxied.

As a side note I'm planning to parametrize the read timeout in the next minor release.

Closing the issue.