Merge branch 'stable'

* stable:
  (PDB-868) Add exponential back offs for db retry logic
  (PDB-865) PDB 2.2 migration fails when nodes have no facts

Conflicts:
	src/puppetlabs/puppetdb/jdbc.clj

acceptance/tests/db_resilience/postgres_restart.rb

@@ -21,9 +21,6 @@
 
     restart_postgres(database)
 
-    # Avoid a restart race condition
-    sleep(1)
-
     step "Verify that the number of active nodes is what we expect" do
       result = on database, %Q|curl -G http://localhost:8080/v3/nodes|
       result_node_statuses = JSON.parse(result.stdout)

project.clj

@@ -31,6 +31,7 @@
                  [cheshire "5.3.1"]
                  [org.clojure/core.match "0.2.0-rc5"]
                  [org.clojure/math.combinatorics "0.0.4"]
+                 [org.clojure/math.numeric-tower "0.0.4"]
                  [org.clojure/tools.logging "0.2.6"]
                  [org.clojure/tools.nrepl "0.2.3"]
                  [puppetlabs/tools.namespace "0.2.4.1"]

src/puppetlabs/puppetdb/jdbc.clj

@@ -11,8 +11,8 @@
             [puppetlabs.puppetdb.time :as pl-time]
             [puppetlabs.puppetdb.jdbc.internal :refer :all]
             [puppetlabs.puppetdb.schema :as pls]
-            [schema.core :as s]))
-
+            [schema.core :as s]
+            [clojure.math.numeric-tower :as math]))
 
 (defn valid-jdbc-query?
   "Most SQL queries generated in the PuppetDB code base are represented internally
@@ -211,31 +211,48 @@
    :repeatable-read java.sql.Connection/TRANSACTION_REPEATABLE_READ
    :serializable java.sql.Connection/TRANSACTION_SERIALIZABLE})
 
+(pls/defn-validated exponential-sleep!
+  "Sleeps for a period of time, based on an adjustable base exponential backoff.
+
+   In most cases a base of 2 is sufficient, but you can adjust this to create
+   tighter or looser sleep cycles."
+  [current-attempt :- s/Int
+   base :- (s/either s/Int Double)]
+  (let [sleep-ms (* (- (math/expt base current-attempt) 1) 1000)]
+    (Thread/sleep sleep-ms)))
+
 (pls/defn-validated retry-sql-or-fail :- Boolean
   "Log the attempts made, and the final failure during SQL retries.
 
    If there are still retries to perform, returns false."
-  [n :- s/Int
-   e]
+  [remaining :- s/Int
+   current :- s/Int
+   exception]
   (cond
-   (zero? n)
+   (zero? remaining)
    (do
      (log/warn "Caught exception. Last attempt, throwing exception.")
-     (throw e))
+     (throw exception))
 
    :else
    (do
-     (log/debug (format "Caught %s: '%s'. SQL Error code: '%s'. Retry attempts left: %s "
-                        (.getName (class e)) (.getMessage e) (.getSQLState e) n))
+     (log/debug (format "Caught %s: '%s'. SQL Error code: '%s'. Attempt: %s of %s."
+                        (.getName (class exception))
+                        (.getMessage exception)
+                        (.getSQLState exception)
+                        (inc current)
+                        (+ current remaining)))
+     (exponential-sleep! current 1.3)
      false)))
 
 (pls/defn-validated retry-sql*
   "Executes f. If an exception is thrown, will retry. At most n retries
    are done. If still some retryable error state is thrown it is bubbled upwards
    in the call chain."
-  [n :- s/Int
+  [remaining :- s/Int
    f]
-  (loop [n n]
+  (loop [r remaining
+         current 0]
     (if-let [result (try
                       [(f)]
 
@@ -244,12 +261,12 @@
                         (let [sqlstate (.getSQLState e)]
                           (case sqlstate
                             ;; Catch connection errors and retry them
-                            "08003" (retry-sql-or-fail n e)
+                            "08003" (retry-sql-or-fail r current e)
 
                             ;; All other errors are not retried
                             (throw e)))))]
       (result 0)
-      (recur (dec n)))))
+      (recur (dec r) (inc current)))))
 
 (defmacro retry-sql
   "Executes body. If a retryable error state is thrown, will retry. At most n
@@ -264,7 +281,7 @@
   [db-spec tx-isolation-level f]
   {:pre [(or (nil? tx-isolation-level)
              (get isolation-levels tx-isolation-level))]}
-  (retry-sql 1
+  (retry-sql 5
              (sql/with-connection db-spec
                (when-let [isolation-level (get isolation-levels tx-isolation-level)]
                  (.setTransactionIsolation (:connection jint/*db*) isolation-level))

src/puppetlabs/puppetdb/scf/migrate.clj

@@ -718,15 +718,16 @@
                        (query-to-vec "SELECT * FROM certname_facts WHERE certname = ?")
                        (reduce #(assoc %1 (:name %2) (:value %2)) {}))
             environment (->> environment_id
-                          (query-to-vec "SELECT name FROM environments WHERE id = ?")
-                          first
-                          :name)]
-        (scf-store/add-facts!
-          {:name (str certname)
-           :values facts
-           :timestamp timestamp
-           :environment environment
-           :producer-timestamp nil})))))
+                             (query-to-vec "SELECT name FROM environments WHERE id = ?")
+                             first
+                             :name)]
+        (when-not (empty? facts)
+          (scf-store/add-facts!
+            {:name (str certname)
+             :values facts
+             :timestamp timestamp
+             :environment environment
+             :producer-timestamp nil}))))))
 
 (defn structured-facts []
   ;; -----------

test/puppetlabs/puppetdb/scf/migrate_test.clj

@@ -125,38 +125,55 @@
             :while (< i 25)]
       (migration)
       (record-migration! i))
-    (let [current-time (to-timestamp (now))]
+    (let [current-time (to-timestamp (now))
+          yesterday (to-timestamp (-> 1 days ago))]
       (sql/insert-records
        :certnames
        {:name "testing1" :deactivated nil}
-       {:name "testing2" :deactivated nil})
+       {:name "testing2" :deactivated nil}
+       {:name "testing3" :deactivated current-time}
+       {:name "testing4" :deactivated nil}
+       {:name "testing5" :deactivated current-time})
       (sql/insert-records
         :environments
        {:id 1 :name "test_env_1"}
-       {:id 2 :name "test_env_2"})
+       {:id 2 :name "test_env_2"}
+       {:id 3 :name "test_env_3"}
+       {:id 4 :name "test_env_4"}
+       {:id 5 :name "test_env_5"})
       (sql/insert-records
        :certname_facts_metadata
        {:certname "testing1" :timestamp current-time :environment_id 1}
-       {:certname "testing2" :timestamp current-time :environment_id 2})
+       {:certname "testing2" :timestamp current-time :environment_id 2}
+       ;; deactivated node with facts
+       {:certname "testing3" :timestamp current-time :environment_id 3}
+       ;; active node with no facts
+       {:certname "testing4" :timestamp yesterday :environment_id 4}
+       ;; deactivated node with no facts
+       {:certname "testing5" :timestamp yesterday :environment_id 5})
       (sql/insert-records
        :certname_facts
        {:certname "testing1" :name "foo"  :value  "1"}
-       {:certname "testing2" :name "bar"  :value "true"})
+       {:certname "testing2" :name "bar"  :value "true"}
+       {:certname "testing3" :name "baz"  :value "false"})
 
       (structured-facts)
       (record-migration! 25)
 
       (let [response
             (query-to-vec
-              "SELECT path,e.id AS environment_id, e.name AS environment,timestamp,value_string
+              "SELECT path, e.id AS environment_id, e.name AS environment,
+              timestamp, value_string
                FROM
                environments e INNER JOIN factsets fs on e.id=fs.environment_id
                               INNER JOIN facts f on f.factset_id=fs.id
                               INNER JOIN fact_values fv on f.fact_value_id=fv.id
                               INNER JOIN fact_paths fp on fp.id=fv.path_id")]
+        ;; every node should with facts should be represented
         (is (= response
-               [{:path "foo", :environment_id 1, :environment "test_env_1",
-                 :timestamp (to-timestamp current-time), :value_string "1"}
-                {:path "bar", :environment_id 2, :environment "test_env_2",
-                 :timestamp (to-timestamp current-time),
-                :value_string "true"}]))))))
+               [{:path "foo" :environment_id 1 :environment "test_env_1"
+                 :timestamp (to-timestamp current-time) :value_string "1"}
+                {:path "bar" :environment_id 2 :environment "test_env_2"
+                 :timestamp (to-timestamp current-time) :value_string "true"}
+                {:path "baz" :environment_id 3 :environment "test_env_3"
+                 :timestamp (to-timestamp current-time) :value_string "false"}]))))))