From 8eff42647906e93d647efe4404fb54a011a7a6e2 Mon Sep 17 00:00:00 2001 From: Miguel de Benito Delgado Date: Tue, 10 Nov 2026 22:34:43 +0100 Subject: [PATCH] :bug: Make renderer benchmark diagnostics bounded and resilient Retain build failure occurrences in failed manifests and preserve the manifest-write error alongside the original preparation failure. Bound diagnostic text, escape terminal controls, and keep Unicode pairs intact. Validate optional traces and partial evidence before encoding, with explicit diagnostics for unsupported or excessive data. Preserve completed phase evidence and owner cleanup when bridge encoding fails. Retain raw numeric observations, including NaN and infinities, and keep the newest log-tail evidence after escaping. AI-assisted-by: gpt-6.1-sol --- .../benches/render_wasm/browser/bridge.cljs | 43 ++++- .../benches/render_wasm/codec.cljs | 36 ++++ .../benches/render_wasm/errors.cljc | 171 ++++++++++++++---- .../render_wasm/node/cli/execution.cljs | 38 ++-- .../benches/render_wasm/node/log.cljs | 37 ++-- .../render_wasm/node/runner/build.cljs | 8 +- .../render_wasm/node/storage/artifacts.cljs | 1 + .../benches/render_wasm/report/format.cljs | 8 +- .../benches/render_wasm/runtime/commands.cljs | 8 + .../render_wasm/artifacts_test.cljs | 2 +- .../render_wasm/build_test.cljs | 15 +- .../render_wasm/cli_integration.cjs | 4 +- .../render_wasm/commands_test.cljs | 10 + .../render_wasm/errors_test.cljs | 56 ++++++ .../render_wasm/execution_test.cljs | 25 ++- .../render_wasm/lifecycle_test.cljs | 102 +++++++++++ .../render_wasm/log_test.cljs | 19 ++ 17 files changed, 502 insertions(+), 81 deletions(-) diff --git a/frontend/performance/benches/render_wasm/browser/bridge.cljs b/frontend/performance/benches/render_wasm/browser/bridge.cljs index 02857b3a07..208aaab464 100644 --- a/frontend/performance/benches/render_wasm/browser/bridge.cljs +++ b/frontend/performance/benches/render_wasm/browser/bridge.cljs @@ -1042,6 +1042,44 @@ evidence)) (.catch #(terminal-failure epoch % "attempt"))))))) +(defn- encodable-phase-prefix + [phases] + (reduce (fn [kept phase] + (try + (codec/encode-str phase) + (conj kept phase) + (catch :default _ (reduced kept)))) + [] phases)) + +(defn- encode-response + [epoch evidence] + (try + (codec/encode-str evidence) + (catch :default cause + (dispose-if-current! epoch) + (let [encoding (assoc (errors/evidence :bridge cause) :operation :encode-response) + original (when (= "failed" (:status evidence)) (errors/project-diagnostic evidence)) + recovered (if original + (assoc original :errors (conj (or (:errors original) + [(dissoc original :partial)]) encoding)) + encoding) + recovered (cond-> recovered + (seq (get-in evidence [:preparation :phases])) + (assoc :phases (encodable-phase-prefix (get-in evidence [:preparation :phases])))) + recovered (reduce (fn [out key] + (if (contains? evidence key) + (try + (codec/encode-str (get evidence key)) + (assoc out key (get evidence key)) + (catch :default _ + (if (= :phases key) + (assoc out :phases (encodable-phase-prefix (:phases evidence))) + out))) + out)) + recovered + [:preparation :phases :scene :effective-graphics])] + (t/encode-str (errors/fail-data recovered)))))) + (defn- encode-evidence "Encodes bridge evidence after timing and resolves failures as bridge failures. @@ -1058,11 +1096,10 @@ [promise] (let [epoch @owner-epoch*] (-> promise - (.then codec/encode-str) + (.then (partial encode-response epoch)) (.catch (fn [cause] (dispose-if-current! epoch) - (t/encode-str (errors/fail-data {:phase "bridge" - :message (errors/message-of cause "result encoding failed")}))))))) + (t/encode-str (errors/fail-data (errors/evidence :bridge cause)))))))) (defn prepare-scene-request "Prepares a scene from a Transit request and returns Transit evidence. diff --git a/frontend/performance/benches/render_wasm/codec.cljs b/frontend/performance/benches/render_wasm/codec.cljs index 80ee92d723..868514d21f 100644 --- a/frontend/performance/benches/render_wasm/codec.cljs +++ b/frontend/performance/benches/render_wasm/codec.cljs @@ -16,6 +16,42 @@ (declare equivalent?) +(defn check-value + "Checks optional transport data within depth and size limits. + + Args: + value: Trace or diagnostic partial data to validate. + + Returns: + The supplied value when traversal stays within depth 32, 100000 visited + values and 1048576 UTF-16 text units. Sequential collections have a finite + count. Numbers retain NaN and infinities. + + Throws: + An error for unsupported values or data that exceeds either limit." + [value] + (loop [pending (list [value 0]) + budget 100000 + text-budget 1048576] + (when (neg? text-budget) + (throw (ex-info "Transport data exceeds text limits" {:type ::data-limit}))) + (if-let [[item depth] (first pending)] + (do + (when (or (zero? budget) (> depth 32)) + (throw (ex-info "Transport data exceeds traversal limits" {:type ::data-limit}))) + (let [children (cond + (map? item) (mapcat (fn [[key value]] [[key (inc depth)] [value (inc depth)]]) item) + (or (and (sequential? item) (counted? item)) (set? item)) (map #(vector % (inc depth)) item) + (or (nil? item) (boolean? item) (number? item) (string? item) + (keyword? item) (symbol? item) (uuid? item) (inst? item)) nil + :else (throw (ex-info "Unsupported transport value" {:type ::unsupported-value})))] + (recur (concat children (rest pending)) (dec budget) + (- text-budget (cond + (string? item) (count item) + (or (keyword? item) (symbol? item)) (+ (count (name item)) (count (namespace item))) + :else 0))))) + value))) + (defn- equivalent-entry? "Finds a map key and compares its value, including keys that contain NaN." [other [k v]] diff --git a/frontend/performance/benches/render_wasm/errors.cljc b/frontend/performance/benches/render_wasm/errors.cljc index 8ac55169b4..c30d05be68 100644 --- a/frontend/performance/benches/render_wasm/errors.cljc +++ b/frontend/performance/benches/render_wasm/errors.cljc @@ -14,6 +14,9 @@ `evidence` and `describe-cause` produce diagnostics for saved records and Transit responses." + #?(:cljs (:require + [benches.render-wasm.codec :as codec] + [clojure.string :as str])) #?(:cljs (:require-macros [app.common.exceptions :as ex] [benches.render-wasm.errors]))) @@ -109,7 +112,8 @@ ([cause] (message-of cause "unknown failure")) ([cause fallback] - (or (ex/ignoring (ex-message cause)) + (or (ex/ignoring (let [message (ex-message cause)] + (when (string? message) message))) (ex/ignoring (str cause)) fallback))) @@ -148,22 +152,29 @@ (ex-info (message-of x) (merge data (ex-data x)) x) x)) + (declare combine) + (defn with-context "Returns an exception with `message` and added diagnostic context. New fields override existing fields; existing partial measurements win over earlier measurements in `data`. An exception with ex-data keeps its underlying cause. Other values become the cause." [cause message data] - (let [existing (ex-data cause) - context (cond-> (merge existing data) - (contains? data :partial) - (assoc :partial (merge (:partial data) (:partial existing))))] - (ex-info message context (if (some? existing) (ex-cause cause) cause)))) + (let [existing (ex-data cause) + malformed (and (contains? existing :partial) (not (map? (:partial existing))) + (map? (:partial data))) + source (if malformed (combine [{:error cause :partial (:partial existing)}]) cause) + context (cond-> (merge (ex-data source) data) + (contains? data :partial) + (assoc :partial (if (map? (:partial data)) + (merge (:partial data) (when (map? (:partial existing)) (:partial existing))) + (:partial data))))] + (ex-info message context (if (and (some? existing) (not malformed)) (ex-cause cause) source)))) (defn- merge-error-context [outer inner] (cond-> (merge outer inner) - (or (:partial outer) (:partial inner)) + (and (map? (:partial outer)) (map? (:partial inner))) (assoc :partial (merge (:partial outer) (:partial inner))))) (defn- get-error-collection @@ -260,7 +271,44 @@ (and (>= nxt 0xDC00) (<= nxt 0xDFFF)))) (subs cut 0 (dec max-chars)) cut))))) - unrenderable-value)) + (subs unrenderable-value 0 (min max-chars (count unrenderable-value))))) + + (defn terminal-text + "Returns bounded text with terminal controls escaped. + + Args: + value: Value to render as text. + max-chars: Positive limit in UTF-16 units after escaping. + + Returns: + Text with C0, DEL and C1 controls represented as Unicode escapes." + [value max-chars] + (bounded-text + (or (ex/ignoring + (str/replace (bounded-text value max-chars) #"[\x00-\x1f\x7f-\x9f]" + (fn [character] + (str "\\u" (.padStart (.toString (.charCodeAt character 0) 16) 4 "0"))))) + unrenderable-value) + max-chars)) + + (defn format-value + "Returns a bounded, readable value with terminal controls escaped. + + Args: + value: Value to print. Strings use JSON quoting. + max-chars: Positive limit in UTF-16 units after escaping. + + Returns: + Readable text, or fallback text when printing fails." + [value max-chars] + (terminal-text + (or (ex/ignoring + (if (string? value) + (js/JSON.stringify (bounded-text value max-chars)) + (binding [*print-level* 8 *print-length* 32] + (pr-str value)))) + unrenderable-value) + max-chars)) (defn project-context "Returns bounded identity, process and ownership details. @@ -287,19 +335,7 @@ (string? (:signal data)) (assoc :signal (bounded-text (:signal data) 1024)) (string? (:endpoint data)) (assoc :endpoint (bounded-text (:endpoint data) 1024)))) - (defn project-diagnostic - "Returns the diagnostic fields of an execution envelope. - - Args: - evidence: Plain execution evidence. - - Returns: - Failure status, location, message and available diagnostic details." - [evidence] - (cond-> (merge (select-keys evidence [:status :phase :message :cause :partial :reason :deadline-exceeded - :operation :errors]) - (project-context evidence)) - (string? (:path evidence)) (assoc :path (bounded-text (:path evidence) 1024)))) + (declare project-diagnostic) (defn- sanitize-cause-value [value] @@ -311,7 +347,11 @@ (bounded-text value max-cause-chars) :else - (bounded-text (or (ex/ignoring (pr-str value)) unrenderable-value) max-cause-chars))) + (bounded-text (or (ex/ignoring + (binding [*print-level* 8 *print-length* 32] + (pr-str value))) + unrenderable-value) + max-cause-chars))) (defn- describe-cause-level [cause] @@ -322,7 +362,7 @@ (string? message) message (string? cause) cause (nil? cause) "unknown failure" - :else (pr-str cause)) + :else (binding [*print-level* 8 *print-length* 32] (pr-str cause))) out {:message (sanitize-cause-value text)}] (if (map? data) (reduce (fn [m k] @@ -342,14 +382,15 @@ (or (ex/ignoring (loop [current cause depth 0 - acc []] - (if (or (nil? current) (>= depth evidence-cause-depth)) + acc [] + seen #{}] + (if (or (nil? current) (contains? seen current) (>= depth evidence-cause-depth)) (if (seq acc) acc [{:message "unknown failure"}]) (let [level (describe-cause-level current) next (ex/ignoring (ex-cause current))] - (recur next (inc depth) (conj acc level)))))) + (recur next (inc depth) (conj acc level) (conj seen current)))))) [{:message unrenderable-cause-text}])) (defn- diagnostic-data @@ -358,9 +399,9 @@ (cond-> (merge (project-context (ex-data cause)) (select-keys (ex-data cause) [:operation]) {:phase (if (keyword? phase) (name phase) (str phase)) - :message (message-of cause) + :message (bounded-text (message-of cause) 1024) :cause (describe-cause cause)}) - partial (assoc :partial partial) + (contains? (ex-data cause) :partial) (assoc :partial partial) (string? (:path (ex-data cause))) (assoc :path (bounded-text (:path (ex-data cause)) 1024))))) @@ -386,6 +427,74 @@ partial (assoc :partial partial) (string? path) (assoc :path (bounded-text path 1024)))) entries))] - (cond-> (diagnostic-data phase cause) - projected (assoc :errors projected) - (some :unresolved-process projected) (assoc :unresolved-process true)))))) + (project-diagnostic + (cond-> (diagnostic-data phase cause) + projected (assoc :errors projected) + (map? (:partial (first projected))) (assoc :partial (:partial (first projected))) + (some :unresolved-process projected) (assoc :unresolved-process true))))) + + (defn- partial-encoding-error + [path cause] + {:phase "diagnostic-encoding" :operation :encode-diagnostic + :path (format-value path 1024) + :message "Diagnostic partial evidence cannot cross Transit" + :cause (describe-cause cause)}) + + (defn- project-partial + [partial] + (if (map? partial) + (reduce-kv (fn [[kept rejected] key value] + (try + (codec/check-value {key value}) + (codec/encode-str {key value}) + [(assoc kept key value) rejected] + (catch :default cause + [kept (conj rejected (partial-encoding-error [:partial key] cause))]))) + [{} []] + partial) + [nil [(partial-encoding-error [:partial] + (ex-info "Diagnostic partial evidence must be a map" {}))]])) + + (defn- project-entry + [entry] + (let [[partial rejected] (when (contains? entry :partial) (project-partial (:partial entry))) + projected (cond-> (project-context entry) + (contains? #{"failed" "stale"} (:status entry)) (assoc :status (:status entry)) + (boolean? (:deadline-exceeded entry)) (assoc :deadline-exceeded (:deadline-exceeded entry)) + (keyword? (:operation entry)) (assoc :operation (:operation entry)) + (contains? entry :phase) (assoc :phase (bounded-text (:phase entry) 1024)) + (contains? entry :message) (assoc :message (bounded-text (:message entry) 1024)) + (contains? entry :reason) (assoc :reason (sanitize-cause-value (:reason entry))) + (contains? entry :cause) + (assoc :cause (mapv (fn [level] + (reduce-kv (fn [out key value] + (assoc out key (sanitize-cause-value value))) + {} (select-keys level [:message :fn :code :type :hint]))) + (take evidence-cause-depth (:cause entry)))) + (some? partial) (assoc :partial partial) + (string? (:path entry)) (assoc :path (bounded-text (:path entry) 1024)))] + [projected rejected])) + + (defn project-diagnostic + "Returns bounded diagnostic fields and representable partial evidence. + + Args: + evidence: Execution evidence with optional failure details. + + Returns: + Diagnostic fields with bounded text. Partial entries that cannot + cross Transit produce ordered encoding diagnostics. Representable + partial values retain their raw numeric values." + [evidence] + (let [alias? (and (seq (:errors evidence)) (contains? evidence :partial) + (identical? (:partial evidence) (:partial (first (:errors evidence))))) + [projected rejected] (project-entry (if alias? (dissoc evidence :partial) evidence)) + entries (mapv project-entry (:errors evidence)) + rejected (into (vec rejected) (mapcat second) entries) + errors (mapv first entries) + projected (cond-> projected + (and alias? (contains? (first errors) :partial)) + (assoc :partial (:partial (first errors))))] + (cond-> projected + (seq errors) (assoc :errors errors) + (seq rejected) (assoc :errors (into (if (seq errors) errors [(dissoc projected :partial)]) rejected))))))) diff --git a/frontend/performance/benches/render_wasm/node/cli/execution.cljs b/frontend/performance/benches/render_wasm/node/cli/execution.cljs index c7acb84be5..80cd213271 100644 --- a/frontend/performance/benches/render_wasm/node/cli/execution.cljs +++ b/frontend/performance/benches/render_wasm/node/cli/execution.cljs @@ -103,16 +103,10 @@ [finished] (doseq [[index cause] (map-indexed vector (:errors finished))] (let [data (ex-data cause) - context (mapv (fn [[key value]] - [key (if (string? value) - (errors/bounded-text (js/JSON.stringify value) 1024) - value)]) + context (mapv (fn [[key value]] [key (errors/format-value value 1024)]) (errors/project-context data)) path (when-let [path (:path data)] - (errors/bounded-text (if (string? path) - (js/JSON.stringify path) - (pr-str path)) - 1024)) + (errors/format-value path 1024)) validation (some-> (::sm/explain data) sm/simplify) entries (:errors (errors/evidence (or (:phase data) :execution) cause)) alias? (and (seq entries) @@ -126,18 +120,22 @@ (rest entries) entries)] (log/error {:message (errors/message-of cause) - :fields (into (filterv (comp some? second) - [[:type (:type data)] [:cause-type (:cause-type data)] - [:path path] - [:role (:role data)] [:operation (:operation data)] - [:phase (:phase data)] [:build (:build-id data)] - [:reason (:reason data)] [:manifest-error (:manifest-error data)] - [:baseline (:baseline data)] [:candidate (:candidate data)] - [:features (:features data)] - [:count (:count data)] [:max-features (:max-features data)] - [:validation validation]]) + :fields (into (mapv (fn [[key value]] + [key (if (string? value) + (errors/terminal-text value 1024) + (errors/format-value value 1024))]) + (filterv (comp some? second) + [[:type (:type data)] [:cause-type (:cause-type data)] + [:path path] + [:role (:role data)] [:operation (:operation data)] + [:phase (:phase data)] [:build (:build-id data)] + [:reason (:reason data)] [:manifest-error (:manifest-error data)] + [:baseline (:baseline data)] [:candidate (:candidate data)] + [:features (:features data)] + [:count (:count data)] [:max-features (:max-features data)] + [:validation validation]])) (concat context - (map #(vector :difference (:field %)) (:mismatches data)) + (map #(vector :difference (errors/format-value (:field %) 1024)) (:mismatches data)) (when entry-context [[:error-context entry-context]]) (map #(vector :error (format/format-error-entry %)) (take 8 entries)) (when (> (count entries) 8) @@ -152,7 +150,7 @@ stream (or (:stderr local) (.-stderr js/process))] (.write ^js stream (str "Could not report benchmark failure: " - (subs message 0 (min 1024 (count message))) "\n"))))) + (errors/terminal-text message 1024) "\n"))))) (defn- finish "Print the optional report and errors without retrying failed report writes." diff --git a/frontend/performance/benches/render_wasm/node/log.cljs b/frontend/performance/benches/render_wasm/node/log.cljs index 4acdac0fcf..1db99a5f80 100644 --- a/frontend/performance/benches/render_wasm/node/log.cljs +++ b/frontend/performance/benches/render_wasm/node/log.cljs @@ -112,14 +112,20 @@ :debug (= :debug console-level) :info (contains? #{:info :debug} console-level) true) - stream (if (= :result level) stdout stderr)] + stream (if (= :result level) stdout stderr) + display (if (contains? #{:debug :info :warn} level) + (->> (str/split-lines (errors/bounded-text text 1024)) + (map #(errors/terminal-text % 1024)) + (str/join "\n") + (#(errors/bounded-text % 1024))) + text)] (when enabled (.write ^js stream (str (if (= :result level) - text - (render level text (color? stream color))) "\n"))) + display + (render level display (color? stream color))) "\n"))) (when failure (if (= :error level) - (.write ^js stderr (str "Could not append log: " *log-path* "\n")) + (.write ^js stderr (str "Could not append log: " (errors/terminal-text *log-path* 1024) "\n")) (throw failure))))) (defn result [text] (write :result text)) @@ -136,10 +142,19 @@ (let [size (.-size (fs/fstatSync fd)) length (min size 8192) buffer (js/Buffer.alloc length) - read (fs/readSync fd buffer 0 length (- size length))] - (->> (str/split-lines (.toString buffer "utf8" 0 read)) - (remove str/blank?) - (take-last 20))) + read (fs/readSync fd buffer 0 length (- size length)) + text (->> (str/split-lines (.toString buffer "utf8" 0 read)) + (remove str/blank?) + (take-last 20) + (map #(errors/terminal-text % (* 6 8192))) + (str/join "\n")) + start (max 0 (- (count text) 8192)) + first (.charCodeAt text start) + start (if (and (pos? start) (<= 0xDC00 first 0xDFFF) + (<= 0xD800 (.charCodeAt text (dec start)) 0xDBFF)) + (inc start) + start)] + (str/split-lines (subs text start))) (finally (fs/closeSync fd))))))) (defn error @@ -148,13 +163,13 @@ (let [tail-path (or tail-log *log-path*) fields (cond-> (vec fields) (and *log-path* (not (some #(= :log (first %)) fields))) - (conj [:log *log-path*]) + (conj [:log (errors/terminal-text *log-path* 1024)]) (and tail-log (not= tail-log *log-path*)) - (conj [:tail-log tail-log])) + (conj [:tail-log (errors/terminal-text tail-log 1024)])) width (reduce max 0 (map #(count (name (first %))) fields)) tail (when tail? (get-tail tail-path))] (write :error - (str "✖ " message + (str "✖ " (errors/terminal-text message 1024) (apply str (map (fn [[key value]] (let [label (name key)] diff --git a/frontend/performance/benches/render_wasm/node/runner/build.cljs b/frontend/performance/benches/render_wasm/node/runner/build.cljs index d6e962ec50..ca7697354e 100644 --- a/frontend/performance/benches/render_wasm/node/runner/build.cljs +++ b/frontend/performance/benches/render_wasm/node/runner/build.cljs @@ -196,7 +196,7 @@ (catch :default cause (let [build @build-ref context (errors/project-context (ex-data cause)) - failure (merge context {:phase @phase :cause (errors/describe-cause cause)}) + failure (errors/evidence @phase cause) saved (when (= :building (get-in build [:manifest :status])) (attempt :catch-fatal (artifacts/write-manifest @@ -208,5 +208,9 @@ :reason (str/join " -> " (keep :message (:cause failure)))}) manifest-error (assoc :manifest-error manifest-error))] (throw (if manifest-error - (errors/fatal-error "renderer build preparation failed" data cause) + (errors/fatal-error + "renderer build preparation failed" data + (errors/combine [{:error cause} + {:phase "storage" :operation :write-manifest + :path (:manifest-path build) :error saved}])) (ex-info "renderer build preparation failed" data cause))))))))) diff --git a/frontend/performance/benches/render_wasm/node/storage/artifacts.cljs b/frontend/performance/benches/render_wasm/node/storage/artifacts.cljs index 0e493674c0..61e53643d2 100644 --- a/frontend/performance/benches/render_wasm/node/storage/artifacts.cljs +++ b/frontend/performance/benches/render_wasm/node/storage/artifacts.cljs @@ -29,6 +29,7 @@ [:created-at :string] [:updated-at :string] [:environment {:optional true} [:map-of :string :string]] + [:failure {:optional true} errors/schema:diagnostic] [:functional :map] [:provenance :map]]) diff --git a/frontend/performance/benches/render_wasm/report/format.cljs b/frontend/performance/benches/render_wasm/report/format.cljs index 16c52bfc1d..d586167e30 100644 --- a/frontend/performance/benches/render_wasm/report/format.cljs +++ b/frontend/performance/benches/render_wasm/report/format.cljs @@ -62,13 +62,11 @@ (defn- quoted-detail [value] - (errors/bounded-text (js/JSON.stringify value) 1024)) + (errors/format-value value 1024)) (defn- identifier->text [value] - (if (string? value) - (quoted-detail value) - (errors/bounded-text (pr-str value) 1024))) + (errors/format-value value 1024)) (def ^:private process-detail-keys [:command :pid :pgid :signals :profile-path :fatal :unresolved-process]) @@ -82,7 +80,7 @@ Returns: Bounded error text and process details when a group may still be running." [{:keys [phase operation message path] :as entry}] - (str (when operation (str (pr-str operation) " ")) + (str (when operation (str (errors/format-value operation 1024) " ")) (quoted-detail phase) (when (some? message) (str ": " (quoted-detail message))) (when path (str "\n Path " (quoted-detail path))) diff --git a/frontend/performance/benches/render_wasm/runtime/commands.cljs b/frontend/performance/benches/render_wasm/runtime/commands.cljs index 5a52793686..6fa8f86ecc 100644 --- a/frontend/performance/benches/render_wasm/runtime/commands.cljs +++ b/frontend/performance/benches/render_wasm/runtime/commands.cljs @@ -26,6 +26,7 @@ (:require-macros [benches.render-wasm.runtime.commands]) (:require [app.common.schema :as sm] + [benches.render-wasm.codec :as codec] [benches.render-wasm.declarations :as decl] [benches.render-wasm.errors :as errors :refer [attempt failure?]])) @@ -159,6 +160,13 @@ (defn- finish-invocation [{:keys [measured input output record] :as invocation}] (check-output input output) + (when (contains? invocation :trace) + (try + (codec/check-value (:trace invocation)) + (codec/encode-str (:trace invocation)) + (catch :default cause + (throw (ex-info "command trace cannot cross Transit" + {:type ::invalid-trace} cause))))) (when measured (record (select-keys invocation [:command :metrics :trace]))) output) diff --git a/frontend/test/performance_tests/render_wasm/artifacts_test.cljs b/frontend/test/performance_tests/render_wasm/artifacts_test.cljs index 7dce7361c6..4e4efbf696 100644 --- a/frontend/test/performance_tests/render_wasm/artifacts_test.cljs +++ b/frontend/test/performance_tests/render_wasm/artifacts_test.cljs @@ -125,7 +125,7 @@ log "renderer compilation failed\n"] (fs/appendFileSync (:log-path failed) log "utf8") (artifacts/write-manifest failed (assoc (:manifest failed) :status :failed - :failure {:stage :renderer :message "compile failed"})) + :failure {:phase "renderer" :message "compile failed"})) (doseq [build [building failed]] (t/is (= ::artifacts/not-ready (:type (ex-data (failure #(artifacts/load-build @temporary-root (:id build)))))))) diff --git a/frontend/test/performance_tests/render_wasm/build_test.cljs b/frontend/test/performance_tests/render_wasm/build_test.cljs index 1975ab86aa..97e0d4f732 100644 --- a/frontend/test/performance_tests/render_wasm/build_test.cljs +++ b/frontend/test/performance_tests/render_wasm/build_test.cljs @@ -232,7 +232,9 @@ (t/is (= "" (:log created))) (t/is (str/includes? (:log observation) "Renderer compiling\n")) (t/is (= :failed (:status manifest))) - (t/is (= :renderer (get-in manifest [:failure :phase]))) + (t/is (= "renderer" (get-in manifest [:failure :phase]))) + (t/is (= "Command exited unsuccessfully" (get-in manifest [:failure :message]))) + (t/is (= [:run-command] (mapv :operation (get-in manifest [:failure :errors])))) (t/is (= :process-exit (get-in manifest [:failure :cause 0 :type]))) (t/is (= {:sha nil :dirty nil} (get-in manifest [:provenance :git]))) (t/is (str/includes? log "compiler stdout before failure\n")) @@ -251,10 +253,15 @@ (let [cause (await (rejected (build/prepare {:root (frontend-root) :build-timeout-ms 10000 :on-created record-created}))) - data (ex-data cause)] + data (ex-data cause) + entries (errors/get-errors cause)] (t/is (errors/fatal? cause)) (t/is (string? (:manifest-error data))) - (t/is (= :process-exit (:type (ex-data (ex-cause cause)))))))) + (t/is (= :process-exit (:type (ex-data (:error (first entries)))))) + (t/is (= 2 (count entries))) + (t/is (= :write-manifest (:operation (second entries)))) + (t/is (= (:manifest-path (retained-build cause)) (:path (second entries)))) + (t/is (str/includes? (errors/message-of (:error (second entries))) "ENOENT"))))) done))) (t/deftest timed-out-lock-holder-retains-its-attempt-and-retry-gets-a-new-id @@ -275,7 +282,7 @@ (t/is (= :process-timeout (:type (ex-data (ex-cause cause))))) (t/is (= (:id retained) (:id manifest))) (t/is (= :failed (:status manifest))) - (t/is (= :renderer (get-in manifest [:failure :phase]))) + (t/is (= "renderer" (get-in manifest [:failure :phase]))) (t/is (= :process-timeout (get-in manifest [:failure :cause 0 :type]))) (t/is (= "held" (fs/readFileSync (path/join (:renderer-dir retained) "lock-acquired.txt") "utf8"))) (t/is (str/includes? log "compiler lock acquired\n")) diff --git a/frontend/test/performance_tests/render_wasm/cli_integration.cjs b/frontend/test/performance_tests/render_wasm/cli_integration.cjs index 149180eadf..648ac8be43 100644 --- a/frontend/test/performance_tests/render_wasm/cli_integration.cjs +++ b/frontend/test/performance_tests/render_wasm/cli_integration.cjs @@ -750,7 +750,7 @@ test( assert.equal(manifest.get(k("id")), id); assert.equal(manifest.get(k("status")).toString(), ":failed"); const failure = manifest.get(k("failure")); - assert.equal(failure.get(k("phase")).toString(), ":renderer"); + assert.equal(failure.get(k("phase")), "renderer"); assert.equal(failure.get(k("exit-code")), 23); assert.equal(failure.get(k("command")), fixture.compiler); assert.equal( @@ -807,7 +807,7 @@ test( ); const failure = manifest.get(k("failure")); assert.equal(manifest.get(k("status")).toString(), ":failed"); - assert.equal(failure.get(k("phase")).toString(), ":identity"); + assert.equal(failure.get(k("phase")), "identity"); assert.equal( failure.get(k("cause"))[0].get(k("type")).toString(), ":benches.render-wasm.identity/mismatch", diff --git a/frontend/test/performance_tests/render_wasm/commands_test.cljs b/frontend/test/performance_tests/render_wasm/commands_test.cljs index b236a684ef..a2b60587bd 100644 --- a/frontend/test/performance_tests/render_wasm/commands_test.cljs +++ b/frontend/test/performance_tests/render_wasm/commands_test.cljs @@ -178,6 +178,16 @@ (t/is (= [::camera/render-sync ::camera/render-sync] (mapv :command (:events result)))))) +(t/deftest ^:async invalid-trace-stops-the-command-and-retains-earlier-measurements + (doseq [trace [{:handle (fn [] nil)} (repeat 0) (nth (iterate vector 0) 40)]] + (let [run (fn [rtx] + (async-work* rtx (fn [rtx complete _] (complete rtx {:trace trace})))) + result (await (cmd/execute (context (volatile! 0)) + (fn [rtx] (.then (camera/render-sync* rtx) run))))] + (t/is (= :failed (:outcome result))) + (t/is (= "command trace cannot cross Transit" (errors/message-of (:error result)))) + (t/is (= [::camera/render-sync] (mapv :command (:events result))))))) + (t/deftest ^:async async-completion-retains-invalid-numeric-observations (let [result (await (cmd/execute diff --git a/frontend/test/performance_tests/render_wasm/errors_test.cljs b/frontend/test/performance_tests/render_wasm/errors_test.cljs index 70752d966e..ef300c168e 100644 --- a/frontend/test/performance_tests/render_wasm/errors_test.cljs +++ b/frontend/test/performance_tests/render_wasm/errors_test.cljs @@ -183,6 +183,62 @@ (t/is (= "unrenderable value" (get-in decoded [0 :cause 0 :fn]))) (t/is (= "unrenderable cause" (get-in decoded [1 :cause 0 :message])))))) +(t/deftest diagnostic-text-is-bounded-without-splitting-surrogate-pairs + (let [message (str (apply str (repeat 1023 "x")) "😀" "tail") + cause (ex-info message {:command message}) + data (-> (errors/evidence :main cause) transit/encode-str transit/decode-str) + hostile (js/Error.)] + (set! (.-message hostile) #js {:toString #(throw (js/Error. "cannot print"))}) + (t/is (= (apply str (repeat 1023 "x")) (:message data))) + (t/is (<= (count (:command data)) 1024)) + (t/is (sm/validate errors/schema:diagnostic (errors/evidence :main hostile))))) + +(t/deftest malformed-partial-data-retains-the-failure-and-representable-evidence + (let [cycle #js {}] + (aset cycle "self" cycle) + (doseq [invalid [(fn [] nil) cycle (js/AbortController.)] + composed? [false true]] + (let [failure (ex-info "phase failed" {:partial {:safe {:elapsed [0 js/Infinity js/NaN]} + :handle invalid}}) + failure (if composed? + (errors/combine [{:error failure} {:error (js/Error. "cleanup failed")}]) + failure) + data (errors/evidence :main failure) + wire (try + (-> data transit/encode-str transit/decode-str) + (catch :default _ nil))] + (t/is (= "phase failed" (:message wire))) + (t/is (= "phase failed" (get-in wire [:cause 0 :message]))) + (t/is (= 0 (get-in wire [:partial :safe :elapsed 0]))) + (t/is (= js/Infinity (get-in wire [:partial :safe :elapsed 1]))) + (t/is (js/Number.isNaN (get-in wire [:partial :safe :elapsed 2]))) + (t/is (= 1 (count (filter #(= :encode-diagnostic (:operation %)) (:errors wire))))))))) + +(t/deftest unbounded-partial-data-produces-an-encoding-diagnostic + (let [data (errors/evidence :main (ex-info "phase failed" {:partial {:trace (repeat 0)}})) + wire (-> data transit/encode-str transit/decode-str)] + (t/is (= "phase failed" (:message wire))) + (t/is (some #(= :encode-diagnostic (:operation %)) (:errors wire))))) + +(t/deftest malformed-partial-shapes-and-cyclic-causes-produce-portable-diagnostics + (doseq [partial [nil false 42 "partial"]] + (let [data (errors/evidence :main (ex-info "phase failed" {:partial partial}))] + (t/is (sm/validate errors/schema:diagnostic data)) + (t/is (some #(= :encode-diagnostic (:operation %)) (:errors data))))) + (let [cycle (js/Error. "cyclic failure")] + (set! (.-cause cycle) cycle) + (let [data (-> (errors/evidence :main cycle) transit/encode-str transit/decode-str)] + (t/is (= "cyclic failure" (:message data))) + (t/is (<= (count (:cause data)) 3))))) + +(t/deftest malformed-optional-metadata-retains-a-valid-failure-diagnostic + (doseq [flag [42 (fn [] nil)]] + (let [cause (errors/combine [{:error (ex-info "main failed" {:deadline-exceeded flag})}]) + data (errors/evidence :main cause) + wire (try (-> data transit/encode-str transit/decode-str) (catch :default _ nil))] + (t/is (= "main failed" (:message wire))) + (t/is (sm/validate errors/schema:diagnostic wire))))) + (t/deftest non-finite-failure-details-cross-transit-as-numbers (let [failure (ex-info "bad measurement" {:code js/NaN :hint js/Infinity :type js/-Infinity}) decoded (-> (errors/evidence :render failure) transit/encode-str transit/decode-str) diff --git a/frontend/test/performance_tests/render_wasm/execution_test.cljs b/frontend/test/performance_tests/render_wasm/execution_test.cljs index a2e65445c1..53e4c26264 100644 --- a/frontend/test/performance_tests/render_wasm/execution_test.cljs +++ b/frontend/test/performance_tests/render_wasm/execution_test.cljs @@ -304,6 +304,25 @@ (t/is (str/includes? @(:errors local) (or message (errors/message-of cause)))) (t/is (= 1 (count (re-seq #"✖" @(:errors local)))))))) +(t/deftest ^:async failure-text-escapes-controls-and-survives-a-throwing-printer + (let [local (capture) + hostile (reify IPrintWithWriter + (-pr-writer [_ _ _] (throw (js/Error. "cannot print path")))) + failure (ex-info (str "work failed\n\u001b" (apply str (repeat 2000 "x"))) + {:path hostile :reason "reason\u0007\u007f\u0085" + :mismatches [{:field [:metric (keyword "metric" "unsafe\u001b")]}]})] + (t/is (= 1 (await (execution/execute + (resolved "help" {:topic nil}) + {"help" (fn [_ _] (throw failure))} local)))) + (t/is (str/includes? @(:errors local) "work failed")) + (t/is (str/includes? @(:errors local) "unrenderable value")) + (t/is (str/includes? @(:errors local) "\\u001b")) + (t/is (str/includes? @(:errors local) "\\u0007")) + (t/is (every? #(<= (count %) 1100) (str/split-lines @(:errors local)))) + (t/is (every? #(let [code (.charCodeAt % 0)] + (or (= code 10) (and (>= code 32) (or (< code 127) (> code 159))))) + (seq @(:errors local)))))) + (t/deftest ^:async error-reporting-failure-uses-a-bounded-fallback (doseq [[code expected] [[1 1] [130 130]]] (let [local (capture) @@ -311,13 +330,15 @@ broken #js {:write (fn [text] (if (str/starts-with? text "Could not report") (swap! fallback conj text) - (throw (js/Error. (apply str (repeat 2000 "x"))))))}] + (throw (js/Error. (str "\u001b" (apply str (repeat 1100 "😀")))))))}] (t/is (= expected (await (execution/execute (resolved "help" {:topic nil}) {"help" (fn [_ _] {:exit-code code :log-path nil :errors [(js/Error. "work failed")]})} (assoc local :stderr broken))))) (t/is (= 1 (count @fallback))) - (t/is (< (count (first @fallback)) 1100)))) + (t/is (< (count (first @fallback)) 1100)) + (t/is (str/includes? (first @fallback) "\\u001b")) + (t/is (not (re-find #"[\uD800-\uDBFF](?![\uDC00-\uDFFF])" (first @fallback)))))) (let [broken #js {:write #(throw (js/Error. "closed"))}] (t/is (= 1 (await (execution/execute (resolved "help" {:topic nil}) diff --git a/frontend/test/performance_tests/render_wasm/lifecycle_test.cljs b/frontend/test/performance_tests/render_wasm/lifecycle_test.cljs index 3d02923a7f..8a1a8641a5 100644 --- a/frontend/test/performance_tests/render_wasm/lifecycle_test.cljs +++ b/frontend/test/performance_tests/render_wasm/lifecycle_test.cljs @@ -729,6 +729,108 @@ (finally (cleanup))))))) +(t/deftest ^:async diagnostic-encoding-keeps-phase-evidence-and-releases-its-owner + (await + (with-entry-env + (^:async fn [cleanup] + (try + (register-phase-case + {:params {:count 2} :context :reuse} + (fn [rtx] + (-> (camera/render-sync* rtx) + (.then (fn [_] + (throw (ex-info "main fixture failed" + {:command "fixture" :path "scene.transit" + :partial {:safe {:elapsed [0 js/Infinity js/NaN]} + :handle (fn [] nil)}}))))))) + (let [request (transit/encode-str (assoc (transit/decode-str (scene-args 7 {})) + :preparation-id "encoding")) + prepared (transit/decode-str (await (browser/prepare-scene-request request))) + response (await (browser/run-prepared (transit/encode-str {:preparation-id "encoding"}))) + evidence (transit/decode-str response) + attempt (measurement/attempt :rects/lifecycle "encoding" false evidence) + saved (-> (result/create-run + {:run-id "encoding" :started-at "start" + :plan {:cases [(load-case)] :warmups 0 :repetitions 1} + :metadata {:git {:sha nil :dirty nil} :build {:functional {}} + :environment {} :scored? true}}) + (result/record-preparation (assoc (:preparation prepared) :warmup? false)) + (result/record-attempt attempt) + (result/record-case-outcome :rects/lifecycle {:outcome :failed}) + (result/finish-run "end" {:reason :failed}) + result/encode result/decode)] + (t/is (= "failed" (:status evidence))) + (t/is (= "main" (:phase evidence))) + (t/is (= "main fixture failed" (:message evidence))) + (t/is (= "main fixture failed" (get-in evidence [:cause 0 :message]))) + (t/is (= "fixture" (:command evidence))) + (t/is (= "scene.transit" (:path evidence))) + (t/is (= [::camera/render-sync] (mapv :command (get-in evidence [:phases 0 :events])))) + (t/is (= (:phases evidence) (:phases attempt))) + (t/is (= (:preparation prepared) (:preparation evidence))) + (t/is (js/Number.isNaN (get-in saved [:attempts 0 :partial :safe :elapsed 2]))) + (t/is (some #(= :encode-diagnostic (:operation %)) (get-in saved [:attempts 0 :failure :errors]))) + (t/is (= "invalid-args" + (:phase (transit/decode-str + (await (browser/run-prepared (transit/encode-str {:preparation-id "encoding"})))))))) + (register-phase-case {:params {:count 2}} camera/render-sync*) + (t/is (= "ok" (:status (transit/decode-str (await (browser/load-scene (scene-args 8 {}))))))) + (finally + (cleanup))))))) + +(t/deftest ^:async malformed-preparation-partial-keeps-the-original-failure-and-setup + (await + (with-entry-env + (^:async fn [cleanup] + (try + (register-phase-case + {:params {:count 2} + :preparation {:callback (fn [rtx] + (.then (camera/render-sync* rtx) + (fn [_] (throw (ex-info "preparation failed" {:partial 42})))))}} + camera/render-sync*) + (let [request (transit/encode-str (assoc (transit/decode-str (scene-args 7 {})) + :preparation-id "malformed")) + data (transit/decode-str (await (browser/prepare-scene-request request)))] + (t/is (= "preparation failed" (:message data))) + (t/is (= "preparation" (:phase data))) + (t/is (= [:preparation] (mapv :phase (:phases data)))) + (t/is (number? (get-in data [:partial :setup :upload-ms]))) + (t/is (some #(= :encode-diagnostic (:operation %)) (:errors data))) + (t/is (= "invalid-args" + (:phase (transit/decode-str + (await (browser/run-prepared (transit/encode-str {:preparation-id "malformed"})))))))) + (finally (cleanup))))))) + +(t/deftest ^:async response-encoding-failure-retains-completed-preparation-work + (await + (with-entry-env + (^:async fn [cleanup] + (let [create-element (.-createElement js/document)] + (try + (set! (.-createElement js/document) + (fn [_] + (let [canvas (fake-canvas 1 nil) + gl (.getContext canvas "webgl2")] + (aset gl "drawingBufferWidth" (fn [] nil)) + canvas))) + (let [request (transit/encode-str (assoc (transit/decode-str (scene-args 7 {})) + :preparation-id "fallback")) + data (transit/decode-str (await (browser/prepare-scene-request request)))] + (t/is (= "failed" (:status data))) + (t/is (= :encode-response (:operation data))) + (t/is (= [:preparation] (mapv :phase (:phases data)))) + (t/is (= :completed (get-in data [:phases 0 :outcome]))) + (t/is (seq (:cause data))) + (t/is (= "invalid-args" + (:phase (transit/decode-str + (await (browser/run-prepared (transit/encode-str {:preparation-id "fallback"})))))))) + (set! (.-createElement js/document) create-element) + (t/is (= "ok" (:status (transit/decode-str (await (browser/load-scene (scene-args 8 {}))))))) + (finally + (set! (.-createElement js/document) create-element) + (cleanup)))))))) + (t/deftest ^:async phase-failure-keeps-raw-evidence-and-stops-the-context (doseq [context [:fresh :reuse] failed-phase [:preparation :main :reset]] diff --git a/frontend/test/performance_tests/render_wasm/log_test.cljs b/frontend/test/performance_tests/render_wasm/log_test.cljs index 599bf9f86c..d12468acc7 100644 --- a/frontend/test/performance_tests/render_wasm/log_test.cljs +++ b/frontend/test/performance_tests/render_wasm/log_test.cljs @@ -106,6 +106,25 @@ (fs/readFileSync parent "utf8"))) (t/is (= "child success\nchild failure\n" (fs/readFileSync child "utf8"))))) +(t/deftest console-diagnostics-escape-controls-and-retain-the-log-evidence + (let [file (path/join @temporary-root "controls.log") + output (capture) + message (str "work failed\u001b\u0007" (apply str (repeat 2000 "x")))] + (log/configure {:color :never :stderr (:stream output)}) + (binding [log/*log-path* file] + (log/warn message)) + (t/is (= (str message "\n") (fs/readFileSync file "utf8"))) + (t/is (str/includes? @(:text output) "\\u001b\\u0007")) + (t/is (< (count @(:text output)) 1100)) + (doseq [separator ["" "\n"]] + (reset! (:text output) "") + (fs/writeFileSync file (str (apply str (repeat 2000 "\u0007")) separator "FATAL: compiler failed\n") "utf8") + (log/error {:message "tail evidence" :tail-log file}) + (t/is (str/includes? @(:text output) "FATAL: compiler failed")) + (t/is (every? #(let [code (.charCodeAt % 0)] + (or (= code 10) (and (>= code 32) (or (< code 127) (> code 159))))) + (seq @(:text output))))))) + (t/deftest error-names-tail-source-and-bounds-evidence-before-appending (let [file (path/join @temporary-root "comparison.log") child (path/join @temporary-root "build.log")