(PE-37113) benchmark: add/report simple catalog query duration metric

src/puppetlabs/puppetdb/cli/benchmark.clj

@@ -71,6 +71,7 @@
    [clojure.pprint :refer [pprint]]
    [clojure.walk :as walk]
    [me.raynes.fs :as fs]
+   [metrics.timers :as timers :refer [timer time!]]
    [murphy :refer [try!]]
    [puppetlabs.i18n.core :refer [trs]]
    [puppetlabs.kitchensink.core :as kitchensink]
@@ -79,6 +80,7 @@
    [puppetlabs.puppetdb.cheshire :as json]
    [puppetlabs.puppetdb.cli.util :refer [exit run-cli-cmd]]
    [puppetlabs.puppetdb.client :as client]
+   [puppetlabs.puppetdb.metrics.core :as metrics]
    [puppetlabs.puppetdb.nio :refer [get-path]]
    [puppetlabs.puppetdb.random
     :refer [safe-sample-normal random-string random-bool random-sha1]]
@@ -116,6 +118,10 @@
 (def ^:private warn-on-reflection-orig *warn-on-reflection*)
 (set! *warn-on-reflection* true)
 
+(def metrics
+  (let [reg (get-in metrics/metrics-registries [:benchmark :registry])]
+    {:query-duration (timer reg (metrics/keyword->metric-name [:global] :query-duration))}))
+
 ;; Completely ad-hoc...
 (def ^:private discard-all-messages?
   (->> (or (System/getenv "PDB_BENCH_DISCARD_ALL_MESSAGES") "")
@@ -632,7 +638,9 @@
   (assert (seq queries))
   (let [[query & more] queries
         result (try!
-                 (query-pdb-discard-response (query-uri base-url) query ssl-opts)
+                 (time!
+                  (:query-duration metrics)
+                  (query-pdb-discard-response (query-uri base-url) query ssl-opts))
                  (assoc event :result true)
                  (catch IOException ex
                    (report-sender-ex ex)
@@ -829,11 +837,12 @@
                   cmd-per-sec (float (/ cmds time-diff-seconds))
                   query-per-sec (float (/ queries time-diff-seconds))]
               (println-err
-               (trs "{0} cmd/s (~{1} nodes @ {2}m) | {3} query/s | {4} err"
+               (trs "{0} cmd/s (~{1} nodes @ {2}m) | {3} q/s {4} s/q | {5} err"
                     cmd-per-sec
                     (int (/ cmd-per-sec expected-node-message-rate))
                     (time/in-minutes run-interval)
-                    query-per-sec
+                    (format "%.2f" query-per-sec)
+                    (format "%.2f" (-> metrics :query-duration timers/mean (/ 1000000000)))
                     errors))
               (recur 0 0 0 t))
             (recur cmds queries errors last-report-time)))))))

src/puppetlabs/puppetdb/metrics/core.clj

@@ -10,6 +10,7 @@
        :reporter (reporter registry {:domain domain})})))
 
 (def metrics-registries {:admin (new-metrics "puppetlabs.puppetdb.admin")
+                         :benchmark (new-metrics "puppetlabs.puppetdb.benchmark")
                          :mq (new-metrics "puppetlabs.puppetdb.mq")
                          :dlo (new-metrics "puppetlabs.puppetdb.dlo")
                          :http (new-metrics "puppetlabs.puppetdb.http")