diff --git a/.clj-kondo/config.edn b/.clj-kondo/config.edn index aeb8f9056c..c89da30aa3 100644 --- a/.clj-kondo/config.edn +++ b/.clj-kondo/config.edn @@ -29,6 +29,7 @@ cljs.core/let hooks.core/check-let benches.render-wasm.declarations/defscene hooks.benches/defscene benches.render-wasm.declarations/defcase hooks.benches/defcase + benches.render-wasm.runtime.commands/defcommand hooks.benches/defcommand benches.render-wasm.runtime.protocol/resolve-or-reject hooks.benches/resolve-or-reject benches.render-wasm.runtime.protocol/resolve-or-reject-with hooks.benches/resolve-or-reject-with}} diff --git a/.clj-kondo/hooks/benches.clj b/.clj-kondo/hooks/benches.clj index 1332af9a8a..5a100be0d8 100644 --- a/.clj-kondo/hooks/benches.clj +++ b/.clj-kondo/hooks/benches.clj @@ -25,6 +25,39 @@ (api/list-node (into [(api/token-node (quote fn)) argv] body))])} {:node node}))) +(defn defcommand + "Analyzes command options and both generated functions." + [{:keys [node]}] + (let [[_ command & forms] (:children node) + [doc forms] (if (string? (api/sexpr (first forms))) + [(first forms) (next forms)] + [nil forms]) + [options forms] (if (api/map-node? (first forms)) + [(first forms) (next forms)] + [nil forms]) + [argv & body] forms + [conditions body] (if (and (api/map-node? (first body)) (next body)) + [(first body) (next body)] + [nil body]) + handlers (:async (some-> options api/sexpr)) + core (api/list-node + (into [(api/token-node 'fn) + (api/vector-node (mapv api/token-node handlers))] + body)) + starred (api/token-node (symbol (str (api/sexpr command) "*"))) + measured (get (some-> options api/sexpr) :measured-variant true) + definition (api/list-node + (into [(api/token-node 'defn) command] + (concat (when doc [doc]) [argv] + (when conditions [conditions]) [core])))] + {:node (api/list-node + (into [(api/token-node 'do)] + (concat (when options [(api/coerce (dissoc (api/sexpr options) :async))]) + [definition] + (when measured + [(api/list-node [(api/token-node 'def) + starred command])]))))})) + (defn resolve-or-reject "Analyzes the body of a Promise-returning form." [{:keys [node]}] diff --git a/frontend/performance/benches/render_wasm/runtime/camera.cljs b/frontend/performance/benches/render_wasm/runtime/camera.cljs index a61a2b7497..99aeb63aa1 100644 --- a/frontend/performance/benches/render_wasm/runtime/camera.cljs +++ b/frontend/performance/benches/render_wasm/runtime/camera.cljs @@ -5,68 +5,118 @@ ;; Copyright (c) KALEIDOS SUBSIDIARY SL (ns benches.render-wasm.runtime.camera - "Standard load, pan and zoom bodies for renderer benchmark cases. + "Control rendering and camera movement in a scene case. - ## Concepts + Recap: A `scene` is a recipe for shapes, and a `snapshot` is just an instance + of the scene. A `case` is what we benchmark: a set of operations executed on + a snapshot. This namespace provides operations to control rendering and camera. - A scene is a recipe for shapes. A case pairs a scene with one measured - action. Its `:run!` body receives `rtx`, a browser runtime map. The browser - builds and uploads the scene snapshot before calling a body. + ## Runtime data - `rtx` contains: + A view contains zoom `:scale`, offsets `:x` and `:y`, and optional viewport + settings for canvas dimensions and device pixel ratio. Hooks are functions + that supply clocks, scheduling and renderer operations. A guard returns to + authorize work or throws an error to reject it. A command context contains: - - `:case`: plain case data, including its `:operation` settings. - - `:scene`: the prepared shape snapshot. - - `:module`: the WASM renderer handle. - - `:view`: the starting `{:scale :x :y}` camera view. The fields are zoom - scale and two camera offsets. - - `:hooks`: clock, scheduling and renderer functions. + - `:case`: the case descriptor, which contains its data settings. + - `:scene`: the prepared snapshot of shapes and references. + - `:view`: the current view. + - `:hooks`: the clock, scheduling, renderer and execution guard functions. - 'Full' (`FRAME_TYPE_FULL`) is the renderer frame type that ends a progressive - render (it does not mean the frame is visible on screen, though!). - A cached preview updates a view and calls `_render_from_cache` once, without - draining to `Full`. - A camera session spans camera start, previews, settling and the final `Full` - drain. A measurement is a map of render slices and elapsed times. + The runtime context for a case operation also includes `:module`, the + instantiated WebAssembly renderer. `pan!` and `zoom!` read movement settings + from `[:case :operation]`. - ## Work and timing + ## Rendering and camera sessions - `load!` drains the first render to `Full` after upload. `Full` marks renderer - completion. Pan and zoom read settings from `[:case :operation]`. `pan!` adds - `:dx` and `:dy` to the starting view. `zoom!` multiplies its `:scale` by - `:factor`. Both submit a number `:steps` of interpolated views. Each view - waits for the browser's next animation frame and makes one cached preview. - They then request a `:settle-ms` pause, in milliseconds, and drain the final - view to `Full`. + A frame type describes the progress of a renderer call. `Full` + (`FRAME_TYPE_FULL`) marks the renderer's completion of the request. GPU + execution and display proceed asynchronously after renderer submission. - Each body returns a promise of a measurement map. For reused cases, - the browser restores the starting view outside interaction timing. Pan and - zoom calculate their target before starting that timer. + A cached preview applies a view and draws once from cached tiles. A camera + session starts the interaction, submits interpolated views, waits for the + requested settling time, ends the interaction and renders until Full. + Each view update waits for the next animation frame and draws one cached + preview. `:settle-ms` gives the requested settling wait in milliseconds. - ## Related code + `render-sync` renders synchronously. `pan` receives explicit offsets, step + count and settling time, and returns the context with its updated view. + These commands accept a command context or its Promise and return a Promise + of the next context. Their measured functions, `render-sync*` and `pan*`, + require a command execution, which runs a function over a command context and + collects its measured calls. Each call records an event with the command's + metric values and optional traces. A metric names a measured quantity, such + as elapsed time. - Scene declarations such as `scenes/rects.cljs` call these functions from - their `:run!` bodies. `declarations.cljs` registers those bodies. - `browser/bridge.cljs` supplies `rtx` and prepares reused cases. `runtime/protocol.cljs` - owns the render drain and camera session; its `Metrics reported` section - defines the measurement fields. Node reads case declarations without running - their bodies. This namespace loads there because renderer effects come - through the browser-supplied `:hooks`." + `load!` renders an uploaded snapshot until Full. `pan!` adds `:dx` and `:dy` + to the starting offsets; `zoom!` multiplies the starting scale by `:factor`. + Both submit `:steps` interpolated views and finish a camera session. These + operations resolve to the recorded render calls and measured durations. + + ## Timing + + Each trace entry records a render call's timestamp, flags, frame type and + duration. Camera measurements also contain cached previews, requested and + observed waits, and completion durations. `:end-ms` is the clock reading + immediately after the final renderer call returns Full. + + `pan!` and `zoom!` calculate their target view before camera timing starts. + The `:interact-ms` duration runs from camera start through the final renderer + return. `pan*` measures its command body, including the target calculation, + through that same endpoint. Command input resolution and argument validation + precede the measured interval. Output validation and event recording follow + the endpoint." (:require + [app.common.schema :as sm] [benches.render-wasm.runtime.commands :refer [defcommand]] [benches.render-wasm.runtime.protocol :as protocol])) (defcommand render-sync - "Renders through the blocking renderer path." - {:requires [:render-sync]} + "Renders the prepared scene synchronously and returns the command context." [rtx] ((get-in rtx [:hooks :render-sync])) rtx) +(def ^:private valid-pan? + (sm/validator + [:map {:closed true} + [:dx ::sm/safe-number] + [:dy ::sm/safe-number] + [:steps [:int {:min 1}]] + [:settle-ms [:and ::sm/safe-number [:>= 0]]]])) + +(defn- run-camera + [rtx target {:keys [steps settle-ms]}] + (-> (protocol/start-camera! rtx {:settle-ms settle-ms}) + (protocol/animate-view! {:to target :steps steps}) + (protocol/finish-camera!))) + +(defcommand pan + "Moves the view by `:dx` and `:dy` through `:steps` cached previews. + Waits `:settle-ms` milliseconds, ends the interaction and renders until Full. + Resolves to the command context with its updated view. Steps must be positive; + the settling wait must be nonnegative." + {:async [complete fail]} + [rtx {:keys [dx dy] :as options}] + {:pre [(valid-pan? options)]} + (let [target (-> (:view rtx) + (update :x + dx) + (update :y + dy))] + (-> (run-camera rtx target options) + (.then (fn [evidence] + (complete (assoc rtx :view target) + {:end-ms (:end-ms evidence) + :metrics {:renderer/call-elapsed (mapv :duration-ms (:slices evidence)) + :renderer/cache-call-elapsed (mapv :duration-ms (:cached-slices evidence)) + :camera/finalization-to-full [(:time-to-full-ms evidence)]} + :trace evidence}))) + (.catch fail)))) + (defn load! - "Drains the uploaded scene until the renderer reports Full completion. - `rtx` supplies the clock and renderer hooks. Returns a promise of first-render - slices and completion times." + "Renders the uploaded snapshot until the renderer returns Full. + Waits for an animation frame before the first render call. Returns a Promise + with recorded render calls, completion durations and the final clock reading + `:end-ms`. The context supplies clock, scheduling and renderer hooks." [rtx] (let [hooks (:hooks rtx)] (protocol/drain hooks {:flags 0 @@ -74,31 +124,27 @@ :immediate false}))) (defn pan! - "Moves the starting `{:scale :x :y}` view by the case's `:dx` and `:dy`. - Submits `:steps` views, each with one cached renderer preview after an - animation frame. Requests a `:settle-ms` pause, then drains until the renderer - reports Full completion. - Returns a promise of interaction measurements." + "Moves the starting view by the offsets in `[:case :operation]`. + `:dx` and `:dy` give the offsets; `:steps` gives the number of interpolated + views. Each update waits for an animation frame and draws a cached preview. + After the `:settle-ms` wait, ends the interaction and renders until Full. + Returns a Promise with recorded render calls, waits and camera durations." [rtx] (let [view (:view rtx) {:keys [steps dx dy settle-ms]} (get-in rtx [:case :operation]) target (-> view (update :x + dx) (update :y + dy))] - (-> (protocol/start-camera! rtx {:settle-ms settle-ms}) - (protocol/animate-view! {:to target :steps steps}) - (protocol/finish-camera!)))) + (run-camera rtx target {:steps steps :settle-ms settle-ms}))) (defn zoom! - "Multiplies the starting `{:scale :x :y}` view's scale by `:factor`. - Submits `:steps` views, each with one cached renderer preview after an - animation frame. Requests a `:settle-ms` pause, then drains until the renderer - reports Full completion. - Returns a promise of interaction measurements." + "Changes the starting scale using settings in `[:case :operation]`. + `:factor` multiplies the scale; `:steps` gives the number of interpolated + views. Each update waits for an animation frame and draws a cached preview. + After the `:settle-ms` wait, ends the interaction and renders until Full. + Returns a Promise with recorded render calls, waits and camera durations." [rtx] (let [view (:view rtx) {:keys [steps factor settle-ms]} (get-in rtx [:case :operation]) target (update view :scale * factor)] - (-> (protocol/start-camera! rtx {:settle-ms settle-ms}) - (protocol/animate-view! {:to target :steps steps}) - (protocol/finish-camera!)))) + (run-camera rtx target {:steps steps :settle-ms settle-ms}))) diff --git a/frontend/performance/benches/render_wasm/runtime/commands.clj b/frontend/performance/benches/render_wasm/runtime/commands.clj index a2b58014c9..438e71eb85 100644 --- a/frontend/performance/benches/render_wasm/runtime/commands.clj +++ b/frontend/performance/benches/render_wasm/runtime/commands.clj @@ -4,19 +4,40 @@ ;; ;; Copyright (c) KALEIDOS SUBSIDIARY SL -(ns benches.render-wasm.runtime.commands) +(ns benches.render-wasm.runtime.commands + "Declarations of renderer commands. + A command transforms a command context, a map of case data, a scene snapshot, + the current camera view and hooks. A scene is a recipe for shapes; a case + pairs a scene with its work. A snapshot contains concrete shapes and their + references. The view stores zoom scale and camera offsets. Hooks are functions + for clocks, scheduling and renderer operations. A measured command records + an event containing raw numeric values for named quantities, called metrics.") (defmacro defcommand - "Defines a command for scenes. + "Defines a base command and its measured function with a `*` suffix. - `(defcommand foo ...)` creates commands `foo` and `foo*`. The latter is - measured (records raw observations). + Both accept a command context or its Promise and return a Promise of the next + context. A synchronous body returns that context. The measured function + requires an active command execution and records one event with + `:command/elapsed`, the body duration in milliseconds. - Both variants accept a context or its Promise and return a Promise of the - updated context. `:requires` declares callable hook names. - `:measured-variant false` defines a composite that awaits its returned context. - Argument destructuring and `:pre` checks precede the measured interval in - every build. The condition map accepts only `:pre`." + Options: + - `:measured-variant false` defines a composite's base function. A composite + combines commands and records events from the measured commands it calls. + - `:async [complete fail]` lets the body complete asynchronously. Successful + completion requires `complete`; `fail` reports a cause. The first call to + either callback determines the outcome. A returned Promise forwards its + rejection to `fail`. + + `complete` accepts the next context and an optional map. `:end-ms` supplies + the clock reading at the end of the work. When the map omits `:end-ms`, + `complete` captures a reading on entry. `:metrics` maps namespaced metric + keywords to nonempty vectors of raw numbers. + `:trace` contains renderer details such as individual render calls and waits. + + Argument destructuring and `:pre` conditions precede work and timing in every + build. A failed condition rejects the returned Promise. The condition map + accepts `:pre`. Output validation and event recording follow the endpoint." [command & forms] (let [[doc forms] (if (string? (first forms)) [(first forms) (next forms)] @@ -29,6 +50,7 @@ [(first body) (next body)] [nil body]) measured (get options :measured-variant true) + handlers (:async options) command-id (keyword (str (get-in &env [:ns :name])) (name command)) starred (symbol (str command "*")) prepare (gensym "prepare")] @@ -36,8 +58,12 @@ (vector? argv) (seq argv) (boolean? measured) - (every? #{:requires :measured-variant} (keys options)) - (every? keyword? (:requires options)) + (every? #{:measured-variant :async} (keys options)) + (or (not (contains? options :async)) + (and (vector? handlers) + (= 2 (count handlers)) + (every? simple-symbol? handlers) + (apply distinct? handlers))) (every? #{:pre} (keys conditions)) (or (nil? (:pre conditions)) (vector? (:pre conditions)))) (throw (ex-info "invalid command declaration" {:command command}))) @@ -48,17 +74,17 @@ {:type ::invalid-arguments :command ~command-id :condition '~condition})))) - (fn [] ~@body))] + (fn ~(or handlers []) ~@body))] (defn ~command ~@(when doc [doc]) [rtx# & args#] (invoke {:command ~command-id :measured false :composite ~(not measured) - :requires ~(:requires options)} + :async ~(some? handlers)} rtx# ~prepare args#)) ~@(when measured [`(defn ~starred ~(str "Measured variant of `" command "`." (when doc (str " " doc))) [rtx# & args#] (invoke {:command ~command-id :measured true :composite false - :requires ~(:requires options)} + :async ~(some? handlers)} rtx# ~prepare args#))])))) diff --git a/frontend/performance/benches/render_wasm/runtime/commands.cljs b/frontend/performance/benches/render_wasm/runtime/commands.cljs index 6a96eedf50..5a52793686 100644 --- a/frontend/performance/benches/render_wasm/runtime/commands.cljs +++ b/frontend/performance/benches/render_wasm/runtime/commands.cljs @@ -5,7 +5,24 @@ ;; Copyright (c) KALEIDOS SUBSIDIARY SL (ns benches.render-wasm.runtime.commands - "Renderer commands and collection of raw command observations." + "Execution of renderer commands and collection of their measurements. + + A command transforms a command context: a map containing case data (`:case`), + the prepared scene snapshot (`:scene`), the current camera view (`:view`) and + functions for clocks, scheduling and renderer operations (`:hooks`). A scene + is a recipe for shapes; a case pairs a scene with its work. A snapshot contains + the concrete shapes and their references. A view contains zoom scale, camera + offsets and optional viewport settings for canvas dimensions and pixel ratio. + The `:check` hook is a guard: + returning authorizes work, and throwing an error rejects it. + + A command execution evaluates a function from one context to the next and + records measured command calls in completion order. Each call records an + event with the command name and its metrics. A metric names a quantity; + each event keeps its raw numeric + values in a vector. An optional trace contains details such as render calls + and waits. Each execution owns its event history and authorizes work while + active. Its outcome contains the next context or an error and earlier events." (:require-macros [benches.render-wasm.runtime.commands]) (:require [app.common.schema :as sm] @@ -19,9 +36,26 @@ [:view decl/schema:view] [:hooks [:and [:map-of :keyword fn?] - [:map [:now fn?] [:check fn?]]]]]) + [:map + [:now fn?] + [:check fn?] + [:frame fn?] + [:sleep fn?] + [:render fn?] + [:render-sync fn?] + [:render-from-cache fn?] + [:set-view fn?] + [:set-view-start fn?] + [:set-view-end fn?]]]]]) (def ^:private valid-context? (sm/validator schema:context)) +(def ^:private schema:completion + [:map {:closed true} + [:end-ms {:optional true} number?] + [:metrics {:optional true} + [:map-of qualified-keyword? [:vector {:min 1} number?]]] + [:trace {:optional true} :any]]) +(def ^:private valid-completion? (sm/validator schema:completion)) (def ^:private owners (js/WeakMap.)) (defn- check-context @@ -42,7 +76,7 @@ output) (defn- scope-context - [rtx events active] + [rtx events diagnostics active] (check-context rtx) (let [previous-check (get-in rtx [:hooks :check]) previous-owner (.get owners previous-check) @@ -54,36 +88,45 @@ (base-check)) scoped (assoc-in rtx [:hooks :check] check)] (.set owners check {:base-check base-check - :record #(do (check) (vswap! events conj %))}) + :record #(do (check) (vswap! events conj %)) + :diagnose #(when @active (vswap! diagnostics conj %))}) (check) scoped)) (defn ^:async ^:no-doc execute - "Executes a context function and returns its outcome and ordered raw events. - A completed execution includes its updated context. A failed execution - includes its cause and any events recorded before failure." + "Runs `run` with a command context and resolves to its outcome. + + `run` returns the next context or its Promise. A successful outcome contains + `:outcome :completed`, `:context` and ordered `:events`. A failed outcome + contains `:outcome :failed`, `:error` and events recorded before failure. + Existing Errors retain their identity; other thrown values become Errors + that retain the value in `:thrown`. + + The context's guard authorizes work during this execution. Passing a returned + context to another execution establishes a new authorization. Repeated calls + to asynchronous completion callbacks can supply `:diagnostics` while the + execution is active. Returned contexts must retain this execution's `:check` + guard. A changed guard rejects completion." [rtx run] - (let [events (volatile! []) - active (volatile! true) - result (try - (attempt :catch-fatal - (let [scoped (scope-context (await rtx) events active)] - (check-output scoped (await (run scoped))))) - (finally - (vreset! active false)))] - (if (failure? result) - {:outcome :failed :error result :events @events} - {:outcome :completed :context result :events @events}))) + (let [events (volatile! []) + diagnostics (volatile! []) + active (volatile! true) + result (try + (attempt :catch-fatal + (let [scoped (scope-context (await rtx) events diagnostics active)] + (check-output scoped (await (run scoped))))) + (finally + (vreset! active false)))] + (cond-> (if (failure? result) + {:outcome :failed :error result :events @events} + {:outcome :completed :context result :events @events}) + (seq @diagnostics) (assoc :diagnostics @diagnostics)))) (defn- prepare-invocation - [{:keys [command measured requires] :as invocation} rtx prepare args] + [{:keys [command measured] :as invocation} rtx prepare args] (check-context rtx) - (let [{:keys [check now] :as hooks} (:hooks rtx) - owner (.get owners check)] - (when-not (sm/validate (into [:map] (map #(vector % fn?) requires)) hooks) - (throw (ex-info "command requires callable hooks" - {:type ::invalid-capabilities :command command - :required requires}))) + (let [{:keys [check now]} (:hooks rtx) + owner (.get owners check)] (check) (when (and measured (nil? owner)) (throw (ex-info "measured command requires an execution" @@ -92,7 +135,12 @@ :input rtx :core (apply prepare rtx args) :now now - :record (:record owner)))) + :record (:record owner) + :diagnose (:diagnose owner)))) + +(defn- thenable? + [output] + (and (some? output) (fn? (.-then output)))) (defn- run-core [{:keys [command measured composite core now] :as invocation}] @@ -101,27 +149,85 @@ (let [start (when measured (now)) output (core) end (when measured (now))] - (when (and (some? output) (fn? (.-then output))) + (when (thenable? output) (.catch (js/Promise.resolve output) errors/as-failure) (throw (ex-info "synchronous command returned asynchronous work" {:type ::async-result :command command}))) (cond-> (assoc invocation :output output) - measured (assoc :elapsed (- end start)))))) + measured (assoc :metrics {:command/elapsed [(- end start)]}))))) (defn- finish-invocation - [{:keys [command measured input output elapsed record]}] + [{:keys [measured input output record] :as invocation}] (check-output input output) (when measured - (record {:command command :metrics {:command/elapsed [elapsed]}})) + (record (select-keys invocation [:command :metrics :trace]))) output) +(defn- complete-invocation + [{:keys [command measured now] :as invocation} output evidence start] + ;; A completion callback can run after the renderer returns. A supplied + ;; endpoint preserves the renderer return time across that scheduling delay. + (let [end (when measured + (if (and (map? evidence) (contains? evidence :end-ms)) + (:end-ms evidence) + (now)))] + (when-not (and (valid-completion? evidence) + (not (contains? (:metrics evidence) :command/elapsed))) + (throw (ex-info "invalid command completion evidence" + {:type ::invalid-completion :command command + ::sm/explain (sm/explain schema:completion evidence)}))) + (cond-> (merge invocation evidence {:output output}) + measured (assoc-in [:metrics :command/elapsed] [(- end start)])))) + +(defn- claim-terminal + [terminal diagnose command signal] + (if-some [first-signal @terminal] + (do + (when diagnose + (diagnose {:type ::duplicate-terminal :command command + :first-signal first-signal :signal signal})) + false) + (do + (vreset! terminal signal) + true))) + +(defn- run-async-core + [{:keys [command measured core now diagnose] :as invocation}] + (js/Promise. + (fn [resolve reject] + (let [terminal (volatile! nil) + start (volatile! nil) + complete (fn complete + ([output] (complete output {})) + ([output evidence] + (when (claim-terminal terminal diagnose command :complete) + (let [result (attempt :catch-fatal + (-> (complete-invocation invocation output evidence @start) + (finish-invocation)))] + (if (failure? result) (reject result) (resolve result)))) + nil)) + fail (fn [cause] + (when (claim-terminal terminal diagnose command :fail) + (reject (errors/as-failure cause))) + nil) + result (attempt :catch-fatal + (vreset! start (when measured (now))) + (let [returned (core complete fail)] + (when (thenable? returned) + (.catch (js/Promise.resolve returned) fail))))] + (when (failure? result) + (fail result)))))) + (defn ^:async invoke - "Resolves a command input and executes its declared core. - Measured invocations append one raw elapsed observation to their execution." + "Runs a command with a context or its Promise and returns the next context. + Resolves to that context as a Promise; errors reject it. A measured command + records one event with elapsed time, additional metric values and any trace." [command rtx prepare args] - (let [invocation (prepare-invocation command (await rtx) prepare args) - result (run-core invocation)] - (finish-invocation - (if (:composite command) - (assoc result :output (await (:output result))) - result)))) + (let [invocation (prepare-invocation command (await rtx) prepare args)] + (if (:async command) + (await (run-async-core invocation)) + (let [result (run-core invocation)] + (finish-invocation + (if (:composite command) + (assoc result :output (await (:output result))) + result)))))) diff --git a/frontend/performance/benches/render_wasm/runtime/protocol.clj b/frontend/performance/benches/render_wasm/runtime/protocol.clj index 75b9ea3a43..0b8768b259 100644 --- a/frontend/performance/benches/render_wasm/runtime/protocol.clj +++ b/frontend/performance/benches/render_wasm/runtime/protocol.clj @@ -4,11 +4,14 @@ ;; ;; Copyright (c) KALEIDOS SUBSIDIARY SL -(ns benches.render-wasm.runtime.protocol) +(ns benches.render-wasm.runtime.protocol + "Forms for evaluating renderer operations as Promises. + A Promise represents a result that can complete with a value or reject with + a cause. These forms include synchronous errors in that result.") (defmacro resolve-or-reject - "Evaluates `body` and returns a Promise. A synchronous throw rejects the - returned promise." + "Evaluates `body` and returns a Promise of its result. + A synchronous throw rejects the Promise." [& body] `(try (js/Promise.resolve (do ~@body)) @@ -16,8 +19,9 @@ (js/Promise.reject cause#)))) (defmacro resolve-or-reject-with - "Evaluates `body` and returns a Promise. A synchronous throw rejects with the - result of `on-error`, evaluated with `cause` bound to the thrown value." + "Evaluates `body` and returns a Promise of its result. + A synchronous throw rejects with `on-error`, evaluated with `cause` bound + to the thrown value." [cause on-error & body] `(try (js/Promise.resolve (do ~@body)) diff --git a/frontend/performance/benches/render_wasm/runtime/protocol.cljs b/frontend/performance/benches/render_wasm/runtime/protocol.cljs index 5a6215c303..5539ee36a5 100644 --- a/frontend/performance/benches/render_wasm/runtime/protocol.cljs +++ b/frontend/performance/benches/render_wasm/runtime/protocol.cljs @@ -5,81 +5,90 @@ ;; Copyright (c) KALEIDOS SUBSIDIARY SL (ns benches.render-wasm.runtime.protocol - "Shared render-completion protocol for the renderer benchmarks. + "Rendering until completion and timing camera movement. - The WASM renderer finishes progressively in tile budgets: one `_render` - call returns a frame type and the caller keeps calling until `FRAME_TYPE_FULL`. - This namespace implements a driver loop and camera sessions over an injected - `hooks` map. Callers use the same timing and continuation rules for - rendering and interaction: + A frame type describes the progress of one renderer call. A render drain is + a sequence of calls that ends when the renderer returns Full. Each call + produces a slice: its timestamp, flags, frame type and duration. Partial and + ViewportReady schedule another call on the next animation frame. Full marks + renderer submission of the completed request. GPU execution and display + proceed asynchronously. - - `drain` drives `_render` to `FRAME_TYPE_FULL`, collecting one slice per - call. - - `restore` puts the camera back to the case's initial view, then drains. - Callers run it outside timing. - - `start-camera!`, `preview-view!`, `animate-view!`, `sleep!` and - `finish-camera!` form one Promise-aware camera session. + A view contains zoom `:scale` and offsets `:x` and `:y`. A cached preview + draws from existing tiles, the fixed regions of the scene that the renderer + caches. A camera session starts an interaction, applies views with cached + previews, waits for the requested settling time, ends the interaction and + renders until Full. Each preview waits for an animation frame. Explicit + pauses can extend the active interval between camera start and settling. + Camera finalization starts immediately before ending the interaction and + ends at the final renderer return. - `hooks` supplies clock, scheduling and renderer operations. The browser - supplies real capabilities; tests supply fakes. + ## Hooks and errors - - `:now` zero-arg clock, ms. - - `:frame` zero-arg promise of the next rAF timestamp. - - `:sleep` `(fn [ms] ...)` promise. - - `:check` zero-arg guard. Throws on cancellation, wall deadline, - context loss or superseded ownership. The protocol checks before work, - after awaited frames and sleeps, and around render calls. It never - retries; synchronous stalls cannot be - interrupted in-page, so Node stays the outer backstop. - - `:render` `(fn [timestamp flags] ...)` returning a frame type. - - `:render-from-cache` zero-arg cached-preview call. The protocol times - the call itself and discards its return value. - - `:set-view` `(fn [view] ...)` with `view` a `{:scale :x :y}` map. - - `:set-view-start` / `:set-view-end` zero-arg camera calls. + Hooks are functions that supply clock, scheduling and renderer operations: - Guard and renderer errors reject the returned promises. The browser's - `:check` guard throws when work is cancelled, exceeds its deadline, - loses its rendering context or is no longer the active task. + - `:now` returns a clock reading in milliseconds. + - `:frame` resolves a Promise with the next animation frame's timestamp. + - `:sleep` accepts a requested wait in milliseconds and returns its Promise. + - `:check` is a guard. Returning authorizes work; throwing rejects it. It can + report cancellation, an expired deadline, loss of the WebGL2 graphics + context or replacement of the active renderer owner. An owner is the + execution authorized to use the renderer. + - `:render` accepts a timestamp and flags and returns a frame type. + - `:render-from-cache` draws one cached preview. + - `:set-view` accepts a view containing scale and both offsets. + - `:set-view-start` and `:set-view-end` start and end the interaction. - Frame types come from `app.common.render-wasm.wasm`: FRAME_TYPE_PARTIAL and - FRAME_TYPE_VIEWPORT_READY continue, FRAME_TYPE_FULL completes, FRAME_TYPE_NONE - or anything else fails the attempt. The previous returned frame type becomes the - next call's flags. `restore` and the final camera-session drain start with - the SyncTiles flag immediately (no rAF); a fresh drain can start with - different flags and wait for a frame. + Guards run before work, after awaited frames and waits, and around render + calls. Guard and renderer errors reject the returned Promises. Errors keep + available traces of render calls and pauses under `:partial`. - ## Metrics reported + Frame types come from `app.common.render-wasm.wasm`. Partial and ViewportReady + continue rendering, Full completes it, and other values reject with + `::unexpected-frame-type`. Each subsequent call receives the preceding frame + type as its flags. SyncTiles asks the renderer to update which tiles the + current view requires. + View restoration and camera finalization use that flag for their first call + and start immediately. A drain can also wait for an animation frame before + its first call. Later calls wait for animation frames. - - `:slices` one map per `_render` call: - - `:timestamp`: the rAF stamp the call ran under, or the clock value for - an immediate call without a frame - - `:flags`: flags passed in - - `:frame-type`: frame type returned - - `:duration-ms`: wall time of the call itself - Raw slices are retained as-is, including zero durations. - - `:cached-slices` one map per gesture frame: - - `:timestamp` rAF stamp of the input - - `:duration-ms`: the timed `_render-from-cache` call. - - `:view-and-preview-ms`: the view update and cached-preview call span. - Cached previews have their own shape: no flags or frame type. - - `:viewport-ready-ms` first Full-or-ViewportReady completion measured - from the drain origin. An immediate Full supplies both boundaries, so - they are equal there. - - `:full-ms` Full completion measured from the drain origin. - - `:interact-ms` from before `_set_view_start` through final Full. - - `:active-ms` from before `_set_view_start` to after the last cached - preview and its guard check, or an authored sleep after that preview. - - `:authored-sleeps` requested and actual durations of optional pauses. - - `:settling-requested-ms` the declared settle wait passed in. - - `:settling-actual-ms` from the end of the active span to finalization - start, recorded separately from the declared value. - - `:set-view-end-ms` wall time of the `_set_view_end` call itself. - Finalization starts before `_set_view_end`, so the final drain times - include it; the call time is still reported on its own. - - `:time-to-viewport-ready-ms` / `:time-to-full-ms` the drain's - boundaries, renamed at the interaction level. - - `:last-input-to-full-ms` from the clock read before the last view update - to the clock read after the final drain promise resolves." + ## Render calls and measured durations + + A trace records individual calls and waits. Durations use milliseconds and + preserve raw numeric values, including zero. A drain origin is the clock + reading from which its completion durations start. + + - `:slices` contains one entry per renderer call: + - `:timestamp`: the animation frame's timestamp or the current clock + reading for an immediate call. + - `:flags`: the flags passed to the renderer. + - `:frame-type`: the returned frame type. + - `:duration-ms`: elapsed time during the call. + - `:cached-slices` contains one entry per cached preview: + - `:timestamp`: the animation frame's timestamp for the view update. + - `:duration-ms`: elapsed time during the cached render call. + - `:view-and-preview-ms`: elapsed time for the view update and preview. + - `:viewport-ready-ms` measures from the drain origin to the first call that + returns ViewportReady or Full. It equals `:full-ms` when the first such + call returns Full. + - `:full-ms` measures from the drain origin to the call that returns Full. + - `:end-ms` is the clock reading immediately after that final call returns. + - `:interact-ms` measures from immediately before camera start through the + final renderer return. + - `:active-ms` measures from camera start through the last cached preview and + its guard check, or through an explicit pause that follows the preview. + - `:authored-sleeps` contains requested and observed durations of explicit + pauses during the active interval. + - `:settling-requested-ms` is the requested settling wait. + - `:settling-actual-ms` measures from the end of the active interval to the + start of camera finalization. + - `:set-view-end-ms` measures the call that ends the interaction. + - `:time-to-viewport-ready-ms` measures from camera finalization to the first + ViewportReady or Full result. `:time-to-full-ms` ends at Full. Both include + the call that ends the interaction. + - `:last-input-to-full-ms` measures from immediately before the last view + update to the final renderer return. The initial input time equals camera + start; each view update replaces it." (:require-macros [benches.render-wasm.runtime.protocol :refer [resolve-or-reject resolve-or-reject-with]]) (:require @@ -88,14 +97,15 @@ (defn- partial-error - "Attaches available trace evidence to a rejection without adding clock reads. - Deeper failure evidence takes precedence over a caller's earlier state." + "Returns an error with completed traces under `:partial`. + Trace fields already present in the error take precedence over `evidence`." [cause evidence] (errors/with-context cause (errors/message-of cause "renderer protocol failed") {:partial evidence})) (defn- next-render-timestamp - "Gets an immediate clock timestamp or awaits the next frame timestamp." + "Resolves to the current clock reading for an immediate render, or to the + next animation frame's timestamp." [{:keys [now frame]} immediate?] (if immediate? (js/Promise.resolve (now)) @@ -103,7 +113,8 @@ (defn- render-slice - "Times one render call and adds its slice to the drain state." + "Returns the updated drain state, frame type and endpoint for one render call. + The state includes the completed call in its `:slices` trace." [{:keys [now check render]} {:keys [flags] :as state} timestamp] @@ -133,7 +144,7 @@ (defn- viewport-ready-time - "Keeps the first submission boundary that exposes the requested viewport." + "Returns the elapsed time to the first ViewportReady or Full result." [current-ready-ms frame-type ended-ms origin-ms] (or current-ready-ms (when (or (= frame-type wasm/FRAME_TYPE_VIEWPORT_READY) @@ -142,7 +153,8 @@ (defn- advance-drain-state - "Updates progressive completion or rejects with the available raw slices." + "Updates the continuation flags and completion time for a returned frame type. + An unexpected type throws an error containing the completed render calls." [{:keys [viewport-ready-ms] :as state} frame-type ended-ms @@ -161,45 +173,36 @@ origin-ms))) (defn- drain-complete? - "Tests for the renderer's Full submission boundary." + "Returns whether the renderer reported Full completion." [frame-type] (= frame-type wasm/FRAME_TYPE_FULL)) (defn- drain-result - "Returns raw slices and completion times from the drain origin." + "Returns traces of render calls, the final clock reading and completion durations + measured from the drain origin." [{:keys [slices viewport-ready-ms]} ended-ms origin-ms] {:slices slices + :end-ms ended-ms :viewport-ready-ms viewport-ready-ms :full-ms (- ended-ms origin-ms)}) (defn drain - "Drives `_render` to `FRAME_TYPE_FULL` and resolves to - `{:slices [...] :viewport-ready-ms ... :full-ms ...}`. + "Renders until a call returns Full and resolves to its traces and durations. - The flow is: + Options: + - `:flags` supplies the first render call's flags. + - `:origin` supplies the starting clock reading for completion durations. + - `:immediate` starts the first call immediately when true. Otherwise, the + first call waits for an animation frame. Subsequent calls wait for frames. - drain - └─ step - ├─ next-render-timestamp - ├─ render-slice - ├─ advance-drain-state - └─ either - ├─ drain-result - └─ step - - `opts` contains: - - `:flags` (first call's flags) - - `:origin` (required starting moment in ms) - - `:immediate` (run the first `_render` in the same task instead of waiting - for a frame; later frames always wait). - - Partial and ViewportReady continue with the returned frame type as the next - flags. FRAME_TYPE_FULL resolves. Anything else rejects with - `::unexpected-frame-type`. A failure of the hook `:check` rejects without - retrying." + The result contains `:slices`, the traces of render calls; `:end-ms`, the final + renderer clock reading; and `:viewport-ready-ms` and `:full-ms`, durations + measured from `:origin`. Partial and ViewportReady continue with the returned + frame type as the next flags. A guard failure or unexpected frame type + rejects the Promise with completed traces in the error's `:partial` field." [{:keys [check] :as hooks} {:keys [flags origin immediate]}] (resolve-or-reject @@ -227,9 +230,11 @@ immediate)))) (defn restore - "Puts the camera back to `view` (`{:scale :x :y}`) and drains with the - SyncTiles flag immediately. Resolves what `drain` resolves. Callers run - this outside timing: the reset itself is never scored." + "Restores `view` and renders its tiles until Full. + The first call uses SyncTiles and starts immediately. Completion durations + begin after restoring the view and ending the interaction. Returns a Promise + with recorded render calls, completion durations and the final clock reading + `:end-ms`." [{:keys [now check set-view set-view-start set-view-end] :as hooks} view] (resolve-or-reject (check) @@ -241,8 +246,10 @@ :immediate true}))) (defn start-camera! - "Starts a measured camera session after the caller's untimed preparation. - `rtx` supplies `:hooks` and the current full `:view`." + "Starts a camera session from the context's current `:view` and `:hooks`. + Resolves to the session with its start time and requested settling wait. + The initial active interval covers the operation that starts the camera. + `:settle-ms` must give a finite, nonnegative duration in milliseconds." [{:keys [hooks view]} {:keys [settle-ms]}] (resolve-or-reject (when-not (and (number? settle-ms) @@ -264,9 +271,9 @@ :authored-sleeps []})))) (defn preview-view! - "Awaits a session and submits one cached preview after exactly one rAF. - The call span includes view update and cache rendering. Failures retain - completed previews and authored pauses without adding clock reads." + "Updates the view and draws one cached preview on the next animation frame. + Resolves to the session with the new view and measured preview durations. + Errors retain completed previews and pauses under `:partial`." [session-p view] (-> (js/Promise.resolve session-p) (.then (fn [{:keys [hooks] :as session}] @@ -297,8 +304,10 @@ (.catch (fn [cause] (throw (partial-error cause evidence))))))))))) (defn animate-view! - "Submits exactly `steps` serial, linearly interpolated full views. - Invalid steps retain the session's completed previews and pauses." + "Moves to `to` through `steps` linearly interpolated views in sequence. + Each update waits for an animation frame and draws one cached preview. + Resolves to the session with its final view. Steps must be a positive integer; + errors retain completed previews and pauses under `:partial`." [session-p {:keys [to steps]}] (-> (js/Promise.resolve session-p) (.then (fn [{from :view :as session}] @@ -316,8 +325,10 @@ (range 1 (inc steps))))))) (defn sleep! - "Awaits an authored pause inside the active span and records its actual time. - Rejections retain earlier completed previews and pauses without new timers." + "Pauses the camera session and records the requested and observed wait. + The wait must be finite and nonnegative. The pause extends the active + interval. Resolves to the updated session; + errors retain completed previews and pauses under `:partial`." [session-p requested-ms] (-> (js/Promise.resolve session-p) (.then (fn [{:keys [hooks] :as session}] @@ -344,7 +355,8 @@ (.catch (fn [cause] (throw (partial-error cause evidence)))))))))))) (defn- finish-interaction - "Ends the camera and returns final metrics, retaining trace evidence on failure." + "Ends the interaction and resolves to camera durations and recorded render calls. + Errors retain completed previews and pauses under `:partial`." [{:keys [now check set-view-end] :as hooks} {:keys [settle-ms started-ms cached-slices last-input-ms active-end-ms authored-sleeps]}] (check) @@ -359,10 +371,11 @@ :origin finalization-start :immediate true}) (.then - (fn [{:keys [slices viewport-ready-ms full-ms]}] + (fn [{:keys [slices end-ms viewport-ready-ms full-ms]}] {:cached-slices cached-slices :slices slices - :interact-ms (- (now) started-ms) + :end-ms end-ms + :interact-ms (- end-ms started-ms) :active-ms (- active-end-ms started-ms) :authored-sleeps authored-sleeps :settling-requested-ms settle-ms @@ -370,15 +383,17 @@ :set-view-end-ms set-view-end-ms :time-to-viewport-ready-ms viewport-ready-ms :time-to-full-ms full-ms - :last-input-to-full-ms (- (now) last-input-ms)})) + :last-input-to-full-ms (- end-ms last-input-ms)})) (.catch (fn [cause] (throw (partial-error cause {:cached-slices cached-slices :authored-sleeps authored-sleeps})))))))) (defn finish-camera! - "Awaits a session, settles, ends the camera and drains through Full. - Failures keep completed cached previews and authored pauses." + "Waits for settling, ends the interaction and renders until Full. + Resolves to cached previews, traces of final render calls, pauses and measured + camera durations. `:end-ms` is the clock reading at the final renderer return. + Errors retain completed previews and pauses under `:partial`." [session-p] (-> (js/Promise.resolve session-p) (.then (fn [{:keys [hooks settle-ms] :as session}] diff --git a/frontend/test/performance_tests/render_wasm/commands_test.cljs b/frontend/test/performance_tests/render_wasm/commands_test.cljs index c903531995..af07feaed0 100644 --- a/frontend/test/performance_tests/render_wasm/commands_test.cljs +++ b/frontend/test/performance_tests/render_wasm/commands_test.cljs @@ -6,6 +6,7 @@ (ns performance-tests.render-wasm.commands-test (:require + [app.common.render-wasm.wasm :as wasm] [benches.render-wasm.builder :as builder] [benches.render-wasm.errors :as errors] [benches.render-wasm.runtime.camera :as camera] @@ -13,7 +14,7 @@ [cljs.test :as t])) (defcommand move - "Moves the camera by the supplied offset." + "Adds the supplied offsets to the command context's view." [rtx {:keys [dx dy]}] (-> rtx (update-in [:view :x] + dx) @@ -44,6 +45,20 @@ [rtx] (assoc-in rtx [:hooks :check] (fn []))) +(defcommand async-work + {:async [complete fail]} + [rtx work] + (work rtx complete fail)) + +(defcommand selected-async + {:async [complete fail] :measured-variant false} + [rtx] + (-> (camera/render-sync* rtx) + (move {:dx 10 :dy 5}) + (camera/render-sync*) + (.then complete) + (.catch fail))) + (defn- context [clock] {:case {:id :commands/example} @@ -51,7 +66,14 @@ :view {:scale 1 :x 0 :y 0} :hooks {:now #(deref clock) :check (fn []) - :render-sync #(vswap! clock + 7)}}) + :frame #(js/Promise.resolve (vswap! clock + 16)) + :sleep #(do (vswap! clock + %) (js/Promise.resolve nil)) + :render (fn [_ _] (vswap! clock + 7) wasm/FRAME_TYPE_FULL) + :render-sync #(vswap! clock + 7) + :render-from-cache #(vswap! clock + 2) + :set-view (fn [_]) + :set-view-start (fn []) + :set-view-end #(vswap! clock + 3)}}) (t/deftest ^:async measurement-uses-core-time (let [clock (volatile! 0) @@ -111,6 +133,208 @@ (t/is (= [{:command ::move :metrics {:command/elapsed [0]}}] (:events result))))) +(t/deftest ^:async async-completion-keeps-endpoints-and-raw-evidence + (doseq [command [async-work async-work*] + supplied [false true]] + (let [clock (volatile! 0) + rtx (context clock) + metrics {:renderer/call-elapsed [1 2 4]} + trace {:steps [1 2 3]} + result (await + (cmd/execute + rtx + (fn [rtx] + (command + (-> (js/Promise.resolve rtx) + (.then #(do (vswap! clock + 1000) %))) + (fn [rtx complete _fail] + (vswap! clock + 7) + (let [end @clock + evidence {:metrics metrics :trace trace} + output (assoc-in rtx [:view :x] 10)] + (if supplied + (-> (js/Promise.resolve nil) + (.then (fn [_] + (vswap! clock + 500) + (complete output (assoc evidence :end-ms end))))) + (do + (complete output evidence) + (js/queueMicrotask #(vswap! clock + 500))))))))))] + (t/is (= :completed (:outcome result))) + (t/is (= 10 (get-in result [:context :view :x]))) + (t/is (= 1507 @clock)) + (t/is (= (if (= command async-work*) + [{:command ::async-work + :metrics (assoc metrics :command/elapsed [7]) + :trace trace}] + []) + (:events result))))) + (let [result (await (cmd/execute (context (volatile! 0)) selected-async))] + (t/is (= :completed (:outcome result))) + (t/is (= {:scale 1 :x 10 :y 5} (get-in result [:context :view]))) + (t/is (= [::camera/render-sync ::camera/render-sync] + (mapv :command (:events result)))))) + +(t/deftest ^:async async-completion-retains-invalid-numeric-observations + (let [result (await + (cmd/execute + (context (volatile! 0)) + #(async-work* % (fn [rtx complete _fail] + (complete rtx {:end-ms js/Infinity + :metrics {:sample/raw [-1 0 js/NaN js/Infinity]}}))))) + values (get-in result [:events 0 :metrics :sample/raw])] + (t/is (= :completed (:outcome result))) + (t/is (= [js/Infinity] (get-in result [:events 0 :metrics :command/elapsed]))) + (t/is (= [-1 0] (subvec values 0 2))) + (t/is (js/Number.isNaN (nth values 2))) + (t/is (= js/Infinity (nth values 3))))) + +(t/deftest ^:async async-commands-use-the-first-terminal-signal + (let [result (await + (cmd/execute + (context (volatile! 0)) + #(async-work* % (fn [rtx complete fail] + (complete (assoc-in rtx [:view :x] 10)) + (complete nil) + (fail (js/Error. "late failure")) + (throw (js/Error. "late throw"))))))] + (t/is (= :completed (:outcome result))) + (t/is (= 10 (get-in result [:context :view :x]))) + (t/is (= [{:command ::async-work :metrics {:command/elapsed [0]}}] (:events result))) + (t/is (= [:complete :fail :fail] (mapv :signal (:diagnostics result))))) + (let [result (await + (cmd/execute + (context (volatile! 0)) + #(async-work* % (fn [rtx complete _fail] + (js/queueMicrotask (fn [] (complete (assoc-in rtx [:view :x] 20)))) + rtx))))] + (t/is (= :completed (:outcome result))) + (t/is (= 20 (get-in result [:context :view :x])))) + (let [unhandled (atom []) + observe #(swap! unhandled conj %)] + (.on js/process "unhandledRejection" observe) + (try + (let [result (await + (cmd/execute + (context (volatile! 0)) + #(async-work* % (fn [rtx complete _fail] + (complete rtx) + (js/Promise.reject (js/Error. "rejected after completion"))))))] + (await (js/Promise. #(js/setImmediate %))) + (t/is (= :completed (:outcome result))) + (t/is (= [{:command ::async-work :metrics {:command/elapsed [0]}}] (:events result))) + (t/is (= [] @unhandled))) + (finally + (.removeListener js/process "unhandledRejection" observe))))) + +(t/deftest ^:async async-failures-retain-causes-and-earlier-events + (doseq [mode [:throw :reject :fail]] + (let [cause (ex-info "renderer failed" {:partial {:slices [{:duration-ms 3}]}}) + result (await + (cmd/execute + (context (volatile! 0)) + #(-> % + (camera/render-sync*) + (async-work* (fn [rtx complete fail] + (case mode + :throw (throw cause) + :reject (js/Promise.reject cause) + :fail (do (fail cause) (complete rtx))))))))] + (t/is (= :failed (:outcome result))) + (t/is (identical? cause (:error result))) + (t/is (= [{:command ::camera/render-sync :metrics {:command/elapsed [7]}}] + (:events result)))))) + +(t/deftest ^:async malformed-async-completion-fails-before-recording + (doseq [[output evidence expected] + [[identity {:end-ms nil} ::cmd/invalid-completion] + [identity {:metrics {:sample/raw []}} ::cmd/invalid-completion] + [identity {:metrics {:sample/raw ["bad"]}} ::cmd/invalid-completion] + [identity {:metrics {:command/elapsed [123]}} ::cmd/invalid-completion] + [#(assoc-in % [:view :scale] 0) {} ::cmd/invalid-context] + [#(assoc-in % [:hooks :check] (fn [])) {} ::cmd/ownership-lost]]] + (let [result (await (cmd/execute (context (volatile! 0)) + #(async-work* % (fn [rtx complete _fail] + (complete (output rtx) evidence)))))] + (t/is (= :failed (:outcome result))) + (t/is (= expected (:type (ex-data (:error result))))) + (t/is (= [] (:events result)))))) + +(t/deftest ^:async async-completion-checks-the-owner-guard + (doseq [cause [(ex-info "deadline expired" {:phase :deadline}) + (ex-info "owner superseded" {::errors/stale true})]] + (let [blocked (volatile! nil) + rtx (assoc-in (context (volatile! 0)) [:hooks :check] + #(when @blocked (throw @blocked))) + result (await (cmd/execute rtx #(async-work* % (fn [rtx complete _fail] + (vreset! blocked cause) + (complete rtx)))))] + (t/is (= :failed (:outcome result))) + (t/is (identical? cause (:error result))) + (t/is (= [] (:events result)))))) + +(t/deftest ^:async late-completion-cannot-record-in-another-execution + (let [callbacks (volatile! nil) + pending (volatile! nil) + first-run (await + (cmd/execute + (context (volatile! 0)) + (fn [rtx] + (vreset! pending + (.catch (async-work* rtx (fn [rtx complete fail] + (vreset! callbacks [rtx complete fail]))) + errors/as-failure)) + rtx))) + [rtx complete fail] @callbacks + next-run (await (cmd/execute (:context first-run) + (fn [next-rtx] + (complete rtx) + (fail (js/Error. "late failure")) + (camera/render-sync* next-rtx)))) + cause (await @pending)] + (t/is (= :completed (:outcome first-run))) + (t/is (= [] (:events first-run))) + (t/is (= ::cmd/inactive-execution (:type (ex-data cause)))) + (t/is (= :completed (:outcome next-run))) + (t/is (= [{:command ::camera/render-sync :metrics {:command/elapsed [7]}}] + (:events next-run))))) + +(t/deftest ^:async pan-commands-return-the-view-and-renderer-evidence + (doseq [command [camera/pan camera/pan*]] + (let [clock (volatile! 0) + view (volatile! nil) + remaining (volatile! [wasm/FRAME_TYPE_PARTIAL wasm/FRAME_TYPE_FULL]) + rtx (update (context clock) :hooks merge + {:set-view #(vreset! view %) + :render (fn [_ _] + (vswap! clock + 7) + (let [frame-type (first @remaining)] + (vswap! remaining rest) + (when (= wasm/FRAME_TYPE_FULL frame-type) + (js/queueMicrotask #(vswap! clock + 500))) + frame-type))}) + options {:dx 10 :dy 5 :steps 2 :settle-ms 5} + result (await (cmd/execute rtx #(command % options)))] + (t/is (= :completed (:outcome result))) + (t/is (= {:scale 1 :x 10 :y 5} @view (get-in result [:context :view]))) + (t/is (= 574 @clock)) + (if (= command camera/pan*) + (do + (t/is (= ::camera/pan (get-in result [:events 0 :command]))) + (t/is (= {:command/elapsed [74] + :renderer/call-elapsed [7 7] + :renderer/cache-call-elapsed [2 2] + :camera/finalization-to-full [33]} + (get-in result [:events 0 :metrics]))) + (t/is (= 74 (get-in result [:events 0 :trace :end-ms])))) + (t/is (= [] (:events result)))) + (vreset! clock 0) + (let [invalid (await (cmd/execute rtx #(command % (assoc options :steps 0))))] + (t/is (= :failed (:outcome invalid))) + (t/is (= ::cmd/invalid-arguments (:type (ex-data (:error invalid))))) + (t/is (= [] (:events invalid))) + (t/is (zero? @clock)))))) + (t/deftest ^:async failed-work-retains-earlier-observations (let [unhandled (atom []) observe #(swap! unhandled conj %)] @@ -158,7 +382,9 @@ (doseq [[input command expected] [[#(assoc-in % [:view :scale] 0) camera/render-sync* ::cmd/invalid-context] [#(assoc % :module #js {}) camera/render-sync* ::cmd/invalid-context] - [#(update % :hooks dissoc :render-sync) camera/render-sync* ::cmd/invalid-capabilities] + [#(update % :hooks dissoc :render-sync) camera/render-sync* ::cmd/invalid-context] + [#(update % :hooks dissoc :frame) camera/render-sync* ::cmd/invalid-context] + [#(assoc-in % [:hooks :sleep] 0) camera/render-sync* ::cmd/invalid-context] [identity #(reject-offset* % -1) ::cmd/invalid-arguments]]] (let [clock (volatile! 0) now-reads (volatile! 0) diff --git a/frontend/test/performance_tests/render_wasm/protocol_test.cljs b/frontend/test/performance_tests/render_wasm/protocol_test.cljs index c778d661a7..f17621553c 100644 --- a/frontend/test/performance_tests/render_wasm/protocol_test.cljs +++ b/frontend/test/performance_tests/render_wasm/protocol_test.cljs @@ -5,8 +5,9 @@ ;; Copyright (c) KALEIDOS SUBSIDIARY SL (ns performance-tests.render-wasm.protocol-test - "Tests drain, restore and interact with an injected clock and renderer. - Browser entry tests cover load and warm pan with a fake module." + "Tests render drains and camera sessions with a controllable clock. + A drain renders until Full completion. A camera session moves a view through + cached previews, a settling wait and final rendering to Full." (:require [app.common.render-wasm.wasm :as wasm] [benches.render-wasm.errors :as errors] @@ -14,16 +15,17 @@ [cljs.test :as t :include-macros true])) (defn- fake-clock - "Controllable ms clock. `advance!` moves it; tests drive time by hand." + "Returns a controllable clock in milliseconds. + `:now` reads it; `:advance!` adds the supplied duration." [start] (let [t (atom start)] {:now (fn [] @t) :advance! (fn [ms] (swap! t + ms) @t)})) (defn- drain-hooks - "Fake hooks driving `:render` through `script` (a vector of frame types - returned in order), recording observed flags in `calls`. `:frame` - advances 16 ms per rAF; `:sleep` advances the clock without yielding." + "Returns hooks that simulate rendering and record flags in `calls`. + `:render` returns the frame types from `script` in order. Each `:frame` adds + 16 ms to the clock; `:sleep` adds the requested wait. Both return Promises." [{:keys [clock script calls check]}] (let [remaining (atom (vec script))] {:now (:now clock) @@ -44,6 +46,31 @@ :set-view-start (fn [] nil) :set-view-end (fn [] nil)})) +(t/deftest ^:async completion-keeps-the-renderer-endpoint + (doseq [camera [false true]] + (let [clock (fake-clock 1000) + hooks (assoc (drain-hooks {:clock clock :script [] :calls (atom [])}) + :render (fn [_ _] + ((:advance! clock) 7) + (js/queueMicrotask #((:advance! clock) 500)) + wasm/FRAME_TYPE_FULL)) + result (await + (if camera + (-> (protocol/start-camera! {:hooks hooks :view {:scale 1 :x 0 :y 0}} + {:settle-ms 0}) + (protocol/animate-view! {:to {:scale 1 :x 10 :y 5} :steps 1}) + (protocol/finish-camera!)) + (protocol/drain hooks {:flags 0 :origin 1000 :immediate true}))) + end (if camera 1023 1007)] + (t/is (= end (:end-ms result))) + (t/is (= (+ end 500) ((:now clock)))) + (if camera + (do + (t/is (= 23 (:interact-ms result))) + (t/is (= 7 (:last-input-to-full-ms result))) + (t/is (= 7 (:time-to-full-ms result)))) + (t/is (= 7 (:full-ms result))))))) + (t/deftest immediate-full-reports-equal-boundaries (t/async done (let [clock (fake-clock 1000)