(SERVER-391) Throw slingshot exception on timeout

src/clj/puppetlabs/puppetserver/ringutils.clj

@@ -5,7 +5,8 @@
             [puppetlabs.kitchensink.core :as ks]
             [puppetlabs.puppetserver.certificate-authority :as ca]
             [puppetlabs.ssl-utils.core :as ssl-utils]
-            [schema.core :as schema]))
+            [schema.core :as schema]
+            [ring.util.response :as rr]))
 
 ;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;
 ;;; Schema
@@ -115,3 +116,14 @@
     (if (client-allowed-access? settings req)
       (handler req)
       {:status 401 :body "Unauthorized"})))
+
+(defn wrap-with-puppet-version-header
+  "Function that returns a middleware that adds an
+  X-Puppet-Version header to the response."
+  [handler version]
+  (fn [request]
+    (let [response (handler request)]
+      ; Our compojure app returns nil responses sometimes.
+      ; In that case, don't add the header.
+      (when response
+        (rr/header response "X-Puppet-Version" version)))))

src/clj/puppetlabs/services/ca/certificate_authority_core.clj

@@ -254,22 +254,11 @@
       (GET "/certificate_revocation_list/:ignored-node-name" []
         (handle-get-certificate-revocation-list ca-settings))))
 
-(defn wrap-with-puppet-version-header
-  "Function that returns a middleware that adds an
-  X-Puppet-Version header to the response."
-  [handler version]
-  (fn [request]
-    (let [response (handler request)]
-      ; Our compojure app returns nil responses sometimes.
-      ; In that case, don't add the header.
-      (when response
-        (rr/header response "X-Puppet-Version" version)))))
-
 (schema/defn ^:always-validate
   build-ring-handler
   [ca-settings :- ca/CaSettings
    puppet-version :- schema/Str]
   (-> (routes ca-settings)
       ;(liberator-dev/wrap-trace :header)           ; very useful for debugging!
-      (wrap-with-puppet-version-header puppet-version)
+      (ringutils/wrap-with-puppet-version-header puppet-version)
       (ringutils/wrap-response-logging)))

src/clj/puppetlabs/services/jruby/jruby_puppet_service.clj

@@ -6,6 +6,7 @@
             [puppetlabs.trapperkeeper.services :as tk-services]
             [puppetlabs.services.protocols.jruby-puppet :as jruby]
             [puppetlabs.services.jruby.jruby-puppet-core :as jruby-core]
+            [slingshot.slingshot :as sling]
             [puppetlabs.services.jruby.jruby-puppet-schemas :as jruby-schemas]))
 
 ;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;
@@ -75,8 +76,14 @@
   [jruby-puppet jruby-service & body]
   `(loop [pool-instance# (jruby/borrow-instance ~jruby-service)]
      (if (nil? pool-instance#)
-       (throw (IllegalStateException.
-                "Error: Attempt to borrow a JRuby instance from the pool timed out")))
+       (sling/throw+
+         {:type    ::jruby-timeout
+          :message (str "Attempt to borrow a JRuby instance from the pool "
+                        "timed out; Puppet Server is temporarily overloaded. If "
+                        "you get this error repeatedly, your server might be "
+                        "misconfigured or trying to serve too many agent nodes. "
+                        "Check Puppet Server settings: "
+                        "jruby-puppet.max-active-instances.")}))
      (if (jruby-schemas/retry-poison-pill? pool-instance#)
        (do
          (jruby-core/return-to-pool pool-instance#)

src/clj/puppetlabs/services/master/master_core.clj

@@ -108,8 +108,9 @@
 
 (defn build-ring-handler
   "Creates the entire compojure application (all routes and middleware)."
-  [request-handler]
+  [request-handler puppet-version]
   {:pre [(fn? request-handler)]}
   (-> (root-routes request-handler)
       ringutils/wrap-request-logging
-      ringutils/wrap-response-logging))
+      ringutils/wrap-response-logging
+      (ringutils/wrap-with-puppet-version-header puppet-version)))

src/clj/puppetlabs/services/master/master_service.clj

@@ -13,19 +13,20 @@
   (init
    [this context]
    (core/validate-memory-requirements!)
-   (let [path        (get-route this)
-         config      (get-config)
-         certname    (get-in config [:puppet-server :certname])
-         localcacert (get-in config [:puppet-server :localcacert])
-         settings    (ca/config->master-settings config)]
+   (let [path           (get-route this)
+         config         (get-config)
+         certname       (get-in config [:puppet-server :certname])
+         localcacert    (get-in config [:puppet-server :localcacert])
+         puppet-version (get-in config [:puppet-server :puppet-version])
+         settings       (ca/config->master-settings config)]
 
      (retrieve-ca-cert! localcacert)
      (initialize-master-ssl! settings certname)
 
      (log/info "Master Service adding a ring handler")
      (add-ring-handler
        this
-      (compojure/context path [] (core/build-ring-handler handle-request))))
+      (compojure/context path [] (core/build-ring-handler handle-request puppet-version))))
    context)
   (start
     [this context]

src/clj/puppetlabs/services/request_handler/request_handler_core.clj

@@ -9,7 +9,8 @@
             [ring.middleware.params :as ring-params]
             [ring.util.codec :as ring-codec]
             [ring.util.response :as ring-response]
-            [slingshot.slingshot :as sling]))
+            [slingshot.slingshot :as sling]
+            [puppetlabs.services.jruby.jruby-puppet-service :as jruby]))
 
 ;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;
 ;;; Internal
@@ -259,21 +260,35 @@
     (= (:type x)
        :puppetlabs.services.request-handler.request-handler-core/bad-request)))
 
+(defn jruby-timeout?
+  [x]
+  "Determine if the supplied slingshot message is for a JRuby borrow timeout."
+  (when (map? x)
+    (= (:type x)
+       :puppetlabs.services.jruby.jruby-puppet-service/jruby-timeout)))
+
+(defn output-error
+  [{:keys [uri]} {:keys [message]} http-status]
+  (log/errorf "Error %d on SERVER at %s: %s" http-status uri message)
+  (-> (ring-response/response message)
+      (ring-response/status http-status)
+      (ring-response/content-type "text/plain")))
+
 ;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;
 ;;; Public
 
 (defn handle-request
-  [request jruby-instance config]
+  [request jruby-service config]
   (sling/try+
-    (->> request
-         wrap-params-for-jruby
-         (as-jruby-request config)
-         clojure.walk/stringify-keys
-         make-request-mutable
-         (.handleRequest jruby-instance)
-         response->map)
-    (catch bad-request? {:keys [message]}
-      (log/errorf "Error 400 on SERVER at %s: %s" (:uri request) message)
-      (-> (ring-response/response message)
-          (ring-response/status 400)
-          (ring-response/content-type "text/plain")))))
+    (jruby/with-jruby-puppet jruby-instance jruby-service
+      (->> request
+           wrap-params-for-jruby
+           (as-jruby-request config)
+           clojure.walk/stringify-keys
+           make-request-mutable
+           (.handleRequest jruby-instance)
+           response->map))
+    (catch bad-request? e
+      (output-error request e 400))
+    (catch jruby-timeout? e
+      (output-error request e 503))))

src/clj/puppetlabs/services/request_handler/request_handler_service.clj

@@ -2,19 +2,13 @@
   (:require [puppetlabs.trapperkeeper.core :as tk]
             [puppetlabs.services.protocols.request-handler :as handler]
             [puppetlabs.services.request-handler.request-handler-core :as core]
-            [puppetlabs.services.jruby.jruby-puppet-service :as jruby]
             [puppetlabs.trapperkeeper.services :as tk-services]))
 
-(defn- handle-request
-  [request jruby-service config]
-  (jruby/with-jruby-puppet jruby-puppet jruby-service
-    (core/handle-request request jruby-puppet config)))
-
 (tk/defservice request-handler-service
                handler/RequestHandlerService
                [[:PuppetServerConfigService get-config]]
                (handle-request
                  [this request]
                  (let [jruby-service (tk-services/get-service this :JRubyPuppetService)
                        config (core/config->request-handler-settings (get-config))]
-                   (handle-request request jruby-service config))))
+                   (core/handle-request request jruby-service config))))

test/unit/puppetlabs/services/master/master_core_test.clj

@@ -8,7 +8,7 @@
 
 (deftest test-master-routes
   (let [handler     (fn ([req] {:request req}))
-        app         (build-ring-handler handler)
+        app         (build-ring-handler handler "1.2.3")
         request     (fn r ([path] (r :get path))
                           ([method path] (app (mock/request method path))))]
     (is (nil? (request "/v2.0/foo")))
@@ -42,7 +42,7 @@
   (testing (str "that the content-type in the ring request is replaced with "
                 "application/octet-stream for a file_bucket_file put request")
     (let [handler     (fn ([req] {:request req}))
-          app         (build-ring-handler handler)
+          app         (build-ring-handler handler "1.2.3")
           resp        (app {:request-method :put
                             :content-type   "text/plain"
                             :uri            "/foo/file_bucket_file/bar"})]

test/unit/puppetlabs/services/request_handler/request_handler_core_test.clj

@@ -6,8 +6,8 @@
             [puppetlabs.trapperkeeper.testutils.logging :as logutils]
             [clojure.test :refer :all]
             [ring.util.codec :as ring-codec]
-            [slingshot.slingshot :as sling]
-            [slingshot.test :refer :all]))
+            [slingshot.test :refer :all]
+            [puppetlabs.services.protocols.jruby-puppet :as jruby]))
 
 ;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;
 ;;; Test Data
@@ -234,14 +234,37 @@
                         ring-codec/url-encode))))))
 
 (deftest handle-request-test
+  (def dummy-service
+    (reify jruby/JRubyPuppetService
+      (borrow_instance [_] {})
+      (return_instance [_ _])
+      (free_instance_count [_])
+      (mark_all_environments_expired_BANG_ [_])
+      (flush_jruby_pool_BANG_ [_])))
+
+  (def dummy-service-with-timeout
+    (reify jruby/JRubyPuppetService
+      (borrow_instance [_] nil)
+      (return_instance [_ _])
+      (free_instance_count [_])
+      (mark_all_environments_expired_BANG_ [_])
+      (flush_jruby_pool_BANG_ [_])))
+
   (logutils/with-test-logging
     (testing "slingshot bad requests translated to ring response"
       (let [bad-message "it's real bad"]
         (with-redefs [core/as-jruby-request (fn [_ _]
                                               (core/throw-bad-request!
                                                bad-message))]
           (let [response (core/handle-request {:body (StringReader. "blah")}
-                                              {}
+                                              dummy-service
                                               {})]
             (is (= 400 (:status response)) "Unexpected response status")
-            (is (= bad-message (:body response)) "Unexpected response body")))))))
+            (is (= bad-message (:body response)) "Unexpected response body"))
+          (let [response (core/handle-request {:body (StringReader. "")}
+                                              dummy-service-with-timeout
+                                              {})]
+            (is (= 503 (:status response)) "Unexpected response status")
+            (is (.startsWith
+                  (:body response)
+                  "Attempt to borrow a JRuby instance from the pool"))))))))