✨ Improve error report and warn on update loops (#12044)

This commit is contained in:
Alonso Torres 2026-10-14 10:20:27 +02:00 committed by GitHub
parent 57ed11942c
commit f76b1447ee
No known key found for this signature in database
GPG Key ID: B5690EEEBB952194
5 changed files with 215 additions and 11 deletions

View File

@ -15,8 +15,8 @@
:git/url "https://github.com/funcool/tubax.git"}
funcool/potok2
{:git/tag "v2.2"
:git/sha "0f7e15a"
{:git/tag "v2.3"
:git/sha "bdebbdb"
:git/url "https://github.com/funcool/potok.git"
:exclusions [funcool/beicon2]}
@ -26,8 +26,8 @@
:git/url "https://github.com/funcool/beicon.git"}
funcool/rumext
{:git/tag "v2.25"
:git/sha "27e5a1a"
{:git/tag "v2.26"
:git/sha "d726717"
:git/url "https://github.com/funcool/rumext.git"}
instaparse/instaparse {:mvn/version "1.5.0"}

View File

@ -16,7 +16,7 @@
[app.main.data.event :as ev]
[app.main.data.profile :as dp]
[app.main.data.websocket :as ws]
[app.main.errors]
[app.main.errors :as errors]
[app.main.features :as feat]
[app.main.rasterizer :as thr]
[app.main.store :as st]
@ -134,6 +134,8 @@
(i18n/init)
(cur/init-styles)
(mf/set-update-scheduler {:on-trip errors/on-update-loop})
(init-ui)
(st/emit! (plugins/initialize)
(initialize)))))

View File

@ -100,6 +100,40 @@
(assoc ::instance cause)
(assoc ::trace (.-stack cause)))))
;; Events in flight when each exception was caught, as report lines
(defonce ^:private in-flight-by-cause (js/WeakMap.))
;; Events kept from each end of a long in-flight list
(def ^:private in-flight-edge-size 10)
(defn- in-flight-lines
"Report lines for the in-flight `events`, outermost first; a long list
keeps only both ends."
[events]
(let [total (count events)
size in-flight-edge-size]
(if (<= total (* 2 size))
(mapv ptk/repr-event events)
(-> []
(into (map ptk/repr-event) (take size events))
(conj (str "... " (- total (* 2 size)) " more ..."))
(into (map ptk/repr-event) (take-last size events))))))
(defn- record-in-flight!
"Keeps the events the store is processing for the report of `cause`.
Runs synchronously on the error path: when an event's `update`, `effect`
or synchronous `watch` throws, the last line is that event. When a
`watch` pipeline fails on a value from the store stream, the store has
already finished that value, so the lines show the events that emitted
it, not the event that owns the pipeline."
[cause]
(try
(when (ex/exception? cause)
(when-let [events (not-empty (ptk/in-flight-events st/state))]
(.set in-flight-by-cause cause (in-flight-lines events))))
(catch :default _
nil)))
(defn on-error
"A general purpose error handler.
@ -114,6 +148,7 @@
(ex/print-throwable error))
(do
(vreset! handling-error? true)
(record-in-flight! (if (map? error) (::instance error) error))
(try
(if (map? error)
(ptk/handle-error error)
@ -166,8 +201,9 @@
(println "HREF: " (rt/get-current-href)))))
(defn- generate-full-report
"Complete report: context, formatted throwable (including `ex-data`) and the
last events."
"Complete report: context, formatted throwable (including `ex-data`), the
events in flight when the error was caught (when recorded) and the last
events."
[cause]
(with-out-str
(print (report-context cause))
@ -177,6 +213,12 @@
(ex/format-throwable cause))
(println)
(when-let [lines (.get in-flight-by-cause cause)]
(println "Events in flight when the error was caught (outermost first):")
(println "--------------------")
(run! println lines)
(println))
(println "Last events:")
(println "--------------------")
(println (st/format-last-events))
@ -202,9 +244,9 @@
"Build the report string for `cause`.
`:format` selects the payload: `:full` (default) includes the formatted
throwable and the last events; `:compact` keeps only the context and the
error type/code/uri, for environment failures. The option is accepted both
as keyword arguments and as a trailing map."
throwable, the in-flight and the last events; `:compact` keeps only the
context and the error type/code/uri, for environment failures. The option
is accepted both as keyword arguments and as a trailing map."
[cause & {:keys [format] :or {format :full}}]
(try
(case format
@ -392,6 +434,24 @@
hint
occurrences))))
(defonce ^:private update-loop-warned-at
(volatile! 0))
(defn on-update-loop
"Handler for the rumext update scheduler trips: logs the throttled
update loop with the events being processed, at most once per
`report-window-ms`. Runs inside store watchers and effect bodies, so it
never throws."
[_]
(try
(let [now (inst-ms (ct/now))]
(when (>= (- now @update-loop-warned-at) report-window-ms)
(vreset! update-loop-warned-at now)
(.warn js/console "[update-scheduler] update loop throttled; in-flight events:"
(into-array (map ptk/repr-event (ptk/in-flight-events st/state))))))
(catch :default _
nil)))
(defn- download-report!
[report event]
(dom/prevent-default event)

View File

@ -402,7 +402,7 @@
(defn inside-vbox [vbox objects frame-id]
(let [frame (get objects frame-id)]
(and (some? frame) (gsh/overlaps? frame vbox))))
(and (some? frame) (some? vbox) (gsh/overlaps? frame vbox))))
(defn setup-active-frames
[objects hover-ids selected active-frames zoom transform vbox]

View File

@ -11,6 +11,10 @@
- stale-asset-error? – pure predicate
- exception->error-data – pure transformer
- on-error re-entrancy guard – prevents recursive invocations
- events in flight – the full report lists the events the
store was processing when it caught the exception; a failing stream
pipeline lists the emitters of the value, not its own event
- on-update-loop – never throws into the scheduler's caller
- flash schedules async report and toast – neither the report nor
ntf/show is emitted synchronously
- organization SSO recovery – expired SSO sessions go back to the provider
@ -368,6 +372,144 @@
;; The guard must have allowed only the first invocation through.
(t/is (= 1 @reentrant-call-count))))
;; ---------------------------------------------------------------------------
;; Events in flight
;;
;; on-error records the events the store is processing when it catches an
;; exception; the full report lists them, outermost first.
;; ---------------------------------------------------------------------------
(def ^:private in-flight-cause (atom nil))
(defmethod ptk/handle-error ::test-in-flight
[err]
(reset! in-flight-cause (::errors/instance err))
nil)
(def ^:private in-flight-heading
"Events in flight when the error was caught (outermost first):")
(defn- in-flight-failure
[]
(ex-info "in-flight failure" {:type ::test-in-flight :hint "in-flight failure"}))
(defn- recursive-event
[n]
(ptk/reify ::test-in-flight-recursive
ptk/WatchEvent
(watch [_ _ _]
(if (pos? n)
(rx/of (recursive-event (dec n)))
(throw (in-flight-failure))))))
(t/deftest ^:async report-lists-the-events-in-flight-of-a-failing-event
(let [store (ptk/store {:state {} :on-error errors/on-error})]
(try
(await
(mock/with-mocks*
{st/state store
st/format-last-events (mock/stub (fn [& _] "(stub last events)"))
rt/get-current-href (constantly "https://penpot.example.com/#/workspace")}
(reset! in-flight-cause nil)
(st/emit!
(ptk/reify ::test-in-flight-outer
ptk/WatchEvent
(watch [_ _ _]
(rx/of (ptk/reify ::test-in-flight-inner
ptk/UpdateEvent
(update [_ _] (throw (in-flight-failure))))))))
(await (async/wait-for #(some? @in-flight-cause) "the failure reaches the handler"))
(let [report (errors/generate-report @in-flight-cause)
outer (.indexOf report "typ:(:frontend-tests.main-errors-test/test-in-flight-outer)")
inner (.indexOf report "typ:(:frontend-tests.main-errors-test/test-in-flight-inner)")]
(t/is (str/includes? report in-flight-heading))
(t/is (< -1 outer inner) "outer event listed before the failing one"))))
(finally
(rx/dispose! store)))))
(t/deftest ^:async report-keeps-both-ends-of-a-long-in-flight-list
(let [store (ptk/store {:state {} :on-error errors/on-error})]
(try
(await
(mock/with-mocks*
{st/state store
st/format-last-events (mock/stub (fn [& _] "(stub last events)"))
rt/get-current-href (constantly "https://penpot.example.com/#/workspace")}
(reset! in-flight-cause nil)
;; 25 nested events: 10 from each end are kept
(st/emit! (recursive-event 24))
(await (async/wait-for #(some? @in-flight-cause) "the failure reaches the handler"))
(let [report (errors/generate-report @in-flight-cause)]
(t/is (str/includes? report "... 5 more ..."))
(t/is (= 20 (count (re-seq #"test-in-flight-recursive" report)))))))
(finally
(rx/dispose! store)))))
(defn- in-flight-section
"The in-flight section of `report`, or nil when absent."
[report]
(let [start (.indexOf report in-flight-heading)]
(when (<= 0 start)
(subs report start (.indexOf report "Last events:" start)))))
(t/deftest ^:async stream-pipeline-failure-lists-the-emitters-of-the-value
(let [store (ptk/store {:state {} :on-error errors/on-error})]
(try
(await
(mock/with-mocks*
{st/state store
st/format-last-events (mock/stub (fn [& _] "(stub last events)"))
rt/get-current-href (constantly "https://penpot.example.com/#/workspace")}
(reset! in-flight-cause nil)
;; The listener's pipeline fails on the trigger that the emitter emits
(st/emit!
(ptk/reify ::test-in-flight-listener
ptk/WatchEvent
(watch [_ _ stream]
(->> stream
(rx/filter (ptk/type? ::test-in-flight-trigger))
(rx/take 1)
(rx/map (fn [_] (throw (in-flight-failure)))))))
(ptk/reify ::test-in-flight-emitter
ptk/WatchEvent
(watch [_ _ _]
(rx/of (ptk/data-event ::test-in-flight-trigger {})))))
(await (async/wait-for #(some? @in-flight-cause) "the failure reaches the handler"))
(let [section (in-flight-section (errors/generate-report @in-flight-cause))]
(t/is (str/includes? section "test-in-flight-emitter"))
(t/is (not (str/includes? section "test-in-flight-trigger")))
(t/is (not (str/includes? section "test-in-flight-listener"))))))
(finally
(rx/dispose! store)))))
(t/deftest ^:async delayed-watch-failure-has-no-in-flight-section
(let [store (ptk/store {:state {} :on-error errors/on-error})]
(try
(await
(mock/with-mocks*
{st/state store
st/format-last-events (mock/stub (fn [& _] "(stub last events)"))
rt/get-current-href (constantly "https://penpot.example.com/#/workspace")}
(reset! in-flight-cause nil)
(st/emit!
(ptk/reify ::test-in-flight-delayed
ptk/WatchEvent
(watch [_ _ _]
(->> (rx/timer 0)
(rx/map (fn [_] (throw (in-flight-failure))))))))
(await (async/wait-for #(some? @in-flight-cause) "the failure reaches the handler"))
(let [report (errors/generate-report @in-flight-cause)]
(t/is (not (str/includes? report in-flight-heading)))
(t/is (str/includes? report "Last events:")))))
(finally
(rx/dispose! store)))))
(t/deftest ^:async update-loop-handler-never-throws
(await
(mock/with-mocks*
{ptk/in-flight-events (fn [_] (throw (js/Error. "in-flight read failure")))}
(t/is (nil? (errors/on-update-loop {:rounds 26}))))))
;; ---------------------------------------------------------------------------
;; Expired organization SSO session
;;