mirror of
https://github.com/penpot/penpot.git
synced 2026-10-28 21:40:34 +00:00
🐛 Make the audit events concurrency limit per profile
The command declared its limit as a plain keyword next to `::climit/key-fn`, metadata that `climit/wrap` does not read: it takes the key only from the positional `key-fn` of the vector form. The limit was a single shared one, so when one call got stuck it held the only permit and every audit batch of that instance was rejected with 429 from then on. The test builds the limiter from the command metadata and checks that two profiles end up with different limiters. AI-assisted-by: deepseek-v4.1-flash
This commit is contained in:
parent
9b8dde2954
commit
18705f2d00
@ -8,6 +8,9 @@
|
||||
- The wrapper stack does auth before params validation, then auditing/rate/concurrency/metrics/retry/condition handling, with DB transaction handling inside that stack. `::db/transaction` metadata controls transaction wrapping.
|
||||
- Params with `::sm/params` are decoded/conformed through the JSON transformer and successful IObj results get `:encode/json` metadata. Legacy spec conforming only applies when no Malli params schema exists.
|
||||
- Nil RPC bodies become HTTP 204 unless explicit status metadata is present. Stream bodies default to `application/octet-stream` when no content type is set.
|
||||
- `::climit/id` is either a plain keyword, which gives one shared limiter per process, or the vector form `[[id key-fn]]`, which gives one limiter per key. `climit/wrap` takes the key only from that positional `key-fn` (`climit/get-limits` maps a plain keyword to a single-element vector), so `::climit/key-fn` is metadata that nothing reads: a command declaring `::climit/id :x/by-profile` next to it ends up with a single shared limiter, and the missing key is visible in the `app.rpc.climit` log lines, whose `id` carries no key suffix. That is what happened to `push-audit-events`, the last user of the dead metadata, from `a5c6d78ee5` (2024-01-27, "fix some fundamental bugs on climit module", which moved the key to the vector form without updating it) until it was fixed; nothing declares `::climit/key-fn` any more, so keep using the vector form for anything that must be per profile.
|
||||
- The `penpot_rpc_climit_queue`/`permits` gauges carry only the limiter name, never the key, so every per-profile limiter of the same name collapses into one series and the last call wins: a per-key pile-up is invisible there and a healthy looking `cola=0` proves nothing. A stuck limiter does show up in `penpot_rpc_climit_timing_count` (the acquired path), which is a counter: compare the same limiter name across instances and the stuck one reads 0 acquisitions while its peer reads thousands.
|
||||
- Nothing in the limiter path has a timeout unless the config sets one, and `psm/acquire` then calls `Semaphore.acquire`, which parks the calling thread forever. That is what turns a wait into a lost worker thread: a permanently parked thread still counts as in-system for every outer limiter of its chain, so the outermost one (the method's own by-profile limiter) stops granting permits and answers 429 to everything. A limiter without `:queue` in the config gets an unlimited queue and therefore never rejects: its pile-up is silent, with no 429 and no log line except the WARN `enqueued`/`acquired` lines of the keyed id, and its per-key nature is invisible in the metrics. Note that a request whose profile limit is exhausted parks *inside* the outer limiter while holding its permit, and handlers that assign `::climit/id` dynamically (media, profile) re-acquire the same keyed limiters, so a chain of such waits can close into a cycle that no timeout ever breaks.
|
||||
|
||||
## DB helpers
|
||||
|
||||
|
||||
@ -157,8 +157,7 @@
|
||||
[:events [:vector schema:frontend-event]]])
|
||||
|
||||
(sv/defmethod ::push-audit-events
|
||||
{::climit/id :submit-audit-events/by-profile
|
||||
::climit/key-fn ::rpc/profile-id
|
||||
{::climit/id [[:submit-audit-events/by-profile ::rpc/profile-id]]
|
||||
::sm/params schema:push-audit-events
|
||||
::audit/skip true
|
||||
::doc/skip true
|
||||
|
||||
@ -12,10 +12,13 @@
|
||||
[app.config :as cf]
|
||||
[app.db :as db]
|
||||
[app.loggers.audit :as audit]
|
||||
[app.metrics :as mtx]
|
||||
[app.rpc :as-alias rpc]
|
||||
[app.rpc.climit :as climit]
|
||||
[app.util.services :as sv]
|
||||
[backend-tests.helpers :as th]
|
||||
[clojure.test :as t]
|
||||
[integrant.core :as ig]
|
||||
[yetti.request]))
|
||||
|
||||
(t/use-fixtures :once th/state-init)
|
||||
@ -35,6 +38,62 @@
|
||||
"x-forwarded-for" "127.0.0.44"
|
||||
"x-real-ip" "127.0.0.43"))))
|
||||
|
||||
(t/deftest push-audit-events-limit-is-keyed-by-profile
|
||||
;; Regression guard. This command asks for a per-profile limit, but it used
|
||||
;; to declare it as a plain keyword next to `::climit/key-fn`, metadata that
|
||||
;; `climit/wrap` does not read: it takes the key only from the positional
|
||||
;; `key-fn` of the vector form. That silently turned the limit into a single
|
||||
;; shared one, so one stuck call ended up rejecting the audit batches of
|
||||
;; every profile on the instance. Two profiles must not share a limiter.
|
||||
(let [config (doto (java.io.File/createTempFile "climit" ".edn")
|
||||
(.deleteOnExit))
|
||||
_ (spit config "{:submit-audit-events/by-profile {:permits 1 :queue 1}}")
|
||||
|
||||
;; The limiter only uses the metrics instance to measure, and with a
|
||||
;; stub collector every `run!` is a no-op.
|
||||
metrics (reify mtx/IMetrics
|
||||
(get-handler [_] nil)
|
||||
(get-collector [_ _] nil)
|
||||
(get-registry [_] nil))
|
||||
|
||||
climit (ig/init-key ::rpc/climit
|
||||
{::climit/enabled true
|
||||
::climit/config (.getAbsolutePath config)
|
||||
::mtx/metrics metrics})
|
||||
|
||||
;; The metadata declared by the command itself, that is what the test
|
||||
;; has to cover.
|
||||
mdata (meta (ns-resolve 'app.rpc.commands.audit 'sm$push-audit-events))
|
||||
|
||||
gate (promise)
|
||||
entered (promise)
|
||||
calls (atom 0)
|
||||
handler (fn [_ _]
|
||||
(when (= 1 (swap! calls inc))
|
||||
(deliver entered true)
|
||||
@gate)
|
||||
:ok)
|
||||
wrapped (climit/wrap {::rpc/climit climit} handler mdata)
|
||||
call (fn [profile-id]
|
||||
(wrapped {::rpc/climit climit} {::rpc/profile-id profile-id}))
|
||||
pid-a (uuid/next)
|
||||
pid-b (uuid/next)
|
||||
holder (future (call pid-a))]
|
||||
|
||||
;; The first call stays inside the handler holding the only permit.
|
||||
(t/is (true? (deref entered 2000 false)))
|
||||
|
||||
;; Another call from the SAME profile shares the limiter, so it waits.
|
||||
(let [same (future (call pid-a))]
|
||||
(t/is (= :waiting (deref same 300 :waiting))))
|
||||
|
||||
;; A different profile owns a different limiter and is served right away.
|
||||
;; With the shared limiter (the bug) this one waits too and times out.
|
||||
(t/is (= :ok (deref (future (call pid-b)) 2000 :timeout)))
|
||||
|
||||
(deliver gate true)
|
||||
(t/is (= :ok (deref holder 2000 :timeout)))))
|
||||
|
||||
(t/deftest prepare-context-initiator-is-plain-string
|
||||
;; The initiator must always be a plain string, never a keyword: shared-key
|
||||
;; authenticated callers (exporter, admin-console) arrive as keywords on
|
||||
|
||||
Loading…
x
Reference in New Issue
Block a user