diff --git a/.serena/memories/frontend/routing-app-shell-subtleties.md b/.serena/memories/frontend/routing-app-shell-subtleties.md index a340fb310f..3408c98328 100644 --- a/.serena/memories/frontend/routing-app-shell-subtleties.md +++ b/.serena/memories/frontend/routing-app-shell-subtleties.md @@ -9,6 +9,9 @@ - The root app renders an exception page from `:exception` state before the normal error boundary. `rt/navigated` clears `:exception`. - Frontend error handling treats stale cross-build JS chunk failures specially: messages containing `$cljs$cst$` or `$cljs$core$I` plus undefined/null/not-a-function signatures trigger throttled reload. - Plugin-originated uncaught errors are identified through the plugin runtime hook and logged rather than turning into the global exception page. +- `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`. +- `generate-report` is total: if formatting fails it returns a minimal fallback string instead of nil, so an already reserved emission is never dropped. +- `flash` reserves the report before generating it, so suppressed occurrences do not pay the `generate-report` cost; the toast is unchanged. ## Store and websocket diff --git a/frontend/src/app/main/data/persistence.cljs b/frontend/src/app/main/data/persistence.cljs index ea97330efa..709a88a51f 100644 --- a/frontend/src/app/main/data/persistence.cljs +++ b/frontend/src/app/main/data/persistence.cljs @@ -128,7 +128,8 @@ :render-context-lost? (dm/get-in state [:render-state :lost])})] (errors/submit-report :event-name "handled-exception" :hint hint - :report (errors/generate-report cause)))))) + :report (errors/generate-report cause) + :cause cause))))) (defn- check-persistence [] diff --git a/frontend/src/app/main/errors.cljs b/frontend/src/app/main/errors.cljs index 670dae2cb0..460dd59e12 100644 --- a/frontend/src/app/main/errors.cljs +++ b/frontend/src/app/main/errors.cljs @@ -156,21 +156,159 @@ (println "--------------------") (println (st/format-last-events)) (println))) - (catch :default cause - (.error js/console "error on generating report" cause) - nil))) + (catch :default err + (.error js/console "error on generating report" err) + ;; Keep this function total: `flash` reserves a report slot before + ;; generating it, so returning nil here would consume the slot + ;; without emitting anything. + (str "Report generation failed: " (or (ex-message err) "--") + "\nOriginal hint: " (or (ex/get-hint cause) "--"))))) + +;; --- Error report governor +;; +;; Bounds the volume of reports emitted by a single browser session. Each +;; report carries a fingerprint; the first occurrence is always emitted and +;; repeated occurrences of the same fingerprint within `report-window-ms` +;; are counted but not emitted. The next emitted report carries the number +;; of occurrences since the previous one as `:occurrences`. The report name +;; is part of the fingerprint, so a handled report never coalesces with an +;; unhandled/exception-page report of the same cause. +;; +;; The fingerprint cache is bounded: when it is full, the fingerprint +;; inserted first is evicted (FIFO order), so memory cannot grow without +;; limit. + +(def report-window-ms + "Minimum time between two reports with the same fingerprint." + (* 2 60 1000)) + +(def max-tracked-fingerprints + "Maximum number of fingerprints kept in the governor cache." + 2000) + +(defn initial-report-state + [] + {:entries {} + :order #queue []}) + +(defonce ^:private report-governor + (atom (initial-report-state))) + +(defn reset-report-governor! + "Testing helper: clear the governor state." + [] + (reset! report-governor (initial-report-state))) + +(defn- label + [v] + (cond + (nil? v) "" + (keyword? v) (name v) + (string? v) v + :else (str v))) + +(defn error-fingerprint + "Stable identity of an error, used to group repeated reports. + + The report name is part of the identity, so a `handled-exception` report + never coalesces with an `unhandled-exception`/`exception-page` report of + the same cause (those two do reach the error reports and alerts)." + [event-name cause] + (let [data (ex-data cause) + ftype (or (:type data) :unknown) + code (or (:code data) :unknown) + hint (or (ex/get-hint cause) "") + ;; A JS stack string starts with "Error: "; the first + ;; actual frame is the second line. + frame (or (some-> (.-stack cause) (str/lines) (second)) "")] + (str (label event-name) "|" (label ftype) "|" (label code) "|" + (str/prune hint 120) "|" (str/prune frame 120)))) + +(defn fallback-fingerprint + "Fingerprint for reports submitted without a `cause` (e.g. the exception + page or a stalled save)." + [event-name hint] + (str (label event-name) "|" (str/prune (or hint "") 120))) + +(defn- evict-oldest + "Drops the fingerprint inserted first. `:order` mirrors the insertion + order of `:entries`, so this is O(1)." + [state] + (let [fingerprint (peek (:order state))] + (-> state + (update :entries dissoc fingerprint) + (update :order pop)))) + +(defn reserve-report* + "Pure decision step of the report governor. + + Given the governor `state`, an error `fingerprint` and the current time in + milliseconds, returns the next governor state with this occurrence's + decision attached: `::emit` tells whether it must be emitted and + `::occurrences` carries the counter (present only when `::emit` is true)." + [state fingerprint now] + (let [entry (get-in state [:entries fingerprint]) + emit? (or (nil? entry) + (>= (- now (:emitted-at entry)) report-window-ms)) + pending (or (:pending entry) 0)] + (cond + ;; New fingerprint: insert it, evicting the oldest when the cache + ;; is full. + (and emit? (nil? entry)) + (let [state (cond-> state + (>= (count (:entries state)) max-tracked-fingerprints) + (evict-oldest))] + (-> state + (assoc-in [:entries fingerprint] {:emitted-at now :pending 0}) + (update :order conj fingerprint) + (assoc ::emit true) + (assoc ::occurrences (inc pending)))) + + ;; Known fingerprint re-emitted after the window: keep its position. + emit? + (-> state + (assoc-in [:entries fingerprint] {:emitted-at now :pending 0}) + (assoc ::emit true) + (assoc ::occurrences (inc pending))) + + ;; Suppressed occurrence: only the counter moves. + :else + (-> state + (update-in [:entries fingerprint :pending] inc) + (assoc ::emit false) + (dissoc ::occurrences))))) + +(defn reserve-report! + "Reserve a slot for a report. Returns the updated governor state, whose + `::emit`/`::occurrences` describe the decision for this occurrence." + [fingerprint now] + (swap! report-governor reserve-report* fingerprint now)) + +(defn- emit-report! + "Emit the audit event for a report that is already reserved by the + governor." + [event-name report hint occurrences] + (st/emit! + (ev/event {::ev/name event-name + :hint hint + :href (rt/get-current-href) + :report report + :occurrences occurrences}))) (defn submit-report - "Report the error report to the audit log subsystem" - [& {:keys [event-name report hint] :or {event-name "unhandled-exception"}}] + "Report the error report to the audit log subsystem, subject to the + report governor." + [& {:keys [event-name report hint cause] + :or {event-name "unhandled-exception"}}] (when (and (not (str/empty? hint)) (string? report) (string? event-name)) - (st/emit! - (ev/event {::ev/name event-name - :hint hint - :href (rt/get-current-href) - :report report})))) + (let [state (reserve-report! (if (ex/exception? cause) + (error-fingerprint event-name cause) + (fallback-fingerprint event-name hint)) + (inst-ms (ct/now)))] + (when (::emit state) + (emit-report! event-name report hint (::occurrences state)))))) (defn- download-report! [report event] @@ -184,6 +322,9 @@ "Show error notification banner and emit error report. A nil timeout keeps the notification visible until dismissed or replaced. + The report is reserved before being generated, so repeated errors that + fall inside the governor window do not pay the report-building cost. + The notification is scheduled asynchronously (via tm/schedule) to avoid pushing a new event into the potok store while the store's own error-handling pipeline is still on the call stack. Emitting @@ -192,15 +333,21 @@ (RangeError: Maximum call stack size exceeded)." [& {:keys [type hint cause timeout report-link?] :or {type :handled timeout 5000}}] - (let [report (when (ex/exception? cause) (generate-report cause))] - (when report - (when-let [event-name (case type - :handled "handled-exception" - :unhandled "unhandled-exception" - :silent nil)] - (submit-report :event-name event-name - :report report - :hint (ex/get-hint cause)))) + (let [report (when (ex/exception? cause) + (when-let [event-name (case type + :handled "handled-exception" + :unhandled "unhandled-exception" + :silent nil)] + (let [report-hint (ex/get-hint cause)] + (when (and (string? report-hint) (not (str/empty? report-hint))) + (let [state (reserve-report! (error-fingerprint event-name cause) (inst-ms (ct/now)))] + (when (::emit state) + (let [generated (generate-report cause)] + (emit-report! event-name + generated + report-hint + (::occurrences state)) + generated)))))))] (ts/schedule #(st/emit! diff --git a/frontend/src/app/main/ui/static.cljs b/frontend/src/app/main/ui/static.cljs index 7dbe18906e..c9a78d5bcd 100644 --- a/frontend/src/app/main/ui/static.cljs +++ b/frontend/src/app/main/ui/static.cljs @@ -565,7 +565,8 @@ (not (contains? #{:not-found :authentication} type))) (errors/submit-report :event-name "exception-page" :report report - :hint (ex/get-hint cause)))) + :hint (ex/get-hint cause) + :cause cause))) (case type :not-found diff --git a/frontend/test/frontend_tests/main_errors_test.cljs b/frontend/test/frontend_tests/main_errors_test.cljs index 081fadffd3..64b274e797 100644 --- a/frontend/test/frontend_tests/main_errors_test.cljs +++ b/frontend/test/frontend_tests/main_errors_test.cljs @@ -31,6 +31,7 @@ [app.util.webapi :as wapi] [beicon.v2.core :as rx] [cljs.test :as t :include-macros true] + [cuerdas.core :as str] [frontend-tests.helpers.mock :as mock] [potok.v2.core :as ptk])) @@ -97,6 +98,240 @@ data (errors/exception->error-data err)] (t/is (= "fallback message" (:hint data)))))) +;; --------------------------------------------------------------------------- +;; Error report governor +;; +;; The governor deduplicates report by fingerprint: the first occurrence is +;; always emitted, repeats inside a 2 minute window are counted, and the +;; fingerprint cache is bounded (the oldest entry is evicted when full). +;; --------------------------------------------------------------------------- + +(t/use-fixtures :each {:before #(errors/reset-report-governor!)}) + +(defn- error-cause + [& {:keys [type code hint]}] + (ex-info (or hint "boom") + (cond-> {} + (some? type) (assoc :type type) + (some? code) (assoc :code code) + (some? hint) (assoc :hint hint)))) + +(defn- capture-reports! + "Run `f` capturing the events emitted through `st/emit!`." + [f] + (let [events (atom [])] + (with-redefs [st/emit! (mock/stub (fn [& emitted] (swap! events into emitted))) + rt/get-current-href (constantly "https://penpot.example.com/#/workspace")] + (f) + @events))) + +(t/deftest fingerprint-is-stable-for-equivalent-errors + (let [cause-a (error-cause :type :network :code :fetch-failed :hint "unable to perform fetch operation") + cause-b (error-cause :type :network :code :fetch-failed :hint "unable to perform fetch operation")] + (t/is (= (errors/error-fingerprint "handled-exception" cause-a) + (errors/error-fingerprint "handled-exception" cause-b))))) + +(t/deftest fingerprint-changes-with-error-identity + (let [base (error-cause :type :network :code :fetch-failed :hint "boom")] + (t/is (not= (errors/error-fingerprint "handled-exception" base) + (errors/error-fingerprint "handled-exception" + (error-cause :type :network :code :fetch-failed :hint "other")))) + (t/is (not= (errors/error-fingerprint "handled-exception" base) + (errors/error-fingerprint "handled-exception" + (error-cause :type :validation :code :fetch-failed :hint "boom")))) + (t/is (not= (errors/error-fingerprint "handled-exception" base) + (errors/error-fingerprint "handled-exception" + (error-cause :type :network :code :other :hint "boom")))))) + +(t/deftest fingerprint-includes-the-report-name + (let [cause (error-cause :type :network :hint "boom")] + (t/is (not= (errors/error-fingerprint "handled-exception" cause) + (errors/error-fingerprint "unhandled-exception" cause))) + (t/is (not= (errors/error-fingerprint "handled-exception" cause) + (errors/error-fingerprint "exception-page" cause))))) + +(t/deftest fingerprint-handles-missing-type-and-code + (let [fingerprint (errors/error-fingerprint "handled-exception" (js/Error. "plain failure"))] + (t/is (string? fingerprint)) + (t/is (str/starts-with? fingerprint "handled-exception|unknown|unknown|")))) + +(t/deftest fallback-fingerprint-is-stable-and-discriminating + (t/is (= (errors/fallback-fingerprint "exception-page" "boom") + (errors/fallback-fingerprint "exception-page" "boom"))) + (t/is (not= (errors/fallback-fingerprint "exception-page" "boom") + (errors/fallback-fingerprint "handled-exception" "boom"))) + (t/is (not= (errors/fallback-fingerprint "exception-page" "boom") + (errors/fallback-fingerprint "exception-page" "other")))) + +(t/deftest governor-emits-first-occurrence-and-suppresses-repeats + (let [d1 (errors/reserve-report* (errors/initial-report-state) "fp" 1000) + d2 (errors/reserve-report* d1 "fp" 2000) + d3 (errors/reserve-report* d2 "fp" 3000) + d4 (errors/reserve-report* d3 "fp" (+ 1000 errors/report-window-ms))] + (t/is (true? (::errors/emit d1))) + (t/is (= 1 (::errors/occurrences d1))) + (t/is (false? (::errors/emit d2))) + (t/is (nil? (::errors/occurrences d2))) + (t/is (false? (::errors/emit d3))) + (t/is (nil? (::errors/occurrences d3))) + (t/is (true? (::errors/emit d4))) + (t/is (= 3 (::errors/occurrences d4))))) + +(t/deftest governor-evicts-oldest-entry-when-cache-is-full + (let [base (reduce (fn [state i] + (errors/reserve-report* state (str "fp-" i) (* 1000 i))) + (errors/initial-report-state) + (range errors/max-tracked-fingerprints)) + state (errors/reserve-report* base + "fp-new" + (* 1000 errors/max-tracked-fingerprints))] + (t/is (= errors/max-tracked-fingerprints (count (:entries state)))) + (t/is (= errors/max-tracked-fingerprints (count (:order state)))) + (t/is (true? (::errors/emit state))) + (t/is (nil? (get-in state [:entries "fp-0"]))) + (t/is (= "fp-1" (peek (:order state)))) + (t/is (some? (get-in state [:entries "fp-new"]))))) + +(t/deftest governor-evicts-by-insertion-order-not-by-last-emission + (let [base (reduce (fn [state i] + (errors/reserve-report* state (str "fp-" i) (* 1000 i))) + (errors/initial-report-state) + (range errors/max-tracked-fingerprints)) + ;; fp-0 re-emits after the window, so its :emitted-at becomes the + ;; most recent one, but it keeps its insertion position. + re-emitted (errors/reserve-report* base + "fp-0" + (+ (* 1000 errors/max-tracked-fingerprints) + errors/report-window-ms)) + state (errors/reserve-report* re-emitted + "fp-new" + (+ (* 1000 errors/max-tracked-fingerprints) + errors/report-window-ms + 1000))] + (t/is (true? (::errors/emit state))) + ;; FIFO: the first inserted one goes, even though it was the last + ;; emitted and fp-1 is the oldest by :emitted-at. + (t/is (nil? (get-in state [:entries "fp-0"]))) + (t/is (some? (get-in state [:entries "fp-1"]))) + (t/is (= errors/max-tracked-fingerprints (count (:entries state)))) + (t/is (= errors/max-tracked-fingerprints (count (:order state)))))) + +(t/deftest submit-report-is-governed-and-reports-occurrences + (let [cause (error-cause :type :network :code :fetch-failed :hint "boom") + events (capture-reports! + (fn [] + (dotimes [_ 5] + (errors/submit-report :event-name "handled-exception" + :report "report" + :hint "boom" + :cause cause))))] + (t/is (= 1 (count events))) + (t/is (= 1 (:occurrences (deref (first events))))))) + +(t/deftest invalid-report-does-not-consume-a-reservation + (let [cause (error-cause :type :network :hint "boom") + events (capture-reports! + (fn [] + (errors/submit-report :event-name "handled-exception" + :report nil :hint "boom" :cause cause) + (errors/submit-report :event-name "handled-exception" + :report "report" :hint "boom" :cause cause)))] + (t/is (= 1 (count events))) + (t/is (= 1 (:occurrences (deref (first events))))))) + +(t/deftest governor-applies-to-every-report-name + (let [events (capture-reports! + (fn [] + (doseq [event-name ["handled-exception" "unhandled-exception" "exception-page"]] + (errors/submit-report :event-name event-name :report "report" :hint event-name) + (errors/submit-report :event-name event-name :report "report" :hint event-name))))] + (t/is (= 3 (count events))))) + +(t/deftest submit-report-without-cause-dedups-by-fallback-fingerprint + (let [events (capture-reports! + (fn [] + (errors/submit-report :event-name "exception-page" :report "report" :hint "boom") + (errors/submit-report :event-name "exception-page" :report "report" :hint "boom") + (errors/submit-report :event-name "exception-page" :report "report" :hint "other")))] + (t/is (= 2 (count events))))) + +(t/deftest governor-bounds-an-incident-like-loop + (let [cause (error-cause :type :network :hint "unable to perform fetch operation") + events (capture-reports! + (fn [] + (dotimes [_ 10000] + (errors/submit-report :event-name "handled-exception" + :report "report" + :hint "unable to perform fetch operation" + :cause cause))))] + (t/is (= 1 (count events))))) + +(t/deftest flash-suppressed-occurrence-does-not-build-a-report + (let [generated (atom 0) + cause (error-cause :type :network :hint "unable to perform fetch operation") + events (atom [])] + (with-redefs [errors/generate-report (fn [_] (swap! generated inc) "report") + st/emit! (mock/stub (fn [& emitted] (swap! events into emitted))) + rt/get-current-href (constantly "https://penpot.example.com/#/workspace") + tm/schedule mock/noop] + (dotimes [_ 3] + (errors/flash :cause cause :type :handled)) + (t/is (= 1 (count @events))) + (t/is (= 1 @generated))))) + +(t/deftest flash-bounds-an-incident-like-loop + (let [generated (atom 0) + cause (error-cause :type :network :hint "unable to perform fetch operation") + events (atom [])] + (with-redefs [errors/generate-report (fn [_] (swap! generated inc) "report") + st/emit! (mock/stub (fn [& emitted] (swap! events into emitted))) + rt/get-current-href (constantly "https://penpot.example.com/#/workspace") + tm/schedule mock/noop] + (dotimes [_ 10000] + (errors/flash :cause cause :type :handled)) + (t/is (= 1 (count @events))) + (t/is (= 1 @generated))))) + +(t/deftest generate-report-is-total-when-formatting-fails + (with-redefs [st/format-last-events (mock/stub (fn [& _] (throw (ex-info "formatting failed" {}))))] + (let [report (errors/generate-report (error-cause :type :network :hint "boom"))] + (t/is (string? report))))) + +(t/deftest flash-emits-a-fallback-report-when-generation-fails + (let [events (atom [])] + (with-redefs [st/format-last-events (mock/stub (fn [& _] (throw (ex-info "formatting failed" {})))) + st/emit! (mock/stub (fn [& emitted] (swap! events into emitted))) + rt/get-current-href (constantly "https://penpot.example.com/#/workspace") + tm/schedule mock/noop] + (errors/flash :cause (error-cause :type :network :hint "boom") :type :handled) + (t/is (= 1 (count @events))) + (t/is (string? (:report (deref (first @events)))))))) + +(t/deftest exception-page-reports-dedup-by-cause + (let [cause-a (error-cause :type :internal :code :unable-to-process-repository-response :hint "boom") + cause-b (error-cause :type :internal :code :other :hint "other") + events (capture-reports! + (fn [] + (errors/submit-report :event-name "exception-page" + :report "report" :hint "boom" :cause cause-a) + (errors/submit-report :event-name "exception-page" + :report "report" :hint "different hint" :cause cause-a) + (errors/submit-report :event-name "exception-page" + :report "report" :hint "other" :cause cause-b)))] + (t/is (= 2 (count events))))) + +(t/deftest reports-of-the-same-cause-under-different-names-do-not-coalesce + (let [cause (error-cause :type :internal :hint "boom") + events (capture-reports! + (fn [] + (errors/submit-report :event-name "handled-exception" + :report "report" :hint "boom" :cause cause) + (errors/submit-report :event-name "unhandled-exception" + :report "report" :hint "boom" :cause cause) + (errors/submit-report :event-name "exception-page" + :report "report" :hint "boom" :cause cause)))] + (t/is (= 3 (count events))))) + ;; --------------------------------------------------------------------------- ;; on-error dispatches to ptk/handle-error ;; @@ -469,9 +704,8 @@ store (ptk/store {:state {} :on-error errors/on-error}) cause (ex-info "Save failed" {:type :network})] (with-redefs [refs/persistence pstate - errors/submit-report (fn [& params] - (swap! reports conj (apply hash-map params))) - tm/schedule (mock/stub (fn [_]))] + st/emit! (mock/stub (fn [& emitted] (swap! reports into emitted))) + tm/schedule (mock/stub (fn [_]))] (try (ptk/emit! store (#'dps/persistence-failed (uuid/next) cause)) (reset! pstate (:persistence @store)) @@ -484,9 +718,12 @@ (t/is (= 2 (count @rejected))) (t/is (= 1 (count @reports))) ;; A standalone timeout and a later save failure are new incidents. + ;; The later failure carries a distinct signature: repeating the same + ;; one inside the governor window is coalesced by design. (errors/on-error (ex-info "Save timed out" {:type :persistence :code :save-timeout})) (t/is (= 2 (count @reports))) - (ptk/emit! store (#'dps/persistence-failed (uuid/next) cause)) + (ptk/emit! store (#'dps/persistence-failed (uuid/next) + (ex-info "Save failed again" {:type :network}))) (t/is (= 3 (count @reports))) (finally (rx/dispose! store))))))