penpot/backend/test/backend_tests/metrics_test.clj

236 lines
11 KiB
Clojure

;; This Source Code Form is subject to the terms of the Mozilla Public
;; License, v. 2.0. If a copy of the MPL was not distributed with this
;; file, You can obtain one at http://mozilla.org/MPL/2.0/.
;;
;; Copyright (c) KALEIDOS SUBSIDIARY SL
(ns backend-tests.metrics-test
(:require
[app.common.exceptions :as ex]
[app.main :as main]
[app.metrics :as mtx]
[app.metrics.definition :as-alias mdef]
[clojure.test :as t]
[integrant.core :as ig]
[promesa.exec :as px])
(:import
io.prometheus.client.Collector$MetricFamilySamples
io.prometheus.client.Collector$MetricFamilySamples$Sample
io.prometheus.client.CollectorRegistry
java.util.concurrent.ScheduledThreadPoolExecutor))
(def ^:private valid-definitions? @#'app.metrics/valid-definitions?)
;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;
;; Helpers
;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;
(defn- sample-names
[metrics]
(->> (mtx/get-registry metrics)
(.metricFamilySamples)
(enumeration-seq)
(mapcat (fn [^Collector$MetricFamilySamples family]
(map (fn [^Collector$MetricFamilySamples$Sample sample]
(.-name sample))
(.samples family))))
(set)))
;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;
;; Tests
;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;
(t/deftest process-metrics-are-exported
;; the process cpu and file descriptor families come from the
;; prometheus client `StandardExports`, registered by `app.metrics`.
;; They are read reflectively from the OS MXBean and depend on the
;; `jdk.management` module at runtime: a pruned jlink JRE turns the
;; MXBean into `sun.management.BaseOperatingSystemImpl`, the reflective
;; getters fail and the families are silently dropped (that is how the
;; production backend lost `process_open_fds`). This test pins the
;; contract the fd alert relies on.
(let [metrics (ig/init-key :app.metrics/metrics {:default {}})
names (sample-names metrics)]
(t/is (contains? names "process_open_fds"))
(t/is (contains? names "process_max_fds"))
(t/is (contains? names "process_cpu_seconds_total"))))
(t/deftest label-coercion
(t/are [value fallback expected]
(= expected (mtx/label value fallback))
"fs" "unknown" "fs"
:s3 "unknown" "s3"
200 "unknown" "200"
nil "unknown" "unknown"
nil "default" "default"))
(t/deftest run-contains-label-arity-bug
;; A wrong label count throws inside the prometheus client; the
;; recording failure must not propagate to the caller.
(let [registry (CollectorRegistry.)
collector (mtx/create-collector {::mdef/name "penpot_test_run_arity"
::mdef/help "test helper"
::mdef/type :counter
::mdef/labels ["a" "b"]
:app.metrics/registry registry})
instance (reify mtx/IMetrics
(get-collector [_ _] collector))]
(t/is (nil? (mtx/run! instance :id :x :inc 1 :labels ["only-one"])))))
(t/deftest run-fails-loudly-without-metrics-instance
;; A missing or invalid instance is a wiring bug: it must fail on every
;; invocation instead of silently dropping the measurement. With
;; asserts enabled this is an AssertionError; with asserts disabled the
;; collector lookup (outside the recording guard) throws instead.
(t/is (thrown? Throwable (mtx/run! nil :id :x :inc 1)))
(t/is (thrown? Throwable (mtx/run! :not-metrics :id :x :inc 1))))
(t/deftest run-records-on-success
(let [registry (CollectorRegistry.)
collector (mtx/create-collector {::mdef/name "penpot_test_run"
::mdef/help "test helper"
::mdef/type :counter
::mdef/labels ["result"]
:app.metrics/registry registry})
instance (reify mtx/IMetrics
(get-collector [_ _] collector))]
(t/is (true? (mtx/run! instance :id :x :inc 1 :labels ["ok"])))))
(t/deftest instance-resolves-the-metrics-from-a-cfg
;; the resolver is a map read and nothing more: it hands back the very
;; instance, not a copy and not a wrapper
(let [metrics (ig/init-key :app.metrics/metrics {:default {}})]
(t/is (identical? metrics (mtx/instance {::mtx/metrics metrics})))))
(t/deftest instance-raises-on-a-cfg-without-metrics
;; A missing instance is a wiring bug, and the resolver is the one place
;; that says so: a module that resolves it at the top of a write sees the
;; failure before anything is persisted.
(let [cause (try
(mtx/instance {})
(catch Throwable e e))]
(t/is (some? cause))
(t/is (= :missing-metrics (:code (ex-data cause))))
(t/is (re-find #"::mtx/metrics" (:hint (ex-data cause))))))
(t/deftest definitions-schema-accepts-all-consumed-keys
(t/is (true? (valid-definitions?
{:test-timing
{::mdef/name "penpot_test_timing"
::mdef/help "test"
::mdef/type :histogram
::mdef/labels ["op"]
::mdef/buckets [5 10 25]}
:test-summary
{::mdef/name "penpot_test_summary"
::mdef/help "test"
::mdef/type :summary
::mdef/quantiles [[0.5 0.01]]
::mdef/max-age 60}}))))
(t/deftest definitions-schema-rejects-unknown-keys
;; A typo such as ::mdef/bucksets must fail at startup instead of
;; silently falling back to the default histogram buckets. The
;; definition map is closed, so unknown keys do not validate.
(t/is (false? (valid-definitions?
{:bad {::mdef/name "penpot_bad_metric"
::mdef/help "typo check"
::mdef/type :histogram
::mdef/bucksets [100]}}))))
(t/deftest create-sampler-reschedules-after-error
;; The docstring promise, tested once for both call sites: an unexpected error
;; on a single sample must not cancel the following runs. The first sample
;; runs immediately and throws; the next one must still be scheduled.
(let [calls (atom 0)
sampler (mtx/create-sampler 1000 (fn []
(swap! calls inc)
(throw (ex-info "boom" {}))))]
(try
(t/is (loop [i 0]
(cond (pos? @calls) true
(> i 200) false
:else (do (Thread/sleep 10) (recur (inc i)))))
"the first sample must run immediately")
(let [queue (.getQueue ^ScheduledThreadPoolExecutor sampler)]
(t/is (loop [i 0]
(cond (= 1 (.size queue)) true
(> i 200) false
:else (do (Thread/sleep 10) (recur (inc i)))))
"the next sample must be scheduled after the error"))
(finally
(px/shutdown-now sampler)))))
;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;
;; HISTOGRAM BUCKETS
;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;
(t/deftest histogram-bucket-tails-extend-past-7-5s
;; The sub-7.5s prefix stays identical, so p50/p90 resolution and the
;; history remain comparable; only the tail grows, per latency profile.
(t/is (= mtx/default-histogram-buckets
(subvec mtx/default-request-histogram-buckets 0 14)))
(t/is (= mtx/default-histogram-buckets
(subvec mtx/default-tasks-histogram-buckets 0 14)))
(t/is (= mtx/default-histogram-buckets
(subvec mtx/default-redis-histogram-buckets 0 14)))
(t/is (= [10000 15000 30000 60000]
(subvec mtx/default-request-histogram-buckets 14)))
(t/is (= [10000 15000 30000 60000 120000 300000]
(subvec mtx/default-tasks-histogram-buckets 14)))
(t/is (= [10000]
(subvec mtx/default-redis-histogram-buckets 14))))
(t/deftest default-metrics-wire-bucket-tails-per-profile
;; Requests and waits cover the 30s/60s CLIMIT timeouts, tasks run
;; until done (300s postgres statement timeout), Redis only needs the
;; pathological case covered.
(doseq [id [:rpc-main-timing :rpc-management-timing :rpc-climit-timing
:audit-http-handler-timing :http-server-dispatch-timing
:update-file-validation-timing]]
(t/is (= mtx/default-request-histogram-buckets
(get-in main/default-metrics [id ::mdef/buckets]))
(str "request buckets on " id)))
(t/is (= mtx/default-tasks-histogram-buckets
(get-in main/default-metrics [:tasks-timing ::mdef/buckets])))
(t/is (= mtx/default-redis-histogram-buckets
(get-in main/default-metrics [:redis-eval-timing ::mdef/buckets]))))
(defn- bucket-value
"Cumulative count of the `le` bucket of a histogram, read from the
registry. Nil when that boundary does not exist."
[metrics mname label-names label-values le]
(.getSampleValue ^CollectorRegistry (mtx/get-registry metrics)
(str mname "_bucket")
(into-array String (conj (vec label-names) "le"))
(into-array String (conj (vec label-values) le))))
(t/deftest histogram-tails-are-registered
;; A 9s observation must land in the new tail instead of piling up in
;; +Inf: every histogram used to stop at 7500.
(let [metrics (ig/init-key :app.metrics/metrics {:default main/default-metrics})]
(mtx/run! metrics :id :rpc-main-timing :val 9000 :labels (into-array String ["update-file"]))
(t/is (= 0.0 (bucket-value metrics "penpot_rpc_main_timing" ["name"] ["update-file"] "7500.0")))
(t/is (= 1.0 (bucket-value metrics "penpot_rpc_main_timing" ["name"] ["update-file"] "10000.0")))
(t/is (nil? (bucket-value metrics "penpot_rpc_main_timing" ["name"] ["update-file"] "120000.0")))
(mtx/run! metrics :id :tasks-timing :val 200000 :labels (into-array String ["file-gc"]))
(t/is (= 0.0 (bucket-value metrics "penpot_tasks_timing" ["name"] ["file-gc"] "60000.0")))
(t/is (= 1.0 (bucket-value metrics "penpot_tasks_timing" ["name"] ["file-gc"] "300000.0")))
(mtx/run! metrics :id :redis-eval-timing :val 9000 :labels (into-array String ["claim"]))
(t/is (= 1.0 (bucket-value metrics "penpot_redis_eval_timing" ["name"] ["claim"] "10000.0")))
(t/is (nil? (bucket-value metrics "penpot_redis_eval_timing" ["name"] ["claim"] "15000.0")))
(mtx/run! metrics :id :http-server-dispatch-timing :val 45000)
(t/is (= 1.0 (bucket-value metrics "penpot_http_server_dispatch_timing" [] [] "60000.0")))
(mtx/run! metrics :id :update-file-validation-timing :val 9000 :labels (into-array String ["validate-affected"]))
(t/is (= 0.0 (bucket-value metrics "penpot_rpc_update_file_validation_timing" ["step"] ["validate-affected"] "7500.0")))
(t/is (= 1.0 (bucket-value metrics "penpot_rpc_update_file_validation_timing" ["step"] ["validate-affected"] "10000.0")))))