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")