🐛 Stop oversized audit events from wedging the archive queue (#12252)

* 🐛 Stop the export-shapes modal event from dumping all exports

The `:export-shapes` modal event carried the full `:exports` vector,
each export embedding its shape (path data, geometry, text content).
One event reached 1.7 MB, which made the audit archive cron POST a
chunk past the proxy body limit and wedge the queue.

Build a compact body for that modal instead: total exports, distinct
shapes and one count per export type, plus the page name. Other modals
keep their props unchanged.

Move the modal `:origin` prop to `::ev/origin` so `make-proto-event`
records it on the event context as `:event-origin`; the UI still reads
the plain prop from the raw state.

Add tests for the summary and for the modal origin.

AI-assisted-by: deepseek-v4.1-flash

* 🐛 Bound exception messages in reports and audit events

A frontend crash whose message embeds a whole payload (a serialized
file) produced a 9.4 MB audit event: the message was repeated in the
`:hint` prop, in the report context and in the stack trace. A single
event that big wedged the audit archive queue.

Bound exception messages at the source: `get-hint` clamps to
`max-message-length` (1000 chars), and the CLJS `format-throwable`
clamps the message line of the stack trace and honors `:trace-length`
(parity with the CLJ version). `report-context` now prints `get-hint`
instead of the raw `:hint` from `ex-data`.

Fix `first-line` on the JVM: `cuerdas/index-of` returns nil when the
substring is missing and `(pos? nil)` throws there (it is false in
CLJS), so single-line messages crashed the backend path.

AI-assisted-by: deepseek-v4.1-flash
This commit is contained in:
Andrey Antukh 2026-10-15 10:19:26 +02:00 committed by GitHub
parent 2cdb575712
commit c74d415ddd
No known key found for this signature in database
GPG Key ID: B5690EEEBB952194
11 changed files with 193 additions and 12 deletions

View File

@ -260,6 +260,8 @@ Nexus dispatches on `:type`: `"telemetry-events"` batches are coerced and insert
Nexus is the long-term store. Every 5 min the `:audit-log-archive` cron takes 128-row chunks of unarchived rows (`FOR UPDATE SKIP LOCKED`, ordered by `created_at`), POSTs them as transit `{:events [...]}` with `x-shared-key: "nexus <key>"` (`:nexus-shared-key`, or derived from the instance secret) and `origin` = public-uri, and marks `archived_at = now()` **only on HTTP 204**, in the same transaction. Anything else is retried next run; flag on but no URI raises `:task-not-configured`. It loops with 100 ms pauses until empty.
A chunk is **one POST** and the task advances only on 204, so a single oversized event wedges the whole queue: a crash report whose message embeds a whole payload (a serialized file, for example) can push the request past the proxy body limit and the rejection blocks every later event until it is pruned by hand. Frontend crash reports are therefore size-bounded at the source (`mem:frontend/routing-app-shell-subtleties`): `app.common.exceptions/get-hint` and the CLJS `format-throwable` clamp exception messages (`max-message-length`).
On the other side, Nexus checks `origin` against its allowlist (403 if not allowed), coerces the events, and inserts them into its own `audit_log` (partitioned by `received_at`, with an incrementing sequence number and `source`). Watch the rename: Penpot's `created-at` is stored as **`received-at`** in Nexus; Nexus's `created-at` is when it was created there. `tracked-at` keeps the origin time. Telemetry batches arriving at `telemetry.penpot.app` land in the same table through the telemetry endpoint above.
Concurrent runs are safe: rows are locked with `FOR UPDATE SKIP LOCKED` inside the same transaction that sends and marks them, so two archivers running at once each take different rows. Only rows Nexus acknowledges (HTTP 204) get marked; anything else is retried on the next run.

View File

@ -9,3 +9,4 @@ Behaviors confirmed against the language/stdlib — do not re-derive from assump
- Valid: `(defn ^:async f)`, `(defn- ^:async f)`, `(^:async fn [] …)` (the latter is what stock `t/async` generates itself).
- `^:async` fns never throw synchronously (rejected promises instead); `try/catch/finally` supported; continuations are microtasks, timers and RxJS schedulers are macrotasks (FIFO).
- `!` suffix allowed cases (only exceptions to the no-new-`!` rule in `mem:clojure/design-rules`): mutating public `app.db` API (`insert!`, `update!`, `delete!`, `run!`, `tx-run!`, `exec!`, ...) and fns whose contract is to work over transients (stdlib `conj!`, `assoc!`, `dissoc!`, `disj!`, `persistent!` and custom helpers over them); any further case must be registered here with justification before use.
- `cuerdas.core/index-of` returns `nil` (not `-1`) when the substring is absent, like `clojure.string/index-of`. `(pos? nil)` **throws on the JVM** but evaluates to `false` in CLJS (JS coercion), so `(if (pos? (str/index-of s "\n")) …)` works in the browser and crashes the backend. Guard with `some?` before `pos?` (this was `app.common.exceptions/first-line`).

View File

@ -16,6 +16,7 @@
- `app.main.errors/submit-report` is governed by a dedup governor: each report carries a fingerprint (`report-name|type|code|hint|first stack frame`; the report name is part of it so a handled report never coalesces with an unhandled/exception-page one), the first occurrence is always emitted, repeats within 2 minutes are counted and included in the next emitted report as `:occurrences`, and the fingerprint cache is bounded (first-inserted entry evicted, FIFO, via `:order` queue) so memory stays fixed. It applies to `handled-exception`, `unhandled-exception` and `exception-page`; a report without an exception cause is ignored and does not consume a reservation.
- Errors caused by the environment (`environment-error-types`: `:network`, `:offline`, `:bad-gateway`, `:service-unavailable`, `:nitrate-unavailable`, `:nitrate-not-configured`) are not application defects: they are reported as audit-only `handled-exception` (never `unhandled-exception`/`exception-page`, so they skip internal reports and alerts), with a compact report and a fingerprint that drops the stack frame. `:offline` has its own handler and no longer falls through to `:default`; `:network`/`:offline` show the `errors.connection-error` toast.
- `generate-report` accepts an explicit `{:format :compact|:full}` (default `:full`) chosen by its caller (`flash`, `exception-section*`): `:compact` keeps the context header plus type/code/uri, and skips the stack, the `ex-data` dump and the last-events list. It is total: if formatting fails it returns a minimal fallback string instead of nil, so an already reserved emission is never dropped.
- Error messages are bounded at the source: `app.common.exceptions/get-hint` clamps to `max-message-length` (1000 chars) and the CLJS `format-throwable` clamps the message line of the stack trace and honors `:trace-length`. A message can embed a whole payload (a serialized file, for example) and reach megabytes; the bound keeps the audit `:hint` prop and the `:report` string small. The `Context: Hint:` header in `report-context` prints `get-hint` (not the raw `:hint` from `ex-data`) for the same reason.
- `flash` runs its whole body (report pipeline first, toast after) inside a single `ts/schedule` callback: nothing executes synchronously on the error handler's stack. The report is reserved before being generated, so suppressed occurrences do not pay the `generate-report` cost; a reporting or notification failure is logged to the console and never propagates, and the toast is still attempted. `flash` returns a total promise (never rejects) resolving with the generated report, or nil when nothing is emitted, once the callback completes; production callers ignore it, tests await it. `flash` derives only the payload format from the cause (`environment-error?` → `:compact`); the audit event name is the canonical one requested by `:type` (`handled-exception`/`unhandled-exception`) and is never reclassified, because external tools filter on those names. `exception-section*` picks `handled-exception`/`exception-page` explicitly per cause; `flash-persistence` only adds the toast hint.
## Store and websocket

View File

@ -29,6 +29,22 @@
(def ^:dynamic *data-length* 8)
(def ^:dynamic *data-level* 8)
(def max-message-length
"Upper bound, in characters, for an exception message surfaced as a hint or
embedded in a formatted stack trace. A message can carry a whole payload (a
serialized file, for instance) and grow to megabytes; only the head helps to
identify the failure, and the rest is noise that bloats reports and the audit
events built from them."
1000)
(defn- truncate
"Truncates a string to at most `n` characters, appending an ellipsis when it
had to cut. Values that are not strings pass through unchanged."
[s n]
(if (and (string? s) (> (count s) n))
(str (subs s 0 n) "...")
s))
(defmacro error
[& {:keys [type hint] :as params}]
`(ex-info ~(or hint (name type))
@ -243,7 +259,7 @@
:cljs
(defn format-throwable
[cause & {:as opts}]
[cause & {:keys [trace-length]}]
(with-out-str
(when-let [exdata (ex-data cause)]
(when-let [hint (or (get exdata :hint)
@ -251,7 +267,7 @@
(when (str/index-of hint "\n")
(println "Hint:")
(println "--------------------")
(println hint)
(println (truncate hint max-message-length))
(println)))
(when-let [explain (get exdata ::sm/explain)]
@ -272,14 +288,20 @@
(println))
(when-let [trace (.-stack cause)]
(println "Trace:")
(println "--------------------")
(println (.-stack cause))))))
(let [lines (str/lines trace)
head (truncate (first lines) max-message-length)
tail (rest lines)]
(println "Trace:")
(println "--------------------")
(when head
(println head))
(doseq [line (if trace-length (take trace-length tail) tail)]
(println line)))))))
(defn first-line
[s]
(let [break-index (str/index-of s "\n")]
(if (pos? break-index)
(if (and (some? break-index) (pos? break-index))
(subs s 0 break-index)
s)))
@ -308,5 +330,6 @@
(defn get-hint
[cause]
(or (some-> (ex-data cause) (get :hint) first-line)
(some-> (ex-message cause) first-line)))
(truncate (or (some-> (ex-data cause) (get :hint) first-line)
(some-> (ex-message cause) first-line))
max-message-length))

View File

@ -0,0 +1,57 @@
;; 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 common-tests.exceptions-test
"Exception message bounding in `app.common.exceptions`.
A message can carry a whole payload (a serialized file, for instance) and
grow to megabytes. `get-hint` and the CLJS `format-throwable` keep a bounded
head so neither the audit `:hint` prop nor the report can explode."
(:require
#?(:cljs [cuerdas.core :as str])
[app.common.exceptions :as ex]
[clojure.test :as t]))
(defn- huge-string
[n]
(apply str (repeat n "x")))
(t/deftest first-line-keeps-a-single-line-message-intact-test
(t/is (= "boom" (ex/first-line "boom")))
(t/is (= "boom" (ex/first-line "boom\nrest of the message"))))
(t/deftest get-hint-returns-the-first-line-test
(t/is (= "boom" (ex/get-hint (ex-info "boom\nsecond line" {})))))
(t/deftest get-hint-prefers-the-ex-data-hint-test
(t/is (= "from-data" (ex/get-hint (ex-info "from-message" {:hint "from-data"})))))
(t/deftest get-hint-bounds-a-huge-message-test
(let [huge (huge-string (* 4 ex/max-message-length))
hint (ex/get-hint (ex-info huge {}))]
(t/is (string? hint))
(t/is (<= (count hint) (+ ex/max-message-length 3)))
(t/is (= (subs hint 0 32) (subs huge 0 32)))))
(t/deftest get-hint-bounds-a-huge-ex-data-hint-test
(let [huge (huge-string (* 4 ex/max-message-length))
hint (ex/get-hint (ex-info "short" {:hint huge}))]
(t/is (<= (count hint) (+ ex/max-message-length 3)))
(t/is (= (subs hint 0 32) (subs huge 0 32)))))
#?(:cljs
(t/deftest format-throwable-bounds-a-huge-trace-message-test
(let [huge (huge-string (* 4 ex/max-message-length))
out (ex/format-throwable (ex-info huge {}))
msg (some #(when (str/includes? % (subs huge 0 16)) %) (str/lines out))]
(t/is (some? msg))
(t/is (<= (count msg) (+ ex/max-message-length 16))))))
#?(:cljs
(t/deftest format-throwable-honors-trace-length-test
(let [full (ex/format-throwable (ex-info "boom" {}))
short (ex/format-throwable (ex-info "boom" {}) {:trace-length 1})]
(t/is (< (count (str/lines short)) (count (str/lines full)))))))

View File

@ -16,6 +16,7 @@
[common-tests.buffer-test]
[common-tests.colors-test]
[common-tests.data-test]
[common-tests.exceptions-test]
[common-tests.files-builder-test]
[common-tests.files-changes-test]
[common-tests.files-migrations-0025-test]
@ -118,6 +119,7 @@
'common-tests.buffer-test
'common-tests.colors-test
'common-tests.data-test
'common-tests.exceptions-test
'common-tests.files-builder-test
'common-tests.files-changes-test
'common-tests.files-migrations-0025-test

View File

@ -17,6 +17,19 @@
;; TODO: rename `:type` to `:name`
(defn- summarize-export-shapes
"Builds a compact body for the `:export-shapes` modal event. We know the
shape of these props here, so instead of dumping every export (each one
carrying its full shape, which can be megabytes) we emit counters: total
exports, distinct shapes and one count per export type."
[props]
(let [exports (:exports props)]
(merge
{:page (:name props)
:num-shapes (count (distinct (map :object-id exports)))
:num-exports (count exports)}
(frequencies (map :type exports)))))
(defn show
([props]
(show (uuid/next) (:type props) props))
@ -26,9 +39,17 @@
(ptk/reify ::show-modal
ev/Event
(-data [_]
(-> props
(dissoc :type)
(assoc :name type)))
(let [origin (:origin props)
data (if (= type :export-shapes)
(assoc (summarize-export-shapes props) :name type)
(-> props
(dissoc :type)
(assoc :name type)))]
;; The origin is event metadata, not a prop: sending it as
;; ::ev/origin makes `make-proto-event` put it on the event context
;; (`:event-origin`); as a plain `:origin` it only stayed as a prop.
(cond-> (dissoc data :origin)
(some? origin) (assoc ::ev/origin origin))))
ptk/UpdateEvent
(update [_ state]

View File

@ -192,7 +192,7 @@
(println "Context:")
(println "--------------------")
(println "Timestamp:" (ct/format-inst (ct/now) :rfc1123))
(println "Hint: " (or (:hint data) (ex-message cause) "--"))
(println "Hint: " (or (ex/get-hint cause) "--"))
(println "Prof ID: " (str (or profile-id "--")))
(println "Team ID: " (str (or team-id "--")))
(when-let [file-id (or (:file-id data) file-id)]

View File

@ -0,0 +1,55 @@
;; 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 frontend-tests.data.modal-test
(:require
[app.common.uuid :as uuid]
[app.main.data.event :as ev]
[app.main.data.modal :as modal]
[cljs.test :as t :include-macros true]))
(t/deftest export-shapes-modal-event-carries-a-summary
(let [shape-a (uuid/next)
shape-b (uuid/next)
exports [{:object-id shape-a :type :png}
{:object-id shape-a :type :svg}
{:object-id shape-b :type :png}]
event (modal/show :export-shapes
{:exports exports
:origin "workspace:sidebar"
:name "Page 1"})
data (ev/-data event)]
(t/testing "the raw exports never leak into the event"
(t/is (not (contains? data :exports))))
(t/testing "the event carries counters instead"
(t/is (= 3 (:num-exports data)))
(t/is (= 2 (:num-shapes data)))
(t/is (= 2 (:png data)))
(t/is (= 1 (:svg data))))
(t/testing "the modal context is preserved"
(t/is (= "Page 1" (:page data)))
(t/is (= :export-shapes (:name data))))
(t/testing "origin is emitted as event metadata, not as a prop"
(t/is (= "workspace:sidebar" (::ev/origin data)))
(t/is (not (contains? data :origin))))))
(t/deftest other-modals-keep-their-props
(let [event (modal/show :some-modal {:foo "bar" :items [1 2 3]})
data (ev/-data event)]
(t/is (= "bar" (:foo data)))
(t/is (= [1 2 3] (:items data)))
(t/is (= :some-modal (:name data)))))
(t/deftest modal-origin-becomes-event-metadata
(let [event (modal/show :some-modal {:foo "bar" :origin "dashboard"})
data (ev/-data event)]
(t/is (= "dashboard" (::ev/origin data)))
(t/is (not (contains? data :origin)))
(t/is (= "bar" (:foo data)))))

View File

@ -191,6 +191,23 @@
;; evaluates to a promise, so the body must settle one.
(await (async/settle))))))
(t/deftest ^:async generate-report-bounds-a-huge-exception-message
;; A message can embed a whole payload (a serialized file) and reach
;; megabytes. The report must keep a bounded head in both the context and
;; the trace, so the audit event built from it can never bloat.
(await
(mock/with-mocks*
{st/format-last-events (mock/stub (fn [& _] "(stub last events)"))
rt/get-current-href (constantly "https://penpot.example.com/#/workspace")}
(let [huge (apply str (repeat 200000 "z"))
report (errors/generate-report (js/Error. huge))]
(t/is (string? report))
(t/is (< (count report) 50000))
(t/is (not (str/includes? report (subs huge 0 1500))))
;; Trailing settle: the body is synchronous, but `with-mocks*`
;; evaluates to a promise, so the body must settle one.
(await (async/settle))))))
(t/deftest ^:async connectivity-handlers-report-governed-compact-audit-events
;; Scenario: a network failure and an offline status through the global
;; handler. Each is reported as a governed compact audit event plus its

View File

@ -14,6 +14,7 @@
[frontend-tests.data.event-test]
[frontend-tests.data.exports-assets-test]
[frontend-tests.data.fix-deleted-fonts-test]
[frontend-tests.data.modal-test]
[frontend-tests.data.nitrate-test]
[frontend-tests.data.persistence-retry-test]
[frontend-tests.data.persistence-test]
@ -157,6 +158,7 @@
'frontend-tests.data.dashboard-test
'frontend-tests.data.event-test
'frontend-tests.data.fix-deleted-fonts-test
'frontend-tests.data.modal-test
'frontend-tests.data.nitrate-test
'frontend-tests.data.persistence-retry-test
'frontend-tests.data.persistence-test